Welcome PowerShell User! This recipe is just one of the hundreds of useful resources contained in the Windows PowerShell Cookbook, 3rd edition.

If you own the book already, login here to get free, online, searchable access to the entire book's content.

If not, the Windows PowerShell Cookbook is available at Amazon, O'Reilly, or any of your other favourite book retailers. If you want to see what the PowerShell Cookbook has to offer, enjoy this free 90 page e-book sample: "The Windows PowerShell Interactive Shell".

Debug or Troubleshoot a Workflow

Problem

You want to diagnose or further understand the behavior of a running workflow.

Solution

When debugging at implementation time, use Write-Output statements to trace important information in your workflow. As with PowerShell scripts, Write-Output is implied when a workflow generates output:

workflow Invoke-DebugWorkflow
{
    $a = 10
    $b = 20
    Write-Output "Current value of A is: $a"

    "All available variables:"
    InlineScript { dir variable: }
}

At runtime, review the workflow’s Progress output to trace its execution.

PS > $j = Invoke-TestWorkflow -AsJob
PS > $j.ChildJobs[0].Progress

ActivityId        : 0
ParentActivityId  : -1
Activity          : Get-Process
StatusDescription : Running
CurrentOperation  : 05df2fad-0a90-4576-aaef-867804d7f948:[localhost]:1.9:
                    Invoke-TestWorkflow line:2 char:2
PercentComplete   : -1
SecondsRemaining  : -1
RecordType        : Processing

(...)

For advanced diagnosis, review the output of $pshome\traces\PSTrace.etl after running Enable-PSWSManCombinedTrace and Disable-PSWSManCombinedTrace.

PS > Enable-PSWSManCombinedTrace
PS > Invoke-TestWorkflow
PS > Disable-PSWSManCombinedTrace
PS > $r = Get-WinEvent -Path $pshome\Traces\PSTrace.etl -Oldest
PS > $r | Where-Object ProviderName -eq Microsoft-Windows-PowerShell |
    Foreach-Object Message
(...)

Activity was queued for execution. 
  WorkflowId: {FD87A839-5D23-4EC5-AEEF-82AD3E3A3360} 
  ActivityName: Get-Process
Trace Information: 
  :Activity DisplayName: Get-Process :ActivityInstanceState: Executing 

(...)

Discussion

When diagnosing a workflow, there are two primary types of debugging you’ll do: authoring-time debugging, and runtime debugging.

Authoring-time debugging

Debugging a workflow during development is what you’ll do most often. In this situation, the questions on your mind will be along the lines of, “What is the value of this variable right now?” and “Is this portion of my workflow even being run?”

Since workflows run as background jobs, interactive debugging (as implemented beautifully for scripts in the PowerShell Integrated Scripting Environment) is not supported. Instead, the primary form of debugging at your disposal is the long-held staple of software: trace statements. If you need to determine the value of a variable, write a trace statement to output the value. If you need to find out if a branch of your workflow is being executed, write a trace statement in that branch that says “Got here!" or something similar.

Runtime debugging

Once you’ve got a workflow written or deployed, how do you diagnose its behavior through runtime analysis alone?

The simplest way to diagnose a worklow’s runtime behavior is through the job object that represents the workflow. If the workflow terminates with an error, you can access the Reason property of the JobStateInfo property to determine why:

PS > $j.ChildJobs[0].JobStateInfo.Reason | Format-List * -Force
Message        : Attempted to divide by zero.
(...)

If the workflow generated errors, you can access these through the Error collection:

PS > $j.ChildJobs[0].Error
Microsoft.PowerShell.Management\Get-Process : Cannot find a process with
the name "IDoNotExist". Verify the process name and call the cmdlet again.
At foo:1 char:1
(...)

