Powershell Logging

Steve Rackham included in categories PowerShell VSCodium

2021-10-19 2021-10-19 929 words 5 minutes

Contents

Overview

Logging is an important feature of any script or console interaction. You want to know what happened and when. Its used for diagnostics, auditing and potential investigation of security issues. This post suggests several logging tools and how to incorporate into your scripts efficiently using User Snippets and Modules.

Logging

There are several excellent logging modules. I recommend the following depending on your needs:

Module	Description
PSFramework	The PSFramework module is designed as a large toolkit, enabling simple integration of advanced features, manageability of code & scripts, as well as enhancements to the individual user’s experience.
PoshLog	PoShLog is powershell cross-platform logging module. PoShLog allows you to log structured event data into console, file and much more places easily. It’s built upon great C# logging library Serilog.

The PSFramework module is powerful and can be daunting. I would see this as the goto framework within a PowerShell shop or enterprise organisation. It comes with a plethora of options and other functions and snippets beyond logging and I do highly recommend it. Check out the documentation to see what it has to offer and if its right for you.

The PoshLog module is simple and produces quality logging that should meet most needs out of the box. I replaced my own logging functions with this module. The module itself is already well documented so check it out here.

This post will focus on using PoshLog and how to efficiently incorporate into your scripts using snippets within VSCodium.

User Snippets

User-Defined Snippets are templates that make it easier to enter repeating code patterns, such as loops or conditional-statements.

For example, I often want to loop through a series of objects with a foreach loop and want to track progress. There is already a builtin snippet for the foreach loop, but how about adding something for Write-Progress?

Example: Progress Output Snippet

So, we can add the following into our snippets:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21


    "Progress Output": {
        "prefix": "progress",
        "body": [
            "# STATUS :---------------------------------------------------------",
            "$$Counter++",
            "",
            "# Write-Progress Operation.",
            "$WriteProgressParams = @{",
            "    Activity         = \"${1:Action}...\"",
            "    Status           = \"Progress: $$Counter of $$CounterTotal\"",
            "    CurrentOperation = \"Processing: ${2:$$item}\"",
            "    PercentComplete  = (($$Counter / $$CounterTotal) * 100)",
            "",
            "} # END $WriteProgressParams",
            "",
            "Write-Progress @WriteProgressParams",
            "",
            "$3"
        ],
        "description": "Status Output"
    },

And when you want to add progress bar simply typing the prefix progress as you are coding will produce this result:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15


# STATUS :---------------------------------------------------------
$Counter++

# Write-Progress Operation.
WriteProgressParams = @{
    Activity         = "Action..."
    Status           = "Progress: $Counter of $CounterTotal"
    CurrentOperation = "Processing: $item"
    PercentComplete  = (($Counter / $CounterTotal) * 100)

} # END WriteProgressParams

Write-Progress @WriteProgressParams

Nice right?

Example: Logging Snippet with PoshLog

If we want to quickly create a code logging experience we can add the following snippet to our snippets:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38


      "logger": {
        "prefix": "logger",
        "body": [
          "# Logging: ####################################################################",
          "# Modules: --------------------------------------------------------------------",
          "if (Get-Module -ListAvailable -Name PoshLog, PoshLog.Enrichers) {",
          "    Import-Module PoshLog",
          "    Import-Module PoShLog.Enrichers",
          "} else {",
          "    Install-Module PoshLog",
          "    Install-PoShLog.Enrichers",
          "    Import-Module PoShLog.Enrichers",
          "    Import-Module PoshLog",
          "",
          "} # END if (Get-Module -ListAvailable -Name PoshLog) ",
          "",
          "# Log Params: ------------------------------------------------------------------",
          "$$LogPath        = \"C:\\Temp\\\"",
          "$$LogFilename    = \"Log-$(Get-Date -Format 'yyyy-MM-dTHH-mm-ss').log\"",
          "$$Log            = [System.IO.Path]::Combine($$LogPath, $$LogFilename )",
          "",
          "# Logger: ----------------------------------------------------------------------",
          "$$Logger = New-Logger |",
          "     Set-MinimumLevel -Value Verbose |",
          "     Add-EnrichWithProperty -Name UserName -Value $($$env:USERNAME).ToLower() |",
          "     Add-EnrichWithEnvironment -UserName -MachineName |",
          "     Add-EnrichWithProcessId | Add-EnrichWithProcessName |",
          "     Add-EnrichWithExceptionDetails |",
          "     Add-SinkFile -Path $$Log -OutputTemplate '[ {Level:u3} ] [ {UserName}@{MachineName} ] [ PID: {ProcessName}:{ProcessId} ] [ {Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} ] {Message:lj}{NewLine}{Exception}' |",
          "     Add-SinkConsole -OutputTemplate \"[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}\" | ",
          "     Start-Logger -PassThru",
          "",
          "",
          "Write-InfoLog -Logger $$Logger \"Log File location: {log}\" -PropertyValues $$Log"
        ],
        "description": "logger"
      }

Whenever we want to add a log to our script or function just type the prefix logger and this is automatically added to your script:

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33


# Logging: ####################################################################
# Modules: --------------------------------------------------------------------
# Import the modules and install if not available.
if (Get-Module -ListAvailable -Name PoshLog, PoshLog.Enrichers) {
    Import-Module PoshLog
    Import-Module PoShLog.Enrichers
} else {
    Install-Module PoshLog
    Install-PoShLog.Enrichers
    Import-Module PoShLog.Enrichers
    Import-Module PoshLog

} # END if (Get-Module -ListAvailable -Name PoshLog) 

# Log Params: ------------------------------------------------------------------
$LogPath        = "C:\Temp\"
$LogFilename    = "Log-$(Get-Date -Format 'yyyy-MM-dTHH-mm-ss').log"
$Log            = [System.IO.Path]::Combine($LogPath, $LogFilename )

# Logger: ----------------------------------------------------------------------
$Logger = New-Logger |
     Set-MinimumLevel -Value Verbose |
     Add-EnrichWithProperty -Name UserName -Value $($env:USERNAME).ToLower() |
     Add-EnrichWithEnvironment -UserName -MachineName |
     Add-EnrichWithProcessId | Add-EnrichWithProcessName |
     Add-EnrichWithExceptionDetails |
     Add-SinkFile -Path $Log -OutputTemplate '[ {Level:u3} ] [ {UserName}@{MachineName} ] [ PID: {ProcessName}:{ProcessId} ] [ {Timestamp:yyyy-MM-dd HH:mm:ss.fff zzz} ] {Message:lj}{NewLine}{Exception}' |
     Add-SinkConsole -OutputTemplate "[{Timestamp:HH:mm:ss} {Level:u3}] {Message:lj}{NewLine}{Exception}" | 
     Start-Logger -PassThru


Write-InfoLog -Logger $Logger "Log File location: {log}" -PropertyValues $Log

Close the Log

Don’t forget to use Close-Logger when you are done.

You can create multiple logs, stream to the EventLog, a syslog and others. Check out the documentation for the module to adjust the snippet to suit your needs.

Bonus Tip

You can quickly create some complicated snippets in a variety of languages using this awesome web site:

https://snippet-generator.app/

Hope that helps!