Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Handle error 995 from winrm #265

Open
kamaradclimber opened this issue Apr 26, 2017 · 3 comments
Open

Handle error 995 from winrm #265

kamaradclimber opened this issue Apr 26, 2017 · 3 comments

Comments

@kamaradclimber
Copy link
Contributor

kamaradclimber commented Apr 26, 2017 •
edited
Loading

Hello,

while running test-kitchen with kitchen-ec2 driver to create windows boxes. We frequently encounter error 995 during instance creation.

For instance:

E, [2017-04-24T17:09:11.760753 #24482] ERROR -- windows-devtools-windows-2012r2: Create failed on instance <windows-devtools-windows-2012r2>.
E, [2017-04-24T17:09:11.760849 #24482] ERROR -- windows-devtools-windows-2012r2: ------Exception-------
E, [2017-04-24T17:09:11.760878 #24482] ERROR -- windows-devtools-windows-2012r2: Class: WinRM::WinRMWSManFault
E, [2017-04-24T17:09:11.760900 #24482] ERROR -- windows-devtools-windows-2012r2: Message: [WSMAN ERROR CODE: 995]: <f:WSManFault Code='995' Machine='ec2-52-10-29-242.us-west-2.compute.amazonaws.com' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The I/O operation has been aborted because of either a thread exit or an application request. </f:Message></f:WSManFault>

Do you think this error could be caught by winrm gem to automatically retry commands?

For completeness, here is the full stacktrace:

...
I, [2017-04-24T16:58:23.063332 #24482]  INFO -- windows-devtools-windows-2012r2: EC2 instance <i-08ebed01132c23abf> ready.
I, [2017-04-24T17:09:11.760563 #24482]  INFO -- windows-devtools-windows-2012r2: [WinRM] Exception suppressed: [WSMAN ERROR CODE: 2150858843]: <f:WSManFault Code='2150858843' Machine='ec2-52-10-29-242.us-west-2.compute.amazonaws.com' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The request for the Windows Remote Shell with ShellId C59DB211-A442-4D81-8833-138577009C7F 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>
E, [2017-04-24T17:09:11.760753 #24482] ERROR -- windows-devtools-windows-2012r2: Create failed on instance <windows-devtools-windows-2012r2>.
E, [2017-04-24T17:09:11.760849 #24482] ERROR -- windows-devtools-windows-2012r2: ------Exception-------
E, [2017-04-24T17:09:11.760878 #24482] ERROR -- windows-devtools-windows-2012r2: Class: WinRM::WinRMWSManFault
E, [2017-04-24T17:09:11.760900 #24482] ERROR -- windows-devtools-windows-2012r2: Message: [WSMAN ERROR CODE: 995]: <f:WSManFault Code='995' Machine='ec2-52-10-29-242.us-west-2.compute.amazonaws.com' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The I/O operation has been aborted because of either a thread exit or an application request. </f:Message></f:WSManFault>
E, [2017-04-24T17:09:11.760930 #24482] ERROR -- windows-devtools-windows-2012r2: ----------------------
E, [2017-04-24T17:09:11.760952 #24482] ERROR -- windows-devtools-windows-2012r2: ------Backtrace-------
E, [2017-04-24T17:09:11.760973 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/http/response_handler.rb:69:in `raise_if_wsman_fault'
E, [2017-04-24T17:09:11.760997 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/http/response_handler.rb:52:in `raise_if_error'
E, [2017-04-24T17:09:11.761019 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/http/response_handler.rb:36:in `parse_to_xml'
E, [2017-04-24T17:09:11.761041 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/http/transport.rb:186:in `send_request'
E, [2017-04-24T17:09:11.761070 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/wsmv/receive_response_reader.rb:95:in `send_get_output_message'
E, [2017-04-24T17:09:11.761092 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/wsmv/receive_response_reader.rb:63:in `read_response'
E, [2017-04-24T17:09:11.761121 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/psrp/receive_response_reader.rb:41:in `read_message'
E, [2017-04-24T17:09:11.761153 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/psrp/receive_response_reader.rb:60:in `block in read_output'
E, [2017-04-24T17:09:11.761175 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/wsmv/receive_response_reader.rb:75:in `with_output'
E, [2017-04-24T17:09:11.761197 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/psrp/receive_response_reader.rb:59:in `read_output'
E, [2017-04-24T17:09:11.761218 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/shells/base.rb:85:in `block in run'
E, [2017-04-24T17:09:11.761249 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/shells/base.rb:135:in `with_command_shell'
E, [2017-04-24T17:09:11.761274 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-2.2.2/lib/winrm/shells/base.rb:84:in `run'
E, [2017-04-24T17:09:11.761303 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/winrm-elevated-1.1.0/lib/winrm/shells/elevated.rb:60:in `run'
E, [2017-04-24T17:09:11.761325 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/transport/winrm.rb:218:in `execute_with_exit_code'
E, [2017-04-24T17:09:11.761346 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/transport/winrm.rb:100:in `execute'
E, [2017-04-24T17:09:11.761366 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/transport/winrm.rb:140:in `wait_until_ready'
E, [2017-04-24T17:09:11.761387 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/bundler/gems/kitchen-ec2-eec4ecd325af/lib/kitchen/driver/ec2.rb:224:in `create'
E, [2017-04-24T17:09:11.761407 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:460:in `public_send'
E, [2017-04-24T17:09:11.761428 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:460:in `block in perform_action'
E, [2017-04-24T17:09:11.761448 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:527:in `synchronize_or_call'
E, [2017-04-24T17:09:11.761469 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:489:in `block in action'
E, [2017-04-24T17:09:11.761490 #24482] ERROR -- windows-devtools-windows-2012r2: /usr/lib64/ruby/2.2.0/benchmark.rb:288:in `measure'
E, [2017-04-24T17:09:11.761518 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:488:in `action'
E, [2017-04-24T17:09:11.761540 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:460:in `perform_action'
E, [2017-04-24T17:09:11.761561 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:370:in `create_action'
E, [2017-04-24T17:09:11.761581 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:359:in `block in transition_to'
E, [2017-04-24T17:09:11.761602 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:358:in `each'
E, [2017-04-24T17:09:11.761622 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:358:in `transition_to'
E, [2017-04-24T17:09:11.761673 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:157:in `verify'
E, [2017-04-24T17:09:11.761704 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:186:in `block in test'
E, [2017-04-24T17:09:11.761727 #24482] ERROR -- windows-devtools-windows-2012r2: /usr/lib64/ruby/2.2.0/benchmark.rb:288:in `measure'
E, [2017-04-24T17:09:11.761749 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/instance.rb:182:in `test'
E, [2017-04-24T17:09:11.761770 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/command.rb:197:in `public_send'
E, [2017-04-24T17:09:11.761791 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/command.rb:197:in `run_action_in_thread'
E, [2017-04-24T17:09:11.761813 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/test-kitchen-1.16.0/lib/kitchen/command.rb:169:in `block (2 levels) in run_action'
E, [2017-04-24T17:09:11.761834 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `call'
E, [2017-04-24T17:09:11.761854 #24482] ERROR -- windows-devtools-windows-2012r2: /home/jenkins/.gem/gems/logging-2.2.2/lib/logging/diagnostic_context.rb:474:in `block in create_with_logging_context'
E, [2017-04-24T17:09:11.761875 #24482] ERROR -- windows-devtools-windows-2012r2: ----End Backtrace-----
I, [2017-04-24T17:09:11.763656 #24482]  INFO -- windows-devtools-windows-2012r2: -----> Destroying <windows-devtools-windows-2012r2>...
I, [2017-04-24T17:19:44.423694 #24482]  INFO -- windows-devtools-windows-2012r2: [WinRM] Exception suppressed: [WSMAN ERROR CODE: 2150858843]: <f:WSManFault Code='2150858843' Machine='ec2-52-10-29-242.us-west-2.compute.amazonaws.com' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The request for the Windows Remote Shell with ShellId 4046810E-CB87-40F0-AE7C-01F342575FA5 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>
I, [2017-04-24T17:30:17.268586 #24482]  INFO -- windows-devtools-windows-2012r2: [WinRM] Exception suppressed: [WSMAN ERROR CODE: 2150858843]: <f:WSManFault Code='2150858843' Machine='ec2-52-10-29-242.us-west-2.compute.amazonaws.com' xmlns:f='http://schemas.microsoft.com/wbem/wsman/1/wsmanfault'><f:Message>The request for the Windows Remote Shell with ShellId C59DB211-A442-4D81-8833-138577009C7F 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>
I, [2017-04-24T17:30:18.464434 #24482]  INFO -- windows-devtools-windows-2012r2: EC2 instance <i-08ebed01132c23abf> destroyed.
I, [2017-04-24T17:30:18.500854 #24482]  INFO -- windows-devtools-windows-2012r2: Finished destroying <windows-devtools-windows-2012r2> (21m6.70s).

Edit: we use a special branch of kitchen-ec2 (https://github.com/criteo-forks/kitchen-ec2/tree/criteo) but having a look at the patches, I don't think it has an impact for this issue.
@kamaradclimber
Copy link
Contributor Author

A closer look at the backtrace seems to indicate test-kitchen is repeatedly trying to launch the powershell command: Write-Host "[WinRM] Established\n".

Of course it might be linked to the fact we've just ignored the error 2150858843 above

@kamaradclimber
Copy link
Contributor Author

@mwrock would you have an idea to help me writing a patch?

@mwrock
Copy link
Member

mwrock commented May 6, 2017

I'm not sure the patch should be in the winrm gem. In the case of this error, a retry could never recover. Somehow the winrm connection is being severed after you have sent a command successfully and while the command was running. This usually means that the machine was rebooted or something restarted the winrm service.

One thing to check is how your aws userdata is setting up winrm. Older versions of kitchen-ec2 had a buggy script that would restart the service and result in these kinds of errors. So if you branched from an older version, that would be something to look for.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@kamaradclimber @mwrock