salt provisioning on windows guest broken?

[Oliver Bestwalter]

Hi,

I dug through the posts here and the open issues on github, but can't find this specific problem. The only bug I found that might have to do with this is: https://github.com/mitchellh/vagrant/issues/5313 (saltstack bootstrap script is always downloaded and run on provision, regardless it is installed already or not).

So here goes:

provider: VirtualBox

Host: Linux (Ubuntu 14.04)

Guest: Windows Server 2008 R2

Vagrantfile: (see end of this post)

I created the box following this tutorial: https://dennypc.wordpress.com/2014/06/09/creating-a-windows-box-with-vagrant-1-6/

Now I am trying to add provisioning with salt and I get this error on running salt.

############### (hopefully) relevant part of debug log from first vagrant up ####################

==> default: Running provisioner: salt...

 INFO environment: Running hook: provisioner_run

 INFO runner: Preparing hooks for middleware sequence...

 INFO runner: 1 hooks defined.

 INFO runner: Running action: #<Method: Vagrant::Action::Builtin::Provision#run_provisioner>

 INFO warden: Calling IN action: #<Proc:0x007f8e40a1d800@/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/lib/vagrant/action/warden.rb:94 (lambda)>

 INFO interface: info: Copying salt minion config to vm.

Copying salt minion config to vm.

 INFO winrm: Uploading: /home/obestwalter/work/prodenv/vagrant_winbox/salt/minion to C:\tmp/minion

DEBUG filemanager: Upload: /home/obestwalter/work/prodenv/vagrant_winbox/salt/minion -> C:\tmp/minion

DEBUG winrmshell: powershell executing:

          $dest_file_path = [System.IO.Path]::GetFullPath('C:\tmp/minion')

          if (Test-Path $dest_file_path) {

            $crypto_provider = new-object -TypeName System.Security.Cryptography.MD5CryptoServiceProvider

            try {

              $file = [System.IO.File]::Open($dest_file_path, [System.IO.Filemode]::Open, [System.IO.FileAccess]::Read)

              $guest_md5 = ([System.BitConverter]::ToString($crypto_provider.ComputeHash($file))).Replace("-","").ToLower()

            }

            finally {

              $file.Dispose()

            }

            if ($guest_md5 -eq 'b3093528507e3684b1ed4623e449848c') {

              exit 0

            }

          }

          Write-Host "should upload file $dest_file_path"

          exit 1

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[{:stdout=>"should upload file C:\\tmp\\minion"}, {:stdout=>"\n"}], :exitcode=>1}

DEBUG winrmshell: cmd executing:

echo %TEMP%

DEBUG winrmshell: Output: {:data=>[{:stdout=>"C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\r\n"}], :exitcode=>0}

DEBUG filemanager: Uploading '/home/obestwalter/work/prodenv/vagrant_winbox/salt/minion' to temp file 'C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.7808051803959843'

DEBUG winrmshell: cmd executing:

echo IyBXQVJOSU5HIFRISVMgQ09ORklHIElTIEpVU1QgRk9SIFZBR1JBTlQhCgpmaWxlX2NsaWVudDogbG9jYWwKbG9nX2xldmVsOiBpbmZvCnN0YXRlX291dHB1dDogbWl4ZWQKCg== >> "C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.7808051803959843"

DEBUG winrmshell: Output: {:data=>[], :exitcode=>0}

DEBUG filemanager: Decoding temp file 'C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.7808051803959843' to 'C:\tmp/minion'

DEBUG winrmshell: powershell executing:

          $tmp_file_path = [System.IO.Path]::GetFullPath('C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.7808051803959843')

          $dest_file_path = [System.IO.Path]::GetFullPath('C:\tmp/minion')

          if (Test-Path $dest_file_path) {

            rm $dest_file_path

          }

          else {

            $dest_dir = ([System.IO.Path]::GetDirectoryName($dest_file_path))

            New-Item -ItemType directory -Force -Path $dest_dir

          }

          $base64_string = Get-Content $tmp_file_path

          $bytes = [System.Convert]::FromBase64String($base64_string) 

          [System.IO.File]::WriteAllBytes($dest_file_path, $bytes)

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[{:stdout=>"\r\n"}, {:stdout=>"\r\n"}, {:stdout=>"    Directory: C:\\"}, {:stdout=>"\r\n\r\n\r\n"}, {:stdout=>"Mode                LastWriteTime     Length Name                              \r\n"}, {:stdout=>"----                -------------     ------ ----                              \r\nd----        13.04.2015     14:34            tmp                               \r\n"}], :exitcode=>0}

 INFO interface: info: Checking if C:\salt\salt-minion.exe is installed

