Debugging UMDF drivers at boot

OSR_Community_User · May 15, 2007, 8:59am

Hi,
I’m trying to debug my UMDF driver at boot time.
I have tried several ways, some of them specified in another thread at this forum (“Debugging a UMDF driver on BOOT in Vista”). All of them failed.
The first was WPP tracing - enabling an autologger in the registry. I’ve specified all the details in the other thread. If someone has any idea why this has failed, I would be happy to know…
The second was writing to a file using fopen_s, fprintf_s and fclose.
This method proved to be unreliable. For instance - I wrote several messages serially from the same function, and some of them were not written at all. That is - if I wrote messages A and B in this order, sometimes message A did not appear in the log file. Even though this is a dual-core system, and they are not necessarily supposed to be written one after the other, they should appear at some point in the file.
After the two methods above failed, I’ve tried debugging with WinDbg and an external machine (same as kernel debugging), using FireWire.
In one of the replies to my other thread, Peter mentioned that I can use DbgPrint to see what happens at boot. But according to the WDK documentation, it can only be used in kernel-mode drivers. Peter mentioned that I should use KD setup. What does this mean?
Anyway, I could not attach the external debugger to my UMDF module.
These are the configurations I have made:

On the target machine: bcdedit /debug on
bcdedit 1394 channel:3
On the host: I chose Kernel Debug and defined it to be 1394 with channel 3
I defined in the registry of the target: HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\WUDF\Services{193a1820-d9ac-4997-8c55-be817523f6aa} - value 0x4. (I also tried with 0x8000004, just in case. Both failed. By the way, is this value in the documentation correct? It is written that the highest bit should be set, meaning that this value is incorrect. It should be 0x80000004 (one zero more)).
I’ve defined in Event Filters - load module wudf* - enabled - handled.
I did this because unlike debugging from the machine itself (normal UMDF debugging), I couldn’t attach the debugger to the WUDFHost.exe process directly when I opened the debugger (this process does not exist on the host machine).
I’ve added breakpoints:
bu WUDFOsrUsbFx2!DllMain
bu WUDFOsrUsbFx2!DllGetClassObject
bu WUDFOsrUsbFx2!CMyDriver::OnDeviceAdd
And a few breakpoints in my code itself.

The results were - the host did connect to the target, it did stop somewhere, but not in those breakpoints (even when I pressed “go” several times), and breakpoints I’ve set manually on the code were not highlighted. They appeared in the breakpoints window, but only with line numbers, no symbols (and it is the exact same code of the driver).
This is what appeared in the debugger’s screen:

nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
0: kd> g
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
0: kd> g
* ERROR: Symbol file could not be found. Defaulted to export symbols for spsys.sys -
Keyboard Hook Success
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
1: kd> g
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
1: kd> g
UMDF: Waiting 4 seconds for debugger to attach.
* ERROR: Module load completed but symbols could not be loaded for secdrv.SYS
UMDF: No user-mode debugger found.
UMDF: Waiting 4 seconds for debugger to attach.
UMDF: No user-mode debugger found.

I’ve been trying to attack this boot issue for more than two weeks now, and all the methods above failed. So if anyone has any suggestion (or a check-list) for any of the methods above, or could identify what I am doing wrong, or another idea how to debug a boot issue, I would be more than thankful.
Thanks,
Gadi

OSR_Community_User · May 15, 2007, 10:36am

Gadi-

The file I/O issues sound like a runtime that isn’t thread-safe?

I believe you are already using the KD Setup Peter referred to (with one possbile exception, noted below, and which I’ll have to get back to you on).

The high order bit controls this function in those entries. Since it wasn’t on, no attempt was made (the output reflects this). You don’t need the 4 seconds in this case (0x80000000 is supposed to just skip any UM attach wait and go directly to KD). What documentation do you refer to (it obviously needs to be fixed)?

If you have access to the LHS/SP1 Beta3 WDK, it contains a new tool called WdfVerifier that will establish these settings for you- just flip to the UMDF tab and click the check box for breaking into KD at either load or start time (or both, which I’m guessing is what you did from this output) and hit “OK”.

