powershell provisioning script hanging

[silarsis]

I have a very small powershell script in the provisioning for a Windows 2012R2 server - snippet follows:

  "provisioners": [{
    "type": "powershell",
    "inline": [
      "Set-ExecutionPolicy Unrestricted -Force",
      "Import-Module ServerManager",
      "echo 'installing windows features'",
      "echo 'install-windowsfeature web-webserver'",
      "install-windowsfeature web-webserver -verbose -includeallsubfeature",
      "echo 'install-windowsfeature web-mgmt-tools'",
      "install-windowsfeature web-mgmt-tools -verbose -includeallsubfeature",

If I run this as-is, the output reads something like this:

==> amazon-windows-ebs: Waiting for WinRM to become available...
==> amazon-windows-ebs: Connected to WinRM!
==> amazon-windows-ebs: Provisioning with Powershell...
==> amazon-windows-ebs: Provisioning with shell script: /tmp/packer-powershell-provisioner243594781
    amazon-windows-ebs: installing windows features
    amazon-windows-ebs: install-windowsfeature web-webserver
    amazon-windows-ebs: VERBOSE: Installation started...
    amazon-windows-ebs: VERBOSE: Continue with installation?
    amazon-windows-ebs: VERBOSE: Prerequisite processing started...
    amazon-windows-ebs: VERBOSE: Prerequisite processing succeeded.
^C==> amazon-windows-ebs: Terminating the source AWS instance...

At that ctrl-c the provisioning had just been sitting for hours.

If I remove the install-windowsfeature web-webserver line, the whole script completes in about 15 minutes.

I'm not sure how to debug what's going on with this. I did enable RDP and RDP into the box, and on trying to do the same install-windowsfeature web-webserver command I got told it had already been installed, so I think the command is completing successfully but not returning control to packer properly, or something similar.

Happy to do any debugging required, and can provide the entire scripts if they're useful - should be straightforward to replicate, it happens every time. Also perfectly willing to believe it's a problem at my end, but would love some pointers on how to debug further ;)

[mefellows]

Hmm that's an interesting one. I'll see if I can repro locally and go from there (I'll come back with some debugging tips after a short dinner break!)

[mefellows]

Confirmed I can repro - taking a look now.

On Debugging... before you debug, it's worth having a basic understanding of the way that Powershell provisioning works:

• For each inline command, we concatenate all of the commands into a local script, upload to the guest and then run that script
• For script(s) the concatenation step is not required, but the process is the same - upload script, run it
• The elevated scenario is slightly different, in that an extra script (a scheduled task) is uploaded and wraps the call to execute the actual script (this is required to work around a limitation of the WinRM security model. sigh).

So, with that, a couple of debugging tips:

• Use the PACKER_LOG=1 and PACKER_LOG_PATH=packeroutput.log env variables to get detailed output of what's happening
• Use the --debug flag to Packer - this pauses Packer on every step along the process allowing you to do deeper investigation (although in this case that's of no real use as the problem is the server doesn't shutdown!) before it shuts down.
• Use of the pause_before parameter of any Provisioner. This allows you to inspect the state of the machine between provisioners (--debug doesn't pause between provisioners, just between the Provisioning step itself). More importantly, it can give you a chance to jump onto the machine and look at the scripts that are being run to ensure they are formatted correctly etc. You can even run them there to see what happens (e.g. sometimes a prompt will appear and that's why its hanging).
• Consider grabbing https://github.com/mefellows/winrm-powershell or https://github.com/mefellows/gobash (massive WIP) to avoid constantly having to RDP onto the machine and use the God-awful terminals. This way you can just run commands from the comfort of your favourite terminal (but, alas, no code completion)
• The Event Viewer can also be a good source, if you can find where the events are being logged to! You can use the Get-EventLog commandlet to save clicks
• And as a general tip, use Vagrant to test out scripts first and once they seem to be working move over to Packer incrementally as with Windows the iteration cycles are exaggerated, to say the least.
• Specifically in this case, I've added the -LogPath c:\foo.log flag to the Install-WindowsFeature commands and now i can winrm-powershell --port 5985 'cat c:\*.log' to see what's happening (Its stuck on "The progress is 68" for me)

But, last of all, is PATIENCE :) By the time I wrote this comment, Packer had actually just finished successfully (I've included the logs and the packer file so you can double check I've done the right thing).

I'm not sure how long you waited but in my case those provisioning steps took 20 minutes (not completely uncommon but the box did seem rather inactive during this time so some further investigation probably warranted). Possibly due to the -IncludeAllSubFeature flag, I'm going to start up the output box now to see if there is anything to learn from a little bit of forensic work.

I'll leave this open for now and once you've had a chance to review the gist from above we can go from there.

[silarsis]

Very quick feedback: I'd left it running during the day, so it was over 6 hours - and cloudwatch showed me no cpu activity to speak of. But, I'll work through what you've given above and see if I can spot the problem, and if I can't I'll upload the full packer config I'm using - maybe it's something else in there.

Thanks heaps for the write-up above, btw - that's a huge help.

[mefellows]

Ahh, AWS. I'll kick one off in the background too - could be a bootstrapping issue or possibly some kind of network ACL/connectivity problem but unlikely.

Let me know how you go, we can have private conversations elsewhere if there is sensitivity in the logs etc.

[silarsis]

Thanks for that - I've been trying to replicate but haven't had time, so sorry for slow response. I'm moving to script instead of inline, and I'll have a closer look next time I get a chance to set it running. Can close this issue for now, given you've run through fine.