Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Memory leak caused KMDF verifier bug check on uninstall #25

Open
lstipakov opened this issue Dec 7, 2022 · 2 comments
Open

Memory leak caused KMDF verifier bug check on uninstall #25

lstipakov opened this issue Dec 7, 2022 · 2 comments
Labels
bug Something isn't working

Comments

@lstipakov
Copy link
Member

I once managed to trigger a bug check on uninstall.

 # Child-SP          RetAddr               Call Site
00 ffffc182`daf9e258 fffff801`4a8142fa     nt!KeBugCheckEx
01 ffffc182`daf9e260 fffff801`4a7ce51f     nt!PspSystemThreadStartup$filt$0+0x44
02 ffffc182`daf9e2a0 fffff801`4a8039bf     nt!_C_specific_handler+0x9f
03 ffffc182`daf9e310 fffff801`4a677a77     nt!RtlpExecuteHandlerForException+0xf
04 ffffc182`daf9e340 fffff801`4a676676     nt!RtlDispatchException+0x297
05 ffffc182`daf9ea60 fffff801`4a80d46c     nt!KiDispatchException+0x186
06 ffffc182`daf9f120 fffff801`4a8064d0     nt!KiExceptionDispatch+0x12c
07 ffffc182`daf9f300 fffff801`4a802851     nt!KiBreakpointTrap+0x310
08 ffffc182`daf9f498 fffff801`4c9fdd5c     nt!DbgBreakPoint+0x1
09 (Inline Function) --------`--------     Wdf01000!Mx::MxDbgBreakPoint+0xc [minkernel\wdf\framework\shared\inc\primitives\km\MxGeneralKm.h @ 156] 
0a ffffc182`daf9f4a0 fffff801`4ca28493     Wdf01000!FxVerifierDbgBreakPoint+0x50 [minkernel\wdf\framework\shared\inc\private\common\fxverifier.h @ 103] 
0b ffffc182`daf9f4e0 fffff801`4ca264f2     Wdf01000!FxPoolDump+0x17b [minkernel\wdf\framework\shared\object\wdfpool.cpp @ 545] 
0c (Inline Function) --------`--------     Wdf01000!FxPoolDestroy+0x42 [minkernel\wdf\framework\shared\object\wdfpool.cpp @ 648] 
0d (Inline Function) --------`--------     Wdf01000!FxPoolPackageDestroy+0x46 [minkernel\wdf\framework\shared\object\wdfpool.cpp @ 707] 
0e ffffc182`daf9f580 fffff801`4ca236e7     Wdf01000!FxDestroy+0xa6 [minkernel\wdf\framework\shared\object\globals.cpp @ 1167] 
*** WARNING: Unable to verify timestamp for ovpn-dco.sys
0f ffffc182`daf9f5c0 fffff801`5a099682     Wdf01000!FxDriver::Unload+0xe7 [minkernel\wdf\framework\shared\core\fxdriver.cpp @ 202] 
10 ffffc182`daf9f610 ffff8d05`402ece30     ovpn_dco+0x9682
11 ffffc182`daf9f618 ffffc182`daf9f7a0     0xffff8d05`402ece30
12 ffffc182`daf9f620 00000000`c0000001     0xffffc182`daf9f7a0
13 ffffc182`daf9f628 ffffe70b`2ea45880     0xc0000001
14 ffffc182`daf9f630 00000000`00000000     0xffffe70b`2ea45880

It seems that WDF detected a leak (from wdfpool.cpp):

if (leak) {
    FxVerifierDbgBreakPoint(FxDriverGlobals);
    return STATUS_MORE_ENTRIES;
}

Normally this doesn't cause a bug check, but since I have KMDF verifier on, here we are.

I was unable to reproduce it anymore.
@lstipakov lstipakov added the bug Something isn't working label Dec 7, 2022
@lstipakov
Copy link
Member Author

I have spent some time trying to reproduce it and monitoring pool usage with poolmon -inpvo without success - at driver removal all pool allocations are freed. Will keep an eye on it.

@lstipakov
Copy link
Member Author

I managed to reproduce it again on the same machine while upgrading from beta2 to rc1.

1: kd> !wdfcrashdump
Retrieving crashdump log information...
Local buffer 0x000001A1C17DAB60, bufferSize 4096
Driver: ovpn-dco
Trace searchpath is: 

