Blue screen cause by usbccgp.sys on XP SP2

Hi, everybody

Recently my usb virtual bus driver was hitting a blue screen, and I need you guys the driver experts to helping me. the virtual usb bus driver simulate a USB controller, and dynamically enumerate usb devices using the technique learned from DDK toaster sample, and the driver communicate to the real usb device over network with the help of a usb filter driver sit on other machine, for every URB it received, the driver mark it as pending and forward to request queue, send the URB to filter driver, wait the response, and finally complete the IRP when response is received. cause the URB processing envolve in network transfer, it is affected by network load and the two machine cpu utilization, the processing time is longer than normal usb bus driver.

the blue screen was caused by a URB, which is pending by my driver, and later cancelled by usbccgp driver, and usbccgp cause a free memory access error. I use IDA Pro decompile the driver, and the following is the function, the bug code is marked.

typedef struct CallDriverContext {
PKEVENT hEvent;
int *completed;
} CallDriverContext, *PCallDriverContext;

//----- (00016600) --------------------------------------------------------
NTSTATUS __stdcall CallDriverSync(int a1, PIRP Irp)
{
char *v3; // ecx@1
PCallDriverContext context; //v4; // eax@1
int v5; // eax@2
NTSTATUS v6; // eax@3
char *v7; // [sp+20h] [bp-14h]@1
int v8; // [sp+4h] [bp-30h]@1
int v9; // [sp+1Ch] [bp-18h]@1
struct _KEVENT Event; // [sp+8h] [bp-2Ch]@1
int v11; // [sp+28h] [bp-Ch]@1
PVOID P; // [sp+24h] [bp-10h]@1
char *v13; // [sp+0h] [bp-34h]@2
NTSTATUS Status; // v14; // [sp+18h] [bp-1Ch]@2
LARGE_INTEGER Timeout; // [sp+2Ch] [bp-8h]@3

v3 = (char *)IoGetCurrentIrpStackLocation(Irp) - 36;
v7 = (char *)Irp->Tail.Overlay.CurrentStackLocation - 36;
v8 = *v3;
v9 = *(v3 + 1);
KeInitializeEvent(&Event, 0, 0);
v11 = 0;
context = v4 = (PCallDriverContext)ExAllocatePoolWithTag(0, sizeof(CallDriverContext), 0x43627355u);
P = v4;
if ( v4 )
{
context->hEvent = &Event;
context->completed = &v11;

IoSetCompletionRoutine(
Irp,
CallDriverSyncCompletion,
(PVOID)context,
TRUE,
TRUE,
TRUE
);

Status = IofCallDriver(a1, Irp);
if ( Status == STATUS_PENDING )
{
Timeout = (LARGE_INTEGER)-5000,0000 i64; // 5000ms = 5s
Status = KeWaitForSingleObject(&Event, 0, 0, 0, &Timeout);
if ( Status == STATUS_TIMEOUT )
{
if ( !InterlockedExchange(&v11, 1) )
{
IoCancelIrp(Irp);
if ( InterlockedExchange(&v11, 2) == 3 )
{
*((_BYTE *)Irp->Tail.Overlay.CurrentStackLocation + 3) |= 1u;
IofCompleteRequest(Irp, 0); // I found this function free the Irp
}
}
KeWaitForSingleObject(&Event, 0, 0, 0, 0);
Irp->IoStatus.Status = 0xC000009C; // <=== BUG CHECK AT HERE! STATUS_DEVICE_DATA_ERROR, -1073741668;
}
}
ExFreePool(context);
Status = Irp->IoStatus.Status;
}
else
{
Status = -1073741670;
}
return Status;
}

signed int __stdcall CallDriverSyncCompletion(int a1, int a2, int a3)
{
PCallDriverContext context; //v4; // eax@1

context = (PCallDriverContext)a3;
InterlockedExchange(context->completed, 3);
KeSetEvent(*context->Event, 0, 0);
return 0xC0000016; // STATUS_MORE_PROCESSING_REQUIRED -1073741802;
}

in WinDbg, I found after return from IofCompleteRequest(), the Irp is freed, does CalllDriverSync suppose to access Irp after it was freed?

function CallDriverSync use the Irp processing style like http://support.microsoft.com/kb/326315/en-us/ Scenario 7: Send a synchronous device-control (IOCTL) request and cancel it if not completed in a certain time period, but the sample does not touch the Irp after complete it.

any helping are welcome

