Search code examples
powershelljobs

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.


Solution

  • 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