Checking if C:\salt\salt-minion.exe is installed

DEBUG winrmshell: powershell executing:

            $command = [Array](Get-Command C:\salt\salt-minion.exe -errorAction SilentlyContinue)

            if ($null -eq $command) { exit 1 }

            write-host $command[0].Definition

            exit 0

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[], :exitcode=>1}

 INFO interface: info: C:\salt\salt-minion.exe was not found.

C:\salt\salt-minion.exe was not found.

 INFO interface: info: Checking if C:\salt\salt-call.exe is installed

Checking if C:\salt\salt-call.exe is installed

DEBUG winrmshell: powershell executing:

            $command = [Array](Get-Command C:\salt\salt-call.exe -errorAction SilentlyContinue)

            if ($null -eq $command) { exit 1 }

            write-host $command[0].Definition

            exit 0

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[], :exitcode=>1}

 INFO interface: info: C:\salt\salt-call.exe was not found.

C:\salt\salt-call.exe was not found.

 INFO interface: info: Bootstrapping Salt... (this may take a while)

Bootstrapping Salt... (this may take a while)

DEBUG winrmshell: powershell executing:

            $p = "C:\tmp/bootstrap_salt.ps1"

            if ((Test-Path $p) -and (!(get-item $p).PSIsContainer)) {

              exit 0

            }

            exit 1

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[], :exitcode=>1}

 INFO winrm: Uploading: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/salt/bootstrap-salt.ps1 to C:\tmp/bootstrap_salt.ps1

DEBUG filemanager: Upload: /opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/salt/bootstrap-salt.ps1 -> C:\tmp/bootstrap_salt.ps1

DEBUG winrmshell: powershell executing:

          $dest_file_path = [System.IO.Path]::GetFullPath('C:\tmp/bootstrap_salt.ps1')

          if (Test-Path $dest_file_path) {

            $crypto_provider = new-object -TypeName System.Security.Cryptography.MD5CryptoServiceProvider

            try {

              $file = [System.IO.File]::Open($dest_file_path, [System.IO.Filemode]::Open, [System.IO.FileAccess]::Read)

              $guest_md5 = ([System.BitConverter]::ToString($crypto_provider.ComputeHash($file))).Replace("-","").ToLower()

            }

            finally {

              $file.Dispose()

            }

            if ($guest_md5 -eq 'c7d8762ae87333a423f1d68b2e08f585') {

              exit 0

            }

          }

          Write-Host "should upload file $dest_file_path"

          exit 1

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[{:stdout=>"should upload file C:\\tmp\\bootstrap_salt.ps1"}, {:stdout=>"\n"}], :exitcode=>1}

DEBUG winrmshell: cmd executing:

echo %TEMP%

DEBUG winrmshell: Output: {:data=>[{:stdout=>"C:\\Users\\ADMINI~1\\AppData\\Local\\Temp\r\n"}], :exitcode=>0}

DEBUG filemanager: Uploading '/opt/vagrant/embedded/gems/gems/vagrant-1.7.2/plugins/provisioners/salt/bootstrap-salt.ps1' to temp file 'C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.29892565979715235'

DEBUG winrmshell: cmd executing:

