Changeset 50803 in vbox for trunk/src

Timestamp:

Mar 17, 2014 2:46:34 PM (11 years ago)

Author:

vboxsync

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

92834

Message:

VBoxGuest.cpp: Logging.

File:

• trunk/src/VBox/Additions/common/VBoxGuest/VBoxGuest.cpp (modified) (64 diffs)

trunk/src/VBox/Additions/common/VBoxGuest/VBoxGuest.cpp

@@ -5 +5 @@
 
 /*
- * Copyright (C) 2007-2013 Oracle Corporation
+ * Copyright (C) 2007-2014 Oracle Corporation
  *
  * This file is part of VirtualBox Open Source Edition (OSE), as
@@ -360 +360 @@
      */
     if (pReq->hypervisorSize == 0)
-        Log(("vboxGuestInitFixateGuestMappings: nothing to do\n"));
+        LogFlowFunc(("Nothing to do\n"));
     else
     {
@@ -372 +372 @@
         uint32_t    iTry;
         bool        fBitched = false;
-        Log(("vboxGuestInitFixateGuestMappings: cbHypervisor=%#x\n", cbHypervisor));
+        LogFlowFunc(("cbHypervisor=%#x\n", cbHypervisor));
         for (iTry = 0; iTry < RT_ELEMENTS(ahTries); iTry++)
         {
@@ -699 +699 @@
         rc = VBoxGuestReportDriverStatus(true /* Driver is active */);
         if (RT_FAILURE(rc))
-            Log(("VBoxGuest::VBoxGuestReinitDevExtAfterHibernation: could not report guest driver status, rc=%Rrc\n", rc));
+            LogFlowFunc(("Could not report guest driver status, rc=%Rrc\n", rc));
     }
     else
-        Log(("VBoxGuest::VBoxGuestReinitDevExtAfterHibernation: could not report guest information to host, rc=%Rrc\n", rc));
-    Log(("VBoxGuest::VBoxGuestReinitDevExtAfterHibernation: returned with rc=%Rrc\n", rc));
+        LogFlowFunc(("Could not report guest information to host, rc=%Rrc\n", rc));
+
+    LogFlowFunc(("Returned with rc=%Rrc\n", rc));
     return rc;
 }
@@ -806 +807 @@
             else
             {
-                Log(("vboxGuestSetBalloonSize(inflate): failed, rc=%Rrc!\n", rc));
+                LogFlowFunc(("Inflating failed, rc=%Rrc\n", rc));
                 RTR0MemObjFree(*pMemObj, true);
                 *pMemObj = NIL_RTR0MEMOBJ;
@@ -818 +819 @@
             pDevExt->MemBalloon.cChunks--;
         else
-            Log(("vboxGuestSetBalloonSize(deflate): failed, rc=%Rrc!\n", rc));
+            LogFlowFunc(("Deflating failed, rc=%Rrc\n", rc));
     }
 
@@ -853 +854 @@
                     if (RT_FAILURE(rc))
                     {
-                        LogRel(("vboxGuestCloseMemBalloon: Deflate failed with rc=%Rrc.  Will leak %u chunks.\n",
-                                rc, pDevExt->MemBalloon.cChunks));
+                        LogRelFunc(("Deflating balloon failed with rc=%Rrc; will leak %u chunks\n",
+                                    rc, pDevExt->MemBalloon.cChunks));
                         break;
                     }
@@ -863 +864 @@
             }
             else
-                LogRel(("vboxGuestCloseMemBalloon: Failed to allocate VMMDev request buffer (rc=%Rrc).  Will leak %u chunks.\n",
-                        rc, pDevExt->MemBalloon.cChunks));
+                LogRelFunc(("Failed to allocate VMMDev request buffer, rc=%Rrc; will leak %u chunks\n",
+                            rc, pDevExt->MemBalloon.cChunks));
             RTMemFree(pDevExt->MemBalloon.paMemObj);
             pDevExt->MemBalloon.paMemObj = NULL;
@@ -971 +972 @@
         {
             pDevExt->pVMMDevMemory = pVMMDev;
-            Log(("VBoxGuestInitDevExt: VMMDevMemory: mapping=%p size=%#RX32 (%#RX32) version=%#RX32\n",
-                 pVMMDev, pVMMDev->u32Size, cbMMIO, pVMMDev->u32Version));
+            LogFlowFunc(("VMMDevMemory: mapping=%p size=%#RX32 (%#RX32), version=%#RX32\n",
+                         pVMMDev, pVMMDev->u32Size, cbMMIO, pVMMDev->u32Version));
         }
         else /* try live without it. */
