Why does PowerShell chops message on stderr?

2019-07-14 06:51发布

站内文章 / 移动开发
64 0 0

问题:

I'm using a PowerShell script to control different compilation steps of an compiler (ghdl.exe).

The compiler has 3 different output formats:

  1. No output and no error => $LastExitCode = 0
  2. outputs on stderr (warnings), but no errors => $LastExitCode = 0
  3. outputs on stderr (errors), and maybe warnings => $LastExitCode != 0

Because handling of stderr and stdout seams to be very buggy, I used the method presented in this StackOverflow post: PowerShell: Manage errors with Invoke-Expression

Here is my implementation with addition message coloring:

function Format-NativeCommandStreams
{ param([Parameter(ValueFromPipeline=$true)]$InputObject)

  begin
  { $ErrorRecordFound = $false  }

  process
  { if (-not $InputObject)
    { Write-Host "Empty"  }
    elseif ($InputObject -is [System.Management.Automation.ErrorRecord])
    { $ErrorRecordFound  = $true
      $text = $InputObject.ToString()
      Write-Host $text -ForegroundColor  Gray

      $stdErr = $InputObject.TargetObject
      if ($stdErr)
      { #Write-Host ("err: type=" + $stdErr.GetType() + "  " + $stdErr)
        if ($stdErr.Contains("warning"))
        { Write-Host "WARNING: "  -NoNewline -ForegroundColor Yellow  }
        else
        { Write-Host "ERROR: "    -NoNewline -ForegroundColor Red      }
        Write-Host $stdErr
      }
    }
    else
    { $stdOut = $InputObject                
      if ($stdOut.Contains("warning"))
      { Write-Host "WARNING: "  -NoNewline -ForegroundColor Yellow  }
      else
      { Write-Host "ERROR: "    -NoNewline -ForegroundColor Red      }
      Write-Host $stdOut
    }
  }

  end
  { $ErrorRecordFound    }
}

Usage:

$Options = @(.....)
$Expr = "ghdl.exe -a " + ($Options -join " ") + " " + $File + " 2>&1"
$ret = Invoke-Expression $Expr | Format-NativeCommandStreams

Normally, the compiler emits one message (error or warning) per line. As shown in the screenshot below, some messages got chopped in up to 8 lines. That's the reason why my output coloring does not work as expected. More over some lines are detected as errors (false positives), so I can't find the real error in the logs.

(clickable)

Example:

C:\Altera\15.0\quartus\eda\sim_lib\altera_mf.vhd:
39963:
53
:
warning:

universal integer bound must be numeric literal or attribute

C:\Altera\15.0\quartus\eda\sim_lib\altera_mf.vhd
:41794:36:warning: universal integer bound must be numeric literal or attribute

Expected Result:

C:\Altera\15.0\quartus\eda\sim_lib\altera_mf.vhd:39963:53:warning: universal integer bound must be numeric literal or attribute
C:\Altera\15.0\quartus\eda\sim_lib\altera_mf.vhd:41794:36:warning: universal integer bound must be numeric literal or attribute

As far as I can see, the compiler (ghdl.exe) does emit the messages as full lines.

Questions:

  • Why does this happen?
  • Who can I solve this?

回答1:

Solution

The complete output on stderr of the executable is simply split across several objects of type System.Management.Automation.ErrorRecord. The actual splitting seems to be non deterministic (*). Moreover, the partial strings are stored inside the property Exception instead of TargetObject. Only the first ErrorRecord has a non-null TargetObject. That is, why subsequent lines of your output containing the string "warning" are not formatted in yellow and white, like this one:

:41794:36:warning: universal integer bound must be numeric literal or attribute

Your grey output comes from the toString() method of each ErrorRecord which returns the value of the property Exception.Message of this record. So one must concatenate all messages together to get the whole output before formatting it. Newlines are preserved in these messages.

EDIT: (*) It depends on the order of write/flush calls of the program in relation to the read calls of the Powershell. If one adds a fflush(stderr) after each fprintf() in my test program below, there will be much more ErrorRecord objects. Except the first one, which seems deterministic, some of them include 2 output lines and some of them 3.

My testbench

Instead of using GHDL I started with a new Visual Studio project and created a console application (HelloWorldEx) with the following code. It simply prints out a lot of numbered lines on stderr 

#include "stdafx.h"
#include <stdio.h>

int _tmain(int argc, _TCHAR* argv[])
{
  // Print some warning messages on stderr
  for(int i=0; i<70; i++) {
    fprintf(stderr, "warning:%070d\n", i); // 80 bytes per line including CR+LF
  }
  return 0; // exit code is not relevant
}

Then I compiled the program and executed it inside the Powershell with: (EDIT: removed debug code from my own script)

.\HelloWorldEx.exe 2>&1 | set-variable Output
$i = 0
$Output | % {
  Write-Host ("--- " + $i + ": "  + $_.GetType() +  " ------------------------")
  Write-Host ($_ | Format-List -Force | Out-String)
  $i++
}

This was the output of the script. As you can see, the output of my program is split accross 3 ErrorRecords (the actual might differ):

