fixes #45 capturing chocolatey errors in the log

chocolatey · Jan 12, 2015 · db00b44 · db00b44
1 parent 9547722
commit db00b44
Show file tree

Hide file tree

Showing 3 changed files with 38 additions and 22 deletions.
diff --git a/Boxstarter.Chocolatey/Chocolatey.ps1 b/Boxstarter.Chocolatey/Chocolatey.ps1
@@ -114,6 +114,8 @@ Intercepts Chocolatey call to check for reboots
         }
         if(((Test-PendingReboot) -or $Boxstarter.IsRebooting) -and $Boxstarter.RebootOk) {return Invoke-Reboot}
         $session=Start-TimedSection "Calling Chocolatey to install $packageName. This may take several minutes to complete..."
+        $currentErrorCount = $global:error.Count
+        $rebootable = $false
         try {
             if($winFeature -eq $true -and (Get-IsRemote)){
                 #DISM Output is more confusing than helpful.
@@ -133,18 +135,36 @@ Intercepts Chocolatey call to check for reboots
             }
         }
         catch { 
-            Write-BoxstarterMessage "There was an error calling chocolatey" -Verbose
-            $ex=$_
-            Log-BoxstarterMessage $_
             #Only write the error to the error stream if it was not previously
             #written by chocolatey
-            if($global:error.Count -gt 1){
-                if(($global:error[1].Exception.Message | Out-String).Contains($_.Exception.Message)){
-                    $errorWritten=$true
+            $chocoErrors = $global:error.Count - $currentErrorCount
+            if($chocoErrors -gt 0){
+                $idx = 0
+                $errorWritten = $false
+                while($idx -lt $chocoErrors){
+                    if(($global:error[$idx].Exception.Message | Out-String).Contains($_.Exception.Message)){
+                        $errorWritten = $true
+                    }
+                    if(!$errorWritten){
+                        Write-Error $_
+                    }
+                    $idx += 1
                 }
             }
-            if(!$errorWritten){
-                Write-Error $_
+        }
+        $chocoErrors = $global:error.Count - $currentErrorCount
+        if($chocoErrors -gt 0){
+            Write-BoxstarterMessage "There was an error calling chocolatey" -Verbose
+            $idx = 0
+            while($idx -lt $chocoErrors){
+                Log-BoxstarterMessage "Error from chocolatey: $($global:error[$idx].Exception | fl * -Force | Out-String)"
+                if($global:error[$idx] -match "code was '(-?\d+)'") {
+                    $errorCode=$matches[1]
+                    if($RebootCodes -contains $errorCode) {
+                       $rebootable = $true
+                    }
+                }
+                $idx += 1
             }
         }
         Stop-Timedsection $session
@@ -153,15 +173,10 @@ Intercepts Chocolatey call to check for reboots
             Remove-ChocolateyPackageInProgress $packageName
             return
         }
-        if($global:error.count -gt 0) {
-            if ($ex -ne $null -and ($ex -match "code was '(-?\d+)'")) {
-                $errorCode=$matches[1]
-                if($RebootCodes -contains $errorCode) {
-                    Write-BoxstarterMessage "Chocolatey Install returned a reboot-able exit code"
-                    Remove-ChocolateyPackageInProgress $packageName
-                    Invoke-Reboot
-                }
-            }
+        if($rebootable) {
+            Write-BoxstarterMessage "Chocolatey Install returned a reboot-able exit code"
+            Remove-ChocolateyPackageInProgress $packageName
+            Invoke-Reboot
         }
     }
 }

diff --git a/BuildScripts/releaseNotes.xml b/BuildScripts/releaseNotes.xml
@@ -1,4 +1,5 @@
 <releaseNotes>
+  - Provide improved error logging of chocolatey errors.
   - Fixes issue where windows update reboots maching in the midst of a run.
   - Fixes failures from exceptions thrown from bitlocker module even when bitlocker is not in use.
   - Fixes Invoke-Reboot from a nested package and bubbles up the reboot signal

diff --git a/tests/Chocolatey/Chocolatey.tests.ps1 b/tests/Chocolatey/Chocolatey.tests.ps1
@@ -91,14 +91,14 @@ Describe "Getting-Chocolatey" {
         }        
     }
 
-    Context "When chocolatey writes a reboot error and reboots are OK" {
+    Context "When chocolatey throws a reboot error and reboots are OK" {
         Mock Test-PendingReboot {return $false}
         $boxstarter.RebootOk=$true
         Mock Remove-Item
         Mock Get-ChildItem {@("dir1","dir2")} -parameterFilter {$path -match "\\lib\\pkg.*"}
         Mock Invoke-Reboot
         Mock Call-Chocolatey {throw "[ERROR] Exit code was '3010'."}
-        
+
         Chocolatey Install pkg -RebootCodes @(56,3010,654) 2>&1 | out-null
 
         it "will Invoke-Reboot" {
@@ -109,13 +109,13 @@ Describe "Getting-Chocolatey" {
         }
     }
 
-    Context "When chocolatey writes a negative reboot error and reboots are OK" {
+    Context "When chocolatey writes a reboot error and reboots are OK" {
         Mock Test-PendingReboot {return $false}
         $boxstarter.RebootOk=$true
         Mock Remove-Item
         Mock Get-ChildItem {@("dir1","dir2")} -parameterFilter {$path -match "\\lib\\pkg.*"}
         Mock Invoke-Reboot
-        Mock Call-Chocolatey {throw "[ERROR] Exit code was '-654'."}
+        Mock Call-Chocolatey {Write-Error "[ERROR] Exit code was '-654'."}
 
         Chocolatey Install pkg -RebootCodes @(56,3010,-654) 2>&1 | out-null
 
@@ -150,7 +150,7 @@ Describe "Getting-Chocolatey" {
         $boxstarter.RebootOk=$true
         Mock Invoke-Reboot
         Mock Call-Chocolatey {Write-Error "[ERROR] Exit code was '3020'." 2>&1 | out-null}
-        
+
         Chocolatey Install pkg -RebootCodes @(56,3010,654) | out-null
 
         it "will not Invoke-Reboot" {