How do I capture .NET trace output from a Powershell job?

Question

I am using a .NET component in Powershell which uses Trace.TraceWarning, Trace.TraceInformation etc.

I want to output these traces to the console when I run my Powershell script.

This works when I use the component in the current session. For example (simulating the effect of trace) gives me 'Hello' output to the console:

 $listener = new-object "system.diagnostics.consoletracelistener"
 [System.Diagnostics.Trace]::Listeners.Add($listener) | Out-Null
 [System.Diagnostics.Trace]::TraceInformation("Hello")

But if I do the same within a Powershell job I get no output, even though ConsoleTraceListener should be writing to STDOUT which in turn I expected to get captured by the job. (Interestingly Console.WriteLine doesn't work from a job either - but Write-Host does).

I am starting my job like so:

$work = {
     $listener = new-object "system.diagnostics.consoletracelistener"
     [System.Diagnostics.Trace]::Listeners.Add($listener) | Out-Null
     [System.Diagnostics.Trace]::TraceInformation("Hello")
}
$job = Start-Job -RunAs32 -ScriptBlock $work
$job | Receive-Job -Wait

ConsoleTraceListener writes to console, so related: http://serverfault.com/questions/399854/powershell-start-job-output — Caramiriel, Jan 29 '15 at 14:53
ConsoleTraceListener appears to write to stdout http://referencesource.microsoft.com/#System/compmod/system/diagnostics/ConsoleTraceListener.cs,b38622e30a1b1559. But for some reason with jobs it's not being picked up — Jack Ukleja, Jan 29 '15 at 14:58
After some more testing I found some interesting things about jobs and child jobs. I think ultimately the issue is that powershell is not using the System.Console class but a custom System.Management.Automation.Host.PSHost class and redirecting the streams. This doesn't seem to be implemented as expected in certain edge cases like yours though. — StephenP, Feb 04 '15 at 00:34
ConsoleTraceListener just uses STDOUT though. Not sure I see how it's an edgecase! — Jack Ukleja, Feb 04 '15 at 01:06

score 1 · Answer 1 · answered Jan 30 '15 at 03:30

I remember running into something similar to this years ago where expected STDOUT and STDIN weren't behaving as expected with start-job and exe's. I ended up using System.Diagnostics.Process and redirecting the STDIN and STDOUT. Here's an example that demonstrates this workaround in a way that may assist you with what you are trying to do.

#added extra trace messages with Get-Date and implemented a random delay for demo purpose
$work = {
     $listener = new-object "system.diagnostics.consoletracelistener"
     [System.Diagnostics.Trace]::Listeners.Add($listener) | Out-Null
     1..10 | % {
         Start-Sleep $(Get-Random 5)
         [System.Diagnostics.Trace]::TraceInformation((Get-Date))
    }
}
#Create a process
$process = New-Object System.Diagnostics.Process 
$process.StartInfo.UseShellExecute = $false
#redirect stdout
$process.StartInfo.RedirectStandardOutput = $true
#call powershell
$process.StartInfo.FileName = "powershell.exe"
#pass the $work scriptblock
$process.StartInfo.Arguments = "-noprofile -command $work"
#start the process
$process.Start() | Out-Null
#readlines as they come in and exit when process is done
while(-not $process.HasExited){
    $process.StandardOutput.ReadLine()
}

Output:

powershell.exe Information: 0 : 01/30/2015 12:27:17
powershell.exe Information: 0 : 01/30/2015 12:27:20
powershell.exe Information: 0 : 01/30/2015 12:27:21
powershell.exe Information: 0 : 01/30/2015 12:27:25
powershell.exe Information: 0 : 01/30/2015 12:27:26
powershell.exe Information: 0 : 01/30/2015 12:27:28
powershell.exe Information: 0 : 01/30/2015 12:27:29
powershell.exe Information: 0 : 01/30/2015 12:27:33
powershell.exe Information: 0 : 01/30/2015 12:27:36
powershell.exe Information: 0 : 01/30/2015 12:27:40

Thanks for your answer, but I consider Start-Process to be "cheating" ;). I'm trying to work out why it doesnt' work for jobs — Jack Ukleja, Feb 03 '15 at 14:54
@JackUkleja this answer, same as `Start-Process` are your only alternatives for this. The output of `[System.Diagnostics.Trace]::TraceInformation(..)` cannot be captured by any type of redirection `*>&1` same as `[console]::WriteLine(..)` or attempting to capture the output of `-WhatIf`. — Santiago Squarzon, Dec 08 '21 at 20:47

Joel Coehoorn · Answer 2 · 2015-01-29T15:12:19.293

-1

It's not clear where you want the captured output to go. Most of the discussion so far revolves around the Console, but since you called it a "job" (I presume you mean Scheduled Task), I'm not so sure the Console is the best place. You'd never see the results. A log file sounds much more appropriate. If that's the case, you should create a TextWriteTraceLister. That will allow you to set a log file for the results.

Additionally, one of the nice features of Tracing in .Net is that you can have more than one listener attached. So if you want to see the output as it runs, you can also attach the ConsoleTraceListener, and it won't interfere with writing to the log file.

Finally, it's also possible to write your own TraceListener. This is useful for things like writing to a logging database or web service. To use your own TraceListener from PowerShell, you would need to build the listener using a .Net language that can be compiled into a class library assembly (dll) that can be deployed to the GAC for use in your project.

edited Jan 29 '15 at 15:12

answered Jan 29 '15 at 15:06

Joel Coehoorn

399,467
113
570
794

1

It's a powershell job, as in something that is being started with Start-Job. The reason I am using a job btw is because I am needing to load and use a x86 .NET assembly from 64bit powershell. Job provides a nice easy way to do that – Jack Ukleja Jan 29 '15 at 15:08
The trace statements when running in a regular psh session get output into the pipeline. So ideally they would be returned from the receive-job command in the same way normal output results are. – Jack Ukleja Jan 29 '15 at 15:11
You might find this helpful: http://stackoverflow.com/questions/11973775/powershell-get-output-from-receive-job – Joel Coehoorn Jan 29 '15 at 15:14
Thanks but not sure an explanation of .NET tracing really helps me. I'm fairly familiar with it. I had considered writing a custom trace listener to hook the events and output them to parts of PSH that I know do work, such as write-host but I'm hoping for a definitive answer on why the scenario in the question doesn't work. – Jack Ukleja Jan 29 '15 at 15:21
This the programmer's equivalent to the theoretical physicist's standard excuse. In stead of "Because Quantum", we get to say "Because Threads." Start-Job pushes the work into a separate thread, and Trace events are fired in separate threads still. Each thread has it's own hidden standard output. Start-Job keeps those results and eventually pushes them back via Receive-Job. For the Trace events... it looks like not so much, at least in this scenario. – Joel Coehoorn Jan 29 '15 at 15:25
I'm not convinced :) The .NET tracing system doesn't really stipulate an approach to "thread safety". Some listeners are thread safe, some aren't. I think the CTL happens to be block when it gets to the console writing step (because that has a global lock I think), but in general there is no "separate thread" for tracing. – Jack Ukleja Jan 29 '15 at 15:30
The code example do use `Start-Job`, so it's not a scheduled task. – Dennis Sep 20 '21 at 17:13

How do I capture .NET trace output from a Powershell job?

2 Answers2