Changeset 38425 in vbox

Timestamp:

Aug 11, 2011 8:22:34 PM (13 years ago)

Author:

vboxsync

Message:

usb/win: better logging

Location:

trunk/src/VBox/HostDrivers/VBoxUSB/win/mon

Files:

• VBoxUsbFlt.cpp (modified) (17 diffs)
• VBoxUsbMon.cpp (modified) (1 diff)

trunk/src/VBox/HostDrivers/VBoxUSB/win/mon/VBoxUsbFlt.cpp

@@ -252 +252 @@
 static void vboxUsbFltDevOwnerSetLocked(PVBOXUSBFLT_DEVICE pDevice, PVBOXUSBFLTCTX pContext, uintptr_t uFltId, bool fIsOneShot)
 {
-    Assert(!pDevice->pOwner);
+    ASSERT_WARN(!pDevice->pOwner, ("device 0x%p has an owner(0x%p)", pDevice, pDevice->pOwner));
     ++pContext->cActiveFilters;
     pDevice->pOwner = pContext;
@@ -261 +261 @@
 static void vboxUsbFltDevOwnerClearLocked(PVBOXUSBFLT_DEVICE pDevice)
 {
-    Assert(pDevice->pOwner);
+    ASSERT_WARN(pDevice->pOwner, ("no owner for device 0x%p", pDevice));
     --pDevice->pOwner->cActiveFilters;
-    Assert(pDevice->pOwner->cActiveFilters < UINT32_MAX/2);
+    ASSERT_WARN(pDevice->pOwner->cActiveFilters < UINT32_MAX/2, ("cActiveFilters (%d)", pDevice->pOwner->cActiveFilters));
     pDevice->pOwner = NULL;
     pDevice->uFltId = 0;
@@ -905 +905 @@
                         }
                     }
+                    else
+                    {
+                        LOG(("driver name not match, was:"));
+                        LOG_USTR(&pHubDevObj->DriverObject->DriverName);
+                        LOG(("but expected:"));
+                        LOG_USTR(&szStandardControllerName[j]);
+                    }
                 }
             }
+            else
+            {
+                LOG(("null driver object (0x%p) or name buffer (0x%p), length(%d)", pHubDevObj->DriverObject,
+                        pHubDevObj->DriverObject ? pHubDevObj->DriverObject->DriverName.Buffer : NULL,
+                        pHubDevObj->DriverObject ? pHubDevObj->DriverObject->DriverName.Length : 0));
+            }
             ObDereferenceObject(pHubFileObj);
         }
