KMDF PCIe driver DPC duration (not latency) nearly triples with graphics activity. RRS feed

  • Question

  • We have a WDF (kmdf) PCIe audio driver that is experiencing much longer than usual (as much as 3x) DPC execution times when there is moderate graphics activity.  I am using the WDF interrupt and DPC, though I've recently tried creating 2 DPCs with WdfDpcCreate() and alternately directing them to a specific CPU at ISR time using basically:

        if (isrBits&audioInt)
                PDPC_CONTEXT pDpc = PcieAudioDeviceGetDpcContext(pThis->mDpcAudio);
                pDpc->regs = READ_REGISTER_ULONG((PULONG)&pThis->mRegisters[REC_INT_INFO]);    // Remove IRQ source and queue DPC
                pDpc->tmr = IsrTime;
                PKDPC dpc = WdfDpcWdmGetDpc(pThis->mDpcAudio);
                KeSetImportanceDpc(dpc, HighImportance);
                if (!KeInsertQueueDpc(dpc, NULL, NULL))
                    LOG(xxxFlag_Error, "  KeInsertQueueDpc(mDpcAudio)  FAILED!");

    I run xperf then stream audio using media player.  I then drag the media player window around for about a second, then leave it completely still for a second or so and repeat this 3 times.  Audio glitches can be heard while I'm dragging the window.  My DPC (and ISR) are on a different CPU from USBXHCI.sys and dxgkrnl.sys (which are busy, but actually quite well-behaved DPC-wise in my traces).  

    Why would my DPC execution time spike so noticeably?  I'm NOT using framework ISR or DPC synchronization:

        // Create the interrupt object here
        WDF_INTERRUPT_CONFIG        InterruptConfig;
        InterruptConfig.EvtInterruptEnable = PcieAudioDevice::sEvtInterruptEnable;
        InterruptConfig.EvtInterruptDisable = PcieAudioDevice::sEvtInterruptDisable;
        InterruptConfig.AutomaticSerialization = FALSE;
        // Define a context area in the WdfInterrupt object
        status = WdfInterruptCreate(device, &InterruptConfig, &attributes, &devExt->mHardwareDevice->mWdfInterrupt);
    ... FOR THE DPC ...
        attributes.ParentObject = device;
        WDF_DPC_CONFIG_INIT(&dpcConfig, PcieAudioDevice::sEvtDpcAudio);
        dpcConfig.AutomaticSerialization = FALSE;
        status = WdfDpcCreate(&dpcConfig, &attributes, &devExt->mHardwareDevice->mDpcAudio);
        if (!NT_SUCCESS(status))
            LOG(xxx_Info, "  WdfDpcCreate for sEvtDpcAudio) failed!", 0, 0, 0, 0);
        pDpcContext = PcieAudioDeviceGetDpcContext(devExt->mHardwareDevice->mDpcAudio);
        pDpcContext->pHardware = devExt->mHardwareDevice;  // Store context in DPC object

    Aside from acquiring my own resource-spinlock (which I've removed for test) what else could possibly cause the DPC to take so long to run?  I see from windbg that there is a "proxy"  handler !FxDpc::DpcHandler, etc  for both the ISR and DPC function vectors.  Could these functions be doing something to introduce longer execution / spin locking into my driver?  Are there any global WDF resources that can be contended for?  

    In the graph below, the spikes are coincident with my dragging the windows around, but the only activity that seems to increase substantially is in my driver.  This particular graph does not show the function name, but with symbol loaded, it shows my sEvtDpcAudio() handler as specified above in the DPC creation.

    Wednesday, August 12, 2015 8:05 PM


  • Look at time spent in ISRs during those spikes. The graphics driver may be spending a lot of time in its ISR, preempting your DPC


    Azius Developer Training Windows device driver, internals, security, & forensics training and consulting. Blog at

    Friday, August 14, 2015 1:34 AM