Skip to content
This repository has been archived by the owner on Feb 19, 2019. It is now read-only.

[BUG] Certain installs and updates fail with a "process with an Id of xxxx is not running" error #603

Closed
kaiaie opened this issue Nov 4, 2014 · 10 comments

Comments

@kaiaie
Copy link

kaiaie commented Nov 4, 2014

I am getting an intermittent error installing or updating certain Chocolatey packages on my Windows 7 machine. The same packages install fine on a Windows Server 2008 R2 machine. I have been unable to determine why some packages are affected and others are not. The error seems to occur when unzipping the downloaded file (possible race condition?)

Below is the output generated while attempting to install the xmlstarlet package; as noted above, this package installs fine on a Windows 2008 R2 server:

F:\>chocolatey -debug install xmlstarlet
DEBUG: Running 'Append-InstallLog' with chocoInstallLog:''
DEBUG: Arguments: $command = 'install'|$force=False
|$prerelease=False|$packageNames='xmlstarlet'
|$source=''
|$version=''|$allVersions=False
|$overrideArguments=False|$InstallArguments=''
|$localonly=False|$verbosity=False|$debug=True|$quiet=False
|$name=''|$ignoreDependencies=False|$forceX86=False
|$packageParameters=''
|PowerShellVersion=2.0|OSVersion=6.1.7601.65536
DEBUG: Running 'Chocolatey-Install' for 'xmlstarlet' with source: '', version: '', installerArguments:''
DEBUG: Running 'Chocolatey-NuGet' for xmlstarlet with source:''. Force? False
Chocolatey (v0.9.8.27) is installing 'xmlstarlet' and dependencies. By installing you accept the license for 'xmlstarlet' and each d
ependency you are installing.
DEBUG: Installing packages to "F:\Chocolatey\lib".
DEBUG: Running 'Run-NuGet' for xmlstarlet with source: '', version:''
DEBUG: ___ NuGet ____
DEBUG: Running 'Get-ConfigValue' with configValue:'useNuGetForSources'
DEBUG: Running 'Get-UserConfigValue' with configValue:'useNuGetForSources'
DEBUG: After checking the user config the value of 'useNuGetForSources' is ''
DEBUG: Value not found in the user config file - checking the global config
DEBUG: Running 'Get-GlobalConfigValue' with configValue:'useNuGetForSources'
DEBUG: After checking the global config the value of 'useNuGetForSources' is 'false'
DEBUG: Running 'Get-UserConfigValue' with configValue:'sources'
DEBUG: Running 'Get-GlobalConfigValue' with configValue:'sources'
DEBUG: Using global sources
DEBUG: Using '-Source "https://chocolatey.org/api/v2/;"' as the source arguments
DEBUG: Calling 'F:\Chocolatey\chocolateyinstall\nuget.exe' install xmlstarlet -OutputDirectory "F:\Chocolatey\lib" -Source
"https://chocolatey.org/api/v2/;" -NonInteractive -NoCache
DEBUG: Attempting to resolve dependency 'xmlstarlet.portable (= 1.6.0)'.
Installing 'xmlstarlet.portable 1.6.0'.
Successfully installed 'xmlstarlet.portable 1.6.0'.
Installing 'xmlstarlet 1.6.0'.
Successfully installed 'xmlstarlet 1.6.0'.
DEBUG: Evaluating NuGet output for line: Attempting to resolve dependency 'xmlstarlet.portable (= 1.6.0)'.
DEBUG: Evaluating NuGet output for line: Installing 'xmlstarlet.portable 1.6.0'.
DEBUG: Evaluating NuGet output for line: Successfully installed 'xmlstarlet.portable 1.6.0'.
DEBUG: NuGet installed xmlstarlet.portable. If we are ignoring dependencies (False) then we will clean this up.

xmlstarlet.portable v1.6.0
DEBUG: Running 'Delete-ExistingErrorLog' for xmlstarlet.portable
DEBUG: Looking for failure log at 'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet.portable\failure.log'
DEBUG: Running 'Run-ChocolateyPS1' for xmlstarlet.portable with packageFolder:'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0',
action: 'install'
DEBUG:   __ PowerShell install (chocolateyinstall.ps1) __
DEBUG:   Looking for chocolateyinstall.ps1 in folder 'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0'. If chocolateyinstall.ps1 is
found, it will be run.
DEBUG: Action file is 'chocolateyInstall.ps1'
DEBUG: Running 'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0\tools\chocolateyInstall.ps1'
DEBUG: Running 'Install-ChocolateyZipPackage' for xmlstarlet with
url:'http://sourceforge.net/projects/xmlstar/files/xmlstarlet/1.6.0/xmlstarlet-1.6.0-win32.zip/download', unzipLocation:
'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0\tools', url64bit:
'http://sourceforge.net/projects/xmlstar/files/xmlstarlet/1.6.0/xmlstarlet-1.6.0-win32.zip/download', specificFolder: '', checksum:
 '', checksumType: '', checksum64: '', checksumType64: ''