echo IyBTYWx0IHZlcnNpb24gdG8gaW5zdGFsbAokdmVyc2lvbiA9ICcyMDE0LjEuMTAnCgojIENyZWF0ZSBDOlx0bXBcIC0gaWYgVmFncmFudCBkb2Vzbid0IHVwbG9hZCBrZXlzIGFuZC9vciBjb25maWcgaXQgbWlnaHQgbm90IGV4aXN0Ck5ldy1JdGVtIEM6XHRtcFwgLUl0ZW1UeXBlIGRpcmVjdG9yeSB8IG91dC1udWxsCgojIENvcHkgbWluaW9uIGtleXMgJiBjb25maWcgdG8gY29ycmVjdCBsb2NhdGlvbgpOZXctSXRlbSBDOlxzYWx0XGNvbmZccGtpXG1pbmlvblwgLUl0ZW1UeXBlIGRpcmVjdG9yeSB8IG91dC1udWxsCgojIENoZWNrIGlmIG1pbmlvbiBrZXlzIGhhdmUgYmVlbiB1cGxvYWRlZAppZiAoVGVzdC1QYXRoIEM6XHRtcFxtaW5pb24ucGVtKSB7CiAgY3AgQzpcdG1wXG1pbmlvbi5wZW0gQzpcc2FsdFxjb25mXHBraVxtaW5pb25cCiAgY3AgQzpcdG1wXG1pbmlvbi5wdWIgQzpcc2FsdFxjb25mXHBraVxtaW5pb25cCn0KCiMgQ2hlY2sgaWYgbWluaW9uIGNvbmZpZyBoYXMgYmVlbiB1cGxvYWRlZAppZiAoVGVzdC1QYXRoIEM6XHRtcFxtaW5pb24pIHsKICBjcCBDOlx0bXBcbWluaW9uIEM6XHNhbHRcY29uZlwKfQoKIyBEZXRlY3QgYXJjaGl0ZWN0dXJlCmlmIChbSW50UHRyXTo6U2l6ZSAtZXEgNCkgewogICRhcmNoID0gIndpbjMyIgp9IGVsc2UgewogICRhcmNoID0gIkFNRDY0Igp9CgojIERvd25sb2FkIG1pbmlvbiBzZXR1cCBmaWxlCldyaXRlLUhvc3QgIkRvd25sb2FkaW5nIFNhbHQgbWluaW9uIGluc3RhbGxlciAoJGFyY2gpLi4uIgokd2ViY2xpZW50ID0gTmV3LU9iamVjdCBTeXN0ZW0uTmV0LldlYkNsaWVudAokdXJsID0gImh0dHBzOi8vZG9jcy5zYWx0c3RhY2suY29tL2Rvd25sb2Fkcy9TYWx0LU1pbmlvbi0kdmVyc2lvbi0kYXJjaC1TZXR1cC5leGUiCiRmaWxlID0gIkM6XHRtcFxzYWx0LmV4ZSIKJHdlYmNsaWVudC5Eb3dubG9hZEZpbGUoJHVybCwgJGZpbGUpCgojIEluc3RhbGwgbWluaW9uIHNpbGVudGx5CldyaXRlLUhvc3QgIkluc3RhbGxpbmcgU2FsdCBtaW5pb24uLi4iCkM6XHRtcFxzYWx0LmV4ZSAvUwoKIyBXYWl0IGZvciBzYWx0LW1pbmlvbiBzZXJ2aWNlIHRvIGJlIHJlZ2lzdGVyZWQgYmVmb3JlIHRyeWluZyB0byBzdGFydCBpdAokc2VydmljZSA9IEdldC1TZXJ2aWNlIHNhbHQtbWluaW9uIC1FcnJvckFjdGlvbiBTaWxlbnRseUNvbnRpbnVlCldoaWxlICghJHNlcnZpY2UpIHsKICBTdGFydC1TbGVlcCAtcyAyCiAgJHNlcnZpY2UgPSBHZXQtU2VydmljZSBzYWx0LW1pbmlvbiAtRXJyb3JBY3Rpb24gU2lsZW50bHlDb250aW51ZQp9CgojIFN0YXJ0IHNlcnZpY2UKU3RhcnQtU2VydmljZSAtTmFtZSAic2FsdC1taW5pb24iIC1FcnJvckFjdGlvbiBTaWxlbnRseUNvbnRpbnVlCgojIENoZWNrIGlmIHNlcnZpY2UgaXMgc3RhcnRlZCwgb3RoZXJ3aXNlIHJldHJ5IHN0YXJ0aW5nIHRoZSAKIyBzZXJ2aWNlIDQgdGltZXMuCiR0cnkgPSAwCldoaWxlICgoJHNlcnZpY2UuU3RhdHVzIC1uZSAiUnVubmluZyIpIC1hbmQgKCR0cnkgLW5lIDQpKSB7CiAgU3RhcnQtU2VydmljZSAtTmFtZSAic2FsdC1taW5pb24iIC1FcnJvckFjdGlvbiBTaWxlbnRseUNvbnRpbnVlCiAgJHNlcnZpY2UgPSBHZXQtU2VydmljZSBzYWx0LW1pbmlvbiAtRXJyb3JBY3Rpb24gU2lsZW50bHlDb250aW51ZQogIFN0YXJ0LVNsZWVwIC1zIDIKICAkdHJ5ICs9IDEKfQoKIyBJZiB0aGUgc2FsdC1taW5pb24gc2VydmljZSBpcyBzdGlsbCBub3QgcnVubmluZywgc29tZXRoaW5nIHByb2JhYmx5CiMgd2VudCB3cm9uZyBhbmQgdXNlciBpbnRlcnZlbnRpb24gaXMgcmVxdWlyZWQgLSByZXBvcnQgZmFpbHVyZS4KaWYgKCRzZXJ2aWNlLlN0YXR1cyAtZXEgIlN0b3BwZWQiKSB7CiAgV3JpdGUtSG9zdCAiRmFpbGVkIHRvIHN0YXJ0IFNhbHQgbWluaW9uIgogIGV4aXQgMQp9CgpXcml0ZS1Ib3N0ICJTYWx0IG1pbmlvbiBzdWNjZXNzZnVsbHkgaW5zdGFsbGVkIgo= >> "C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.29892565979715235"

