Merge branch 'pr617' into stable

* pr617:
  (maint) comment cleanup
  (GH-526) set messaging to output as error
  (GH-520) Debug/Verbose should be global scope
  (maint) formatting
  (GH-616) Deterministicly capture unzipped/extracted files

src/chocolatey.resources/helpers/chocolateyInstaller.psm1

@@ -14,10 +14,10 @@
 
 $helpersPath = (Split-Path -parent $MyInvocation.MyCommand.Definition);
 
-$DebugPreference = "SilentlyContinue"
-if ($env:ChocolateyEnvironmentDebug -eq 'true') { $DebugPreference = "Continue"; }
-$VerbosePreference = "SilentlyContinue"
-if ($env:ChocolateyEnvironmentVerbose -eq 'true') { $VerbosePreference = "Continue"; $verbosity = $true }
+$global:DebugPreference = "SilentlyContinue"
+if ($env:ChocolateyEnvironmentDebug -eq 'true') { $global:DebugPreference = "Continue"; }
+$global:VerbosePreference = "SilentlyContinue"
+if ($env:ChocolateyEnvironmentVerbose -eq 'true') { $global:VerbosePreference = "Continue"; $verbosity = $true }
 
 $installArguments = $env:chocolateyInstallArguments
 

src/chocolatey.resources/helpers/chocolateyScriptRunner.ps1

@@ -7,10 +7,10 @@
   [string]$packageScript
 )
 
-$DebugPreference = "SilentlyContinue"
-if ($env:ChocolateyEnvironmentDebug -eq 'true') { $DebugPreference = "Continue"; }
-$VerbosePreference = "SilentlyContinue"
-if ($env:ChocolateyEnvironmentVerbose -eq 'true') { $VerbosePreference = "Continue"; $verbosity = $true }
+$global:DebugPreference = "SilentlyContinue"
+if ($env:ChocolateyEnvironmentDebug -eq 'true') { $global:DebugPreference = "Continue"; }
+$global:VerbosePreference = "SilentlyContinue"
+if ($env:ChocolateyEnvironmentVerbose -eq 'true') { $global:VerbosePreference = "Continue"; $verbosity = $true }
 
 Write-Debug "Running 'ChocolateyScriptRunner' for $($env:packageName) v$($env:packageVersion) with packageScript `'$packageScript`', packageFolder:`'$($env:packageFolder)`', installArguments: `'$installArguments`', packageParameters: `'$packageParameters`',"
 

src/chocolatey.resources/helpers/functions/Get-ChocolateyUnzip.ps1

