ForkExec: better debug output

Include the pid of the child process in all messages relating to it,
to help in cases where the same program is started multiple times.

Log something in the parent when destroying the fake API instance and
thus canceling the fake method call from the child, because that will
trigger a "lost connection" message in the child which was hard to
correlate with events in the server without those additional log
messages in the parent.

1 files changed, 31 insertions, 10 deletions

diff --git a/src/syncevo/ForkExec.cpp b/src/syncevo/ForkExec.cpp
index adde43ff..ce97c268 100644
--- a/src/syncevo/ForkExec.cpp
+++ b/src/syncevo/ForkExec.cpp
@@ -136,6 +136,15 @@ ForkExecParent::~ForkExecParent()
     if (m_childPid) {
         g_spawn_close_pid(m_childPid);
     }
+#ifndef GDBUS_CXX_HAVE_DISCONNECT
+    if (m_api) {
+        SE_LOG_DEBUG(NULL, "ForkExecParent: shutting down, telling %s %ld that it lost the connection, it %s",
+                     m_helper.c_str(),
+                     (long)m_childPid,
+                     m_api->hasWatches() ? "is watching" : "is not watching");
+        m_api.reset();
+    }
+#endif
 }
 
 /**
@@ -309,10 +318,11 @@ gboolean ForkExecParent::outputReady(GIOChannel *source,
         if (status == G_IO_STATUS_EOF ||
             (condition & (G_IO_HUP|G_IO_ERR)) ||
             error) {
-            SE_LOG_DEBUG(NULL, "reading helper %s done: %s",
+            SE_LOG_DEBUG(NULL, "reading helper %s %ld done: %s",
                          source == me->m_out ? "stdout" :
                          me->m_mergedStdoutStderr ? "combined stdout/stderr" :
                          "stderr",
+                         (long)me->m_childPid,
                          (const char *)error);
 
             // Will remove event source from main loop.
@@ -358,7 +368,8 @@ void ForkExecParent::checkCompletion() throw ()
             m_onQuit(m_status);
             if (!m_hasConnected ||
                 m_status != 0) {
-                SE_LOG_DEBUG(NULL, "ForkExecParent: child was signaled %s, signal %d, int %d, term %d, int sent %s, term sent %s",
+                SE_LOG_DEBUG(NULL, "ForkExecParent: child %ld was signaled %s, signal %d (SIGINT=%d, SIGTERM=%d), int sent %s, term sent %s",
+                             (long)m_childPid,
                              WIFSIGNALED(m_status) ? "yes" : "no",
                              WTERMSIG(m_status), SIGINT, SIGTERM,
                              m_sigIntSent ? "yes" : "no",
@@ -398,8 +409,9 @@ void ForkExecParent::checkCompletion() throw ()
 void ForkExecParent::newClientConnection(GDBusCXX::DBusConnectionPtr &conn) throw()
 {
     try {
-        SE_LOG_DEBUG(NULL, "ForkExecParent: child %s has connected",
-                     m_helper.c_str());
+        SE_LOG_DEBUG(NULL, "ForkExecParent: child %s %ld has connected",
+                     m_helper.c_str(),
+                     (long)m_childPid);
         m_hasConnected = true;
 #ifndef GDBUS_CXX_HAVE_DISCONNECT
         m_api.reset(new ForkExecParentDBusAPI(conn, getInstance()));
@@ -430,8 +442,9 @@ void ForkExecParent::stop(int signal)
         return;
     }
 
-    SE_LOG_DEBUG(NULL, "ForkExecParent: killing %s with signal %d (%s %s)",
+    SE_LOG_DEBUG(NULL, "ForkExecParent: killing %s %ld with signal %d (%s %s)",
                  m_helper.c_str(),
+                 (long)m_childPid,
                  signal,
                  (!signal || signal == SIGINT) ? "SIGINT" : "",
                  (!signal || signal == SIGTERM) ? "SIGTERM" : "");
@@ -455,13 +468,21 @@ void ForkExecParent::kill()
         return;
     }
 
-    SE_LOG_DEBUG(NULL, "ForkExecParent: killing %s with SIGKILL",
-                 m_helper.c_str());
+    SE_LOG_DEBUG(NULL, "ForkExecParent: killing %s %ld with SIGKILL",
+                 m_helper.c_str(),
+                 (long)m_childPid);
     ::kill(m_childPid, SIGKILL);
 #ifndef GDBUS_CXX_HAVE_DISCONNECT
-    // Drop our connection to the child. Prevents further communication
-    // from child to us!
-    m_api.reset();
+    // Cancel the pending method call from the child to us. This will
+    // send an error reply to the child, which it'll treat as
+    // "connection lost".
+    if (m_api) {
+        SE_LOG_DEBUG(NULL, "ForkExecParent: telling %s %ld that it lost the connection, it %s",
+                     m_helper.c_str(),
+                     (long)m_childPid,
+                     m_api->hasWatches() ? "is watching" : "is not watching");
+        m_api.reset();
+    }
 #endif
 }