search

microsoft / Windows-driver-samples

This repo contains driver samples prepared for use with Microsoft Visual Studio and the Windows Driver Kit (WDK). It contains both Universal Windows Driver and desktop-only driver samples.
Microsoft Public License
6.88k stars 4.92k forks source link

WdfRequestRetrieveOutputBuffer in Ppm_SaveMessageInContentsInRequest #112

Open n-mam opened 7 years ago

n-mam commented 7 years ago

In the below execute-complete sequence , what happens if an asynchronous Ppm_PowerOff (via EvtDeviceD0Exit due to S4/D3 hibernate) is triggered on the UCSI stack somewhere around the point when we zero out cmdCtx via Ppm_CompleteActiveRequest ?

    status = Ppm_ExecuteCommand(ppmCtx, cmdCtx->Command);
    if (!NT_SUCCESS(status))
    {
        cmdCtx->Status = status;
        Ppm_CompleteActiveRequest(ppmCtx);
        goto Exit;
    }

Ppm_CompleteActiveRequest:

    RtlZeroMemory(cmdCtx, sizeof(*cmdCtx));

As EvtDeviceD0Exit is asynchronous and since the ACPI notify callback for a command completion (in response to BIOS notify 80 for the last SetNotificationEnable command via Ppm_PowerOff ) can also be triggered any time, there is a potential that the zero'ing out of cctx from Ppm_CompleteActiveRequest happens while the last notify 80 callback is being executed.. The function Ppm_SaveMessageInContentsInRequest touches the WDF request without checking if it is a valid request. It could happen that just around the time it tries to get the output buffer The ctx structure (and hence it's request member) is zeroed out as a result of an earlier Ppm_CompleteActiveRequest call status = WdfRequestRetrieveOutputBuffer(request, outputSize, (PVOID*) &messageIn, nullptr);

n-mam commented 7 years ago 
2: kd> .bugcheck
Bugcheck code 0000010D
Arguments 00000000`00000005 00000000`00000000 00000000`00001008 ffffd10e`ea5be590
2: kd> k
 # Child-SP          RetAddr           Call Site
