PrintVerifier Team Blog

Attaching a debugger to the print filter pipeline service

2009-03-24T21:46:31Z

As you should know by now, Application Verifier (and Print Verifier) works by sending error messages to the debugger that is attached to the associated process. For XPSDrv drivers, the filters are hosted by the print filter pipeline service, so you must attach a debugger to printfilterpipelinesvc.exe.

Note: I am making the assumption that you are generally familiar with how to use WinDbg to debug user-mode applications. If not, you should first read the help documentation that is included with the Debugging Tools for Windows package. Since print drivers are user-mode components only the sections on user-mode debugging are relevant. You can skip those parts of the documentation that are specific to kernel-mode debugging.

There are two basic ways to attach WinDbg to a process.

· Use WinDbg from the command line to start the process.

· Attach WinDbg to an existing process.

The filter pipeline host must be started by the print spooler, so you must use the second option to attach WinDbg to the process. However, the filter pipeline host is not persistent. A new instance of the service is started when an application submits a job to the print queue and the service is terminated shortly after the job is complete. It is difficult, at best, to attach WinDbg to printfilterpipelinesvc.exe after the print job is submitted but before the filter that you are trying to debug starts running, especially if you want to debug the filter’s startup or initialization code.

To work around this problem, you can modify the amount of time that printfilterpipelinesvc.exe persists after a print job is finished. That value is controlled by the PipelineHostTimeout value of the HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control\Print registry key.

To change the filter pipeline service timeout value:

1. Run RegEdit and navigate to HKEY_LOCAL_MACHINE\System\CurrentControlSet\Control\Print.

2. Add a PipelineHostTimeout REG_DWORD value to the key, if it is not already present.

3. Set PipelineHostTimeout to the timeout value, in milliseconds.

Set a large enough value to give yourself ample time to attach the process and set breakpoints. This paper assumes a 1.5 minute timeout, so PipelineHostTimeout is set to 90000.

After setting the PipelineHostTimeout value, use the following procedure to attach WinDbg to the pipeline filter service:

To Attach WinDbg to the filter pipeline service

1. Run WinDbg with elevated privileges, but do not attach it to a process.

2. Submit a print job to your driver and wait for it to complete.

The filter pipeline service continues running for the specified timeout value.

3. On the WinDbg File menu, click Attach to a Process.

4. In the Attach to Process dialog box, select printfilterpipelinesvc.exe and click OK.

Tip: If the process is listed as “Access Denied”, it probably means that WinDbg is not running with elevated privileges.

5. Set breakpoints, as appropriate.

6. Submit the print job again.

The filter host process should break into the debugger at the first breakpoint or the first verifier stop, whichever comes first. From there, you can step through code, examine variables, and so on.

Enabling PrintVerifier for XPSDrv

2009-03-24T21:37:02Z

I wanted to use the next couple of posts to cover PrintVerifier in the context of XPSDrv. I don’t plan on covering the workflow involved in debugging individual stops since the troubleshooting steps for stops that you encounter in the XPSDrv scenario are exactly the same as other stops. Identify the stop code from the debugger, look up the details for the stop code in the Application Verifier documentation and take it from there.

But there are some things that are different when it comes to XPSDrv and these differences lie mainly in the setup and configuration phase. So let’s discuss these differences in the next couple of posts. First up is, of course, to enable PrintVerifier.

1. Click Start and run Application Verifier from the All Programs menu.

The program initially displays the following window:

Figure 1. Application Verifier before configuration

2. Press Ctrl-A and open PrintFilterPipelineSvc.exe, which is located in Windows\System32.

PrintFilterPipelineSvc.exe is the filter pipeline service. This action adds PrintFilterPipelineSvc.exe to the list of images in the Applications pane and displays a set of associated Application Verifier tests in the Tests pane.

3. Select the Printing test, which enables Print Verifier. This test has two components:

· PrintAPI tests the interface between applications and the print spooler.

· PrintDriver tests the interface between the core print driver and its plugins as well as the filter pipeline manager and XPSDrv filters.

