{"id":572,"date":"2008-08-06T09:28:02","date_gmt":"2008-08-06T17:28:02","guid":{"rendered":"http:\/\/www.sapien.com\/blog\/?p=572"},"modified":"2008-08-06T09:30:01","modified_gmt":"2008-08-06T17:30:01","slug":"more-fun-with-debug-messages","status":"publish","type":"post","link":"https:\/\/dev.sapien.com\/blog\/2008\/08\/06\/more-fun-with-debug-messages\/","title":{"rendered":"More Fun with Debug Messages"},"content":{"rendered":"

A few weeks ago I posted an entry<\/a> 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.<\/p>\n

The other major change to the function is that I reformatted the date time to reflect milliseconds.<\/p>\n

$timestamp=get-date -f ‘MM\/dd\/yyyy HH:mm:ss:ffff’ <\/span><\/p>\n

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.<\/p>\n

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.<\/p>\n

\n
\n
   1:<\/span> $debuglog=$TRUE<\/pre>\n
   2:<\/span><\/pre>\n
   3:<\/span> if<\/span> ($debuglog) {<\/pre>\n
   4:<\/span>     #define a temporary name for the transcript file<\/span><\/pre>\n
   5:<\/span>     $transcriptName=\"{0}_transcript.txt\"<\/span> -f $myinvocation.mycommand.name<\/pre>\n
   6:<\/span>     $transcript=(Join-Path \"C:\\\" $transcriptName )<\/pre>\n
   7:<\/span>     Start-Transcript $transcript | Out-Null<\/pre>\n
   8:<\/span><\/pre>\n
   9:<\/span> }<\/pre>\n<\/div>\n<\/div>\n
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.<\/p>\n
At the end of the script, I have similar code to create a debug log file based on the script name.<\/p>\n
\n
\n
   1:<\/span> if<\/span> ($debuglog) {<\/pre>\n
   2:<\/span>     $filename=\"{0}_debug.txt\"<\/span> -f $myinvocation.mycommand.name<\/pre>\n
   3:<\/span>     $debuglogfile=(Join-Path \"c:\\\" $filename)<\/span><\/pre>\n
   4:<\/span><\/pre>\n
   5:<\/span>     Stop-Transcript | Out-Null<\/pre>\n
   6:<\/span><\/pre>\n
   7:<\/span>     Get-Content $transcript | Select-String -Pattern \"DEBUG:\" | Out-File $debuglogfile<\/span><\/pre>\n
   8:<\/span><\/pre>\n
   9:<\/span>     notepad $debuglogfile<\/pre>\n
  10:<\/span><\/pre>\n
  11:<\/span>     $rc=Read-Host \"Do you want to delete $transcript [YN]?\"<\/span><\/pre>\n
  12:<\/span>     if ($rc -match \"y\") {<\/pre>\n
  13:<\/span>         Remove-Item $transcript<\/pre>\n
  14:<\/span>     }<\/pre>\n
  15:<\/span><\/pre>\n
  16:<\/span> }<\/pre>\n<\/div>\n<\/div>\n
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.<\/p>\n
Here’s a sample script that uses the Write-DebugMessage function and my debug logging code.<\/p>\n
\n
\n
   1:<\/span> Function Write-DebugMessage {<\/pre>\n
   2:<\/span>        Param([string]$text)<\/pre>\n
   3:<\/span><\/pre>\n
   4:<\/span>        #set to Continue to turn on debug messages<\/span><\/pre>\n
   5:<\/span>        $debugpreference=\"continue\"<\/span><\/pre>\n
   6:<\/span><\/pre>\n
   7:<\/span>        # build a text string of information that can be passed<\/span><\/pre>\n
   8:<\/span>        # to the Debug pipeline<\/span><\/pre>\n
   9:<\/span><\/pre>\n
  10:<\/span>        #here are some variables you might want to work with<\/span><\/pre>\n
  11:<\/span>        $computer=$env:computername<\/pre>\n
  12:<\/span>        $domain=$env:userdomain<\/pre>\n
  13:<\/span>        $user=$env:username<\/pre>\n
  14:<\/span><\/pre>\n
  15:<\/span>        #return a timestamp value with milliseconds<\/span><\/pre>\n
  16:<\/span>        #like 08\/06\/2008 11:08:37:4361<\/span><\/pre>\n
  17:<\/span>        #Or you can use an expression like this<\/span><\/pre>\n
  18:<\/span>        #(Get-Date -Format g).toString()<\/span><\/pre>\n
  19:<\/span>        $timestamp=get-date -f 'MM\/dd\/yyyy HH:mm:ss:ffff'<\/span><\/pre>\n
  20:<\/span><\/pre>\n
  21:<\/span>        $line=$($myinvocation.scriptlinenumber)<\/pre>\n
  22:<\/span>        $script<\/span>=$($myinvocation.invocationname)<\/pre>\n
  23:<\/span><\/pre>\n
  24:<\/span>        [string]$msg=\"[{0}:{1}\\{2}] {3} Line:{4} {5}\"<\/span> -f $computer,$domain,$user,$timestamp,$line,$text<\/pre>\n
  25:<\/span><\/pre>\n
  26:<\/span>        Write-Debug $msg<\/pre>\n
  27:<\/span><\/pre>\n
  28:<\/span>    }<\/pre>\n
  29:<\/span><\/pre>\n
  30:<\/span> Function Foo-Me {<\/pre>\n
  31:<\/span><\/pre>\n
  32:<\/span>    Write-DebugMessage \"in function $($myinvocation.invocationname)\"<\/span><\/pre>\n
  33:<\/span>    Write-DebugMessage \"getting services\"<\/span><\/pre>\n
  34:<\/span>    Get-Service<\/pre>\n
  35:<\/span>    Write-DebugMessage \"exiting function\"<\/span><\/pre>\n
  36:<\/span> }<\/pre>\n
  37:<\/span><\/pre>\n
  38:<\/span> #setting this to $TRUE doesn't do any good if the debug pipeline is <\/span><\/pre>\n
  39:<\/span> #turned off    <\/span><\/pre>\n
  40:<\/span> debuglog=$TRUE<\/pre>\n
  41:<\/span><\/pre>\n
  42:<\/span> if<\/span> ($debuglog) {<\/pre>\n
  43:<\/span>    #define a temporary name for the transcript file<\/span><\/pre>\n
  44:<\/span>    $transcriptName=\"{0}_transcript.txt\"<\/span> -f $myinvocation.mycommand.name<\/pre>\n
  45:<\/span>    $transcript=(Join-Path \"C:\\\" $transcriptName ) <\/span><\/pre>\n
  46:<\/span>    Start-Transcript $transcript | Out-Null<\/pre>\n
  47:<\/span><\/pre>\n
  48:<\/span> write-DebugMessage \"starting $($myinvocation.invocationname)\"<\/span><\/pre>\n
  49:<\/span><\/pre>\n
  50:<\/span> sleep 4<\/pre>\n
  51:<\/span><\/pre>\n
  52:<\/span> write-DebugMessage \"Getting Date\"<\/span><\/pre>\n
  53:<\/span> get-Date<\/pre>\n
  54:<\/span><\/pre>\n
  55:<\/span> write-DebugMessage \"Getting powershell process<\/span>\"<\/span><\/pre>\n
  56:<\/span> get-Process powershell<\/pre>\n
  57:<\/span><\/pre>\n
  58:<\/span> write-DebugMessage \"Calling Foo-Me\"<\/span><\/pre>\n
  59:<\/span> foo-Me<\/pre>\n
  60:<\/span><\/pre>\n
  61:<\/span> write-DebugMessage \"Getting WMI Information\"<\/span><\/pre>\n
  62:<\/span> $d=Get-WmiObject win32_logicaldisk -filter \"deviceid='c:'<\/span>\"<\/span><\/pre>\n
  63:<\/span><\/pre>\n
  64:<\/span> write-DebugMessage (\"Drive C size is {0}GB\" -f ([int]($d.Size\/1GB)))<\/span><\/pre>\n
  65:<\/span><\/pre>\n
  66:<\/span> a=@(1,2,3,4,5)<\/pre>\n
  67:<\/span> write-DebugMessage $a<\/pre>\n
  68:<\/span><\/pre>\n
  69:<\/span> write-DebugMessage \"finished\"<\/span><\/pre>\n
  70:<\/span><\/pre>\n
  71:<\/span> if ($debuglog) {<\/pre>\n
  72:<\/span>    $filename=\"{0}_debug.txt\" -f $myinvocation.mycommand.name<\/span><\/pre>\n
  73:<\/span>    $debuglogfile=(Join-Path \"c:\\\" $filename)<\/span><\/pre>\n
  74:<\/span><\/pre>\n
  75:<\/span>    Stop-Transcript | Out-Null<\/pre>\n
  76:<\/span><\/pre>\n
  77:<\/span>    Get-Content $transcript | Select-String -Pattern \"DEBUG:\" | Out-File $debuglogfile<\/span><\/pre>\n
  78:<\/span><\/pre>\n
  79:<\/span>    notepad $debuglogfile<\/pre>\n
  80:<\/span><\/pre>\n
  81:<\/span>    $rc=Read-Host \"Do you want to delete $transcript [YN]?\"<\/span><\/pre>\n
  82:<\/span>    if ($rc -match \"y\") {<\/pre>\n
  83:<\/span>        Remove-Item $transcript<\/pre>\n
  84:<\/span>    }<\/pre>\n
  85:<\/span><\/pre>\n
  86:<\/span><\/pre>\n<\/div>\n<\/div>\n
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.<\/p>\n
If you have any suggestions on this topic, I’d love to hear them.<\/p>\n
\n
You can download the debug demo script here<\/a><\/div>\n","protected":false},"excerpt":{"rendered":"
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 and made other improvements.<\/p>\n","protected":false},"author":3,"featured_media":0,"comment_status":"open","ping_status":"open","sticky":false,"template":"","format":"standard","meta":{"_monsterinsights_skip_tracking":false,"_monsterinsights_sitenote_active":false,"_monsterinsights_sitenote_note":"","_monsterinsights_sitenote_category":0,"footnotes":""},"categories":[25],"tags":[259,260,28,57,261,255],"class_list":["post-572","post","type-post","status-publish","format-standard","hentry","category-windows-powershell","tag-debug","tag-get-date","tag-powershell","tag-scripting","tag-transcript","tag-write-debug"],"jetpack_featured_media_url":"","_links":{"self":[{"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/posts\/572","targetHints":{"allow":["GET"]}}],"collection":[{"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/posts"}],"about":[{"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/types\/post"}],"author":[{"embeddable":true,"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/users\/3"}],"replies":[{"embeddable":true,"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/comments?post=572"}],"version-history":[{"count":1,"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/posts\/572\/revisions"}],"predecessor-version":[{"id":573,"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/posts\/572\/revisions\/573"}],"wp:attachment":[{"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/media?parent=572"}],"wp:term":[{"taxonomy":"category","embeddable":true,"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/categories?post=572"},{"taxonomy":"post_tag","embeddable":true,"href":"https:\/\/dev.sapien.com\/blog\/wp-json\/wp\/v2\/tags?post=572"}],"curies":[{"name":"wp","href":"https:\/\/api.w.org\/{rel}","templated":true}]}}