DEBUG: Running 'Get-ChocolateyWebFile' for xmlstarlet with
url:'http://sourceforge.net/projects/xmlstar/files/xmlstarlet/1.6.0/xmlstarlet-1.6.0-win32.zip/download',
fileFullPath:'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip',
url64bit:'http://sourceforge.net/projects/xmlstar/files/xmlstarlet/1.6.0/xmlstarlet-1.6.0-win32.zip/download', checksum: '',
checksumType: '', checksum64: '', checksumType64: ''
DEBUG: Running 'Get-ProcessorBits'
DEBUG: CPU is 64 bit
DEBUG: Setting url to 'http://sourceforge.net/projects/xmlstar/files/xmlstarlet/1.6.0/xmlstarlet-1.6.0-win32.zip/download' and
bitPackage to 64
DEBUG: Running 'Get-WebHeaders' with
url:'http://sourceforge.net/projects/xmlstar/files/xmlstarlet/1.6.0/xmlstarlet-1.6.0-win32.zip/download', userAgent: 'chocolatey
command line'
DEBUG: Setting the UserAgent to 'chocolatey command line'
DEBUG: Web Headers Received:
DEBUG:   'Connection':'close'
DEBUG:   'Accept-Ranges':'bytes'
DEBUG:   'Content-Length':'1527204'
DEBUG:   'Content-Type':'application/octet-stream'
DEBUG:   'Date':'Tue, 04 Nov 2014 21:33:50 GMT'
DEBUG:   'ETag':'"539a60fe-174da4"'
DEBUG:   'Last-Modified':'Fri, 13 Jun 2014 02:25:02 GMT'
DEBUG:   'Server':'nginx'
DEBUG: xmlstarlet's requested file has already been downloaded. Using cached copy at
  'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip'.
DEBUG: Checking that 'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip' is the size we expect it to be.
DEBUG: Verifying package provided checksum of '' for 'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip'.
DEBUG: Running 'Get-CheckSumValid' with file:'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip',
checksum: '', checksumType: ''
DEBUG: Running 'Get-ChocolateyUnzip' with
fileFullPath:'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip'', destination:
'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0\tools', specificFolder: '`, packageName: 'xmlstarlet'
Extracting C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\xmlstarletInstall.zip to F:\Chocolatey\lib\xmlstarlet.portable.1.6.
0\tools...
DEBUG: wrapping 7za invocation with Write-FileUpdateLog
DEBUG: Running 'Write-FileUpdateLog' with logFilePath:'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0\xmlstarletInstall.zip.txt'',
locationToMonitor:F:\Chocolatey\lib\xmlstarlet.portable.1.6.0\tools, Operation: '
    param($7zip, $destination, $fileFullPath, [ref]$exitCodeRef)
$process = Start-Process $7zip -ArgumentList "x -o`"$destination`" -y `"$fileFullPath`"" -Wait -WindowStyle Hidden -PassThru
    # this is here for specific cases in Posh v3 where -Wait is not honored
    try { if (!($process.HasExited)) { Wait-Process $process } } catch { }

    $exitCodeRef.Value = $process.ExitCode
  '
DEBUG: Tracking current state of 'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0\tools'
Write-Error : xmlstarlet did not finish successfully. Boo to the chocolatey gods!
-----------------------
[ERROR] Process with an Id of 278388 is not running.
-----------------------
At F:\Chocolatey\chocolateyinstall\helpers\functions\Write-ChocolateyFailure.ps1:30 char:14
+   Write-Error <<<<  $errorMessage
    + CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
    + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Write-Error

Write-Error : xmlstarlet did not finish successfully. Boo to the chocolatey gods!
-----------------------
[ERROR] Process with an Id of 278388 is not running.
-----------------------
At F:\Chocolatey\chocolateyinstall\helpers\functions\Write-ChocolateyFailure.ps1:30 char:14
+   Write-Error <<<<  $errorMessage
    + CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
    + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Write-Error

DEBUG: Running 'Move-BadInstall' for xmlstarlet.portable version: '1.6.0',
packageFolder:'F:\Chocolatey\lib\xmlstarlet.portable.1.6.0'
DEBUG: Moving bad package 'xmlstarlet.portable v1.6.0' to 'F:\Chocolatey\lib-bad'.
Write-Error : Package 'xmlstarlet.portable v1.6.0' did not install successfully: Process with an Id of 278388 is not running.
At F:\Chocolatey\chocolateyinstall\functions\Chocolatey-NuGet.ps1:90 char:28
+                 Write-Error <<<<  "Package `'$installedPackageName v$installedPackageVersion`' did not install successfully: $($_
.Exception.Message)"
    + CategoryInfo          : NotSpecified: (:) [Write-Error], WriteErrorException
    + FullyQualifiedErrorId : Microsoft.PowerShell.Commands.WriteErrorException,Write-Error