The breaks you are seeing are for the load event breaks on modules beginning with Wudf (my guess at order would be redirector, service, host process and your driver, but I suppose I could have the first two backwards).

For breakpoints (or for that matter, any useful user-mode debugging) to work, you have to be running NTSD (or CDB) against the user mode process. KD won’t debug user-mode code (but it can be used to control a user-mode debugger in a combined session). It’s too early yet here (I work unusually early hours for this time zone) for me to get anything for you on that [since the host process isn’t started directly by you, need to know how that gets changed to launch a debugger against it].

I CAN, however tell you how to get at least some trace info to the kernel debugger:

HKLM\Software\Microsoft\Windows NT\CurrentVersion\WUDF- value name is “LogKd”, DWORD value (should already exist)- just set it to 1.

Problem is, I can’t tell you exactly how much [which providers] gets to KD this way. But, being able to see some debugger output related to your driver might help a little.

I’ll post back after I get the rest of the answers (probably be another 2-3 hours).

Sorry I can’t be of more help- the UMDF and KMDF QA teams have been merged into a single WDF team, so I’m ramping up on UMDF [and owning WdfVerifier helps a bit- I at least know the keys and have a general idea of what they do], but these things take time…

OSR_Community_User · May 15, 2007, 1:15pm

Gadi-

Still can’t find anybody, but fortunately I’m not entirely unresourceful…

This combo should let you use KD to debug the UMDF host process. I assume you already have the debugging tools for windows package on the test machine.

HKLM\Software\Microsoft\Windows NT\CurrentVersion\Image File Exectution Options\WudfHost.Exe (you’ll need to create that last subkey).

Value named “Debugger” of type REG_SZ set to “ntsd -d”.

That ought to get you going- I’m thinking you don’t even need the high order bit (the ntsd break ought to appear in kd, as I understand it). But it probably doesn’t hurt to be redundant after all the time you’ve spent on this…

I’ve done some of this sort of debugging (in my audio days). It takes some getting used to (swapping between kd and ntsd, etc). There is somewhat sketchy (bare-bones and dense) documentation on debugging a user mode process with KD in the debugger package (in mine, anyway- Debuggers/Debugger Operation/Starting the Debugger/Controlling the User mode debugger from the kernel debugger).

As far as I can tell from reading the code- the trace option I listed should give you messages for the UMDF core, anyway (i.e., messages from any WPP macros in your driver might not appear- just don’t know the code well enough to know where to check for that, yet).

At any rate, once you get the debuggers hooked up, you ought to be able to make some progress, with or without the trace messages.

Please let me know how this works for you (because this is exactly the sort of horribly confusing setup scenario we’re trying to incorporate in future versions of WdfVerifier or perhaps as new tools of their own).

OSR_Community_User · May 15, 2007, 6:06pm

There are two registry settings. One will cause UMDF to break in when the host starts. The other will cause UMDF to break in after it loads your driver. You probably want to set the second one of these so that your module is already loaded. The high bit should be set - we’ll update the documentation to contain the correct number if you can tell us which doc page had this information on it.

Set the registry key to 0x80000000 and then start UMDF. You will get a break in that looks like nonsense.

Type .lines to enable source-level debugging and then type .reload /user to reload the user-mode symbols and the stack should suddenly start looking useful. You should see that you are broken into the wudfhost process. LM should show you that your driver is loaded.

Now you can set a breakpoint in your driver and ‘g’.

-p