4. In the Tests pane, under Basics, select all the tests except Threadpool. The configured Application Verifier should look like Figure 5.

Figure 2. Application Verifier configured for print verification.

For information on the other tests, use the Help menu to view the help documentation.

5. Click Save to enable this Application Verifier configuration.

Note that you might have to restart the print filter pipeline process in order for these settings to persist. You can do this either via the task manager and kill printfilterpipelinesvc.exe or restart your system. After either of these steps, Application Verifier will be enabled for the print filter pipeline process.

New stops

2009-02-24T10:24:56Z

We just released a new version of Application Verifier. As part of this release, we added a number of stops to Print Verifier. Unfortunately, we neglected to document these stops in the recent release of App Verifier. By the time we discovered this mistake, it was too late for the doc writers to update the documentation. We will definitely get this rectified in the next release. But in the meantime, we thought we’d publish the documentation for the new stops here.

A020

Application Verifier break message

Async Notify handle returned by RegisterForPrintAsyncNotifications was not released properly

Probable cause

Handle allocated by RegisterForPrintAsyncNotifications function had not been released until the program exited. Most likely, it needs to be released by calling UnRegisterForPrintAsyncNotifications() before exiting.

Troubleshooting Steps

To troubleshoot this stop:

o Determine the routine that called winspool to allocate the handle on its behalf by using the second parameter of this verifier stop.

o Dump the initialization stack trace using the dps command in the debugger.

o Find the first non-winspool and non-vfPrint module name that called vfPrint!VfHookRegisterForPrintAsyncNotifications. This routine is typically found in the 3rd stack frame.

Information displayed by Application Verifier

Parameter 1 - Handle value.

Parameter 2 - Initialization stack trace. Use dps to dump the stack trace if it is not NULL.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A020

Stop code: 032

Severity: Warning

One-time error: no

Error report: None

Log to file: yes

Create backtrace: yes

A021

Application Verifier break message

Attempt to use an invalid handle in UnRegisterForPrintAsyncNotifications.

Probable cause

The handle was not opened by the RegisterForPrintAsyncNotifications Win32 API function.

Troubleshooting Steps

To troubleshoot this stop, view the stack trace of the routine that attempted this action using the 'k' command in the debugger.

Information displayed by Application Verifier

Parameter 1 - Handle value.

Parameter 2 - Not used.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A021

Stop code: 033

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

A022

Application Verifier break message

Attempt to use a closed handle in UnRegisterForPrintAsyncNotifications API function.

Probable cause

An async notify handle was used after it has been closed.

Troubleshooting Steps

To troubleshoot this stop:

o Use the 'k' command in the debugger to view the current stack trace. This will indicate the routine that tried to use the closed handle.

o Use the 'dps' debugger command on the second parameter of the stop to view the stack trace of the routine that closed the handle.

Information displayed by Application Verifier

Parameter 1 - Handle value.

Parameter 2 - Stack trace of the closing. Use dps to dump the stack trace if it is not NULL.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A022

Stop code: 034

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

A023

Application Verifier break message

Third-party function reports failure but increases reference count for input interface.

Probable cause

A third-party method receives interface pointer as input. When such method returns a failure code, the interface reference count should remain the same. But in this case the reference count was increased.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Format: The %lS method returns %x error code but increases ref count of %lS parameter.

Parameter 1 - Called interface pointer. If NULL, called function is static.

Parameter 2 - Input interface pointer.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A023

Stop code: 035

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

A024

Application Verifier break message

Windows API function reports failure but increases reference count for input interface.

Probable cause

An API method receives interface pointer as input. When such method returns fail code, interface ref count should remain the same. But in this case reference count was increased. Please report this error to Microsoft because it could be a problem in API code.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Parameter 1 - Called interface pointer. If NULL, called function is static.

Parameter 2 - Input interface pointer.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A024

Stop code: 036

Severity: Warning

One-time error: no

Error report: None

Log to file: yes

Create backtrace: yes

A025

