PS: Why I Use My Template For Logging

3 minute read

Description:

Logging is an essential function for scripting because it not only can display text to a screen, but it records times that scripts have ran and their associated output. I found a couple examples from the Microsoft Script Center and have since incorporated them into my PS Template Script.

To Resolve:

  1. So going by template script:

    • So in the Begin {} block of all my scripts I write a functions called Start-Log, Write-Log, and Stop-Log.
    • These simply create a folder in the script’s running directory called PSLogs and then writes a logfile which is a transaction of the script
    • Under this folder you get yyyy-mm-dd-function-name.log files for each time you run a script.
    • If it runs more than once in the same day, you see them in a single file. Different days will produce new files.
  2. Within the script I use Write-Log which is actually just using Write-Verbose but since Verbose is forced to be on at the beginning of the script, they will be written to the logfile. The power of these functions come from Start-Transcript and Stop-Transcript as it will record EVERYTHING that happens during the script, even terminating errors! This avoids the need for complex If.. then statements for logging!

  3. Getting more technical:
    • The Start-Log function will create the PSLogs directory and the logfile. If it is over 10MB it will clear it.
    • The Write-Log function has two parameters - InputObject and Color. Input object works just like Write-Output in that you can pass objects and it will expand them out. Color is statically set to Green but you can change that if you wish.
    • The Stop-Log is kinda complicated. It stops the transcript and then takes the logfile and parses it and cleans it up.
    • The reason for the complicated clean up is that it takes output that normally looks like this:
    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
    39
    40
    41
    42
    43
    44
    45
    46
    47
    48
    49
    50
    51
    52
    53
    54
    55
    56
    57
    58
    59
    60
    61
    62
    63
    64
    65
    66
    67
    68
    69
    70
    71
    72
    73
    74
    75
    76
    77
    78
    
    **********************
    Windows PowerShell transcript start
    Start time: 20200323065436
    Username: computerName\Gerry
    RunAs User: computerName\Gerry
    Configuration Name: 
    Machine: computerName (Microsoft Windows NT 10.0.18362.0)
    Host Application: PowerShell.exe -noexit -command Set-Location 'C:\scripts'
    Process ID: 2916
    PSVersion: 5.1.18362.628
    PSEdition: Desktop
    PSCompatibleVersions: 1.0, 2.0, 3.0, 4.0, 5.0, 5.1.18362.628
    BuildVersion: 10.0.18362.628
    CLRVersion: 4.0.30319.42000
    WSManStackVersion: 3.0
    PSRemotingProtocolVersion: 2.3
    SerializationVersion: 1.1.0.1
    **********************
    Transcript started, output file is C:\scripts\PSLogs\2020-03-23-Test2.log
    VERBOSE: 2020-03-23 06:54:36 AM: hello
    VERBOSE: 2020-03-23 06:54:36 AM: Function completed on computerName
    VERBOSE: 2020-03-23 06:54:36 AM: ####################</Function>####################
    **********************
    Windows PowerShell transcript end
    End time: 20200323065436
    **********************
    **********************
    Windows PowerShell transcript start
    Start time: 20200323065600
    Username: computerName\Gerry
    RunAs User: computerName\Gerry
    Configuration Name: 
    Machine: computerName (Microsoft Windows NT 10.0.18362.0)
    Host Application: PowerShell.exe -noexit -command Set-Location 'C:\scripts'
    Process ID: 2916
    PSVersion: 5.1.18362.628
    PSEdition: Desktop
    PSCompatibleVersions: 1.0, 2.0, 3.0, 4.0, 5.0, 5.1.18362.628
    BuildVersion: 10.0.18362.628
    CLRVersion: 4.0.30319.42000
    WSManStackVersion: 3.0
    PSRemotingProtocolVersion: 2.3
    SerializationVersion: 1.1.0.1
    **********************
    Transcript started, output file is C:\scripts\PSLogs\2020-03-23-Test2.log
    VERBOSE: 2020-03-23 06:56:00 AM: hello
    VERBOSE: 2020-03-23 06:56:00 AM: Function completed on computerName
    VERBOSE: 2020-03-23 06:56:00 AM: ####################</Function>####################
    **********************
    Windows PowerShell transcript end
    End time: 20200323065600
    **********************
    **********************
    Windows PowerShell transcript start
    Start time: 20200323065603
    Username: computerName\Gerry
    RunAs User: computerName\Gerry
    Configuration Name: 
    Machine: computerName (Microsoft Windows NT 10.0.18362.0)
    Host Application: PowerShell.exe -noexit -command Set-Location 'C:\scripts'
    Process ID: 2916
    PSVersion: 5.1.18362.628
    PSEdition: Desktop
    PSCompatibleVersions: 1.0, 2.0, 3.0, 4.0, 5.0, 5.1.18362.628
    BuildVersion: 10.0.18362.628
    CLRVersion: 4.0.30319.42000
    WSManStackVersion: 3.0
    PSRemotingProtocolVersion: 2.3
    SerializationVersion: 1.1.0.1
    **********************
    Transcript started, output file is C:\scripts\PSLogs\2020-03-23-Test2.log
    VERBOSE: 2020-03-23 06:56:03 AM: hello
    VERBOSE: 2020-03-23 06:56:03 AM: Function completed on computerName
    VERBOSE: 2020-03-23 06:56:03 AM: ####################</Function>####################
    **********************
    Windows PowerShell transcript end
    End time: 20200323065603
    **********************
    
    • … And makes it look like this:
    1
    2
    3
    4
    5
    6
    7
    8
    9
    10
    11
    12
    
    2020-03-23 09:33:41 AM: ##########<Start Function>##########
    2020-03-23 09:33:41 AM: Function started on computerName
    2020-03-23 09:33:41 AM: hello
    2020-03-23 09:33:41 AM: hello
    2020-03-23 09:33:41 AM: Function completed on computerName
    2020-03-23 09:33:41 AM: ###########<End Function>###########
    2020-03-23 09:34:00 AM: ##########<Start Function>##########
    2020-03-23 09:34:00 AM: Function started on computerName
    2020-03-23 09:34:00 AM: hello
    2020-03-23 09:34:00 AM: hello
    2020-03-23 09:34:00 AM: Function completed on computerName
    2020-03-23 09:34:00 AM: ###########<End Function>###########
    
    • I’m wondering if this is the basis for the -UseMinimalHeader switch in PS7? O_o
  4. You could skip most of this logging non sense if you wish and use the redirect method:

    1
    
    Powershell.Exe -Noprofile -File Test.Ps1 > Test.Log
    
    • This has been tested to record Write-Error, Write-Warning, and just about any other console output PS spits out.

-----------------------------------------------------------
Spotted a mistake in this article? Why not suggest an edit!
Did you like the article? Donations are always welcome!
-----------------------------------------------------------

Comments