Trace format prefix is: %7!u!: %!FUNC! - 
Trying to extract TMF information from - c:\temp\ovpn-dco 0.8.3\signed\amd64\win10\Wdf01000.pdb\6948A828801BE167AC9E65B7605CBF611\Wdf01000.pdb
There are 94 log entries for ovpn-dco
--- start of log ---
11903: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power idle state FxIdleGoingToDx from FxIdleDisabled
11904: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power idle state FxIdleInDx from FxIdleGoingToDx
11905: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering Power State WdfDevStatePowerStopped from WdfDevStatePowerGotoD3Stopped
11906: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power policy state WdfDevStatePwrPolStoppingSendStatus from WdfDevStatePwrPolStopping
11907: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power idle state FxIdleInDxStopped from FxIdleInDx
11908: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power idle state FxIdleStopped from FxIdleInDxStopped
11909: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power policy state WdfDevStatePwrPolStopped from WdfDevStatePwrPolStoppingSendStatus
11910: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering PnP State WdfDevStatePnpRemovingDisableInterfaces from WdfDevStatePnpQueriedRemoving
11911: FxPkgIo::StopProcessingForPower - Perform FxIoStopProcessingForPowerPurgeManaged for all queues of WDFDEVICE 0x000030F06D2DDFC8
11912: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D386518 requests cancelled
11913: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D386518
11914: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D386518
11915: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D386518
11916: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D386518 Power Transition State 0x00000007(FxIoQueuePowerPurge)
11917: FxIoQueue::ProcessPowerEvents - Power purge: WDFQUEUE 0x000030F06D386518 is purging without in-flight requests
11918: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D386518 Power Transition State 0x00000008(FxIoQueuePowerPurgeNotifyingDriver)
11919: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D386518 Power Transition State 0x00000009(FxIoQueuePowerPurgeDriverNotified)
11920: FxIoQueue::ProcessPowerEvents - Power Stop: WDFQUEUE 0x000030F06D386518 is now powered off with no in-flight requests
11921: FxIoQueue::StopProcessingForPower - Waiting for all inflight requests to be acknowledged  on WDFQUEUE 0x000030F06D386518
11922: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D3A8518 requests cancelled
11923: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D3A8518
11924: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3A8518
11925: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3A8518
11926: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3A8518 Power Transition State 0x00000007(FxIoQueuePowerPurge)
11927: FxIoQueue::ProcessPowerEvents - Power purge: WDFQUEUE 0x000030F06D3A8518 is purging without in-flight requests
11928: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3A8518 Power Transition State 0x00000008(FxIoQueuePowerPurgeNotifyingDriver)
11929: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3A8518 Power Transition State 0x00000009(FxIoQueuePowerPurgeDriverNotified)
11930: FxIoQueue::ProcessPowerEvents - Power Stop: WDFQUEUE 0x000030F06D3A8518 is now powered off with no in-flight requests
11931: FxIoQueue::StopProcessingForPower - Waiting for all inflight requests to be acknowledged  on WDFQUEUE 0x000030F06D3A8518
11932: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D3CA518 requests cancelled
11933: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D3CA518
11934: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3CA518
11935: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3CA518
11936: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3CA518 Power Transition State 0x00000007(FxIoQueuePowerPurge)
11937: FxIoQueue::ProcessPowerEvents - Power purge: WDFQUEUE 0x000030F06D3CA518 is purging without in-flight requests
11938: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3CA518 Power Transition State 0x00000008(FxIoQueuePowerPurgeNotifyingDriver)
11939: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3CA518 Power Transition State 0x00000009(FxIoQueuePowerPurgeDriverNotified)
11940: FxIoQueue::ProcessPowerEvents - Power Stop: WDFQUEUE 0x000030F06D3CA518 is now powered off with no in-flight requests
11941: FxIoQueue::StopProcessingForPower - Waiting for all inflight requests to be acknowledged  on WDFQUEUE 0x000030F06D3CA518
11942: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D3EE508 requests cancelled
11943: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D3EE508
11944: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3EE508
11945: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3EE508
11946: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3EE508 Power Transition State 0x00000007(FxIoQueuePowerPurge)
11947: FxIoQueue::ProcessPowerEvents - Power purge: WDFQUEUE 0x000030F06D3EE508 is purging without in-flight requests
11948: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3EE508 Power Transition State 0x00000008(FxIoQueuePowerPurgeNotifyingDriver)
11949: FxIoQueue::DispatchEvents - WDFQUEUE 0x000030F06D3EE508 Power Transition State 0x00000009(FxIoQueuePowerPurgeDriverNotified)
11950: FxIoQueue::ProcessPowerEvents - Power Stop: WDFQUEUE 0x000030F06D3EE508 is now powered off with no in-flight requests
11951: FxIoQueue::StopProcessingForPower - Waiting for all inflight requests to be acknowledged  on WDFQUEUE 0x000030F06D3EE508
11952: FxSelfManagedIoMachine::ProcessEvent - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering self managed io state FxSelfManagedIoFlushing from FxSelfManagedIoStopped
11953: FxSelfManagedIoMachine::ProcessEvent - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering self managed io state FxSelfManagedIoFlushed from FxSelfManagedIoFlushing
11954: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power policy state WdfDevStatePwrPolStoppedRemoving from WdfDevStatePwrPolStopped
11955: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering power policy state WdfDevStatePwrPolRemoved from WdfDevStatePwrPolStoppedRemoving
11956: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering PnP State WdfDevStatePnpRemoved from WdfDevStatePnpRemovingDisableInterfaces
11957: FxChildList::NotifyDeviceRemove - WDFCHILDLIST 000030F06D323208:  removing children
11958: FxChildList::ProcessModificationsLocked - Begin processing modifications on WDFCHILDLIST 000030F06D323208
11959: FxChildList::ProcessModificationsLocked - end processing modifications on WDFCHILDLIST 000030F06D323208
11960: FxChildList::ProcessModificationsLocked - Begin processing modifications on WDFCHILDLIST 000030F06D323208
11961: FxChildList::ProcessModificationsLocked - end processing modifications on WDFCHILDLIST 000030F06D323208
11962: FxChildList::ProcessModificationsLocked - Begin processing modifications on WDFCHILDLIST 000030F06D323208
11963: FxChildList::ProcessModificationsLocked - end processing modifications on WDFCHILDLIST 000030F06D323208
11964: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering PnP State WdfDevStatePnpRemovedChildrenRemoved from WdfDevStatePnpRemoved
11965: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering PnP State WdfDevStatePnpFdoRemoved from WdfDevStatePnpRemovedChildrenRemoved
11966: FxPkgIo::StopProcessingForPower - Perform FxIoStopProcessingForPowerPurgeNonManaged for all queues of WDFDEVICE 0x000030F06D2DDFC8
11967: FxSelfManagedIoMachine::ProcessEvent - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering self managed io state FxSelfManagedIoCleanup from FxSelfManagedIoFlushed
11968: FxSelfManagedIoMachine::ProcessEvent - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering self managed io state FxSelfManagedIoFinal from FxSelfManagedIoCleanup
11969: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D3EE508 requests cancelled
11970: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D3EE508
11971: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3EE508
11972: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3EE508
11973: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D3CA518 requests cancelled
11974: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D3CA518
11975: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3CA518
11976: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3CA518
11977: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D3A8518 requests cancelled
11978: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D3A8518
11979: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3A8518
11980: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D3A8518
11981: FxIoQueue::QueuePurge - All WDFQUEUE 0x000030F06D386518 requests cancelled
11982: FxIoQueue::QueuePurge - All driver cancellable requests cancelled  in WDFQUEUE 0x000030F06D386518
11983: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D386518
11984: FxIoQueue::DispatchEvents - Thread FFFFCF0FA7AD7040 is processing WDFQUEUE 0x000030F06D386518
11985: FxPkgPnp::RemoveChildList - Removing FxChildList FFFFCF0F92CDCDF0, WDFCHILDLIST 000030F06D323208
11986: FxIoTarget::WaitForDisposeEvent - WDFIOTARGET 000030F06D538248, Waiting on Dispose event FFFFB786B99CF0E0
11987: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x000030F06D2DDFC8 !devobj 0xFFFFCF0F92ADF540 entering PnP State WdfDevStatePnpFinal from WdfDevStatePnpFdoRemoved
11988: FxPkgPnp::_PnpRemoveDevice - WDFDEVICE 000030F06D2DDFC8, !devobj FFFFCF0F92ADF540 waiting for remove event to finish processing
11989: FxPkgPnp::CleanupStateMachines - WDFDEVICE 000030F06D2DDFC8, !devobj FFFFCF0F92ADF540 waiting for pnp state machine to finish
11990: FxDevice::Destroy - Deleting !devobj FFFFCF0F92ADF540, WDFDEVICE 000030F06D2DDFC8, attached to !devobj FFFFCF0F8D1F2DA0
11991: FxPkgIo::~FxPkgIo - Destroyed FxPkgIo 0xFFFFCF0F92ACA090
11992: FxDriver::Unload - Unloading WDFDRIVER 000030F06D2F0268, PDRIVER_OBJECT_UM FFFFCF0F92C7CE30
11993: FxDriver::Unload - Driver unload routine Exit WDFDRIVER 000030F06D2F0268, PDRIVER_OBJECT_UM FFFFCF0F92C7CE30
11994: FxPoolDestroy - Destroying Pool 0xFFFFCF0F92C95E48
11995: FxPoolDump - FxPoolDump: NonPagedBytes 136, PagedBytes 0, NonPagedAllocations 1, PagedAllocations 0,PeakNonPagedBytes 33748, PeakPagedBytes 392,FxPoolDump: PeakNonPagedAllocations 131, PeakPagedAllocations 10
11996: FxPoolDump - FX_POOL 0xFFFFCF0F92C95E48 leaked non-paged memory alloc 0xFFFFCF0FB5044A50 (tracking block FFFFCF0FB5044A10)
---- end of log ----

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
1 participant
@lstipakov