Application Verifier break message

IPrintAsyncNotifyChannel contract violation by the operating system.

Probable cause

The platform implementation of IPrintAsyncNotifyChannel violated part of the special contract implied or defined by IPrintAsyncNotifyChannel. IPrintAsyncNotifyChannel has special exceptions to AddRef and Release. This requires that the platform calls OnEventNotify and ChannelClosed with the same pointer value as the channel was created with. Please report this error to Microsoft.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Format: %s was called with the wrong interface pointer.

Parameter 1 - Actual interface pointer.

Parameter 2 - Expected interface pointer.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A025

Stop code: 037

Severity: Warning

One-time error: no

Error report: None

Log to file: yes

Create backtrace: yes

A026

Application Verifier break message

IPrintAsyncNotifyChannel contract violation by channel consumer.

Probable cause

On bidirectional channels, calling SendNotification, CloseChannel, or making the final Release on the interface pointer relinquishes 'ownership'. After creating the channel and sending the first notification, you cannot call Release until your callback's OnEventNotify is invoked. If either you invoke CloseChannel or get a ChannelClosed notification, then you must not perform the final Release call.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Format: %s was called, but channel 'ownership' currently belongs to print spooler

Parameter 1 - IPrintAsyncNotifyChannel interface pointer.

Parameter 2 - Not used.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A026

Stop code: 038

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

A027

Application Verifier break message

Race detected during closing of IPrintAsyncNotifyChannel.

Probable cause

This stop indicates that a notification arrives _during_ the call to CloseChannel. If this condition occurs, it may be imposible for the consumer to correctly release the channel.

This stop should not be frequently encountered. It can be prevented by always ensuring a listener is available before a bidirectional channel is created, AND/OR ensuring that no listener can be started before attempting closing a channel that has already sent a notification but not recieved the callback.

Please report this error to Microsoft.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Format: In function %s, a call is already in progress on a different thread. See help for more info.

Parameter 1 - IPrintAsyncNotifyChannel interface pointer.

Parameter 2 - Thread id of member function called.

Parameter 3 - Thread id of callback event function.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A027

Stop code: 039

Severity: Warning

One-time error: no

Error report: None

Log to file: yes

Create backtrace: yes

A028

Application Verifier break message

Calling a print API that makes network calls on a GUI thread. This can lead to unbound in time UI hangs.

Probable cause

A print API was called that makes network calls on a GUI thread. This can lead to unbound in time UI hangs. Typically such APIs need to be called on a worker thread, with no message pumps.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Format: %s was called on a thread that is a GUI thread. This can lead to unbound in time UI hangs.

Parameter 1 - HWND of the top-level visible window.

Parameter 2 - Current thread ID.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A028

Stop code: 040

Severity: Warning

One-time error: no

Error report: None

Log to file: yes

Create backtrace: yes

A029

Application Verifier break message

Calling an API that will pop up user interface is Session0.

Probable cause

A call was made to an API that will pop up user interface is Session0.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace using the 'k' command in the debugger.

Information displayed by Application Verifier

Format: The illegal-to-call in Session0 API: %s

Parameter 1 - Not used.

Parameter 2 - Not used.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintAPI

Stop ID: 0000A029

Stop code: 041

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

D02A

Application Verifier break message

A print driver called ExitThread.

Probable cause

A print driver module called ExitThread. When a print driver module calls ExitThread, the thread is exited before any destructors can be called or any other automatic cleanup can be performed. This can lead to undefined behavior. Therefore, print drivers should always return from their thread function.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace by using the 'k' command in the debugger to identify the print driver module and routine that invoked ExitThread.

Information displayed by Application Verifier

Parameter 1 - Not used.

Parameter 2 - Not used.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintDriver

Stop ID: 0000D02A

Stop code: 042

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

D02B

Application Verifier break message

A print driver called TerminateThread.

Probable cause

