[wdmaudiodev] Re: Possible problem in IPortDMus::Notify and servicegroup dispatching?

  • From: "Evert van der Poll" <evert@xxxxxxxxxxx>
  • To: <wdmaudiodev@xxxxxxxxxxxxx>
  • Date: Sun, 15 Aug 2010 22:03:58 +0100

Hi Tobias,

I have seen this exact behaviour in my own driver and for months I couldn't
figure out what was wrong. It only happened on multi-processor or
hyper-threaded machines, so it was obviously caused by something
deadlocking. The symptoms were: complete system freeze at random moments.
Only hard-reset would help.

I went through my code over and over again but couldn't find anything wrong.
Like you I also suspected IAllocatorMXF::PutMessage(). In the end I used
Syser to track down the problem (where would we be without Syser? Ok, it's
not perfect, but I couldn't have fixed this without it).

I also found IPortDMus::Notify() to be the culprit. Of course it's hard to
provide irrefutable evidence but I'd say this qualifies as a system bug.

What solved it for me is to minimize the IPortDMus::Notify() calls. I use
some sort of flag for indicating that the port has been notified which will
only be reset after the queue has been emptied.
For as long as the flag is set I don't call IPortDMus::Notify() anymore,
since I know that queue processing will continue anyway.


Regards,

Evert van der Poll






-----Original Message-----
From: wdmaudiodev-bounce@xxxxxxxxxxxxx
[mailto:wdmaudiodev-bounce@xxxxxxxxxxxxx]On Behalf Of Tobias Erichsen
Sent: Sunday, August 15, 2010 4:22 PM
To: wdmaudiodev@xxxxxxxxxxxxx
Subject: [wdmaudiodev] Possible problem in IPortDMus::Notify and
servicegroup dispatching?


Hi again,
I have been able to create a crash-dump with my problem using the
<CrashOnCtrlScroll>
method.

When running my driver with verifier active, the freeze does not show up, I
guess the
timing being really tight is important to reproduce the effect (thats also
the reason
why my checked build will not freeze, but runs for hours and hours!)

This time I held no locks whatsoever in my capture-path, no events arrived
on my
render-path during the test - still the system froze after a couple of
seconds...

After analyzing this dump, I think I found an issue in the way Windows XP
handles
IPortDMus::Notify and dispatching the DPCs to the capture-stream's
service-group on
SMP systems.  (Possibly something to do with multiple locks being acquired
in the
wrong order???)

I have found one similar topic here on the list from Art Edwards
("Driver-Verifier-Deadlock-on-x64-System), but  he did not get
any response....

So any pointers would be highly welcome ;-)

Here is what windbg told me:

============================================================================
=====
1: kd> !running -t

System Processors 3 (affinity mask)
  Idle Processors 0

Prcbs  Current   Next
  0    ffdff120  89568020            ................

ChildEBP RetAddr
ba4cbdd8 ba19a7fb nt!KeBugCheckEx+0x1b
ba4cbdf4 ba19a033 i8042prt!I8xProcessCrashDump+0x237
ba4cbe3c 805456e5 i8042prt!I8042KeyboardInterruptService+0x21c
ba4cbe3c 806e785e nt!KiInterruptDispatch+0x45
ba4cbed0 b9815b22 hal!KfAcquireSpinLock+0x2e
ba4cbee0 b9818bd1 portcls!CIrpStream::AcquireMappingIrp+0x12
ba4cbef8 b981a97c portcls!CIrpStream::GetPacketInfo+0x1b
ba4cbf68 b981aba1 portcls!CPackerMXF::CheckIRPHeadTime+0x1a
ba4cbf80 b981ac30 portcls!CPackerMXF::GetDestBuffer+0x10
ba4cbfa0 b9819b27 portcls!CPackerMXF::ProcessQueues+0x59
ba4cbfac b9819f20 portcls!CPortPinDMus::ServeCapture+0x37
ba4cbfb4 b98167bf portcls!CPortPinDMus::RequestService+0x26
ba4cbfcc 80545ebf portcls!CServiceGroup::ServiceDpc+0x2a
ba4cbff4 80545a2b nt!KiRetireDpcList+0x61
ba4cbff8 acec2b98 nt!KiDispatchInterrupt+0x2b
WARNING: Frame IP not in any known module. Following frames may be wrong.
80545a2b 00000000 0xacec2b98

  1    ba338120  8a6f4b30            ................

ChildEBP RetAddr
ba4dbfb8 b981679e nt!KefAcquireSpinLockAtDpcLevel+0x12
ba4dbfcc 80545ebf portcls!CServiceGroup::ServiceDpc+0x1a
ba4dbff4 80545a2b nt!KiRetireDpcList+0x61
ba4dbff8 ba4fbb20 nt!KiDispatchInterrupt+0x2b
WARNING: Frame IP not in any known module. Following frames may be wrong.
80545a2b 00000000 0xba4fbb20
============================================================================
=========
0: kd> !thread
THREAD 89568020  Cid 1514.1574  Teb: 7ffd8000 Win32Thread: e26302e8 RUNNING
on processor 0
IRP List:
    89448ae8: (0006,0094) Flags: 00000a00  Mdl: 893cb008
Not impersonating
DeviceMap                 e23604b0
Owning Process            0       Image:         <Unknown>
Attached Process          891289a0       Image:         virtualMIDILast.exe
Wait Start TickCount      35452          Ticks: 1205 (0:00:00:18.828)
Context Switch Count      53473                 LargeStack
UserTime                  00:00:00.046
KernelTime                00:00:00.062
Win32 Start Address 0x00403e20
Start Address 0x7c8106f9
Stack Init acec3000 Current acec2b88 Base acec3000 Limit acebf000 Call 0
Priority 13 BasePriority 8 PriorityDecrement 5 DecrementCount 16
ChildEBP RetAddr  Args to Child
ba4cbdd8 ba19a7fb 000000e2 00000000 00000000 nt!KeBugCheckEx+0x1b (FPO:
[5,0,0])
ba4cbdf4 ba19a033 0069cd40 0133afc6 00000000
i8042prt!I8xProcessCrashDump+0x237 (FPO: [3,0,0])
ba4cbe3c 805456e5 8a1fd6f8 8a69cc88 00010008
i8042prt!I8042KeyboardInterruptService+0x21c (FPO: [Non-Fpo])
ba4cbe3c 806e785e 8a1fd6f8 8a69cc88 00010008 nt!KiInterruptDispatch+0x45
(FPO: [0,2] TrapFrame @ ba4cbe60)
ba4cbed0 b9815b22 c0000001 89161368 ba4cbf10 hal!KfAcquireSpinLock+0x2e
(FPO: [0,0,0])
ba4cbee0 b9818bd1 00000000 c0000001 897bba78
portcls!CIrpStream::AcquireMappingIrp+0x12 (FPO: [1,0,0])
ba4cbef8 b981a97c 89161368 ba4cbf10 00000000
portcls!CIrpStream::GetPacketInfo+0x1b (FPO: [3,0,4])
ba4cbf68 b981aba1 c0000001 892a2400 897bba78
portcls!CPackerMXF::CheckIRPHeadTime+0x1a (FPO: [0,22,4])
ba4cbf80 b981ac30 ba4cbf9c 899e057c 892a2400
portcls!CPackerMXF::GetDestBuffer+0x10 (FPO: [1,1,4])
ba4cbfa0 b9819b27 899e0578 899b3ed8 b9819f20
portcls!CPackerMXF::ProcessQueues+0x59 (FPO: [0,2,4])
ba4cbfac b9819f20 ba4cbfcc b98167bf 892a2408
portcls!CPortPinDMus::ServeCapture+0x37 (FPO: [0,0,0])
ba4cbfb4 b98167bf 892a2408 806e7427 ffdff000
portcls!CPortPinDMus::RequestService+0x26 (FPO: [1,0,0])
ba4cbfcc 80545ebf 899e0558 899e0548 00000000
portcls!CServiceGroup::ServiceDpc+0x2a (FPO: [4,0,0])
ba4cbff4 80545a2b acec2b98 00000000 00000000 nt!KiRetireDpcList+0x61 (FPO:
[0,1,0])
ba4cbff8 acec2b98 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2b
(FPO: [Uses EBP] [0,0,1])
WARNING: Frame IP not in any known module. Following frames may be wrong.
80545a2b 00000000 00000009 0081850f bb830000 0xacec2b98
============================================================================
=========
1: kd> !thread
THREAD 8a6f4b30  Cid 0004.002c  Teb: 00000000 Win32Thread: 00000000 RUNNING
on processor 1
IRP List:
    892da5f0: (0006,0190) Flags: 00000000  Mdl: 891577d0
    89324cd8: (0006,0190) Flags: 00000000  Mdl: 8939a258
    892be8f0: (0006,0190) Flags: 00000000  Mdl: 891560a0
    899d6a70: (0006,0190) Flags: 00000000  Mdl: 893902c8
    89371b50: (0006,0190) Flags: 00000000  Mdl: 893bb658
    8931c768: (0006,0190) Flags: 00000000  Mdl: 891ae4b0
    89137cd8: (0006,0190) Flags: 00000000  Mdl: 891a9208
    8914ae20: (0006,0190) Flags: 00000000  Mdl: 89f95cd8
    892a1660: (0006,0190) Flags: 00000000  Mdl: 892908f0
    89287678: (0006,0190) Flags: 00000000  Mdl: 8952a9b0
    891af4e0: (0006,0190) Flags: 00000000  Mdl: 89238d98
    891a8338: (0006,0190) Flags: 00000000  Mdl: 894af008
    892e2cd8: (0006,0190) Flags: 00000000  Mdl: 892c68e0
    891a8a60: (0006,0190) Flags: 00000000  Mdl: 891456b8
    8920c678: (0006,0190) Flags: 00000000  Mdl: 89397770
    8921cb78: (0006,0190) Flags: 00000000  Mdl: 89154360
    8922d870: (0006,0190) Flags: 00000000  Mdl: 8a6a6798
Not impersonating
DeviceMap                 e1000130
Owning Process            0       Image:         <Unknown>
Attached Process          8a6f69c8       Image:         System
Wait Start TickCount      35452          Ticks: 1205 (0:00:00:18.828)
Context Switch Count      18280
UserTime                  00:00:00.000
KernelTime                00:00:00.156
Start Address nt!ExpWorkerThread (0x805386ae)
Stack Init ba4fc000 Current ba4fbb10 Base ba4fc000 Limit ba4f9000 Call 0
Priority 12 BasePriority 12 PriorityDecrement 0 DecrementCount 0
ChildEBP RetAddr  Args to Child
ba4dbfb8 b981679e 806e7427 ba338000 ba3389c0
nt!KefAcquireSpinLockAtDpcLevel+0x12 (FPO: [0,0,0])
ba4dbfcc 80545ebf 899e0558 899e0548 00000000
portcls!CServiceGroup::ServiceDpc+0x1a (FPO: [4,0,0])
ba4dbff4 80545a2b ba4fbb20 00000000 00000000 nt!KiRetireDpcList+0x61 (FPO:
[0,1,0])
ba4dbff8 ba4fbb20 00000000 00000000 00000000 nt!KiDispatchInterrupt+0x2b
(FPO: [Uses EBP] [0,0,1])
WARNING: Frame IP not in any known module. Following frames may be wrong.
80545a2b 00000000 00000009 0081850f bb830000 0xba4fbb20

******************

WDMAUDIODEV addresses:
Post message: mailto:wdmaudiodev@xxxxxxxxxxxxx
Subscribe:    mailto:wdmaudiodev-request@xxxxxxxxxxxxx?subject=subscribe
Unsubscribe:  mailto:wdmaudiodev-request@xxxxxxxxxxxxx?subject=unsubscribe
Moderator:    mailto:wdmaudiodev-moderators@xxxxxxxxxxxxx

URL to WDMAUDIODEV page:
http://www.wdmaudiodev.com/


******************

WDMAUDIODEV addresses:
Post message: mailto:wdmaudiodev@xxxxxxxxxxxxx
Subscribe:    mailto:wdmaudiodev-request@xxxxxxxxxxxxx?subject=subscribe
Unsubscribe:  mailto:wdmaudiodev-request@xxxxxxxxxxxxx?subject=unsubscribe
Moderator:    mailto:wdmaudiodev-moderators@xxxxxxxxxxxxx

URL to WDMAUDIODEV page:
http://www.wdmaudiodev.com/

Other related posts: