Methods to write logs using PowerShell (Recording and Auditing all the important actions in the script)
In this article we will learn how to enable logging for PowerShell script. There are many different ways to record the actions in PowerShell and below are the few familiar one
- PowerShell Transcripts
- Custom Logging to a file
- Write-Verbose
- Write-Error
- Write-Information
- Write-Debug
- Write-Warning
Here I will be discussing only PowerShell Transcripts, Custom logging and advanced logging (Microsoft trace model) which are commonly used everywhere.
1 – PowerShell Transcript
A PowerShell transcript is a file that contains all the PowerShell cmdlet history and it’s output. It’s one of the familiar way of recording all the actions performed through the script. Below are the few example to understand how to enable the PowerShell transcript
You can just type Start-Transcript from the PowerShell console to enable the logs. From the below screen you can see a .TXT file is automatically created under the documents folder and started recording the PowerShell console.
PS C:\> Start-Transcript Transcript started, output file is C:\Users\Vivek\Documents\PowerShell_transcript.INBLRWIT7Y78533.ysZvn4Py.20220130114311.txt PS C:\>
I’ve typed a ping command in the next line and you can see all the command history and output will be saved under the .TXT file automatically.
PS C:\> Ping 127.0.0.1
Pinging 127.0.0.1 with 32 bytes of data:
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Ping statistics for 127.0.0.1:
Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 0ms, Maximum = 0ms, Average = 0ms
PS C:\>
Below is the content inside the .TXT file. You can see all the PowerShell cmdlet and output is captured in the text file. By default, it captures some header information along with the cmdlet information and output that are really useful to understand about the script execution.
Stop-Transcript is the cmdlet to stop the transcript. Transcript will continue recording all the cmdlet history and output until you stop transcription or close the PowerShell session
PS C:\Users\vivek\Documents> Get-Content .\PowerShell_transcript.INBLRWIT7Y78533.ysZvn4Py.20220130114311.txt
**********************
Windows PowerShell transcript start
Start time: 20220130114311
Username: VRR\vivek
RunAs User: VRR\vivek
Configuration Name:
Machine: ABCD533 (Microsoft Windows NT 10.0.19042.0)
Host Application: C:\WINDOWS\System32\WindowsPowerShell\v1.0\powershell.exe -NoProfile -NonInteractive -ExecutionPolicy Bypass -Command Import-Module 'c:\Users\VIvek\.vscode\extensions\ms-vscode.powershell-2021.12.0\modules\PowerShellEditorServices\PowerShellEditorServices.psd1'; Start-EditorServices -HostName 'Visual Studio Code Host' -HostProfileId 'Microsoft.VSCode' -HostVersion '2021.12.0' -AdditionalModules @('PowerShellEditorServices.VSCode') -BundledModulesPath 'c:\Users\Vivek\.vscode\extensions\ms-vscode.powershell-2021.12.0\modules' -EnableConsoleRepl -StartupBanner '=====> PowerShell Integrated Console v2021.12.0 <=====
' -LogLevel 'Normal' -LogPath 'c:\Users\a391132\.vscode\extensions\ms-vscode.powershell-2021.12.0\logs\1643476716-687e3cba-942e-47fb-a7ed-a1b4a78546e61643476713433\EditorServices.log' -SessionDetailsPath 'c:\Users\a391132\.vscode\extensions\ms-vscode.powershell-2021.12.0\sessions\PSES-VSCode-18308-130677' -FeatureFlags @()
Process ID: 11420
PSVersion: 5.1.19041.1320
PSEdition: Desktop
PSCompatibleVersions: 1.0, 2.0, 3.0, 4.0, 5.0, 5.1.19041.1320
BuildVersion: 10.0.19041.1320
CLRVersion: 4.0.30319.42000
WSManStackVersion: 3.0
PSRemotingProtocolVersion: 2.3
SerializationVersion: 1.1.0.1
**********************
Transcript started, output file is C:\Users\Vivek\Documents\PowerShell_transcript.INBLRWIT7Y78533.ysZvn4Py.20220130114311.txt
PS>@{ 'computerName' = if ([Environment]::MachineName) {[Environment]::MachineName} else {'localhost'}; 'processId' = $PID; 'instanceId' = $host.InstanceId }
Name Value
---- -----
processId 11420
computerName ABCD533
instanceId 804d0602-0c3b-4a7d-af5d-9b412a6b8ad3
PS C:\> Ping 127.0.0.1
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Reply from 127.0.0.1: bytes=32 time<1ms TTL=128
Ping statistics for 127.0.0.1:
Packets: Sent = 4, Received = 4, Lost = 0 (0% loss),
Approximate round trip times in milli-seconds:
Minimum = 0ms, Maximum = 0ms, Average = 0ms
You can also provide the custom log file location with .LOG extension to capture the transcript.
$logFile = "C:\temp\Logs.log" Start-Transcript $logFile
If you are looking for a perfect solution for logging PowerShell transcript is not a best option as it capture each and every line items in your script and it’s output as per the above example , also transcript logging is not in a structured format to read.
2 – Custom Logging (Logging to a File)
We will write a function here and simply add the string and create a custom log file.
Write-log is the function here and we should define a log file with it’s path ($LogFile = “C:\temp\TestConnection.log“)
Function Write-Log {
Param(
[Parameter(Mandatory=$True)]
[String]$Text
)
$LogFile = "C:\temp\TestConnection.log"
[String]$LogMessage = [System.String]:: Format("[$(Get-date)] -"),$Text
Add-Content -Path $LogFile -Value $LogMessage
}
From the below script you can understand how to use the function in the script and write the logs – You can also see logs write date.
$Computers = "Localhost","ABCD123"
Write-Log "Checking device availability"
$Computers | % { If(Test-Connection -ComputerName $_)
{
Write-Log "Device $_ is online"
}
else
{
Write-Log "Device $_ is Offline"
}
}
Function Write-Log {
Param(
[Parameter(Mandatory=$True)]
[String]$Text
)
$LogFile = "C:\temp\TestConnection.log"
[String]$LogMessage = [System.String]:: Format("[$(Get-date)] -"),$Text
Add-Content -Path $LogFile -Value $LogMessage
}
Below is the log file after the script execution.
2 – Advanced logging – Microsoft trace format
Below is the advanced command which is very similar to the Microsoft trace log format. This logs contains the message, message severity and the component type.
You can set the severity for the message and it will reflect in the log file.
Function Write-Log
{
Param
(
[String]$Message,
[String]$Path = $File_Log_Path,
[int]$severity,
[string]$component
)
$TimeZoneBias = Get-WmiObject -query "SELECT Bias FROM Win32_TimeZone"
$Date= Get-Date -Format "HH:mm:ss.fff"
$Date2= Get-Date -Format "MM-dd-yyyy"
$type=1
"<![LOG[$Message]LOG]!><time=$([char]34)$date+$($TimeZoneBias.bias)$([char]34) date=$([char]34)$date2$([char]34) component=$([char]34)$component$([char]34) context=$([char]34)$([char]34) type=$([char]34)$severity$([char]34) thread=$([char]34)$([char]34) file=$([char]34)$([char]34)>"| Out-File -FilePath $Path -Append -NoClobber -Encoding default
}
From the below script you can understand how to use the log function with it’s parameters.
$Computers = "Localhost","ABCD123"
Write-Log -message "Checking device availability" -severity 1 -component "Information"
$File_Log_Path = "C:\temp\TestConnection.log"
$Computers | % { If(Test-Connection -ComputerName $_)
{
Write-Log -Message "Device $_ is online" -severity 2 -component "Device Availability Check"
}
else
{
Write-Log -message "Device $_ is Offline" -severity 3 -component "Device Availability Check"
}
}
Function Write-Log
{
Param
(
[String]$Message,
[String]$Path = $File_Log_Path,
[int]$severity,
[string]$component
)
$TimeZoneBias = Get-WmiObject -query "SELECT Bias FROM Win32_TimeZone"
$Date= Get-Date -Format "HH:mm:ss.fff"
$Date2= Get-Date -Format "MM-dd-yyyy"
$type=1
"<![LOG[$Message]LOG]!><time=$([char]34)$date+$($TimeZoneBias.bias)$([char]34) date=$([char]34)$date2$([char]34) component=$([char]34)$component$([char]34) context=$([char]34)$([char]34) type=$([char]34)$severity$([char]34) thread=$([char]34)$([char]34) file=$([char]34)$([char]34)>"| Out-File -FilePath $Path -Append -NoClobber -Encoding default
}
Below is the Log files generated from the script. You can see the line items are with colors based on the severity we set for the logs. Also please note the component and Date/Time
Thanks for reading.