DEBUG: Evaluating NuGet output for line: Installing 'xmlstarlet 1.6.0'.
DEBUG: Evaluating NuGet output for line: Successfully installed 'xmlstarlet 1.6.0'.
DEBUG: NuGet installed xmlstarlet. If we are ignoring dependencies (False) then we will clean this up.

xmlstarlet v1.6.0
DEBUG: Running 'Delete-ExistingErrorLog' for xmlstarlet
DEBUG: Looking for failure log at 'C:\Users\ken\AppData\Local\Temp\chocolatey\xmlstarlet\failure.log'
DEBUG: Found the failure log. Deleting it...
DEBUG: Running 'Run-ChocolateyPS1' for xmlstarlet with packageFolder:'F:\Chocolatey\lib\xmlstarlet.1.6.0', action: 'install'
DEBUG:   __ PowerShell install (chocolateyinstall.ps1) __
DEBUG:   Looking for chocolateyinstall.ps1 in folder 'F:\Chocolatey\lib\xmlstarlet.1.6.0'. If chocolateyinstall.ps1 is found, it
will be run.
DEBUG: Action file is 'chocolateyInstall.ps1'
DEBUG: Running 'F:\Chocolatey\lib\xmlstarlet.1.6.0\tools\chocolateyInstall.ps1'
DEBUG: Running 'Get-ChocolateyBins' for F:\Chocolatey\lib\xmlstarlet.1.6.0
DEBUG:   __ Executable Links (*.exe) __
DEBUG: Looking for executables in folder: F:\Chocolatey\lib\xmlstarlet.1.6.0
Adding batch files for any executables found to a location on PATH. In other words the executable will be available from ANY
command line/powershell prompt.
DEBUG: Found '' for batch redirect
DEBUG: There are no executables (that are not ignored) in the package.
DEBUG: Evaluating NuGet output for line:
Finished installing 'xmlstarlet' and dependencies - if errors not shown in console, none detected. Check log for errors if unsure.
@ferventcoder
Copy link
Contributor

@kaiaie what version of posh do you have installed on Win2008?

Also, we tweaked an issue with this in the current release (released a few hours ago - 0.9.8.28) - it's possible that you won't see the process id issues on the latest version.

@kaiaie
Copy link
Author

kaiaie commented Nov 5, 2014

@ferventcoder both machines are running PowerShell 2.0

I upgraded chocolatey on the Win7 box to 0.9.8.28 and tried reinstalling xmlstarlet but got the same error.

@ferventcoder
Copy link
Contributor

It looks like it is erroring on the line that tries to wait the process if it is still running (which has a try catch) but I think it might actually be something else. It's hard to say.

@ferventcoder
Copy link
Contributor

What happens if you try to install the app without chocolatey in the equation on one of the failing systems?

@kaiaie
Copy link
Author

kaiaie commented Nov 6, 2014

Installing the app without chocolatey is easy enough-- it's just a .zip file, no msi installer or anything (http://sourceforge.net/projects/xmlstar/files/). In other words, this is not a blocker for me, it's just odd that chocolatey fails for this one package on this one machine and works fine elsewhere...

ferventcoder added a commit to chocolatey/choco that referenced this issue Feb 20, 2015
This is chocolatey-archive/chocolatey#603.
Set the Error action preference to move on silently, then set it back
to what it was. This will allow the process wait check to fail without
any issues.
@ferventcoder
Copy link
Contributor

I believe I just fixed this - It will be testable in choco 0.9.9-rc8 and above.

@calvn
Copy link

calvn commented Jun 29, 2015

Seems that I am running into this issue with chocolatey 0.9.9.8

2015-06-29 15:30:22,809 [INFO ] - ============================================================
2015-06-29 15:30:22,809 [INFO ] - Chocolatey v0.9.9.8
2015-06-29 15:30:22,825 [DEBUG] - Chocolatey is running on Windows v 6.1.7601.65536
2015-06-29 15:30:22,825 [DEBUG] - Attempting to delete file "C:/ProgramData/chocolatey/choco.exe.old".
2015-06-29 15:30:22,825 [DEBUG] - Attempting to delete file "C:\ProgramData\chocolatey\choco.exe.old".
2015-06-29 15:30:22,825 [DEBUG] - Command line: "C:\ProgramData\chocolatey\choco.exe" install consul -version 0.5.2.2015052201 -dvy -source C:/Users/vagrant/AppData/Local/Temp
2015-06-29 15:30:22,825 [DEBUG] - Received arguments: install consul -version 0.5.2.2015052201 -dvy -source C:/Users/vagrant/AppData/Local/Temp
2015-06-29 15:30:22,872 [DEBUG] - 
NOTE: Hiding sensitive configuration data! Please double and triple 
 check to be sure no sensitive data is shown, especially if copying 
 output to a gist for review.
