diff --git a/.gitignore b/.gitignore index 0492a8e..5caa9df 100644 --- a/.gitignore +++ b/.gitignore @@ -19,9 +19,10 @@ /build/bin/Debug /build/obj/Debug /bin -/sys/RCb21300 -/sys/RCa21300 +/sys/x64/Debug +/x64/Debug +/x64/Debug (static) *.user /.vs/config -/sys/x64/Debug -/x64 +/sys/RCa21300 +/sys/RCb21300 diff --git a/sys/ByteArray.c b/sys/ByteArray.c index 5968db5..0a00e7d 100644 --- a/sys/ByteArray.c +++ b/sys/ByteArray.c @@ -1,4 +1,6 @@ #include "ByteArray.h" +#include "trace.h" +#include "bytearray.tmh" // // Helpers diff --git a/sys/Context.h b/sys/Context.h index 4bf4bbd..94da20c 100644 --- a/sys/Context.h +++ b/sys/Context.h @@ -32,6 +32,9 @@ typedef struct _PDO_IDENTIFICATION_DESCRIPTION { WDF_CHILD_IDENTIFICATION_DESCRIPTION_HEADER Header; // should contain this header + // + // Unique serial number of the device on the bus + // ULONG SerialNo; // @@ -140,6 +143,11 @@ typedef struct _FDO_DEVICE_DATA // WDFSPINLOCK PendingPluginRequestsLock; + // + // Periodic timer sweeping up orphaned requests + // + WDFTIMER PendingPluginRequestsCleanupTimer; + } FDO_DEVICE_DATA, *PFDO_DEVICE_DATA; #define FDO_FIRST_SESSION_ID 100 @@ -165,8 +173,21 @@ WDF_DECLARE_CONTEXT_TYPE_WITH_NAME(FDO_FILE_DATA, FileObjectGetData) // typedef struct _FDO_PLUGIN_REQUEST_DATA { + // + // Unique serial number of the device on the bus + // ULONG Serial; + // + // High resolution timestamp taken when this request got moved to pending state + // + LARGE_INTEGER Timestamp; + + // + // Performance counter system frequency taken upon fetching timestamp + // + LARGE_INTEGER Frequency; + } FDO_PLUGIN_REQUEST_DATA, *PFDO_PLUGIN_REQUEST_DATA; WDF_DECLARE_CONTEXT_TYPE_WITH_NAME(FDO_PLUGIN_REQUEST_DATA, PluginRequestGetData) diff --git a/sys/Driver.c b/sys/Driver.c index 7a4ab22..dddd941 100644 --- a/sys/Driver.c +++ b/sys/Driver.c @@ -25,12 +25,14 @@ SOFTWARE. #include "busenum.h" #include +#include "driver.tmh" #ifdef ALLOC_PRAGMA #pragma alloc_text (INIT, DriverEntry) #pragma alloc_text (PAGE, Bus_EvtDeviceAdd) #pragma alloc_text (PAGE, Bus_DeviceFileCreate) #pragma alloc_text (PAGE, Bus_FileClose) +#pragma alloc_text (PAGE, Bus_EvtDriverContextCleanup) #pragma alloc_text (PAGE, Bus_PdoStageResult) #endif @@ -40,18 +42,36 @@ SOFTWARE. // NTSTATUS DriverEntry(IN PDRIVER_OBJECT DriverObject, IN PUNICODE_STRING RegistryPath) { - WDF_DRIVER_CONFIG config; - NTSTATUS status; - WDFDRIVER driver; + WDF_DRIVER_CONFIG config; + NTSTATUS status; + WDFDRIVER driver; + WDF_OBJECT_ATTRIBUTES attributes; KdPrint((DRIVERNAME "Virtual Gamepad Emulation Bus Driver [built: %s %s]\n", __DATE__, __TIME__)); + // + // Initialize WPP Tracing + // + WPP_INIT_TRACING(DriverObject, RegistryPath); + + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Loading Virtual Gamepad Emulation Bus Driver [built: %s %s]", + __DATE__, __TIME__); + + // + // Register cleanup callback + // + WDF_OBJECT_ATTRIBUTES_INIT(&attributes); + attributes.EvtCleanupCallback = Bus_EvtDriverContextCleanup; + WDF_DRIVER_CONFIG_INIT(&config, Bus_EvtDeviceAdd); - status = WdfDriverCreate(DriverObject, RegistryPath, WDF_NO_OBJECT_ATTRIBUTES, &config, &driver); + status = WdfDriverCreate(DriverObject, RegistryPath, &attributes, &config, &driver); if (!NT_SUCCESS(status)) { + WPP_CLEANUP(DriverObject); KdPrint((DRIVERNAME "WdfDriverCreate failed with status 0x%x\n", status)); } @@ -73,15 +93,17 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) WDF_OBJECT_ATTRIBUTES fdoAttributes; WDF_OBJECT_ATTRIBUTES fileHandleAttributes; WDF_OBJECT_ATTRIBUTES collectionAttributes; + WDF_OBJECT_ATTRIBUTES timerAttributes; PFDO_DEVICE_DATA pFDOData; VIGEM_BUS_INTERFACE busInterface; PINTERFACE interfaceHeader; + WDF_TIMER_CONFIG reqTimerCfg; UNREFERENCED_PARAMETER(Driver); PAGED_CODE(); - KdPrint((DRIVERNAME "Bus_EvtDeviceAdd: 0x%p\n", Driver)); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Entry"); WdfDeviceInitSetDeviceType(DeviceInit, FILE_DEVICE_BUS_EXTENDER); // More than one process may talk to the bus at the same time @@ -117,16 +139,19 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Error creating device 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfDeviceCreate failed with status %!STATUS!", + status); return status; } - KdPrint((DRIVERNAME "Created FDO: 0x%X\n", device)); - pFDOData = FdoGetData(device); if (pFDOData == NULL) { - KdPrint((DRIVERNAME "Error creating device context\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "FdoGetData failed"); return STATUS_UNSUCCESSFUL; } @@ -143,7 +168,10 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) status = WdfCollectionCreate(&collectionAttributes, &pFDOData->PendingPluginRequests); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfCollectionCreate failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfCollectionCreate failed with status %!STATUS!", + status); return STATUS_UNSUCCESSFUL; } @@ -153,12 +181,41 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) status = WdfSpinLockCreate(&collectionAttributes, &pFDOData->PendingPluginRequestsLock); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfSpinLockCreate failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfSpinLockCreate failed with status %!STATUS!", + status); return STATUS_UNSUCCESSFUL; } #pragma endregion +#pragma region Create timer for sweeping up orphaned requests + + WDF_TIMER_CONFIG_INIT_PERIODIC( + &reqTimerCfg, + Bus_PlugInRequestCleanUpEvtTimerFunc, + ORC_TIMER_START_DELAY + ); + WDF_OBJECT_ATTRIBUTES_INIT(&timerAttributes); + timerAttributes.ParentObject = device; + + status = WdfTimerCreate(&reqTimerCfg, &timerAttributes, &pFDOData->PendingPluginRequestsCleanupTimer); + if (!NT_SUCCESS(status)) { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfTimerCreate failed with status %!STATUS!", + status); + return status; + } + + WdfTimerStart( + pFDOData->PendingPluginRequestsCleanupTimer, + WDF_REL_TIMEOUT_IN_MS(ORC_TIMER_PERIODIC_DUE_TIME) + ); + +#pragma endregion + #pragma region Add query interface // @@ -191,7 +248,10 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) &queryInterfaceConfig); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceAddQueryInterface failed 0x%0x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfDeviceAddQueryInterface failed with status %!STATUS!", + status); return(status); } @@ -211,7 +271,10 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfIoQueueCreate failed with status %!STATUS!", + status); return status; } @@ -223,7 +286,10 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceCreateDeviceInterface failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfDeviceCreateDeviceInterface failed with status %!STATUS!", + status); return status; } @@ -239,6 +305,8 @@ NTSTATUS Bus_EvtDeviceAdd(IN WDFDRIVER Driver, IN PWDFDEVICE_INIT DeviceInit) #pragma endregion + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Exit with status %!STATUS!", status); + return status; } @@ -263,17 +331,25 @@ Bus_DeviceFileCreate( PAGED_CODE(); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Entry"); + pFileData = FileObjectGetData(FileObject); + if (pFileData == NULL) { - KdPrint((DRIVERNAME "Bus_DeviceFileCreate: ERROR! File handle context not found\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "FileObjectGetData failed to return file object from WDFFILEOBJECT 0x%p", + FileObject); } else { pFDOData = FdoGetData(Device); if (pFDOData == NULL) { - KdPrint((DRIVERNAME "Bus_DeviceFileCreate: ERROR! FDO context not found\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "FdoGetData failed"); status = STATUS_NO_SUCH_DEVICE; } else @@ -284,11 +360,16 @@ Bus_DeviceFileCreate( pFileData->SessionId = sessionId; status = STATUS_SUCCESS; - KdPrint((DRIVERNAME "Bus_DeviceFileCreate: File id=%d. Device refcount=%d\n", (int)sessionId, (int)refCount)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "File/session id = %d, device ref. count = %d", + (int)sessionId, (int)refCount); } } WdfRequestComplete(Request, status); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Exit with status %!STATUS!", status); } // @@ -313,13 +394,17 @@ Bus_FileClose( PAGED_CODE(); - KdPrint((DRIVERNAME "Bus_FileClose called\n")); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Entry"); // Check common context pFileData = FileObjectGetData(FileObject); if (pFileData == NULL) { - KdPrint((DRIVERNAME "Bus_FileClose: ERROR! File handle context not found\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "FileObjectGetData failed to return file object from WDFFILEOBJECT 0x%p", + FileObject); return; } @@ -328,14 +413,19 @@ Bus_FileClose( pFDOData = FdoGetData(device); if (pFDOData == NULL) { - KdPrint((DRIVERNAME "Bus_FileClose: ERROR! FDO context not found\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "FdoGetData failed"); status = STATUS_NO_SUCH_DEVICE; } else { refCount = InterlockedDecrement(&pFDOData->InterfaceReferenceCounter); - KdPrint((DRIVERNAME "Bus_FileClose: Device refcount=%d\n", (int)refCount)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Device ref. count = %d", + (int)refCount); } list = WdfFdoGetDefaultChildList(device); @@ -355,31 +445,74 @@ Bus_FileClose( break; } - KdPrint((DRIVERNAME "Bus_FileClose enumerate: status=%d devicePID=%d currentPID=%d fileSessionId=%d deviceSessionId=%d ownerIsDriver=%d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_DRIVER, + "PDO properties: status = %!STATUS!, pdoPID = %d, curPID = %d, pdoSID = %d, curSID = %d, internal = %d", (int)childInfo.Status, (int)description.OwnerProcessId, (int)CURRENT_PROCESS_ID(), - (int)pFileData->SessionId, (int)description.SessionId, - (int)description.OwnerIsDriver)); + (int)pFileData->SessionId, + (int)description.OwnerIsDriver + ); // Only unplug devices with matching session id if (childInfo.Status == WdfChildListRetrieveDeviceSuccess && description.SessionId == pFileData->SessionId && !description.OwnerIsDriver) { - KdPrint((DRIVERNAME "Bus_FileClose unplugging\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Unplugging device with serial %d", + description.SerialNo); // "Unplug" child status = WdfChildListUpdateChildDescriptionAsMissing(list, &description.Header); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfChildListUpdateChildDescriptionAsMissing failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DRIVER, + "WdfChildListUpdateChildDescriptionAsMissing failed with status %!STATUS!", + status); } } } WdfChildListEndIteration(list, &iterator); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Exit with status %!STATUS!", status); +} + +VOID +Bus_EvtDriverContextCleanup( + _In_ WDFOBJECT DriverObject +) +/*++ +Routine Description: + + Free all the resources allocated in DriverEntry. + +Arguments: + + DriverObject - handle to a WDF Driver object. + +Return Value: + + VOID. + +--*/ +{ + UNREFERENCED_PARAMETER(DriverObject); + + PAGED_CODE(); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Entry"); + + // + // Stop WPP Tracing + // + WPP_CLEANUP(WdfDriverWdmGetDriverObject((WDFDRIVER)DriverObject)); + } // @@ -394,17 +527,20 @@ Bus_PdoStageResult( _In_ NTSTATUS Status ) { - ULONG i; - PFDO_DEVICE_DATA pFdoData; - WDFREQUEST curRequest; - ULONG curSerial; - ULONG items; + ULONG i; + PFDO_DEVICE_DATA pFdoData; + WDFREQUEST curRequest; + ULONG curSerial; + ULONG items; UNREFERENCED_PARAMETER(InterfaceHeader); PAGED_CODE(); - KdPrint((DRIVERNAME "Bus_PdoStageResult: Stage: %d, Serial: %d, status: 0x%X\n", Stage, Serial, Status)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "%!FUNC! Entry (stage = %d, serial = %d, status = %!STATUS!)", + Stage, Serial, Status); pFdoData = FdoGetData(InterfaceHeader->Context); @@ -417,14 +553,20 @@ Bus_PdoStageResult( items = WdfCollectionGetCount(pFdoData->PendingPluginRequests); - KdPrint((DRIVERNAME "Items count: %d\n", items)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Items count: %d", + items); for (i = 0; i < items; i++) { curRequest = WdfCollectionGetItem(pFdoData->PendingPluginRequests, i); curSerial = PluginRequestGetData(curRequest)->Serial; - KdPrint((DRIVERNAME "Serial: %d, curSerial: %d\n", Serial, curSerial)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Serial: %d, curSerial: %d", + Serial, curSerial); if (Serial == curSerial) { @@ -432,11 +574,81 @@ Bus_PdoStageResult( WdfCollectionRemove(pFdoData->PendingPluginRequests, curRequest); - KdPrint((DRIVERNAME "Removed item with serial: %d\n", curSerial)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Removed item with serial: %d", + curSerial); break; } } WdfSpinLockRelease(pFdoData->PendingPluginRequestsLock); } + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Exit"); } + +_Use_decl_annotations_ +VOID +Bus_PlugInRequestCleanUpEvtTimerFunc( + WDFTIMER Timer +) +{ + ULONG i; + PFDO_DEVICE_DATA pFdoData; + WDFREQUEST curRequest; + ULONG items; + WDFDEVICE device; + PFDO_PLUGIN_REQUEST_DATA pPluginData; + LONGLONG freq; + LARGE_INTEGER pcNow; + LONGLONG ellapsed; + + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Entry"); + + device = WdfTimerGetParentObject(Timer); + pFdoData = FdoGetData(device); + + WdfSpinLockAcquire(pFdoData->PendingPluginRequestsLock); + + items = WdfCollectionGetCount(pFdoData->PendingPluginRequests); + + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Items count: %d", + items); + + for (i = 0; i < items; i++) + { + curRequest = WdfCollectionGetItem(pFdoData->PendingPluginRequests, i); + pPluginData = PluginRequestGetData(curRequest); + + freq = pPluginData->Frequency.QuadPart / ORC_PC_FREQUENCY_DIVIDER; + pcNow = KeQueryPerformanceCounter(NULL); + ellapsed = (pcNow.QuadPart - pPluginData->Timestamp.QuadPart) / freq; + + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_DRIVER, + "PDO (serial = %d) age: %llu", + pPluginData->Serial, ellapsed); + + if (ellapsed >= ORC_REQUEST_MAX_AGE) + { + WdfRequestComplete(curRequest, STATUS_SUCCESS); + + WdfCollectionRemove(pFdoData->PendingPluginRequests, curRequest); + + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DRIVER, + "Removed item with serial: %d", + pPluginData->Serial); + + break; + } + } + WdfSpinLockRelease(pFdoData->PendingPluginRequestsLock); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Exit"); +} + diff --git a/sys/Ds4.c b/sys/Ds4.c index 027ee2a..627375e 100644 --- a/sys/Ds4.c +++ b/sys/Ds4.c @@ -25,6 +25,7 @@ SOFTWARE. #include "busenum.h" #include +#include "ds4.tmh" NTSTATUS Ds4_PreparePdo(PWDFDEVICE_INIT DeviceInit, PUNICODE_STRING DeviceId, PUNICODE_STRING DeviceDescription) { @@ -34,14 +35,26 @@ NTSTATUS Ds4_PreparePdo(PWDFDEVICE_INIT DeviceInit, PUNICODE_STRING DeviceId, PU // prepare device description status = RtlUnicodeStringInit(DeviceDescription, L"Virtual DualShock 4 Controller"); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "RtlUnicodeStringInit failed with status %!STATUS!", + status); return status; + } // Set hardware IDs RtlUnicodeStringInit(&buffer, L"USB\\VID_054C&PID_05C4&REV_0100"); status = WdfPdoInitAddHardwareID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfPdoInitAddHardwareID failed with status %!STATUS!", + status); return status; + } RtlUnicodeStringCopy(DeviceId, &buffer); @@ -49,26 +62,50 @@ NTSTATUS Ds4_PreparePdo(PWDFDEVICE_INIT DeviceInit, PUNICODE_STRING DeviceId, PU status = WdfPdoInitAddHardwareID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfPdoInitAddHardwareID failed with status %!STATUS!", + status); return status; + } // Set compatible IDs RtlUnicodeStringInit(&buffer, L"USB\\Class_03&SubClass_00&Prot_00"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfPdoInitAddCompatibleID (#01) failed with status %!STATUS!", + status); return status; + } RtlUnicodeStringInit(&buffer, L"USB\\Class_03&SubClass_00"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfPdoInitAddCompatibleID (#02) failed with status %!STATUS!", + status); return status; + } RtlUnicodeStringInit(&buffer, L"USB\\Class_03"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfPdoInitAddCompatibleID (#03) failed with status %!STATUS!", + status); return status; + } return STATUS_SUCCESS; } @@ -92,7 +129,10 @@ NTSTATUS Ds4_PrepareHardware(WDFDEVICE Device) status = WdfDeviceAddQueryInterface(Device, &ifaceCfg); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceAddQueryInterface failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfDeviceAddQueryInterface failed with status %!STATUS!", + status); return status; } @@ -126,8 +166,6 @@ NTSTATUS Ds4_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION NTSTATUS status; PDS4_DEVICE_DATA ds4 = Ds4GetData(Device); - KdPrint((DRIVERNAME "Initializing DS4 context...\n")); - // Initialize periodic timer WDF_TIMER_CONFIG timerConfig; WDF_TIMER_CONFIG_INIT_PERIODIC(&timerConfig, Ds4_PendingUsbRequestsTimerFunc, DS4_QUEUE_FLUSH_PERIOD); @@ -143,7 +181,10 @@ NTSTATUS Ds4_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION status = WdfTimerCreate(&timerConfig, &timerAttribs, &ds4->PendingUsbInRequestsTimer); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfTimerCreate failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfTimerCreate failed with status %!STATUS!", + status); return status; } @@ -157,38 +198,71 @@ NTSTATUS Ds4_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION status = WdfDriverOpenParametersRegistryKey(WdfGetDriver(), STANDARD_RIGHTS_ALL, WDF_NO_OBJECT_ATTRIBUTES, &keyParams); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDriverOpenParametersRegistryKey failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfDriverOpenParametersRegistryKey failed with status %!STATUS!", + status); return status; } RtlUnicodeStringInit(&keyName, L"Targets"); - status = WdfRegistryCreateKey(keyParams, &keyName, - KEY_ALL_ACCESS, REG_OPTION_NON_VOLATILE, NULL, WDF_NO_OBJECT_ATTRIBUTES, &keyTargets); + status = WdfRegistryCreateKey( + keyParams, + &keyName, + KEY_ALL_ACCESS, + REG_OPTION_NON_VOLATILE, + NULL, + WDF_NO_OBJECT_ATTRIBUTES, + &keyTargets + ); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRegistryCreateKey failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfRegistryCreateKey failed with status %!STATUS!", + status); return status; } RtlUnicodeStringInit(&keyName, L"DualShock"); - status = WdfRegistryCreateKey(keyTargets, &keyName, - KEY_ALL_ACCESS, REG_OPTION_NON_VOLATILE, NULL, WDF_NO_OBJECT_ATTRIBUTES, &keyDS); + status = WdfRegistryCreateKey( + keyTargets, + &keyName, + KEY_ALL_ACCESS, + REG_OPTION_NON_VOLATILE, + NULL, + WDF_NO_OBJECT_ATTRIBUTES, + &keyDS + ); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRegistryCreateKey failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfRegistryCreateKey failed with status %!STATUS!", + status); return status; } DECLARE_UNICODE_STRING_SIZE(serialPath, 4); RtlUnicodeStringPrintf(&serialPath, L"%04d", Description->SerialNo); - status = WdfRegistryCreateKey(keyDS, &serialPath, - KEY_ALL_ACCESS, REG_OPTION_NON_VOLATILE, NULL, WDF_NO_OBJECT_ATTRIBUTES, &keySerial); + status = WdfRegistryCreateKey( + keyDS, + &serialPath, + KEY_ALL_ACCESS, + REG_OPTION_NON_VOLATILE, + NULL, + WDF_NO_OBJECT_ATTRIBUTES, + &keySerial + ); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRegistryCreateKey failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfRegistryCreateKey failed with status %!STATUS!", + status); return status; } @@ -196,13 +270,15 @@ NTSTATUS Ds4_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION status = WdfRegistryQueryValue(keySerial, &valueName, sizeof(MAC_ADDRESS), &ds4->TargetMacAddress, NULL, NULL); - KdPrint((DRIVERNAME "MAC-Address: %02X:%02X:%02X:%02X:%02X:%02X\n", + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_DS4, + "MAC-Address: %02X:%02X:%02X:%02X:%02X:%02X\n", ds4->TargetMacAddress.Vendor0, ds4->TargetMacAddress.Vendor1, ds4->TargetMacAddress.Vendor2, ds4->TargetMacAddress.Nic0, ds4->TargetMacAddress.Nic1, - ds4->TargetMacAddress.Nic2)); + ds4->TargetMacAddress.Nic2); if (status == STATUS_OBJECT_NAME_NOT_FOUND) { @@ -211,13 +287,19 @@ NTSTATUS Ds4_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION status = WdfRegistryAssignValue(keySerial, &valueName, REG_BINARY, sizeof(MAC_ADDRESS), (PVOID)&ds4->TargetMacAddress); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRegistryAssignValue failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfRegistryAssignValue failed with status %!STATUS!", + status); return status; } } else if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRegistryQueryValue failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_DS4, + "WdfRegistryQueryValue failed with status %!STATUS!", + status); return status; } @@ -302,11 +384,13 @@ VOID Ds4_GetDeviceDescriptorType(PUSB_DEVICE_DESCRIPTOR pDescriptor, PPDO_DEVICE VOID Ds4_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_DS4, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0x03; // HID pInfo->SubClass = 0x00; @@ -346,6 +430,8 @@ VOID Ds4_PendingUsbRequestsTimerFunc( PIO_STACK_LOCATION irpStack; PPDO_DEVICE_DATA pdoData; + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_DS4, "%!FUNC! Entry"); + hChild = WdfTimerGetParentObject(Timer); pdoData = PdoGetData(hChild); ds4Data = Ds4GetData(hChild); @@ -374,5 +460,7 @@ VOID Ds4_PendingUsbRequestsTimerFunc( // Complete pending request WdfRequestComplete(usbRequest, status); } + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DS4, "%!FUNC! Exit with status %!STATUS!", status); } diff --git a/sys/Queue.c b/sys/Queue.c index d8a3da7..6ceafd8 100644 --- a/sys/Queue.c +++ b/sys/Queue.c @@ -24,6 +24,7 @@ SOFTWARE. #include "busenum.h" +#include "queue.tmh" #ifdef ALLOC_PRAGMA #pragma alloc_text (PAGE, Bus_EvtIoDefault) @@ -54,14 +55,16 @@ VOID Bus_EvtIoDeviceControl( Device = WdfIoQueueGetDevice(Queue); - KdPrint((DRIVERNAME "Bus_EvtIoDeviceControl: 0x%p\n", Device)); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_QUEUE, "%!FUNC! Entry (device: 0x%p)", Device); switch (IoControlCode) { #pragma region IOCTL_VIGEM_CHECK_VERSION case IOCTL_VIGEM_CHECK_VERSION: - KdPrint((DRIVERNAME "IOCTL_VIGEM_CHECK_VERSION\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_QUEUE, + "IOCTL_VIGEM_CHECK_VERSION"); status = WdfRequestRetrieveInputBuffer(Request, sizeof(VIGEM_CHECK_VERSION), (PVOID)&pCheckVersion, &length); @@ -73,13 +76,20 @@ VOID Bus_EvtIoDeviceControl( status = (pCheckVersion->Version == VIGEM_COMMON_VERSION) ? STATUS_SUCCESS : STATUS_NOT_SUPPORTED; + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_QUEUE, + "Requested version: 0x%04X, compiled version: 0x%04X", + pCheckVersion->Version, VIGEM_COMMON_VERSION); + break; #pragma endregion #pragma region IOCTL_VIGEM_PLUGIN_TARGET case IOCTL_VIGEM_PLUGIN_TARGET: - KdPrint((DRIVERNAME "IOCTL_VIGEM_PLUGIN_TARGET\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_QUEUE, + "IOCTL_VIGEM_PLUGIN_TARGET"); status = Bus_PlugInDevice(Device, Request, FALSE, &length); @@ -89,7 +99,9 @@ VOID Bus_EvtIoDeviceControl( #pragma region IOCTL_VIGEM_UNPLUG_TARGET case IOCTL_VIGEM_UNPLUG_TARGET: - KdPrint((DRIVERNAME "IOCTL_VIGEM_UNPLUG_TARGET\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_QUEUE, + "IOCTL_VIGEM_UNPLUG_TARGET"); status = Bus_UnPlugDevice(Device, Request, FALSE, &length); @@ -99,13 +111,18 @@ VOID Bus_EvtIoDeviceControl( #pragma region IOCTL_XUSB_SUBMIT_REPORT case IOCTL_XUSB_SUBMIT_REPORT: - KdPrint((DRIVERNAME "IOCTL_XUSB_SUBMIT_REPORT\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_QUEUE, + "IOCTL_XUSB_SUBMIT_REPORT"); status = WdfRequestRetrieveInputBuffer(Request, sizeof(XUSB_SUBMIT_REPORT), (PVOID)&xusbSubmit, &length); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRequestRetrieveInputBuffer failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "WdfRequestRetrieveInputBuffer failed with status %!STATUS!", + status); break; } @@ -114,6 +131,10 @@ VOID Bus_EvtIoDeviceControl( // This request only supports a single PDO at a time if (xusbSubmit->SerialNo == 0) { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "Invalid serial 0 submitted"); + status = STATUS_INVALID_PARAMETER; break; } @@ -127,12 +148,17 @@ VOID Bus_EvtIoDeviceControl( #pragma region IOCTL_XUSB_REQUEST_NOTIFICATION case IOCTL_XUSB_REQUEST_NOTIFICATION: - KdPrint((DRIVERNAME "IOCTL_XUSB_REQUEST_NOTIFICATION\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_QUEUE, + "IOCTL_XUSB_REQUEST_NOTIFICATION"); // Don't accept the request if the output buffer can't hold the results if (OutputBufferLength < sizeof(XUSB_REQUEST_NOTIFICATION)) { - KdPrint((DRIVERNAME "IOCTL_XUSB_REQUEST_NOTIFICATION: output buffer too small: %ul\n", OutputBufferLength)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "Output buffer %d too small, require at least %d", + (int)OutputBufferLength, (int)sizeof(XUSB_REQUEST_NOTIFICATION)); break; } @@ -140,7 +166,10 @@ VOID Bus_EvtIoDeviceControl( if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRequestRetrieveInputBuffer failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "WdfRequestRetrieveInputBuffer failed with status %!STATUS!", + status); break; } @@ -149,6 +178,10 @@ VOID Bus_EvtIoDeviceControl( // This request only supports a single PDO at a time if (xusbNotify->SerialNo == 0) { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "Invalid serial 0 submitted"); + status = STATUS_INVALID_PARAMETER; break; } @@ -162,13 +195,18 @@ VOID Bus_EvtIoDeviceControl( #pragma region IOCTL_DS4_SUBMIT_REPORT case IOCTL_DS4_SUBMIT_REPORT: - KdPrint((DRIVERNAME "IOCTL_DS4_SUBMIT_REPORT\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_QUEUE, + "IOCTL_DS4_SUBMIT_REPORT"); status = WdfRequestRetrieveInputBuffer(Request, sizeof(DS4_SUBMIT_REPORT), (PVOID)&ds4Submit, &length); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRequestRetrieveInputBuffer failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "WdfRequestRetrieveInputBuffer failed with status %!STATUS!", + status); break; } @@ -177,6 +215,10 @@ VOID Bus_EvtIoDeviceControl( // This request only supports a single PDO at a time if (ds4Submit->SerialNo == 0) { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "Invalid serial 0 submitted"); + status = STATUS_INVALID_PARAMETER; break; } @@ -190,12 +232,17 @@ VOID Bus_EvtIoDeviceControl( #pragma region IOCTL_DS4_REQUEST_NOTIFICATION case IOCTL_DS4_REQUEST_NOTIFICATION: - KdPrint((DRIVERNAME "IOCTL_DS4_REQUEST_NOTIFICATION\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_QUEUE, + "IOCTL_DS4_REQUEST_NOTIFICATION"); // Don't accept the request if the output buffer can't hold the results if (OutputBufferLength < sizeof(DS4_REQUEST_NOTIFICATION)) { - KdPrint((DRIVERNAME "IOCTL_DS4_REQUEST_NOTIFICATION: output buffer too small: %ul\n", OutputBufferLength)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "Output buffer %d too small, require at least %d", + (int)OutputBufferLength, (int)sizeof(DS4_REQUEST_NOTIFICATION)); break; } @@ -203,7 +250,10 @@ VOID Bus_EvtIoDeviceControl( if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRequestRetrieveInputBuffer failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "WdfRequestRetrieveInputBuffer failed with status %!STATUS!", + status); break; } @@ -212,6 +262,10 @@ VOID Bus_EvtIoDeviceControl( // This request only supports a single PDO at a time if (ds4Notify->SerialNo == 0) { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_QUEUE, + "Invalid serial 0 submitted"); + status = STATUS_INVALID_PARAMETER; break; } @@ -225,7 +279,9 @@ VOID Bus_EvtIoDeviceControl( #pragma region IOCTL_XGIP_SUBMIT_REPORT case IOCTL_XGIP_SUBMIT_REPORT: - KdPrint((DRIVERNAME "IOCTL_XGIP_SUBMIT_REPORT\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_QUEUE, + "IOCTL_XGIP_SUBMIT_REPORT"); status = WdfRequestRetrieveInputBuffer(Request, sizeof(XGIP_SUBMIT_REPORT), (PVOID)&xgipSubmit, &length); @@ -318,7 +374,11 @@ VOID Bus_EvtIoDeviceControl( #pragma endregion default: - KdPrint((DRIVERNAME "UNKNOWN IOCTL CODE 0x%x\n", IoControlCode)); + + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_QUEUE, + "Unknown I/O control code 0x%X", IoControlCode); + break; // default status is STATUS_INVALID_PARAMETER } @@ -326,8 +386,15 @@ VOID Bus_EvtIoDeviceControl( { WdfRequestCompleteWithInformation(Request, status, length); } + + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_QUEUE, "%!FUNC! Exit with status %!STATUS!", status); } +// +// Gets called upon driver-to-driver communication. +// +// TODO: incomplete and unused currently +// VOID Bus_EvtIoInternalDeviceControl( _In_ WDFQUEUE Queue, _In_ WDFREQUEST Request, @@ -383,7 +450,9 @@ VOID Bus_EvtIoDefault( UNREFERENCED_PARAMETER(Queue); UNREFERENCED_PARAMETER(Request); - KdPrint((DRIVERNAME "Bus_EvtIoDefault called\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_QUEUE, "%!FUNC! Entry"); WdfRequestComplete(Request, STATUS_INVALID_DEVICE_REQUEST); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_QUEUE, "%!FUNC! Exit"); } \ No newline at end of file diff --git a/sys/ViGEmBus.vcxproj b/sys/ViGEmBus.vcxproj index 366c89a..bb36a47 100644 --- a/sys/ViGEmBus.vcxproj +++ b/sys/ViGEmBus.vcxproj @@ -214,6 +214,11 @@ $(DDK_LIB_PATH)ntstrsafe.lib;$(DDK_LIB_PATH)wdmsec.lib;%(AdditionalDependencies) + + true + true + trace.h + @@ -227,6 +232,9 @@ true + true + true + trace.h @@ -252,6 +260,11 @@ $(DDK_LIB_PATH)ntstrsafe.lib;$(DDK_LIB_PATH)wdmsec.lib;%(AdditionalDependencies) + + true + true + trace.h + @@ -265,6 +278,9 @@ true + true + true + trace.h @@ -283,6 +299,7 @@ + diff --git a/sys/ViGEmBus.vcxproj.filters b/sys/ViGEmBus.vcxproj.filters index a589514..cb0c79e 100644 --- a/sys/ViGEmBus.vcxproj.filters +++ b/sys/ViGEmBus.vcxproj.filters @@ -66,6 +66,9 @@ Header Files + + Header Files + diff --git a/sys/busenum.c b/sys/busenum.c index 2894fba..183332d 100644 --- a/sys/busenum.c +++ b/sys/busenum.c @@ -26,6 +26,7 @@ SOFTWARE. #include "busenum.h" #include #include +#include "busenum.tmh" #ifdef ALLOC_PRAGMA #pragma alloc_text (PAGE, Bus_PlugInDevice) @@ -56,24 +57,33 @@ NTSTATUS Bus_PlugInDevice( PAGED_CODE(); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Entry"); + pFdoData = FdoGetData(Device); status = WdfRequestRetrieveInputBuffer(Request, sizeof(VIGEM_PLUGIN_TARGET), (PVOID)&plugIn, &length); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRequestRetrieveInputBuffer failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfRequestRetrieveInputBuffer failed with status %!STATUS!", status); return status; } if ((sizeof(VIGEM_PLUGIN_TARGET) != plugIn->Size) || (length != plugIn->Size)) { - KdPrint((DRIVERNAME "Input buffer size mismatch")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "sizeof(VIGEM_PLUGIN_TARGET) buffer size mismatch [%d != %d]", + sizeof(VIGEM_PLUGIN_TARGET), plugIn->Size); return STATUS_INVALID_PARAMETER; } if (plugIn->SerialNo == 0) { - KdPrint((DRIVERNAME "Serial no. 0 not allowed")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "Serial no. 0 not allowed"); return STATUS_INVALID_PARAMETER; } @@ -82,14 +92,20 @@ NTSTATUS Bus_PlugInDevice( fileObject = WdfRequestGetFileObject(Request); if (fileObject == NULL) { - KdPrint((DRIVERNAME "File object associated with request is null")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfRequestGetFileObject failed to fetch WDFFILEOBJECT from request 0x%p", + Request); return STATUS_INVALID_PARAMETER; } pFileData = FileObjectGetData(fileObject); if (pFileData == NULL) { - KdPrint((DRIVERNAME "File object context associated with request is null")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "FileObjectGetData failed to get context data for 0x%p", + fileObject); return STATUS_INVALID_PARAMETER; } @@ -141,22 +157,49 @@ NTSTATUS Bus_PlugInDevice( description.ProductId = plugIn->ProductId; } + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "New PDO properties: serial = %d, type = %d, pid = %d, session = %d, internal = %d, vid = 0x%04X, pid = 0x%04X", + description.SerialNo, + description.TargetType, + description.OwnerProcessId, + description.SessionId, + description.OwnerIsDriver, + description.VendorId, + description.ProductId + ); + WdfSpinLockAcquire(pFdoData->PendingPluginRequestsLock); - KdPrint((DRIVERNAME "Items count: %d\n", WdfCollectionGetCount(pFdoData->PendingPluginRequests))); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Current pending requests count: %d", + WdfCollectionGetCount(pFdoData->PendingPluginRequests)); status = WdfChildListAddOrUpdateChildDescriptionAsPresent(WdfFdoGetDefaultChildList(Device), &description.Header, NULL); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfChildListAddOrUpdateChildDescriptionAsPresent failed with 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfChildListAddOrUpdateChildDescriptionAsPresent failed with status %!STATUS!", + status); goto pluginEnd; } + // + // The requested serial number is already in use + // if (status == STATUS_OBJECT_NAME_EXISTS) { status = STATUS_INVALID_PARAMETER; + + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "The described PDO already exists (%!STATUS!)", + status); + goto pluginEnd; } @@ -168,7 +211,10 @@ NTSTATUS Bus_PlugInDevice( status = WdfObjectAllocateContext(Request, &requestAttribs, (PVOID)&pReqData); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfCollectionAdd failed with 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfObjectAllocateContext failed with status %!STATUS!", + status); goto pluginEnd; } @@ -178,24 +224,43 @@ NTSTATUS Bus_PlugInDevice( // pReqData->Serial = plugIn->SerialNo; + // + // Timestamp the request to track its age + // + pReqData->Timestamp = KeQueryPerformanceCounter(&pReqData->Frequency); + // // Keep track of pending request in collection // status = WdfCollectionAdd(pFdoData->PendingPluginRequests, Request); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfCollectionAdd failed with 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfCollectionAdd failed with status %!STATUS!", + status); goto pluginEnd; } - KdPrint((DRIVERNAME "Added item with serial: %d\n", plugIn->SerialNo)); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_BUSENUM, + "Added item with serial: %d", + plugIn->SerialNo); status = NT_SUCCESS(status) ? STATUS_PENDING : status; + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_BUSENUM, + "Status before releasing lock: %!STATUS!", + status); + pluginEnd: WdfSpinLockRelease(pFdoData->PendingPluginRequestsLock); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Exit with status %!STATUS!", status); + return status; } @@ -222,19 +287,25 @@ NTSTATUS Bus_UnPlugDevice( PAGED_CODE(); - KdPrint((DRIVERNAME "Entered Bus_UnPlugDevice\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Entry"); status = WdfRequestRetrieveInputBuffer(Request, sizeof(VIGEM_UNPLUG_TARGET), (PVOID)&unPlug, &length); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Bus_UnPlugDevice: WdfRequestRetrieveInputBuffer failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfRequestRetrieveInputBuffer failed with status %!STATUS!", + status); return status; } if ((sizeof(VIGEM_UNPLUG_TARGET) != unPlug->Size) || (length != unPlug->Size)) { - KdPrint((DRIVERNAME "Bus_UnPlugDevice: Input buffer size mismatch")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "sizeof(VIGEM_UNPLUG_TARGET) buffer size mismatch [%d != %d]", + sizeof(VIGEM_UNPLUG_TARGET), unPlug->Size); return STATUS_INVALID_PARAMETER; } @@ -246,18 +317,28 @@ NTSTATUS Bus_UnPlugDevice( fileObject = WdfRequestGetFileObject(Request); if (fileObject == NULL) { - KdPrint((DRIVERNAME "Bus_UnPlugDevice: File object associated with request is null")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfRequestGetFileObject failed to fetch WDFFILEOBJECT from request 0x%p", + Request); return STATUS_INVALID_PARAMETER; } pFileData = FileObjectGetData(fileObject); if (pFileData == NULL) { - KdPrint((DRIVERNAME "Bus_UnPlugDevice: File object context associated with request is null")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "FileObjectGetData failed to get context data for 0x%p", + fileObject); return STATUS_INVALID_PARAMETER; } } + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Starting child list traversal"); + list = WdfFdoGetDefaultChildList(Device); WDF_CHILD_LIST_ITERATOR_INIT(&iterator, WdfRetrievePresentChildren); @@ -274,21 +355,40 @@ NTSTATUS Bus_UnPlugDevice( // Error or no more children, end loop if (!NT_SUCCESS(status) || status == STATUS_NO_MORE_ENTRIES) { + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "WdfChildListRetrieveNextDevice returned with status %!STATUS!", + status); break; } // If unable to retrieve device if (childInfo.Status != WdfChildListRetrieveDeviceSuccess) { + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "childInfo.Status = %d", + childInfo.Status); continue; } // Child isn't the one we looked for, skip if (!unplugAll && description.SerialNo != unPlug->SerialNo) { + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Seeking serial mismatch: %d != %d", + description.SerialNo, + unPlug->SerialNo); continue; } + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "description.SessionId = %d, pFileData->SessionId = %d", + description.SessionId, + pFileData->SessionId); + // Only unplug owned children if (IsInternal || description.SessionId == pFileData->SessionId) { @@ -296,13 +396,22 @@ NTSTATUS Bus_UnPlugDevice( status = WdfChildListUpdateChildDescriptionAsMissing(list, &description.Header); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Bus_UnPlugDevice: WdfChildListUpdateChildDescriptionAsMissing failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfChildListUpdateChildDescriptionAsMissing failed with status %!STATUS!", + status); } } } WdfChildListEndIteration(list, &iterator); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Finished child list traversal"); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Exit with status %!STATUS!", STATUS_SUCCESS); + return STATUS_SUCCESS; } @@ -311,6 +420,8 @@ NTSTATUS Bus_UnPlugDevice( // NTSTATUS Bus_XusbSubmitReport(WDFDEVICE Device, ULONG SerialNo, PXUSB_SUBMIT_REPORT Report, BOOLEAN FromInterface) { + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSENUM, "%!FUNC! Entry"); + return Bus_SubmitReport(Device, SerialNo, Report, FromInterface); } @@ -326,14 +437,17 @@ NTSTATUS Bus_QueueNotification(WDFDEVICE Device, ULONG SerialNo, WDFREQUEST Requ PDS4_DEVICE_DATA ds4Data; - KdPrint((DRIVERNAME "Entered Bus_QueueNotification\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Entry"); hChild = Bus_GetPdo(Device, SerialNo); // Validate child if (hChild == NULL) { - KdPrint((DRIVERNAME "Bus_QueueNotification: PDO with serial %d not found\n", SerialNo)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "Bus_GetPdo: PDO with serial %d not found", + SerialNo); return STATUS_NO_SUCH_DEVICE; } @@ -341,14 +455,20 @@ NTSTATUS Bus_QueueNotification(WDFDEVICE Device, ULONG SerialNo, WDFREQUEST Requ pdoData = PdoGetData(hChild); if (pdoData == NULL) { - KdPrint((DRIVERNAME "Bus_QueueNotification: PDO context not found\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "PdoGetData failed"); return STATUS_INVALID_PARAMETER; } // Check if caller owns this PDO if (!IS_OWNER(pdoData)) { - KdPrint((DRIVERNAME "Bus_QueueNotification: PID mismatch: %d != %d\n", pdoData->OwnerProcessId, CURRENT_PROCESS_ID())); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "PDO & Request ownership mismatch: %d != %d", + pdoData->OwnerProcessId, + CURRENT_PROCESS_ID()); return STATUS_ACCESS_DENIED; } @@ -359,7 +479,13 @@ NTSTATUS Bus_QueueNotification(WDFDEVICE Device, ULONG SerialNo, WDFREQUEST Requ xusbData = XusbGetData(hChild); - if (xusbData == NULL) break; + if (xusbData == NULL) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "XusbGetData failed"); + break; + } status = WdfRequestForwardToIoQueue(Request, pdoData->PendingNotificationRequests); @@ -368,22 +494,40 @@ NTSTATUS Bus_QueueNotification(WDFDEVICE Device, ULONG SerialNo, WDFREQUEST Requ ds4Data = Ds4GetData(hChild); - if (ds4Data == NULL) break; + if (ds4Data == NULL) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "Ds4GetData failed"); + break; + } status = WdfRequestForwardToIoQueue(Request, pdoData->PendingNotificationRequests); break; default: status = STATUS_NOT_SUPPORTED; + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_BUSENUM, + "Unknown target type: %d (%!STATUS!)", + pdoData->TargetType, + status); break; } if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfRequestForwardToIoQueue failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "WdfRequestForwardToIoQueue failed with status %!STATUS!", + status); } - return (NT_SUCCESS(status)) ? STATUS_PENDING : status; + status = (NT_SUCCESS(status)) ? STATUS_PENDING : status; + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Exit with status %!STATUS!", status); + + return status; } // @@ -391,16 +535,22 @@ NTSTATUS Bus_QueueNotification(WDFDEVICE Device, ULONG SerialNo, WDFREQUEST Requ // NTSTATUS Bus_Ds4SubmitReport(WDFDEVICE Device, ULONG SerialNo, PDS4_SUBMIT_REPORT Report, BOOLEAN FromInterface) { + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSENUM, "%!FUNC! Entry"); + return Bus_SubmitReport(Device, SerialNo, Report, FromInterface); } NTSTATUS Bus_XgipSubmitReport(WDFDEVICE Device, ULONG SerialNo, PXGIP_SUBMIT_REPORT Report, BOOLEAN FromInterface) { + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSENUM, "%!FUNC! Entry"); + return Bus_SubmitReport(Device, SerialNo, Report, FromInterface); } NTSTATUS Bus_XgipSubmitInterrupt(WDFDEVICE Device, ULONG SerialNo, PXGIP_SUBMIT_INTERRUPT Report, BOOLEAN FromInterface) { + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSENUM, "%!FUNC! Entry"); + return Bus_SubmitReport(Device, SerialNo, Report, FromInterface); } @@ -432,14 +582,17 @@ NTSTATUS Bus_SubmitReport(WDFDEVICE Device, ULONG SerialNo, PVOID Report, BOOLEA BOOLEAN changed; - KdPrint((DRIVERNAME "Entered Bus_SubmitReport\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSENUM, "%!FUNC! Entry"); hChild = Bus_GetPdo(Device, SerialNo); // Validate child if (hChild == NULL) { - KdPrint((DRIVERNAME "Bus_SubmitReport: PDO with serial %d not found\n", SerialNo)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "Bus_GetPdo: PDO with serial %d not found", + SerialNo); return STATUS_NO_SUCH_DEVICE; } @@ -447,14 +600,20 @@ NTSTATUS Bus_SubmitReport(WDFDEVICE Device, ULONG SerialNo, PVOID Report, BOOLEA pdoData = PdoGetData(hChild); if (pdoData == NULL) { - KdPrint((DRIVERNAME "Bus_SubmitReport: PDO context not found\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "PdoGetData failed"); return STATUS_INVALID_PARAMETER; } // Check if caller owns this PDO if (!FromInterface && !IS_OWNER(pdoData)) { - KdPrint((DRIVERNAME "Bus_SubmitReport: PID mismatch: %d != %d\n", pdoData->OwnerProcessId, CURRENT_PROCESS_ID())); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSENUM, + "PDO & Request ownership mismatch: %d != %d", + pdoData->OwnerProcessId, + CURRENT_PROCESS_ID()); return STATUS_ACCESS_DENIED; } @@ -488,9 +647,17 @@ NTSTATUS Bus_SubmitReport(WDFDEVICE Device, ULONG SerialNo, PVOID Report, BOOLEA // Don't waste pending IRP if input hasn't changed if (!changed) + { + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Input report hasn't changed since last update, aborting with %!STATUS!", + status); return status; + } - KdPrint((DRIVERNAME "Bus_SubmitReport: received new report\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Received new report, processing"); // Get pending USB request switch (pdoData->TargetType) @@ -562,6 +729,13 @@ NTSTATUS Bus_SubmitReport(WDFDEVICE Device, ULONG SerialNo, PVOID Report, BOOLEA default: status = STATUS_NOT_SUPPORTED; + + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_BUSENUM, + "Unknown target type: %d (%!STATUS!)", + pdoData->TargetType, + status); + goto endSubmitReport; } @@ -570,7 +744,9 @@ NTSTATUS Bus_SubmitReport(WDFDEVICE Device, ULONG SerialNo, PVOID Report, BOOLEA else if (!NT_SUCCESS(status)) goto endSubmitReport; - KdPrint((DRIVERNAME "Bus_SubmitReport: pending IRP found\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSENUM, + "Processing pending IRP"); // Get pending IRP pendingIrp = WdfRequestWdmGetIrp(usbRequest); @@ -633,6 +809,9 @@ NTSTATUS Bus_SubmitReport(WDFDEVICE Device, ULONG SerialNo, PVOID Report, BOOLEA WdfRequestComplete(usbRequest, status); endSubmitReport: + + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSENUM, "%!FUNC! Exit with status %!STATUS!", status); + return status; } diff --git a/sys/busenum.h b/sys/busenum.h index 5c5b813..b115d9c 100644 --- a/sys/busenum.h +++ b/sys/busenum.h @@ -25,6 +25,7 @@ SOFTWARE. #pragma once +#include "trace.h" #include #include #define NTSTRSAFE_LIB @@ -57,6 +58,11 @@ SOFTWARE. #define DRIVERNAME "ViGEm: " #define MAX_HARDWARE_ID_LENGTH 0xFF +#define ORC_PC_FREQUENCY_DIVIDER 1000 +#define ORC_TIMER_START_DELAY 500 // ms +#define ORC_TIMER_PERIODIC_DUE_TIME 500 // ms +#define ORC_REQUEST_MAX_AGE 500 // ms + #pragma endregion #pragma region Helpers @@ -99,6 +105,10 @@ EVT_WDF_IO_QUEUE_IO_INTERNAL_DEVICE_CONTROL Pdo_EvtIoInternalDeviceControl; EVT_WDF_TIMER Xgip_SysInitTimerFunc; +EVT_WDF_OBJECT_CONTEXT_CLEANUP Bus_EvtDriverContextCleanup; + +EVT_WDF_TIMER Bus_PlugInRequestCleanUpEvtTimerFunc; + #pragma endregion #pragma region Bus enumeration-specific functions diff --git a/sys/buspdo.c b/sys/buspdo.c index 2d64789..d65a3d7 100644 --- a/sys/buspdo.c +++ b/sys/buspdo.c @@ -26,6 +26,7 @@ SOFTWARE. #include "busenum.h" #include #include +#include "buspdo.tmh" #ifdef ALLOC_PRAGMA #pragma alloc_text(PAGE, Bus_CreatePdo) @@ -101,7 +102,7 @@ NTSTATUS Bus_CreatePdo( PAGED_CODE(); - KdPrint((DRIVERNAME "Entered Bus_CreatePdo\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_DRIVER, "%!FUNC! Entry"); // // Get the FDO interface ASAP to report progress to bus @@ -114,7 +115,10 @@ NTSTATUS Bus_CreatePdo( NULL); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfFdoQueryForInterface failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfFdoQueryForInterface failed with status %!STATUS!", + status); return status; } @@ -128,7 +132,10 @@ NTSTATUS Bus_CreatePdo( status = WdfPdoInitAssignRawDevice(DeviceInit, &GUID_DEVCLASS_VIGEM_RAWPDO); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfPdoInitAssignRawDevice failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfPdoInitAssignRawDevice failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -137,7 +144,10 @@ NTSTATUS Bus_CreatePdo( status = WdfDeviceInitAssignSDDLString(DeviceInit, &SDDL_DEVOBJ_SYS_ALL_ADM_RWX_WORLD_RWX_RES_RWX); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceInitAssignSDDLString failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfDeviceInitAssignSDDLString failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -191,30 +201,60 @@ NTSTATUS Bus_CreatePdo( default: - KdPrint((DRIVERNAME "Unsupported target type\n")); status = STATUS_INVALID_PARAMETER; + + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "Unknown target type: %d (%!STATUS!)", + Description->TargetType, + status); + goto endCreatePdo; } // set device id status = WdfPdoInitAssignDeviceID(DeviceInit, &deviceId); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfPdoInitAssignDeviceID failed with status %!STATUS!", + status); goto endCreatePdo; + } // prepare instance id status = RtlUnicodeStringPrintf(&buffer, L"%02d", Description->SerialNo); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "RtlUnicodeStringPrintf failed with status %!STATUS!", + status); goto endCreatePdo; + } // set instance id status = WdfPdoInitAssignInstanceID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfPdoInitAssignInstanceID failed with status %!STATUS!", + status); goto endCreatePdo; + } // set device description (for English operating systems) status = WdfPdoInitAddDeviceText(DeviceInit, &deviceDescription, &deviceLocation, 0x409); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfPdoInitAddDeviceText failed with status %!STATUS!", + status); goto endCreatePdo; + } // default locale is English // TODO: add more locales @@ -242,9 +282,18 @@ NTSTATUS Bus_CreatePdo( status = WdfDeviceCreate(&DeviceInit, &pdoAttributes, &hChild); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfDeviceCreate failed with status %!STATUS!", + status); goto endCreatePdo; + } - KdPrint((DRIVERNAME "Created PDO: 0x%X\n", hChild)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + "Created PDO 0x%p", + hChild); switch (Description->TargetType) { @@ -257,7 +306,10 @@ NTSTATUS Bus_CreatePdo( status = WdfObjectAllocateContext(hChild, &pdoAttributes, (PVOID)&xusbData); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfObjectAllocateContext failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfObjectAllocateContext failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -271,7 +323,10 @@ NTSTATUS Bus_CreatePdo( status = WdfObjectAllocateContext(hChild, &pdoAttributes, (PVOID)&ds4Data); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfObjectAllocateContext failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfObjectAllocateContext failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -285,7 +340,10 @@ NTSTATUS Bus_CreatePdo( status = WdfObjectAllocateContext(hChild, &pdoAttributes, (PVOID)&xgipData); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfObjectAllocateContext failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfObjectAllocateContext failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -302,7 +360,10 @@ NTSTATUS Bus_CreatePdo( status = WdfDeviceCreateDeviceInterface(Device, (LPGUID)&GUID_DEVINTERFACE_USB_DEVICE, NULL); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceCreateDeviceInterface failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfDeviceCreateDeviceInterface failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -320,6 +381,15 @@ NTSTATUS Bus_CreatePdo( pdoData->VendorId = Description->VendorId; pdoData->ProductId = Description->ProductId; + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + "PDO Context properties: serial = %d, type = %d, pid = %d, vid = 0x%04X, pid = 0x%04X", + pdoData->SerialNo, + pdoData->TargetType, + pdoData->OwnerProcessId, + pdoData->VendorId, + pdoData->ProductId); + // Initialize additional contexts (if available) switch (Description->TargetType) { @@ -347,7 +417,11 @@ NTSTATUS Bus_CreatePdo( if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Couldn't initialize additional contexts\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "Couldn't initialize additional contexts: %!STATUS!", + status); + goto endCreatePdo; } @@ -364,7 +438,10 @@ NTSTATUS Bus_CreatePdo( status = WdfIoQueueCreate(Device, &usbInQueueConfig, WDF_NO_OBJECT_ATTRIBUTES, &pdoData->PendingUsbInRequests); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate (PendingUsbInRequests) failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfIoQueueCreate (PendingUsbInRequests) failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -374,7 +451,10 @@ NTSTATUS Bus_CreatePdo( status = WdfIoQueueCreate(Device, ¬ificationsQueueConfig, WDF_NO_OBJECT_ATTRIBUTES, &pdoData->PendingNotificationRequests); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate (PendingNotificationRequests) failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfIoQueueCreate (PendingNotificationRequests) failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -389,7 +469,10 @@ NTSTATUS Bus_CreatePdo( status = WdfIoQueueCreate(hChild, &defaultPdoQueueConfig, WDF_NO_OBJECT_ATTRIBUTES, &defaultPdoQueue); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_BUSPDO, + "WdfIoQueueCreate (Default) failed with status %!STATUS!", + status); goto endCreatePdo; } @@ -430,10 +513,15 @@ NTSTATUS Bus_CreatePdo( #pragma endregion endCreatePdo: - KdPrint((DRIVERNAME "BUS_PDO_REPORT_STAGE_RESULT Stage: ViGEmPdoCreate, Serial: 0x%X, Status: 0x%X (%d)\n", - Description->SerialNo, status, NT_SUCCESS(status))); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_BUSPDO, + "BUS_PDO_REPORT_STAGE_RESULT Stage: ViGEmPdoCreate [serial: %d, status: %!STATUS!]", + Description->SerialNo, status); BUS_PDO_REPORT_STAGE_RESULT(busInterface, ViGEmPdoCreate, Description->SerialNo, status); + + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSPDO, "%!FUNC! Exit with status %!STATUS!", status); + return status; } @@ -454,7 +542,7 @@ NTSTATUS Bus_EvtDevicePrepareHardware( UNREFERENCED_PARAMETER(ResourcesRaw); UNREFERENCED_PARAMETER(ResourcesTranslated); - KdPrint((DRIVERNAME "Bus_EvtDevicePrepareHardware: 0x%p\n", Device)); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSENUM, "%!FUNC! Entry"); pdoData = PdoGetData(Device); @@ -483,8 +571,15 @@ NTSTATUS Bus_EvtDevicePrepareHardware( break; } + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_BUSPDO, + "BUS_PDO_REPORT_STAGE_RESULT Stage: ViGEmPdoCreate [serial: %d, status: %!STATUS!]", + pdoData->SerialNo, status); + BUS_PDO_REPORT_STAGE_RESULT(pdoData->BusInterface, ViGEmPdoPrepareHardware, pdoData->SerialNo, status); + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_BUSPDO, "%!FUNC! Exit with status %!STATUS!", status); + return status; } @@ -510,6 +605,9 @@ VOID Pdo_EvtIoInternalDeviceControl( PPDO_DEVICE_DATA pdoData; PIO_STACK_LOCATION irpStack; + + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSPDO, "%!FUNC! Entry"); + hDevice = WdfIoQueueGetDevice(Queue); pdoData = PdoGetData(hDevice); // No help from the framework available from here on @@ -520,7 +618,9 @@ VOID Pdo_EvtIoInternalDeviceControl( { case IOCTL_INTERNAL_USB_SUBMIT_URB: - KdPrint((DRIVERNAME ">> IOCTL_INTERNAL_USB_SUBMIT_URB\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> IOCTL_INTERNAL_USB_SUBMIT_URB"); urb = (PURB)URB_FROM_IRP(irp); @@ -528,7 +628,9 @@ VOID Pdo_EvtIoInternalDeviceControl( { case URB_FUNCTION_CONTROL_TRANSFER: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_CONTROL_TRANSFER\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_CONTROL_TRANSFER"); switch (urb->UrbControlTransfer.SetupPacket[6]) { @@ -564,7 +666,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_CONTROL_TRANSFER_EX: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_CONTROL_TRANSFER_EX\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_CONTROL_TRANSFER_EX"); status = STATUS_UNSUCCESSFUL; @@ -572,7 +676,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER"); status = UsbPdo_BulkOrInterruptTransfer(urb, hDevice, Request); @@ -580,7 +686,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_SELECT_CONFIGURATION: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_SELECT_CONFIGURATION\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_SELECT_CONFIGURATION"); status = UsbPdo_SelectConfiguration(urb, pdoData); @@ -588,7 +696,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_SELECT_INTERFACE: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_SELECT_INTERFACE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_SELECT_INTERFACE"); status = UsbPdo_SelectInterface(urb, pdoData); @@ -596,13 +706,17 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_GET_DESCRIPTOR_FROM_DEVICE: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_GET_DESCRIPTOR_FROM_DEVICE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_GET_DESCRIPTOR_FROM_DEVICE"); switch (urb->UrbControlDescriptorRequest.DescriptorType) { case USB_DEVICE_DESCRIPTOR_TYPE: - KdPrint((DRIVERNAME ">> >> >> USB_DEVICE_DESCRIPTOR_TYPE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> >> USB_DEVICE_DESCRIPTOR_TYPE"); status = UsbPdo_GetDeviceDescriptorType(urb, pdoData); @@ -610,7 +724,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case USB_CONFIGURATION_DESCRIPTOR_TYPE: - KdPrint((DRIVERNAME ">> >> >> USB_CONFIGURATION_DESCRIPTOR_TYPE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> >> USB_CONFIGURATION_DESCRIPTOR_TYPE"); status = UsbPdo_GetConfigurationDescriptorType(urb, pdoData); @@ -618,35 +734,49 @@ VOID Pdo_EvtIoInternalDeviceControl( case USB_STRING_DESCRIPTOR_TYPE: - KdPrint((DRIVERNAME ">> >> >> USB_STRING_DESCRIPTOR_TYPE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> >> USB_STRING_DESCRIPTOR_TYPE"); status = UsbPdo_GetStringDescriptorType(urb, pdoData); break; case USB_INTERFACE_DESCRIPTOR_TYPE: - KdPrint((DRIVERNAME ">> >> >> USB_INTERFACE_DESCRIPTOR_TYPE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> >> USB_INTERFACE_DESCRIPTOR_TYPE"); break; case USB_ENDPOINT_DESCRIPTOR_TYPE: - KdPrint((DRIVERNAME ">> >> >> USB_ENDPOINT_DESCRIPTOR_TYPE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> >> USB_ENDPOINT_DESCRIPTOR_TYPE"); break; default: - KdPrint((DRIVERNAME ">> >> >> Unknown descriptor type\n")); + + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> >> Unknown descriptor type"); + break; } - KdPrint((DRIVERNAME "<< <<\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + "<< <<"); break; case URB_FUNCTION_GET_STATUS_FROM_DEVICE: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_GET_STATUS_FROM_DEVICE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_GET_STATUS_FROM_DEVICE"); // Defaults always succeed status = STATUS_SUCCESS; @@ -655,7 +785,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_ABORT_PIPE: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_ABORT_PIPE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_ABORT_PIPE"); status = UsbPdo_AbortPipe(hDevice); @@ -663,7 +795,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_CLASS_INTERFACE: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_CLASS_INTERFACE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_CLASS_INTERFACE"); status = UsbPdo_ClassInterface(urb, hDevice, pdoData); @@ -671,7 +805,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case URB_FUNCTION_GET_DESCRIPTOR_FROM_INTERFACE: - KdPrint((DRIVERNAME ">> >> URB_FUNCTION_GET_DESCRIPTOR_FROM_INTERFACE\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> URB_FUNCTION_GET_DESCRIPTOR_FROM_INTERFACE"); status = UsbPdo_GetDescriptorFromInterface(urb, pdoData); @@ -694,17 +830,26 @@ VOID Pdo_EvtIoInternalDeviceControl( break; default: - KdPrint((DRIVERNAME ">> >> Unknown function: 0x%X\n", urb->UrbHeader.Function)); + + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> >> Unknown function: 0x%X", + urb->UrbHeader.Function); + break; } - KdPrint((DRIVERNAME "<<\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + "<<"); break; case IOCTL_INTERNAL_USB_GET_PORT_STATUS: - KdPrint((DRIVERNAME ">> IOCTL_INTERNAL_USB_GET_PORT_STATUS\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> IOCTL_INTERNAL_USB_GET_PORT_STATUS"); // We report the (virtual) port as always active *(unsigned long *)irpStack->Parameters.Others.Argument1 = USBD_PORT_ENABLED | USBD_PORT_CONNECTED; @@ -715,7 +860,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case IOCTL_INTERNAL_USB_RESET_PORT: - KdPrint((DRIVERNAME ">> IOCTL_INTERNAL_USB_RESET_PORT\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> IOCTL_INTERNAL_USB_RESET_PORT"); // Sure, why not ;) status = STATUS_SUCCESS; @@ -724,7 +871,9 @@ VOID Pdo_EvtIoInternalDeviceControl( case IOCTL_INTERNAL_USB_SUBMIT_IDLE_NOTIFICATION: - KdPrint((DRIVERNAME ">> IOCTL_INTERNAL_USB_SUBMIT_IDLE_NOTIFICATION\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> IOCTL_INTERNAL_USB_SUBMIT_IDLE_NOTIFICATION"); // TODO: implement // This happens if the I/O latency is too high so HIDUSB aborts communication. @@ -733,7 +882,12 @@ VOID Pdo_EvtIoInternalDeviceControl( break; default: - KdPrint((DRIVERNAME ">> Unknown I/O control code 0x%X\n", IoControlCode)); + + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_BUSPDO, + ">> Unknown I/O control code 0x%X", + IoControlCode); + break; } @@ -741,5 +895,7 @@ VOID Pdo_EvtIoInternalDeviceControl( { WdfRequestComplete(Request, status); } + + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_BUSPDO, "%!FUNC! Exit with status %!STATUS!", status); } diff --git a/sys/trace.h b/sys/trace.h new file mode 100644 index 0000000..d67e89f --- /dev/null +++ b/sys/trace.h @@ -0,0 +1,61 @@ +/*++ + +Module Name: + + Trace.h + +Abstract: + + Header file for the debug tracing related function defintions and macros. + +Environment: + + Kernel mode + +--*/ + +// +// Define the tracing flags. +// +// Tracing GUID - c5ce18fe-27bd-4049-b0b4-8a47cab1dcd9 +// + +#define WPP_CONTROL_GUIDS \ + WPP_DEFINE_CONTROL_GUID( \ + ViGEmBusTraceGuid, (c5ce18fe,27bd,4049,b0b4,8a47cab1dcd9), \ + \ + WPP_DEFINE_BIT(MYDRIVER_ALL_INFO) \ + WPP_DEFINE_BIT(TRACE_BUSENUM) \ + WPP_DEFINE_BIT(TRACE_BUSPDO) \ + WPP_DEFINE_BIT(TRACE_BYTEARRAY) \ + WPP_DEFINE_BIT(TRACE_DRIVER) \ + WPP_DEFINE_BIT(TRACE_DS4) \ + WPP_DEFINE_BIT(TRACE_QUEUE) \ + WPP_DEFINE_BIT(TRACE_USBPDO) \ + WPP_DEFINE_BIT(TRACE_UTIL) \ + WPP_DEFINE_BIT(TRACE_XGIP) \ + WPP_DEFINE_BIT(TRACE_XUSB) \ + ) + +#define WPP_FLAG_LEVEL_LOGGER(flag, level) \ + WPP_LEVEL_LOGGER(flag) + +#define WPP_FLAG_LEVEL_ENABLED(flag, level) \ + (WPP_LEVEL_ENABLED(flag) && \ + WPP_CONTROL(WPP_BIT_ ## flag).Level >= level) + +#define WPP_LEVEL_FLAGS_LOGGER(lvl,flags) \ + WPP_LEVEL_LOGGER(flags) + +#define WPP_LEVEL_FLAGS_ENABLED(lvl, flags) \ + (WPP_LEVEL_ENABLED(flags) && WPP_CONTROL(WPP_BIT_ ## flags).Level >= lvl) + +// +// This comment block is scanned by the trace preprocessor to define our +// Trace function. +// +// begin_wpp config +// FUNC Trace{FLAG=MYDRIVER_ALL_INFO}(LEVEL, MSG, ...); +// FUNC TraceEvents(LEVEL, FLAGS, MSG, ...); +// end_wpp +// diff --git a/sys/usbpdo.c b/sys/usbpdo.c index a3bb46e..f43b073 100644 --- a/sys/usbpdo.c +++ b/sys/usbpdo.c @@ -24,6 +24,7 @@ SOFTWARE. #include "busenum.h" +#include "usbpdo.tmh" // @@ -33,7 +34,9 @@ BOOLEAN USB_BUSIFFN UsbPdo_IsDeviceHighSpeed(IN PVOID BusContext) { UNREFERENCED_PARAMETER(BusContext); - KdPrint((DRIVERNAME "UsbPdo_IsDeviceHighSpeed: TRUE\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_USBPDO, + "IsDeviceHighSpeed: TRUE"); return TRUE; } @@ -55,7 +58,10 @@ NTSTATUS USB_BUSIFFN UsbPdo_QueryBusInformation( UNREFERENCED_PARAMETER(BusInformationBufferLength); UNREFERENCED_PARAMETER(BusInformationActualLength); - KdPrint((DRIVERNAME "UsbPdo_QueryBusInformation: STATUS_UNSUCCESSFUL\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_USBPDO, + "QueryBusInformation: %!STATUS!", STATUS_UNSUCCESSFUL); + return STATUS_UNSUCCESSFUL; } @@ -67,7 +73,10 @@ NTSTATUS USB_BUSIFFN UsbPdo_SubmitIsoOutUrb(IN PVOID BusContext, IN PURB Urb) UNREFERENCED_PARAMETER(BusContext); UNREFERENCED_PARAMETER(Urb); - KdPrint((DRIVERNAME "UsbPdo_SubmitIsoOutUrb: STATUS_UNSUCCESSFUL\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_USBPDO, + "SubmitIsoOutUrb: %!STATUS!", STATUS_UNSUCCESSFUL); + return STATUS_UNSUCCESSFUL; } @@ -79,7 +88,10 @@ NTSTATUS USB_BUSIFFN UsbPdo_QueryBusTime(IN PVOID BusContext, IN OUT PULONG Curr UNREFERENCED_PARAMETER(BusContext); UNREFERENCED_PARAMETER(CurrentUsbFrame); - KdPrint((DRIVERNAME "UsbPdo_QueryBusTime: STATUS_UNSUCCESSFUL\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_USBPDO, + "QueryBusTime: %!STATUS!", STATUS_UNSUCCESSFUL); + return STATUS_UNSUCCESSFUL; } @@ -94,7 +106,9 @@ VOID USB_BUSIFFN UsbPdo_GetUSBDIVersion( { UNREFERENCED_PARAMETER(BusContext); - KdPrint((DRIVERNAME "UsbPdo_GetUSBDIVersion: 0x500, 0x200\n")); + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_USBPDO, + "GetUSBDIVersion: 0x500, 0x200"); if (VersionInformation != NULL) { @@ -217,7 +231,10 @@ NTSTATUS UsbPdo_GetConfigurationDescriptorType(PURB urb, PPDO_DEVICE_DATA pCommo // NTSTATUS UsbPdo_GetStringDescriptorType(PURB urb, PPDO_DEVICE_DATA pCommon) { - KdPrint((DRIVERNAME "Index = %d\n", urb->UrbControlDescriptorRequest.Index)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + "Index = %d", + urb->UrbControlDescriptorRequest.Index); switch (pCommon->TargetType) { @@ -240,7 +257,10 @@ NTSTATUS UsbPdo_GetStringDescriptorType(PURB urb, PPDO_DEVICE_DATA pCommon) } case 1: { - KdPrint((DRIVERNAME "LanguageId = 0x%X\n", urb->UrbControlDescriptorRequest.LanguageId)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + "LanguageId = 0x%X", + urb->UrbControlDescriptorRequest.LanguageId); if (urb->UrbControlDescriptorRequest.TransferBufferLength < DS4_MANUFACTURER_NAME_LENGTH) { @@ -268,7 +288,10 @@ NTSTATUS UsbPdo_GetStringDescriptorType(PURB urb, PPDO_DEVICE_DATA pCommon) } case 2: { - KdPrint((DRIVERNAME "LanguageId = 0x%X\n", urb->UrbControlDescriptorRequest.LanguageId)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + "LanguageId = 0x%X", + urb->UrbControlDescriptorRequest.LanguageId); if (urb->UrbControlDescriptorRequest.TransferBufferLength < DS4_PRODUCT_NAME_LENGTH) { @@ -314,11 +337,16 @@ NTSTATUS UsbPdo_SelectConfiguration(PURB urb, PPDO_DEVICE_DATA pCommon) pInfo = &urb->UrbSelectConfiguration.Interface; - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: TotalLength %d\n", urb->UrbHeader.Length)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: TotalLength %d", + urb->UrbHeader.Length); if (urb->UrbHeader.Length == sizeof(struct _URB_SELECT_CONFIGURATION)) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: NULL ConfigurationDescriptor\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: NULL ConfigurationDescriptor"); return STATUS_SUCCESS; } @@ -328,7 +356,9 @@ NTSTATUS UsbPdo_SelectConfiguration(PURB urb, PPDO_DEVICE_DATA pCommon) if (urb->UrbHeader.Length < XUSB_CONFIGURATION_SIZE) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Invalid ConfigurationDescriptor\n")); + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Invalid ConfigurationDescriptor"); return STATUS_INVALID_PARAMETER; } @@ -340,7 +370,9 @@ NTSTATUS UsbPdo_SelectConfiguration(PURB urb, PPDO_DEVICE_DATA pCommon) if (urb->UrbHeader.Length < DS4_CONFIGURATION_SIZE) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Invalid ConfigurationDescriptor\n")); + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Invalid ConfigurationDescriptor"); return STATUS_INVALID_PARAMETER; } @@ -352,7 +384,9 @@ NTSTATUS UsbPdo_SelectConfiguration(PURB urb, PPDO_DEVICE_DATA pCommon) if (urb->UrbHeader.Length < XGIP_CONFIGURATION_SIZE) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Invalid ConfigurationDescriptor\n")); + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Invalid ConfigurationDescriptor"); return STATUS_INVALID_PARAMETER; } @@ -374,16 +408,20 @@ NTSTATUS UsbPdo_SelectInterface(PURB urb, PPDO_DEVICE_DATA pCommon) { PUSBD_INTERFACE_INFORMATION pInfo = &urb->UrbSelectInterface.Interface; - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_INTERFACE: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_INTERFACE: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_INTERFACE: Class %d, SubClass %d, Protocol %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_SELECT_INTERFACE: Class %d, SubClass %d, Protocol %d", (int)pInfo->Class, (int)pInfo->SubClass, - (int)pInfo->Protocol)); + (int)pInfo->Protocol); switch (pCommon->TargetType) { @@ -455,7 +493,10 @@ NTSTATUS UsbPdo_SelectInterface(PURB urb, PPDO_DEVICE_DATA pCommon) } case DualShock4Wired: { - KdPrint((DRIVERNAME "Warning: not implemented\n")); + TraceEvents(TRACE_LEVEL_WARNING, + TRACE_USBPDO, + "Not implemented"); + break; } default: @@ -479,7 +520,9 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R if (pdoData == NULL) { - KdPrint((DRIVERNAME ">> >> >> Invalid common context\n")); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_USBPDO, + ">> >> >> PdoGetData failed"); return STATUS_INVALID_PARAMETER; } @@ -492,7 +535,10 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R // Check context if (xusb == NULL) { - KdPrint((DRIVERNAME "No XUSB context found on device %p\n", Device)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_USBPDO, + "No XUSB context found on device %p", + Device); return STATUS_UNSUCCESSFUL; } @@ -500,7 +546,9 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R // Data coming FROM us TO higher driver if (pTransfer->TransferFlags & USBD_TRANSFER_DIRECTION_IN) { - KdPrint((DRIVERNAME ">> >> >> Incoming request, queuing...\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> Incoming request, queuing..."); if (XUSB_IS_DATA_PIPE(pTransfer)) { @@ -584,16 +632,21 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R } // Data coming FROM the higher driver TO us - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER: Handle %p, Flags %X, Length %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER: Handle %p, Flags %X, Length %d", pTransfer->PipeHandle, pTransfer->TransferFlags, - pTransfer->TransferBufferLength)); + pTransfer->TransferBufferLength); if (pTransfer->TransferBufferLength == XUSB_LEDSET_SIZE) // Led { PUCHAR Buffer = pTransfer->TransferBuffer; - KdPrint((DRIVERNAME "-- LED Buffer: %02X %02X %02X\n", Buffer[0], Buffer[1], Buffer[2])); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + "-- LED Buffer: %02X %02X %02X", + Buffer[0], Buffer[1], Buffer[2]); // extract LED byte to get controller slot if (Buffer[0] == 0x01 && Buffer[1] == 0x03 && Buffer[2] >= 0x02) @@ -603,8 +656,10 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R if (Buffer[2] == 0x04) xusb->LedNumber = 2; if (Buffer[2] == 0x05) xusb->LedNumber = 3; - KdPrint((DRIVERNAME "-- LED Number: %d\n", xusb->LedNumber)); - + TraceEvents(TRACE_LEVEL_INFORMATION, + TRACE_USBPDO, + "-- LED Number: %d", + xusb->LedNumber); // // Report back to FDO that we are ready to operate // @@ -622,7 +677,9 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R { PUCHAR Buffer = pTransfer->TransferBuffer; - KdPrint((DRIVERNAME "-- Rumble Buffer: %02X %02X %02X %02X %02X %02X %02X %02X\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + "-- Rumble Buffer: %02X %02X %02X %02X %02X %02X %02X %02X", Buffer[0], Buffer[1], Buffer[2], @@ -630,14 +687,14 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R Buffer[4], Buffer[5], Buffer[6], - Buffer[7])); + Buffer[7]); RtlCopyBytes(xusb->Rumble, Buffer, pTransfer->TransferBufferLength); } // Notify user-mode process that new data is available status = WdfIoQueueRetrieveNextRequest(pdoData->PendingNotificationRequests, ¬ifyRequest); - + if (NT_SUCCESS(status)) { PXUSB_REQUEST_NOTIFICATION notify = NULL; @@ -657,7 +714,10 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R } else { - KdPrint((DRIVERNAME "WdfRequestRetrieveOutputBuffer failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_USBPDO, + "WdfRequestRetrieveOutputBuffer failed with status %!STATUS!", + status); } } @@ -671,7 +731,9 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R if (pTransfer->TransferFlags & USBD_TRANSFER_DIRECTION_IN && pTransfer->PipeHandle == (USBD_PIPE_HANDLE)0xFFFF0084) { - // KdPrint((DRIVERNAME ">> >> >> Incoming request, queuing...\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> Incoming request, queuing..."); /* This request is sent periodically and relies on data the "feeder" has to supply, so we queue this request and return with STATUS_PENDING. @@ -706,7 +768,10 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R } else { - KdPrint((DRIVERNAME "WdfRequestRetrieveOutputBuffer failed with status 0x%X\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_USBPDO, + "WdfRequestRetrieveOutputBuffer failed with status %!STATUS!", + status); } } @@ -719,7 +784,7 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R // Data coming FROM us TO higher driver if (pTransfer->TransferFlags & USBD_TRANSFER_DIRECTION_IN) { - KdPrint((DRIVERNAME ">> >> >> Incoming request, queuing...\n")); + KdPrint((DRIVERNAME ">> >> >> Incoming request, queuing...")); /* This request is sent periodically and relies on data the "feeder" has to supply, so we queue this request and return with STATUS_PENDING. @@ -730,7 +795,7 @@ NTSTATUS UsbPdo_BulkOrInterruptTransfer(PURB urb, WDFDEVICE Device, WDFREQUEST R } // Data coming FROM the higher driver TO us - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER: Handle %p, Flags %X, Length %d\n", + KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_BULK_OR_INTERRUPT_TRANSFER: Handle %p, Flags %X, Length %d", pTransfer->PipeHandle, pTransfer->TransferFlags, pTransfer->TransferBufferLength)); @@ -760,7 +825,9 @@ NTSTATUS UsbPdo_AbortPipe(WDFDEVICE Device) // Check context if (ds4 == NULL) { - KdPrint((DRIVERNAME "No DS4 context found on device %p\n", Device)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_USBPDO, + "No DS4 context found on device %p", Device); return STATUS_UNSUCCESSFUL; } @@ -788,13 +855,17 @@ NTSTATUS UsbPdo_ClassInterface(PURB urb, WDFDEVICE Device, PPDO_DEVICE_DATA pCom { struct _URB_CONTROL_VENDOR_OR_CLASS_REQUEST* pRequest = &urb->UrbControlVendorClassRequest; - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_CLASS_INTERFACE\n")); - KdPrint((DRIVERNAME ">> >> >> TransferFlags = 0x%X, Request = 0x%X, Value = 0x%X, Index = 0x%X, BufLen = %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> URB_FUNCTION_CLASS_INTERFACE"); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> TransferFlags = 0x%X, Request = 0x%X, Value = 0x%X, Index = 0x%X, BufLen = %d", pRequest->TransferFlags, pRequest->Request, pRequest->Value, pRequest->Index, - pRequest->TransferBufferLength)); + pRequest->TransferBufferLength); switch (pCommon->TargetType) { @@ -809,7 +880,10 @@ NTSTATUS UsbPdo_ClassInterface(PURB urb, WDFDEVICE Device, PPDO_DEVICE_DATA pCom UCHAR reportId = HID_GET_REPORT_ID(pRequest); UCHAR reportType = HID_GET_REPORT_TYPE(pRequest); - KdPrint((DRIVERNAME ">> >> >> >> GET_REPORT(%d): %d\n", reportType, reportId)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> >> GET_REPORT(%d): %d", + reportType, reportId); switch (reportType) { @@ -893,7 +967,10 @@ NTSTATUS UsbPdo_ClassInterface(PURB urb, WDFDEVICE Device, PPDO_DEVICE_DATA pCom UCHAR reportId = HID_GET_REPORT_ID(pRequest); UCHAR reportType = HID_GET_REPORT_TYPE(pRequest); - KdPrint((DRIVERNAME ">> >> >> >> SET_REPORT(%d): %d\n", reportType, reportId)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> >> SET_REPORT(%d): %d", + reportType, reportId); switch (reportType) { @@ -1195,7 +1272,10 @@ NTSTATUS UsbPdo_GetDescriptorFromInterface(PURB urb, PPDO_DEVICE_DATA pCommon) struct _URB_CONTROL_DESCRIPTOR_REQUEST* pRequest = &urb->UrbControlDescriptorRequest; - KdPrint((DRIVERNAME ">> >> >> _URB_CONTROL_DESCRIPTOR_REQUEST: Buffer Length %d\n", pRequest->TransferBufferLength)); + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_USBPDO, + ">> >> >> _URB_CONTROL_DESCRIPTOR_REQUEST: Buffer Length %d", + pRequest->TransferBufferLength); switch (pCommon->TargetType) { diff --git a/sys/util.c b/sys/util.c index 0d6b7bc..3ebc372 100644 --- a/sys/util.c +++ b/sys/util.c @@ -25,6 +25,7 @@ SOFTWARE. #include #include "busenum.h" +#include "util.tmh" VOID ReverseByteArray(PUCHAR Array, INT Length) diff --git a/sys/xgip.c b/sys/xgip.c index 6c42d3f..387d26a 100644 --- a/sys/xgip.c +++ b/sys/xgip.c @@ -24,6 +24,7 @@ SOFTWARE. #include "busenum.h" +#include "xgip.tmh" NTSTATUS Xgip_PreparePdo(PWDFDEVICE_INIT DeviceInit, PUNICODE_STRING DeviceId, PUNICODE_STRING DeviceDescription) { @@ -104,7 +105,7 @@ NTSTATUS Xgip_PrepareHardware(WDFDEVICE Device) status = WdfDeviceAddQueryInterface(Device, &ifaceCfg); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceAddQueryInterface failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, TRACE_XGIP, "WdfDeviceAddQueryInterface failed with status %!STATUS!", status); return status; } @@ -127,7 +128,7 @@ NTSTATUS Xgip_AssignPdoContext(WDFDEVICE Device) PXGIP_DEVICE_DATA xgip = XgipGetData(Device); - KdPrint((DRIVERNAME "Initializing XGIP context...\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_XGIP, "Initializing XGIP context..."); RtlZeroMemory(xgip, sizeof(XGIP_DEVICE_DATA)); @@ -144,7 +145,7 @@ NTSTATUS Xgip_AssignPdoContext(WDFDEVICE Device) status = WdfIoQueueCreate(Device, &pendingUsbQueueConfig, WDF_NO_OBJECT_ATTRIBUTES, &xgip->PendingUsbInRequests); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, TRACE_XGIP, "WdfIoQueueCreate failed with status %!STATUS!", status); return status; } @@ -154,7 +155,7 @@ NTSTATUS Xgip_AssignPdoContext(WDFDEVICE Device) status = WdfIoQueueCreate(Device, ¬ificationsQueueConfig, WDF_NO_OBJECT_ATTRIBUTES, &xgip->PendingNotificationRequests); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, TRACE_XGIP, "WdfIoQueueCreate failed with status %!STATUS!", status); return status; } @@ -166,7 +167,7 @@ NTSTATUS Xgip_AssignPdoContext(WDFDEVICE Device) status = WdfCollectionCreate(&collectionAttribs, &xgip->XboxgipSysInitCollection); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfCollectionCreate failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, TRACE_XGIP, "WdfCollectionCreate failed with status %!STATUS!", status); return status; } @@ -185,7 +186,7 @@ NTSTATUS Xgip_AssignPdoContext(WDFDEVICE Device) status = WdfTimerCreate(&timerConfig, &timerAttribs, &xgip->XboxgipSysInitTimer); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfTimerCreate failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, TRACE_XGIP, "WdfTimerCreate failed with status %!STATUS!", status); return status; } @@ -291,11 +292,11 @@ VOID Xgip_GetDeviceDescriptorType(PUSB_DEVICE_DESCRIPTOR pDescriptor, PPDO_DEVIC VOID Xgip_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_XGIP, ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0xFF; pInfo->SubClass = 0x47; @@ -321,11 +322,11 @@ VOID Xgip_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) pInfo = (PUSBD_INTERFACE_INFORMATION)((PCHAR)pInfo + pInfo->Length); - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_XGIP, ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0xFF; pInfo->SubClass = 0x47; @@ -354,14 +355,14 @@ VOID Xgip_SysInitTimerFunc( // Is TRUE when collection is filled up if (xgip->XboxgipSysInitReady) { - KdPrint((DRIVERNAME "XBOXGIP ready, completing requests...\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_XGIP, "XBOXGIP ready, completing requests..."); // Get pending IN request status = WdfIoQueueRetrieveNextRequest(xgip->PendingUsbInRequests, &usbRequest); if (NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Request found\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_XGIP, "Request found"); // Get top memory object mem = (WDFMEMORY)WdfCollectionGetFirstItem(xgip->XboxgipSysInitCollection); @@ -381,9 +382,9 @@ VOID Xgip_SysInitTimerFunc( urb->UrbBulkOrInterruptTransfer.TransferBufferLength = (ULONG)size; RtlCopyBytes(urb->UrbBulkOrInterruptTransfer.TransferBuffer, Buffer, size); - KdPrint((DRIVERNAME "[%X] Buffer length: %d\n", + TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_XGIP, "[%X] Buffer length: %d", ((PUCHAR)urb->UrbBulkOrInterruptTransfer.TransferBuffer)[0], - urb->UrbBulkOrInterruptTransfer.TransferBufferLength)); + urb->UrbBulkOrInterruptTransfer.TransferBufferLength); // Complete pending request WdfRequestComplete(usbRequest, status); @@ -396,7 +397,7 @@ VOID Xgip_SysInitTimerFunc( // Stop timer when collection is purged if (WdfCollectionGetCount(xgip->XboxgipSysInitCollection) == 0) { - KdPrint((DRIVERNAME "Collection finished\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_XGIP, "Collection finished"); WdfTimerStop(xgip->XboxgipSysInitTimer, FALSE); } diff --git a/sys/xusb.c b/sys/xusb.c index 5ca15f9..0e01225 100644 --- a/sys/xusb.c +++ b/sys/xusb.c @@ -24,6 +24,7 @@ SOFTWARE. #include "busenum.h" +#include "xusb.tmh" NTSTATUS Xusb_PreparePdo( PWDFDEVICE_INIT DeviceInit, @@ -38,7 +39,13 @@ NTSTATUS Xusb_PreparePdo( // prepare device description status = RtlUnicodeStringInit(DeviceDescription, L"Virtual Xbox 360 Controller"); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "RtlUnicodeStringInit failed with status %!STATUS!", + status); return status; + } // Set hardware ID RtlUnicodeStringPrintf(&buffer, L"USB\\VID_%04X&PID_%04X", VendorId, ProductId); @@ -47,32 +54,63 @@ NTSTATUS Xusb_PreparePdo( status = WdfPdoInitAddHardwareID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfPdoInitAddHardwareID failed with status %!STATUS!", + status); return status; + } + // Set compatible IDs RtlUnicodeStringInit(&buffer, L"USB\\MS_COMP_XUSB10"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfPdoInitAddCompatibleID #1 failed with status %!STATUS!", + status); return status; + } RtlUnicodeStringInit(&buffer, L"USB\\Class_FF&SubClass_5D&Prot_01"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfPdoInitAddCompatibleID #2 failed with status %!STATUS!", + status); return status; + } RtlUnicodeStringInit(&buffer, L"USB\\Class_FF&SubClass_5D"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfPdoInitAddCompatibleID #3 failed with status %!STATUS!", + status); return status; + } RtlUnicodeStringInit(&buffer, L"USB\\Class_FF"); status = WdfPdoInitAddCompatibleID(DeviceInit, &buffer); if (!NT_SUCCESS(status)) + { + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfPdoInitAddCompatibleID #4 failed with status %!STATUS!", + status); return status; + } return STATUS_SUCCESS; } @@ -101,7 +139,10 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) status = WdfDeviceAddQueryInterface(Device, &ifaceCfg); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Couldn't register unknown interface GUID: %08X-%04X-%04X-%02X%02X%02X%02X%02X%02X%02X%02X (status 0x%x)\n", + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "Couldn't register unknown interface GUID: %08X-%04X-%04X-%02X%02X%02X%02X%02X%02X%02X%02X " \ + "(WdfDeviceAddQueryInterface failed with status %!STATUS!)", GUID_DEVINTERFACE_XUSB_UNKNOWN_0.Data1, GUID_DEVINTERFACE_XUSB_UNKNOWN_0.Data2, GUID_DEVINTERFACE_XUSB_UNKNOWN_0.Data3, @@ -113,7 +154,7 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) GUID_DEVINTERFACE_XUSB_UNKNOWN_0.Data4[5], GUID_DEVINTERFACE_XUSB_UNKNOWN_0.Data4[6], GUID_DEVINTERFACE_XUSB_UNKNOWN_0.Data4[7], - status)); + status); return status; } @@ -125,7 +166,10 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) status = WdfDeviceAddQueryInterface(Device, &ifaceCfg); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Couldn't register unknown interface GUID: %08X-%04X-%04X-%02X%02X%02X%02X%02X%02X%02X%02X (status 0x%x)\n", + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "Couldn't register unknown interface GUID: %08X-%04X-%04X-%02X%02X%02X%02X%02X%02X%02X%02X " \ + "(WdfDeviceAddQueryInterface failed with status %!STATUS!)", GUID_DEVINTERFACE_XUSB_UNKNOWN_1.Data1, GUID_DEVINTERFACE_XUSB_UNKNOWN_1.Data2, GUID_DEVINTERFACE_XUSB_UNKNOWN_1.Data3, @@ -137,7 +181,7 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) GUID_DEVINTERFACE_XUSB_UNKNOWN_1.Data4[5], GUID_DEVINTERFACE_XUSB_UNKNOWN_1.Data4[6], GUID_DEVINTERFACE_XUSB_UNKNOWN_1.Data4[7], - status)); + status); return status; } @@ -149,7 +193,10 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) status = WdfDeviceAddQueryInterface(Device, &ifaceCfg); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "Couldn't register unknown interface GUID: %08X-%04X-%04X-%02X%02X%02X%02X%02X%02X%02X%02X (status 0x%x)\n", + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "Couldn't register unknown interface GUID: %08X-%04X-%04X-%02X%02X%02X%02X%02X%02X%02X%02X " \ + "(WdfDeviceAddQueryInterface failed with status %!STATUS!)", GUID_DEVINTERFACE_XUSB_UNKNOWN_2.Data1, GUID_DEVINTERFACE_XUSB_UNKNOWN_2.Data2, GUID_DEVINTERFACE_XUSB_UNKNOWN_2.Data3, @@ -161,7 +208,7 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) GUID_DEVINTERFACE_XUSB_UNKNOWN_2.Data4[5], GUID_DEVINTERFACE_XUSB_UNKNOWN_2.Data4[6], GUID_DEVINTERFACE_XUSB_UNKNOWN_2.Data4[7], - status)); + status); return status; } @@ -189,7 +236,10 @@ NTSTATUS Xusb_PrepareHardware(WDFDEVICE Device) status = WdfDeviceAddQueryInterface(Device, &ifaceCfg); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfDeviceAddQueryInterface failed status 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfDeviceAddQueryInterface failed with status %!STATUS!", + status); return status; } @@ -204,7 +254,7 @@ NTSTATUS Xusb_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION WDF_OBJECT_ATTRIBUTES_INIT(&attributes); attributes.ParentObject = Device; - KdPrint((DRIVERNAME "Initializing XUSB context...\n")); + TraceEvents(TRACE_LEVEL_VERBOSE, TRACE_XUSB, "Initializing XUSB context..."); PXUSB_DEVICE_DATA xusb = XusbGetData(Device); @@ -224,7 +274,10 @@ NTSTATUS Xusb_AssignPdoContext(WDFDEVICE Device, PPDO_IDENTIFICATION_DESCRIPTION status = WdfIoQueueCreate(Device, &holdingInQueueConfig, WDF_NO_OBJECT_ATTRIBUTES, &xusb->HoldingUsbInRequests); if (!NT_SUCCESS(status)) { - KdPrint((DRIVERNAME "WdfIoQueueCreate (HoldingUsbInRequests) failed 0x%x\n", status)); + TraceEvents(TRACE_LEVEL_ERROR, + TRACE_XUSB, + "WdfIoQueueCreate (HoldingUsbInRequests) failed with status %!STATUS!", + status); return status; } @@ -393,11 +446,13 @@ VOID Xusb_GetDeviceDescriptorType(PUSB_DEVICE_DESCRIPTOR pDescriptor, PPDO_DEVIC VOID Xusb_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) { - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_XUSB, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0xFF; pInfo->SubClass = 0x5D; @@ -423,11 +478,13 @@ VOID Xusb_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) pInfo = (PUSBD_INTERFACE_INFORMATION)((PCHAR)pInfo + pInfo->Length); - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_XUSB, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0xFF; pInfo->SubClass = 0x5D; @@ -469,11 +526,13 @@ VOID Xusb_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) pInfo = (PUSBD_INTERFACE_INFORMATION)((PCHAR)pInfo + pInfo->Length); - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_XUSB, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0xFF; pInfo->SubClass = 0x5D; @@ -491,11 +550,13 @@ VOID Xusb_SelectConfiguration(PUSBD_INTERFACE_INFORMATION pInfo) pInfo = (PUSBD_INTERFACE_INFORMATION)((PCHAR)pInfo + pInfo->Length); - KdPrint((DRIVERNAME ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d\n", + TraceEvents(TRACE_LEVEL_VERBOSE, + TRACE_XUSB, + ">> >> >> URB_FUNCTION_SELECT_CONFIGURATION: Length %d, Interface %d, Alternate %d, Pipes %d", (int)pInfo->Length, (int)pInfo->InterfaceNumber, (int)pInfo->AlternateSetting, - pInfo->NumberOfPipes)); + pInfo->NumberOfPipes); pInfo->Class = 0xFF; pInfo->SubClass = 0xFD;