>does CalllDriverSync suppose to access Irp after it was freed?
It is possible in your case because CallDriverSync gets Irp and calls KeWaitForSingleObject. When KeWaitForSingleObject returns it could possible that other stuff, your driver or others, free Irp. There are nothing to prevent this.
Is it permanent situation or it could be happened occasionally?

Igor Sharovar

The question is what is your code doing when this IRP is cancelled.
The code segment from usbccgp is a pretty standard irp processing
pattern.

Mark Roddy

On Thu, Nov 26, 2009 at 4:15 AM, wrote:
> Hi, everybody
>
> Recently my usb virtual bus driver was hitting a blue screen, and I need you guys the driver experts to helping me. the virtual usb bus driver simulate a USB controller, and dynamically enumerate usb devices using the technique learned from DDK toaster sample, and the driver communicate to the real usb device over network with the help of a usb filter driver sit on other machine, for every URB it received, the driver mark it as pending and forward to request queue, send the URB to filter driver, wait the response, and finally complete the IRP when response is received. cause the URB processing envolve in network transfer, it is affected by network load and the two machine cpu utilization, the processing time is longer than normal usb bus driver.
>
> the blue screen was caused by a URB, which is pending by my driver, and later cancelled by usbccgp driver, and usbccgp cause a free memory access error. I use IDA Pro decompile the driver, and the following is the function, the bug code is marked.
>
> typedef struct CallDriverContext {
> ? ? ? ?PKEVENT hEvent;
> ? ? ? ?int *completed;
> } CallDriverContext, *PCallDriverContext;
>
> //----- (00016600) --------------------------------------------------------
> NTSTATUS __stdcall CallDriverSync(int a1, PIRP Irp)
> {
> ?char *v3; // ecx@1
> ?PCallDriverContext context; //v4; // eax@1
> ?int v5; // eax@2
> ?NTSTATUS v6; // eax@3
> ?char *v7; // [sp+20h] [bp-14h]@1
> ?int v8; // [sp+4h] [bp-30h]@1
> ?int v9; // [sp+1Ch] [bp-18h]@1
> ?struct _KEVENT Event; // [sp+8h] [bp-2Ch]@1
> ?int v11; // [sp+28h] [bp-Ch]@1
> ?PVOID P; // [sp+24h] [bp-10h]@1
> ?char *v13; // [sp+0h] [bp-34h]@2
> ?NTSTATUS Status; // v14; // [sp+18h] [bp-1Ch]@2
> ?LARGE_INTEGER Timeout; // [sp+2Ch] [bp-8h]@3
>
> ?v3 = (char *)IoGetCurrentIrpStackLocation(Irp) - 36;
> ?v7 = (char *)Irp->Tail.Overlay.CurrentStackLocation - 36;
> ?v8 = *v3;
> ?v9 = (v3 + 1);
> ?KeInitializeEvent(&Event, 0, 0);
> ?v11 = 0;
> ?context = v4 = (PCallDriverContext)ExAllocatePoolWithTag(0, sizeof(CallDriverContext), 0x43627355u);
> ?P = v4;
> ?if ( v4 )
> ?{
> ? ?context->hEvent = &Event;
> ? ?context->completed = &v11;
>
> ? ?IoSetCompletionRoutine(
> ? ? ? ? ? ?Irp,
> ? ? ? ? ? ?CallDriverSyncCompletion,
> ? ? ? ? ? ?(PVOID)context,
> ? ? ? ? ? TRUE,
> ? ? ? ? ? TRUE,
> ? ? ? ? ? TRUE
> ? ?);
>
> ? ?Status = IofCallDriver(a1, Irp);
> ? ?if ( Status == STATUS_PENDING )
> ? ?{
> ? ? ?Timeout = (LARGE_INTEGER)-5000,0000 i64; // 5000ms = 5s
> ? ? ?Status = KeWaitForSingleObject(&Event, 0, 0, 0, &Timeout);
> ? ? ?if ( Status == STATUS_TIMEOUT )
> ? ? ?{
> ? ? ? ?if ( !InterlockedExchange(&v11, 1) )
> ? ? ? ?{
> ? ? ? ? ?IoCancelIrp(Irp);
> ? ? ? ? ?if ( InterlockedExchange(&v11, 2) == 3 )
> ? ? ? ? ?{
> ? ? ? ? ? ?
((_BYTE *)Irp->Tail.Overlay.CurrentStackLocation + 3) |= 1u;
> ? ? ? ? ? ?IofCompleteRequest(Irp, 0); // I found this function free the Irp
> ? ? ? ? ?}
> ? ? ? ?}
> ? ? ? ?KeWaitForSingleObject(&Event, 0, 0, 0, 0);
> ? ? ? ?Irp->IoStatus.Status = 0xC000009C; // <=== BUG CHECK AT HERE! STATUS_DEVICE_DATA_ERROR, -1073741668;
> ? ? ?}
> ? ?}
> ? ?ExFreePool(context);
> ? ?Status = Irp->IoStatus.Status;
> ?}
> ?else
> ?{
> ? ?Status = -1073741670;
> ?}
> ?return Status;
> }
>
> signed int__stdcall CallDriverSyncCompletion(int a1, int a2, int a3)
> {
> ?PCallDriverContext context; //v4; // eax@1
>
> ?context = (PCallDriverContext)a3;
> ?InterlockedExchange(context->completed, 3);
> ?KeSetEvent(*context->Event, 0, 0);
> ?return 0xC0000016; // STATUS_MORE_PROCESSING_REQUIRED -1073741802;
> }
>
> in WinDbg, I found after return from IofCompleteRequest(), the Irp is freed, does CalllDriverSync suppose to access Irp after it was freed?
>
> function CallDriverSync use the Irp processing style like http://support.microsoft.com/kb/326315/en-us/ ?Scenario 7: Send a synchronous device-control (IOCTL) request and cancel it if not completed in a certain time period, but the sample does not touch the Irp after complete it.
>
> any helping are welcome
>
>
> —
> NTDEV is sponsored by OSR
>
> For our schedule of WDF, WDM, debugging and other seminars visit:
> http://www.osr.com/seminars
>
> To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer
>

