WdfDmaTransactionExecute bug checks!

NTDEV
1

Ok, I’m an idiot and just too stupid to figure out my problem. Now that that’s out of the way, here’s the issue I’m working on:

I have a group of devices that use the PLX 9080 for which I’m migrating a driver based on the BlueWater Systems WinDK to one based on the KMDF. The 9080 is similar enough to the PLX 9656 that I’m using the PLX9x5x sample driver as a guide. Of course, I’ve changed the dma profile to WdfDmaProfileScatterGatherDuplex since the 9080 only supports 32-bit addressing.

I’m trying to setup a bus-master dma for reading data from the device. A pointer to the buffer to receive the data is embedded in a data structure sent via DeviceIoControl. The driver handles the IOCTL in an EvtDeviceIoInCallerContext–allocates an MDL via IoAllocateMdl, locks the buffer down using MmProbeAndLockPages, and retrieves the virtual address via MmGetSystemAddressForMdlSafe. The operation appears to be successful; in fact, I can configure the device to periodically interrupt and write to all of this buffer from within the EvtInterruptIsr routine…i.e., at DIRQL and without bug checking.

However, during setup of the DMA, while I receive STATUS_SUCCESS upon calling WdfDmaTransactionInitialize, I get a IRQL_NOT_LESS_OR_EQUAL bug check for WdfDmaTransactionExecute. Note that the EvtProgramReadDma supplied to WdfDmaTransactionInitialize is NOT called–I neither hit a breakpoint inside the routine, nor do I see any traces from the routine.

Like the PLX9x5x driver, the DmaEnabler, ReadDmaTransaction, and ReadCommonBuffer are created in the EvtDeviceAdd. Stepping through the device initialization, all appear to be created successfully.

So, I’m tripping on an invalid pointer or paged data during WdfDmaTransactionExecute that is not apparent during the WdfDmaTransactionInitialize. My first notion was to suspect the mdl and virtual address user buffer, but as I mentioned, I’m able to write to the buffer from beginning to end from within the EvtInterruptIsr…

Note that the driver is 64-bits (AMD64), while the application sending down the embedded buffer pointer is 32-bit. I have yet to test the driver compiled for x86–which I’m about start.

Any suggestions?

Thanks,
Larry

PS I’ll be heading home soon; so, I might not get back to this till morning.

2

Could you provide WinDbg trace by running “!analyze -v” after getting the bug check?

Igor Sharovar

3

> Note that the driver is 64-bits (AMD64), while the application sending down the embedded buffer

pointer is 32-bit. I have yet to test the driver compiled for x86–which I’m about start.

Try it.

Probably you have invalid input buffer structure for 32/64 issue. Read the docs on how to handle such input buffers correctly.

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

4

Just before the crash, I have the trace for the WdfDmaTransactionInitialize:

PCI6000: WdfDmaTransactionInitialize(
0x0000057FFA15F548,
0xFFFFFA600ABC2EF0,
WdfDmaDirectionReadFromDevice,
0xFFFFFA80040F26F0,
0xFFFFFA600B541000,
2000)

Upon calling WdfDmaTransactionExecute, I get a bug check.
!analyze -v produces:
*******************************************************************************
* *
* Bugcheck Analysis *
* *
*******************************************************************************

IRQL_NOT_LESS_OR_EQUAL (a)
An attempt was made to access a pageable (or completely invalid) address at an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: fffffa853414b628, memory referenced
Arg2: 0000000000000002, IRQL
Arg3: 0000000000000000, bitfield :
bit 0 : value 0 = read operation, 1 = write operation
bit 3 : value 0 = not an execute operation, 1 = execute operation (only on chips which support this level of status)
Arg4: fffff80001e0f268, address which referenced memory

Debugging Details:

// a note about mismatched symbols in reference to kernel32!pNlsUserInfo

READ_ADDRESS: fffffa853414b628

CURRENT_IRQL: 2

