PowerShell 2.0: A Configurable and Flexible Script Logger Module

One thing that has been lamented frequently about PowerShell is that it is very difficult to log, if not impossible, to log all of the various types of streams it has to a single source. The legacy Windows shell CMD, and Unix shells like Bash, Ksh etc only deal with three streams: stdin, stdout and stderr for Input, Ouput and Error respectively. PowerShell has many more: Input, Output, Verbose, Warning, Debug, Progress and Error. Finally, the APIs in v2.0 offer enough hooks to unify the logging but you got to work a bit to make it come together. Well, to be honest, you got me doing the work. The rest is easy ;)

import-module .\scriptlogger.psm1 -force

$logger = New-ScriptLogger

# override error handler
$logger.ErrorHandler = {
    param($record)
    
    $record.tostring() >> scriptlog.txt
}

# override verbose handler
$logger.VerboseHandler = {
    param($record)
    
    $record.message >> scriptlog.txt
}

# run scriptblock with logging
$logger.Invoke(
    {
        $verbosepreference='continue';
        $erroractionpreference = 'continue';
        $debugpreference = 'continue';
        write-verbose "verbose";
        write-error "an error";
        write-warning "a warning"
        Write-debug "debug string"
        "this is output"
        1,2,3
    })
And here is the module; save it as ScriptLogger.psm1. By default, all logging goes to an attached debugger, like sysinternals DbgView. You can override any of the handlers like above and do what you want. Each handler receives one argument: a ErrorRecord, WarningRecord, VerboseRecord, DebugRecord or ProgressRecord. All of these Types are native powershell types and are documented on MSDN.
<#
    Name     : Universal Script Logging Module (ScriptLogger.psm1)
    Version  : 0.1
    Author   : Oisin Grehan (MVP)
    Site     : http://www.nivot.org/
#>
function New-ScriptLogger {
    New-Module -AsCustomObject -ScriptBlock {
        
        $script:ps              = [powershell]::Create()
        $script:ar              = $null
        $script:module          = $ExecutionContext.SessionState.Module
        
        [scriptblock]
        $script:ErrorHandler    = {
            param(
                [Management.Automation.ErrorRecord]
                $record
            )
            [diagnostics.debug]::writeline(
                "Error: " + $record.tostring());
        }
        [scriptblock]
        $script:WarningHandler  = {
            param(
                [Management.Automation.WarningRecord]
                $record
            )        
            [diagnostics.debug]::writeline(
                "Warning: " + $record.message);
        }
        [scriptblock]
        $script:VerboseHandler  = {
            param(
                [Management.Automation.VerboseRecord]
                $record
            )
            [diagnostics.debug]::writeline(
                "Verbose: " + $record.message);
        }
        [scriptblock]
        $script:DebugHandler    = {
            param(
                [Management.Automation.DebugRecord]
                $record
            )
            [diagnostics.debug]::writeline(
                "Debug: " + $record.message);
        }
        [scriptblock]
        $script:ProgressHandler = {
            param(
                [Management.Automation.ProgressRecord]
                $record
            )        
            [diagnostics.debug]::writeline(
                "Progress: " + $record);
        }
        
        $script:Handlers   = @{
            Error = Register-ObjectEvent $ps.Streams.Error DataAdded -Action {
                & $event.MessageData {& $ErrorHandler @args} $event.sender[$eventargs.index]
            } -MessageData $module #-SupportEvent
            
            Warning = Register-ObjectEvent $ps.Streams.Warning DataAdded -Action {
                & $event.MessageData {& $WarningHandler @args} $event.sender[$eventargs.index]
            } -MessageData $module #-SupportEvent
            
            Verbose = Register-ObjectEvent $ps.Streams.Verbose DataAdded -Action {
                & $event.MessageData {& $VerboseHandler @args} $event.sender[$eventargs.index]
            } -MessageData $module #-SupportEvent
            
            Debug = Register-ObjectEvent $ps.Streams.Debug DataAdded -Action {
                & $event.MessageData {& $DebugHandler @args} $event.sender[$eventargs.index]
            } -MessageData $module #-SupportEvent
            
            Progress = Register-ObjectEvent $ps.Streams.Progress DataAdded -Action {
                & $event.MessageData {& $ProgressHandler @args} $event.sender[$eventargs.index]
            } -MessageData $module #-SupportEvent
        }
        
        function Invoke {
            param(
                [validatenotnullorempty()]
                [scriptblock]$script
            )
            
            try {
            
                write-host -foreground green "Running"
                
                $ps.commands.clear()
                $command = new-object management.automation.runspaces.command $script, $true            
                $ps.commands.addcommand($command) > $null                
                $ps.invoke() # returns output                
            
            } catch {
            
                # oops-ee!
                write-host -foreground red "Unhandled terminating error: $_"
                $record = new-object management.automation.errorrecord $(
                    new-object exception $_.tostring()), "TerminatingError", "NotSpecified", $null
                & $ErrorHandler $record
            
            } finally {
            
                write-host -foreground green "Complete"
            
            }
        }
                
        Export-ModuleMember -Function Invoke -Variable ErrorHandler, WarningHandler, VerboseHandler, DebugHandler, ProgressHandler
    }
}

Have fun!

PowerShell 2.0 – Persisting Command History

update: 2009-09-27 - removed usage of closures - turns out i hadn't tested that modification properly. oops.

Here’s a quick one – in order to sway excessive BASH jealously, I knocked this up to persist the last 100 history items between PowerShell sessions. It hooks the special engine (as opposed to object) event “poweshell.exiting” and runs a script to save history to an XML file using the universally useful Export-CliXML cmdlet. Another trick in there is to use a closure to capture the value of the $historyPath variable. I need to do this because powershell event handlers use their own runspace (and will lose the values of the variables in the current runspace). I also could have passed the value via the –MessageData parameter and done it that way, but I figured I’m already in v2 territory so lets use that feature ;-)

# save last 100 history items on exit
$historyPath = Join-Path (split-path $profile) history.clixml

# hook powershell's exiting event & hide the registration with -supportevent.
Register-EngineEvent -SourceIdentifier powershell.exiting -SupportEvent -Action {
    Get-History -Count 100 | Export-Clixml (Join-Path (split-path $profile) history.clixml) }

# load previous history, if it exists
if ((Test-Path $historyPath)) {
    Import-Clixml $historyPath | ? {$count++;$true} | Add-History
    Write-Host -Fore Green "`nLoaded $count history item(s).`n"
}

Dump this into your profile and have fun!

PowerShell 2.0 Now Available for Vista and Server 2008

I’ve been reliably informed (and double checked) and I’m happy to relay to you all that PowerShell 2.0 is available as part of the Windows Management Framework RC. This includes the following components:

  • WinRM 2.0
  • Windows PowerShell 2.0
  • BITS 4.0

This is the culmination of nearly three years’ of work to bring Windows to the cutting edge of automation technology. Grab it while it’s toasty from:

https://connect.microsoft.com/windowsmanagement/Downloads

Spread the word!

About the author

Irish, PowerShell MVP, .NET/ASP.NET/SharePoint Developer, Budding Architect. Developer. Montrealer. Opinionated. Montreal, Quebec.

Month List

Page List