Changeset 54237 in vbox for trunk/src/VBox/Additions/common/VBoxGuest

Timestamp:

Feb 17, 2015 3:19:35 PM (10 years ago)

Author:

vboxsync

Message:

VBoxGuest.cpp: Partly back out of r92834 because everything shouldn't be LogFlow, nor LogFlowFunc.

File:

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

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

@@ -5 +5 @@
 
 /*
- * Copyright (C) 2007-2014 Oracle Corporation
+ * Copyright (C) 2007-2015 Oracle Corporation
  *
  * This file is part of VirtualBox Open Source Edition (OSE), as
@@ -361 +361 @@
      */
     if (pReq->hypervisorSize == 0)
-        LogFlowFunc(("Nothing to do\n"));
+        Log(("vboxGuestInitFixateGuestMappings: nothing to do\n"));
     else
     {
@@ -373 +373 @@
         uint32_t    iTry;
         bool        fBitched = false;
-        LogFlowFunc(("cbHypervisor=%#x\n", cbHypervisor));
+        Log(("vboxGuestInitFixateGuestMappings: cbHypervisor=%#x\n", cbHypervisor));
         for (iTry = 0; iTry < RT_ELEMENTS(ahTries); iTry++)
         {
@@ -765 +765 @@
         rc = VBoxGuestReportDriverStatus(true /* Driver is active */);
         if (RT_FAILURE(rc))
-            LogFlowFunc(("Could not report guest driver status, rc=%Rrc\n", rc));
+            Log(("VBoxGuestReinitDevExtAfterHibernation: could not report guest driver status, rc=%Rrc\n", rc));
     }
     else
-        LogFlowFunc(("Could not report guest information to host, rc=%Rrc\n", rc));
-
-    LogFlowFunc(("Returned with rc=%Rrc\n", rc));
+        Log(("VBoxGuestReinitDevExtAfterHibernation: could not report guest information to host, rc=%Rrc\n", rc));
+    LogFlow(("VBoxGuestReinitDevExtAfterHibernation: returned with rc=%Rrc\n", rc));
     return rc;
 }
@@ -873 +872 @@
             else
             {
-                LogFlowFunc(("Inflating failed, rc=%Rrc\n", rc));
+                Log(("vboxGuestSetBalloonSize(inflate): failed, rc=%Rrc!\n", rc));
                 RTR0MemObjFree(*pMemObj, true);
                 *pMemObj = NIL_RTR0MEMOBJ;
@@ -885 +884 @@
             pDevExt->MemBalloon.cChunks--;
         else
-            LogFlowFunc(("Deflating failed, rc=%Rrc\n", rc));
+            Log(("vboxGuestSetBalloonSize(deflate): failed, rc=%Rrc!\n", rc));
     }
 
@@ -920 +919 @@
                     if (RT_FAILURE(rc))
                     {
-                        LogRelFunc(("Deflating balloon failed with rc=%Rrc; will leak %u chunks\n",
-                                    rc, pDevExt->MemBalloon.cChunks));
+                        LogRel(("vboxGuestCloseMemBalloon: Deflate failed with rc=%Rrc.  Will leak %u chunks.\n",
+                                rc, pDevExt->MemBalloon.cChunks));
                         break;
                     }
@@ -930 +929 @@
             }
             else
