1.1 --- a/xenvbd_filter/xenvbd_filter.c	Tue Oct 01 11:42:11 2013 +1000
     1.2 +++ b/xenvbd_filter/xenvbd_filter.c	Tue Oct 01 13:46:32 2013 +1000
     1.3 @@ -155,6 +155,8 @@ static VOID
     1.4  XenVbd_SendRequestComplete(WDFREQUEST request, WDFIOTARGET target, PWDF_REQUEST_COMPLETION_PARAMS params, WDFCONTEXT context) {
     1.5    NTSTATUS status;
     1.6    PSCSI_REQUEST_BLOCK srb = context;
     1.7 +  LARGE_INTEGER systemtime;
     1.8 +  ULONGLONG elapsed;
     1.9  
    1.10    UNREFERENCED_PARAMETER(target);
    1.11    UNREFERENCED_PARAMETER(params);
    1.12 @@ -164,6 +166,12 @@ XenVbd_SendRequestComplete(WDFREQUEST re
    1.13    if (status != 0 || srb->SrbStatus != SRB_STATUS_SUCCESS) {
    1.14      FUNCTION_MSG("Request Status = %08x, SRB Status = %08x\n", status, srb->SrbStatus);
    1.15    }
    1.16 +  KeQuerySystemTime(&systemtime);
    1.17 +  elapsed = systemtime.QuadPart - ((PLARGE_INTEGER)((PUCHAR)context + sizeof(SCSI_REQUEST_BLOCK) + sizeof(SRB_IO_CONTROL)))->QuadPart;
    1.18 +  elapsed = elapsed / 10000; // now in ms
    1.19 +  if (elapsed > 1000) {
    1.20 +    FUNCTION_MSG("Event took %d ms\n", (ULONG)elapsed);
    1.21 +  }
    1.22    ExFreePoolWithTag(context, XENVBD_POOL_TAG);
    1.23    WdfObjectDelete(request);
    1.24  }
    1.25 @@ -181,11 +189,12 @@ XenVbd_SendEvent(WDFDEVICE device) {
    1.26  
    1.27    status = WdfRequestCreate(WDF_NO_OBJECT_ATTRIBUTES, xvfd->wdf_target, &request);
    1.28    if (status != STATUS_SUCCESS) {
    1.29 +    FUNCTION_MSG("WdfRequestCreate failed %08x\n", status);
    1.30      /* this is bad - event will be dropped */
    1.31      return;
    1.32    }
    1.33  
    1.34 -  buf = ExAllocatePoolWithTag(NonPagedPool, sizeof(SCSI_REQUEST_BLOCK) + sizeof(SRB_IO_CONTROL), XENVBD_POOL_TAG);
    1.35 +  buf = ExAllocatePoolWithTag(NonPagedPool, sizeof(SCSI_REQUEST_BLOCK) + sizeof(SRB_IO_CONTROL) + sizeof(LARGE_INTEGER), XENVBD_POOL_TAG);
    1.36    RtlZeroMemory(buf, sizeof(SCSI_REQUEST_BLOCK) + sizeof(SRB_IO_CONTROL));
    1.37    srb = (PSCSI_REQUEST_BLOCK)(buf);
    1.38    sic = (PSRB_IO_CONTROL)(buf + sizeof(SCSI_REQUEST_BLOCK));
    1.39 @@ -205,6 +214,8 @@ XenVbd_SendEvent(WDFDEVICE device) {
    1.40    memcpy(sic->Signature, XENVBD_CONTROL_SIG, 8);
    1.41    sic->Timeout = (ULONG)-1;
    1.42    sic->ControlCode = XENVBD_CONTROL_EVENT;
    1.43 +  
    1.44 +  KeQuerySystemTime((PLARGE_INTEGER)((PUCHAR)buf + sizeof(SCSI_REQUEST_BLOCK) + sizeof(SRB_IO_CONTROL)));
    1.45  
    1.46    RtlZeroMemory(&stack, sizeof(IO_STACK_LOCATION));
    1.47    stack.MajorFunction = IRP_MJ_SCSI;