2015-06-29 15:30:22,887 [DEBUG] - Configuration: CommandName='install'|
CacheLocation='C:\Users\vagrant\AppData\Local\Temp'|
ContainsLegacyPackageInstalls='True'|
CommandExecutionTimeoutSeconds='2700'|
Sources='C:/Users/vagrant/AppData/Local/Temp'|Debug='True'|
Verbose='True'|Force='False'|Noop='False'|HelpRequested='False'|
RegularOutput='True'|PromptForConfirmation='False'|
AcceptLicense='True'|
AllowUnofficialBuild='False'|Input='consul'|Version='0.5.2.2015052201'|
AllVersions='False'|SkipPackageInstallProvider='False'|
PackageNames='consul'|Prerelease='False'|ForceX86='False'|
OverrideArguments='False'|NotSilent='False'|IgnoreDependencies='False'|
AllowMultipleVersions='False'|ForceDependencies='False'|
Information.PlatformType='Windows'|
Information.PlatformVersion='6.1.7601.65536'|
Information.PlatformName='Windows Server 2008 R2'|
Information.ChocolateyVersion='0.9.9.8'|
Information.ChocolateyProductVersion='0.9.9.8'|
Information.FullName='choco, Version=0.9.9.8, Culture=neutral, PublicKeyToken=79d02ea9cad655eb'|