-                LogRelFunc(("Failed to allocate VMMDev request buffer, rc=%Rrc; will leak %u chunks\n",
-                            rc, pDevExt->MemBalloon.cChunks));
+                LogRel(("vboxGuestCloseMemBalloon: 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;
@@ -1048 +1047 @@
         {
             pDevExt->pVMMDevMemory = pVMMDev;
-            LogFlowFunc(("VMMDevMemory: mapping=%p size=%#RX32 (%#RX32), version=%#RX32\n",
-                         pVMMDev, pVMMDev->u32Size, cbMMIO, pVMMDev->u32Version));
+            Log(("VBoxGuestInitDevExt: VMMDevMemory: mapping=%p size=%#RX32 (%#RX32) version=%#RX32\n",
+                 pVMMDev, pVMMDev->u32Size, cbMMIO, pVMMDev->u32Version));
         }
         else /* try live without it. */
-            LogRelFunc(("Bogus VMMDev memory; u32Version=%RX32 (expected %RX32), u32Size=%RX32 (expected <= %RX32)\n",
-                        pVMMDev->u32Version, VMMDEV_MEMORY_VERSION, pVMMDev->u32Size, cbMMIO));
+            LogRel(("VBoxGuestInitDevExt: Bogus VMMDev memory; u32Version=%RX32 (expected %RX32) u32Size=%RX32 (expected <= %RX32)\n",
+                    pVMMDev->u32Version, VMMDEV_MEMORY_VERSION, pVMMDev->u32Size, cbMMIO));
     }
 
@@ -1068 +1067 @@
     if (RT_FAILURE(rc))
     {
-        LogRelFunc(("Failed to create spinlock, rc=%Rrc\n", rc));
+        LogRel(("VBoxGuestInitDevExt: failed to create spinlock, rc=%Rrc!\n", rc));
         if (pDevExt->EventSpinlock != NIL_RTSPINLOCK)
             RTSpinlockDestroy(pDevExt->EventSpinlock);
@@ -1077 +1076 @@
     if (RT_FAILURE(rc))
     {
-        LogRelFunc(("Failed to create mutex, rc=%Rrc\n", rc));
+        LogRel(("VBoxGuestInitDevExt: failed to create mutex, rc=%Rrc!\n", rc));
         RTSpinlockDestroy(pDevExt->SessionSpinlock);
         RTSpinlockDestroy(pDevExt->EventSpinlock);
@@ -1112 +1111 @@
                     rc = VBoxGuestReportDriverStatus(true /* Driver is active */);
                     if (RT_FAILURE(rc))
-                        LogRelFunc(("VBoxReportGuestDriverStatus failed, rc=%Rrc\n", rc));
+                        LogRel(("VBoxGuestInitDevExt: VBoxReportGuestDriverStatus failed, rc=%Rrc\n", rc));
 
                     /** @todo Move heartbeat initialization into a separate function. */
@@ -1129 +1128 @@
                             rc = VbglGRAlloc(&pDevExt->pReqGuestHeartbeat, sizeof(*pDevExt->pReqGuestHeartbeat), VMMDevReq_GuestHeartbeat);
                             if (RT_FAILURE(rc))
-                                LogRelFunc(("VbglGRAlloc(VMMDevReq_GuestHeartbeat) %Rrc\n", rc));
+                                LogRel(("VBoxGuestInitDevExt: VbglGRAlloc(VMMDevReq_GuestHeartbeat) %Rrc\n", rc));
 
                             if (RT_SUCCESS(rc))
                             {
-                                LogFlowFunc(("Setting up heartbeat to trigger every %RU64 sec\n", pDevExt->cNsHeartbeatInterval / 1000000000));
+                                LogRel(("VBoxGuestInitDevExt: Setting up heartbeat to trigger every %RU64 sec\n",
+                                        pDevExt->cNsHeartbeatInterval / 1000000000));
                                 rc = RTTimerCreateEx(&pDevExt->pHeartbeatTimer, pDevExt->cNsHeartbeatInterval,
                                                      0, (PFNRTTIMER)VBoxGuestHeartbeatTimerHandler, pDevExt);
@@ -1142 +1142 @@
                                 rc = RTTimerStart(pDevExt->pHeartbeatTimer, 0);
                                 if (RT_FAILURE(rc))
-                                    LogRelFunc(("Heartbeat timer failed to start, rc=%Rrc\n", rc));
+                                    LogRel(("VBoxGuestInitDevExt: Heartbeat timer failed to start, rc=%Rrc\n", rc));
                             }
                             if (RT_FAILURE(rc))
                             {
-                                LogRelFunc(("Failed to set up the timer, guest heartbeat is disabled\n"));
+                                LogRel(("VBoxGuestInitDevExt: Failed to set up the timer, guest heartbeat is disabled\n"));
                                 /* Disable host heartbeat check if we failed */
                                 VBoxGuestHeartbeatHostConfigure(pDevExt, false);
@@ -1155 +1155 @@
                         }
                         else
-                            LogRelFunc(("Failed to configure host for heartbeat checking, rc=%Rrc\n", rc));
+                            LogRel(("VBoxGuestInitDevExt: Failed to configure host for heartbeat checking, rc=%Rrc\n", rc));
                     }
 
@@ -1161 +1161 @@
                     return VINF_SUCCESS;
                 }
-                else
-                    LogRelFunc(("Failed to set host flags, rc=%Rrc\n", rc));
+
+                LogRel(("VBoxGuestInitDevExt: failed to set host flags, rc=%Rrc\n", rc));
             }
             else
-                LogRelFunc(("VBoxGuestInitDevExt: VBoxReportGuestInfo failed, rc=%Rrc\n", rc));
+                LogRel(("VBoxGuestInitDevExt: VBoxReportGuestInfo failed, rc=%Rrc\n", rc));
             VbglGRFree((VMMDevRequestHeader *)pDevExt->pIrqAckEvents);
         }
         else
-            LogRelFunc(("VBoxGRAlloc failed, rc=%Rrc\n", rc));
+            LogRel(("VBoxGuestInitDevExt: VBoxGRAlloc failed, rc=%Rrc\n", rc));
 
         VbglTerminate();
     }
     else
-        LogRelFunc(("VbglInit failed, rc=%Rrc\n", rc));
+        LogRel(("VBoxGuestInitDevExt: VbglInit failed, rc=%Rrc\n", rc));
 
     rc2 = RTSemFastMutexDestroy(pDevExt->MemBalloon.hMtx); AssertRC(rc2);
