How-To streamline Powershell logs and console output
Over the years, I have developed a series of functions that help me handle the logging and console output of my PowerShell code. It started after getting frustrated with repeating my code multiple times in different locations or worse, when I had to make a change to the formatting. As time went on, I realized that it was really handier to just create a function can simply pass the type of message along with the message. The big benefit is that with a simple flip of switch, I could log to a file, to the console, and even handle debug or verbose output.
Let’s talk about logging behavior. I am working on a pretty cool integration with PowerShell DSC and NetApp Powershell toolkit. The process requires creating tons of code and functions which leads to a lot of debugging. Now, One might just plan to use a myriad of ‘write-host’, ‘write-verbose’, ‘write-error’, etc commands and sprinkle them into the code. I have found that centralizing this into a singular function or method, for those creating classes, just makes the code better and easier to use.
Recently, I had a scenario where we needed to print to console and to a log file all output for Info and Debug code. Once we finished debugging the code, we needed to ‘turn-off’ the debug console printing as well as the log file. I also needed to have some messages only go to the console and others go to the log. This would need a lot of repetition in the code and even more multiple layers to debug. What happens when I want to use special formatting in a State condition that isn’t one of your common options. In this case, I created the following function.
function New-MessageLogger{ [CmdletBinding()] param( [switch] $Info, [switch] $Warn, [switch] $Debugger, [switch] $State, [switch] $Err, [string] $PassedMessage, [switch] $Log, [switch] $Blocking ) # Default directory to drop this file. $__LogDirectory = '\logs' # Set the script name variable to be this script otherwise, we should return # the default name of this function. $__ScriptName = $script:MyInvocation.MyCommand.Name if([string]::IsNullOrEmpty($__ScriptName)) { $__ScriptName = $MyInvocation.InvocationName } # Get the formatted timestamp for the log entry $__CurrentTimeStamp = (Get-Date -format "yyyy-MM-dd_HH:mm:ss") # This variable is used to tell the system to throw the message instead of just writing to the # log and moving on. This is very handy as you can control all exception cases and logging # from a central location. $__DeadmanSwitch = $false # Because we are supporting Switch parameters, we will need to use a cascading conditional # for this. if ($Warn) { # The __Classification Variable is used for console printing while the __LogClassification variable is to ensure # that the log print out is clear and formatted nicely # $__Classification = 'WARNING: ' $__LogClassification = 'WARNING : ' $__expression = 'Write-Warning ' } elseif ($Debugger){ # Since the variable $Verbose should be considered protected, I decided to use a different # variable called -Debugger to trigger. This still will only print if the $VerbosePreference is enabled. if($VerbosePreference -eq "continue" ) { $__Classification = 'DEBUG:`t ' $__LogClassification = 'DEBUG : ' # $__expression = 'Write-Host -foregroundcolor "yellow" ' $__expression = 'Write-Verbose ' } } elseif ($State){ # State is a helpful visual cue that can be used for things like script start or changes in state. $__Classification = 'STATE:`t ' $__LogClassification = 'State : ' $__expression = ( "Write-Host " + $__Classification ) } elseif($Err) { if($Blocking){ $__DeadmanSwitch = $true } $__Classification = 'Error:`t ' $__LogClassification = 'Error : ' $__expression = ( "Write-Host -foregroundcolor 'red' " + $__Classification ) } else{ # If no Option sent then assume that it is an Informational message. Since we have this set as the default, # There is no reason to create a conditional check for the -Info switch. It is still good to support this, # as it makes reviewing the code much easier. $__Classification = 'INFO:`t ' $__LogClassification = 'INFO : ' $__expression = ( "Write-Host " + $__Classification ) } if ($__expression) { # This variable $__WrittenMessage will contain the formatted message string and would be printing in the following way: # tmp.ps1:::INFO 2017-01-02_11:07:09 This is a quick message printed and logged\ # $__WrittenMessage = ( "{0}`t{1}`t{2}" -f $__ScriptName, $__CurrentTimeStamp, $PassedMessage ) Invoke-Expression ( $__expression + "'" + $__WrittenMessage + "'" ) if($Log){ # First we should determine if this is a script or a direct function call. Based on the location # we will set the root path for the logs. $__LogPath = split-path -parent $script:MyInvocation.MyCommand.Definition if([string]::IsNullOrEmpty($__LogPath)) { $__LogPath = '.' } $__LogPath += $__LogDirectory # Need to add the log directory to the $__LogPath variable if ( -not (Test-Path $__LogPath) ){ # Need to create the Log directory if it does not exist New-Item -Type Directory $__LogPath | Out-Null } $__LogFileOutput = $($__LogPath + "\" + $__ScriptName.replace('.','_') +".log") ( "{0}{1}" -f $__LogClassification , $__WrittenMessage ) | Out-File -FilePath $__LogFileOutput -Append } if ( $__DeadmanSwitch ){ # In the event that the passed message is an error type and should be considered a blocker, we can trigger the __DeadmanSwitch # by passing the variable $Blocking. This allows us to centrally manage how to log and throw exceptions. The call to this # function can be then triggered and used inside of your custom Try/Catch handlers. throw $PassedMessage } } } New-MessageLogger -Info 'This is a quick message' New-MessageLogger -Warn 'This is a quick warning message' -Log New-MessageLogger -Debugger 'This is a quick debug message' -Verbose -Log New-MessageLogger -State 'This is a state change' -Log -Verbose New-MessageLogger -Info 'This is a quick message printed and logged' -Log New-MessageLogger -Err 'This is an error message printed and logged' -Log New-MessageLogger -Err 'This is an error message printed and logged with an exception' -Log -Blocking