Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Powershell: get output from Receive-Job

I have a collection of jobs that are running. When they complete I use receive-job and it writes the output to the screen. I'd like to take that output and log it to a file. I don't want to tee the output produced while the jobs are running because with multiple jobs running at once the logging would be interspersed. Get-Job | Receive-Job prints the output in a nice organized manner.

I have tried all of the following and no output is written to the file or stored in a variable, it just goes to the screen:

#Wait for last job to complete
While (Get-Job -State "Running") {    
    Log "Running..." -v $info
    Start-Sleep 10        
}    
Log ("Jobs Completed. Output:") -v $info

# Getting the information back from the jobs
foreach($job in Get-Job){
    Receive-Job -Job $job | Out-File c:\Test.log -Append
    $output = Receive-Job -Job $job        
    Log ("OUTPUT: "+$output)
    Receive-Job -Job $job -OutVariable $foo
    Log ("FOO: "+$foo)
}

EDIT: I have removed the extra Receive-Job calls in the foreach to the following after seeing Keith's comment:

# Getting the information back from the jobs
foreach($job in Get-Job){
    Receive-Job -Job $job -OutVariable temp
    Write-Host ("Temp: "+$temp)
    $temp | Out-File -FilePath c:\Test.log -Append 
}

I also verified I'm not using Receive-Job anywhere else in the script. The write-host $temp and the out-file still produce no output though.

like image 386
Justin Holbrook Avatar asked Aug 15 '12 17:08

Justin Holbrook


4 Answers

If the job uses Write-Host to produce output, Receive-Job returns $null, but the results get written to the host. However, if the job uses Write-Output to produce output in lieu of Write-Host, Receive-Job returns a string array [string[]] of the job output.

To demonstrate, enter this innocuous code at the PowerShell prompt:

$job = Start-Job -ScriptBlock {
    [int] $counter = 0
    while ($counter -lt 10) {
        Write-Output "Counter = $counter."
        Start-Sleep -Seconds 5
        $counter++
    }
}

Wait about 20-30 seconds for the job to produce some output, then enter this code:

$result = Receive-Job -Job $job
$result.Count
$result
$result | Get-Member

The $result object contains the strings produced by the job.

like image 194
doer Avatar answered Nov 16 '22 04:11

doer


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
like image 45
Justin Holbrook Avatar answered Nov 16 '22 06:11

Justin Holbrook


I found soulution how to receive Write-Host results to variable with Receive-Job CMDlet, it's working on Powershell 5.1:

$var = Receive-Job $job 6>&1
like image 10
SpongeBob the codder Avatar answered Nov 16 '22 05:11

SpongeBob the codder


I know this is old. I don't use jobs very often so I was obviously having the same problem when I stumbled on this thread. Anyway, I arrived at a different solution so I thought I'd throw it out there.

Also in PowerShell 5.1 I simply referenced the properties on the Job Object(s) In my case this looked like:

$Jobs.ChildJobs.Output | Out-File <LogFile> -Append

It looks like all the streams are recorded in this way. Simple echoes go to the Output, presumable the success stream. Write-Host commands go to Information Stream.

Output        : {}
Error         : {}
Progress      : {}
Verbose       : {}
Debug         : {}
Warning       : {}
Information   : {}
like image 5
Steven Avatar answered Nov 16 '22 04:11

Steven