FAULTING_IP:
hal!HalpDmaNextContiguousPiece+68
fffff800`01e0f268 4c3954ee30 cmp qword ptr [rsi+rbp*8+30h],r10

DEFAULT_BUCKET_ID: VISTA_DRIVER_FAULT

BUGCHECK_STR: 0xA

PROCESS_NAME: utul32.exe

TRAP_FRAME: fffffa6009bb5d80 -- (.trap 0xfffffa6009bb5d80)
.trap 0xfffffa6009bb5d80
NOTE: The trap frame does not contain all registers.
Some register values may be zeroed or incorrect.
rax=0000000000000000 rbx=0000000000000000 rcx=0000000000000fff
rdx=0000000000001000 rsi=0000000000000000 rdi=0000000000000000
rip=fffff80001e0f268 rsp=fffffa6009bb5f18 rbp=00000000a600b1e1
r8=0000000000000400 r9=000fffffa600b1e1 r10=00000000000fffff
r11=fffffa8005eb3a00 r12=0000000000000000 r13=0000000000000000
r14=0000000000000000 r15=0000000000000000
iopl=0 nv up ei pl nz na po nc
hal!HalpDmaNextContiguousPiece+0x68:
fffff800`01e0f268 4c3954ee30 cmp qword ptr [rsi+rbp*8+30h],r10 ds:d0b0:8f38=????????????????
.trap
Resetting default scope

LAST_CONTROL_TRANSFER: from fffff80001f574f2 to fffff80001ea76f0