@@ -918 +931 @@
 NTSTATUS VBoxUsbFltClose(PVBOXUSBFLTCTX pContext)
 {
+    LOG(("Closing context(0x%p)", pContext));
     LIST_ENTRY ReplugDevList;
     InitializeListHead(&ReplugDevList);
 
-    Assert(pContext);
+    ASSERT_WARN(pContext, ("null context"));
 
     KIRQL Irql = KeGetCurrentIrql();
-    Assert(Irql == PASSIVE_LEVEL);
+    ASSERT_WARN(Irql == PASSIVE_LEVEL, ("irql==(%d)", Irql));
 
     VBOXUSBFLT_LOCK_ACQUIRE();
@@ -931 +945 @@
     if (pContext->pChangeEvent)
     {
+        LOG(("seting & closing change event (0x%p)", pContext->pChangeEvent));
         KeSetEvent(pContext->pChangeEvent,
                 0, /* increment*/
@@ -937 +952 @@
         pContext->pChangeEvent = NULL;
     }
+    else
+    {
+        LOG(("no change event"));
+    }
     RemoveEntryList(&pContext->ListEntry);
 
+    LOG(("removing owner filters"));
     /* now re-arrange the filters */
     /* 1. remove filters */
     VBoxUSBFilterRemoveOwner(pContext);
 
+    LOG(("enumerating devices.."));
     /* 2. check if there are devices owned */
     for (PLIST_ENTRY pEntry = g_VBoxUsbFltGlobals.DeviceList.Flink;
@@ -952 +973 @@
             continue;
 
-        Assert(pDevice->enmState != VBOXUSBFLT_DEVSTATE_ADDED);
-        Assert(pDevice->enmState != VBOXUSBFLT_DEVSTATE_REMOVED);
+        LOG(("found device(0x%p), pdo(0x%p), state(%d), filter id(0x%p), oneshot(%d)",
+                pDevice, pDevice->Pdo, pDevice->enmState, pDevice->uFltId, (int)pDevice->fIsFilterOneShot));
+        ASSERT_WARN(pDevice->enmState != VBOXUSBFLT_DEVSTATE_ADDED, ("VBOXUSBFLT_DEVSTATE_ADDED state for device(0x%p)", pDevice));
+        ASSERT_WARN(pDevice->enmState != VBOXUSBFLT_DEVSTATE_REMOVED, ("VBOXUSBFLT_DEVSTATE_REMOVED state for device(0x%p)", pDevice));
 
         vboxUsbFltDevOwnerClearLocked(pDevice);
@@ -959 +982 @@
         if (vboxUsbFltDevCheckReplugLocked(pDevice, pContext))
         {
+            LOG(("device needs replug"));
             InsertHeadList(&ReplugDevList, &pDevice->RepluggingLe);
             /* retain to ensure the device is not removed before we issue a replug */
@@ -965 +989 @@
             ObReferenceObject(pDevice->Pdo);
         }
+        else
+        {
+            LOG(("device does NOT need replug"));
+        }
     }
     VBOXUSBFLT_LOCK_RELEASE();
@@ -971 +999 @@
     vboxUsbFltReplugList(&ReplugDevList);
 
+    LOG(("SUCCESS done context(0x%p)", pContext));
     return STATUS_SUCCESS;
 }
@@ -976 +1005 @@
 NTSTATUS VBoxUsbFltCreate(PVBOXUSBFLTCTX pContext)
 {
+    LOG(("Creating context(0x%p)", pContext));
     memset(pContext, 0, sizeof (*pContext));
     pContext->Process = RTProcSelf();
@@ -981 +1011 @@
     InsertHeadList(&g_VBoxUsbFltGlobals.ContextList, &pContext->ListEntry);
     VBOXUSBFLT_LOCK_RELEASE();
+    LOG(("SUCCESS context(0x%p)", pContext));
     return STATUS_SUCCESS;
 }
@@ -986 +1017 @@
 int VBoxUsbFltAdd(PVBOXUSBFLTCTX pContext, PUSBFILTER pFilter, uintptr_t *pId)
 {
+    LOG(("adding filter, Context (0x%p)..", pContext));
     *pId = 0;
     /* LOG the filter details. */
@@ -1034 +1066 @@
 int VBoxUsbFltRemove(PVBOXUSBFLTCTX pContext, uintptr_t uId)
 {
+    LOG(("removing filter id(0x%p), Context (0x%p)..", pContext, uId));
     Assert(uId);
 
@@ -1045 +1078 @@
     }
 
+    LOG(("enumerating devices.."));
     for (PLIST_ENTRY pEntry = g_VBoxUsbFltGlobals.DeviceList.Flink;
             pEntry != &g_VBoxUsbFltGlobals.DeviceList;
@@ -1062 +1096 @@
             continue;
 
+        LOG(("found device(0x%p), pdo(0x%p), state(%d), filter id(0x%p), oneshot(%d)",
+                pDevice, pDevice->Pdo, pDevice->enmState, pDevice->uFltId, (int)pDevice->fIsFilterOneShot));
         ASSERT_WARN(!pDevice->fIsFilterOneShot, ("device(0x%p) is filtered with a oneshot filter", pDevice));
         pDevice->uFltId = 0;
@@ -1068 +1104 @@
     }
     VBOXUSBFLT_LOCK_RELEASE();
+
+    LOG(("done enumerating devices"));
 
     if (RT_SUCCESS(rc))

trunk/src/VBox/HostDrivers/VBoxUSB/win/mon/VBoxUsbMon.cpp

@@ -1339 +1339 @@
 #endif
 
-    LOG(("VBoxUSBMon::DriverEntry\n"));
+    LOGREL(("Built %s %s", __DATE__, __TIME__));
 
     memset (&g_VBoxUsbMonGlobals, 0, sizeof (g_VBoxUsbMonGlobals));