diff --git a/hphp/runtime/debugger/cmd/cmd_extended.cpp b/hphp/runtime/debugger/cmd/cmd_extended.cpp index f2581775e..2eaca68b9 100644 --- a/hphp/runtime/debugger/cmd/cmd_extended.cpp +++ b/hphp/runtime/debugger/cmd/cmd_extended.cpp @@ -160,6 +160,7 @@ bool CmdExtended::invokeHelp(DebuggerClient &client, const std::string &cls) { } bool CmdExtended::invokeClient(DebuggerClient &client, const std::string &cls){ + client.usageLogCommand("extended", cls); DebuggerCommandPtr cmd = CreateExtendedCommand(cls); if (cmd) { cmd->onClient(client); diff --git a/hphp/runtime/debugger/cmd/cmd_extended.h b/hphp/runtime/debugger/cmd/cmd_extended.h index 4ff019c6e..e42de3836 100644 --- a/hphp/runtime/debugger/cmd/cmd_extended.h +++ b/hphp/runtime/debugger/cmd/cmd_extended.h @@ -39,13 +39,13 @@ public: virtual bool onServer(DebuggerProxy &proxy); +protected: // so CmdUser can override these functions virtual const ExtendedCommandMap &getCommandMap(); virtual void invokeList(DebuggerClient &client, const std::string &cls); virtual bool invokeHelp(DebuggerClient &client, const std::string &cls); virtual bool invokeClient(DebuggerClient &client, const std::string &cls); -protected: virtual void onClientImpl(DebuggerClient &client); void helpImpl(DebuggerClient &client, const char *name); diff --git a/hphp/runtime/debugger/cmd/cmd_machine.cpp b/hphp/runtime/debugger/cmd/cmd_machine.cpp index c58a4741f..880625f57 100644 --- a/hphp/runtime/debugger/cmd/cmd_machine.cpp +++ b/hphp/runtime/debugger/cmd/cmd_machine.cpp @@ -169,6 +169,7 @@ bool CmdMachine::AttachSandbox(DebuggerClient &client, sandbox->desc().c_str()); CmdMachinePtr cmdMachine = client.xend(&cmd); if (cmdMachine->m_succeed) { + client.setSandbox(sandbox); client.playMacro("startup"); } else { // Note: it would be nice to give them more info about the process we think diff --git a/hphp/runtime/debugger/cmd/cmd_user.cpp b/hphp/runtime/debugger/cmd/cmd_user.cpp index b4b74b5be..255035e5f 100644 --- a/hphp/runtime/debugger/cmd/cmd_user.cpp +++ b/hphp/runtime/debugger/cmd/cmd_user.cpp @@ -96,6 +96,7 @@ bool CmdUser::invokeHelp(DebuggerClient &client, const std::string &cls) { } bool CmdUser::invokeClient(DebuggerClient &client, const std::string &cls) { + client.usageLogCommand("user", cls); p_DebuggerClientCmdUser pclient(NEWOBJ(c_DebuggerClientCmdUser)()); pclient->m_client = &client; try { diff --git a/hphp/runtime/debugger/debugger.cpp b/hphp/runtime/debugger/debugger.cpp index 63bb08473..ba0bdf089 100644 --- a/hphp/runtime/debugger/debugger.cpp +++ b/hphp/runtime/debugger/debugger.cpp @@ -597,9 +597,10 @@ void Debugger::InitUsageLogging() { if (s_debugger.m_usageLogger) s_debugger.m_usageLogger->init(); } -void Debugger::UsageLog(const std::string &mode, const std::string &cmd, - const std::string &data) { - if (s_debugger.m_usageLogger) s_debugger.m_usageLogger->log(mode, cmd, data); +void Debugger::UsageLog(const std::string &mode, const std::string &sandboxId, + const std::string &cmd, const std::string &data) { + if (s_debugger.m_usageLogger) s_debugger.m_usageLogger->log(mode, sandboxId, + cmd, data); } const char *Debugger::InterruptTypeName(CmdInterrupt &cmd) { @@ -618,8 +619,10 @@ const char *Debugger::InterruptTypeName(CmdInterrupt &cmd) { } } -void Debugger::UsageLogInterrupt(const std::string &mode, CmdInterrupt &cmd) { - UsageLog(mode, "interrupt", InterruptTypeName(cmd)); +void Debugger::UsageLogInterrupt(const std::string &mode, + const std::string &sandboxId, + CmdInterrupt &cmd) { + UsageLog(mode, sandboxId, "interrupt", InterruptTypeName(cmd)); } /////////////////////////////////////////////////////////////////////////////// diff --git a/hphp/runtime/debugger/debugger.h b/hphp/runtime/debugger/debugger.h index a1f8d61e8..c7316622e 100644 --- a/hphp/runtime/debugger/debugger.h +++ b/hphp/runtime/debugger/debugger.h @@ -100,9 +100,13 @@ public: // Usage logging static void SetUsageLogger(DebuggerUsageLogger *usageLogger); static void InitUsageLogging(); - static void UsageLog(const std::string &mode, const std::string &cmd, + static void UsageLog(const std::string &mode, + const std::string &sandboxId, + const std::string &cmd, const std::string &data = ""); - static void UsageLogInterrupt(const std::string &mode, CmdInterrupt &cmd); + static void UsageLogInterrupt(const std::string &mode, + const std::string &sandboxId, + CmdInterrupt &cmd); private: static Debugger s_debugger; diff --git a/hphp/runtime/debugger/debugger_base.h b/hphp/runtime/debugger/debugger_base.h index 25fd1dbe5..7376994d9 100644 --- a/hphp/runtime/debugger/debugger_base.h +++ b/hphp/runtime/debugger/debugger_base.h @@ -128,6 +128,7 @@ extern const char *PHP_KEYWORDS[]; /////////////////////////////////////////////////////////////////////////////// +DECLARE_BOOST_TYPES(DSandboxInfo); DECLARE_BOOST_TYPES(DMachineInfo); class DMachineInfo { public: @@ -141,6 +142,7 @@ public: bool m_interrupting; // True if the machine is paused at an interrupt bool m_sandboxAttached; + DSandboxInfoPtr m_sandbox; bool m_initialized; // True if the initial connection protocol is complete std::string m_rpcHost; int m_rpcPort; @@ -148,7 +150,6 @@ public: /////////////////////////////////////////////////////////////////////////////// -DECLARE_BOOST_TYPES(DSandboxInfo); class DSandboxInfo { public: DSandboxInfo() {} @@ -230,8 +231,8 @@ class DebuggerUsageLogger { public: virtual ~DebuggerUsageLogger() {} virtual void init() {} - virtual void log(const std::string &mode, const std::string &cmd, - const std::string &data) {} + virtual void log(const std::string &mode, const std::string &sandboxId, + const std::string &cmd, const std::string &data) {} }; /////////////////////////////////////////////////////////////////////////////// diff --git a/hphp/runtime/debugger/debugger_client.cpp b/hphp/runtime/debugger/debugger_client.cpp index 6a2c2e0c2..1c492d7de 100644 --- a/hphp/runtime/debugger/debugger_client.cpp +++ b/hphp/runtime/debugger/debugger_client.cpp @@ -95,16 +95,18 @@ void DebuggerClient::onSignal(int sig) { int secWait = 10; int secLeft = secWait - (now - m_sigTime); if (secLeft <= 0) { + usageLogEvent("signal quit"); error("Program is not responding. Please restart debugger to get a " "new connection."); quit(); // NB: the machine is running, so can't send a real CmdQuit. return; } + usageLogEvent("signal wait"); info("Please wait. If not responding in %d second%s, " "press Ctrl-C again to quit.", secLeft, secLeft > 1 ? "s" : ""); } else { + usageLogEvent("signal start"); info("Pausing program execution, please wait..."); - usageLog("signal"); m_sigTime = now; } m_signum = CmdSignal::SignalBreak; @@ -460,6 +462,7 @@ bool DebuggerClient::connectRPC(const std::string &host, int port) { local->m_rpcPort = port; switchMachine(local); m_rpcHost = "rpc:" + host; + usageLogEvent("RPC connect", m_rpcHost); return !local->m_interrupting; } @@ -613,7 +616,7 @@ void DebuggerClient::init(const DebuggerClientOptions &options) { m_options.user = Process::GetCurrentUser(); } - usageLog("init"); + usageLogEvent("init"); loadConfig(); @@ -692,26 +695,32 @@ void DebuggerClient::run() { } catch (DebuggerServerLostException &e) { // Loss of connection TRACE_RB(1, "DebuggerClient::run: server lost exception\n"); - usageLog(m_commandCanonical, "DebuggerServerLostException"); + usageLogEvent("DebuggerServerLostException", m_commandCanonical); reconnect = true; } catch (DebuggerProtocolException &e) { // Bad or unexpected data. Give reconnect a shot, it could help... TRACE_RB(1, "DebuggerClient::run: protocol exception\n"); - usageLog(m_commandCanonical, "DebuggerProtocolException"); + usageLogEvent("DebuggerProtocolException", m_commandCanonical); reconnect = true; } catch (...) { TRACE_RB(1, "DebuggerClient::run: unknown exception\n"); - usageLog(m_commandCanonical, "UnknownException"); + usageLogEvent("UnknownException", m_commandCanonical); Logger::Error("Unhandled exception, exiting."); } // Note: it's silly to try to reconnect when stopping, or if we have a // problem while quitting. if (reconnect && !m_stopped && (m_commandCanonical != "quit")) { - if (DebuggerClient::reconnect()) continue; + usageLogEvent("reconnect attempt", m_commandCanonical); + if (DebuggerClient::reconnect()) { + usageLogEvent("reconnect success", m_commandCanonical); + continue; + } + usageLogEvent("reconnect failed", m_commandCanonical); Logger::Error("Unable to reconnect to server, exiting."); } break; } + usageLogEvent("exit"); // Closing all proxy connections will force the local proxy to pop out of // it's wait, and eventually exit the main thread. closeAllConnections(); @@ -1028,7 +1037,8 @@ DebuggerCommandPtr DebuggerClient::waitForNextInterrupt() { } } else { CmdInterruptPtr intr = dynamic_pointer_cast(cmd); - Debugger::UsageLogInterrupt(getUsageMode(), *intr.get()); + Debugger::UsageLogInterrupt(getUsageMode(), getSandboxId(), + *intr.get()); } m_sigTime = 0; m_machine->m_interrupting = true; @@ -1078,7 +1088,7 @@ DebuggerCommandPtr DebuggerClient::eventLoop(EventLoopKind loopKind, cmd->is((DebuggerCommand::Type)expectedCmd)) { // For the nested cases, the caller has sent a cmd to the server and is // expecting a specific response. When we get it, return it. - usageLog("done", boost::lexical_cast(expectedCmd)); + usageLogEvent("command done", boost::lexical_cast(expectedCmd)); m_machine->m_interrupting = true; // Machine is stopped m_inputState = TakingCommand; return cmd; @@ -1103,7 +1113,7 @@ DebuggerCommandPtr DebuggerClient::eventLoop(EventLoopKind loopKind, } m_sigTime = 0; CmdInterruptPtr intr = dynamic_pointer_cast(cmd); - Debugger::UsageLogInterrupt(getUsageMode(), *intr.get()); + Debugger::UsageLogInterrupt(getUsageMode(), getSandboxId(), *intr.get()); cmd->onClient(*this); // When we make a new connection to a machine, we have to wait for it @@ -1705,7 +1715,7 @@ bool DebuggerClient::process() { } case '?': { if (match("?")) { - usageLog("help", m_line); + usageLogCommand("help", m_line); CmdHelp().onClient(*this); return true; } @@ -1718,7 +1728,7 @@ bool DebuggerClient::process() { default: { DebuggerCommand *cmd = createCommand(); if (cmd) { - usageLog(m_commandCanonical, m_line); + usageLogCommand(m_commandCanonical, m_line); if (cmd->is(DebuggerCommand::KindOfRun)) playMacro("startup"); DebuggerCommandPtr deleter(cmd); cmd->onClient(*this); @@ -1916,12 +1926,12 @@ void DebuggerClient::processTakeCode() { char first = m_line[0]; if (first == '@') { - usageLog("@", m_line); + usageLogCommand("@", m_line); m_code = string("m_sandbox = sandbox; +} + +// Return the ID of the current sandbox, if there is one. If we're connected to +// a machine that is attached to a sandbox, then we'll have an ID. +std::string DebuggerClient::getSandboxId() { + if ((m_machine != nullptr) && m_machine->m_sandboxAttached && + (m_machine->m_sandbox != nullptr)) { + return m_machine->m_sandbox->id(); + } + return "None"; +} + void DebuggerClient::updateThreads(DThreadInfoPtrVec threads) { TRACE(2, "DebuggerClient::updateThreads\n"); m_threads = threads; @@ -2247,6 +2274,7 @@ void DebuggerClient::record(const char *line) { bool DebuggerClient::apiGrab() { TRACE(2, "DebuggerClient::apiGrab\n"); + usageLogEvent("api grab"); Lock l(m_inApiUseLck); if (m_inApiUse) { return false; @@ -2257,6 +2285,7 @@ bool DebuggerClient::apiGrab() { void DebuggerClient::apiFree() { TRACE(2, "DebuggerClient::apiFree\n"); + usageLogEvent("api grab"); Lock l(m_inApiUseLck); m_inApiUse = false; } @@ -2277,10 +2306,18 @@ const char *DebuggerClient::getUsageMode() { return isApiMode() ? "api" : "terminal"; } -void DebuggerClient::usageLog(const std::string &cmd, const std::string &data) { - Debugger::UsageLog(getUsageMode(), cmd, data); +// Log the execution of a command. +void DebuggerClient::usageLogCommand(const std::string &cmd, + const std::string &data) { + Debugger::UsageLog(getUsageMode(), getSandboxId(), cmd, data); } +// Log random, interesting events in the client. +void DebuggerClient::usageLogEvent(const std::string &eventName, + const std::string &data) { + Debugger::UsageLog(getUsageMode(), getSandboxId(), + "ClientEvent: " + eventName, data); +} /////////////////////////////////////////////////////////////////////////////// // configuration diff --git a/hphp/runtime/debugger/debugger_client.h b/hphp/runtime/debugger/debugger_client.h index 32f576e3c..6f5467d11 100644 --- a/hphp/runtime/debugger/debugger_client.h +++ b/hphp/runtime/debugger/debugger_client.h @@ -223,6 +223,8 @@ public: m_sandboxes = sandboxes; } DSandboxInfoPtr getSandbox(int index) const; + void setSandbox(DSandboxInfoPtr sandbox); + std::string getSandboxId(); /** * Thread functions. @@ -342,6 +344,11 @@ public: } std::string getCurrentUser() const { return m_options.user; } + // Usage logging + void usageLogCommand(const std::string &cmd, const std::string &data); + void usageLogEvent(const std::string &eventName, + const std::string &data = ""); + private: enum InputState { TakingCommand, @@ -487,7 +494,6 @@ private: // usage logging const char *getUsageMode(); - void usageLog(const std::string &cmd, const std::string &data = ""); }; /////////////////////////////////////////////////////////////////////////////// diff --git a/hphp/runtime/debugger/debugger_proxy.cpp b/hphp/runtime/debugger/debugger_proxy.cpp index 33575b45a..98bd01e07 100644 --- a/hphp/runtime/debugger/debugger_proxy.cpp +++ b/hphp/runtime/debugger/debugger_proxy.cpp @@ -37,7 +37,8 @@ DebuggerProxy::DebuggerProxy(SmartPtr socket, bool local) TRACE(2, "DebuggerProxy::DebuggerProxy\n"); m_thrift.create(socket); m_dummyInfo = DSandboxInfo::CreateDummyInfo((int64_t)this); - Debugger::UsageLog("server", "connnect", socket->getAddress()); + Debugger::UsageLog("server", m_dummyInfo.id(), + "connnect", socket->getAddress()); } DebuggerProxy::~DebuggerProxy() { @@ -49,7 +50,7 @@ DebuggerProxy::~DebuggerProxy() { m_dummySandbox->stop(); } - Debugger::UsageLog("server", "disconnect"); + Debugger::UsageLog("server", getSandboxId(), "disconnect"); TRACE_RB(2, "DebuggerProxy::~DebuggerProxy complete\n"); } @@ -548,7 +549,7 @@ void DebuggerProxy::processInterrupt(CmdInterrupt &cmd) { return; } - Debugger::UsageLogInterrupt("server", cmd); + Debugger::UsageLogInterrupt("server", getSandboxId(), cmd); // Wait for commands from the debugger client and process them. We'll stay // here until we get a command that should cause the thread to continue. @@ -562,7 +563,8 @@ void DebuggerProxy::processInterrupt(CmdInterrupt &cmd) { checkStop(); if (res) { TRACE_RB(2, "Proxy got cmd type %d\n", res->getType()); - Debugger::UsageLog("server", boost::lexical_cast(res->getType())); + Debugger::UsageLog("server", getSandboxId(), + boost::lexical_cast(res->getType())); // Any control flow command gets installed here and we continue execution. m_flow = dynamic_pointer_cast(res); if (m_flow) {