Our KMDF driver talks to NDIS miniport driver using IO controls. Our driver creates a Remote IO Target and pends upto 32 Io Control read requests for receiving incoming HCI events. The miniport driver uses METHOD_OUT_DIRECT for the operation. The initial posting of 32 read requests happen at PASSIVE_LEVEL and all requests are delivered to the NDIS without any problem. However the problem starts when the read requests are completed. The miniport driver completes pending read request from a DPC(DISPATCH_LEVEL) and we reissue read request from the complation routine itself. This works fine for few times but eventually at some point the system bug checks with code ATTEMPTED_SWITCH_FROM_DPC(0xB8) while issuing a Read from the DPC.
We tried using worker threads for reissuing read requests at PASSIVE_LEVEL. Although this eliminated the B8 bug check it introduced another problem. The miniport driver completes all 32 pending read requests at one go in a single DPC. The Worker thread gets scheduled only after the miniport driver exhausted all pending read requests and as a result the miniport driver drops incoming HCI events from time to time. This leads to other problems and finally the data transfer breaks.
The Crash dump info and source code provided below. Please help me to fix this issue. Thanks in advance.
################################
Crash Dump info
################################
Microsoft (R) Windows Debugger Version 6.9.0003.113 X86
Copyright (c) Microsoft Corporation. All rights reserved.
Loading Dump File [C:\Windows\Minidump\122210-42416-01.dmp]
Mini Kernel Dump File: Only registers and stack trace are available
Symbol search path is: symsrv*c:\symbols*http://msdl.microsoft.com/download/symbols;Z:\AMP Drivers\Drivers\Setup_1.0.2
Executable search path is: Z:\AMP Drivers\Drivers\Setup_1.0.2
Windows 7 Kernel Version 7600 MP (2 procs) Free x86 compatible
Product: WinNt, suite: TerminalServer SingleUserTS
Built by: 7600.16617.x86fre.win7_gdr.100618-1621
Kernel base = 0x82005000 PsLoadedModuleList = 0x82144570
Debug session time: Wed Dec 22 12:33:41.431 2010 (GMT+5)
System Uptime: 0 days 0:01:28.227
Loading Kernel Symbols
…
Loading User Symbols
Loading unloaded module list
…
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************
Use !analyze -v to get detailed debugging information.
BugCheck 100000B8, {98760a58, 845ec800, 95389fd0, 0}
*** WARNING: Unable to verify timestamp for netr28.sys
*** ERROR: Module load completed but symbols could not be loaded for netr28.sys
Probably caused by : BtPort.sys ( BtPort!WdfRequestSend+1d )
Followup: MachineOwner
1: kd> !analyze -v
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************
ATTEMPTED_SWITCH_FROM_DPC (b8)
A wait operation, attach process, or yield was attempted from a DPC routine.
This is an illegal operation and the stack track will lead to the offending
code and original DPC routine.
Arguments:
Arg1: 98760a58, Original thread which is the cause of the failure
Arg2: 845ec800, New thread
Arg3: 95389fd0, Stack address of the original thread
Arg4: 00000000
Debugging Details:
FAULTING_THREAD: 98760a58
CUSTOMER_CRASH_COUNT: 1
DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT
BUGCHECK_STR: 0xB8
PROCESS_NAME: FileTransfe
CURRENT_IRQL: 2
LAST_CONTROL_TRANSFER: from 82060c6d to 82059de6
STACK_TEXT:
84607908 82060c6d 98760a58 00000000 845e7120 nt!KiSwapContext+0x26
84607940 8205fad3 98760b18 98760a58 821445f0 nt!KiSwapThread+0x266
84607968 8205974f 98760a58 98760b18 00000018 nt!KiCommitThreadWait+0x1df
846079e4 82268c74 821445f0 00000012 00000000 nt!KeWaitForSingleObject+0x393
84607a18 84df3352 84def318 8ce1f5d0 84e606a0 nt!MmLockPagableSectionByHandle+0x146
84607a24 84e606a0 00000000 7321a128 8a1e3b40 ndis!ndisReferencePackage+0x41
84607b0c 82033f44 8a1e3b40 8ce1f5d0 00000000 ndis!ndisDeviceControlIrpHandler+0xa9
84607b24 849a4164 8cd5da34 8cdf1eb8 00000000 nt!IofCallDriver+0x63
84607b3c 80d4b9fd 00000005 8ce00f20 8cde5ed0 Wdf01000!imp_WdfRequestSend+0x2de
84607b54 80df7962 731ff0d8 7321a128 00000000 BtPort!WdfRequestSend+0x1d [c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfrequest.h @ 661]
84607ba0 80df6f50 8cde5008 00000000 0000000b 84607ba0 80df6f50 8cde5008 00000000 0000000b BtPort!PalProxySendEventReadReq+0x1a2 [d:\code\bt_pal_proxy.c @ 609]
84607bc0 849b3317 7320e140 7321a128 8cd5da34 BtPort!PalProxyEventReadIoctlCompletionRoutine+0x90 [d:\code\bt_pal_proxy.c @ 68]
84607bec 84997c36 8cde5768 8cde5ed0 00000000 Wdf01000!FxRequestBase::CompleteSubmitted+0xf6
84607c08 84997cde 01df1eb8 986972c0 84607c40 Wdf01000!FxIoTarget::RequestCompletionRoutine+0x12d
84607c18 82069bed 00000000 8cde5768 8cdf1eb8 Wdf01000!FxIoTarget::_RequestCompletionRoutine+0x35
84607c40 8205afa0 00000000 8cde5768 986972c0 nt!IopUnloadSafeCompletion+0x45
84607c84 8a9e2fc1 82400001 8b800000 00000001 nt!IopfCompleteRequest+0x115
WARNING: Stack unwind information not available. Following frames may be wrong.
84607c98 8a9e3321 8b912399 84607d14 82408700 netr28+0xb4fc1
84607e1c 8a9314ae 8b800000 8b817080 000005d6 netr28+0xb5321
84607e6c 8a93175e 8cdee2e0 000005d6 00000000 netr28+0x34ae
84607e98 8a9500b0 8b81d290 00000200 8b800000 netr28+0x375e
84607eac 8a92fbbb 8b800000 00000002 00000000 netr28+0x220b0
84607ec8 8a92fd38 8b800000 00000000 84607f10 netr28+0x1bbb
84607ee0 84e45301 8b800000 00000000 00000000 netr28+0x1d38
84607f20 84df09f4 87ffdabc 00ffd9a8 00000000 ndis!ndisMiniportDpc+0xda
84607f48 8205a835 87ffdabc 87ffd9a8 00000000 ndis!ndisInterruptDpc+0xaf
84607fa4 8205a698 845e7120 98760a58 00000000 nt!KiExecuteAllDpcs+0xf9
84607ff4 82059e5c 95389c00 00000000 00000000 nt!KiRetireDpcList+0xd5
84607ff8 95389c00 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2c
82059e5c 00000000 0000001a 00d6850f bb830000 0x95389c00
STACK_COMMAND: .thread 0xffffffff98760a58 ; kb
FOLLOWUP_IP:
BtPort!WdfRequestSend+1d [c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfrequest.h @ 661]
80d4b9fd 5d pop ebp
FAULTING_SOURCE_CODE:
No source found for ‘c:\winddk\7600.16385.0\inc\wdf\kmdf\1.9\wdfrequest.h’
SYMBOL_STACK_INDEX: 9
SYMBOL_NAME: BtPort!WdfRequestSend+1d
FOLLOWUP_NAME: MachineOwner
MODULE_NAME: BtPort
IMAGE_NAME: BtPort.sys
DEBUG_FLR_IMAGE_TIMESTAMP: 4d119fbf
FAILURE_BUCKET_ID: 0xB8_BtPort!WdfRequestSend+1d
BUCKET_ID: 0xB8_BtPort!WdfRequestSend+1d
Followup: MachineOwner
################################
Source code for Read rountines
################################
NTSTATUS PalProxySendEventReadReq(__in BtPalProxyInstData *inst)
{
NTSTATUS status = STATUS_UNSUCCESSFUL;
PREAD_IOCTL_CONTEXT rwContext = NULL;
WDFMEMORY inputMem, outputMem;
NDIS_OID *Oid;
WDFREQUEST NewRequest;
WDF_OBJECT_ATTRIBUTES attributes;
BtTrace(TRACE_LEVEL_VERBOSE, DBG_READ, “PalProxySendEventReadIoctl Begins…\n”);
WDF_OBJECT_ATTRIBUTES_INIT(&attributes);
attributes.ParentObject = inst->WdfDevice;
WDF_OBJECT_ATTRIBUTES_SET_CONTEXT_TYPE(
&attributes,
READ_IOCTL_CONTEXT
);
/* Create New Request Object for the IOCTL*/
status = WdfRequestCreate(&attributes,
inst->currentIOTarget,
&NewRequest);
if (!NT_SUCCESS(status))
{
BtTrace(TRACE_LEVEL_ERROR, DBG_INIT,“WdfRequestCreate Failed with status: 0x%x\n”, status);
return FALSE;
}
WDF_OBJECT_ATTRIBUTES_INIT(&attributes);
attributes.ParentObject = NewRequest;
status = WdfMemoryCreate(
&attributes,
NonPagedPool,
MEM_ALLOC_TAG,
sizeof(DWORD),
&inputMem,
(PVOID*)&Oid
);
if (!NT_SUCCESS(status)) {
BtTrace(TRACE_LEVEL_ERROR, DBG_READ,“Failure in WdfMemoryCreate status 0x%x\n”, status);
WdfObjectDelete(NewRequest);
return status;
}
*Oid = RT_OID_802_11_BT_HCI_GET_CMD;
status = WdfMemoryCreate(
&attributes,
NonPagedPool,
MEM_ALLOC_TAG,
MAX_HCI_MESSAGE_SIZE,
&outputMem,
NULL
);
if (!NT_SUCCESS(status)) {
WdfObjectDelete(NewRequest);
BtTrace(TRACE_LEVEL_ERROR, DBG_READ,“Failure in WdfMemoryCreate status 0x%x\n”, status);
return status;
}
status = WdfIoTargetFormatRequestForIoctl(
inst->currentIOTarget,
NewRequest,
IOCTL_HCI_READ,
inputMem,
NULL,
outputMem,
NULL);
if (!NT_SUCCESS(status))
{
BtTrace(TRACE_LEVEL_ERROR, DBG_READ,“Failure in WdfIoTargetFormatRequestForIoctl status 0x%x\n”, status);
WdfObjectDelete(NewRequest);
return status;
}
WdfRequestSetCompletionRoutine(NewRequest, PalProxyEventReadIoctlCompletionRoutine, inst);
//Add the Request to PendingIoctlReadQ
if (WdfRequestSend(NewRequest, inst->currentIOTarget, WDF_NO_SEND_OPTIONS) == FALSE)
{
status = WdfRequestGetStatus(NewRequest);
if (!NT_SUCCESS(status))
{
BtTrace(TRACE_LEVEL_ERROR, DBG_READ,“WdfRequestSend Failed with Status: 0x%x\n”, status);
WdfObjectDelete(NewRequest);
return status;
}
}
BtTrace(TRACE_LEVEL_VERBOSE, DBG_READ, “PalProxySendEventReadIoctl Ends…\n”);
return status;
}
VOID
PalProxyEventReadIoctlCompletionRoutine(
__in WDFREQUEST Request,
__in WDFIOTARGET Target,
__in PWDF_REQUEST_COMPLETION_PARAMS CompletionParams,
__in WDFCONTEXT Context
)
{
NTSTATUS status = STATUS_SUCCESS;
BtPalProxyInstData *inst = Context;
size_t EventBufLength;
PVOID outputBuffer = NULL;
BtTrace(TRACE_LEVEL_VERBOSE,DBG_READ,“PalProxyEventReadIoctlCompletionRoutine Begins…\n”);
status = CompletionParams->IoStatus.Status;
EventBufLength = CompletionParams->Parameters.Ioctl.Output.Length;
if(!NT_SUCCESS(status)) {
BtTrace(TRACE_LEVEL_WARNING, DBG_READ, “Ioctl Event Read Completed with Status FAILURE: %0x\n”, status);
goto Exit;
}
outputBuffer = WdfMemoryGetBuffer(CompletionParams->Parameters.Ioctl.Output.Buffer, NULL);
PalProxyHandleHCIEvents(inst, (Uint8*)outputBuffer, (Uint16)EventBufLength);
// Pending another read
status = PalProxySendEventReadReq(inst, NULL);
if(!NT_SUCCESS(status)) {
BtTrace(TRACE_LEVEL_ERROR,DBG_READ,“Unable to send message to AMP Driver\n”);
}
Exit:
WdfObjectDelete(Request);
BtTrace(TRACE_LEVEL_VERBOSE,DBG_READ,“PalProxyEventReadIoctlCompletionRoutine Ends…\n”);
}
##############################