Re: [win-pv-devel] xenvif Win7 BSOD - DRIVER_POWER_STATE_FAILURE

[Paul Durrant <Paul.Durrant@xxxxxxxxxx>]

> -----Original Message-----
> From: win-pv-devel [mailto:win-pv-devel-bounces@xxxxxxxxxxxxxxxxxxxx] On
> Behalf Of Martin Cerveny
> Sent: 05 February 2017 00:16
> To: win-pv-devel@xxxxxxxxxxxxxxxxxxxx
> Subject: [win-pv-devel] xenvif Win7 BSOD - DRIVER_POWER_STATE_FAILURE
> 
> Hello.
> 
> Sometimes (1:50) the shutdown of domain hung and reset after timeout
> (few
> minutes) with BSOD - DRIVER_POWER_STATE_FAILURE. The problem
> appeared from
> my first usage of 8.2 development PV drivers (eg. > 6 month).
> 
> Is it normal for xenvif that "(d2) XENVIF|VifDisable: ====>" did not
> finish and started wait for packet "(d2) XENVIF|ReceiverWaitForPackets:
> device/vif/0: ====>"
> after disable ?

This suggests that the network stack has not returned all packets to the 
driver, or that there is an accounting error somewhere. XENVIF is waiting 
because it cannot shutdown until all buffers are back (because it would leak 
memory otherwise).
In some versions of Windows it seems that trying to indicate more than one 
packet at once can lead to this kind of problem, so I added patch b4ac56d6a714 
on Sept 22 last year. I guess you were using code older than that.

 Cheers,

  Paul