Information.Is64Bit='True'|Information.IsInteractive='False'|
Information.IsUserAdministrator='True'|
Information.IsProcessElevated='True'|Features.AutoUninstaller='False'|
Features.CheckSumFiles='True'|Features.FailOnAutoUninstaller='False'|
ListCommand.LocalOnly='False'|
ListCommand.IncludeRegistryPrograms='False'|
UpgradeCommand.FailOnUnfound='False'|
UpgradeCommand.FailOnNotInstalled='False'|
UpgradeCommand.NotifyOnlyAvailableUpgrades='False'|
NewCommand.AutomaticPackage='False'|SourceCommand.Command='unknown'|
FeatureCommand.Command='unknown'|PushCommand.TimeoutInSeconds='0'|
PinCommand.Command='unknown'|
2015-06-29 15:30:22,887 [DEBUG] - _ Chocolatey:ChocolateyInstallCommand - Normal Run Mode _
2015-06-29 15:30:22,918 [INFO ] - Installing the following packages:
2015-06-29 15:30:22,918 [INFO ] - consul
2015-06-29 15:30:22,918 [INFO ] - By installing you accept licenses for the packages.
2015-06-29 15:30:23,231 [INFO ] - [NuGet] Installing 'consul 0.5.2.2015052201'.
2015-06-29 15:30:23,247 [DEBUG] - [NuGet] Added file '0.5.2_SHA256SUMS' to folder 'consul\binaries'.
2015-06-29 15:30:23,247 [DEBUG] - [NuGet] Added file '0.5.2_web_ui.zip' to folder 'consul\binaries'.
2015-06-29 15:30:23,247 [DEBUG] - [NuGet] Added file '0.5.2_windows_386.zip' to folder 'consul\binaries'.
2015-06-29 15:30:23,262 [DEBUG] - [NuGet] Added file 'nssm-2.24.zip' to folder 'consul\binaries'.
2015-06-29 15:30:23,262 [DEBUG] - [NuGet] Added file 'chocolateyInstall.ps1' to folder 'consul\tools'.
2015-06-29 15:30:23,262 [DEBUG] - [NuGet] Added file 'chocolateyUninstall.ps1' to folder 'consul\tools'.
2015-06-29 15:30:23,262 [DEBUG] - [NuGet] Added file 'consul.nupkg' to folder 'consul'.
2015-06-29 15:30:23,262 [INFO ] - [NuGet] Successfully installed 'consul 0.5.2.2015052201'.
2015-06-29 15:30:23,262 [INFO ] - 
consul v0.5.2.2015052201
2015-06-29 15:30:23,293 [DEBUG] - Contents of 'C:\ProgramData\chocolatey\lib\consul\tools\chocolateyInstall.ps1':
2015-06-29 15:30:23,309 [DEBUG] - try {
  $binariesPath = $(Join-Path (Split-Path -parent $MyInvocation.MyCommand.Definition) "..\binaries\")
  $toolsPath = (Split-Path -Parent $MyInvocation.MyCommand.Definition)

  # NSSM related variables
  $nssmVersion = '2.24'
  $nssmSourcePath = $(Join-Path $binariesPath "nssm-$nssmVersion.zip")

  # Consul related variables
  $consulVersion = '0.5.2'
  $sourcePath = $(Join-Path $binariesPath "$($consulVersion)_windows_386.zip")
  $sourcePathUI = $(Join-Path $binariesPath "$($consulVersion)_web_ui.zip")

  # Install NSSM locally within consul
  Get-ChocolateyUnzip $nssmSourcePath $toolsPath

  $folderToIgnore = 'win32'
  $forderToRun = 'win64'

  if (Get-ProcessorBits 32) {
    $folderToIgnore = 'win64'
    $forderToRun = 'win32'
  }

  Set-Content -Path ($toolsPath + "\nssm-$nssmVersion\$folderToIgnore\nssm.exe.ignore") -Value $null
  $nssmBinPath = ($toolsPath + "\nssm-$nssmVersion\$forderToRun\nssm.exe")

  # Unzip and move Consul
  Get-ChocolateyUnzip  $sourcePath "$(Split-Path -parent $MyInvocation.MyCommand.Definition)"
  Get-ChocolateyUnzip  $sourcePathUI "$(Split-Path -parent $MyInvocation.MyCommand.Definition)"

  Write-Host "Creating $env:PROGRAMDATA\consul\logs"
  New-Item -ItemType directory -Path "$env:PROGRAMDATA\consul\logs" -ErrorAction SilentlyContinue | Out-Null
  Write-Host "Creating $env:PROGRAMDATA\consul\config"
  New-Item -ItemType directory -Path "$env:PROGRAMDATA\consul\config" -ErrorAction SilentlyContinue | Out-Null

  # Create event log source
  # User -Force to avoid "A key at this path already exists" exception. Overwrite not an issue since key is not further modified
  $registryPath = 'HKLM:\SYSTEM\CurrentControlSet\services\eventlog\Application'
  New-Item -Path $registryPath -Name consul -Force | Out-Null
  # Set EventMessageFile value
  Set-ItemProperty $registryPath\consul EventMessageFile "C:\Windows\Microsoft.NET\Framework64\v2.0.50727\EventLogMessages.dll" | Out-Null


  #Uninstall service if it already exists. Stops the service first if it's running
  $service = Get-Service "consul" -ErrorAction SilentlyContinue
  if ($service) {
    Write-Host "Uninstalling existing service"
    if ($service.Status -eq "Running") {
      Write-Host "Stopping consul process ..."
      net stop consul | Out-Null
    }

    $service = Get-WmiObject -Class Win32_Service -Filter "Name='consul'"
    $service.delete() | Out-Null
  }

  Write-Host "Installing the consul service"
  # Install the service
  & $nssmBinPath install consul $(Join-Path $toolsPath "consul.exe") agent -config-dir=%PROGRAMDATA%\consul\config -data-dir=%PROGRAMDATA%\consul\data | Out-Null
  & $nssmBinPath set consul AppEnvironmentExtra GOMAXPROCS=$env:NUMBER_OF_PROCESSORS | Out-Null
  & $nssmBinPath set consul ObjectName NetworkService | Out-Null
  & $nssmBinPath set consul AppStdout "$env:PROGRAMDATA\consul\logs\consul-output.log" | Out-Null
  & $nssmBinPath set consul AppStderr "$env:PROGRAMDATA\consul\logs\consul-error.log" | Out-Null
  & $nssmBinPath set consul AppRotateBytes 10485760 | Out-Null
  & $nssmBinPath set consul AppRotateFiles 1 | Out-Null
  & $nssmBinPath set consul AppRotateOnline 1 | Out-Null

  # Restart service on failure natively via Windows sc. There is a memory leak if service restart is performed via NSSM
  # The NSSM configuration will set the default behavior of NSSM to stop the service if
  # consul fails (for example, unable to resolve cluster) and end the nssm.exe and consul.exe process.
  # The sc configuration will set Recovery under the Consul service properties such that a new instance will be started on failure,
  # spawning new nssm.exe and consul.exe processes. In short, nothing changed from a functionality perspective (the service will
  # still attempt to restart on failure) but this method kills the nssm.exe process thus avoiding memory hog.
  & $nssmBinPath set consul AppExit Default Exit | Out-Null
  cmd.exe /c "sc failure consul reset= 0 actions= restart/60000" | Out-Null

  Write-ChocolateySuccess 'consul'
} catch {
  Write-ChocolateyFailure 'consul' $($_.Exception.Message)
  throw
}

2015-06-29 15:30:23,309 [DEBUG] - Calling command ['"C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe" -NoProfile -NoLogo -ExecutionPolicy Bypass -Command "[System.Threading.Thread]::CurrentThread.CurrentCulture = '';[System.Threading.Thread]::CurrentThread.CurrentUICulture = ''; & import-module -name 'C:\ProgramData\chocolatey\helpers\chocolateyInstaller.psm1'; & 'C:\ProgramData\chocolatey\helpers\chocolateyScriptRunner.ps1' -packageScript 'C:\ProgramData\chocolatey\lib\consul\tools\chocolateyInstall.ps1' -installArguments '' -packageParameters ''"']
2015-06-29 15:30:23,950 [ERROR] -  Process with an Id of 2984 is not running.
2015-06-29 15:30:23,950 [DEBUG] -  DEBUG: Posh version is 2.0
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-BinRoot'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-ChecksumValid'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-ChocolateyUnzip'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-ChocolateyWebFile'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-EnvironmentVariable'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-EnvironmentVariableNames'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-FtpFile'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-ProcessorBits'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-UACEnabled'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-VirusCheckValid'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-WebFile'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Get-WebHeaders'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-BinFile'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyDesktopLink'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyEnvironmentVariable'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyExplorerMenuItem'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyFileAssociation'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyInstallPackage'.
2015-06-29 15:30:23,950 [ERROR] -  At C:\ProgramData\chocolatey\helpers\functions\Write-ChocolateyFailure.ps1:24 c
2015-06-29 15:30:23,950 [ERROR] -  har:8
2015-06-29 15:30:23,950 [ERROR] -  +   throw <<<<  "$failureMessage"
2015-06-29 15:30:23,950 [ERROR] -      + CategoryInfo          : OperationStopped: (Process with an...is not runn 
2015-06-29 15:30:23,950 [ERROR] -     ing.:String) [], RuntimeException
2015-06-29 15:30:23,950 [ERROR] -      + FullyQualifiedErrorId : Process with an Id of 2984 is not running.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyPackage'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyPath'.
2015-06-29 15:30:23,950 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyPinnedTaskBarItem'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyPowershellCommand'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyShortcut'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyVsixPackage'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Install-Vsix'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Install-ChocolateyZipPackage'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Set-EnvironmentVariable'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Start-ChocolateyProcessAsAdmin'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Test-ProcessAdminRights'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Uninstall-BinFile'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Uninstall-ChocolateyPackage'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'UnInstall-ChocolateyZipPackage'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Update-SessionEnvironment'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Write-ChocolateyFailure'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Write-ChocolateySuccess'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting function 'Write-FileUpdateLog'.
2015-06-29 15:30:23,965 [INFO ] -  VERBOSE: Exporting alias 'Generate-BinFile'.
2015-06-29 15:30:23,997 [INFO ] -  VERBOSE: Exporting alias 'Add-BinFile'.
2015-06-29 15:30:23,997 [INFO ] -  VERBOSE: Exporting alias 'Remove-BinFile'.
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: Running 'Get-ChocolateyUnzip' with 
2015-06-29 15:30:23,997 [INFO ] -  fileFullPath:'C:\ProgramData\chocolatey\lib\consul\tools\..\binaries\nssm-2.24.
2015-06-29 15:30:23,997 [INFO ] -  zip'', destination: 'C:\ProgramData\chocolatey\lib\consul\tools', 
2015-06-29 15:30:23,997 [INFO ] -  specificFolder: '`, packageName: ''
2015-06-29 15:30:23,997 [INFO ] -  Extracting C:\ProgramData\chocolatey\lib\consul\tools\..\binaries\nssm-2.24.zip to C:\ProgramData\chocolatey\lib\consul\tools...
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: 7zip found at 'C:\ProgramData\chocolatey\tools\7za.exe'
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: calling 7za directly
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: Calling 'C:\ProgramData\chocolatey\tools\7za.exe x -aoa 
2015-06-29 15:30:23,997 [INFO ] -  -o"C:\ProgramData\chocolatey\lib\consul\tools" -y 
2015-06-29 15:30:23,997 [INFO ] -  "C:\ProgramData\chocolatey\lib\consul\tools\..\binaries\nssm-2.24.zip"'
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: 7za exit code: 0
2015-06-29 15:30:23,997 [INFO ] -  C:\ProgramData\chocolatey\lib\consul\tools
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: Running 'Get-ProcessorBits'
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: Running 'Get-ChocolateyUnzip' with 
2015-06-29 15:30:23,997 [INFO ] -  fileFullPath:'C:\ProgramData\chocolatey\lib\consul\tools\..\binaries\0.5.2_wind
2015-06-29 15:30:23,997 [INFO ] -  ows_386.zip'', destination: 'C:\ProgramData\chocolatey\lib\consul\tools', 
2015-06-29 15:30:23,997 [INFO ] -  specificFolder: '`, packageName: ''
2015-06-29 15:30:23,997 [INFO ] -  Extracting C:\ProgramData\chocolatey\lib\consul\tools\..\binaries\0.5.2_windows_386.zip to C:\ProgramData\chocolatey\lib\consul\tools...
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: 7zip found at 'C:\ProgramData\chocolatey\tools\7za.exe'
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: calling 7za directly
2015-06-29 15:30:23,997 [DEBUG] -  DEBUG: Calling 'C:\ProgramData\chocolatey\tools\7za.exe x -aoa 
2015-06-29 15:30:23,997 [INFO ] -  -o"C:\ProgramData\chocolatey\lib\consul\tools" -y 
2015-06-29 15:30:23,997 [INFO ] -  "C:\ProgramData\chocolatey\lib\consul\tools\..\binaries\0.5.2_windows_386.zip"'
2015-06-29 15:30:24,012 [WARN ] -  WARNING: Write-ChocolateyFailure is deprecated. If you are the package 
2015-06-29 15:30:24,012 [INFO ] -  maintainer, please use 'throw $_.Exception' instead.
2015-06-29 15:30:24,012 [DEBUG] - Command ['"C:\Windows\System32\WindowsPowerShell\v1.0\powershell.exe" -NoProfile -NoLogo -ExecutionPolicy Bypass -Command "[System.Threading.Thread]::CurrentThread.CurrentCulture = '';[System.Threading.Thread]::CurrentThread.CurrentUICulture = ''; & import-module -name 'C:\ProgramData\chocolatey\helpers\chocolateyInstaller.psm1'; & 'C:\ProgramData\chocolatey\helpers\chocolateyScriptRunner.ps1' -packageScript 'C:\ProgramData\chocolatey\lib\consul\tools\chocolateyInstall.ps1' -installArguments '' -packageParameters ''"'] exited with '1'
2015-06-29 15:30:24,012 [DEBUG] - Calling command ['"shutdown" /a']
2015-06-29 15:30:24,028 [DEBUG] - Command ['"shutdown" /a'] exited with '1116'
2015-06-29 15:30:24,043 [DEBUG] - Capturing package files in 'C:\ProgramData\chocolatey\lib\consul'
2015-06-29 15:30:24,075 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\consul.nupkg'
  with checksum '66A13E5A10A7E7CA1B20EFF2EA2208AC'
2015-06-29 15:30:24,075 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\binaries\0.5.2_SHA256SUMS'
  with checksum '63289EDFB26AFB48E0E4CD8110629D01'
2015-06-29 15:30:24,075 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\binaries\0.5.2_web_ui.zip'
  with checksum 'EB98BA602BC7E177333EB2E520881F4F'
2015-06-29 15:30:24,090 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\binaries\0.5.2_windows_386.zip'
  with checksum 'D5DE018E601DB10850F89C1E81559D4A'
2015-06-29 15:30:24,090 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\binaries\nssm-2.24.zip'
  with checksum 'B2EDD0E4A7A7BE9D157C0DA0EF65B1BC'
2015-06-29 15:30:24,090 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\chocolateyInstall.ps1'
  with checksum '60F66EE4FE81706134EB5E8E2072EA65'
2015-06-29 15:30:24,090 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\chocolateyUninstall.ps1'
  with checksum 'D3507DFEF5209948F073295CF6484F6B'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\consul.exe'
  with checksum '974432CDFFAF53462789D8A87ED4D518'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\ChangeLog.txt'
  with checksum '205769831FA302018FB26845D3835962'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\README.txt'
  with checksum 'ED2BC805600C380E85FE240E715ABB81'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\account.cpp'
  with checksum 'B432CC0EDDB92622E68C16944EF65E98'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\account.h'
  with checksum 'C1B1DCFDCE66CB24B458B0F34278C8DB'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\console.cpp'
  with checksum '2B504E046DC126E68BFC90056B2C9E60'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\console.h'
  with checksum '9E242CCE5F18C22854F7E417171E5E67'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\env.cpp'
  with checksum 'F49F53D2A1527B35258B33773D048B9C'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\env.h'
  with checksum 'F3C5C5EC2AEAFA00FF4C2FBE5622521C'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\event.cpp'
  with checksum '53CA1240B593D6277E58A9D3334B537C'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\event.h'
  with checksum 'BD2D50FA5FBBB97285F9984E6CD1E4D4'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\gui.cpp'
  with checksum '87A2C4762F8F544056F223315F6F8A90'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\gui.h'
  with checksum 'A015F901E2ECE542EC8DA0D62A2DEC91'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\imports.cpp'
  with checksum 'B3841F61DF8EAAE6503C4535FFFA2678'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\imports.h'
  with checksum 'BEA805FC9BD24E29F911B4C8AF2E1C67'
2015-06-29 15:30:24,137 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\io.cpp'
  with checksum '4A0F774542B30B8D2F89B16A52F4E180'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\io.h'
  with checksum 'D38837B657FD6110F6DFCC464CB5A28A'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\messages.mc'
  with checksum '8CE6DC904ADF43A36CC1874B56FE10E5'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\nssm.cpp'
  with checksum '4C6D4F21F01D8EA96856B9BE08819006'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\nssm.h'
  with checksum '489522C3667DE3BAF5F28A66DD684005'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\nssm.ico'
  with checksum '4288408C2D7F43FBD9D920C8319F1956'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\nssm.rc'
  with checksum 'FFACD065D645999917FF340D7C7E9EE0'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\nssm.sln'
  with checksum 'F779189B1586DFA1D64F9279AD8E23EC'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\nssm.vcproj'
  with checksum '6E6FABD941F67804A55F5D9EE21A7E11'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\process.cpp'
  with checksum 'E58E6825766F138869E72B66085C0758'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\process.h'
  with checksum '7D2B1A9335864BB2C334273FE40CF732'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\registry.cpp'
  with checksum '445B79BFC0A559C5CF4C048C54218566'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\registry.h'
  with checksum '12766774BADE41953CA460AE72168F1B'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\resource.h'
  with checksum 'A06FEE0B96D7CD81E1B0A9CB9E359396'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\service.cpp'
  with checksum '95FB7517F1606492A69D3B3DDEC9C01D'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\service.h'
  with checksum 'E317D08FBC98329115C47D8095190D83'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\settings.cpp'
  with checksum '762C0AC39328C797AECEF896A1319877'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\settings.h'
  with checksum '92BFCAF191385245DF8A907C7DD27E3E'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\src\version.cmd'
  with checksum '3E67B67B2ECB2D3042DFAA7D216883B1'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\win32\nssm.exe'
  with checksum 'D9EC6F3A3B2AC7CD5EEF07BD86E3EFBC'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\win32\nssm.exe.ignore'
  with checksum 'D41D8CD98F00B204E9800998ECF8427E'
2015-06-29 15:30:24,153 [DEBUG] -  Found 'C:\ProgramData\chocolatey\lib\consul\tools\nssm-2.24\win64\nssm.exe'
  with checksum 'BECEAE2FDC4F7729A93E94AC2CCD78CC'
2015-06-29 15:30:24,153 [DEBUG] - Attempting to create directory "C:\ProgramData\chocolatey\.chocolatey".
2015-06-29 15:30:24,168 [DEBUG] - Attempting to create directory "C:\ProgramData\chocolatey\.chocolatey\consul.0.5.2.2015052201".
2015-06-29 15:30:24,215 [DEBUG] - Attempting to delete file "C:\ProgramData\chocolatey\.chocolatey\consul.0.5.2.2015052201\.sxs".
2015-06-29 15:30:24,215 [DEBUG] - Attempting to delete file "C:\ProgramData\chocolatey\.chocolatey\consul.0.5.2.2015052201\.pin".
2015-06-29 15:30:24,231 [ERROR] - The install of consul was NOT successful.
2015-06-29 15:30:24,231 [ERROR] - Error while running 'C:\ProgramData\chocolatey\lib\consul\tools\chocolateyInstall.ps1'.
 See log for details.
2015-06-29 15:30:24,231 [DEBUG] - Attempting to create directory "C:\ProgramData\chocolatey\lib-bad".
2015-06-29 15:30:24,231 [DEBUG] - Moving 'C:\ProgramData\chocolatey\lib\consul'
 to 'C:\ProgramData\chocolatey\lib-bad\consul'
2015-06-29 15:30:26,231 [WARN ] - 
Chocolatey installed 0/1 package(s). 1 package(s) failed.
 See the log for details (C:\ProgramData\chocolatey\logs\chocolatey.log).
2015-06-29 15:30:26,231 [ERROR] - Failures:
2015-06-29 15:30:26,231 [ERROR] -  - consul
2015-06-29 15:30:26,231 [DEBUG] - Exiting with 1

@ferventcoder
Copy link
Contributor

@cleung2010 I see how this may look like a similar issue but it doesn't appear to be. You may want to remove the try catch from around the chocolatey script so you get a better handle on where the error is occurring. It looks like something in the package itself. Also any issues with choco belong at https://github.com/chocolatey/choco/issues, not over here. Thanks!

@calvn
Copy link

calvn commented Jun 30, 2015

@ferventcoder the issue is not from the package, as it works perfectly on 0.9.8.27 which is before changes to Get-ChocolateyUnzip.ps1 were made. In any case, I'll open a new issue, but I've pinned to using 0.9.8.27 for the moment.

@ferventcoder
Copy link
Contributor

@cleung2010 thanks, I will follow up over there.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

3 participants