--- 0: System.Management.Automation.ErrorRecord ------------------------


writeErrorStream      : True
Exception             : System.Management.Automation.RemoteException: warning:00000000000000000000000000000000000000000
                        00000000000000000000000000000
TargetObject          : warning:0000000000000000000000000000000000000000000000000000000000000000000000
CategoryInfo          : NotSpecified: (warning:0000000...000000000000000:String) [], RemoteException
FullyQualifiedErrorId : NativeCommandError
ErrorDetails          : 
InvocationInfo        : System.Management.Automation.InvocationInfo
PipelineIterationInfo : {0, 0, 0}
PSMessageDetails      : 




--- 1: System.Management.Automation.ErrorRecord ------------------------


writeErrorStream      : True
Exception             : System.Management.Automation.RemoteException: warning:00000000000000000000000000000000000000000
                        00000000000000000000000000001
                        warning:0000000000000000000000000000000000000000000000000000000000000000000002
                        warning:0000000000000000000000000000000000000000000000000000000000000000000003
                        warning:0000000000000000000000000000000000000000000000000000000000000000000004
                        warning:0000000000000000000000000000000000000000000000000000000000000000000005
                        warning:0000000000000000000000000000000000000000000000000000000000000000000006
                        warning:0000000000000000000000000000000000000000000000000000000000000000000007
                        warning:0000000000000000000000000000000000000000000000000000000000000000000008
                        warning:0000000000000000000000000000000000000000000000000000000000000000000009
                        warning:0000000000000000000000000000000000000000000000000000000000000000000010
                        warning:0000000000000000000000000000000000000000000000000000000000000000000011
                        warning:0000000000000000000000000000000000000000000000000000000000000000000012
                        warning:0000000000000000000000000000000000000000000000000000000000000000000013
                        warning:0000000000000000000000000000000000000000000000000000000000000000000014
                        warning:0000000000000000000000000000000000000000000000000000000000000000000015
                        warning:0000000000000000000000000000000000000000000000000000000000000000000016
                        warning:0000000000000000000000000000000000000000000000000000000000000000000017
                        warning:0000000000000000000000000000000000000000000000000000000000000000000018
                        warning:0000000000000000000000000000000000000000000000000000000000000000000019
                        warning:0000000000000000000000000000000000000000000000000000000000000000000020
                        warning:0000000000000000000000000000000000000000000000000000000000000000000021
                        warning:0000000000000000000000000000000000000000000000000000000000000000000022
                        warning:0000000000000000000000000000000000000000000000000000000000000000000023
                        warning:0000000000000000000000000000000000000000000000000000000000000000000024
                        warning:0000000000000000000000000000000000000000000000000000000000000000000025
                        warning:0000000000000000000000000000000000000000000000000000000000000000000026
                        warning:0000000000000000000000000000000000000000000000000000000000000000000027
                        warning:0000000000000000000000000000000000000000000000000000000000000000000028
                        warning:0000000000000000000000000000000000000000000000000000000000000000000029
                        warning:0000000000000000000000000000000000000000000000000000000000000000000030
                        warning:0000000000000000000000000000000000000000000000000000000000000000000031
                        warning:0000000000000000000000000000000000000000000000000000000000000000000032
                        warning:0000000000000000000000000000000000000000000000000000000000000000000033
                        warning:0000000000000000000000000000000000000000000000000000000000000000000034
                        warning:0000000000000000000000000000000000000000000000000000000000000000000035
                        warning:0000000000000000000000000000000000000000000000000000000000000000000036
                        warning:0000000000000000000000000000000000000000000000000000000000000000000037
                        warning:0000000000000000000000000000000000000000000000000000000000000000000038
                        warning:0000000000000000000000000000000000000000000000000000000000000000000039
                        warning:0000000000000000000000000000000000000000000000000000000000000000000040
                        warning:0000000000000000000000000000000000000000000000000000000000000000000041
                        warning:0000000000000000000000000000000000000000000000000000000000000000000042
                        warning:0000000000000000000000000000000000000000000000000000000000000000000043
                        warning:0000000000000000000000000000000000000000000000000000000000000000000044
                        warning:0000000000000000000000000000000000000000000000000000000000000000000045
                        warning:0000000000000000000000000000000000000000000000000000000000000000000046
                        warning:0000000000000000000000000000000000000000000000000000000000000000000047
                        warning:0000000000000000000000000000000000000000000000000000000000000000000048
                        warning:0000000000000000000000000000000000000000000000000000000000000000000049
                        warning:0000000000000000000000000000000000000000000000000000000000000000000050
                        warning:00000000000000000000000000000000000000000000000000000000000
TargetObject          : 
CategoryInfo          : NotSpecified: (:) [], RemoteException
FullyQualifiedErrorId : NativeCommandErrorMessage
ErrorDetails          : 
InvocationInfo        : System.Management.Automation.InvocationInfo
PipelineIterationInfo : {0, 0, 1}
PSMessageDetails      : 




--- 2: System.Management.Automation.ErrorRecord ------------------------