DEBUG winrmshell: Output: {:data=>[], :exitcode=>0}

DEBUG filemanager: Decoding temp file 'C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.29892565979715235' to 'C:\tmp/bootstrap_salt.ps1'

DEBUG winrmshell: powershell executing:

          $tmp_file_path = [System.IO.Path]::GetFullPath('C:\Users\ADMINI~1\AppData\Local\Temp/winrm-upload-0.29892565979715235')

          $dest_file_path = [System.IO.Path]::GetFullPath('C:\tmp/bootstrap_salt.ps1')

          if (Test-Path $dest_file_path) {

            rm $dest_file_path

          }

          else {

            $dest_dir = ([System.IO.Path]::GetDirectoryName($dest_file_path))

            New-Item -ItemType directory -Force -Path $dest_dir

          }

          $base64_string = Get-Content $tmp_file_path

          $bytes = [System.Convert]::FromBase64String($base64_string) 

          [System.IO.File]::WriteAllBytes($dest_file_path, $bytes)

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[{:stdout=>"\r\n"}, {:stdout=>"\r\n"}, {:stdout=>"    Directory: C:\\"}, {:stdout=>"\r\n\r\n\r\n"}, {:stdout=>"Mode                LastWriteTime     Length Name                              "}, {:stdout=>"\r\n----                -------------     ------ ----                              \r\n"}, {:stdout=>"d----        13.04.2015     14:34            tmp                               \r\n"}], :exitcode=>0}

DEBUG winrmshell: powershell executing:

powershell.exe -executionpolicy bypass -file C:\tmp/bootstrap_salt.ps1

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

DEBUG winrmshell: Output: {:data=>[{:stderr=>"New-Item : Item with specified name C:\\tmp\\ already exists.\r\n"}, {:stderr=>"At C:\\tmp\\bootstrap_salt.ps1:5 char:9\r\n"}, {:stderr=>"+ New-Item <<<<  C:\\tmp\\ -ItemType directory | out-null\r\n    + CategoryInfo          : ResourceExists: (C:\\tmp\\:String) [New-Item], IOE \r\n   xception\r\n    + FullyQualifiedErrorId : DirectoryExist,Microsoft.PowerShell.Commands.New \r\n   ItemCommand\r\n \r\n"}, {:stdout=>"Downloading Salt minion installer (AMD64)..."}, {:stdout=>"\n"}, {:stdout=>"Installing Salt minion..."}, {:stdout=>"\n"}, {:stdout=>"Failed to start Salt minion"}, {:stdout=>"\n"}], :exitcode=>1}

ERROR warden: Error occurred: The following WinRM command responded with a non-zero exit status.

Vagrant assumes that this means the command failed!

powershell.exe -executionpolicy bypass -file C:\tmp/bootstrap_salt.ps1

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

Stdout from the command:

Stderr from the command:

New-Item : Item with specified name C:\tmp\ already exists.

At C:\tmp\bootstrap_salt.ps1:5 char:9

+ New-Item <<<<  C:\tmp\ -ItemType directory | out-null

    + CategoryInfo          : ResourceExists: (C:\tmp\:String) [New-Item], IOE 

   xception

    + FullyQualifiedErrorId : DirectoryExist,Microsoft.PowerShell.Commands.New 

   ItemCommand

 

 INFO warden: Beginning recovery process...

 INFO warden: Recovery complete.

