Changeset 39313 in vbox for trunk/src/VBox/Additions/common/VBoxService/VBoxServiceControlExecThread.cpp

Timestamp:

Nov 15, 2011 2:43:38 PM (13 years ago)

Author:

vboxsync

svn:sync-xref-src-repo-rev:

74874

Message:

VBoxService: Logging adjustments.

File:

• trunk/src/VBox/Additions/common/VBoxService/VBoxServiceControlExecThread.cpp (modified) (43 diffs)

trunk/src/VBox/Additions/common/VBoxService/VBoxServiceControlExecThread.cpp

@@ -164 +164 @@
     AssertPtrReturn(pThread, VERR_INVALID_POINTER);
 
-    VBoxServiceVerbose(3, "ControlExec: [PID %u]: Signalling shutdown ...\n",
+    VBoxServiceVerbose(3, "ControlThead: [PID %u]: Signalling shutdown ...\n",
                        pThread->uPID);
 
@@ -176 +176 @@
     int rc = VBoxServiceControlThreadPerform(pThread->uPID, &ctrlRequest);
     if (RT_FAILURE(rc))
-        VBoxServiceVerbose(3, "ControlExec: [PID %u]: Sending quit request failed with rc=%Rrc\n",
+        VBoxServiceVerbose(3, "ControlThead: [PID %u]: Sending quit request failed with rc=%Rrc\n",
                            pThread->uPID, rc);
     return rc;
@@ -197 +197 @@
         && !ASMAtomicReadBool(&pThread->fStopped)) /* Only shutdown threads which aren't yet. */
     {
-        VBoxServiceVerbose(3, "ControlExec: [PID %u]: Waiting for shutdown ...\n",
+        VBoxServiceVerbose(3, "ControlThead: [PID %u]: Waiting for shutdown ...\n",
                            pThread->uPID);
 
@@ -205 +205 @@
         if (RT_FAILURE(rcThread))
         {
-            VBoxServiceError("ControlExec: [PID %u]: Shutdown returned error rc=%Rrc\n",
+            VBoxServiceError("ControlThead: [PID %u]: Shutdown returned error rc=%Rrc\n",
                              pThread->uPID, rcThread);
             if (RT_SUCCESS(rc))
@@ -225 +225 @@
         return;
 
-    VBoxServiceVerbose(3, "ControlExec: [PID %u]: Freeing thread data ...\n",
+    VBoxServiceVerbose(3, "ControlThead: [PID %u]: Freeing thread data ...\n",
                        pThread->uPID);
 
@@ -316 +316 @@
 
 #ifdef DEBUG_andy
-    VBoxServiceVerbose(4, "ControlExec: HandleOutputEvent fPollEvt=0x%x, idPollHnd=%u\n",
+    VBoxServiceVerbose(4, "ControlThead: HandleOutputEvent fPollEvt=0x%x, idPollHnd=%u\n",
                        fPollEvt, idPollHnd);
 #endif
@@ -342 +342 @@
 {
 #ifdef DEBUG_andy
-    VBoxServiceVerbose(4, "ControlExec: HandleIPCRequest\n");
+    VBoxServiceVerbose(4, "ControlThead: HandleIPCRequest\n");
 #endif
 
@@ -358 +358 @@
         int rc = RTPipeRead(pThread->hNotificationPipeR, abBuf, sizeof(abBuf), &cbIgnore);
         if (RT_FAILURE(rc))
-            VBoxServiceError("ControlExec: Draining IPC notification pipe failed with rc=%Rrc\n", rc);
+            VBoxServiceError("ControlThead: Draining IPC notification pipe failed with rc=%Rrc\n", rc);
 
         int rcReq = VINF_SUCCESS; /* Actual request result. */
@@ -438 +438 @@
                      ? rcReq : rc;
 
-        VBoxServiceVerbose(4, "ControlExec: Handled IPC request with rcReq=%Rrc, enmType=%u, cbData=%u\n",
+        VBoxServiceVerbose(4, "ControlThead: Handled IPC request with rcReq=%Rrc, enmType=%u, cbData=%u\n",
                            rcReq, pRequest->enmType, pRequest->cbData);
 
@@ -498 +498 @@
     if (RT_FAILURE(rc))
     {
-        VBoxServiceError("ControlExec: Unable to assign PID to new thread, rc=%Rrc\n", rc);
+        VBoxServiceError("ControlThead: Unable to assign PID to new thread, rc=%Rrc\n", rc);
         return rc;
     }
@@ -506 +506 @@
      * and that it's now OK to send input to the process.
      */
-    VBoxServiceVerbose(3, "ControlExec: [PID %u]: Process started, CID=%u, User=%s\n",
+    VBoxServiceVerbose(3, "ControlThead: [PID %u]: Process started, CID=%u, User=%s\n",
                        pThread->uPID, pThread->uContextID, pThread->pszUser);
     rc = VbglR3GuestCtrlExecReportStatus(pThread->uClientID, pThread->uContextID,
@@ -531 +531 @@
         if (RT_SUCCESS(rc2))
         {
-            /*VBoxServiceVerbose(4, "ControlExec: [PID %u}: RTPollNoResume idPollHnd=%u\n",
+            /*VBoxServiceVerbose(4, "ControlThead: [PID %u}: RTPollNoResume idPollHnd=%u\n",
                                  pThread->uPID, idPollHnd);*/
             switch (idPollHnd)
@@ -608 +608 @@
             if (cMsElapsed >= cMsTimeout)
             {
-                VBoxServiceVerbose(3, "ControlExec: [PID %u]: Timed out (%ums elapsed > %ums timeout), killing ...",
+                VBoxServiceVerbose(3, "ControlThead: [PID %u]: Timed out (%ums elapsed > %ums timeout), killing ...",
                                    pThread->uPID, cMsElapsed, cMsTimeout);
 
@@ -644 +644 @@
         if (MsProcessKilled == UINT64_MAX)
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Is still alive and not killed yet\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Is still alive and not killed yet\n",
                                pThread->uPID);
 
@@ -654 +654 @@
         for (size_t i = 0; i < 10; i++)
         {
-            VBoxServiceVerbose(4, "ControlExec: [PID %u]: Kill attempt %d/10: Waiting to exit ...\n",
+            VBoxServiceVerbose(4, "ControlThead: [PID %u]: Kill attempt %d/10: Waiting to exit ...\n",
                                pThread->uPID, i + 1);
             rc2 = RTProcWait(hProcess, RTPROCWAIT_FLAGS_NOBLOCK, &ProcessStatus);
             if (RT_SUCCESS(rc2))
             {
-                VBoxServiceVerbose(4, "ControlExec: [PID %u]: Kill attempt %d/10: Exited\n",
+                VBoxServiceVerbose(4, "ControlThead: [PID %u]: Kill attempt %d/10: Exited\n",
                                    pThread->uPID, i + 1);
                 fProcessAlive = false;
@@ -666 +666 @@
             if (i >= 5)
             {
-                VBoxServiceVerbose(4, "ControlExec: [PID %u]: Kill attempt %d/10: Trying to terminate ...\n",
+                VBoxServiceVerbose(4, "ControlThead: [PID %u]: Kill attempt %d/10: Trying to terminate ...\n",
                                    pThread->uPID, i + 1);
                 RTProcTerminate(hProcess);
@@ -674 +674 @@
 
         if (fProcessAlive)
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Could not be killed\n", pThread->uPID);
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Could not be killed\n", pThread->uPID);
     }
 
@@ -688 +688 @@
         if (     fProcessTimedOut  && !fProcessAlive && MsProcessKilled != UINT64_MAX)
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Timed out and got killed\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Timed out and got killed\n",
                                pThread->uPID);
             uStatus = PROC_STS_TOK;
@@ -694 +694 @@
         else if (fProcessTimedOut  &&  fProcessAlive && MsProcessKilled != UINT64_MAX)
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Timed out and did *not* get killed\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Timed out and did *not* get killed\n",
                                pThread->uPID);
             uStatus = PROC_STS_TOA;
@@ -700 +700 @@
         else if (pThread->fShutdown && (fProcessAlive || MsProcessKilled != UINT64_MAX))
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Got terminated because system/service is about to shutdown\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Got terminated because system/service is about to shutdown\n",
                                pThread->uPID);
             uStatus = PROC_STS_DWN; /* Service is stopping, process was killed. */
@@ -707 +707 @@
         else if (fProcessAlive)
         {
-            VBoxServiceError("ControlExec: [PID %u]: Is alive when it should not!\n",
+            VBoxServiceError("ControlThead: [PID %u]: Is alive when it should not!\n",
                              pThread->uPID);
         }
         else if (MsProcessKilled != UINT64_MAX)
         {
-            VBoxServiceError("ControlExec: [PID %u]: Has been killed when it should not!\n",
+            VBoxServiceError("ControlThead: [PID %u]: Has been killed when it should not!\n",
                              pThread->uPID);
         }
         else if (ProcessStatus.enmReason == RTPROCEXITREASON_NORMAL)
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Ended with RTPROCEXITREASON_NORMAL (%u)\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Ended with RTPROCEXITREASON_NORMAL (%u)\n",
                                pThread->uPID, ProcessStatus.iStatus);
 
@@ -725 +725 @@
         else if (ProcessStatus.enmReason == RTPROCEXITREASON_SIGNAL)
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Ended with RTPROCEXITREASON_SIGNAL (%u)\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Ended with RTPROCEXITREASON_SIGNAL (%u)\n",
                                pThread->uPID, ProcessStatus.iStatus);
 
@@ -733 +733 @@
         else if (ProcessStatus.enmReason == RTPROCEXITREASON_ABEND)
         {
-            VBoxServiceVerbose(3, "ControlExec: [PID %u]: Ended with RTPROCEXITREASON_ABEND (%u)\n",
+            VBoxServiceVerbose(3, "ControlThead: [PID %u]: Ended with RTPROCEXITREASON_ABEND (%u)\n",
                                pThread->uPID, ProcessStatus.iStatus);
 
@@ -740 +740 @@
         }
         else
-            VBoxServiceVerbose(1, "ControlExec: [PID %u]: Handling process status %u not implemented\n",
+            VBoxServiceVerbose(1, "ControlThead: [PID %u]: Handling process status %u not implemented\n",
                                pThread->uPID, ProcessStatus.enmReason);
 
-        VBoxServiceVerbose(3, "ControlExec: [PID %u]: Sending final status, ClientID=%u, CID=%u, Status=%u, Flags=0x%x\n",
+        VBoxServiceVerbose(3, "ControlThead: [PID %u]: Sending final status, ClientID=%u, CID=%u, Status=%u, Flags=0x%x\n",
                            pThread->uPID, pThread->uClientID, pThread->uContextID, uStatus, uFlags);
         rc = VbglR3GuestCtrlExecReportStatus(pThread->uClientID, pThread->uContextID,
@@ -749 +749 @@
                                              NULL /* pvData */, 0 /* cbData */);
         if (RT_FAILURE(rc))
-            VBoxServiceError("ControlExec: [PID %u]: Error reporting final status to host; rc=%Rrc\n",
+            VBoxServiceError("ControlThead: [PID %u]: Error reporting final status to host; rc=%Rrc\n",
                              pThread->uPID, rc);
 
-        VBoxServiceVerbose(3, "ControlExec: [PID %u]: Process loop ended with rc=%Rrc\n",
+        VBoxServiceVerbose(3, "ControlThead: [PID %u]: Process loop ended with rc=%Rrc\n",
                            pThread->uPID, rc);
     }
     else
-        VBoxServiceError("ControlExec: [PID %u]: Loop failed with rc=%Rrc\n",
+        VBoxServiceError("ControlThead: [PID %u]: Loop failed with rc=%Rrc\n",
                          pThread->uPID, rc);
     return rc;
@@ -833 +833 @@
 #endif
 #ifdef DEBUG
-    VBoxServiceVerbose(3, "ControlExec: VBoxServiceControlExecMakeFullPath: %s -> %s\n",
+    VBoxServiceVerbose(3, "ControlThead: VBoxServiceControlExecMakeFullPath: %s -> %s\n",
                        pszPath, pszExpanded);
 #endif
@@ -870 +870 @@
         rc = VBoxServiceControlThreadMakeFullPath(pszExecResolved, pszResolved, cbResolved);
 #ifdef DEBUG
-        VBoxServiceVerbose(3, "ControlExec: VBoxServiceControlExecResolveExecutable: %s -> %s\n",
+        VBoxServiceVerbose(3, "ControlThead: VBoxServiceControlExecResolveExecutable: %s -> %s\n",
                            pszFileName, pszResolved);
 #endif
@@ -1041 +1041 @@
                 uProcFlags |= RTPROC_FLAGS_SERVICE;
 #ifdef DEBUG
-            VBoxServiceVerbose(3, "ControlExec: Command: %s\n", szExecExp);
+            VBoxServiceVerbose(3, "ControlThead: Command: %s\n", szExecExp);
             for (size_t i = 0; papszArgsExp[i]; i++)
-                VBoxServiceVerbose(3, "ControlExec:\targv[%ld]: %s\n", i, papszArgsExp[i]);
+                VBoxServiceVerbose(3, "ControlThead:\targv[%ld]: %s\n", i, papszArgsExp[i]);
 #endif
             /* Do normal execution. */
@@ -1066 +1066 @@
 {
     AssertPtrReturn(pThread, VERR_INVALID_POINTER);
-    VBoxServiceVerbose(3, "ControlExec: Thread of process \"%s\" started\n", pThread->pszCmd);
+    VBoxServiceVerbose(3, "ControlThead: Thread of process \"%s\" started\n", pThread->pszCmd);
 
     int rc = VbglR3GuestCtrlConnect(&pThread->uClientID);
     if (RT_FAILURE(rc))
     {
-        VBoxServiceError("ControlExec: Thread failed to connect to the guest control service, aborted! Error: %Rrc\n", rc);
+        VBoxServiceError("ControlThead: Thread failed to connect to the guest control service, aborted! Error: %Rrc\n", rc);
         RTThreadUserSignal(RTThreadSelf());
         return rc;
     }
-    VBoxServiceVerbose(3, "ControlExec: Guest process \"%s\" got client ID=%u\n",
+    VBoxServiceVerbose(3, "ControlThead: Guest process \"%s\" got client ID=%u\n",
                        pThread->pszCmd, pThread->uClientID);
 
@@ -1148 +1148 @@
                                                                            &hProcess);
                                 if (RT_FAILURE(rc))
-                                    VBoxServiceError("ControlExec: Error starting process, rc=%Rrc\n", rc);
+                                    VBoxServiceError("ControlThead: Error starting process, rc=%Rrc\n", rc);
                                 /*
                                  * Tell the control thread that it can continue
@@ -1203 +1203 @@
                                 else /* Something went wrong; report error! */
                                 {
-                                    VBoxServiceError("ControlExec: Could not start process '%s' (CID: %u)! Error: %Rrc\n",
+                                    VBoxServiceError("ControlThead: Could not start process '%s' (CID: %u)! Error: %Rrc\n",
                                                      pThread->pszCmd, pThread->uContextID, rc);
 
@@ -1210 +1210 @@
                                                                           NULL /* pvData */, 0 /* cbData */);
                                     if (RT_FAILURE(rc2))
-                                        VBoxServiceError("ControlExec: Could not report process start error! Error: %Rrc (process error %Rrc)\n",
+                                        VBoxServiceError("ControlThead: Could not report process start error! Error: %Rrc (process error %Rrc)\n",
                                                          rc2, rc);
                                 }
@@ -1238 +1238 @@
     if (pThread->uClientID)
     {
-        VBoxServiceVerbose(3, "ControlExec: [PID %u]: Cancelling pending waits (client ID=%u)\n",
+        VBoxServiceVerbose(3, "ControlThead: [PID %u]: Cancelling pending waits (client ID=%u)\n",
                            pThread->uPID, pThread->uClientID);
         int rc2 = VbglR3GuestCtrlCancelPendingWaits(pThread->uClientID);
         if (RT_FAILURE(rc2))
         {
-            VBoxServiceError("ControlExec: [PID %u]: Cancelling pending waits failed; rc=%Rrc\n",
+            VBoxServiceError("ControlThead: [PID %u]: Cancelling pending waits failed; rc=%Rrc\n",
                              pThread->uPID, rc2);
             if (RT_SUCCESS(rc))
@@ -1250 +1250 @@
 
         /* Disconnect from guest control service. */
+        VBoxServiceError("ControlThead: [PID %u]: Disconnecting (client ID=%u) ...\n",
+                         pThread->uPID, pThread->uClientID);
         VbglR3GuestCtrlDisconnect(pThread->uClientID);
         pThread->uClientID = 0;
     }
 
-    VBoxServiceVerbose(3, "ControlExec: [PID %u]: Thread of process \"%s\" ended with rc=%Rrc\n",
+    VBoxServiceVerbose(3, "ControlThead: [PID %u]: Thread of process \"%s\" ended with rc=%Rrc\n",
                        pThread->uPID, pThread->pszCmd, rc);
 
@@ -1346 +1348 @@
         if (RT_FAILURE(rc))
         {
-            VBoxServiceError("ControlExec: RTThreadCreate failed, rc=%Rrc\n, pThread=%p\n",
+            VBoxServiceError("ControlThead: RTThreadCreate failed, rc=%Rrc\n, pThread=%p\n",
                              rc, pThread);
         }
         else
         {
-            VBoxServiceVerbose(4, "ControlExec: Waiting for thread to initialize ...\n");
+            VBoxServiceVerbose(4, "ControlThead: Waiting for thread to initialize ...\n");
 
             /* Wait for the thread to initialize. */
@@ -1357 +1359 @@
             if (ASMAtomicReadBool(&pThread->fShutdown))
             {
-                VBoxServiceError("ControlExec: Thread for process \"%s\" failed to start!\n", pszCmd);
+                VBoxServiceError("ControlThead: Thread for process \"%s\" failed to start!\n", pszCmd);
                 rc = VERR_GENERAL_FAILURE;
             }
@@ -1400 +1402 @@
         PVBOXSERVICECTRLTHREAD pNext = RTListNodeGetNext(&pOldThread->Node, VBOXSERVICECTRLTHREAD, Node);
 
-        VBoxServiceVerbose(3, "ControlExec: PID %u was used before, shutting down stale exec thread ...\n",
+        VBoxServiceVerbose(3, "ControlThead: PID %u was used before, shutting down stale exec thread ...\n",
                            uPID);
         rc = vboxServiceControlThreadShutdown(pOldThread);
         if (RT_FAILURE(rc))
         {
-            VBoxServiceVerbose(3, "ControlExec: Unable to shut down stale exec thread, rc=%Rrc\n", rc);
+            VBoxServiceVerbose(3, "ControlThead: Unable to shut down stale exec thread, rc=%Rrc\n", rc);
             /* Keep going. */
         }
@@ -1431 +1433 @@
     /* Rest in pRequest is optional (based on the request type). */
 
-    VBoxServiceVerbose(4, "ControlExec: Performing PID=%u, enmType=%u, pvData=0x%p, cbData=%u ...\n",
+    VBoxServiceVerbose(4, "ControlThead: Performing PID=%u, enmType=%u, pvData=0x%p, cbData=%u ...\n",
                        uPID, pRequest->enmType, pRequest->pvData, pRequest->cbData);
 
@@ -1462 +1464 @@
             if (RT_SUCCESS(rc) && cbWritten)
             {
-                VBoxServiceVerbose(4, "ControlExec: [PID %u]: Waiting for response on enmType=%u, pvData=0x%p, cbData=%u\n",
+                VBoxServiceVerbose(4, "ControlThead: [PID %u]: Waiting for response on enmType=%u, pvData=0x%p, cbData=%u\n",
                                    uPID, pRequest->enmType, pRequest->pvData, pRequest->cbData);
                 /* Wait on the request to get completed (or we are asked to abort/shutdown). */
@@ -1468 +1470 @@
                 if (RT_SUCCESS(rc))
                 {
-                    VBoxServiceVerbose(4, "ControlExec: [PID %u]: Performed with rc=%Rrc, cbData=%u\n",
+                    VBoxServiceVerbose(4, "ControlThead: [PID %u]: Performed with rc=%Rrc, cbData=%u\n",
                                        uPID, pRequest->rc, pRequest->cbData);
 
@@ -1480 +1482 @@
                         rc2 = RTSemEventMultiReset(pThread->RequestEvent);
                         if (RT_FAILURE(rc2))
-                            VBoxServiceError("ControlExec: Unable to reset request event, rc=%Rrc\n", rc2);
+                            VBoxServiceError("ControlThead: Unable to reset request event, rc=%Rrc\n", rc2);
 
                         rc2 = RTCritSectLeave(&pThread->CritSect);
@@ -1492 +1494 @@
         rc = VERR_NOT_FOUND;
 
-    VBoxServiceVerbose(4, "ControlExec: Performed PID=%u, enmType=%u, pvData=0x%p, cbData=%u with rc=%Rrc\n",
+    VBoxServiceVerbose(4, "ControlThead: Performed PID=%u, enmType=%u, pvData=0x%p, cbData=%u with rc=%Rrc\n",
                        uPID, pRequest->enmType, pRequest->pvData, pRequest->cbData, rc);
     return rc;
@@ -1511 +1513 @@
     if (RT_SUCCESS(rc))
     {
-        VBoxServiceVerbose(3, "ControlExec: [PID %u]: Shutting down ...\n",
+        VBoxServiceVerbose(3, "ControlThead: [PID %u]: Shutting down ...\n",
                            pThread->uPID);