HHVM Debugger: hook up logging

Reviewed By: velocityboy

Differential Revision: D10208488

fbshipit-source-id: 89b67ba2d0634424d0ab17200ca22647575e7f84

hphp/runtime/ext/vsdebug/debugger.cpp

@@ -19,6 +19,7 @@
 #include "hphp/runtime/base/intercept.h"
 #include "hphp/runtime/base/stat-cache.h"
 #include "hphp/runtime/base/unit-cache.h"
+#include "hphp/runtime/debugger/debugger.h"
 #include "hphp/runtime/ext/vsdebug/ext_vsdebug.h"
 #include "hphp/runtime/ext/vsdebug/debugger.h"
 #include "hphp/runtime/ext/vsdebug/command.h"
@@ -80,7 +81,8 @@ void Debugger::runSessionCleanupThread() {
 
 void Debugger::setClientConnected(
   bool connected,
-  bool synchronous /*= false*/
+  bool synchronous /* = false */,
+  ClientInfo* clientInfo /* = nullptr */
 ) {
   DebuggerSession* sessionToDelete = nullptr;
   SCOPE_EXIT {
@@ -128,6 +130,41 @@ void Debugger::setClientConnected(
     }
 
     if (connected) {
+      // Ensure usage logging is initialized if configured. Init is a no-op if
+      // the logger is already initialized.
+      auto logger = Eval::Debugger::GetUsageLogger();
+      if (logger != nullptr) {
+        logger->init();
+
+        if (clientInfo == nullptr) {
+          VSDebugLogger::Log(
+            VSDebugLogger::LogLevelInfo,
+            "Clearing client info. Connected client has no ID."
+          );
+          logger->clearClientInfo();
+        } else {
+          VSDebugLogger::Log(
+            VSDebugLogger::LogLevelInfo,
+            "Setting connected client info: user=%s,uid=%d,pid=%d",
+            clientInfo->clientUser.c_str(),
+            clientInfo->clientUid,
+            clientInfo->clientPid
+          );
+          logger->setClientInfo(
+            clientInfo->clientUser,
+            clientInfo->clientUid,
+            clientInfo->clientPid
+          );
+        }
+      } else {
+        VSDebugLogger::Log(
+          VSDebugLogger::LogLevelWarning,
+          "Not logging user: no usage logger configured."
+        );
+      }
+
+      VSDebugLogger::LogFlush();
+
       // Create a new debugger session.
       assertx(m_session == nullptr);
       m_session = new DebuggerSession(this);
@@ -185,6 +222,14 @@ void Debugger::setClientConnected(
         m_connectionNotifyCondition.notify_all();
       }
     } else {
+      auto logger = Eval::Debugger::GetUsageLogger();
+      if (logger != nullptr) {
+        VSDebugLogger::Log(
+          VSDebugLogger::LogLevelInfo,
+          "Clearing client info - user disconnected."
+        );
+        logger->clearClientInfo();
+      }
 
       // The client has detached. Walk through any requests we are currently
       // attached to and release them if they are blocked in the debugger.
@@ -913,6 +958,9 @@ bool Debugger::executeClientCommand(
       m_pendingEventMessages.clear();
     };
 
+    // Log command if logging is enabled.
+    logClientCommand(command);
+
     bool resumeThread = callback(m_session, responseMsg);
     if (command->commandTarget() != CommandTarget::WorkItem) {
       sendCommandResponse(command, responseMsg);
@@ -1117,6 +1165,48 @@ void Debugger::dispatchCommandToRequest(
   }
 }
 
+void Debugger::logClientCommand(
+  VSCommand* command
+) {
+  auto logger = Eval::Debugger::GetUsageLogger();
+  if (logger == nullptr) {
+    return;
+  }
+
+  const std::string cmd(command->commandName());
+
+  // Don't bother logging certain very chatty commands. These can
+  // be sent frequently by the client UX and their arguments aren't
+  // interesting from a security perspective.
+  if (cmd == "CompletionsCommand" ||
+      cmd == "ContinueCommand" ||
+      cmd == "StackTraceCommand" ||
+      cmd == "ThreadsCommand") {
+    return;
+  }
+
+  try {
+    folly::json::serialization_opts jsonOptions;
+    jsonOptions.sort_keys = true;
+    jsonOptions.pretty_formatting = true;
+
+    const std::string sandboxId = g_context.isNull()
+      ? ""
+      : g_context->getSandboxId().toCppString();
+    const std::string data =
+      folly::json::serialize(command->getMessage(), jsonOptions);
+    const std::string mode = RuntimeOption::ServerExecutionMode()
+      ? "vsdebug-webserver"
+      : "vsdebug-script";
+    logger->log(mode, sandboxId, cmd, data);
+  } catch (...) {
+    VSDebugLogger::Log(
+      VSDebugLogger::LogLevelError,
+      "Error logging client command"
+    );
+  }
+}
+
 void Debugger::onClientMessage(folly::dynamic& message) {
   Lock lock(m_lock);
 

hphp/runtime/ext/vsdebug/debugger.h

@@ -179,6 +179,12 @@ struct DebuggerOptions {
   bool notifyOnBpCalibration;
 };
 
+struct ClientInfo {
+  std::string clientUser;
+  pid_t clientPid;
+  uid_t clientUid;
+};
+
 struct Debugger final {
   Debugger();
   virtual ~Debugger() {
@@ -195,7 +201,11 @@ struct Debugger final {
   // connected or not. Many debugger events will be skipped if no client is
   // connected to avoid impacting perf when there is no debugger client
   // attached.
-  void setClientConnected(bool connected, bool synchronous = false);
+  void setClientConnected(
+    bool connected,
+    bool synchronous = false,
+    ClientInfo* clientInfo = nullptr
+  );
 
   // Shuts down the debugger session and cleans up any resources. This will also
   // unblock any requests that are broken in to the debugger.
@@ -250,6 +260,8 @@ struct Debugger final {
   // a connected debugger client.
   void onClientMessage(folly::dynamic& message);
 
+  void logClientCommand(VSCommand* command);
+
   // Enters the debugger if the program is paused.
   void enterDebuggerIfPaused(RequestInfo* requestInfo);
 

hphp/runtime/ext/vsdebug/socket_transport.cpp

@@ -578,7 +578,11 @@ void SocketTransport::waitForConnection(
             // We have established a connection with a client.
             m_clientConnected = true;
             setTransportFd(newFd);
-            m_debugger->setClientConnected(true);
+            m_debugger->setClientConnected(
+              true,
+              false,
+              domainSocket ? &m_clientInfo : nullptr
+            );
           }
         }
       }
@@ -655,6 +659,7 @@ bool SocketTransport::validatePeerCreds(int newFd, ClientInfo& info) {
 
   info.clientUser = std::string(pw.pw_name);
   info.clientPid = ucred.pid;
+  info.clientUid = ucred.uid;
   return pw.pw_name != nullptr && strlen(pw.pw_name) > 0;
 #else
   return true;

hphp/runtime/ext/vsdebug/socket_transport.h

@@ -17,6 +17,7 @@
 #ifndef incl_HPHP_VSDEBUG_SOCKET_TRANSPORT_H_
 #define incl_HPHP_VSDEBUG_SOCKET_TRANSPORT_H_
 
+#include "hphp/runtime/ext/vsdebug/debugger.h"
 #include "hphp/runtime/ext/vsdebug/transport.h"
 
 namespace HPHP {
@@ -40,10 +41,6 @@ struct SocketTransport : public DebugTransport {
   void cleanupFd(int fd) override;
 
 private:
-  struct ClientInfo {
-    std::string clientUser;
-    pid_t clientPid;
-  };
 
   void createAbortPipe();
   void listenForClientConnection();