Hello List,
http://support.microsoft.com/kb/320275/en
http://support.microsoft.com/kb/326315
While trying to understand more on IRP completion, I came across the above links. Although one of them has been revised on 2012, I think the content could still be applicable. Is that correct ?
Thanks,
Arvind
Well the first question I would ask is why are you dealing with WDM instead
of using KMDF? Yes the articles are good, but it is really stupid to have
to deal with much of the challenges of IRP Handling when the framework does
it for you.
Don Burn
Windows Driver Consulting
Website: http://www.windrvr.com
-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of
xxxxx@outlook.com
Sent: Saturday, November 22, 2014 8:57 AM
To: Windows System Software Devs Interest List
Subject: [ntdev] IRP Handling
Hello List,
http://support.microsoft.com/kb/320275/en
http://support.microsoft.com/kb/326315
While trying to understand more on IRP completion, I came across the above
links. Although one of them has been revised on 2012, I think the content
could still be applicable. Is that correct ?
Thanks,
Arvind
NTDEV is sponsored by OSR
Visit the list at: http://www.osronline.com/showlists.cfm?list=ntdev
OSR is HIRING!! See http://www.osr.com/careers
For our schedule of WDF, WDM, debugging and other seminars visit:
http://www.osr.com/seminars
To unsubscribe, visit the List Server section of OSR Online at
http://www.osronline.com/page.cfm?name=ListServer
Hi Don,
I agree that KMDF is the way forward, but how about FSD and/or legacy drivers ?
Thanks,
Arvind
P.S.
I have a dump that involves 3rd party FSD and I am thinking that it may not be completing an IRP correctly causing terminal service to not respond.
Here’s an article from 1997 (!) that comprehensively describes I/O Completion:
http://www.osronline.com/article.cfm?article=83
It’s a surprisingly complicated topic.
Peter
OSR
@OSRDrivers
Hi Peter,
Thanks for sharing the link. I already have it bookmarked along with few others.
Different ways of handling IRPs - cheat sheet (part 1 of 2)
Different ways of handling IRPs - cheat sheet (part 2 of 2)
The NT Insider:That’s Just the Way It Is - How NT Describes I/O Requests
The Basics:Rules for Irp Dispatching and Completion Routines
The NT Insider:Properly Pending IRPs - IRP Handling for the Rest of Us
The NT Insider:Proper Completion – Resubmitting IRPs from within a Completion Routine
The NT Insider:Rolling Your Own - Building IRPs to Perform I/O
The NT Insider:Secrets of the Universe Revealed! - How NT Handles I/O Completion
The NT Insider:The Truth About Cancel - IRP Cancel Operations (Part I)
The NT Insider:The Truth About Cancel - IRP Cancel Operations (Part II)
In the meantime, I was thinking of enabling driver verifier (option "4. I/O Verification - http://support.microsoft.com/kb/244617) on those few production systems that experience “terminal service hung” symptom. Will that suffice or option “6. Enhanced I/O verification” is also recommended ?
Asking for guidance on driver verifier options without sharing the dump is laughable, but I am hesitating for the fact…
A) That I am not a “driver developer”, thus involving members on a field case (of a system engineer) would not be appropriate.
B) And the dump involves a 3rd party driver and their members here might feel that raising a support incident would be more appropriate.
But if you/all think otherwise, I can share the problem details.
Thanks,
Arvind
Mr. Dalvi…
Enabling verifier is ALWAYS a good idea.
Thanks for your sensitivity… Feel free to post the output from the !analyze -v – Please make sure the symbols are set correctly (when you do the !analyze -V you shouldn’t see any box boxes with stars that say “YOUR SYMBOLS ARE WRONG” in the output). If people don’t want to help, they won’t. If they want to help, they will.
Cheers,
Peter
OSR
@OSRDrivers
Thanks Peter.
Coming to problem detail, I will first state the symptom and then the output of few related extensions. If you need output of other extensions, do let me know.
Once/twice a month, users cannot connect (via *Citrix) to *server#7. Their existing sessions do not respond either. Administrators too cannot logon using terminal services. An attempt to log on interactively (via Console) results in a blank-blue screen. But the server responds to ping, allows remote access to C$ and to administrative tools like event viewer.
*Citrix - Presentation Server 4.5 Rollup Pack 1
*Server#7 - Running as a virtual machine in VMware environment.
Since interactive logon ends up as a blank-blue screen, I asked the administrators to suspend the VM and then extract a complete memory dump from it using vmss2core tool.
kd> vertarget
Windows Server 2003 Kernel Version 3790 (Service Pack 2) UP Free x86 compatible
Product: Server, suite: TerminalServer
Built by: 3790.srv03_sp2_qfe.130703-1535
Machine Name:
Kernel base = 0x80800000 PsLoadedModuleList = 0x808a8ee8
Debug session time: Mon Sep 29 16:42:19.407 2014 (UTC + 5:30)
System Uptime: 13 days 15:28:03.309
kd> !gflag
Current NtGlobalFlag contents: 0x00080000
dps - Disable paging of kernel stacks
kd> !cpuid
CP F/M/S Manufacturer MHz
0 6,26,5 GenuineIntel 2534
kd> !running
System Processors 1 (affinity mask)
Idle Processors 1
All processors idle.
kd> !ready
Processor 0: No threads in READY state
kd> !vm 1
*** Virtual Memory Usage ***
Physical Memory: 524135 ( 2096540 Kb)
Page File: ??\C:\pagefile.sys
Current: 4190208 Kb Free Space: 3794248 Kb
Minimum: 4190208 Kb Maximum: 4190208 Kb
Available Pages: 179211 ( 716844 Kb)
ResAvail Pages: 398323 ( 1593292 Kb)
Locked IO Pages: 134 ( 536 Kb)
Free System PTEs: 192830 ( 771320 Kb)
Free NP PTEs: 32766 ( 131064 Kb)
Free Special NP: 0 ( 0 Kb)
Modified Pages: 1219 ( 4876 Kb)
Modified PF Pages: 1044 ( 4176 Kb)
NonPagedPool Usage: 0 ( 0 Kb)
NonPagedPoolNx Usage: 12566 ( 50264 Kb)
NonPagedPool Max: 65535 ( 262140 Kb)
PagedPool 0 Usage: 16377 ( 65508 Kb)
PagedPool 1 Usage: 1151 ( 4604 Kb)
PagedPool 2 Usage: 1168 ( 4672 Kb)
PagedPool 3 Usage: 1173 ( 4692 Kb)
PagedPool 4 Usage: 1152 ( 4608 Kb)
PagedPool Usage: 21021 ( 84084 Kb)
PagedPool Maximum: 67584 ( 270336 Kb)
********** 24 pool allocations have failed **********
Shared Commit: 65302 ( 261208 Kb)
Special Pool: 0 ( 0 Kb)
Shared Process: 43213 ( 172852 Kb)
PagedPool Commit: 21037 ( 84148 Kb)
Driver Commit: 2198 ( 8792 Kb)
Committed pages: 435482 ( 1741928 Kb)
Commit limit: 1533463 ( 6133852 Kb)
kd> !locks
**** DUMP OF ALL RESOURCE OBJECTS ****
KD: Scanning for held locks…
Resource @ cdm!TransportResource (0xf599a9c0) Exclusively owned
Contention Count = 73
NumberOfSharedWaiters = 73
Threads: 882a65d8-01<*> 87fc4880-01 87e9f890-01 87c6a020-01
88441548-01 87dae020-01 88444b30-01 881b14d0-01
87de3da8-01 87fe64a0-01 87c40620-01 88514da8-01
87aa7580-01 87e7e2e0-01 8837c608-01 87b89580-01
87e43020-01 88275548-01 87f128b8-01 87af6560-01
87a3d020-01 8786f320-01 878be4b0-01 87bcaa48-01
878e5b30-01 878e2938-01 877e4798-01 87849308-01
882a4540-01 87849020-01 87b8bb10-01 87f83550-01
87791b30-01 87756da8-01 87b05b30-01 87797020-01
87d26da8-01 876dbab0-01 87b25930-01 88393b00-01
88039da8-01 884e8c68-01 87b84da8-01 8824c020-01
876aeb30-01 8788cda8-01 87656020-01 879fbda8-01
87635998-01 87783490-01 87606b30-01 87571020-01
87c7f7e0-01 87aa24d8-01 87b898b8-01 87571da8-01
875c1020-01 87f7d6a8-01 87c1fda8-01 8754db10-01
87468808-01 87fea020-01 873dda78-01 88500b10-01
87aa4da8-01 87323580-01 87ddada8-01 87c47778-01
8786f020-01 8735d198-01 872a67c8-01 872ceda8-01
883528a8-01 87db9b10-01
KD: Scanning for held locks…
Resource @ 0x88889810 Shared 1 owning threads
Threads: 8813fb30-01<*>
KD: Scanning for held locks…
Resource @ 0x87ade540 Shared 1 owning threads
Threads: 87fc4880-01<*>
Resource @ 0x87ade578 Exclusively owned
Threads: 87fc4880-01<*>
Resource @ 0x8883b1fc Exclusively owned
Threads: 87fc4880-01<*>
KD: Scanning for held locks…
Resource @ 0x883c8020 Shared 1 owning threads
Threads: 87fbf598-01<*>
KD: Scanning for held locks…
Resource @ 0x8829f778 Shared 1 owning threads
Threads: 87d6c6c8-01<*>
KD: Scanning for held locks…
Resource @ 0x87dc33d8 Shared 1 owning threads
Threads: 87dfb020-01<*>
KD: Scanning for held locks…
Resource @ 0x87c41020 Shared 1 owning threads
Threads: 882456c8-01<*>
KD: Scanning for held locks…
Resource @ 0x87bd2538 Shared 1 owning threads
Threads: 883ad908-01<*>
KD: Scanning for held locks…
Resource @ 0x87da5308 Shared 1 owning threads
Threads: 87b0a020-01<*>
KD: Scanning for held locks…
Resource @ 0x87efb830 Shared 1 owning threads
Contention Count = 1
NumberOfExclusiveWaiters = 1
Threads: 87b04940-01<*>
Threads Waiting On Exclusive Access:
882a65d8
KD: Scanning for held locks…
Resource @ 0x882156e8 Shared 1 owning threads
Threads: 8806f988-01<*>
KD: Scanning for held locks…
Resource @ 0x8800d948 Shared 1 owning threads
Threads: 87a832b8-01<*>
KD: Scanning for held locks…
Resource @ 0x87cf2c18 Shared 1 owning threads
Threads: 87d078b0-01<*>
KD: Scanning for held locks…
Resource @ 0x8a1e65f0 Shared 1 owning threads
Threads: 87da4798-01<*>
KD: Scanning for held locks…
Resource @ 0x881cd958 Shared 1 owning threads
Threads: 87de15d0-01<*>
KD: Scanning for held locks…
Resource @ 0x880c66b8 Shared 1 owning threads
Threads: 87e65520-01<*>
KD: Scanning for held locks…
Resource @ 0x882da6f8 Shared 1 owning threads
Threads: 87aa24d8-01<*>
Resource @ 0x882da730 Exclusively owned
Threads: 87aa24d8-01<*>
Resource @ 0x879b3344 Exclusively owned
Threads: 87aa24d8-01<*>
KD: Scanning for held locks…
Resource @ 0x87501778 Shared 1 owning threads
Threads: 87c47778-01<*>
Resource @ 0x875017b0 Exclusively owned
Threads: 87c47778-01<*>
Resource @ 0x87cf72f4 Exclusively owned
Threads: 87c47778-01<*>
KD: Scanning for held locks…
Resource @ 0x87babf80 Shared 2 owning threads
Threads: 8786f020-01<*> 87f59830-01<*>
Resource @ 0x87babfb8 Exclusively owned
Contention Count = 1
NumberOfExclusiveWaiters = 1
Threads: 8786f020-01<*>
Threads Waiting On Exclusive Access:
87f59830
Resource @ 0x8735d44c Exclusively owned
Threads: 8786f020-01<*>
KD: Scanning for held locks…
Resource @ 0x88a69988 Shared 1 owning threads
Threads: 8735d198-01<*>
Resource @ 0x88a699c0 Exclusively owned
Threads: 8735d198-01<*>
Resource @ 0x873142f4 Exclusively owned
Threads: 8735d198-01<*>
KD: Scanning for held locks…
Resource @ 0x8793a290 Shared 1 owning threads
Threads: 872a67c8-01<*>
Resource @ 0x8793a2c8 Exclusively owned
Threads: 872a67c8-01<*>
Resource @ 0x872da2f4 Exclusively owned
Threads: 872a67c8-01<*>
KD: Scanning for held locks.
Resource @ 0x87e1f720 Shared 1 owning threads
Threads: 872ceda8-01<*>
Resource @ 0x87e1f758 Exclusively owned
Threads: 872ceda8-01<*>
Resource @ 0x872c588c Exclusively owned
Threads: 872ceda8-01<*>
KD: Scanning for held locks…
Resource @ 0x882b7e78 Shared 1 owning threads
Threads: 87db9b10-01<*>
Resource @ 0x882b7eb0 Exclusively owned
Threads: 87db9b10-01<*>
Resource @ 0x872b994c Exclusively owned
Threads: 87db9b10-01<*>
KD: Scanning for held locks…
15580 total locks, 39 locks currently held
kd> !thread 882a65d8
THREAD 882a65d8 Cid 0004.55d8 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
8a2bdf10 SynchronizationEvent
882a6650 NotificationTimer
Not impersonating
DeviceMap e1001798
Owning Process 8a397648 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 75448353 Ticks: 178 (0:00:00:02.781)
Context Switch Count 6738
UserTime 00:00:00.000
KernelTime 00:00:00.125
Start Address cdm!CdmWorkerDispatch (0xf5989810)
Stack Init b8222000 Current b8221b50 Base b8222000 Limit b821f000 Call 0
Priority 16 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr Args to Child
b8221b68 80834045 882a65d8 882a6680 00000000 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
b8221b94 80829da6 882a65d8 87efb830 00000000 nt!KiSwapThread+0x2e5 (FPO: [Non-Fpo])
b8221bdc 8087ea91 8a2bdf10 0000001b 00000000 nt!KeWaitForSingleObject+0x346 (FPO: [Non-Fpo])
b8221c18 8087ecab 88745bd8 87efb818 00000000 nt!ExpWaitForResource+0xd5 (FPO: [Non-Fpo])
b8221c38 f594bfbb 87efb830 00000001 88b0faa0 nt!ExAcquireResourceExclusiveLite+0x8d (FPO: [Non-Fpo])
b8221c60 f5980c52 0000000a 00020000 88b0faa0 cdm!CdmIoctlTrUnbind+0x9b (FPO: [Non-Fpo])
b8221c7c f59723d2 88b0faa0 88579168 00000000 cdm!CdmDereferenceTransport+0x172 (FPO: [Non-Fpo])
b8221c9c f5974eba 00000001 00000002 87efcbf8 cdm!UnBindFromTransport+0x262 (FPO: [Non-Fpo])
b8221d38 f5975074 00000000 00000001 891c5ec0 cdm!CdmFscFsControlFile+0x80a (FPO: [Non-Fpo])
b8221d50 f5989677 891c5ec0 87efcbf8 891c5f78 cdm!CdmFspFsControlFile+0x14 (FPO: [Non-Fpo])
b8221d94 f598989e 891d0720 00000000 882a65d8 cdm!CdmFspDispatch+0xa7 (FPO: [Non-Fpo])
b8221dac 8094c16a 891c5f78 00000000 00000000 cdm!CdmWorkerDispatch+0x8e (FPO: [Non-Fpo])
b8221ddc 8088fe2e f5989810 891c5f78 00000000 nt!PspSystemThreadStartup+0x2e (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
kd> !thread 87b04940
THREAD 87b04940 Cid 0004.a014 Teb: 00000000 Win32Thread: 00000000 WAIT: (Unknown) KernelMode Non-Alertable
87efb8ac NotificationEvent
IRP List:
883696a8: (0006,0094) Flags: 00000074 Mdl: 00000000
Not impersonating
DeviceMap e1001798
Owning Process 8a397648 Image: System
Attached Process N/A Image: N/A
Wait Start TickCount 74423679 Ticks: 1024852 (0:04:26:53.312)
Context Switch Count 3
UserTime 00:00:00.000
KernelTime 00:00:00.000
Start Address cdm!CdmIoctlTrReaderThread (0xf594c6b0)
Stack Init 94112000 Current 94111cc4 Base 94112000 Limit 9410f000 Call 0
Priority 16 BasePriority 8 PriorityDecrement 0
ChildEBP RetAddr Args to Child
94111cdc 80834045 87b04940 87b049e8 88369718 nt!KiSwapContext+0x26 (FPO: [Uses EBP] [0,0,4])
94111d08 80829da6 87efb8cc 00000103 87efb8a4 nt!KiSwapThread+0x2e5 (FPO: [Non-Fpo])
94111d50 f594a774 87efb8ac 00000000 00000000 nt!KeWaitForSingleObject+0x346 (FPO: [Non-Fpo])
94111d78 f594c759 8865d9b0 87efb8cc 87d50270 cdm!IcaDrvRead+0x84 (FPO: [Non-Fpo])
94111dac 8094c16a 88745bd8 00000000 00000000 cdm!CdmIoctlTrReaderThread+0xa9 (FPO: [Non-Fpo])
94111ddc 8088fe2e f594c6b0 87efb818 00000000 nt!PspSystemThreadStartup+0x2e (FPO: [Non-Fpo])
00000000 00000000 00000000 00000000 00000000 nt!KiThreadStartup+0x16
kd> !irp 883696a8 -v
Irp is active with 1 stacks 3 is current (= 00000000)
No Mdl: System buffer=e24b4ca8: Thread 87b04968: Irp is completed. Pending has been returned
Flags = 00000074
ThreadListEntry.Flink = 87b04b48
ThreadListEntry.Blink = 87b04b48
IoStatus.Status = 00000000
IoStatus.Information = 00000024
RequestorMode = 00000000
Cancel = 00
CancelIrql = 0
ApcEnvironment = 00
UserIosb = 87efb8a4
UserEvent = 87efb8ac
Overlay.AsynchronousParameters.UserApcRoutine = 00000000
Overlay.AsynchronousParameters.UserApcContext = 00000000
Overlay.AllocationSize = 00000000 - 00000000
CancelRoutine = 00000000
UserBuffer = 87d50270
&Tail.Overlay.DeviceQueueEntry = 883696e8
Tail.Overlay.Thread = 87b04968
Tail.Overlay.AuxiliaryBuffer = 808217a0
Tail.Overlay.ListEntry.Flink = 808f8b06
Tail.Overlay.ListEntry.Blink = 00000000
Tail.Overlay.CurrentStackLocation = 00000000
Tail.Overlay.OriginalFileObject = 8865d9b0
Tail.Apc = 00300012
Tail.CompletionKey = 00300012
cmd flg cl Device File Completion-Context
[3, 0] 0 0 8a1c40d0 00000000 00000000-00000000
\Driver\TermDD
Args: 00000000 00000000 00000000 ffffffff
xxxxx@outlook.com wrote:
Once/twice a month, users cannot connect (via *Citrix) to *server#7. Their existing sessions do not respond either. Administrators too cannot logon using terminal services. An attempt to log on interactively (via Console) results in a blank-blue screen. But the server responds to ping, allows remote access to C$ and to administrative tools like event viewer.
Good luck with this one. You’re going to have to call Microsoft Product
Support and pay for a support incident. There’s no way anybody here can
help you.
And, unfortunately, the first thing THEY are going to ask is, “does the
same thing happen if you aren’t running in a VM?” Terminal Services is
a resource-hungry little puppy.
You do seem to have one transport-related lock that is a bottleneck, but
only a Terminal Services engineer can help you with that.
–
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.
Thanks Tim.
Leaving the case aside, do you think the IRP has been completed correctly ? (specially when it returns “Irp is completed. Pending has been returned”)
Of 145 IRPs, I have pasted 3 samples where 883696a8 (the one in middle) has this status.
88355780: Irp is active with 1 stacks 1 is current (= 0x883557f0)
No Mdl: No System Buffer: Thread 87e1d998: Irp stack trace.
cmd flg cl Device File Completion-Context
[3, 0] 0 1 8a1c40d0 884c9f90 00000000-00000000 pending
\Driver\TermDD
Args: 00001378 00000000 00000000 00000000
883696a8: Irp is active with 1 stacks 3 is current (= 00000000)
No Mdl: System buffer=e24b4ca8: Thread 87b04968: Irp is completed. Pending has been returned
cmd flg cl Device File Completion-Context
[3, 0] 0 0 8a1c40d0 00000000 00000000-00000000
\Driver\TermDD
Args: 00000000 00000000 00000000 ffffffff
883b48b8: Irp is active with 1 stacks 1 is current (= 0x883b4928)
No Mdl: No System Buffer: Thread 884dfb30: Irp stack trace.
cmd flg cl Device File Completion-Context
[3, 0] 0 1 8a1c40d0 87b31c10 00000000-00000000 pending
\Driver\TermDD
Args: 000003fc 00000000 00000000 00000000
On Nov 24, 2014, at 9:15 PM, xxxxx@outlook.com wrote:
Leaving the case aside, do you think the IRP has been completed correctly ? (specially when it returns “Irp is completed. Pending has been returned”)
Of 145 IRPs, I have pasted 3 samples where 883696a8 (the one in middle) has this status.
What does this have to do with the dump you just posted? That didn’t have any IRPs.
Tim Roberts, xxxxx@probo.com
Providenza & Boekelheide, Inc.
Yes. I agree this needs to go to product support for resolution.
Peter-n-Tim…Thanks for all your help.