-            LogRel(("VBoxGuestInitDevExt: Bogus VMMDev memory; u32Version=%RX32 (expected %RX32) u32Size=%RX32 (expected <= %RX32)\n",
-                    pVMMDev->u32Version, VMMDEV_MEMORY_VERSION, pVMMDev->u32Size, cbMMIO));
+            LogRelFunc(("Bogus VMMDev memory; u32Version=%RX32 (expected %RX32), u32Size=%RX32 (expected <= %RX32)\n",
+                        pVMMDev->u32Version, VMMDEV_MEMORY_VERSION, pVMMDev->u32Size, cbMMIO));
     }
 
@@ -991 +992 @@
     if (RT_FAILURE(rc))
     {
-        LogRel(("VBoxGuestInitDevExt: failed to create spinlock, rc=%Rrc!\n", rc));
+        LogRelFunc(("Failed to create spinlock, rc=%Rrc\n", rc));
         if (pDevExt->EventSpinlock != NIL_RTSPINLOCK)
             RTSpinlockDestroy(pDevExt->EventSpinlock);
@@ -1000 +1001 @@
     if (RT_FAILURE(rc))
     {
-        LogRel(("VBoxGuestInitDevExt: failed to create mutex, rc=%Rrc!\n", rc));
+        LogRelFunc(("Failed to create mutex, rc=%Rrc\n", rc));
         RTSpinlockDestroy(pDevExt->SessionSpinlock);
         RTSpinlockDestroy(pDevExt->EventSpinlock);
@@ -1035 +1036 @@
                     rc = VBoxGuestReportDriverStatus(true /* Driver is active */);
                     if (RT_FAILURE(rc))
-                        LogRel(("VBoxGuestInitDevExt: VBoxReportGuestDriverStatus failed, rc=%Rrc\n", rc));
-
-                    Log(("VBoxGuestInitDevExt: returns success\n"));
+                        LogRelFunc(("VBoxReportGuestDriverStatus failed, rc=%Rrc\n", rc));
+
+                    LogFlowFunc(("VBoxGuestInitDevExt: returns success\n"));
                     return VINF_SUCCESS;
                 }
                 else
-                    LogRelFunc(("failed to set host flags, rc=%Rrc\n", rc));
+                    LogRelFunc(("Failed to set host flags, rc=%Rrc\n", rc));
             }
             else
-                LogRel(("VBoxGuestInitDevExt: VBoxReportGuestInfo failed, rc=%Rrc\n", rc));
+                LogRelFunc(("VBoxGuestInitDevExt: VBoxReportGuestInfo failed, rc=%Rrc\n", rc));
             VbglGRFree((VMMDevRequestHeader *)pDevExt->pIrqAckEvents);
         }
         else
-            LogRel(("VBoxGuestInitDevExt: VBoxGRAlloc failed, rc=%Rrc\n", rc));
+            LogRelFunc(("VBoxGRAlloc failed, rc=%Rrc\n", rc));
 
         VbglTerminate();
     }
     else
-        LogRel(("VBoxGuestInitDevExt: VbglInit failed, rc=%Rrc\n", rc));
+        LogRelFunc(("VbglInit failed, rc=%Rrc\n", rc));
 
     rc2 = RTSemFastMutexDestroy(pDevExt->MemBalloon.hMtx); AssertRC(rc2);
@@ -1207 +1208 @@
 
     *ppSession = pSession;
-    LogFlow(("VBoxGuestCreateKernelSession: pSession=%p proc=%RTproc (%d) r0proc=%p\n",
-             pSession, pSession->Process, (int)pSession->Process, (uintptr_t)pSession->R0Process)); /** @todo %RTr0proc */
+    LogFlowFunc(("pSession=%p proc=%RTproc (%d) r0proc=%p\n",
+                 pSession, pSession->Process, (int)pSession->Process, (uintptr_t)pSession->R0Process)); /** @todo %RTr0proc */
     return VINF_SUCCESS;
 }
@@ -1292 +1293 @@
         {
             if (s_cErrors++ < 32)
-                LogRel(("VBoxGuestWaitAlloc: out-of-memory!\n"));
+                LogRelFunc(("Out of memory, returning NULL\n"));
             return NULL;
         }
