dandunckelman
commented
7 years ago @mwrock I just updated to v1.9.4, which has v2.2.2 of winrm.
No errors like before, but I now get this (truncated above/below log entries):
453.540 ERR DEBUG winrmshell: [WinRM] remote shell created with shell_id: 00D03ABC-B2A9-4A40-981B-27AE97FEDD61
453.584 ERR DEBUG winrmshell: [WinRM] Command created for powershell -ExecutionPolicy Bypass -OutputFormat Text -file "c:\tmp\vagrant-shell.ps1"
453.584 ERR if (!$?) { if($LASTEXITCODE) { exit $LASTEXITCODE } else { exit 1 } } with id: 839F96E1-394A-42A8-AB6E-B5D2BB1535EE
453.584 ERR DEBUG winrmshell: [WinRM] creating command_id: 839F96E1-394A-42A8-AB6E-B5D2BB1535EE on shell_id 00D03ABC-B2A9-4A40-981B-27AE97FEDD61
453.584 ERR DEBUG winrmshell: [WinRM] Waiting for output...
454.517 ERR DEBUG winrmshell: [WinRM] Processing output
454.521 OUT ==> wincon: Node Script: windows-restart.ps1
454.526 OUT ==> wincon: Hive: HKEY_LOCAL_MACHINE\Software\TechAccelerator
454.530 OUT ==> wincon: Name Property
454.532 OUT ==> wincon: ---- --------
454.534 OUT ==> wincon: windows-restart.ps1 (default) : 1
454.536 OUT ==> wincon: Sleeping for a bit.
454.543 ERR DEBUG winrmshell: [WinRM] Waiting for output...
514.637 ERR DEBUG winrmshell: [WinRM] Processing output
514.640 OUT ==> wincon: Restarting node.
514.642 OUT ==> wincon: Waiting for restart: 1
514.646 ERR DEBUG winrmshell: [WinRM] Waiting for output...
515.340 ERR DEBUG winrmshell: [WinRM] Processing output
515.350 ERR DEBUG winrmshell: [WinRM] Waiting for output...
515.363 ERR DEBUG winrmshell: [WinRM] cleaning up command_id: 839F96E1-394A-42A8-AB6E-B5D2BB1535EE on shell_id 00D03ABC-B2A9-4A40-981B-27AE97FEDD61
802.046 ERR INFO winrmshell: [WinRM] Exception suppressed: [WSMAN ERROR CODE: 2150858843]: <f:WSManFault Code='2150858843' Machine='172.17.0.13' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The request for the Windows Remote Shell with ShellId 00D03ABC-B2A9-4A40-981B-27AE97FEDD61 failed because the shell was not found on the server. Possible causes are: the specified ShellId is incorrect or the shell no longer exists on the server. Provide the correct ShellId or create a new shell and retry the operation. </f:Message></f:WSManFault>
1087.754 ERR INFO winrmshell: [WinRM] Exception suppressed: [WSMAN ERROR CODE: 2150858843]: <f:WSManFault Code='2150858843' Machine='172.17.0.13' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The request for the Windows Remote Shell with ShellId 00D03ABC-B2A9-4A40-981B-27AE97FEDD61 failed because the shell was not found on the server. Possible causes are: the specified ShellId is incorrect or the shell no longer exists on the server. Provide the correct ShellId or create a new shell and retry the operation. </f:Message></f:WSManFault>
1087.755 ERR ERROR warden: Error occurred: An error occurred executing a remote WinRM command.
1087.755 ERR Shell: Powershell
1087.755 ERR Command: powershell -ExecutionPolicy Bypass -OutputFormat Text -file "c:\tmp\vagrant-shell.ps1"
1087.755 ERR Message: Bad HTTP response returned from server. Body(if present): (500).
1087.755 ERR INFO warden: Beginning recovery process...
1087.755 ERR INFO warden: Recovery complete.
1087.755 ERR ERROR warden: Error occurred: An error occurred executing a remote WinRM command.
1087.755 ERR Shell: Powershell
1087.755 ERR Command: powershell -ExecutionPolicy Bypass -OutputFormat Text -file "c:\tmp\vagrant-shell.ps1"
1087.755 ERR Message: Bad HTTP response returned from server. Body(if present): (500).You'll see in the logs that we run a script called windows-restart.ps1, which, as you can guess, restarts the VM.
This error makes sense in this example:
The request for the Windows Remote Shell with ShellId 00D03ABC-B2A9-4A40-981B-27AE97FEDD61 failed because the shell was not found on the server.
Possible causes are: the specified ShellId is incorrect or the shell no longer exists on the serverI doubt the shell can persist across a reboot...so, what would you advise we do in this case?
- Should a new way of handling reboots be found?
- Could this gem be updated to account for this case?
- Something else?
mwrock
This addresses the issues raised in this comment. Vagrant, and perhaps other applications, used to wrap shell commands in its own retryable block that would intercept errors raised in open, command execution, cleanup or shell close. Winrm now only wraps shell open in a retryable block. If a command requests a system reboot, its posible that the cleanup or shell close operations fail and raise an exception in the hosting application.
This PR wraps both cleanup and close in their own retryable block. Further, if all retries fail, it will not raise the error but will send it to the log output.
Signed-off-by: Matt Wrock matt@mattwrock.com