A print driver module called TerminateThread. TerminateThread is used to cause a thread to exit. When this occurs, the target thread has no chance to execute any user-mode code. DLLs attached to the thread are not notified that the thread is terminating. The system frees the thread's initial stack. TerminateThread is a dangerous function that should only be used in the most extreme cases.

For example, TerminateThread can result in the following problems:

o If the target thread owns a critical section, the critical section will not be released.

o If the target thread is allocating memory from the heap, the heap lock will not be released.

o If the target thread is executing certain kernel32 calls when it is terminated, the kernel32 state for the thread's process could be inconsistent.

o If the target thread is manipulating the global state of a shared DLL, the state of the DLL could be destroyed, affecting other users of the DLL.

Troubleshooting Steps

To troubleshoot this stop, view the current stack trace by using the 'k' command in the debugger to identify the print driver module and routine that invoked TerminateThread.

Information displayed by Application Verifier

Parameter 1 - Not used.

Parameter 2 - Not used.

Parameter 3 - Not used.

Parameter 4 - Not used.

Additional information

Test Layer: PrintDriver

Stop ID: 0000D02B

Stop code: 043

Severity: Error

One-time error: no

Error report: Break

Log to file: yes

Create backtrace: yes

Unintended hibernation

2009-02-12T10:53:26Z

Sorry for what might have seemed like terminal hibernation. We’ve just been busy working on PrintVerifier and other components of Windows that we haven’t had time to update this blog. We hope to be more active in this space in the coming weeks and months.

PrintVerifier Philosophy

2007-05-12T01:37:24Z

I thought I'd spend the rest of the afternoon penning my thoughts on metaphysics, epistemology and associated topics. Nah! Just kidding!

Our philosophy when it comes to PrintVerifier is that when in doubt DO NOT break. In other words, during the verification process if PrintVerifier detects a potential problem but is not 100% certain about the legality/seriousness of the problem, then no stop will be issued. PrintVerifier stops are very indicative of a real problem in the code being verified and need to be investigated.

PrintVerifier stop == There IS a problem

PrintVerifier stop != There MAYBE a problem

WinHEC is almost here

2007-05-11T22:13:31Z

Whew! The long wait is finally over. One last working day before it is time to leave for WinHEC. Eagerly looking forward to meeting everyone and unveiling PrintVerifier.

PrintTicket/PrintCapabilities verification

2007-05-11T03:21:24Z

One of the really cool features in PrintVerifier is runtime verification of PrintTicket and PrintCapabilities documents. Let's talk a little more about this feature.

We have integrated the essence of the PTConform tool into PrintVerifier. While the PTConform tool is invaluable in its own way, it has certain drawbacks. In order to effectively verify the PrintTicket functionality of your print driver, you have to first save the set of PrintTickets/PrintCapabilities that your driver can potentially produce as static XML files and then run PTConform on these files. Needless to say, this can be a tedious task. PrintVerifier gives you the ability to perform this verification at runtime. PrintVerifier validates the following:

PrintTickets that are passed in by the application
PrintTickets/PrintCapabilities that are returned by the plug-in/filter.

If any of the above are found to be non-conformant to the Print Schema, a PrintVerifier stop is issued. The stop will contain the error message returned by PTConform as well as the PrintTicket/PrintCapabilities XML text.

PrintVerifier also offers you the flexibility to turn off just the PT/PC verification but get all the other benefits of the PrintAPI and PrintDriver layer checks. This could be of use in a scenario where you want to focus on a portion of your code that is not related to PT/PC and don't want to be randomized by PT/PC related stops. Although this flexibility is made available for a reason, we recommend that you stick to the default settings.

In summary, the PTConform integration with PrintVerifier allows you to validate your PrintTicket handling code simply by enabling PrintVerifier for the processes that host your print component.

What is a verifier stop?

2007-05-11T02:25:25Z

I was in the process of writing up a few blog posts to do with debugging specific PrintVerifier stops when I realized that we haven't covered the basic concept of a verifier stop. So let's do that.

=======================================
VERIFIER STOP 0000A012 : pid 0xD68: Leaked PrintTicket provider
handle detected