> 
> Thanks, Martin Cerveny
> 
> (I have last minidump if need to check some driver state)
> 
> -----------------------------------------------------------------------------
> 
> Config:
> 
> - xen4.8 + xen4.5.3
> - Dom0 kernel 4.7.9-200.fc24.x86_64 or 3.10-xs
> - win7 with git drivers ("Xen_Project XEN* 8.2.0 (DEBUG)")
> 
> Xen console output (only XENVIF after shutdown begins):
> 
> (d2) XENVIF|MacDumpAddressTable: ====>
> (d2) XENVIF|MacDumpAddressTable: <====
> (d2) XENVIF|MacRemoveMulticastAddress: attr/vif/0: 01:00:5E:7F:FF:FA
> (d2) XENVIF|MacDumpAddressTable: ====>
> (d2) XENVIF|MacDumpAddressTable: <====
> (d2) XENVIF|MacRemoveMulticastAddress: attr/vif/0: 33:33:00:00:00:0C
> (d2) XENVIF|VifDisable: ====>
> (d2) XENVIF|FrontendDisable: ====>
> (d2) XENVIF|TransmitterDisable: ====>
> (d2) XENVIF|TransmitterDisable: <====
> (d2) XENVIF|ReceiverDisable: ====>
> (d2) XENVIF|ReceiverDisable: <====
> (d2) XENVIF|MacDisable: ====>
> (d2) XENVIF|MacDisable: <====
> (d2) XENVIF|FrontendDisable: <====
> (d2) XENVIF|ReceiverWaitForPackets: device/vif/0: ====>
> 
> And then BSOD:
> 
> (d2) XEN|BUGCHECK: ====>
> (d2) XEN|BUGCHECK: DRIVER_POWER_STATE_FAILURE: 0000000000000003
> FFFFFA80068EE240 FFF
> (d2) FF80000B9A3D8 FFFFFA8006879CA0
> (d2) XEN|BUGCHECK: Code 00000003
> (d2) XEN|BUGCHECK: OUTSTANDING IRP FFFFFA8006879CA0 (Device Object
> FFFFFA80068EE240)
> (d2)
> (d2) XEN|BUGCHECK: IRP STACK:
> (d2) XEN|BUGCHECK: [ 0] 16 02 00 e1
> (d2) XEN|BUGCHECK: [ 0] CompletionRoutine = ntoskrnl.exe +
> 00000000002C1210
> (d2) XEN|BUGCHECK: [ 0] Context = FFFFFA8009A4A8A0
> (d2) XEN|BUGCHECK: [ 1] 00 00 00 00
> (d2) XEN|BUGCHECK: [ 1] CompletionRoutine = 0000000000000000
> (d2) XEN|BUGCHECK: [ 1] Context = FFFFFA8009A4A8A0
> (d2) XEN|BUGCHECK: [>2] 00 00 00 00
> (d2) XEN|BUGCHECK: [>2] CompletionRoutine = 0000000000000000
> (d2) XEN|BUGCHECK: [>2] Context = 0000000000000000
> (d2) XEN|BUGCHECK: [ 3] 00 00 00 00
> (d2) XEN|BUGCHECK: [ 3] CompletionRoutine = 0000000000000000
> (d2) XEN|BUGCHECK: [ 3] Context = 0000000000000000
> (d2) XEN|BUGCHECK: <====
> 
> Windbg analyze from minidump:
> 
> -------------------------------------------------------------------------------
> 0: kd> !analyze -v
> **********************************************************
> *********************
> *
> *                        Bugcheck Analysis
> *
> **********************************************************
> *********************
> 
> DRIVER_POWER_STATE_FAILURE (9f)
> A driver has failed to complete a power IRP within a specific time.
> Arguments:
> Arg1: 0000000000000003, A device object has been blocking an Irp for too
> long a time
> Arg2: fffffa80068ee240, Physical Device Object of the stack
> Arg3: fffff80000b9a3d8, nt!TRIAGE_9F_POWER on Win7 and higher,
> otherwise the Functional Device Object of the stack
> Arg4: fffffa8006879ca0, The blocked IRP
> 
> Debugging Details:
> ------------------
> DRVPOWERSTATE_SUBCODE:  3
> IMAGE_NAME:  xenvif.sys
> DEBUG_FLR_IMAGE_TIMESTAMP:  588dd829
> MODULE_NAME: xenvif
> FAULTING_MODULE: fffff88004e00000 xenvif
> DEFAULT_BUCKET_ID:  WIN7_DRIVER_FAULT
> BUGCHECK_STR:  0x9F
> PROCESS_NAME:  System
> CURRENT_IRQL:  2
> ANALYSIS_VERSION: 6.3.9600.17336 (debuggers(dbg).150226-1500) amd64fre
> DPC_STACK_BASE:  FFFFF80000BA0FB0
> 
> STACK_TEXT:
> fffff800`00b9a388 fffff800`02d3f3c0 : 00000000`0000009f 00000000`00000003
> fffffa80`068ee240 fffff800`00b9a3d8 : nt!KeBugCheckEx
> fffff800`00b9a390 fffff800`02cd85cc : fffff800`00b9a4c0 fffff800`00b9a4c0
> 00000000`00000000 00000000`00000001 : nt! ??
> ::FNODOBFM::`string'+0x2e4a0
> fffff800`00b9a430 fffff800`02cd8466 : fffff800`02e81fe0 00000000`000f7a1e
> 00000000`00000000 fffff800`00b9a750 : nt!KiProcessTimerDpcTable+0x6c
> fffff800`00b9a4a0 fffff800`02cd834e : 00000024`d75f3e70 fffff800`00b9ab18
> 00000000`000f7a1e fffff800`02e4e648 : nt!KiProcessExpiredTimerList+0xc6
> fffff800`00b9aaf0 fffff800`02cd8137 : 000000e9`236b75c1 000000e9`000f7a1e
> 000000e9`236b7546 00000000`0000001e : nt!KiTimerExpiration+0x1be
> fffff800`00b9ab90 fffff800`02cc510a : fffff800`02e4be80 fffff800`02e59cc0
> 00000000`00000000 fffff880`08361790 : nt!KiRetireDpcList+0x277
> fffff800`00b9ac40 00000000`00000000 : fffff800`00b9b000 fffff800`00b95000
> fffff800`00b9ac00 00000000`00000000 : nt!KiIdleLoop+0x5a
> 
> STACK_COMMAND:  kb
> FOLLOWUP_NAME:  MachineOwner
> FAILURE_BUCKET_ID:
> X64_0x9F_3_POWER_DOWN_xennet_IMAGE_xenvif.sys
> BUCKET_ID:  X64_0x9F_3_POWER_DOWN_xennet_IMAGE_xenvif.sys
> ANALYSIS_SOURCE:  KM
> FAILURE_ID_HASH_STRING:
> km:x64_0x9f_3_power_down_xennet_image_xenvif.sys
> FAILURE_ID_HASH:  {b27a967d-d007-1b04-dc5b-027eac27961a}
> 
> Followup: MachineOwner
> ---------
> 
> ---------------------------------------------------------------------------------------
> 0: kd> !irp fffffa8006879ca0 1
> 
> Irp is active with 3 stacks 2 is current (= 0xfffffa8006879db8)
>   No Mdl: No System Buffer: Thread 00000000:  Irp stack trace.
> Flags = 00000000
> ThreadListEntry.Flink = fffffa8006879cc0
> ThreadListEntry.Blink = fffffa8006879cc0
> IoStatus.Status = c00000bb
> IoStatus.Information = 00000000
> RequestorMode = 00000000
> Cancel = 00
> CancelIrql = 0
> ApcEnvironment = 00
> UserIosb = 00000000
> UserEvent = 00000000
> Overlay.AsynchronousParameters.UserApcRoutine = 00000000
> Overlay.AsynchronousParameters.UserApcContext = 00000000
> Overlay.AllocationSize = 00000000 - 00000000
> CancelRoutine = 00000000
> UserBuffer = 00000000
> &Tail.Overlay.DeviceQueueEntry = fffffa8006879d18
> Tail.Overlay.Thread = 00000000
> Tail.Overlay.AuxiliaryBuffer = 00000000
> Tail.Overlay.ListEntry.Flink = fffffa8017add0b8
> Tail.Overlay.ListEntry.Blink = fffff80002e81bc0
> Tail.Overlay.CurrentStackLocation = fffffa8006879db8
> Tail.Overlay.OriginalFileObject = 00000000
> Tail.Apc = 00000000
> Tail.CompletionKey = 00000000
>       cmd  flg cl Device   File     Completion-Context
>   [  0, 0]   0  0 00000000 00000000 00000000-00000000
>                          Args: 00000000 00000000 00000000 00000000
> >[ 16, 2]   0 e1 fffffa80081b9050 00000000 fffff80002f1e210-fffffa8009a4a8a0
> Success Error Cancel pending
>                 \Driver\xennet   nt!PopSystemIrpCompletion
>                          Args: 00016600 00000000 00000006 00000006
>   [  0, 0]   0  0 00000000 00000000 00000000-fffffa8009a4a8a0
>                          Args: 00000000 00000000 00000000 00000000
> 
> 
> _______________________________________________
> win-pv-devel mailing list
> win-pv-devel@xxxxxxxxxxxxxxxxxxxx
> https://lists.xenproject.org/cgi-bin/mailman/listinfo/win-pv-devel
_______________________________________________
win-pv-devel mailing list
win-pv-devel@xxxxxxxxxxxxxxxxxxxx
https://lists.xenproject.org/cgi-bin/mailman/listinfo/win-pv-devel