-----Original Message-----
From: xxxxx@lists.osr.com [mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@n-trig.com
Sent: Tuesday, May 15, 2007 6:01 AM
To: Windows System Software Devs Interest List
Subject: [ntdev] Debugging UMDF drivers at boot

Hi,
I’m trying to debug my UMDF driver at boot time.
I have tried several ways, some of them specified in another thread at this forum (“Debugging a UMDF driver on BOOT in Vista”). All of them failed.
The first was WPP tracing - enabling an autologger in the registry. I’ve specified all the details in the other thread. If someone has any idea why this has failed, I would be happy to know…
The second was writing to a file using fopen_s, fprintf_s and fclose.
This method proved to be unreliable. For instance - I wrote several messages serially from the same function, and some of them were not written at all. That is - if I wrote messages A and B in this order, sometimes message A did not appear in the log file. Even though this is a dual-core system, and they are not necessarily supposed to be written one after the other, they should appear at some point in the file.
After the two methods above failed, I’ve tried debugging with WinDbg and an external machine (same as kernel debugging), using FireWire.
In one of the replies to my other thread, Peter mentioned that I can use DbgPrint to see what happens at boot. But according to the WDK documentation, it can only be used in kernel-mode drivers. Peter mentioned that I should use KD setup. What does this mean?
Anyway, I could not attach the external debugger to my UMDF module.
These are the configurations I have made:

On the target machine: bcdedit /debug on
bcdedit 1394 channel:3
On the host: I chose Kernel Debug and defined it to be 1394 with channel 3
I defined in the registry of the target: HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows NT\CurrentVersion\WUDF\Services{193a1820-d9ac-4997-8c55-be817523f6aa} - value 0x4. (I also tried with 0x8000004, just in case. Both failed. By the way, is this value in the documentation correct? It is written that the highest bit should be set, meaning that this value is incorrect. It should be 0x80000004 (one zero more)).
I’ve defined in Event Filters - load module wudf* - enabled - handled.
I did this because unlike debugging from the machine itself (normal UMDF debugging), I couldn’t attach the debugger to the WUDFHost.exe process directly when I opened the debugger (this process does not exist on the host machine).
I’ve added breakpoints:
bu WUDFOsrUsbFx2!DllMain
bu WUDFOsrUsbFx2!DllGetClassObject
bu WUDFOsrUsbFx2!CMyDriver::OnDeviceAdd
And a few breakpoints in my code itself.

The results were - the host did connect to the target, it did stop somewhere, but not in those breakpoints (even when I pressed “go” several times), and breakpoints I’ve set manually on the code were not highlighted. They appeared in the breakpoints window, but only with line numbers, no symbols (and it is the exact same code of the driver).
This is what appeared in the debugger’s screen:

nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
0: kd> g
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
0: kd> g
* ERROR: Symbol file could not be found. Defaulted to export symbols for spsys.sys -
Keyboard Hook Success
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
1: kd> g
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
1: kd> g
UMDF: Waiting 4 seconds for debugger to attach.
* ERROR: Module load completed but symbols could not be loaded for secdrv.SYS
UMDF: No user-mode debugger found.
UMDF: Waiting 4 seconds for debugger to attach.
UMDF: No user-mode debugger found.

I’ve been trying to attack this boot issue for more than two weeks now, and all the methods above failed. So if anyone has any suggestion (or a check-list) for any of the methods above, or could identify what I am doing wrong, or another idea how to debug a boot issue, I would be more than thankful.
Thanks,
Gadi

Questions? First check the Kernel Driver FAQ at http://www.osronline.com/article.cfm?id=256

To unsubscribe, visit the List Server section of OSR Online at http://www.osronline.com/page.cfm?name=ListServer

OSR_Community_User · May 17, 2007, 8:04am

Hi,
Thanks for the elaborated replies.
It helped a lot and I managed to debug at BOOT.
Bob, about the KD, I didn’t get to it yet (because the debugger worked and that solved some of the issues), but I’m sure I will need it in the near future, and I will let you know how it works as soon as I will know.
About the incorrect registry value - it is located in http://msdn2.microsoft.com/en-us/library/aa510985.aspx
Thanks again,
Gadi

OSR_Community_User · May 17, 2007, 8:58am

Thanks, Gadi-

I suspect after Peter’s mail and the fact that you were able to debug already that you shouldn’t need to do what I suggested. As I said, I’m still learning myself, and Peter is much more expert than I am.

I do appreciate the feedback, though- understanding what is difficult (to do, to understand, etc.) is important if we are to make it better the next time around.

OSR_Community_User · May 22, 2007, 2:26pm

Can you describe how you enabled the autologger ?

You can use tracelog -addautologger to do that for you. You need to
provide all the details just like creating a trace session. Then reboot
and the log session will be started automatically.

You can use !wmitrace extension on the debugger if you want to get
details on the trace session and events.

-----Original Message-----
From: xxxxx@lists.osr.com
[mailto:xxxxx@lists.osr.com] On Behalf Of xxxxx@n-trig.com
Sent: Tuesday, May 15, 2007 6:01 AM
To: Windows System Software Devs Interest List
Subject: [ntdev] Debugging UMDF drivers at boot

Hi,
I’m trying to debug my UMDF driver at boot time.
I have tried several ways, some of them specified in another thread at
this forum (“Debugging a UMDF driver on BOOT in Vista”). All of them
failed.
The first was WPP tracing - enabling an autologger in the registry. I’ve
specified all the details in the other thread. If someone has any idea
why this has failed, I would be happy to know…
The second was writing to a file using fopen_s, fprintf_s and fclose.
This method proved to be unreliable. For instance - I wrote several
messages serially from the same function, and some of them were not
written at all. That is - if I wrote messages A and B in this order,
sometimes message A did not appear in the log file. Even though this is
a dual-core system, and they are not necessarily supposed to be written
one after the other, they should appear at some point in the file.
After the two methods above failed, I’ve tried debugging with WinDbg and
an external machine (same as kernel debugging), using FireWire.
In one of the replies to my other thread, Peter mentioned that I can use
DbgPrint to see what happens at boot. But according to the WDK
documentation, it can only be used in kernel-mode drivers. Peter
mentioned that I should use KD setup. What does this mean?
Anyway, I could not attach the external debugger to my UMDF module.
These are the configurations I have made:

On the target machine: bcdedit /debug on
bcdedit 1394 channel:3
On the host: I chose Kernel Debug and defined it to be 1394 with
channel 3
I defined in the registry of the target:
HKEY_LOCAL_MACHINE\SOFTWARE\Microsoft\Windows
NT\CurrentVersion\WUDF\Services{193a1820-d9ac-4997-8c55-be817523f6aa}

value 0x4. (I also tried with 0x8000004, just in case. Both failed.
By the way, is this value in the documentation correct? It is written
that the highest bit should be set, meaning that this value is
incorrect. It should be 0x80000004 (one zero more)).

I’ve defined in Event Filters - load module wudf* - enabled -
handled.
I did this because unlike debugging from the machine itself (normal UMDF
debugging), I couldn’t attach the debugger to the WUDFHost.exe process
directly when I opened the debugger (this process does not exist on the
host machine).
I’ve added breakpoints:
bu WUDFOsrUsbFx2!DllMain
bu WUDFOsrUsbFx2!DllGetClassObject
bu WUDFOsrUsbFx2!CMyDriver::OnDeviceAdd
And a few breakpoints in my code itself.

The results were - the host did connect to the target, it did stop
somewhere, but not in those breakpoints (even when I pressed “go”
several times), and breakpoints I’ve set manually on the code were not
highlighted. They appeared in the breakpoints window, but only with line
numbers, no symbols (and it is the exact same code of the driver).
This is what appeared in the debugger’s screen:

nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
0: kd> g
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
0: kd> g
* ERROR: Symbol file could not be found. Defaulted to export symbols
for spsys.sys -
Keyboard Hook Success
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
1: kd> g
nt!DbgLoadImageSymbols+0x47:
81c55201 cc int 3
1: kd> g
UMDF: Waiting 4 seconds for debugger to attach.
* ERROR: Module load completed but symbols could not be loaded for
secdrv.SYS
UMDF: No user-mode debugger found.
UMDF: Waiting 4 seconds for debugger to attach.
UMDF: No user-mode debugger found.

I’ve been trying to attack this boot issue for more than two weeks now,
and all the methods above failed. So if anyone has any suggestion (or a
check-list) for any of the methods above, or could identify what I am
doing wrong, or another idea how to debug a boot issue, I would be more
than thankful.
Thanks,
Gadi

Questions? First check the Kernel Driver FAQ at
http://www.osronline.com/article.cfm?id=256

To unsubscribe, visit the List Server section of OSR Online at
http://www.osronline.com/page.cfm?name=ListServer