You have pointed your error. Why not take a try? You lose control of your irp after IoCompleteRequest called, then any manipulation to the irp is unsafe.

Mark,

You point the correction direction, I want to know how can I behave correctly when the IRP is cancelled.
Currently the WDF queue automatically cancel the queued IRP on behalf of my driver, I do not handle the IRP cancellation explicitly; another method is l register a EvtIoCanceledOnQueue callback, and call WdfRequestComplete with STATUS_CANCELLED inside it.

The problem is both way lead to usbccgp crashes, I also try to call WdfRequestComplete with STATUS_UNSUCCESSFUL, but I don?t known if it is allowed .

Ligong Liu

Are you sure that ccgp access the IRP after completerequest is invoked for this IRP ?

Usbccgp can access the irp after it’s completion handler is called.
This is a standard synchronous irp processing pattern. The irp
dispatch side waits for an event set by it’s completion handler, and
that completion handler returns SMPR, stopping further processing by
the io manager of this irp. The irp returns to the control of the
dispatch code in usbccgp.

The problem remains in the irp managent code on the op’s driver.

On Friday, November 27, 2009, <xiedong_sl> wrote:
> Are you sure that ccgp access the IRP after completerequest is invoked for this IRP ?
>
>
> —
> NTDEV is sponsored by OSR
>
> For our schedule of WDF, WDM, debugging and other seminars visit:
> http://www.osr.com/seminars
>
> To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer
>


Mark Roddy</xiedong_sl>

You need to synchronize access to the Irp among routines which use the same Irp. I don’t know your code but I see a potential problem which likely triggers this BSDO. CallDriverSync calls KeWaitForSingleObject and another
routine like EvtIoCanceledOnQueue would cancel Irp. And later when CallDriverSync exits from KeWaitForSingleObject it would try to access not valid Irp.
You need to allocate synchronization primitives and keep them, for example, in a DeviceObjectExtention. One variable could be a Boolean which indicate if Irp valid or not. And likely you need a SpinLock to access this variable. Any access to the Irp should be done by using the Boolean variable and the SpinLock.

Igor Sharovar

> Currently the WDF queue automatically cancel the queued IRP on behalf of my driver

If you’re using WDF - why not use IO target object instead of calling IoCallDriver yourself?


Maxim S. Shatskih
Windows DDK MVP
xxxxx@storagecraft.com
http://www.storagecraft.com

>you need a SpinLock to access this variable. Any access to the Irp should be done by using the

Boolean variable and the SpinLock.

…or pointer variable and InterlockedExchangePointer


Maxim S. Shatskih
Windows DDK MVP
xxxxx@storagecraft.com
http://www.storagecraft.com