STACK_TEXT:
fffffa6009bb5528 fffff80001f574f2 : fffffa80053c8550 0000000000000065 fffffa853414b628 fffff80001eea20c : nt!RtlpBreakWithStatusInstruction
fffffa6009bb5530 fffff80001f582ab : fffffa8500000003 0000000000000000 fffff80001ee7aa0 000000000000000a : nt!KiBugCheckDebugBreak+0x12
fffffa6009bb5590 fffff80001ead554 : 0000000000000000 0000000000000000 0000000000000000 0000000000000000 : nt!KeBugCheck2+0x6eb
fffffa6009bb5c00 fffff80001ead1ee : 000000000000000a fffffa853414b628 0000000000000002 0000000000000000 : nt!KeBugCheckEx+0x104
fffffa6009bb5c40 fffff80001eac0cb : 0000000000000000 0000000000000000 0000000000000000 fffffa8005eb3518 : nt!KiBugCheckDispatch+0x6e
fffffa6009bb5d80 fffff80001e0f268 : fffffa80040f26f0 fffffa600b541000 fffff80001e0f3b4 fffffa8005eb3518 : nt!KiPageFault+0x20b
fffffa6009bb5f18 fffff80001e0f3b4 : fffffa8005eb3518 fffffa8005eb3a00 fffffa8003ead860 fffffa80040f26f0 : hal!HalpDmaNextContiguousPiece+0x68
fffffa6009bb5f30 fffff80001e12399 : fffffa8005eb3518 fffffa8005eb3a00 fffffa80040f26f0 0000000000000000 : hal!HalpDmaMapScatterTransfer+0x34
fffffa6009bb5f80 fffff80001e12312 : fffffa8005eb3518 fffffa8005eb3510 0000000000000400 0000000000000000 : hal!HalpMapTransfer+0x79
fffffa6009bb6000 fffff80001e1180f : 0000000000000000 fffff80001e0ee45 0000000000000000 0000000000000001 : hal!IoMapTransfer+0x8e
fffffa6009bb6040 fffff80001e11fdd : fffffa8004ce5bd0 fffffa8005eb3a00 fffffa8005eb3a00 0000057f00000000 : hal!HalpAllocateAdapterCallback+0xc7
fffffa6009bb60e0 fffff80001e115df : fffffa8005eb34d0 0000000000000400 fffffa8005eb3a00 fffffa80040f26f0 : hal!HalAllocateAdapterChannel+0x101
fffffa6009bb6120 fffffa60008105e0 : fffff80001e2ff00 fffffa8005ea0ab0 fffffa60000000a0 fffffa6009bb0018 : hal!HalBuildScatterGatherList+0x2f3
fffffa6009bb6190 fffffa600080bad1 : 0000057f00000001 0000000000000000 fffffa8005ea0b18 0000000000000000 : Wdf01000!FxDmaScatterGatherTransaction::StageTransfer+0x400
fffffa6009bb6270 fffffa600abc4335 : fffffa80040f26f0 fffffa80052fc700 0000000000000010 0000000000000284 : Wdf01000!imp_WdfDmaTransactionExecute+0x171
fffffa6009bb6300 fffffa600abc3dec : 0000057ffa15f548 0000057ffa15f548 0000000000000000 fffffa80040f26f0 : pci6000!WdfDmaTransactionExecute+0x25 [e:\ddks\winddk\6001.18001\inc\wdf\kmdf\1.7\wdfdmatransaction.h @ 189]
fffffa6009bb6330 fffffa600abcce54 : 0000057ffa1e3f78 0000057ffad038f8 fffffa6009bb6490 0000000000000000 : pci6000!PCI6000ScanBMDMAStart+0x5bc [e:\test\pci6000\pci6000_ioctl.c @ 1147]
fffffa6009bb6400 fffffa60008830b9 : 0000057ffb396398 0000057ffad038f8 0000000000000000 0000000000000004 : pci6000!PCI6000EvtIoDeviceControl+0x634 [e:\test\pci6000\pci6000_ioctl.c @ 369]
fffffa6009bb64d0 fffffa600088259e : 0000057ffad03800 0000057ffad038f8 fffffa80069a7010 fffffa80052fc700 : Wdf01000!FxIoQueue::DispatchRequestToDriver+0x6d9
fffffa6009bb6570 fffffa6000881d22 : fffffa8004c69c60 0000000000000000 fffffa8004c69c00 fffffa6000860023 : Wdf01000!FxIoQueue::DispatchEvents+0x83e
fffffa6009bb66d0 fffffa6000888f59 : fffffa80069a7000 fffffa80052fc700 0000057ffb396398 0000057ffad038f8 : Wdf01000!FxIoQueue::QueueRequestFromForward+0x42e
fffffa6009bb6780 fffffa600084b5e0 : 0000057ffad03800 fffffa80069a7010 fffffa8004acd8d0 fffffa600abcc5a0 : Wdf01000!FxPkgIo::EnqueueRequest+0x3dd
fffffa6009bb6820 fffffa600abc4635 : fffffa80052fc700 0000057ffad038f8 fffffa6009bb6898 fffffa8005e1c080 : Wdf01000!imp_WdfDeviceEnqueueRequest+0x60
fffffa6009bb6860 fffffa600abcc7b1 : 0000057ffa1e3f78 0000057ffad038f8 0000000000000065 0000000000000003 : pci6000!WdfDeviceEnqueueRequest+0x25 [e:\ddks\winddk\6001.18001\inc\wdf\kmdf\1.7\wdfdevice.h @ 3181]
fffffa6009bb6890 fffffa6000888750 : 0000057ffa1e3f78 0000057ffad038f8 fffffa80053c1800 fffffa80069a70f0 : pci6000!PCI6000EvtDeviceIoInCallerContext+0x211 [e:\test\pci6000\pci6000_ioctl.c @ 139]
fffffa6009bb6910 fffffa600086c865 : 0000000086782000 fffffa80052fc700 fffffa80053c1760 fffffa8004ce5bd0 : Wdf01000!FxPkgIo::Dispatch+0x4d0
fffffa6009bb69e0 fffff8000210fb1e : fffffa8004e27ea0 0000000000000004 fffffa80053c1878 0000000076f9f801 : Wdf01000!FxDevice::Dispatch+0xa9
fffffa6009bb6a10 fffff80002118586 : 0000000000000000 0000000000000000 0000000000000000 0000000000000000 : nt!IopXxxControlFile+0x5be
fffffa6009bb6b40 fffff80001eacef3 : 0000000000000000 0000000000000000 0000000000000000 0000000000000000 : nt!NtDeviceIoControlFile+0x56
fffffa6009bb6bb0 000000007514385e : fffffa6009bb6c20 000000000007ee28 0000000200000030 0000000075143d09 : nt!KiSystemServiceCopyEnd+0x13
000000000007ede8 000000007524ab46 : 0000000000000000 000000000007fd20 00000000752a87c3 000000000007f820 : wow64cpu!DeviceIoctlFileFault+0x35
000000000007eed0 000000007524a14c : 0000000000000000 0000000000000000 0000000075243258 000000007ffe0030 : wow64!RunCpuSimulation+0xa
000000000007ef00 0000000076f8bf9d : 0000000076f50000 0000000000000000 000000007efdf000 000000007efdf000 : wow64!Wow64LdrpInitialize+0x4b4
000000000007f460 0000000076f8bb9c : 0000000000000000 0000000000000000 000000007efdf000 0000000076f8d5c7 : ntdll!LdrpInitializeProcess+0x1568
000000000007f720 0000000076f768de : 000000000007f820 0000000000000000 000000007efdf000 0000000000000000 : ntdll! ?? ::FNODOBFM::string'+0x20959 000000000007f7d0 0000000000000000 : 0000000000000000 0000000000000000 0000000000000000 00000000`00000000 : ntdll!LdrInitializeThunk+0xe