03320FE8 : PrintTicket provider handle being leaked.
0312FF48 : Initialization stack trace. Use dps to dump the stack
trace if it is not NULL.
00000CC0 : Thread id of the thread that opened the handle.
00000000 : Not used.
=======================================

What you see above is what is referred to commonly as a verifier stop. The concept of a verifier stop is common to Application Verifier and not specific to PrintVerifier. All checks/verifications in AppVerifier issue a verifier stop to indicate a problem in the code/component being verified. Let's go over the important pieces of information that are part of a verifier stop.

Stop code ID: The stop code ID is very important since this is what you use to look up additional information about the stop in the documentation. The numbering scheme will also give you a rough idea about what type of verification caused the stop. For example, all PrintAPI layer stops are numbered starting from 0000A000 and all PrintDriver layer stops are numbered starting from 0000D000. So in the snippet shown above, you can right away tell that it is a PrintAPI layer stop.
Stop code title: The stop code title gives you rough idea about the root cause of the stop. For example, in the snippet shown above you can tell from the title that the root cause of the stop is the component being verified leaking a PrintTicket provider handle.
Parameters: The parameters of a verifier stop provide the additional information you need to troubleshoot/debug the stop and pinpoint the root cause. A verifier stop can have a maximum of 4 parameters although not all might be used. For instance, in the snippet shown above you will see that only the first 3 parameters are used. The documentation for each verifier stop lists specific troubleshooting steps (inclusive of debugger commands) that you can take to display the additional information represented by the parameters.

So that's as far as pieces of information that are common to all verifier stops. But there is additional piece of information that only PrintDriver layer stops display.

=======================================
VERIFIER STOP 0000D006 : pid 0x1644: The plugin driver closed the printer handle.

00000000018F6898 : Printer handle that was closed.
0000000001E733B0 : Stack trace of the closing. Use dps to dump the stack trace if it is not NULL.
0000000000000000 : Not used.
0000000000000000 : Not used.

This verifier stop was caused by the GetSupportedVersions method in the plug-in module at C:\WINDOWS\system32\spool\DRIVERS\x64\3\PTPlug_GetSupVersions_1.dll
=======================================

In the snippet shown above, you will see the additional line stating that the GetSupportedVersions method in the PTPlug_GetSupVersions_1.dll caused the PrintVerifier stop to occur. This will allow you to isolate the problem area in your driver's code to a small manageable section. This feature is specific to the PrintDriver layer stops. The reason for including this information only for PrintDriver stops is that in most cases, the plug-in/filter being verified is not on the call stack at the time of the stop. As explained here, the PrintDriver hooks perform checks both before and after calling the plug-in/filter's COM interface methods. Since a number of checks are performed (and stops issued) after the plug-in/filter method has returned, the module being verified is no longer on the call stack. Therefore, the need to display the additional information for PrintDriver stops.

PrintVerifier demo

2007-05-10T23:25:40Z

We will be presenting a demo of the PrintVerifier workflow at WinHEC 2007. You can find a screencast of the demo here. The demo illustrates how to enable PrintVerifier for a process and walks you through the troubleshooting steps to be taken for debugging a PrintVerifier stop.

Simple yet powerful

2007-05-10T20:56:44Z

I came across this nugget while reading Steven Sinofsky's internal blog.

I am helping a company design an entirely new approach to one of their standard products. It looks simple. During a user test, one person said that he really liked it, but it was too bad he wouldn't use it.
"Why not?" we asked.
"Because it isn't powerful enough for my particular problem," he replied.
"Try it," we suggested, "we would like to see where it fails so we can make it better."
Well, it didn't fail. it handled his problem just fine. Looking simple was the culprit. if it looks simple, he seemed to think, it must not be powerful.

PrintVerifier could very easily be the product discussed in the example. At times (both thru this blog as well as thru WinHEC presentations) we might put a lot of emphasis on the simplicity of PrintVerifier. But make no mistake...PrintVerifier is a very powerful tool that will enable you to develop quality drivers and applications.