00 ffffab81`1a4fc978 fffff806`6d88c6f6 nt!KeBugCheckEx
01 (Inline Function) --------`-------- Wdf01000!Mx::MxBugCheckEx+0x13
02 ffffab81`1a4fc980 fffff806`6d85be67 Wdf01000!FxVerifierBugCheckWorker+0x1e [d:\rs1\minkernel\wdf\framework\shared\object\fxverifierbugcheck.cpp @ 68]
03 (Inline Function) --------`-------- Wdf01000!FxObjectHandleGetPtr+0x48bc9
04 (Inline Function) --------`-------- Wdf01000!FxObjectHandleGetPtrAndGlobals+0x48bc9
05 ffffab81`1a4fc9c0 fffff806`73203d13 Wdf01000!imp_WdfRequestRetrieveOutputBuffer+0x48be7 [d:\rs1\minkernel\wdf\framework\shared\core\fxrequestapi.cpp @ 1132]
06 ffffab81`1a4fca50 fffff806`7320bf04 UcmUcsi!Ppm_SaveMessageInContentsInRequest+0x7f
07 ffffab81`1a4fcaa0 fffff806`73203a10 UcmUcsi!Ppm_CommandCompletionHandler+0xf4
08 ffffab81`1a4fcb00 fffff806`732038d1 UcmUcsi!Ppm_ProcessNotifications+0x108
09 ffffab81`1a4fcb60 fffff806`6d9a4b8a UcmUcsi!Ppm_NotificationHandler+0x81
0a ffffab81`1a4fcbb0 fffff801`ac8a01b9 ACPI!DispatchNotificationWorker+0xaa
0b ffffab81`1a4fcc00 fffff801`ac80b729 nt!ExpWorkerThread+0xe9
0c ffffab81`1a4fcc90 fffff801`ac958bb6 nt!PspSystemThreadStartup+0x41
0d ffffab81`1a4fcce0 00000000`00000000 nt!KiStartSystemThread+0x16
2: kd> !poaction
PopAction: fffff801acb0a3c0
  State..........: 3 - Set System State
  Updates........: 0 
  Action.........: Sleep
  Lightest State.: Hibernate
  Flags..........: 8000000c OverrideApps|Critical
  Irp minor......: SetPower
  System State...: Hibernate
  Hiber Context..: ffffd10eda9833c0

Allocated power irps (PopIrpList - fffff801acb0aa30)
  IRP: ffffd10eeb2af8e0 (wait-wake/S3), PDO: ffffd10ee8cf2e20
  IRP: ffffd10eea2a0800 (set/S4), PDO: ffffd10eea5a9ca0, CURRENT: ffffd10ee9397700, NOTIFY: ffffd10ee94260a0
  IRP: ffffd10eea3d5450 (set/D3,), PDO: ffffd10eea5a9ca0, CURRENT: ffffd10ee9397700
  IRP: ffffd10eeab57c10 (set/S4), PDO: ffffd10ee7b72b90, CURRENT: ffffd10ee8b51c60, NOTIFY: ffffd10ee7b73dc0
  IRP: ffffd10eea8d0010 (set/D3,), PDO: ffffd10ee7b72b90, CURRENT: ffffd10ee8b51c60

Irp worker threads (PopIrpThreadList - fffff801acb09670)
  THREAD: ffffd10eda463040 (static)
  THREAD: ffffd10eda464040 (static)
  THREAD: ffffd10ee9469040 (dynamic)
  THREAD: ffffd10eea473040 (dynamic), IRP: ffffd10eea3d5450, DEVICE: ffffd10ee9397700
  THREAD: ffffd10eeadda040 (dynamic)
  THREAD: ffffd10eea5c57c0 (dynamic)
  THREAD: ffffd10eea316040 (dynamic), IRP: ffffd10eea8d0010, DEVICE: ffffd10ee8b51c60
  THREAD: ffffd10eeaaab040 (dynamic)
  THREAD: ffffd10ee9308040 (dynamic)
  THREAD: ffffd10eea7be280 (dynamic)
  THREAD: ffffd10eeab87040 (dynamic)
  THREAD: ffffd10eea705040 (dynamic)
  THREAD: ffffd10eea96e7c0 (dynamic)
  THREAD: ffffd10eea5ac040 (dynamic)
  THREAD: ffffd10eeaf77040 (dynamic)

Broadcast in progress: TRUE

Device State ffffd10eeb4bedd0
  Irp minor......: SetPower
  System State...: Hibernate
  Worker thread..: ffffd10ee87d37c0
  Status.........: 0
  Waking.........: FALSE
  Cancelled......: FALSE
  Ignore errors..: TRUE
  Ignore not imp.: FALSE

2: kd> !amli lc
 Ctxt=ffffd10ee8c36010, ThID=ffffd10eea473040, Flgs=---CR----, pbOp=ffffd10ee848a9ad, Obj=\_SB.UBTC._DSM
AMLI_DBGERR: SIG_CTXT does not match (6d9c1310)

2: kd> !stacks 2 UcmUcsi
Proc.Thread  .Thread  Ticks   ThreadState Blocker
                            [fffff801acbc5940 Idle]
                            [ffffd10eda454480 System]
   4.00118c  ffffd10eea56c7c0 ffff9b89 RUNNING    nt!KeBugCheckEx
                                        Wdf01000!FxVerifierBugCheckWorker+0x1e
                                        Wdf01000!FxVerifierBugCheckWorker+0x1e
                                        Wdf01000!imp_WdfRequestRetrieveOutputBuffer+0x48be7
                                        Wdf01000!imp_WdfRequestRetrieveOutputBuffer+0x48be7
                                        Wdf01000!imp_WdfRequestRetrieveOutputBuffer+0x48be7
                                        UcmUcsi!Ppm_SaveMessageInContentsInRequest+0x7f
                                        UcmUcsi!Ppm_CommandCompletionHandler+0xf4
                                        UcmUcsi!Ppm_ProcessNotifications+0x108
                                        UcmUcsi!Ppm_NotificationHandler+0x81
                                        ACPI!DispatchNotificationWorker+0xaa
                                        nt!ExpWorkerThread+0xe9
                                        nt!PspSystemThreadStartup+0x41
                                        nt!KiStartSystemThread+0x16
   4.00135c  ffffd10eea473040 ffff9b8a RUNNING    ACPI!GetNameSpaceObjectNoLock+0xfd
                                        ACPI!GetNameSpaceObject+0x86
                                        ACPI!ParseAndGetNameSpaceObject+0x4a
                                        ACPI!ParseNameObj+0x34
                                        ACPI!ParseScope+0x8b2
                                        ACPI!RunContext+0x1e0
                                        ACPI!InsertReadyQueue+0x403
                                        ACPI!RestartContext+0x151
                                        ACPI!SyncEvalObject+0x28b
                                        ACPI!AMLIEvalNameSpaceObject+0xad
                                        ACPI!ACPIIoctlEvalControlMethod+0x68
                                        ACPI!ACPIIrpDispatchDeviceControl+0x157
                                        ACPI!ACPIDispatchIrp+0xce
                                        Wdf01000!FxIoTarget::SubmitSync+0x1a5
                                        Wdf01000!FxIoTarget::SubmitSync+0x1a5
                                        Wdf01000!FxIoTargetSendIoctl+0x392
                                        Wdf01000!imp_WdfIoTargetSendInternalIoctlSynchronously+0x48
                                        UcmUcsi!Acpi_EvaluateUcsiDsm+0x2d4
                                        UcmUcsi!Ppm_ExecuteCommand+0xc4
                                        UcmUcsi!Fdo_EvtDeviceD0Exit+0xe3
                                        Wdf01000!FxPnpDeviceD0Exit::InvokeClient+0x2e
                                        Wdf01000!FxPrePostCallback::InvokeStateless+0x36
                                        Wdf01000!FxPkgPnp::PowerGotoDxIoStopped+0xfb
                                        Wdf01000!FxPkgPnp::PowerGotoDxIoStopped+0xfb
                                        Wdf01000!FxPkgPnp::PowerGotoDNotZeroIoStopped+0x9
                                        Wdf01000!FxPkgPnp::PowerProcessEventInner+0x231
                                        Wdf01000!FxPkgPnp::PowerProcessEventInner+0x231
                                        Wdf01000!FxPkgPnp::PowerProcessEvent+0x16a
                                        Wdf01000!FxPkgFdo::DispatchDeviceSetPower+0x65
                                        Wdf01000!FxPkgFdo::DispatchDeviceSetPower+0x65
                                        Wdf01000!FxPkgPnp::Dispatch+0xef
                                        Wdf01000!FxDevice::DispatchWithLock+0x155
                                        Wdf01000!FxDevice::DispatchWithLock+0x155
                                        Wdf01000!FxDevice::DispatchWithLock+0x155
                                        nt!PopIrpWorker+0x1de
                                        nt!PspSystemThreadStartup+0x41
                                        nt!KiStartSystemThread+0x16

24: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering power policy state WdfDevStatePwrPolStarted from WdfDevStatePwrPolStartingDecideS0Wake
25: FxPowerIdleMachine::ProcessEventLocked - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering power idle state FxIdleDisabled from FxIdleDisabled
26: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering PnP State WdfDevStatePnpEnableInterfaces from WdfDevStatePnpHardwareAvailable
27: FxPkgPnp::PnpEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering PnP State WdfDevStatePnpStarted from WdfDevStatePnpEnableInterfaces
28: FxPkgPnp::Dispatch - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700, IRP_MJ_PNP, 0x00000014(IRP_MN_QUERY_PNP_DEVICE_STATE) IRP 0xFFFFD10EEB47E010
29: FxPkgFdo::HandleQueryPnpDeviceStateCompletion - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 returning PNP_DEVICE_STATE 0x0 IRP 0xFFFFD10EEB47E010
30: FxPkgPnp::Dispatch - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700, IRP_MJ_PNP, 0x00000007(IRP_MN_QUERY_DEVICE_RELATIONS) type BusRelations IRP 0xFFFFD10EEB47E010
31: FxPkgPnp::Dispatch - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 IRP_MJ_POWER, 0x00000002(IRP_MN_SET_POWER) IRP 0xFFFFD10EEA2A0800 for PowerSystemHibernate (S4)
32: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering power policy state WdfDevStatePwrPolSleeping from WdfDevStatePwrPolStarted
33: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering power policy state WdfDevStatePwrPolSleepingNoWakePowerDown from WdfDevStatePwrPolSleeping
34: FxPkgPnp::Dispatch - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 IRP_MJ_POWER, 0x00000002(IRP_MN_SET_POWER) IRP 0xFFFFD10EEA3D5450 for PowerDeviceD3
35: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering Power State WdfDevStatePowerGotoDx from WdfDevStatePowerD0
36: FxSelfManagedIoMachine::ProcessEvent - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering self managed io state FxSelfManagedIoSuspending from FxSelfManagedIoStarted
37: FxSelfManagedIoMachine::ProcessEvent - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering self managed io state FxSelfManagedIoStopped from FxSelfManagedIoSuspending
38: FxPkgIo::StopProcessingForPower - Perform FxIoStopProcessingForPowerHold for all queues of WDFDEVICE 0x00002EF116BDAC38
39: FxPkgPnp::PowerPolicyEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering power policy state WdfDevStatePwrPolSleepingNoWakeCompletePowerDown from WdfDevStatePwrPolSleepingNoWakePowerDown
40: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering Power State WdfDevStatePowerNotifyingD0ExitToWakeInterrupts from WdfDevStatePowerGotoDx
41: FxPkgPnp::PowerEnterNewState - WDFDEVICE 0x00002EF116BDAC38 !devobj 0xFFFFD10EE9397700 entering Power State WdfDevStatePowerGotoDxIoStopped from WdfDevStatePowerNotifyingD0ExitToWakeInterrupts
---- end of log ----
MichelleBergeron commented 7 years ago

Nice race condition @n-mam , thanks for reporting :) We're now tracking this as a bug on our end and we'll fix it in a future version of Windows.