STACK_COMMAND: kb

FOLLOWUP_IP:
pci6000!WdfDmaTransactionExecute+25 [e:\ddks\winddk\6001.18001\inc\wdf\kmdf\1.7\wdfdmatransaction.h @ 189]
fffffa60`0abc4335 4883c428 add rsp,28h

FAULTING_SOURCE_CODE:
185: WDFCONTEXT Context
186: )
187: {
188: return ((PFN_WDFDMATRANSACTIONEXECUTE) WdfFunctions[WdfDmaTransactionExecuteTableIndex])(WdfDriverGlobals, DmaTransaction, Context);

189: }
190:
191: //
192: // WDF Function: WdfDmaTransactionRelease
193: //
194: typedef

SYMBOL_STACK_INDEX: f

SYMBOL_NAME: pci6000!WdfDmaTransactionExecute+25

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: pci6000

IMAGE_NAME: pci6000.sys

DEBUG_FLR_IMAGE_TIMESTAMP: 4b696ad8

FAILURE_BUCKET_ID: X64_0xA_pci6000!WdfDmaTransactionExecute+25

BUCKET_ID: X64_0xA_pci6000!WdfDmaTransactionExecute+25

Followup: MachineOwner

5

Some generic debugging advice here:

You definitely want to eliminate any 32-bit to 64-bit issues that you may be having… so, as a first step (as Max suggested) get this working on x86. On x64 there’s the 4GB+ of physical memory issue (and the differences with how the DMA buffers are handled for that), as well as the user buffer pointer issues to deal with. You don’t want to be trying to solve multiple potential problems at one time.

Also, I assume that NONE of your driver is pageable, right? If it is, one tends to debug these things by removing any pageable routine designations.

I also assume you’re running with KMDF Verifier enabled. If not, please enable it for your driver.

In terms of more specific help:

The MDL you’re passing in, and the buffer to which it points, are both valid? Where IS the buffer, in the user’s address space I assume? Why are you allocating an MDL in the InCallerContext callback as opposed to using a standard Request object?

Peter
OSR

6

Hi Maxim,

Yes, my first thought was that the user buffer wasn’t locked down correctly. To test, I setup the device to periodically interrupt (via the device’s Local Interrupt) and within the interrupt handler, I write to the virtual address acquired for the user buffer. In a user mode application, I can view the contents of the buffer–and I see the data I expected. So, I can write to all of the user buffer from within the interrupt handler.

This virtual address (and it’s mdl) used in the isr is the same that I feed the DMA engine in WdfDmaTransactionInitialize. Do I need to do something differently for the DMA, vs direct access in an isr?

Note that I do detect whether the app sending the Request is 32-bits, and account for the different pointer size within the buffer:

typedef struct _SUBSYS_ISRDATA32
{
…
CHAR*POINTER_32 DataPtr;
…
} SUBSYS_ISRDATA32, *PSUBSYS_ISRDATA32;

In the EvtDeviceIoInCallerContext, I map the user buffer into the kernel like this:

pBuffer = (PVOID)subSys->DataPtr;

usrScan->pBufferMdl = IoAllocateMdl( pBuffer,
byteCount,
FALSE,
FALSE,
NULL);

//…
try
{
MmProbeAndLockPages( usrScan->pBufferMdl,
KernelMode,
IoModifyAccess);

usrScan->pBufferStart = (PUSHORT)MmGetSystemAddressForMdlSafe(usrScan->pBufferMdl, NormalPagePriority);
}
except {…
}

Thanks,
Larry

7

> To test, I setup the device to periodically interrupt (via the device’s Local Interrupt) and within the >interrupt handler, I write to the virtual address acquired for the user buffer.
In your ISR you should only verify an interrupt. The rest processing should be done in DPC.
Which example of PLX9x5x sample do you use? The latest WDK contains example which was written on WDF. You should look this sample again. It does not use such sequences of call to Windows API to get MDL, which you use. WDF does all work. In your dispatcher functions EvtIoRead/EvtIoWrite you get request and calls WdfDmaTransactionInitializeUsingRequest. In callback function EvtProgramXXXDma you already get builded SGL.

Igor Sharovar

8

Hi Igor,

I used the WDF version of the PLX9x5x. In fact, I borrowed heavily from it.

I would have liked to use EvtIoRead/Write handling of the sample, but I have large DLL with a lot of history that is calling into the driver, and I can only make minor changes to the operation of the DLL. When this DLL initiates DMA’s, it expects the request to complete when the transfer is setup, not when the transfer completes.

The code writing to the buffer in the ISR was for testing purposes. I figured if I had a problem with locking down the buffer and retrieving a virtual address, I should see a bug check when accessing it in an ISR. If I got (un)lucky and managed to lock down a buffer, just not the user buffer I intended, then filling the buffer with data and displaying the user buffer in the application should indicate a problem.

But I don’t get a bug check, and displaying the contents of the buffer in the application shows the pattern I expected…

I don’t know if this has anything to do with the problem I’m seeing, but calling WdfDmaTransactionSetMaximumLength before WdfDmaTransactionInitialize leads to a bug check…I hadn’t noticed any indication in the docs that SetMaximumLenght must follow the Initialize function–only that the DmaTransaction must first be created. Perhaps the issue is with the DmaTransaction…

Thanks,
Larry

9

>I would have liked to use EvtIoRead/Write handling of the sample, but I have large DLL with a lot of >history that is calling into the driver, and I can only make minor changes to the operation of the DLL. >When this DLL initiates DMA’s, it expects the request to complete when the transfer is setup, not when >the transfer completes.
Understood.
Why do you allocate MDL in driver? You could use DIRECT I/O request for communicating from user application to the driver. In this case when the drivers gets request a MDL would be already created. You just need to call WdfRequestRetrieveInputWdmMdl to get MDL.

Igor Sharovar

10

While I still have work to do, I am past the bug check that was occurring upon WdfDmaTransactionExecute, at least on the 32-bit platform.

Reviewing the WDM support for DMA in Oney’s book, I noticed that he uses the VIRTUAL address of the MDL retrieved via MmGetMdlVirtualAddress to index into the buffer described by the MDL. I, however, was supplying the WdfDmaTransactionInitialize function the SYSTEM address retrieved via MmGetSystemAddressForMdlSafe…

Thanks,
Larry