1.2.2 and up return an error for successful Puppet provisioning

[ringods]

This morning, I upgraded vagrant-windows from 1.2.1 to 1.2.3. Since then, every run (which was successful before) ends with an error:

Notice: Finished catalog run in 214.89 seconds
An error occurred executing a remote WinRM command.

Shell: powershell
Command:  puppet apply --modulepath '/ProgramData/PuppetLabs/puppet/etc/modules;/tmp/vagrant-puppet/modules-0' --color=false --manifestdir /tmp/vagrant-puppet/m
anifests --detailed-exitcodes /tmp/vagrant-puppet/manifests/init.pp
Message: Command execution failed with an exit code of 1

C:\Code\hb-windows-iis-site>vagrant plugin list
nugrant (1.1.0)
vagrant-vsphere (0.5.1)
vagrant-windows (1.2.2)

Version 1.2.2 gives the same results. Could this be related to this commit?

SHA: c28998b05cf1f5c33521110b8a28e67d574dea63

[sneal]

It appears the Puppet run is failing with an exit code of 1. Vagrant-windows 1.2 and 1.2.1 would produce false positives by not properly raising exceptions when a command failed.

The portion of this change which you've noticed is that the default for commands is to throw an exception if it fails rather than return the non-zero exit code (just like core Vagrant). In 1.2 and 1.2.1 vagrant-windows would default to returning a non-zero exit code and never raise an exception. The Puppet provisioner expects an exception to be raised if it fails.

[ringods]

Something has in an influence on the outcome of the puppet run. I have a manifest that installs the .NET Framework 3.5 for me using the winfeature module:

winfeature { 'AS-Net-Framework':
  ensure => 'present',
}

Running this via Vagrant has this outcome:

C:\Code\hb-windows-iis-site>vagrant up sql
Bringing machine 'sql' up with 'virtualbox' provider...
[sql] Importing base box 'hb-windows-2008r2'...
[sql] Matching MAC address for NAT networking...
[sql] Setting the name of the VM...
[sql] Clearing any previously set forwarded ports...
[sql] Creating shared folders metadata...
[sql] Clearing any previously set network interfaces...
[sql] Preparing network interfaces based on configuration...
[sql] Forwarding ports...
[sql] -- 22 => 2222 (adapter 1)
[sql] -- 3389 => 3391 (adapter 1)
[sql] -- 5985 => 5986 (adapter 1)
[sql] Running 'pre-boot' VM customizations...
[sql] Booting VM...
[sql] Waiting for machine to boot. This may take a few minutes...
[sql] Machine booted and ready!
[sql] Configuring and enabling network interfaces...
[sql] Mounting shared folders...
[sql] -- /vagrant
[sql] -- /tmp/vagrant-puppet/manifests
[sql] -- /tmp/vagrant-puppet/modules-0
[sql] Running provisioner: puppet...
Running Puppet with /tmp/vagrant-puppet/manifests/sql.pp...
Notice: Compiled catalog for directory.domain.com in environment production in 0.59 seconds
Notice: Invoking Add-WindowsFeature: Import-Module ServerManager; Add-WindowsFeature AS-Net-Framework
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Notify[winfeature-add-msg-AS-Net-Framework]/message: defined 'message' as 'Invoking Add-WindowsFeature: Impor
t-Module ServerManager; Add-WindowsFeature AS-Net-Framework     '
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns:
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: Success Restart Needed Exit Code Feature Result

Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: ------- -------------- --------- --------------

Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: True    No             Success   {.NET Framework 3
.5.1, .NET Environment, C...
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: executed successfully
Notice: Finished catalog run in 81.61 seconds
An error occurred executing a remote WinRM command.

Shell: powershell
Command:  puppet apply --modulepath '/ProgramData/PuppetLabs/puppet/etc/modules;/tmp/vagrant-puppet/modules-0' --manifestdir /tmp/vagrant-puppet/manifests --det
ailed-exitcodes /tmp/vagrant-puppet/manifests/sql.pp
Message: Command execution failed with an exit code of 1

The installation of the feature was successful, but still the error code seems to be 1. I then changed my Vagrant so I can run puppet manually: giving it an empty manifests just to let the provisioner mount the manifests and modules folder. Here is the output when running the same manifest from a Command Prompt as a local administrator:

C:\Users\Administrator>cd \tmp\vagrant-puppet\manifests

C:\tmp\vagrant-puppet\manifests>puppet apply --modulepath '/ProgramData/PuppetLabs/puppet/etc/modules;/tmp/vagrant-puppet/modules-0' sql.pp
Notice: Compiled catalog for directory.domain.com in environment production in 0.47 seconds
Notice: Invoking Add-WindowsFeature: Import-Module ServerManager; Add-WindowsFeature AS-Net-Framework
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Notify[winfeature-add-msg-AS-Net-Framework]/message: defined 'message' as 'Invoking Add-WindowsFeature: Import-Module ServerManager; Add-WindowsFeature AS-Net-Framework     '
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns:
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: Success Restart Needed Exit Code Feature Result

Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: ------- -------------- --------- --------------

Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: True    No             Success   {.NET Framework 3.5.1, .NET Environment, C...
Notice: /Stage[main]//Winfeature[AS-Net-Framework]/Exec[winfeature-install-feature-AS-Net-Framework]/returns: executed successfully
Notice: Finished catalog run in 58.28 seconds

C:\tmp\vagrant-puppet\manifests>echo Exit code is %errorlevel%
Exit code is 0

Further investigation is probably needed for the integrated vagrant+vagrant-windows+puppet setup...

[ringods]

Just after posting my previous message, I started digging in the vagrant-windows code and noticed this line:

https://github.com/WinRb/vagrant-windows/blob/master/lib/vagrant-windows/monkey_patches/plugins/provisioners/puppet/provisioner/puppet.rb#L44

From the Puppet docs:

--detailed-exitcodes
Provide transaction information via exit codes. If this is enabled, an exit code of '2' means 
there were changes, an exit code of '4' means there were failures during the transaction, 
and an exit code of '6' means there were both changes and failures.

So a successful Puppet can return a non-zero return value. Does the Powershell executing puppet apply interpret this as an error and return 1 as a result?

[ringods]

Something to keep in mind: http://zduck.com/2012/powershell-batch-files-exit-codes/

[ringods]

And dropping --detailed-exitcodes from the command prompt is not (yet) an option as we could be bitten by this Puppet bug:

http://projects.puppetlabs.com/issues/19033

[sneal]

Interesting. With --detailed-exitcodes It seems like we should be looking for an exit code of 0 or 2, otherwise we should assume a failure. Do you have any recommendations here?

[sneal]

And yes, anything other than 0 is currently interpreted as an error by the puppet provisioner here. The winrm communicator by default checks all exit codes and raises an exception for anything other than 0.

[sneal]

Fixed in 1.3.0

A Puppet exit code of 0 or 2 is not acceptable, while any other code will result in a Vagrant error.

This was a bit more difficult to track down because it also required changing the communicator to explicitly return the $LASTEXITCODE because PowerShell was only returning True or False by default.

[ringods]

Tnx!!

[ferventcoder]

I'm interested in the commits that led to this getting fixed.

[ferventcoder]

Nevermind, found it https://github.com/WinRb/vagrant-windows/blob/master/lib/vagrant-windows/communication/winrmcommunicator.rb#L93

Not the commit - but the change at least :)