writeErrorStream      : True
Exception             : System.Management.Automation.RemoteException: 00000000051
                        warning:0000000000000000000000000000000000000000000000000000000000000000000052
                        warning:0000000000000000000000000000000000000000000000000000000000000000000053
                        warning:0000000000000000000000000000000000000000000000000000000000000000000054
                        warning:0000000000000000000000000000000000000000000000000000000000000000000055
                        warning:0000000000000000000000000000000000000000000000000000000000000000000056
                        warning:0000000000000000000000000000000000000000000000000000000000000000000057
                        warning:0000000000000000000000000000000000000000000000000000000000000000000058
                        warning:0000000000000000000000000000000000000000000000000000000000000000000059
                        warning:0000000000000000000000000000000000000000000000000000000000000000000060
                        warning:0000000000000000000000000000000000000000000000000000000000000000000061
                        warning:0000000000000000000000000000000000000000000000000000000000000000000062
                        warning:0000000000000000000000000000000000000000000000000000000000000000000063
                        warning:0000000000000000000000000000000000000000000000000000000000000000000064
                        warning:0000000000000000000000000000000000000000000000000000000000000000000065
                        warning:0000000000000000000000000000000000000000000000000000000000000000000066
                        warning:0000000000000000000000000000000000000000000000000000000000000000000067
                        warning:0000000000000000000000000000000000000000000000000000000000000000000068
                        warning:0000000000000000000000000000000000000000000000000000000000000000000069

TargetObject          : 
CategoryInfo          : NotSpecified: (:) [], RemoteException
FullyQualifiedErrorId : NativeCommandErrorMessage
ErrorDetails          : 
InvocationInfo        : System.Management.Automation.InvocationInfo
PipelineIterationInfo : {0, 0, 2}
PSMessageDetails      :


回答2:

You can a bit of debugging to sort this out. I suggest starting with something like this:

ghdl.exe <whatever args you supply> 2>&1 | set-variable ghdlOutput
$i = 0
$ghdlOutput | % {write-host "$i `t: " $_.gettype() "`t" $_ ; $i++}

This will list the line number, type of the output line, and each live of the output. You may have to tweak the code some to get the output to look OK.

From there you can see if the compiler is really splitting up errors into multiple lines. If it is you can try devise a strategy for determining which lines are stdout and which are stderr. If not, then you'll have some clues to debugging your script above.

Or can bag this whole approach and use the .NET system.diagnostics.process class and redirect stdout and stderr as separate streams. Use the Start method that takes a ProcessStartInfo. You should be able to google examples of doing this if you need to.



回答3:

Just for completeness, here are my current CommandLets, which restore the error messages as a single line and color them as wanted:

Usage:

$InvokeExpr = "ghdl.exe " + ($Options -join " ") + " --work=unisim " + $File.FullName + " 2>&1"
$ErrorRecordFound = Invoke-Expression $InvokeExpr | Collect-NativeCommandStream | Write-ColoredGHDLLine

CommandLet to restore the error messages:

function Collect-NativeCommandStream
{ [CmdletBinding()]
  param([Parameter(ValueFromPipeline=$true)]$InputObject)

  begin
  { $LineRemainer = ""  }

  process
  { if (-not $InputObject)
    { Write-Host "Empty pipeline!"  }
    elseif ($InputObject -is [System.Management.Automation.ErrorRecord])
    { if ($InputObject.FullyQualifiedErrorId -eq "NativeCommandError")
      { Write-Output $InputObject.ToString()    }
      elseif ($InputObject.FullyQualifiedErrorId -eq "NativeCommandErrorMessage")
      { $NewLine = $LineRemainer + $InputObject.ToString()
        while (($NewLinePos = $NewLine.IndexOf("`n")) -ne -1)
        { Write-Output $NewLine.Substring(0, $NewLinePos)
          $NewLine = $NewLine.Substring($NewLinePos + 1)
        }
        $LineRemainer = $NewLine
      }
    }
    elseif ($InputObject -is [String])
    { Write-Output $InputObject    }
    else
    { Write-Host "Unsupported object in pipeline stream"    }
  }

  end
  {   }
}

CommandLet to color warnings and errors:

function Write-ColoredGHDLLine
{ [CmdletBinding()]
  param([Parameter(ValueFromPipeline=$true)]$InputObject)

  begin
  { $ErrorRecordFound = $false  }

  process
  { if (-not $InputObject)
    { Write-Host "Empty pipeline!"  }
    elseif ($InputObject -is [String])
    { if ($InputObject.Contains("warning"))
      { Write-Host "WARNING: "  -NoNewline -ForegroundColor Yellow  }
      else
      { $ErrorRecordFound  = $true
        Write-Host "ERROR: "    -NoNewline -ForegroundColor Red
      }
      Write-Host $InputObject
    }
    else
    { Write-Host "Unsupported object in pipeline stream"    }
  }

  end
  { $ErrorRecordFound    }
}


标签： powershell error-handling ghdl
举报

收藏的人(0)

Ta的文章 更多文章
登录 后发表评论
0条评论
还没有人评论过~