@@ -74,8 +74,8 @@ param(
 
   $7zip = Join-Path "$helpersPath" '..\tools\7za.exe'
   if (!([System.IO.File]::Exists($7zip))) {
-	Update-SessionEnvironment
-	$7zip = Join-Path "$env:ChocolateyInstall" 'tools\7za.exe'
+    Update-SessionEnvironment
+    $7zip = Join-Path "$env:ChocolateyInstall" 'tools\7za.exe'
   }
   $7zip = [System.IO.Path]::GetFullPath($7zip)
   Write-Debug "7zip found at `'$7zip`'"
@@ -91,31 +91,58 @@ param(
     $destination32 = $destination
   }
 
-  $exitCode = -1
-  $unzipOps = {
-    param($7zip, $destination, $fileFullPath, [ref]$exitCodeRef)
-    $params = "x -aoa -o`"$destination`" -y `"$fileFullPath`""
-    Write-Debug "Executing command ['$7zip' $params]"
-    $process = New-Object System.Diagnostics.Process
-    $process.StartInfo = new-object System.Diagnostics.ProcessStartInfo($7zip, $params)
-    $process.StartInfo.UseShellExecute = $false
-    $process.StartInfo.WindowStyle = [System.Diagnostics.ProcessWindowStyle]::Hidden
-
-    $process.Start() | Out-Null
-    $process.WaitForExit()
-    $processExitCode = $process.ExitCode
-    $process.Dispose()
-    Write-Debug "Command ['$7zip' $params] exited with `'$processExitCode`'."
-
-    $exitCodeRef.Value = $processExitCode
+  $params = "x -aoa -o`"$destination`" -y `"$fileFullPath`""
+  Write-Debug "Executing command ['$7zip' $params]"
+
+  # Capture 7z's output into a StringBuilder and write it out in blocks, to improve I/O performance.
+  $global:zipFileList = New-Object System.Text.StringBuilder
+  $global:zipDestinationFolder = $destination
+
+  # Redirecting output slows things down a bit.
+  $writeOutput = {
+    if ($EventArgs.Data -ne $null) {
+      $line = $EventArgs.Data
+      Write-Verbose "$line"
+      if ($line.StartsWith("Extracting")) {
+        $global:zipFileList.AppendLine($global:zipDestinationFolder + "\" + $line.Substring(12))
+      }
+    }
   }
 
+  $writeError = {
+    if ($EventArgs.Data -ne $null) {
+      Write-Error "$($EventArgs.Data)"
+    }
+  }
+
+  $process = New-Object System.Diagnostics.Process
+  $process.EnableRaisingEvents = $true
+  Register-ObjectEvent  -InputObject $process -SourceIdentifier "LogOutput_ChocolateyZipProc" -EventName OutputDataReceived -Action $writeOutput | Out-Null
+  Register-ObjectEvent -InputObject $process -SourceIdentifier "LogErrors_ChocolateyZipProc" -EventName ErrorDataReceived -Action  $writeError | Out-Null
+
+  $process.StartInfo = new-object System.Diagnostics.ProcessStartInfo($7zip, $params)
+  $process.StartInfo.RedirectStandardOutput = $true
+  $process.StartInfo.RedirectStandardError = $true
+  $process.StartInfo.UseShellExecute = $false
+  $process.StartInfo.WorkingDirectory = Get-Location
+  $process.StartInfo.WindowStyle = [System.Diagnostics.ProcessWindowStyle]::Hidden
+
+  [void] $process.Start()
+  if ($process.StartInfo.RedirectStandardOutput) { $process.BeginOutputReadLine() }
+  if ($process.StartInfo.RedirectStandardError) { $process.BeginErrorReadLine() }
+  $process.WaitForExit()
+
+  # For some reason this forces the jobs to finish and waits for
+  # them to do so. Without this it never finishes.
+  Unregister-Event -SourceIdentifier "LogOutput_ChocolateyZipProc"
+  Unregister-Event -SourceIdentifier "LogErrors_ChocolateyZipProc"
+
+  $exitCode = $process.ExitCode
+  $process.Dispose()
+  Write-Debug "Command ['$7zip' $params] exited with `'$exitCode`'."
+
   if ($zipExtractLogFullPath) {
-    Write-Debug "wrapping 7za invocation with Write-FileUpdateLog"
-    Write-FileUpdateLog -logFilePath $zipExtractLogFullPath -locationToMonitor $destination -scriptToRun $unzipOps -argumentList $7zip,$destination32,$fileFullPath32,([ref]$exitCode)
-  } else {
-    Write-Debug "calling 7za directly"
-    Invoke-Command $unzipOps -ArgumentList $7zip,$destination32,$fileFullPath32,([ref]$exitCode)
+    Set-Content $zipExtractLogFullPath $global:zipFileList.ToString() -Encoding UTF8 -Force
   }
 
   Write-Debug "7za exit code: $exitCode"

src/chocolatey.resources/helpers/functions/Start-ChocolateyProcessAsAdmin.ps1

@@ -64,22 +64,12 @@ Elevating Permissions and running [`"$exeToRun`" $wrappedStatements]. This may t
     if ($EventArgs.Data -ne $null) {
       Write-Host "$($EventArgs.Data)"
     }
-
-    #foreach ($line in $EventArgs.Data) {
-      #Write-Host "$line"
-    #}
   }
 
   $writeError = {
     if ($EventArgs.Data -ne $null) {
-      Write-Host "[ERROR] $($EventArgs.Data)" -ForegroundColor $ErrorColor -BackgroundColor Black
+      Write-Error "$($EventArgs.Data)"
     }
-    #foreach ($line in $EventArgs.Data) {
-      #if (!$line.IsNullOrEmpty) {
-        # do not stop execution, but pass the output back to the user.
-      #  Write-Host "[ERROR] $line" -ForegroundColor $ErrorColor -BackgroundColor Black
-      #}
-    #}
   }
 
   $process = New-Object System.Diagnostics.Process

src/chocolatey/infrastructure.app/services/FilesService.cs

@@ -128,7 +128,7 @@ public PackageFiles capture_package_files(string directory, ChocolateyConfigurat
         public PackageFile get_package_file(string file)
         {
             var hash = _hashProvider.hash_file(file);
-            this.Log().Debug(ChocolateyLoggers.Verbose,() => " Found '{0}'{1}  with checksum '{2}'".format_with(file, Environment.NewLine, hash));
+            this.Log().Debug(ChocolateyLoggers.Verbose, () => " Found '{0}'{1}  with checksum '{2}'".format_with(file, Environment.NewLine, hash));
 
             return new PackageFile { Path = file, Checksum = hash };
         }

src/chocolatey/infrastructure/logging/Log4NetAppenderConfiguration.cs

@@ -145,7 +145,7 @@ public static void set_logging_level_debug_when_debug(bool enableDebug, string e
         /// </param>
         /// <param name="enableDebug">If debug is also enabled</param>
         /// <param name="verboseLoggerName">Name of the verbose logger.</param>
-        public static void set_verbose_logger_when_verbose(bool enableVerbose,bool enableDebug, string verboseLoggerName)
+        public static void set_verbose_logger_when_verbose(bool enableVerbose, bool enableDebug, string verboseLoggerName)
         {
             if (enableVerbose)
             {