Powershell calling sqlcmd swallowing error

[Mark S]

I'm executing Sql Server 2008 commands on a remote server using Powershell. The commands are generally executing fine, however when a command fails the error code/state is not being passed back to Bamboo. Hence, Bamboo is indicating "success". The error message is being passed back, though clearly it's not an option to have to check the logs after each run.

In the deployment project I have a Script task, running as Powershell which looks something like:

Invoke-Command -computerName ${bamboo.sqlHost} -scriptBlock { sqlcmd -S ${bamboo.sqlServer} -d ${bamboo.sqlDatabase} -b -Q "SELECT TOP 3 name FROM sys.schemasXX"}

The deployment succeeds, but the log outputs:

Msg 208, Level 16, State 1, Server IDW-SQLDB01\DEV8, Line 1
Invalid object name 'sys.schemasXX'.

[Robert Praetorius]

We have a similar problem and we have two layers in our solution.  We have the additional restriction that the SQLCMD scripts have to work in systems outside Bamboo (which means that we can't use -r, which would otherwise be helpful).

If you dig into the Bamboo source code, you'll see that individual lines in the log are tagged as success or error depending on whether they come from stdout or stderr.  Error lines will be marked with class errorOutputLog in HTML or will have "error" at the beginning of the line in the plain-text log.

Since we can't send SQLCMD errors to stderr (see previous paragraph), we fake that part with a PowerShell filter the locates error messages in the SQLCMD output and converts them to PowerShell errors.

The other thing that bit us is that deployments are flagged as successful or failed depending on the exit code of the script.  Even if individual lines are errors, Bamboo will see the script as succeeding unless it returns a non-zero exit code.  Again, we take care of this with a PowerShell filter.

This is the SQLCMD filter:

Function Wrap-SqlCmdError($target)
{
  begin {$firstLineOfError = $null}
  process
  {
    if ($firstLineOfError -ne $null)
    {
      New-Object System.Management.Automation.ErrorRecord `
        (New-Object System.Data.DataException "sqlcmd error: $_"), $firstLineOfError, 'NotSpecified', $target
      $firstLineOfError = $null
    }
    elseif ($_ -match '^(HResult 0x[0-9a-f]+|Msg \d+), Level \d+, State \d+')
    {
      $firstLineOfError = $_
    }
    else { $_ }
  }
  end { if ($firstLineOfError -ne $null) { $firstLineOfError } }
}

Here's how we use it (update.bat invokes SQLCMD and sends the output to UpdateLog.txt):

  CMD /C update.bat 
  Get-Content UpdateLog.txt | Wrap-SqlCmdError 'sqlcmd invoked from update.bat'

(I got the trick of using ErrorRecord from http://stackoverflow.com/a/33002914)

This is the overall deployment script filter (used at the task level in deployment projects with PowerShell tasks):

# see https://community.atlassian.com/t5/Bamboo-questions/What-exit-code-is-Bamboo-expecting-from-a-command-to-highlight/qaq-p/456940#M14469
function Exit-WithNonZeroIfErrorsSeen()
{
  begin {$sawError = $false}
  process
  {
    if ($_ -is [System.Management.Automation.ErrorRecord])
    {
      $sawError = $true
      Write-Error -ErrorRecord $_
    }
    else { $_ }
  }
  end { [System.Environment]::Exit([int]$sawError) }
}

 and here's how it gets used

Invoke-Command -ComputerName randomhostname -Credential $cred -Authentication Credssp -ScriptBlock $command 2>&1 | Exit-WithNonZeroIfErrorsSeen

[Robert Praetorius]

One a somewhat related front. . .in addition to invoking sqlcmd from PowerShell within Bamboo tasks, we also invoke msbuild to run the SqlSchemaCompare target.  Like sqlcmd, msbuild sends its error output to stdout.  The solution for msbuild is somewhat different - I build a custom log sink that sends errors to stderr:

function Get-CustomMSBuildLogger
(
 [hashtable] $testConfig
)
{
 $assemblyPath = Join-Path $testConfig.TemporaryRoot BuildLogger.dll
 if (!(Test-Path $assemblyPath))
 {
 Add-Type @'
using Microsoft.Build.Utilities; using Microsoft.Build.Framework;
public class ErrorOnlyLogger : Logger {
 public override void Initialize(IEventSource eventSource)
 {
 eventSource.ErrorRaised += (s, e) => {System.Console.Error.WriteLine(
 "{0}({1},{2}): error {3}: {4} [{5}]",
 e.File, e.LineNumber, e.ColumnNumber, e.Code, e.Message, e.ProjectFile);};
 }
}
'@ -ReferencedAssemblies `
 (Join-Path $testConfig.MSBuildDirectory Microsoft.Build.Utilities.Core.dll),
 (Join-Path $testConfig.MSBuildDirectory Microsoft.Build.Framework.dll) `
 -OutputAssembly $assemblyPath -OutputType Library
 }
 return $assemblyPath
}

and then I reference the assembly containing the log sink when I run the SqlSchemaCompare target:

 $testConfig.MSBuildLoggerPath = Get-CustomMSBuildLogger $testConfig

 # . . . (much unrelated code happens here) . . .

 # see https://blogs.msdn.microsoft.com/ssdt/2014/07/15/msbuild-support-for-schema-compare-is-available/
 # to get an idea of how this works. You can generate an .scmp file by doing a schema
 # comparison in Visual Studio (if you have SSDT installed) and saving the comparison.

 Copy-Item $testConfig.ScmpProjectPath . -Verbose 4>&1 2>&1 | &$logger
 $templateSCmp = Get-Content $testConfig.ScmpFilePath -Raw
 $msBuildLoggerPath = $testConfig.MSBuildLoggerPath
 foreach ($catalog in $testConfig.DBDescriptions.Values.DBName)
 {
 $templateSCmp.Replace('NewInstanceName', $testConfig.LocalDBInstances.New.InstName `
 ).Replace('OldInstanceName', $testConfig.LocalDBInstances.Old.InstName) `
 -replace 'Initial Catalog=\w+', "Initial Catalog=$catalog" `
 | Out-File "schComp$catalog.scmp" -Encoding utf8 -Force 2>&1 | &$logger

 $catalog | Add-Banner | &$logger

 &$testconfig.MSBuild /logger:"ErrorOnlyLogger,$msBuildLoggerPath" `
 /target:SqlSchemaCompare `
 /property:XmlOutput=”schComp$catalog.xml” `
 /property:SqlScmpFilePath="schComp$catalog.scmp" 2>&1 | &$logger
 }

[Robert Praetorius]

As long as I'm having this little conversation with myself, it'd be good to comment on why I go to the trouble of piping through Exit-WithNonZeroIfErrorsSeen, rather than just examining $Error.  Over the years, I've seem a number of scripts that call the Clear method on $Error (as in $Error.Clear()).  Typically this happens because the script is iterating over something (hosts, files, whatever) and wants to manually track errors each time through to loop and/or it wants to attribute errors to each host/file/etc.  Which seems reasonable.

But if somebody were to invoke such a script within Bamboo (directly or indirectly) and was relying on $Error at the end of the script to know if any errors had been encountered, they'd be out of luck.  Exit-WithNonZeroIfErrorsSeen is more awkward, but more careful.

[Robert Praetorius]

Also, if somebody has a simpler, cleaner, more straightforward solution to the general problem of error handling in PowerShell running under Bamboo, please point out the obvious solution, if such a thing exists (after you finish laughing at the baroqueness of the workarounds I've implemented).

[Marcin Gardias]

http://stackoverflow.com/questions/1210942/catching-return-code-of-a-command-with-invoke-command-powershell-2

http://stackoverflow.com/questions/8549184/how-to-capture-the-return-value-of-a-scriptblock-invoked-with-powershells-invok