Learn PowerShell - Logging & Debugging

#Introduction

In episode 22 you learned to write scripts that are clean, fast, secure, and documented. But there's one quality that separates amateur scripts from production-grade ones: the trail. A script that runs at 02:00 and fails silently without a record is a nightmare — you'll never know what happened, when, or on which line.

Imagine a script as an airplane's autopilot. A good autopilot doesn't just fly — it records every decision in the flight recorder, and the plane has instrumentation allowing the pilot to check status at any time. This episode equips your scripts with that flight recorder and instrumentation: output streams for tiered messages, permanent log files, a debugger to peek at execution line by line, transcripts to record entire sessions, and profiling tools to measure performance.

#Understanding Output Streams

PowerShell separates output into streams based on their level of importance. Five cmdlets you must memorize:

Write-Verbose "Mulai backup database"
Write-Debug "Nilai variabel: $server"
Write-Information "Langkah 1 dari 3 selesai"
Write-Warning "Disk hampir penuh: 92 persen terpakai"
Write-Error "Backup gagal: koneksi database terputus"

The most important point: Write-Verbose and Write-Debug don't appear by default. Users see a clean script; details appear only when requested:

# Per script (parameter)
.\backup.ps1 -Verbose
 
# For the running session
$VerbosePreference = "Continue"
$DebugPreference = "Continue"

$VerbosePreference and $DebugPreference are preference variables that control whether those streams are shown, hidden, or stopped. Adding Write-Verbose at every important step is almost free — so do it from the start, don't regret it on the first day of debugging.

#Log Files

#A Simple Log Function

Verbose streams disappear when the script finishes — log files don't. For a permanent trail, write to a file. This small function unifies all streams into one file with timestamps:

function Write-Log {
    param(
        [Parameter(Mandatory)]
        [string]$Message,
        [string]$Level = "INFO",
        [string]$LogPath = "C:\Logs\app.log"
    )
    $line = "{0} [{1}] {2}" -f (Get-Date -Format "yyyy-MM-dd HH:mm:ss"), $Level, $Message
    Add-Content -Path $LogPath -Value $line -Encoding UTF8
}
 
Write-Log "Backup dimulai" -Level "INFO"
Write-Log "Backup gagal: disk penuh" -Level "ERROR"

Every log line has three parts: time, level, message. This pattern makes searching easy with Select-String and lets external tooling (such as SIEM or log aggregators) parse it. Replace Write-Output calls in production scripts with Write-Log, and you have a permanent audit trail.

#Debugging with Breakpoints

#Set-PSBreakpoint

When logs aren't enough and you need to watch execution run, PowerShell has a built-in debugger. Set-PSBreakpoint marks stop points — at a specific line, when a variable changes, or when a function is called:

Set-PSBreakpoint -Script "C:\Scripts\backup.ps1" -Line 12
Set-PSBreakpoint -Script "C:\Scripts\backup.ps1" -Variable "server"
 
Get-PSBreakpoint
Remove-PSBreakpoint -Id 1

Once breakpoints are set, run the script. Execution stops exactly at the marked line, and the console switches to debugger mode.

#Stepping and Inspecting Variables

Inside the debugger, you control execution with short commands:

c          # continue - run until the next breakpoint
s          # step into - enter the function being called
o          # step over - finish this line without going into details
q          # quit - stop debugging
$server    # type a variable name to see its value

The commands s (step into), o (step over), c (continue), and q (quit) are the four basic debugging moves, the same across almost every language. When the script stops at a breakpoint, type any variable name to see its current value — this is the most direct way to find why logic goes astray.

#Debugging in VS Code

The terminal works, but VS Code gives far more comfortable debugging: click points, a variables panel, and watch. You only need the PowerShell extension from Microsoft.

#launch.json and Breakpoints

Create a launch.json file in the .vscode folder for debug configuration:

{
  "version": "0.2.0",
  "configurations": [
    {
      "name": "PowerShell: Jalankan Skrip",
      "type": "PowerShell",
      "request": "launch",
      "script": "${file}",
      "args": [],
      "cwd": "${workspaceFolder}"
    }
  ]
}

To set a breakpoint, click to the left of the line number — a red dot appears, and execution will stop there. Press F5 to start debugging.

#Debug Console and Watch

When execution stops, the bottom panel becomes the Debug Console — you can run any command mid-execution, inspect variables, and even call functions. The Watch panel shows variables you add to the watch list and updates their values at every breakpoint. This is VS Code's advantage: the script's state is visible visually, not through text scattered across the console.

#Transcripts

To record an entire session — what was typed and what was output — use transcripts:

Start-Transcript -Path "C:\Logs\session_$(Get-Date -Format 'yyyyMMdd').log"
 
# run the work that needs recording
Get-ADUser -Filter "Enabled -eq 'true'"
Get-HotFix | Select-Object -First 5
 
Stop-Transcript

Start-Transcript starts recording; Stop-Transcript stops it. Everything that happens in between is saved to the file. Transcripts are useful for audit documentation or reproducing troubleshooting sessions — but remember, they record everything, including sensitive input.

#Profiling

A script that works isn't necessarily a fast script. Three profiling tools you should master:

#Measure-Command

Measure-Command runs a script block and measures its duration — the fastest way to compare two approaches:

$elapsed = Measure-Command { Get-ADUser -Filter * }
Write-Output "Fetching all users: $($elapsed.TotalSeconds) seconds"

#Stopwatch

Measure-Command hides the normal output of commands inside it. When you need step-by-step measurement within one script, use the .NET Stopwatch:

$stopwatch = [System.Diagnostics.Stopwatch]::StartNew()
 
Start-Sleep -Seconds 2
$stopwatch.Stop()
Write-Output "Stage 1: $($stopwatch.Elapsed.TotalMilliseconds) ms"
 
$stopwatch.Restart()
Start-Sleep -Seconds 1
$stopwatch.Stop()
Write-Output "Stage 2: $($stopwatch.Elapsed.TotalMilliseconds) ms"

#Performance Counters

To see machine conditions while a script runs — for example measuring a script's CPU impact — use Get-Counter:

Get-Counter -Counter "\Processor(_Total)\% Processor Time" -SampleInterval 1 -MaxSamples 5

The output shows CPU usage percentage over 5 samples spaced 1 second apart. The combination of Measure-Command, Stopwatch, and Get-Counter answers profiling's three questions: how long, how much per stage, and how much it costs the machine.

#Conclusion

In this episode 23 you've equipped your scripts with complete instrumentation: tiered output streams (Write-Verbose, Write-Debug, Write-Information, Write-Warning, Write-Error) with the $VerbosePreference and $DebugPreference preference variables; permanent log files via a Write-Log function; debugging with Set-PSBreakpoint, stepping (s, o, c, q), and variable inspection; visual debugging in VS Code with launch.json, breakpoints, Debug Console, and Watch; session transcripts with Start-Transcript and Stop-Transcript; and profiling with Measure-Command, Stopwatch, and Get-Counter.

Key takeaways:

• Add Write-Verbose at every important step — cheap now, saves debugging later.
• Log files with the time-level-message format are a permanent audit trail.
• Breakpoints and stepping turn "guesswork" into direct observation.
• Measure before and after optimization; don't optimize on gut feeling.

Your scripts can now explain themselves. But there's one equally important follow-up question: how do you prove a script is correct, not just believe it? In the next episode, episode 24, we'll cover Testing with Pester: writing unit tests for PowerShell functions, running tests automatically, and making tests the safety net before scripts touch production. See you there!