@@ -1341 +1341 @@
 
     *ppSession = pSession;
-    LogFlowFunc(("pSession=%p proc=%RTproc (%d) r0proc=%p\n",
-                 pSession, pSession->Process, (int)pSession->Process, (uintptr_t)pSession->R0Process)); /** @todo %RTr0proc */
+    LogFlow(("VBoxGuestCreateKernelSession: pSession=%p proc=%RTproc (%d) r0proc=%p\n",
+             pSession, pSession->Process, (int)pSession->Process, (uintptr_t)pSession->R0Process)); /** @todo %RTr0proc */
     return VINF_SUCCESS;
 }
@@ -1419 +1419 @@
     if (!pWait)
     {
-        static unsigned s_cErrors = 0;
         int rc;
 
@@ -1425 +1424 @@
         if (!pWait)
         {
-            if (s_cErrors++ < 32)
-                LogRelFunc(("Out of memory, returning NULL\n"));
+            LogRelMax(32, ("VBoxGuestWaitAlloc: out-of-memory!\n"));
             return NULL;
         }
@@ -1433 +1431 @@
         if (RT_FAILURE(rc))
         {
-            if (s_cErrors++ < 32)
-                LogRelFunc(("RTSemEventMultiCreate failed with rc=%Rrc\n", rc));
+            LogRelMax(32, ("VBoxGuestCommonIOCtl: RTSemEventMultiCreate failed with rc=%Rrc!\n", rc));
             RTMemFree(pWait);
             return NULL;
@@ -1564 +1561 @@
     if (RT_FAILURE(rc))
     {
-        LogFlowFunc(("Failed to allocate %u (%#x) bytes to cache the request; rc=%Rrc\n",
-                     sizeof(*pReq), sizeof(*pReq), rc));
+        Log(("VBoxGuestSetGuestCapabilities: failed to allocate %u (%#x) bytes to cache the request. rc=%Rrc!!\n",
+             sizeof(*pReq), sizeof(*pReq), rc));
         return rc;
     }
@@ -1574 +1571 @@
     rc = VbglGRPerform(&pReq->header);
     if (RT_FAILURE(rc))
-        LogFlowFunc(("VbglGRPerform failed, rc=%Rrc\n", rc));
+        Log(("VBoxGuestSetGuestCapabilities: VbglGRPerform failed, rc=%Rrc!\n", rc));
 
     VbglGRFree(&pReq->header);
@@ -1593 +1590 @@
 int  VBoxGuestCommonIOCtlFast(unsigned iFunction, PVBOXGUESTDEVEXT pDevExt, PVBOXGUESTSESSION pSession)
 {
-    LogFlowFunc(("iFunction=%#x pDevExt=%p pSession=%p\n", iFunction, pDevExt, pSession));
+    LogFlow(("VBoxGuestCommonIOCtlFast: iFunction=%#x pDevExt=%p pSession=%p\n", iFunction, pDevExt, pSession));
 
     NOREF(iFunction);
@@ -1612 +1609 @@
 static int VBoxGuestCommonIOCtl_GetVMMDevPort(PVBOXGUESTDEVEXT pDevExt, VBoxGuestPortInfo *pInfo, size_t *pcbDataReturned)
 {
-    LogFlowFuncEnter();
+    LogFlow(("VBoxGuestCommonIOCtl: GETVMMDEVPORT\n"));
 
     pInfo->portAddress = pDevExt->IOPortBase;
@@ -1632 +1629 @@
 int VBoxGuestCommonIOCtl_SetMouseNotifyCallback(PVBOXGUESTDEVEXT pDevExt, VBoxGuestMouseSetNotifyCallback *pNotify)
 {
-    LogFlowFuncEnter();
+    LogFlow(("VBoxGuestCommonIOCtl: SET_MOUSE_NOTIFY_CALLBACK\n"));
 
     RTSpinlockAcquire(pDevExt->EventSpinlock);
@@ -1660 +1657 @@
         pInfo->u32Result = VBOXGUEST_WAITEVENT_OK;
         if (fReqEvents & ~((uint32_t)1 << iEvent))
-            LogFlowFunc(("WAITEVENT: returns %#x\n", pInfo->u32EventFlagsOut));
+            LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x\n", pInfo->u32EventFlagsOut));
         else
-            LogFlowFunc(("WAITEVENT: returns %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
+            LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
         pSession->fPendingCancelWaitEvents = false;
         return VINF_SUCCESS;
@@ -1692 +1689 @@
     if (RT_UNLIKELY(iEvent < 0))
     {
-        LogRel(("Invalid input mask %#x\n", fReqEvents));
+        LogRel(("VBoxGuestCommonIOCtl: WAITEVENT: Invalid input mask %#x!!\n", fReqEvents));
         return VERR_INVALID_PARAMETER;
     }
@@ -1707 +1704 @@
     {
         pInfo->u32Result = VBOXGUEST_WAITEVENT_TIMEOUT;
-        LogFlowFunc(("Returning VERR_TIMEOUT\n"));
+        LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns VERR_TIMEOUT\n"));
         return VERR_TIMEOUT;
     }
@@ -1762 +1759 @@
         pInfo->u32Result = VBOXGUEST_WAITEVENT_OK;
         if (fReqEvents & ~((uint32_t)1 << iEvent))
-            LogFlowFunc(("Returning %#x\n", pInfo->u32EventFlagsOut));
+            LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x\n", pInfo->u32EventFlagsOut));
         else
-            LogFlowFunc(("Returning %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
+            LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns %#x/%d\n", pInfo->u32EventFlagsOut, iEvent));
         rc = VINF_SUCCESS;
     }
@@ -1772 +1769 @@
         pInfo->u32Result = VBOXGUEST_WAITEVENT_INTERRUPTED;
         rc = VERR_INTERRUPTED;
-        LogFlowFunc(("Returning VERR_INTERRUPTED\n"));
+        LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns VERR_INTERRUPTED\n"));
     }
     else if (rc == VERR_TIMEOUT)
     {
         pInfo->u32Result = VBOXGUEST_WAITEVENT_TIMEOUT;
-        LogFlowFunc(("Returning VERR_TIMEOUT (2)\n"));
+        LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns VERR_TIMEOUT (2)\n"));
     }
     else
@@ -1783 +1780 @@
         if (RT_SUCCESS(rc))
         {
-            static unsigned s_cErrors = 0;
-            if (s_cErrors++ < 32)
-                LogRelFunc(("Returning %Rrc but no events\n", rc));
+            LogRelMax(32, ("VBoxGuestCommonIOCtl: WAITEVENT: returns %Rrc but no events!\n", rc));
             rc = VERR_INTERNAL_ERROR;
         }
         pInfo->u32Result = VBOXGUEST_WAITEVENT_ERROR;
-        LogFlowFunc(("Returning %Rrc\n", rc));
+        LogFlow(("VBoxGuestCommonIOCtl: WAITEVENT: returns %Rrc\n", rc));
     }
 
@@ -1807 +1802 @@
     bool                    fCancelledOne = false;
 
-    LogFlowFunc(("CANCEL_ALL_WAITEVENTS\n"));
+    LogFlow(("VBoxGuestCommonIOCtl: CANCEL_ALL_WAITEVENTS\n"));
 
     /*
@@ -1925 +1920 @@
             {
                 AssertFailed();
-                LogRel(("calling caps set for acquired caps %d\n", pCaps->u32OrMask));
+                LogRel(("VBoxDrv: calling caps set for acquired caps %d\n", pCaps->u32OrMask));
                 enmRequired = kLevel_NoOne;
                 break;
@@ -2027 +2022 @@
     const uint32_t          cbMinSize = (uint32_t)vmmdevGetRequestSize(enmType);
 
-    LogFlowFunc(("Type=%d\n", pReqHdr->requestType));
+    LogFlow(("VBoxGuestCommonIOCtl: VMMREQUEST type %d\n", pReqHdr->requestType));
 
     if (cbReq < cbMinSize)
     {
-        LogRelFunc(("Invalid hdr size %#x, expected >= %#x; type=%#x!!\n",
-                    cbReq, cbMinSize, enmType));
+        LogRel(("VBoxGuestCommonIOCtl: VMMREQUEST: invalid hdr size %#x, expected >= %#x; type=%#x!!\n",
+                cbReq, cbMinSize, enmType));
         return VERR_INVALID_PARAMETER;
     }
     if (cbReq > cbData)
     {
-        LogRelFunc(("Invalid size %#x, expected >= %#x (hdr); type=%#x!!\n",
-                    cbData, cbReq, enmType));
+        LogRel(("VBoxGuestCommonIOCtl: VMMREQUEST: invalid size %#x, expected >= %#x (hdr); type=%#x!!\n",
+                cbData, cbReq, enmType));
         return VERR_INVALID_PARAMETER;
     }
@@ -2044 +2039 @@
     if (RT_FAILURE(rc))
     {
-        LogFlowFunc(("Invalid header: size %#x, expected >= %#x (hdr); type=%#x; rc=%Rrc\n",
-                     cbData, cbReq, enmType, rc));
+        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: invalid header: size %#x, expected >= %#x (hdr); type=%#x; rc=%Rrc!!\n",
+             cbData, cbReq, enmType, rc));
         return rc;
     }
@@ -2052 +2047 @@
     if (RT_FAILURE(rc))
     {
-        LogFlowFunc(("Operation not allowed! type=%#x, rc=%Rrc\n", enmType, rc));
+        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: Operation not allowed! type=%#x rc=%Rrc\n", enmType, rc));
         return rc;
     }
@@ -2066 +2061 @@
     if (RT_FAILURE(rc))
     {
-        LogFlowFunc(("Failed to allocate %u (%#x) bytes to cache the request; rc=%Rrc\n",
-                     cbReq, cbReq, rc));
+        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: failed to allocate %u (%#x) bytes to cache the request. rc=%Rrc!!\n",
+             cbReq, cbReq, rc));
         return rc;
     }
@@ -2087 +2082 @@
     }
     else if (RT_FAILURE(rc))
-        LogFlowFunc(("VbglGRPerform failed; rc=%Rrc\n", rc));
+        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: VbglGRPerform - rc=%Rrc!\n", rc));
     else
     {
-        LogFlowFunc(("Request execution failed; VMMDev rc=%Rrc\n",
-                     pReqCopy->rc));
+        Log(("VBoxGuestCommonIOCtl: VMMREQUEST: request execution failed; VMMDev rc=%Rrc!\n", pReqCopy->rc));
         rc = pReqCopy->rc;
     }
@@ -2230 +2224 @@
         &&  (    !fInterruptible
              ||  rc != VERR_INTERRUPTED))
-        LogRelFlow(("wait failed! %Rrc\n", rc));
+        LogRel(("VBoxGuestHGCMAsyncWaitCallback: wait failed! %Rrc\n", rc));
 
     VBoxGuestWaitFreeUnlocked(pDevExt, pWait);
@@ -2245 +2239 @@
 {
     PVBOXGUESTDEVEXT pDevExt = (PVBOXGUESTDEVEXT)pvUser;
-    LogFlowFunc(("requestType=%d\n", pHdr->header.requestType));
+    LogFlow(("VBoxGuestHGCMAsyncWaitCallback: requestType=%d\n", pHdr->header.requestType));
     return VBoxGuestHGCMAsyncWaitCallbackWorker((VMMDevHGCMRequestHeader volatile *)pHdr,
                                                 pDevExt,
@@ -2262 +2256 @@
 {
     PVBOXGUESTDEVEXT pDevExt = (PVBOXGUESTDEVEXT)pvUser;
-    LogFlowFunc(("requestType=%d\n", pHdr->header.requestType));
+    LogFlow(("VBoxGuestHGCMAsyncWaitCallbackInterruptible: requestType=%d\n", pHdr->header.requestType));
     return VBoxGuestHGCMAsyncWaitCallbackWorker((VMMDevHGCMRequestHeader volatile *)pHdr,
                                                 pDevExt,
@@ -2281 +2275 @@
      * to deal with cancelled requests.
      */
-    LogFlowFunc(("%.128s\n",
-                   pInfo->Loc.type == VMMDevHGCMLoc_LocalHost || pInfo->Loc.type == VMMDevHGCMLoc_LocalHost_Existing
-                 ? pInfo->Loc.u.host.achName : "<not local host>"));
+    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>"));
 
     rc = VbglR0HGCMInternalConnect(pInfo, VBoxGuestHGCMAsyncWaitCallback, pDevExt, RT_INDEFINITE_WAIT);
     if (RT_SUCCESS(rc))
     {
-        LogFlowFunc(("u32Client=%RX32 result=%Rrc (rc=%Rrc)\n",
-                     pInfo->u32ClientID, pInfo->result, rc));
+        Log(("VBoxGuestCommonIOCtl: HGCM_CONNECT: u32Client=%RX32 result=%Rrc (rc=%Rrc)\n",
+             pInfo->u32ClientID, pInfo->result, rc));
         if (RT_SUCCESS(pInfo->result))
         {
@@ -2307 +2301 @@
             if (i >= RT_ELEMENTS(pSession->aHGCMClientIds))
             {
-                static unsigned             s_cErrors = 0;
                 VBoxGuestHGCMDisconnectInfo Info;
-
-                if (s_cErrors++ < 32)
-                    LogRelFunc(("Too many HGCMConnect calls for one session\n"));
-
+                LogRelMax(32, ("VBoxGuestCommonIOCtl: HGCM_CONNECT: too many HGCMConnect calls for one session!\n"));
                 Info.result = 0;
                 Info.u32ClientID = pInfo->u32ClientID;
@@ -2347 +2337 @@
     if (i >= RT_ELEMENTS(pSession->aHGCMClientIds))
     {
-        static unsigned s_cErrors = 0;
-        if (s_cErrors++ > 32)
-            LogRelFunc(("u32Client=%RX32\n", u32ClientId));
+        LogRelMax(32, ("VBoxGuestCommonIOCtl: HGCM_DISCONNECT: u32Client=%RX32\n", u32ClientId));
         return VERR_INVALID_HANDLE;
     }
@@ -2358 +2346 @@
      * to deal with cancelled requests.
      */
-    LogFlowFunc(("u32Client=%RX32\n", pInfo->u32ClientID));
+    Log(("VBoxGuestCommonIOCtl: HGCM_DISCONNECT: u32Client=%RX32\n", pInfo->u32ClientID));
     rc = VbglR0HGCMInternalDisconnect(pInfo, VBoxGuestHGCMAsyncWaitCallback, pDevExt, RT_INDEFINITE_WAIT);
     if (RT_SUCCESS(rc))
     {
-        LogFlowFunc(("Disconnected with rc=%Rrc\n", pInfo->result)); /** int32_t vs. int! */
+        LogFlow(("VBoxGuestCommonIOCtl: HGCM_DISCONNECT: result=%Rrc\n", pInfo->result));
         if (pcbDataReturned)
             *pcbDataReturned = sizeof(*pInfo);
@@ -2394 +2382 @@
     if (pInfo->cParms > 4096) /* (Just make sure it doesn't overflow the next check.) */
     {
-        LogRelFunc(("cParm=%RX32 is not sane\n", pInfo->cParms));
+        LogRel(("VBoxGuestCommonIOCtl: HGCM_CALL: cParm=%RX32 is not sane\n", pInfo->cParms));
         return VERR_INVALID_PARAMETER;
     }
@@ -2407 +2395 @@
     if (cbData < cbActual)
     {
-        LogRelFunc(("cbData=%#zx (%zu) required size is %#zx (%zu)\n",
-                    cbData, cbData, cbActual, cbActual));
+        LogRel(("VBoxGuestCommonIOCtl: HGCM_CALL: cbData=%#zx (%zu) required size is %#zx (%zu)\n",
+               cbData, cbData, cbActual, cbActual));
         return VERR_INVALID_PARAMETER;
     }
@@ -2422 +2410 @@
     if (RT_UNLIKELY(i >= RT_ELEMENTS(pSession->aHGCMClientIds)))
     {
-        static unsigned s_cErrors = 0;
-        if (s_cErrors++ > 32)
-            LogRelFunc(("Invalid handle; u32Client=%RX32\n", u32ClientId));
+        LogRelMax(32, ("VBoxGuestCommonIOCtl: HGCM_CALL: Invalid handle. u32Client=%RX32\n", u32ClientId));
         return VERR_INVALID_HANDLE;
     }
@@ -2434 +2420 @@
      * be interruptible (should add a flag for this later I guess).
      */
-    LogFlowFunc(("u32Client=%RX32\n", pInfo->u32ClientID));
+    LogFlow(("VBoxGuestCommonIOCtl: HGCM_CALL: u32Client=%RX32\n", pInfo->u32ClientID));
     fFlags = !fUserData && pSession->R0Process == NIL_RTR0PROCESS ? VBGLR0_HGCMCALL_F_KERNEL : VBGLR0_HGCMCALL_F_USER;
     uint32_t cbInfo = (uint32_t)(cbData - cbExtra);
@@ -2455 +2441 @@
     if (RT_SUCCESS(rc))
     {
-        LogFlowFunc(("Result rc=%Rrc\n", pInfo->result)); /** int32_t vs. int! */
+        LogFlow(("VBoxGuestCommonIOCtl: HGCM_CALL: result=%Rrc\n", pInfo->result));
         if (pcbDataReturned)
             *pcbDataReturned = cbActual;
@@ -2463 +2449 @@
         if (   rc != VERR_INTERRUPTED
             && rc != VERR_TIMEOUT)
-        {
-            static unsigned s_cErrors = 0;
-            if (s_cErrors++ < 32)
-                LogRelFunc(("%s-bit call failed; rc=%Rrc\n",
-                            f32bit ? "32" : "64", rc));
-        }
+            LogRelMax(32, ("VBoxGuestCommonIOCtl: HGCM_CALL: %s Failed. rc=%Rrc.\n", f32bit ? "32" : "64", rc));
         else
-            LogFlowFunc(("%s-bit call failed; rc=%Rrc\n",
-                         f32bit ? "32" : "64", rc));
+            Log(("VBoxGuestCommonIOCtl: HGCM_CALL: %s Failed. rc=%Rrc.\n", f32bit ? "32" : "64", rc));
     }
     return rc;
 }
+
 #endif /* VBOX_WITH_HGCM */
-
 
 /**
@@ -2496 +2476 @@
                                                    VBoxGuestCheckBalloonInfo *pInfo, size_t *pcbDataReturned)
 {
-    LogFlowFuncEnter();
-
-    int rc = RTSemFastMutexRequest(pDevExt->MemBalloon.hMtx);
+    VMMDevGetMemBalloonChangeRequest *pReq;
+    int rc;
+
+    LogFlow(("VBoxGuestCommonIOCtl: CHECK_MEMORY_BALLOON\n"));
+    rc = RTSemFastMutexRequest(pDevExt->MemBalloon.hMtx);
     AssertRCReturn(rc, rc);
 
@@ -2507 +2489 @@
     if (   pDevExt->MemBalloon.pOwner != pSession
         && pDevExt->MemBalloon.pOwner == NULL)
-    {
         pDevExt->MemBalloon.pOwner = pSession;
-    }
 
     if (pDevExt->MemBalloon.pOwner == pSession)
     {
-        VMMDevGetMemBalloonChangeRequest *pReq;
-        rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(VMMDevGetMemBalloonChangeRequest),
-                         VMMDevReq_GetMemBalloonChangeRequest);
+        rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(VMMDevGetMemBalloonChangeRequest), VMMDevReq_GetMemBalloonChangeRequest);
         if (RT_SUCCESS(rc))
         {
@@ -2544 +2522 @@
             }
             else
-                LogRelFunc(("VbglGRPerform failed; rc=%Rrc\n", rc));
+                LogRel(("VBoxGuestCommonIOCtl: CHECK_MEMORY_BALLOON: VbglGRPerform failed. rc=%Rrc\n", rc));
             VbglGRFree(&pReq->header);
         }
@@ -2552 +2530 @@
 
     RTSemFastMutexRelease(pDevExt->MemBalloon.hMtx);
-
-    LogFlowFunc(("Returns %Rrc\n", rc));
+    LogFlow(("VBoxGuestCommonIOCtl: CHECK_MEMORY_BALLOON returns %Rrc\n", rc));
     return rc;
 }
@@ -2572 +2549 @@
                                                     VBoxGuestChangeBalloonInfo *pInfo, size_t *pcbDataReturned)
 {
-    int rc = RTSemFastMutexRequest(pDevExt->MemBalloon.hMtx);
+    int rc;
+
+    LogFlow(("VBoxGuestCommonIOCtl: CHANGE_BALLOON\n"));
+    rc = RTSemFastMutexRequest(pDevExt->MemBalloon.hMtx);
     AssertRCReturn(rc, rc);
 
@@ -2587 +2567 @@
         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;
@@ -2614 +2593 @@
 {
     VMMDevReqWriteCoreDump *pReq = NULL;
-    int rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(VMMDevReqWriteCoreDump),
-                         VMMDevReq_WriteCoreDump);
+    int rc;
+
+    LogFlow(("VBoxGuestCommonIOCtl: WRITE_CORE_DUMP\n"));
+    rc = VbglGRAlloc((VMMDevRequestHeader **)&pReq, sizeof(*pReq), VMMDevReq_WriteCoreDump);
     if (RT_FAILURE(rc))
     {
-        LogFlowFunc(("Failed to allocate %u (%#x) bytes to cache the request; rc=%Rrc\n",
-                     sizeof(VMMDevReqWriteCoreDump), sizeof(VMMDevReqWriteCoreDump), rc));
+        Log(("VBoxGuestCommonIOCtl: WRITE_CORE_DUMP: failed to allocate %u (%#x) bytes to cache the request. rc=%Rrc!!\n",
+             sizeof(*pReq), sizeof(*pReq), rc));
         return rc;
     }
@@ -2626 +2607 @@
     rc = VbglGRPerform(&pReq->header);
     if (RT_FAILURE(rc))
-        LogFlowFunc(("VbglGRPerform failed, rc=%Rrc\n", rc));
+        Log(("VBoxGuestCommonIOCtl: WRITE_CORE_DUMP: VbglGRPerform failed, rc=%Rrc!\n", rc));
 
     VbglGRFree(&pReq->header);
@@ -2658 +2639 @@
 }
 
+
 static bool VBoxGuestCommonGuestCapsValidateValues(uint32_t fCaps)
 {
@@ -2665 +2647 @@
     return true;
 }
+
 
 /** Check whether any unreported VMM device events should be reported to any of
@@ -2725 +2708 @@
     if (!VBoxGuestCommonGuestCapsValidateValues(fOrMask))
     {
-        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid fOrMask\n",
-                    pSession, fOrMask, fNotMask, enmFlags));
+        LogRel(("VBoxGuestCommonGuestCapsAcquire: pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid fOrMask\n",
+                pSession, fOrMask, fNotMask, enmFlags));
         return VERR_INVALID_PARAMETER;
     }
@@ -2733 +2716 @@
         && enmFlags != VBOXGUESTCAPSACQUIRE_FLAGS_NONE)
     {
-        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid enmFlags %d\n",
-                    pSession, fOrMask, fNotMask, enmFlags));
+        LogRel(("VBoxGuestCommonGuestCapsAcquire: pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- invalid enmFlags %d\n",
+                pSession, fOrMask, fNotMask, enmFlags));
         return VERR_INVALID_PARAMETER;
     }
@@ -2740 +2723 @@
     if (!VBoxGuestCommonGuestCapsModeSet(pDevExt, fOrMask, true, &fSetCaps))
     {
-        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- calling caps acquire for set caps\n",
-                    pSession, fOrMask, fNotMask, enmFlags));
+        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));
         return VERR_INVALID_STATE;
     }
@@ -2747 +2730 @@
     if (enmFlags & VBOXGUESTCAPSACQUIRE_FLAGS_CONFIG_ACQUIRE_MODE)
     {
-        LogRelFunc(("pSession(0x%p), OR(0x%x), NOT(0x%x), flags(0x%x) -- configured acquire caps: 0x%x\n",
-                    pSession, fOrMask, fNotMask, enmFlags));
+        Log(("VBoxGuestCommonGuestCapsAcquire: 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;
     }
@@ -2788 +2771 @@
     if (fOtherConflictingCaps)
     {
-        LogFlowFunc(("Caps 0x%x were busy\n", fOtherConflictingCaps));
+        Log(("VBoxGuestCommonGuestCapsAcquire: Caps 0x%x were busy\n", fOtherConflictingCaps));
         return VERR_RESOURCE_BUSY;
     }
@@ -2802 +2785 @@
     if (RT_FAILURE(rc))
     {
-        LogRelFunc(("VBoxGuestSetGuestCapabilities failed, rc=%Rrc\n", rc));
+        LogRel(("VBoxGuestCommonGuestCapsAcquire: VBoxGuestSetGuestCapabilities failed, rc=%Rrc\n", rc));
 
         /* Failure branch
@@ -2829 +2812 @@
 }
 
+
 static int VBoxGuestCommonIOCTL_GuestCapsAcquire(PVBOXGUESTDEVEXT pDevExt, PVBOXGUESTSESSION pSession, VBoxGuestCapsAquire *pAcquire)
 {
     int rc = VBoxGuestCommonGuestCapsAcquire(pDevExt, pSession, pAcquire->u32OrMask, pAcquire->u32NotMask, pAcquire->enmFlags);
     if (RT_FAILURE(rc))
-        LogRelFunc(("Failed, rc=%Rrc\n", rc));
+        LogRel(("VBoxGuestCommonIOCtl: GUEST_CAPS_ACQUIRE failed rc=%Rrc\n", rc));
     pAcquire->rc = rc;
     return VINF_SUCCESS;
@@ -2858 +2842 @@
 {
     int rc;
-    LogFlowFunc(("iFunction=%#x, pDevExt=%p, pSession=%p, pvData=%p, cbData=%zu\n",
-                 iFunction, pDevExt, pSession, pvData, cbData));
+    LogFlow(("VBoxGuestCommonIOCtl: iFunction=%#x pDevExt=%p pSession=%p pvData=%p cbData=%zu\n",
+             iFunction, pDevExt, pSession, pvData, cbData));
 
     /*
@@ -3070 +3054 @@
             default:
             {
-                LogRelFunc(("Unknown request iFunction=%#x, stripped size=%#x\n",
-                            iFunction, VBOXGUEST_IOCTL_STRIP_SIZE(iFunction)));
+                LogRel(("VBoxGuestCommonIOCtl: Unknown request iFunction=%#x stripped size=%#x\n",
+                        iFunction, VBOXGUEST_IOCTL_STRIP_SIZE(iFunction)));
                 rc = VERR_NOT_SUPPORTED;
                 break;
@@ -3078 +3062 @@
     }
 
-    LogFlowFunc(("Returning %Rrc *pcbDataReturned=%zu\n", rc, pcbDataReturned ? *pcbDataReturned : 0));
+    LogFlow(("VBoxGuestCommonIOCtl: returns %Rrc *pcbDataReturned=%zu\n", rc, pcbDataReturned ? *pcbDataReturned : 0));
     return rc;
 }
@@ -3127 +3111 @@
             PVBOXGUESTWAIT  pSafe;
 
-#ifndef DEBUG_andy
-            LogFlowFunc(("Acknowledge events succeeded: %#RX32\n", fEvents));
-#endif
+            Log3(("VBoxGuestCommonISR: acknowledge events succeeded %#RX32\n", fEvents));
+
             /*
              * VMMDEV_EVENT_MOUSE_POSITION_CHANGED can only be polled for.
@@ -3139 +3122 @@
 #ifndef RT_OS_WINDOWS
                 if (pDevExt->MouseNotifyCallback.pfnNotify)
-                    pDevExt->MouseNotifyCallback.pfnNotify
-                                          (pDevExt->MouseNotifyCallback.pvUser);
+                    pDevExt->MouseNotifyCallback.pfnNotify(pDevExt->MouseNotifyCallback.pvUser);
 #endif
             }
@@ -3194 +3176 @@
         }
         else /* something is serious wrong... */
-            LogFlowFunc(("Acknowledging events failed, rc=%Rrc (events=%#x)\n",
-                         pReq->header.rc, pReq->events));
-    }
-#ifndef DEBUG_andy
+            Log(("VBoxGuestCommonISR: acknowledge events failed rc=%Rrc (events=%#x)!!\n",
+                 pReq->header.rc, pReq->events));
+    }
     else
-        LogFlowFunc(("Not ours\n"));
-#endif
+        Log3(("VBoxGuestCommonISR: not ours\n"));
 
     RTSpinlockRelease(pDevExt->EventSpinlock);