RedirectorStrategy: Add request counters to traces

Signed-off-by: Dmitry Fleytman <dfleytma@redhat.com>
daynix · Feb 10, 2016 · 0a4f481 · 0a4f481
1 parent 074128a
commit 0a4f481
Show file tree

Hide file tree

Showing 3 changed files with 39 additions and 6 deletions.
diff --git a/UsbDk/RedirectorStrategy.cpp b/UsbDk/RedirectorStrategy.cpp
@@ -613,12 +613,14 @@ void CUsbDkRedirectorStrategy::TraceTransferError(const CRedirectorRequest &WdfR
                 "%!FUNC! %!usbdktransferdirection! transfer failed: %!STATUS! UsbdStatus 0x%x, "
                 "Endpoint address %llu, "
                 "Transfer type %!usbdktransfertype!, "
-                "Length %llu",
+                "Length %llu "
+                " (Request ID: %lld)",
                 Context->Direction,
                 Status, UsbdStatus,
                 Context->EndpointAddress,
                 Context->TransferType,
-                DataBuffer.Size());
+                DataBuffer.Size(),
+                WdfRequest.GetId());
 }
 
 void CUsbDkRedirectorStrategy::ReadPipe(WDFREQUEST Request)

diff --git a/UsbDk/UsbTarget.cpp b/UsbDk/UsbTarget.cpp
@@ -131,6 +131,8 @@ void CWdfUsbPipe::Create(WDFUSBDEVICE Device, WDFUSBINTERFACE Interface, UCHAR P
 
 void CWdfUsbPipe::ReadAsync(CTargetRequest &Request, WDFMEMORY Buffer, PFN_WDF_REQUEST_COMPLETION_ROUTINE Completion)
 {
+    Request.SetId(m_RequestConter++);
+
     auto status = WdfUsbTargetPipeFormatRequestForRead(m_Pipe, Request, Buffer, nullptr);
     if (!NT_SUCCESS(status))
     {
@@ -149,6 +151,8 @@ void CWdfUsbPipe::ReadAsync(CTargetRequest &Request, WDFMEMORY Buffer, PFN_WDF_R
 
 void CWdfUsbPipe::WriteAsync(CTargetRequest &Request, WDFMEMORY Buffer, PFN_WDF_REQUEST_COMPLETION_ROUTINE Completion)
 {
+    Request.SetId(m_RequestConter++);
+
     auto status = WdfUsbTargetPipeFormatRequestForWrite(m_Pipe, Request, Buffer, nullptr);
     if (!NT_SUCCESS(status))
     {
@@ -172,6 +176,8 @@ void CWdfUsbPipe::SubmitIsochronousTransfer(CTargetRequest &Request,
                                             size_t PacketNumber,
                                             PFN_WDF_REQUEST_COMPLETION_ROUTINE Completion)
 {
+    Request.SetId(m_RequestConter++);
+
     CIsochronousUrb Urb(m_Device, m_Pipe, Request);
     CPreAllocatedWdfMemoryBuffer DataBuffer(Buffer);
 
@@ -204,27 +210,39 @@ void CWdfUsbPipe::SubmitIsochronousTransfer(CTargetRequest &Request,
 
 NTSTATUS CWdfUsbPipe::Abort(WDFREQUEST Request)
 {
-    TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_USBTARGET, "%!FUNC! for pipe %d", EndpointAddress());
+    auto RequestId = m_RequestConter++;
+
+    TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_USBTARGET,
+                "%!FUNC! for pipe %d (Request ID: %lld)",
+                EndpointAddress(), RequestId);
 
     auto status = WdfUsbTargetPipeAbortSynchronously(m_Pipe, Request, nullptr);
 
     if (!NT_SUCCESS(status))
     {
-        TraceEvents(TRACE_LEVEL_ERROR, TRACE_USBTARGET, "%!FUNC! WdfUsbTargetPipeAbortSynchronously failed: %!STATUS!", status);
+        TraceEvents(TRACE_LEVEL_ERROR, TRACE_USBTARGET,
+                    "%!FUNC! for pipe %d failed: %!STATUS! (Request ID: %lld)",
+                    EndpointAddress(), status, RequestId);
     }
 
     return status;
 }
 
 NTSTATUS CWdfUsbPipe::Reset(WDFREQUEST Request)
 {
-    TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_USBTARGET, "%!FUNC! for pipe %d", EndpointAddress());
+    auto RequestId = m_RequestConter++;
+
+    TraceEvents(TRACE_LEVEL_INFORMATION, TRACE_USBTARGET,
+                "%!FUNC! for pipe %d (Request ID: %lld)",
+                EndpointAddress(), RequestId);
 
     auto status = WdfUsbTargetPipeResetSynchronously(m_Pipe, Request, nullptr);
 
     if (!NT_SUCCESS(status))
     {
-        TraceEvents(TRACE_LEVEL_ERROR, TRACE_USBTARGET, "%!FUNC! WdfUsbTargetPipeResetSynchronously failed: %!STATUS!", status);
+        TraceEvents(TRACE_LEVEL_ERROR, TRACE_USBTARGET,
+                    "%!FUNC! for pipe %d failed: %!STATUS! (Request ID: %lld)",
+                    EndpointAddress(), status, RequestId);
     }
 
     return status;
@@ -442,6 +460,8 @@ NTSTATUS CWdfUsbTarget::ResetDevice(WDFREQUEST Request)
 NTSTATUS CWdfUsbTarget::ControlTransferAsync(CTargetRequest &WdfRequest, PWDF_USB_CONTROL_SETUP_PACKET SetupPacket, WDFMEMORY Data,
                                          PWDFMEMORY_OFFSET TransferOffset, PFN_WDF_REQUEST_COMPLETION_ROUTINE Completion)
 {
+    WdfRequest.SetId(m_ControlTransferCouter++);
+
     auto status = WdfUsbTargetDeviceFormatRequestForControlTransfer(m_UsbDevice, WdfRequest, SetupPacket, Data, TransferOffset);
 
     if (!NT_SUCCESS(status))

diff --git a/UsbDk/UsbTarget.h b/UsbDk/UsbTarget.h
@@ -43,6 +43,12 @@ class CTargetRequest : public CWdfRequest
 
     PUSBDK_TARGET_REQUEST_CONTEXT Context() const
     { return static_cast<PUSBDK_TARGET_REQUEST_CONTEXT>(CWdfRequest::Context()); }
+
+    void SetId(ULONG64 Id) const
+    { Context()->RequestId = Id; }
+
+    ULONG64 GetId() const
+    { return Context()->RequestId; }
 };
 
 class CWdfUsbPipe : public CAllocatable<NonPagedPool, 'PUHR'>
@@ -81,17 +87,20 @@ class CWdfUsbPipe : public CAllocatable<NonPagedPool, 'PUHR'>
     }
 
 private:
+
     WDFUSBINTERFACE m_Interface = WDF_NO_HANDLE;
     WDFUSBDEVICE m_Device = WDF_NO_HANDLE;
     WDFUSBPIPE m_Pipe = WDF_NO_HANDLE;
     WDF_USB_PIPE_INFORMATION m_Info;
+    CAtomicCounter m_RequestConter;
 
     void SubmitIsochronousTransfer(CTargetRequest &Request,
         CIsochronousUrb::Direction Direction,
         WDFMEMORY Buffer,
         PULONG64 PacketSizes,
         size_t PacketNumber,
         PFN_WDF_REQUEST_COMPLETION_ROUTINE Completion);
+
     CWdfUsbPipe(const CWdfUsbPipe&) = delete;
     CWdfUsbPipe& operator= (const CWdfUsbPipe&) = delete;
 };
@@ -199,6 +208,8 @@ class CWdfUsbTarget
     CObjHolder<CWdfUsbInterface, CVectorDeleter<CWdfUsbInterface> > m_Interfaces;
     UCHAR m_NumInterfaces = 0;
 
+    CAtomicCounter m_ControlTransferCouter;
+
     CWdfUsbTarget(const CWdfUsbTarget&) = delete;
     CWdfUsbTarget& operator= (const CWdfUsbTarget&) = delete;
 };