NOTE: After some experimentation I have found that using write-output or just outputting a variable directly is not a good solution either. If you have a function that uses either of those methods and also returns a value the output will be concatenated with the return value!
The best way I have found to log output from jobs is to use write-host in combination with the Start-Transcript and Stop-Transcript cmdlets. There are some disadvantages such as the ISE does not support Transcript cmdlets. Also I haven't found a way to output to the transcript without it going to the host (I wanted a robust log with a less verbose user experience), but it seems to be the best solution available currently. It is the only way I've been able to log concurrent jobs without interspersing the output without having to right multiple temporary log files for each job and then combining them.
Below was my previous answer that I left just for documentation reasons:
The issue here was not getting output from Receive-Job. The output from the jobs I was expecting to see is being written in the job by write-host. When receive-job was called I saw all my output on the screen, but nothing was available to pipe elsewhere. It seems when I call receive-job all those write-host cmdlets execute, but there's nothing for me to pick up and pipe to out-file. The following script demonstrates this. You'll notice "Sleepy Time" appears in both the log file and the host, while "Slept" only appears in the host. So, rather than trying to pipe Receive-Job to write-host, I need to modify my Log function to not use write-host or to split the output as shown below.
cls
rm c:\jobs.log
$foo = @(1,2,3)
$jobs = @()
foreach($num in $foo){
$s = { get-process -name "explorer"
Start-Sleep $args[0]
$x = ("Sleepy Time: "+$args[0])
write-host $x
$x
write-host ("Slept: "+$args[0])
}
$id = [System.Guid]::NewGuid()
$jobs += $id
Start-Job -Name $id -ScriptBlock $s -args $num
}
While (Get-Job -State "Running") {
cls
Get-Job
Start-Sleep 1
}
cls
Get-Job
write-host "Jobs completed, getting output"
foreach($job in $jobs){
Receive-Job -Name $job | out-file c:/jobs.log -append
}
Remove-Job *
notepad c:\jobs.log
Below is a sample that will run concurrent jobs and then log them sequentially as per mbourgon's request. You'll notice the timestamps indicate the work was interspersed, but the logging is displayed sequentially by job.
#This is an example of logging concurrent jobs sequentially
#It must be run from the powershell prompt as ISE does not support transcripts
cls
$logPath = "c:\jobs.log"
rm $logPath
Start-Transcript -Path $logPath -Append
#Define some stuff
$foo = @(0,1,2)
$bar = @(@(1,"AAA"),@(2,"BBB"),@(3,"CCC"))
$func = {
function DoWork1 {
Log "This is DoWork1"
return 0
}
function DoWork2 {
Log "This is DoWork2"
return 0
}
function Log {
Param([parameter(ValueFromPipeline=$true)]$InputObject)
$nl = [Environment]::NewLine.Chars(0)
$time = Get-Date -Format {HH:mm:ss}
Write-Host ($time+">"+$InputObject+$nl)
}
}
#Start here
foreach($num in $foo){
$s = { $num = $args[0]
$bar = $args[1]
$logPath = $args[2]
Log ("Num: "+$num)
for($i=0; $i -lt 5; $i++){
$out = ([string]::$i+$bar[$num][1])
Log $out
start-sleep 1
}
Start-Sleep $num
$x = DoWork1
Log ("The value of x is: "+$x)
$y = DoWork2
Log ("The value of y is: "+$y)
}
Start-Job -InitializationScript $func -ScriptBlock $s -args $num, $bar, $logPath
}
While (Get-Job -State "Running") {
cls
Get-Job
Start-Sleep 1
}
cls
Get-Job
write-host "Jobs completed, getting output"
Get-Job | Receive-Job
Remove-Job *
Stop-Transcript
notepad $logPath