ERROR warden: Error occurred: The following WinRM command responded with a non-zero exit status.

Vagrant assumes that this means the command failed!

powershell.exe -executionpolicy bypass -file C:\tmp/bootstrap_salt.ps1

if ($?) { exit 0 } else { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } }

Stdout from the command:

Stderr from the command:

New-Item : Item with specified name C:\tmp\ already exists.

At C:\tmp\bootstrap_salt.ps1:5 char:9

+ New-Item <<<<  C:\tmp\ -ItemType directory | out-null

    + CategoryInfo          : ResourceExists: (C:\tmp\:String) [New-Item], IOE 

   xception

    + FullyQualifiedErrorId : DirectoryExist,Microsoft.PowerShell.Commands.New 

   ItemCommand

 

 INFO warden: Beginning recovery process...

 INFO warden: Calling recover: #<Vagrant::Action::Builtin::HandleForwardedPortCollisions:0x00000001550a68>

 INFO warden: Recovery complete.

 INFO warden: Beginning recovery process...

 INFO warden: Recovery complete.

 INFO warden: Beginning recovery process...

 INFO warden: Recovery complete.

 INFO warden: Beginning recovery process...

 INFO warden: Recovery complete.

 INFO warden: Beginning recovery process...

 INFO warden: Recovery complete.

[...] etc. (runs into this error several times, before giving up)

############################### Vagrantfile ####################################

Vagrant.configure("2") do |config|

    config.vm.box = "w2k8_r2_base"

config.vm.communicator = "winrm"

config.winrm.username = "Administrator"

config.winrm.password = "Vagrant123"

config.vm.network "forwarded_port", guest: 3389, host: 33389, id: "rdp", auto_correct: true

    config.vm.provider :virtualbox do |v, override|

        v.customize ["modifyvm", :id, "--memory", 2048]

        v.customize ["modifyvm", :id, "--cpus", 2]

    end

    config.vm.synced_folder ".", "C:/salt/srv/salt/"

    config.vm.provision :salt do |salt|

        salt.minion_config = "salt/minion"

        salt.run_highstate = true

    end

end

############################### Vagrantfile ####################################

Cheers

Oliver

[dragon788]

It sounds like its seeing a port already in use and trying to recover that, but it looks like you have mixed slashes in the powershell.exe command, mixed slashes are BAD. Try making them all / or all \ in the path to your script.

[Oliver Bestwalter]

Hi,

On Monday, 13 April 2015 17:19:07 UTC+2, dragon788 wrote:

It sounds like its seeing a port already in use and trying to recover that, but it looks like you have mixed slashes in the powershell.exe command, mixed slashes are BAD. Try making them all / or all \ in the path to your script.

 Thanks, but I don't think this has anything to do with the problem as far as I understand it: 

> New-Item : Item with specified name C:\tmp\ already exists.

If I understand that correctly it complains that the folder already exists - so this has nothing to do with ports - correct?

As for the mixing of backslashes and slashes: That is ugly - I agree, but it's not a problem, see for example here

> winrm: Uploading: /home/obestwalter/work/prodenv/vagrant_winbox/salt/minion to C:\tmp/minion

that happens all over the place and is not under my control. I am developing mainly on linux and I used to wonder if this mixing is a problem on windows, so I made some experiments a while ago with paths with mixed slashes and my conclusion was, that windows does not really care ...

Cheers

Oliver

[Shawn Neal]

I think PR 5593 should fix your issue.

I think what happened is that we tightened up the error code and stderr detection in the WinRM communicator and this exposed an issue with the Salt bootstrap PowerShell script. Basically, the script is not idempotent. It attempts to create a directory that can already exists, and if it does exist it causes an error.

You might be able to workaround the issue by providing your own salt bootstrap script to the provisioner block.

[Oliver Bestwalter]

Hi Shawn,

great, thanks! 

Do you think it would be helpful if I open an issue and reference your pull request? Or is there an issue about this already?

Cheers

Oliver

[Shawn Neal]

Hi Oliver,

No need to open an issue, I think the link you added is enough. Seth already reviewed the PR and I just merged it.

--
You received this message because you are subscribed to a topic in the Google Groups "Vagrant" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/vagrant-up/gNeoYgpJnMk/unsubscribe.
To unsubscribe from this group and all its topics, send an email to vagrant-up+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[Oliver Bestwalter]

Nice!