August 6, 2008 / by Jeffery Hicks / Windows PowerShell / 3 Comments

More Fun with Debug Messages

A few weeks ago I posted an entry on creating customized debug messages that you can use in your scripting. After some more testing and tweaking I revised and renamed the function. Write-DebugMessage can now be used within your script to send messages to the debug pipeline. I moved the $debugpreference setting to the function itself. If you set it to Continue,the message will be written to the debug pipeline.

The other major change to the function is that I reformatted the date time to reflect milliseconds.

$timestamp=get-date -f ‘MM/dd/yyyy HH:mm:ss:ffff’

It all works great. But one of my online PowerShell students asked about saving debug messages to a file. That seemed like a reasonable request. Unfortunately, PowerShell v1.0 doesn’t appear to have any provision for redirecting the debug pipeline. Undaunted I dug in and came up with this solution.

When you record a PowerShell transcript, everything, including debug messages is written to it. My solution was to create a transcript file, parse out the debug messages and save them to a new file.

   1: $debuglog=$TRUE
   2:
   3: if ($debuglog) {
   4:     #define a temporary name for the transcript file
   5:     $transcriptName="{0}_transcript.txt" -f $myinvocation.mycommand.name
   6:     $transcript=(Join-Path "C:\" $transcriptName )
   7:     Start-Transcript $transcript | Out-Null
   8:
   9: }

Set the $debuglog variable to $True if you want to log your debug messages. If so, I define a transcript name generated from the script name which I pull from $myinvocation.mycommand.name. I could probably parse it further to drop the extension but it works and it is temporary for the most part. You must start the transcript before you have any debug message code.

At the end of the script, I have similar code to create a debug log file based on the script name.

   1: if ($debuglog) {
   2:     $filename="{0}_debug.txt" -f $myinvocation.mycommand.name
   3:     $debuglogfile=(Join-Path "c:\" $filename)
   4:
   5:     Stop-Transcript | Out-Null
   6:
   7:     Get-Content $transcript | Select-String -Pattern "DEBUG:" | Out-File $debuglogfile
   8:
   9:     notepad $debuglogfile
  10:
  11:     $rc=Read-Host "Do you want to delete $transcript [YN]?"
  12:     if ($rc -match "y") {
  13:         Remove-Item $transcript
  14:     }
  15:
  16: }

The Get-Content expression parses out the debug lines and writes them to the debug log file. At the end, I’ve added code to prompt you to delete the temporary transcript file.

Here’s a sample script that uses the Write-DebugMessage function and my debug logging code.

   1: Function Write-DebugMessage {
   2:        Param([string]$text)
   3:
   4:        #set to Continue to turn on debug messages
   5:        $debugpreference="continue"
   6:
   7:        # build a text string of information that can be passed
   8:        # to the Debug pipeline
   9:
  10:        #here are some variables you might want to work with
  11:        $computer=$env:computername
  12:        $domain=$env:userdomain
  13:        $user=$env:username
  14:
  15:        #return a timestamp value with milliseconds
  16:        #like 08/06/2008 11:08:37:4361
  17:        #Or you can use an expression like this
  18:        #(Get-Date -Format g).toString()
  19:        $timestamp=get-date -f 'MM/dd/yyyy HH:mm:ss:ffff'
  20:
  21:        $line=$($myinvocation.scriptlinenumber)
  22:        $script=$($myinvocation.invocationname)
  23:
  24:        [string]$msg="[{0}:{1}\{2}] {3} Line:{4} {5}" -f $computer,$domain,$user,$timestamp,$line,$text
  25:
  26:        Write-Debug $msg
  27:
  28:    }
  29:
  30: Function Foo-Me {
  31:
  32:    Write-DebugMessage "in function $($myinvocation.invocationname)"
  33:    Write-DebugMessage "getting services"
  34:    Get-Service
  35:    Write-DebugMessage "exiting function"
  36: }
  37:
  38: #setting this to $TRUE doesn't do any good if the debug pipeline is 
  39: #turned off    
  40: debuglog=$TRUE
  41:
  42: if ($debuglog) {
  43:    #define a temporary name for the transcript file
  44:    $transcriptName="{0}_transcript.txt" -f $myinvocation.mycommand.name
  45:    $transcript=(Join-Path "C:\" $transcriptName ) 
  46:    Start-Transcript $transcript | Out-Null
  47:
  48: write-DebugMessage "starting $($myinvocation.invocationname)"
  49:
  50: sleep 4
  51:
  52: write-DebugMessage "Getting Date"
  53: get-Date
  54:
  55: write-DebugMessage "Getting powershell process"
  56: get-Process powershell
  57:
  58: write-DebugMessage "Calling Foo-Me"
  59: foo-Me
  60:
  61: write-DebugMessage "Getting WMI Information"
  62: $d=Get-WmiObject win32_logicaldisk -filter "deviceid='c:'"
  63:
  64: write-DebugMessage ("Drive C size is {0}GB" -f ([int]($d.Size/1GB)))
  65:
  66: a=@(1,2,3,4,5)
  67: write-DebugMessage $a
  68:
  69: write-DebugMessage "finished"
  70:
  71: if ($debuglog) {
  72:    $filename="{0}_debug.txt" -f $myinvocation.mycommand.name
  73:    $debuglogfile=(Join-Path "c:\" $filename)
  74:
  75:    Stop-Transcript | Out-Null
  76:
  77:    Get-Content $transcript | Select-String -Pattern "DEBUG:" | Out-File $debuglogfile
  78:
  79:    notepad $debuglogfile
  80:
  81:    $rc=Read-Host "Do you want to delete $transcript [YN]?"
  82:    if ($rc -match "y") {
  83:        Remove-Item $transcript
  84:    }
  85:
  86:

There is one major caveat to this technique which may or not be relevant to you. PowerShell only allows one transcript per session. If you are running a transcript in your PowerShell console and try to run this script you’ll get an error message and no debug log will be created.

If you have any suggestions on this topic, I’d love to hear them.

You can download the debug demo script here

, , , , ,