@@ -1300 +1301 @@
         {
             if (s_cErrors++ < 32)
-                LogRel(("VBoxGuestCommonIOCtl: RTSemEventMultiCreate failed with rc=%Rrc!\n", rc));
+                LogRelFunc(("RTSemEventMultiCreate failed with rc=%Rrc\n", rc));
             RTMemFree(pWait);
             return NULL;
@@ -1430 +1431 @@
     if (RT_FAILURE(rc))
     {
-        Log(("VBoxGuestSetGuestCapabilities: failed to allocate %u (%#x) bytes to cache the request. rc=%Rrc!!\n",
-             sizeof(*pReq), sizeof(*pReq), rc));
+        LogFlowFunc(("Failed to allocate %u (%#x) bytes to cache the request; rc=%Rrc\n",
+                     sizeof(*pReq), sizeof(*pReq), rc));
         return rc;
     }
@@ -1440 +1441 @@
     rc = VbglGRPerform(&pReq->header);
     if (RT_FAILURE(rc))
-        Log(("VBoxGuestSetGuestCapabilities: VbglGRPerform failed, rc=%Rrc!\n", rc));
+        LogFlowFunc(("VbglGRPerform failed, rc=%Rrc\n", rc));
 
     VbglGRFree(&pReq->header);
@@ -1459 +1460 @@
 int  VBoxGuestCommonIOCtlFast(unsigned iFunction, PVBOXGUESTDEVEXT pDevExt, PVBOXGUESTSESSION pSession)
 {
-    Log(("VBoxGuestCommonIOCtlFast: iFunction=%#x pDevExt=%p pSession=%p\n", iFunction, pDevExt, pSession));
+    LogFlowFunc(("iFunction=%#x pDevExt=%p pSession=%p\n", iFunction, pDevExt, pSession));
 
     NOREF(iFunction);
@@ -1478 +1479 @@
 static int VBoxGuestCommonIOCtl_GetVMMDevPort(PVBOXGUESTDEVEXT pDevExt, VBoxGuestPortInfo *pInfo, size_t *pcbDataReturned)
 {
-    Log(("VBoxGuestCommonIOCtl: GETVMMDEVPORT\n"));
+    LogFlowFuncEnter();
+
     pInfo->portAddress = pDevExt->IOPortBase;
     pInfo->pVMMDevMemory = (VMMDevMemory *)pDevExt->pVMMDevMemory;
@@ -1497 +1499 @@
 int VBoxGuestCommonIOCtl_SetMouseNotifyCallback(PVBOXGUESTDEVEXT pDevExt, VBoxGuestMouseSetNotifyCallback *pNotify)
 {
-    Log(("VBoxGuestCommonIOCtl: SET_MOUSE_NOTIFY_CALLBACK\n"));
+    LogFlowFuncEnter();
 
     RTSpinlockAcquire(pDevExt->EventSpinlock);
@@ -1525 +1527 @@
         pInfo->u32Result = VBOXGUEST_WAITEVENT_OK;
         if (fReqEvents & ~((uint32_t)1 << iEvent))
-            Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x\n", pInfo->u32EventFlagsOut));
+            LogFlowFunc(("WAITEVENT: returns %#x\n", pInfo->u32EventFlagsOut));
         else
-            Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
+            LogFlowFunc(("WAITEVENT: returns %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
         pSession->fPendingCancelWaitEvents = false;
         return VINF_SUCCESS;
     }
+
     RTSpinlockReleaseNoInts(pDevExt->EventSpinlock);
     return VERR_TIMEOUT;
@@ -1556 +1559 @@
     if (RT_UNLIKELY(iEvent < 0))
     {
-        LogRel(("VBoxGuestCommonIOCtl: WAITEVENT: Invalid input mask %#x!!\n", fReqEvents));
+        LogRel(("Invalid input mask %#x\n", fReqEvents));
         return VERR_INVALID_PARAMETER;
     }
@@ -1571 +1574 @@
     {
         pInfo->u32Result = VBOXGUEST_WAITEVENT_TIMEOUT;
-        Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns VERR_TIMEOUT\n"));
+        LogFlowFunc(("Returning VERR_TIMEOUT\n"));
         return VERR_TIMEOUT;
     }
@@ -1626 +1629 @@
         pInfo->u32Result = VBOXGUEST_WAITEVENT_OK;
         if (fReqEvents & ~((uint32_t)1 << iEvent))
-            Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x\n", pInfo->u32EventFlagsOut));
+            LogFlowFunc(("Returning %#x\n", pInfo->u32EventFlagsOut));
         else
-            Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
+            LogFlowFunc(("Returning %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
         rc = VINF_SUCCESS;
     }
@@ -1636 +1639 @@
         pInfo->u32Result = VBOXGUEST_WAITEVENT_INTERRUPTED;
         rc = VERR_INTERRUPTED;
-        Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns VERR_INTERRUPTED\n"));
+        LogFlowFunc(("Returning VERR_INTERRUPTED\n"));
     }
     else if (rc == VERR_TIMEOUT)
     {
         pInfo->u32Result = VBOXGUEST_WAITEVENT_TIMEOUT;
-        Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns VERR_TIMEOUT (2)\n"));
+        LogFlowFunc(("Returning VERR_TIMEOUT (2)\n"));
     }
     else
@@ -1649 +1652 @@
             static unsigned s_cErrors = 0;
             if (s_cErrors++ < 32)
-                LogRel(("VBoxGuestCommonIOCtl: WAITEVENT: returns %Rrc but no events!\n", rc));
+                LogRelFunc(("Returning %Rrc but no events\n", rc));
             rc = VERR_INTERNAL_ERROR;
         }
         pInfo->u32Result = VBOXGUEST_WAITEVENT_ERROR;
-        Log(("VBoxGuestCommonIOCtl: WAITEVENT: returns %Rrc\n", rc));
+        LogFlowFunc(("Returning %Rrc\n", rc));
     }
 
@@ -1671 +1674 @@
     bool                    fCancelledOne = false;
 
-    Log(("VBoxGuestCommonIOCtl: CANCEL_ALL_WAITEVENTS\n"));
+    LogFlowFunc(("CANCEL_ALL_WAITEVENTS\n"));
 
     /*
@@ -1891 +1894 @@
     const uint32_t          cbMinSize = vmmdevGetRequestSize(enmType);
 
-    Log(("VBoxGuestCommonIOCtl: VMMREQUEST type %d\n", pReqHdr->requestType));
+    LogFlowFunc(("Type=%d\n", pReqHdr->requestType));
 
     if (cbReq < cbMinSize)
     {
-        LogRel(("VBoxGuestCommonIOCtl: VMMREQUEST: invalid hdr size %#x, expected >= %#x; type=%#x!!\n",
-             cbReq, cbMinSize, enmType));
+        LogRelFunc(("Invalid hdr size %#x, expected >= %#x; type=%#x!!\n",
+                    cbReq, cbMinSize, enmType));
         return VERR_INVALID_PARAMETER;
     }
     if (cbReq > cbData)
     {
-        LogRel(("VBoxGuestCommonIOCtl: VMMREQUEST: invalid size %#x, expected >= %#x (hdr); type=%#x!!\n",
-             cbData, cbReq, enmType));
+        LogRelFunc(("Invalid size %#x, expected >= %#x (hdr); type=%#x!!\n",
+                    cbData, cbReq, enmType));
         return VERR_INVALID_PARAMETER;
     }
@@ -1908 +1911 @@
     if (RT_FAILURE(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: invalid header: size %#x, expected >= %#x (hdr); type=%#x; rc=%Rrc!!\n",
-             cbData, cbReq, enmType, rc));
+        LogFlowFunc(("Invalid header: size %#x, expected >= %#x (hdr); type=%#x; rc=%Rrc\n",
+                     cbData, cbReq, enmType, rc));
         return rc;
     }
@@ -1916 +1919 @@
     if (RT_FAILURE(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: Operation not allowed! type=%#x rc=%Rrc\n", enmType, rc));
+        LogFlowFunc(("Operation not allowed! type=%#x, rc=%Rrc\n", enmType, rc));
         return rc;
     }
@@ -1930 +1933 @@
     if (RT_FAILURE(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: failed to allocate %u (%#x) bytes to cache the request. rc=%Rrc!!\n",
-             cbReq, cbReq, rc));
+        LogFlowFunc(("Failed to allocate %u (%#x) bytes to cache the request; rc=%Rrc\n",
+                     cbReq, cbReq, rc));
         return rc;
     }
@@ -1951 +1954 @@
     }
     else if (RT_FAILURE(rc))
-        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: VbglGRPerform - rc=%Rrc!\n", rc));
+        LogFlowFunc(("VbglGRPerform failed; rc=%Rrc\n", rc));
     else
     {
-        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: request execution failed; VMMDev rc=%Rrc!\n", pReqCopy->rc));
+        LogFlowFunc(("Request execution failed; VMMDev rc=%Rrc\n",
+                     pReqCopy->rc));
         rc = pReqCopy->rc;
     }
@@ -2093 +2097 @@
         &&  (    !fInterruptible
              ||  rc != VERR_INTERRUPTED))
-        LogRel(("VBoxGuestHGCMAsyncWaitCallback: wait failed! %Rrc\n", rc));
+        LogRelFlow(("wait failed! %Rrc\n", rc));
 
     VBoxGuestWaitFreeUnlocked(pDevExt, pWait);
@@ -2108 +2112 @@
 {
     PVBOXGUESTDEVEXT pDevExt = (PVBOXGUESTDEVEXT)pvUser;
-    Log(("VBoxGuestHGCMAsyncWaitCallback: requestType=%d\n", pHdr->header.requestType));
+    LogFlowFunc(("requestType=%d\n", pHdr->header.requestType));
     return VBoxGuestHGCMAsyncWaitCallbackWorker((VMMDevHGCMRequestHeader volatile *)pHdr,
                                                 pDevExt,
@@ -2125 +2129 @@
 {
     PVBOXGUESTDEVEXT pDevExt = (PVBOXGUESTDEVEXT)pvUser;
-    Log(("VBoxGuestHGCMAsyncWaitCallbackInterruptible: requestType=%d\n", pHdr->header.requestType));
+    LogFlowFunc(("requestType=%d\n", pHdr->header.requestType));
     return VBoxGuestHGCMAsyncWaitCallbackWorker((VMMDevHGCMRequestHeader volatile *)pHdr,
                                                 pDevExt,
@@ -2144 +2148 @@
      * to deal with cancelled requests.
      */
-    Log(("VBoxGuestCommonIOCtl: HGCM_CONNECT: %.128s\n",
-         pInfo->Loc.type == VMMDevHGCMLoc_LocalHost || pInfo->Loc.type == VMMDevHGCMLoc_LocalHost_Existing
-         ? pInfo->Loc.u.host.achName : "<not local host>"));
+    LogFlowFunc(("%.128s\n",
+                   pInfo->Loc.type == VMMDevHGCMLoc_LocalHost || pInfo->Loc.type == VMMDevHGCMLoc_LocalHost_Existing
+                 ? pInfo->Loc.u.host.achName : "<not local host>"));
 
     rc = VbglR0HGCMInternalConnect(pInfo, VBoxGuestHGCMAsyncWaitCallback, pDevExt, RT_INDEFINITE_WAIT);
     if (RT_SUCCESS(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: HGCM_CONNECT: u32Client=%RX32 result=%Rrc (rc=%Rrc)\n",
-             pInfo->u32ClientID, pInfo->result, rc));
+        LogFlowFunc(("u32Client=%RX32 result=%Rrc (rc=%Rrc)\n",
+                     pInfo->u32ClientID, pInfo->result, rc));
         if (RT_SUCCESS(pInfo->result))
         {
@@ -2174 +2178 @@
 
                 if (s_cErrors++ < 32)
-                    LogRel(("VBoxGuestCommonIOCtl: HGCM_CONNECT: too many HGCMConnect calls for one session!\n"));
+                    LogRelFunc(("Too many HGCMConnect calls for one session\n"));
 
                 Info.result = 0;
@@ -2210 +2214 @@
         static unsigned s_cErrors = 0;
         if (s_cErrors++ > 32)
-            LogRel(("VBoxGuestCommonIOCtl: HGCM_DISCONNECT: u32Client=%RX32\n", u32ClientId));
+            LogRelFunc(("u32Client=%RX32\n", u32ClientId));
         return VERR_INVALID_HANDLE;
     }
@@ -2219 +2223 @@
      * to deal with cancelled requests.
      */
-    Log(("VBoxGuestCommonIOCtl: HGCM_DISCONNECT: u32Client=%RX32\n", pInfo->u32ClientID));
+    LogFlowFunc(("u32Client=%RX32\n", pInfo->u32ClientID));
     rc = VbglR0HGCMInternalDisconnect(pInfo, VBoxGuestHGCMAsyncWaitCallback, pDevExt, RT_INDEFINITE_WAIT);
     if (RT_SUCCESS(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: HGCM_DISCONNECT: result=%Rrc\n", pInfo->result));
+        LogFlowFunc(("Disconnected with rc=%Rrc\n", pInfo->result)); /** int32_t vs. int! */
         if (pcbDataReturned)
             *pcbDataReturned = sizeof(*pInfo);
@@ -2255 +2259 @@
     if (pInfo->cParms > 4096) /* (Just make sure it doesn't overflow the next check.) */
     {
-        LogRel(("VBoxGuestCommonIOCtl: HGCM_CALL: cParm=%RX32 is not sane\n", pInfo->cParms));
+        LogRelFunc(("cParm=%RX32 is not sane\n", pInfo->cParms));
         return VERR_INVALID_PARAMETER;
     }
@@ -2268 +2272 @@
     if (cbData < cbActual)
     {
-        LogRel(("VBoxGuestCommonIOCtl: HGCM_CALL: cbData=%#zx (%zu) required size is %#zx (%zu)\n",
-               cbData, cbData, cbActual, cbActual));
+        LogRelFunc(("cbData=%#zx (%zu) required size is %#zx (%zu)\n",
+                    cbData, cbData, cbActual, cbActual));
         return VERR_INVALID_PARAMETER;
     }
@@ -2285 +2289 @@
         static unsigned s_cErrors = 0;
         if (s_cErrors++ > 32)
-            LogRel(("VBoxGuestCommonIOCtl: HGCM_CALL: Invalid handle. u32Client=%RX32\n", u32ClientId));
+            LogRelFunc(("Invalid handle; u32Client=%RX32\n", u32ClientId));
         return VERR_INVALID_HANDLE;
     }
@@ -2295 +2299 @@
      * be interruptible (should add a flag for this later I guess).
      */
-    Log(("VBoxGuestCommonIOCtl: HGCM_CALL: u32Client=%RX32\n", pInfo->u32ClientID));
+    LogFlowFunc(("u32Client=%RX32\n", pInfo->u32ClientID));
     fFlags = !fUserData && pSession->R0Process == NIL_RTR0PROCESS ? VBGLR0_HGCMCALL_F_KERNEL : VBGLR0_HGCMCALL_F_USER;
 #ifdef RT_ARCH_AMD64
@@ -2315 +2319 @@
     if (RT_SUCCESS(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: HGCM_CALL: result=%Rrc\n", pInfo->result));
+        LogFlowFunc(("Result rc=%Rrc\n", pInfo->result)); /** int32_t vs. int! */
         if (pcbDataReturned)
             *pcbDataReturned = cbActual;
@@ -2326 +2330 @@
             static unsigned s_cErrors = 0;
             if (s_cErrors++ < 32)
-                LogRel(("VBoxGuestCommonIOCtl: HGCM_CALL: %s Failed. rc=%Rrc.\n", f32bit ? "32" : "64", rc));
+                LogRelFunc(("%s-bit call failed; rc=%Rrc\n",
+                            f32bit ? "32" : "64", rc));
         }
         else
-            Log(("VBoxGuestCommonIOCtl: HGCM_CALL: %s Failed. rc=%Rrc.\n", f32bit ? "32" : "64", rc));
+            LogFlowFunc(("%s-bit call failed; rc=%Rrc\n",
+                         f32bit ? "32" : "64", rc));
     }
     return rc;
 }
-
-
 #endif /* VBOX_WITH_HGCM */
+
 
 /**
@@ -2355 +2360 @@
                                                    VBoxGuestCheckBalloonInfo *pInfo, size_t *pcbDataReturned)
 {
-    VMMDevGetMemBalloonChangeRequest *pReq;
-    int rc;
-
-    Log(("VBoxGuestCommonIOCtl: CHECK_MEMORY_BALLOON\n"));
-    rc = RTSemFastMutexRequest(pDevExt->MemBalloon.hMtx);
+    LogFlowFuncEnter();
+
+    int rc = RTSemFastMutexRequest(pDevExt->MemBalloon.hMtx);
     AssertRCReturn(rc, rc);
 
@@ -2368 +2371 @@
     if (   pDevExt->MemBalloon.pOwner != pSession
         && pDevExt->MemBalloon.pOwner == NULL)
+    {
         pDevExt->MemBalloon.pOwner = pSession;
+    }
 
     if (pDevExt->MemBalloon.pOwner == pSession)
     {
-        rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(VMMDevGetMemBalloonChangeRequest), VMMDevReq_GetMemBalloonChangeRequest);
+        VMMDevGetMemBalloonChangeRequest *pReq;
+        rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(VMMDevGetMemBalloonChangeRequest),
+                         VMMDevReq_GetMemBalloonChangeRequest);
         if (RT_SUCCESS(rc))
         {
@@ -2401 +2408 @@
             }
             else
-                LogRel(("VBoxGuestCommonIOCtl: CHECK_MEMORY_BALLOON: VbglGRPerform failed. rc=%Rrc\n", rc));
+                LogRelFunc(("VbglGRPerform failed; rc=%Rrc\n", rc));
             VbglGRFree(&pReq->header);
         }
@@ -2409 +2416 @@
 
     RTSemFastMutexRelease(pDevExt->MemBalloon.hMtx);
-    Log(("VBoxGuestCommonIOCtl: CHECK_MEMORY_BALLOON returns %Rrc\n", rc));
+
+    LogFlowFunc(("Returns %Rrc\n", rc));
     return rc;
 }
@@ -2443 +2451 @@
         if (pDevExt->MemBalloon.pOwner == pSession)
         {
-            rc = vboxGuestSetBalloonSizeFromUser(pDevExt, pSession, pInfo->u64ChunkAddr, !!pInfo->fInflate);
+            rc = vboxGuestSetBalloonSizeFromUser(pDevExt, pSession, pInfo->u64ChunkAddr,
+                                                 !!pInfo->fInflate);
             if (pcbDataReturned)
                 *pcbDataReturned = 0;
@@ -2469 +2478 @@
 {
     VMMDevReqWriteCoreDump *pReq = NULL;
-    int rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(*pReq), VMMDevReq_WriteCoreDump);
+    int rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(VMMDevReqWriteCoreDump),
+                         VMMDevReq_WriteCoreDump);
     if (RT_FAILURE(rc))
     {
-        Log(("VBoxGuestCommonIOCtl: WRITE_CORE_DUMP: failed to allocate %u (%#x) bytes to cache the request. rc=%Rrc!!\n",
-             sizeof(*pReq), sizeof(*pReq), rc));
+        LogFlowFunc(("Failed to allocate %u (%#x) bytes to cache the request; rc=%Rrc\n",
+                     sizeof(VMMDevReqWriteCoreDump), sizeof(VMMDevReqWriteCoreDump), rc));
         return rc;
     }
@@ -2480 +2490 @@
     rc = VbglGRPerform(&pReq->header);
     if (RT_FAILURE(rc))
-        Log(("VBoxGuestCommonIOCtl: WRITE_CORE_DUMP: VbglGRPerform failed, rc=%Rrc!\n", rc));
+        LogFlowFunc(("VbglGRPerform failed, rc=%Rrc\n", rc));
 
     VbglGRFree(&pReq->header);
@@ -2609 +2619 @@
     if (!VBoxGuestCommonGuestCapsValidateValues(fOrMask))
     {
-        LogRel(("VBoxGuestCommonGuestCapsAcquire: pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid fOrMask\n",
-                pSession, fOrMask, fNotMask, enmFlags));
+        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid fOrMask\n",
+                    pSession, fOrMask, fNotMask, enmFlags));
         return VERR_INVALID_PARAMETER;
     }
@@ -2617 +2627 @@
         && enmFlags != VBOXGUESTCAPSACQUIRE_FLAGS_NONE)
     {
-        LogRel(("VBoxGuestCommonGuestCapsAcquire: pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid enmFlags %d\n",
-                pSession, fOrMask, fNotMask, enmFlags));
+        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid enmFlags %d\n",
+                    pSession, fOrMask, fNotMask, enmFlags));
         return VERR_INVALID_PARAMETER;
     }
@@ -2624 +2634 @@
     if (!VBoxGuestCommonGuestCapsModeSet(pDevExt, fOrMask, true, &fSetCaps))
     {
-        LogRel(("VBoxGuestCommonGuestCapsAcquire: pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- calling caps acquire for set caps\n",
-                pSession, fOrMask, fNotMask, enmFlags));
+        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- calling caps acquire for set caps\n",
+                    pSession, fOrMask, fNotMask, enmFlags));
         return VERR_INVALID_STATE;
     }
@@ -2631 +2641 @@
     if (enmFlags & VBOXGUESTCAPSACQUIRE_FLAGS_CONFIG_ACQUIRE_MODE)
     {
-        Log(("VBoxGuestCommonGuestCapsAcquire: pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- configured acquire caps: 0x%x\n",
-             pSession, fOrMask, fNotMask, enmFlags));
+        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- configured acquire caps: 0x%x\n",
+                    pSession, fOrMask, fNotMask, enmFlags));
         return VINF_SUCCESS;
     }
@@ -2672 +2682 @@
     if (fOtherConflictingCaps)
     {
-        Log(("VBoxGuest: Caps 0x%x were busy\n", fOtherConflictingCaps));
+        LogFlowFunc(("Caps 0x%x were busy\n", fOtherConflictingCaps));
         return VERR_RESOURCE_BUSY;
     }
@@ -2686 +2696 @@
     if (RT_FAILURE(rc))
     {
-        LogRel(("VBoxGuestCommonGuestCapsAcquire: VBoxGuestSetGuestCapabilities failed, rc=%Rrc\n", rc));
+        LogRelFunc(("VBoxGuestSetGuestCapabilities failed, rc=%Rrc\n", rc));
 
         /* Failure branch
@@ -2717 +2727 @@
     int rc = VBoxGuestCommonGuestCapsAcquire(pDevExt, pSession, pAcquire->u32OrMask, pAcquire->u32NotMask, pAcquire->enmFlags);
     if (RT_FAILURE(rc))
-        LogRel(("VBoxGuestCommonGuestCapsAcquire: failed rc=%Rrc\n", rc));
+        LogRelFunc(("Failed, rc=%Rrc\n", rc));
     pAcquire->rc = rc;
     return VINF_SUCCESS;
@@ -2742 +2752 @@
 {
     int rc;
-    Log(("VBoxGuestCommonIOCtl: iFunction=%#x pDevExt=%p pSession=%p pvData=%p cbData=%zu\n",
-         iFunction, pDevExt, pSession, pvData, cbData));
+    LogFlowFunc(("iFunction=%#x, pDevExt=%p, pSession=%p, pvData=%p, cbData=%zu\n",
+                 iFunction, pDevExt, pSession, pvData, cbData));
 
     /*
@@ -2963 +2973 @@
             default:
             {
-                LogRel(("VBoxGuestCommonIOCtl: Unknown request iFunction=%#x stripped size=%#x\n",
-                        iFunction, VBOXGUEST_IOCTL_STRIP_SIZE(iFunction)));
+                LogRelFunc(("Unknown request iFunction=%#x, stripped size=%#x\n",
+                            iFunction, VBOXGUEST_IOCTL_STRIP_SIZE(iFunction)));
                 rc = VERR_NOT_SUPPORTED;
                 break;
@@ -2971 +2981 @@
     }
 
-    Log(("VBoxGuestCommonIOCtl: returns %Rrc *pcbDataReturned=%zu\n", rc, pcbDataReturned ? *pcbDataReturned : 0));
+    LogFlowFunc(("Returning %Rrc *pcbDataReturned=%zu\n", rc, pcbDataReturned ? *pcbDataReturned : 0));
     return rc;
 }
@@ -3020 +3030 @@
             PVBOXGUESTWAIT  pSafe;
 
-            Log3(("VBoxGuestCommonISR: acknowledge events succeeded %#RX32\n", fEvents));
+            LogFlowFunc(("Acknowledge events succeeded: %#RX32\n", fEvents));
 
             /*
@@ -3086 +3096 @@
         }
         else /* something is serious wrong... */
-            Log(("VBoxGuestCommonISR: acknowledge events failed rc=%Rrc (events=%#x)!!\n",
-                 pReq->header.rc, pReq->events));
-    }
+            LogFlowFunc(("Acknowledging events failed, rc=%Rrc (events=%#x)\n",
+                         pReq->header.rc, pReq->events));
+    }
+#ifndef DEBUG_andy
     else
-        LogFlow(("VBoxGuestCommonISR: not ours\n"));
+        LogFlowFunc(("Not ours\n"));
+#endif
 
     RTSpinlockReleaseNoInts(pDevExt->EventSpinlock);