Verbose or Debug?

This morning there was some discussion on Twitter about when to use Write-Verbose and when to use Write-Debug. They both can provide additional information about what your script or function is doing, although you have to write the code. Typically, I use Write-Verbose to provide trace and flow messages. When enabled, it makes it easier to follow what the script is doing and often the messages include variable information. Write-Debug is helpful for providing detailed debug messages, but it also has the effect of turning on debuggging when you include it.

Here’s a sample script that uses both cmdlets.

[cc lang=”PowerShell”]

#requires -version 2.0

[cmdletbinding()]
Param([string]$computername=$env:computername)

$start=Get-Date
Write-Verbose “Starting $($myinvocation.mycommand)”
Write-Debug “`$computername is $computername”
Write-Verbose “Connecting to $computername”

Try {
Write-Debug “Trying WMI”
$cs=get-wmiobject -class win32_computersystem -ComputerName $computername -errorAction Stop
}
Catch {
Write-Debug “Exception caught”
Write-Warning (“Failed to get WMI information from $computername. {0}” -f $_.Exception.Message)
}

if ($cs) {
Write-Verbose “Processing Results”
Write-Debug ($cs | Select * | Out-string)
$cs | Select Model,Manufacturer
}
$end=Get-Date
Write-Debug (“Total processing time {0}” -f ($end-$start).ToString())
Write-Verbose “Ending $($myinvocation.mycommand)”
[/cc]

The script can use the common -Verbose and -Debug common parameters because I include the [cmdletbinding()] attribute. You don’t need to define the parameters. When I run the script normally it runs as expected.

[cc lang=”DOS”]
PS S:\> .\debugdemo.ps1

Model Manufacturer
—– ————
Qosmio X505 TOSHIBA
[/cc]

When I use -Verbose, all the Write-Verbose commands “work”.

The -Debug parameter does the same thing for Write-Debug, but it also turns on debugging:

Not only do I get the Write-Debug messages, but I get a prompt for every command. I can drop into the debug prompt using the Suspend option and look at variables or run any other PowerShell commands. Some 3rd party script editors, like PrimalScript, also take advantage of Write-Debug messages. I can load the script into the editor and run it with Debug turned on (F7 or F5) and the debug messages show in the Debug window.

This ability to step through a script is very handy, but often (personally) I just need to see where I’m at in the script and Write-Verbose suffices. As you see you can have both types of commands, and you can certainly run the script with both parameters. One last note, both cmdlets require that the message be a string. When I want to write objects using either Write-Debug or Write-Verbose, I use expressions like this:

[cc lang=”PowerShell”]
Write-Debug ($cs | Select * | Out-string)
[/cc]

I encourage you to include Verbose/Debug messages from the very beginning of your script development. You only see the messages when you use the appropriate parameter. It may seem like a lot of work up front, but when the time comes to debug or trace a problem, you’ll realize it was time well spent.

PowerShell Automatic Logging

If you regularly download or look at the functions and scripts I post here, you’ll notice I often use Write-Verbose to indicate what is happening. This comes in handy for troubleshooting. But often it would also be helpful to record as a log file of script activity. Unfortunately, you can’t pipe Write-Verbose to Out-File. So I came up with my own function called Write-Log that gives me the best of both worlds. I can get verbose messages and send those messages to a text file for logging.

The function is relatively simple. This is the core code without the comment based help.

The function takes two parameters, -Message and -Path. The former is the string of text you want to display and/or log to a text file. The Path is the filename and path of the log file. I’ve given this parameter a default value of $env:temp\PowerShellLog.txt. The function writes the message string to the log file with the current date and time prepended.

Output is always appended to the log file. Because the function uses cmdlet binding, if it detects -Verbose then the Write-Verbose message will be visible.

Now here’s the fun part. I wanted to make Write-Log to behave like Write-Verbose. That is, I wanted to include the command in my scripts and functions but only have it actually do something when I needed it. My Write-Log function looks for two variables. The first is $LoggingPreference. If this has a value of “Continue”, then logging takes place. I also reference another variable called $loggingFilePreference. This variable contains the filename and path for your log file and takes precedence over the temp file default.

There are several ways then that you could use this. First off, you need to dot source the function either in your PowerShell session or your script/function. Within your code use Write-Log just like you would Write-Verbose. To “activate”, all you need to do is set $LoggingPreference to “Continue” somewhere. Here’s one example.

My TryMe function includes a parameter called -Log. If I use this parameter, then the logging variables are set and my Write-Log commands will work. If I don’t use -Log, Write-Log is still called but nothing is written. Because TryMe uses cmdlet binding, if I run it with -Verbose then I’ll get the verbose message via Write-Log. You can even use both -Verbose and -Log which will give you verbose messages and write to the log file.

Another way would be to turn on the logging variable and use the default log. Here’s a snippet.

This gives me the -Logging parameter that turns everything on. Remember, in this snippet the log file will the default in the TEMP folder. Although as an added bonus because you can specify a log file, you can write to multiple log files within the same script or function.

I hope you’ll let me know what you think and if you find this useful. If so, don’t forget my tip jar.

Download Write-Log.ps1.

Verbose Variations

talkbubble While I’ve been judging entries in the 2010 Scripting Games, I’ve noticed a few things that I thought I would comment on here. In longer and complicated scripts, I’ve always suggested script developers provide some sort of feedback about what the script is doing.  Typically this is done with Write-Host, but there are several ways you can approach this. Let me discuss a few variations.

Continue reading