Thanks everybody for joining the discussion, I want to clarify the problem and got the answer.
(1) usbccgp.sys is part of Windows USB stack, not my code
(2) my driver use WDF framework, and sit below usbccgp.sys, act as a bus driver. my driver use WDFREQUEST and WDFQUEUE object to manage IRP. usbccgp.sys call IoCallDriver to pass IRP to my driver.
(3) upon receive IO request I call WdfRequestForwardToIoQueue to forward the request to another manual dispatch queue, and complete it when the real process is completed.
(4) when a composite device is plug in to the virtual bus, windows load usbccgp.sys to manage the PDO.
(5) normaly windows do not crash, but when I enable driver verifier for my driver, turn on special pool, and pool checking, the bug will be cached. If my driver did not complete the IRP in 5 seconds, usbccgp.sys will cancel it, and WDF will automatically cancel my queued request. then usbccgp.sys will crash the sysyem, WinDbg report freed memory access error.
(6) the code below is part of usbccgp, I decompile from usbccgp.sys, I believe the following code path has problem.
if ( Status == STATUS_TIMEOUT )
{
if ( !InterlockedExchange(&v11, 1) )
{
IoCancelIrp(Irp);
if ( InterlockedExchange(&v11, 2) == 3 )
{
*((_BYTE *)Irp->Tail.Overlay.CurrentStackLocation + 3) |= 1u;
IofCompleteRequest(Irp, 0); // THIS CALL FREE IRP
}
}
KeWaitForSingleObject(&Event, 0, 0, 0, 0);
Irp->IoStatus.Status = 0xC000009C; // <== CRASH AT HERE, SHOULD ACCESS IRP
}

the corresponding assamble code of above is follow:
usbccgp!CallDriverSync+0x14c:
f8aa074c 8b450c mov eax,dword ptr [ebp+0Ch]
f8aa074f 8b4860 mov ecx,dword ptr [eax+60h]
f8aa0752 0fb65103 movzx edx,byte ptr [ecx+3]
f8aa0756 83ca01 or edx,1
f8aa0759 8b450c mov eax,dword ptr [ebp+0Ch]
f8aa075c 8b4860 mov ecx,dword ptr [eax+60h]
f8aa075f 885103 mov byte ptr [ecx+3],dl
f8aa0762 32d2 xor dl,dl
f8aa0764 8b4d0c mov ecx,dword ptr [ebp+0Ch] ; Irp
f8aa0767 ff15a8dda9f8 call dword ptr [usbccgp!_imp_IofCompleteRequest (f8a9dda8)]

usbccgp!CallDriverSync+0x16d:
f8aa076d 6a00 push 0
f8aa076f 6a00 push 0
f8aa0771 6a00 push 0
f8aa0773 6a00 push 0
f8aa0775 8d55d4 lea edx,[ebp-2Ch]
f8aa0778 52 push edx
f8aa0779 ff15b8dda9f8 call dword ptr [usbccgp!_imp__KeWaitForSingleObject (f8a9ddb8)]
f8aa077f 8b450c mov eax,dword ptr [ebp+0Ch] ; Irp
f8aa0782 c740189c0000c0 mov dword ptr [eax+18h],0C000009Ch ; access Irp after call IofCompleteRequest

(7) WDK document section “IoCompleteRequest routine” said: The caller of IoCompleteRequest must not attempt to access the just-completed IRP. Such an attempt is a programming error that causes a system crash. usbccgp.sys violate this rule.

>if ( InterlockedExchange(&v11, 2) == 3 )
>{
>*((_BYTE *)Irp->Tail.Overlay.CurrentStackLocation + 3) |= 1u;
> IofCompleteRequest(Irp, 0); // THIS CALL FREE IRP }

You should return after IofCompleteRequest. You complete Irp and later call Irp->IoStatus.Status. In this point Irp is not valid yet.

Igor Sharovar

Igor Sharovar wrote:

Subject: RE:[ntdev] Blue screen cause by usbccgp.sys on XP SP2

>if ( InterlockedExchange(&v11, 2) == 3 ) >{
>*((_BYTE *)Irp->Tail.Overlay.CurrentStackLocation + 3) |= 1u;
> IofCompleteRequest(Irp, 0); // THIS CALL FREE IRP }

You should return after IofCompleteRequest. You complete Irp
and later call Irp->IoStatus.Status. In this point Irp is not
valid yet.

Igor Sharovar

Igor, it’s not his code - that’s what IDA shows regarding usbccgp.sys,
according to OP.

Regards,
Alex krol

>Igor, it’s not his code - that’s what IDA shows regarding usbccgp.sys, according to OP.

Sorry, I didn’t carefully read whole post.
The Monday’s morning after long weekend always is hard :frowning:

Igor Sharovar

*((_BYTE *)Irp->Tail.Overlay.CurrentStackLocation + 3) |= 1u
= ===========> IoMarkIrpPending