If neither the exception nor error objects provide the information you need to diagnose your workflow, execution tracing is the next place to turn. For every workflow execution, PowerShell logs the progress of every command to the job’s Progress stream. As demonstrated by the solution, this progress information includes the activity name, script position, execution status, and more. The CurrentOperation property includes the workflow GUID, computer the activity was run on, activity ID, and script position. With a little parsing, we can create a very useful script trace.

PS > $j.ChildJobs[0].Progress | Select Activity,StatusDescription,
    {($_.CurrentOperation -split ":",4)[3]} | ft -auto

Activity        StatusDescription ($_.CurrentOperation -split ":",4)[3]
--------        ----------------- -------------------------------------
Get-Process     Running            Invoke-DebugWorkflow line:3 char:3
Get-Process     Completed          Invoke-DebugWorkflow line:3 char:3
Get-Service     Running            Invoke-DebugWorkflow line:4 char:4
Get-Service     Completed          Invoke-DebugWorkflow line:4 char:4
Get-CimInstance Running            Invoke-DebugWorkflow line:5 char:5
Get-CimInstance Completed          Invoke-DebugWorkflow line:5 char:5

Even with this much detail, problems are sometimes rooted extremely deeply in the infrastructure. For example, PowerShell may run into problems during its automatic connection management. Or, it might start throttling connection attempts because your workflow has hit the per-computer connection limit.

For analysis at this level of detail, you can use the PSDiagnostics module. This module lets you monitor PowerShell’s rich stream of Event Tracing for Windows (ETW) information. Comprehensive documentation of these events isn’t possible, but the text of the message can often be insightful. To dump the diagnostic information into a text file for later viewing, run the following commands:

workflow Invoke-DebugWorkflow
{
    foreach -parallel ($item in 1..10)
    {
        InlineScript
        {
            "Starting $USING:item"
            Start-Sleep -Seconds 2
            "Ending $USING:item"
        } -PSComputername SomeComputerName
    }
}

PS > Enable-PSWSManCombinedTrace
PS > Invoke-DebugWorkflow
PS > Disable-PSWSManCombinedTrace
PS > $r = Get-WinEvent -Path $pshome\Traces\PSTrace.etl -Oldest
PS > $r | format-List > c:\temp\Invoke-DebugWorkflow.log

If you open Invoke-DebugWorkflow.log in a text editor, you can use the Message properties for analysis. For example, here are some messages that show PowerShell reusing a connection it’s made to a remote machine:

Message      : Trace Information: 
                PSW ConnMgr: Creating new connection to service request
(...)
Message      : Trace Information: 
                PowerShell activity: Finished running command.
(...)
Message      : Trace Information: 
                PSW ConnMgr: Assigning existing connection to request
(...)
Message      : Trace Information: 
                PowerShell activity: Finished running command.

Of course, a text editor isn’t the only way to analyze these logs. Given that these event logs are returned as fully structured objects, you can easily write scripts to automate the analysis of these large data sets. For more information about analyzing ETW logfiles, see Chapter 23.

As a final source of runtime knowledge, PowerShell workflows expose a fairly detailed list of performance counters. These counters let you track the number of running workflows, number of remoting connections being used, and more. To see these counters, use the Get-Counter cmdlet:

PS > Get-Counter -ListSet "PowerShell Workflow" | Foreach Paths

(...)
\PowerShell Workflow(*)\# of running workflow jobs
(...)

PS > Get-Counter "\PowerShell Workflow(*)\# of running workflow jobs"

Timestamp                 CounterSamples                                                                                      
---------                 --------------                                                                                      
8/24/2012 9:00:20 PM      \\computer\powershell workflow(7564)\
                            # of running workflow jobs : 1

For more information about working with performance counters, see Access Windows Performance Counters. For more information about writing PowerShell workflows, see Write a Workflow.

See Also

Access Windows Performance Counters

Write a Workflow

Chapter 23, Event Logs

Creative Commons License
This work is licensed under a Creative Commons Attribution-NonCommercial-NoDerivs 3.0 Unported License.