Debugging Guide
This comprehensive guide covers debugging techniques for psake build scripts, from basic output inspection to advanced PowerShell debugging.
Quick Debugging Checklist
When your build fails or behaves unexpectedly:
- Enable verbose output:
Invoke-psake -Verbose - Check task execution order:
Invoke-psake -docs -detaileddocs - Verify properties: Add
Write-Hoststatements in your Properties block - Test individual tasks: Run tasks one at a time
- Check external command output: Use
execwith verbose flag - Use the PowerShell debugger: Set breakpoints for complex issues
Verbose Output
Basic Verbose Mode
The simplest debugging approach is enabling verbose output:
# Enable verbose output
Invoke-psake -buildFile .\psakefile.ps1 -Verbose
# Combine with specific task
Invoke-psake -taskList Build -Verbose
# Also enable debug output
Invoke-psake -Verbose -Debug
This shows:
- Task execution order
- Dependency resolution
- Property values
- Detailed execution flow
Adding Custom Verbose Messages
Properties {
$Configuration = 'Release'
$BuildDir = Join-Path $PSScriptRoot 'build'
Write-Verbose "Properties initialized:"
Write-Verbose " Configuration: $Configuration"
Write-Verbose " BuildDir: $BuildDir"
}
Task Build {
Write-Verbose "Starting build process"
Write-Verbose "Current directory: $PWD"
exec { dotnet build } -Verbose
Write-Verbose "Build completed successfully"
}
Controlling Output Levels
Properties {
$VerbosePreference = 'Continue' # Always show verbose
# Or: 'SilentlyContinue' to hide verbose
}
Task Build {
# This will show even without -Verbose flag
Write-Verbose "This is verbose output"
# Different output levels
Write-Debug "Debug level information"
Write-Information "Informational message"
Write-Warning "Warning message"
Write-Host "Always visible output"
}
Using PowerShell Debugger
Setting Breakpoints
Method 1: Line breakpoints
# Before running psake
Set-PSBreakpoint -Script .\psakefile.ps1 -Line 25
# Run psake (will pause at line 25)
Invoke-psake
# At the breakpoint:
# - Inspect variables: $Configuration, $BuildDir, etc.
# - Step through: s (step into), v (step over), o (step out)
# - Continue: c
# - Quit debugging: q
Method 2: Function/Task breakpoints
# Break when a specific task runs
Set-PSBreakpoint -Script .\psakefile.ps1 -Command Build
# Run psake
Invoke-psake -taskList Build
Method 3: Variable breakpoints
# Break when a variable is read or written
Set-PSBreakpoint -Variable Configuration -Mode ReadWrite -Script .\psakefile.ps1
Invoke-psake
Method 4: Inline breakpoint
Add directly in your psakefile.ps1:
Task Build {
# Execution will pause here
Wait-Debugger
# Or use the older method
Set-PSBreakpoint -Script $PSCommandPath -Line $MyInvocation.ScriptLineNumber
exec { dotnet build }
}
Debugger Commands
When paused at a breakpoint:
# Inspect variables
$Configuration
$BuildDir
Get-Variable
# Evaluate expressions
Test-Path $BuildDir
$PSScriptRoot
# List local variables
Get-Variable -Scope Local
# View call stack
Get-PSCallStack
# Step commands
s # Step into
v # Step over (or 'o' in older versions)
o # Step out
c # Continue execution
q # Quit debugger
# List breakpoints
Get-PSBreakpoint
# Remove breakpoints
Get-PSBreakpoint | Remove-PSBreakpoint
Debugging in VS Code
If using Visual Studio Code with PowerShell extension:
- Open your psakefile.ps1 in VS Code
- Click in the gutter to set breakpoints (red dots)
- Press F5 or use "Run and Debug"
- Add launch configuration in
.vscode/launch.json:
{
"version": "0.2.0",
"configurations": [
{
"name": "Debug psake Build",
"type": "PowerShell",
"request": "launch",
"script": "${workspaceFolder}/psakefile.ps1",
"args": [],
"cwd": "${workspaceFolder}"
}
]
}
Or debug the Invoke-psake call:
{
"name": "Debug psake",
"type": "PowerShell",
"request": "launch",
"script": "Invoke-psake",
"args": [
"-buildFile", "${workspaceFolder}/psakefile.ps1",
"-taskList", "Build"
]
}
Inspecting Task Execution
View Task Documentation
# List all tasks with descriptions
Invoke-psake -docs
# Detailed documentation with dependencies
Invoke-psake -detaileddocs
Example output:
Name Depends On
---- ----------
Build Clean, Restore
Test Build
Package Test
Deploy Package
Understanding Task Execution Order
# Add task execution logging
FormatTaskName {
param($taskName)
Write-Host "======================================" -ForegroundColor Cyan
Write-Host "Executing Task: $taskName" -ForegroundColor Cyan
Write-Host "======================================" -ForegroundColor Cyan
}
Task Build -depends Clean, Restore {
Write-Host "Build task running"
}
Tracing Task Dependencies
# Create a helper to trace execution
Properties {
$script:ExecutionTrace = @()
}
FormatTaskName {
param($taskName)
$script:ExecutionTrace += @{
Task = $taskName
Timestamp = Get-Date
}
Write-Host "[$(Get-Date -Format 'HH:mm:ss')] Starting: $taskName" -ForegroundColor Green
}
Task Build -depends Test {
# Build logic
}
Task Cleanup {
# Show execution trace at the end
Write-Host "`nExecution Trace:" -ForegroundColor Yellow
$script:ExecutionTrace | ForEach-Object {
Write-Host " $($_.Timestamp.ToString('HH:mm:ss.fff')) - $($_.Task)"
}
}
Testing Task Dependencies Individually
# Test each task independently
Invoke-psake -taskList Clean
Invoke-psake -taskList Restore
Invoke-psake -taskList Build
# This helps identify which task is failing
Logging Strategies
Basic File Logging
Properties {
$LogFile = Join-Path $PSScriptRoot 'build.log'
# Initialize log file
"Build started at $(Get-Date)" | Set-Content $LogFile
}
function Write-BuildLog {
param([string]$Message)
$timestamp = Get-Date -Format 'yyyy-MM-dd HH:mm:ss'
$logMessage = "[$timestamp] $Message"
# Write to console and file
Write-Host $logMessage
$logMessage | Add-Content $script:LogFile
}
Task Build {
Write-BuildLog "Starting build for configuration: $Configuration"
try {
exec { dotnet build }
Write-BuildLog "Build succeeded"
} catch {
Write-BuildLog "Build failed: $_"
throw
}
}
Structured Logging
Properties {
$LogFile = Join-Path $PSScriptRoot 'build.json'
$script:BuildLog = @{
StartTime = Get-Date
Tasks = @()
Properties = @{
Configuration = $Configuration
BuildNumber = $BuildNumber
}
}
}
function Add-TaskLog {
param(
[string]$TaskName,
[string]$Status,
[string]$Message = '',
[timespan]$Duration
)
$script:BuildLog.Tasks += @{
Task = $TaskName
Status = $Status
Message = $Message
Duration = $Duration.TotalSeconds
Timestamp = Get-Date
}
}
FormatTaskName {
param($taskName)
$script:CurrentTaskStart = Get-Date
$script:CurrentTaskName = $taskName
}
Task Build {
$taskStart = Get-Date
try {
exec { dotnet build }
$duration = (Get-Date) - $taskStart
Add-TaskLog -TaskName 'Build' -Status 'Success' -Duration $duration
} catch {
$duration = (Get-Date) - $taskStart
Add-TaskLog -TaskName 'Build' -Status 'Failed' -Message $_.Exception.Message -Duration $duration
throw
}
}
Task Cleanup {
# Save log to file
$script:BuildLog.EndTime = Get-Date
$script:BuildLog.Duration = ($script:BuildLog.EndTime - $script:BuildLog.StartTime).TotalSeconds
$script:BuildLog | ConvertTo-Json -Depth 10 | Set-Content $LogFile
Write-Host "Build log saved to: $LogFile"
}
Logging External Command Output
Task Build {
$logFile = Join-Path $PSScriptRoot 'build-output.log'
# Capture and log command output
$output = exec { dotnet build } -PassThru
$output | Set-Content $logFile
# Or redirect output
exec { dotnet build 2>&1 | Tee-Object -FilePath $logFile }
}
Integration with Logging Frameworks
# Using PSFramework (install: Install-Module PSFramework)
Import-Module PSFramework
Properties {
# Configure logging
Set-PSFLoggingProvider -Name logfile -FilePath './logs/build.log' -Enabled $true
}
Task Build {
Write-PSFMessage -Level Important "Starting build"
try {
exec { dotnet build }
Write-PSFMessage -Level Significant "Build completed successfully"
} catch {
Write-PSFMessage -Level Error "Build failed" -ErrorRecord $_
throw
}
}
Debugging External Commands
Using exec with Verbose Output
Task Build {
# Show command being executed
exec { dotnet build } -Verbose
# Or manually log it
$cmd = 'dotnet build'
Write-Host "Executing: $cmd" -ForegroundColor Yellow
exec { & $cmd }
}
Capturing Exit Codes
Task Build {
# exec will throw on non-zero exit code
try {
exec { dotnet build }
} catch {
Write-Host "Command failed with exit code: $LASTEXITCODE"
Write-Host "Error: $_"
throw
}
}
Debugging Command Failures
Task Build {
# Run command with error handling
$ErrorActionPreference = 'Continue'
$output = dotnet build 2>&1
if ($LASTEXITCODE -ne 0) {
Write-Host "Build failed with exit code: $LASTEXITCODE" -ForegroundColor Red
Write-Host "Output:" -ForegroundColor Red
$output | ForEach-Object { Write-Host $_ -ForegroundColor Red }
# Optionally save to file for analysis
$output | Set-Content './build-error.log'
throw "Build failed. See build-error.log for details."
}
}
Testing Commands Interactively
Task Build {
# Use -WhatIf pattern for dry runs
if ($WhatIfPreference) {
Write-Host "Would execute: dotnet build -c $Configuration"
return
}
exec { dotnet build -c $Configuration }
}
# Invoke with:
# Invoke-psake -WhatIf
Common Debugging Scenarios
Scenario 1: Task Not Running as Expected
Problem: A task doesn't execute or executes in wrong order.
Debug steps:
# 1. Check if task exists
Invoke-psake -docs
# 2. View task dependencies
Invoke-psake -detaileddocs
# 3. Add execution tracing
FormatTaskName {
param($taskName)
Write-Host ">>> Executing: $taskName at $(Get-Date -Format 'HH:mm:ss.fff')"
}
# 4. Check preconditions
Task Build -precondition { $Configuration -eq 'Release' } {
Write-Host "Precondition passed: Configuration = $Configuration"
# Task logic
}
Scenario 2: Properties Have Unexpected Values
Problem: Properties don't have the values you expect.
Debug steps:
Properties {
$Configuration = 'Debug'
$BuildNumber = $env:BUILD_NUMBER ?? '0'
# Debug output
Write-Host "=== Property Values ===" -ForegroundColor Cyan
Get-Variable -Scope Script | Where-Object {
$_.Name -in @('Configuration', 'BuildNumber')
} | ForEach-Object {
Write-Host "$($_.Name) = $($_.Value)"
}
}
# Or create a debug task
Task ShowProperties {
Write-Host "Configuration: $Configuration"
Write-Host "BuildNumber: $BuildNumber"
Write-Host "PSScriptRoot: $PSScriptRoot"
# Show all properties
Get-Variable -Scope Script | Format-Table Name, Value
}
# Run: Invoke-psake -taskList ShowProperties
Scenario 3: Path Issues
Problem: Files or directories not found.
Debug steps:
Task Build {
# Debug paths
Write-Host "Current directory: $PWD"
Write-Host "Script root: $PSScriptRoot"
Write-Host "Build directory: $BuildDir"
# Verify paths exist
@($BuildDir, $SrcDir, $TestDir) | ForEach-Object {
if (Test-Path $_) {
Write-Host "✓ Found: $_" -ForegroundColor Green
} else {
Write-Host "✗ Missing: $_" -ForegroundColor Red
}
}
# List contents
Write-Host "`nContents of $SrcDir:"
Get-ChildItem $SrcDir | ForEach-Object {
Write-Host " $($_.Name)"
}
}
Scenario 4: Dependency Cycle
Problem: Circular dependency error.
Debug steps:
# Use detailed docs to visualize dependencies
Invoke-psake -detaileddocs
# Create a dependency graph
Task ShowDependencies {
$tasks = @{
Build = @('Clean', 'Restore')
Test = @('Build')
Package = @('Test')
Deploy = @('Package')
}
Write-Host "Task Dependency Graph:"
$tasks.GetEnumerator() | ForEach-Object {
Write-Host "$($_.Key) -> $($_.Value -join ', ')"
}
}
Performance Debugging
Measuring Task Execution Time
Properties {
$script:TaskTimings = @{}
}
FormatTaskName {
param($taskName)
$script:CurrentTask = $taskName
$script:TaskTimings[$taskName] = @{
Start = Get-Date
}
Write-Host "[$([Math]::Round(((Get-Date) - $script:BuildStart).TotalSeconds, 2))s] Starting: $taskName"
}
# Override TaskTearDown to capture end time
TaskTearDown {
$end = Get-Date
$start = $script:TaskTimings[$script:CurrentTask].Start
$duration = ($end - $start).TotalSeconds
$script:TaskTimings[$script:CurrentTask].Duration = $duration
Write-Host "[$([Math]::Round(((Get-Date) - $script:BuildStart).TotalSeconds, 2))s] Completed: $script:CurrentTask (took $([Math]::Round($duration, 2))s)"
}
Properties {
$script:BuildStart = Get-Date
}
Task Summary {
Write-Host "`n=== Task Performance ===" -ForegroundColor Yellow
$script:TaskTimings.GetEnumerator() | Sort-Object { $_.Value.Duration } -Descending | ForEach-Object {
$duration = [Math]::Round($_.Value.Duration, 2)
Write-Host "$($_.Key): ${duration}s"
}
$total = [Math]::Round(((Get-Date) - $script:BuildStart).TotalSeconds, 2)
Write-Host "`nTotal build time: ${total}s" -ForegroundColor Green
}
Identifying Slow Operations
function Measure-BuildStep {
param(
[string]$Name,
[scriptblock]$ScriptBlock
)
Write-Host "Starting: $Name..." -NoNewline
$start = Get-Date
try {
& $ScriptBlock
$duration = ((Get-Date) - $start).TotalSeconds
Write-Host " completed in $([Math]::Round($duration, 2))s" -ForegroundColor Green
} catch {
$duration = ((Get-Date) - $start).TotalSeconds
Write-Host " failed after $([Math]::Round($duration, 2))s" -ForegroundColor Red
throw
}
}
Task Build {
Measure-BuildStep "Restore packages" {
exec { dotnet restore }
}
Measure-BuildStep "Compile code" {
exec { dotnet build --no-restore }
}
Measure-BuildStep "Run tests" {
exec { dotnet test --no-build }
}
}
Advanced Debugging Techniques
Remote Debugging
# On remote machine, enable PowerShell remoting
Enable-PSRemoting -Force
# From local machine
$session = New-PSSession -ComputerName remote-server
# Run psake remotely with debugging
Invoke-Command -Session $session -ScriptBlock {
Import-Module psake
Set-PSBreakpoint -Script C:\builds\psakefile.ps1 -Line 50
Invoke-psake -buildFile C:\builds\psakefile.ps1
}
# Enter interactive session for debugging
Enter-PSSession $session
Debugging in CI/CD
# Add CI-specific debugging
Properties {
$IsCI = $env:CI -eq 'true'
}
Task Build {
if ($IsCI) {
# More verbose output in CI
$VerbosePreference = 'Continue'
$DebugPreference = 'Continue'
# Dump environment
Write-Host "=== Environment Variables ==="
Get-ChildItem env: | Sort-Object Name | ForEach-Object {
Write-Host "$($_.Name) = $($_.Value)"
}
}
exec { dotnet build } -Verbose:$IsCI
}
Creating Debug Snapshots
Task CreateDebugSnapshot {
$snapshotDir = Join-Path $PSScriptRoot 'debug-snapshot'
New-Item -ItemType Directory -Path $snapshotDir -Force | Out-Null
# Capture environment state
@{
PowerShellVersion = $PSVersionTable
EnvironmentVariables = Get-ChildItem env: | ForEach-Object { @{$_.Name = $_.Value} }
InstalledModules = Get-Module -ListAvailable | Select-Object Name, Version
WorkingDirectory = $PWD
Properties = @{
Configuration = $Configuration
BuildDir = $BuildDir
}
Timestamp = Get-Date
} | ConvertTo-Json -Depth 10 | Set-Content "$snapshotDir/snapshot.json"
# Copy relevant files
Copy-Item .\psakefile.ps1 $snapshotDir
Copy-Item .\*.log $snapshotDir -ErrorAction SilentlyContinue
Write-Host "Debug snapshot saved to: $snapshotDir"
}
See Also
- Common Errors - Solutions to frequent errors
- FAQ - Frequently asked questions
- Debug Script - Basic debugging tutorial
- Logging Errors - Error logging strategies
- Build Script Resilience - Writing robust builds