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.

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

runspacepool fails to execute commands after a read timeout #21

Open
adirn15 opened this issue Dec 5, 2018 · 12 comments
Open

runspacepool fails to execute commands after a read timeout #21

adirn15 opened this issue Dec 5, 2018 · 12 comments

Comments

@adirn15
Copy link

adirn15 commented Dec 5, 2018

I have a runspacepool in which I create multiple powershell commands. I invoke them asynchronously until they complete and parse their outputs. the problem is that if one of the commands get a timeout error, which can be a ReadTimeout, ConnectTimeout etc, it causes the runspacepool to fail, not able to execute more commands, and also unables to close (throws HTTP error 400 in both cases).
this causes 2 issues:

  1. it leaves an open process on the remote host since it is unable to close it
  2. it prevents from executing more commands, or retrieving output from the commands that are not completed yet, since the runspacepool is corrupted.

example:
I added a short read_timeout to reproduce the error, but this happened to me with the default parameter. the code will fail when trying to exit the "with RunspacePool" clause
(if you unquote the comments inside the exception, it will show an attempt to run a new PowerShell in the runspacepool after getting a readTimeout, which also fails)

    wsman = WSMan("remote_host", cert_validation=False, ssl=False, read_timeout=1)
    with RunspacePool(wsman, min_runspaces=2, max_runspaces=2) as pool:
        lst = [PowerShell(pool) for i in range(0, 4)]
        lst[1].add_script('sleep 60; write-output "output2"')
        lst[0].add_script('write-output "output1"')
        lst[2].add_script('write-output "output3"')
        lst[3].add_script('write-output "output4"')
        for ps in lst:
            ps.begin_invoke()

        while lst:
            print(lst)
            for i in lst:
                try:
                    i.poll_invoke(timeout=1)
                except Exception as e:
                    print('got error {} in command {}'.format(type(e), i.commands))
                    if i in lst:
                        lst.remove(i)

                    #     ps = PowerShell(pool)
                    #     ps.add_script('write-output "output 5"')
                    #     ps.begin_invoke()    # this line will fail

                    continue

                if i.state != PSInvocationState.RUNNING:
                    print("completed: {}".format(i.output))
                    lst.remove(i)

@jborean93
Copy link
Owner

I need to test this out to find out what is actually happening but from reading the code if you are catching the error you should still be able to continue using the runspace pool and other pipelines as the runspace will only close when you exit the with branch or explicitly call pool.close().

One thing to note, the timeout value for poll_invoke is actually the WSMan Operational Timeout value which tells Windows how long you need to wait before sending a reply back to the host saying the timeout was reached. The value for read_timeout on the WSMan object should always be 5-10+ seconds more than the WSMan operational timeout to avoid getting a read timeout exception altogether but that isn't fall proof. You said you set read_timeout=1 for the example script, in your normal script which you are encountering this issue what value are you setting for timeout?

@adirn15
Copy link
Author

adirn15 commented Dec 10, 2018

in the normal script I used the default parameters of the wsman object. I eventually managed to prevent it from occuring by adding sleep(0.1) between the poll_invoke() and the begin_invoke(). probably sending multiple messages at once can cause the remote host to get stuck and not respond in time to all of them.

on another note, is there any way i can get the process id of the wsmprovhost.exe that is created on the remote host? I want to be sure that this process is closed no matter what error occurs, and this was an example to an error that prevents the remote process from closing. I saw the runspace pool has a shellId but I can't figure out how to get the pid by that. I also dont want to kill all wsmprovhost processes since they can break other things on the remote host.

thanks again
Nitzan

@jborean93
Copy link
Owner

Thanks for the info, I think I just need to dig into it and try and replicate it myself.

on another note, is there any way i can get the process id of the wsmprovhost.exe that is created on the remote host?

You can run add .add_script('$pid') as the first pipeline command to get the PID of wsmanprovhost.exe but it doesn't look like the PID is on the created WSMan shell object so there isn't an easy way to view this without running that initial script. You can use pool.get_runspace_pools() to return a list of running pipelines on the host and from there get the runspace object that the pipeline is associated with. While the docs for the .NET method state only disconnected pools are returned I found that WSMan will return all open pools on the server with this method https://github.com/jborean93/pypsrp/blob/master/pypsrp/powershell.py#L434-L437. This may be something that can help you to kill orphaned pools based on the ID.

@maybe-hello-world
Copy link

The issue is still actual. For me with Wireshark it's looks like that after timeout the library get 401 answer from winrm, tries to authenticate again and receive 400 error with no reason. Maybe some negotiation protocol error?
Short tcp log is here: https://pastebin.com/XDCuCZBV, I also captured these packets if you need it. This example is reproducible by creating RunspacePool and waiting a minute before sending request.

maybe-hello-world added a commit to maybe-hello-world/tortilla-scvmm that referenced this issue Nov 25, 2019
@relgames
Copy link

relgames commented Apr 16, 2020

Hi, looks like the issue is still happening. I'm writing a tool which keeps RunspacePool open and runs PowerShell scripts periodically (every few minutes).

What I noticed, RunspacePool becomes Disconnected on Windows after a few minutes:
Still connected, PS scripts work:

PS C:\Users\1Admin\AppData\Local\Temp> Get-WSManInstance -ConnectionURI 'http://localhost:5985/wsman' -ResourceURI shell -Enumerate  | Format-Table ShellId,ClientIp,State,ShellRunTime,ShellInactivity

ShellId                              ClientIP       State     ShellRunTime ShellInactivity
-------                              --------       -----     ------------ ---------------
398D3897-5B04-4380-A710-5922AE017D71 <my-ip> Connected P0DT0H4M53S  P0DT0H0M29S

The it becomes Disconnected after ~2 minutes:

ShellId                              ClientIP       State        ShellRunTime ShellInactivity
-------                              --------       -----        ------------ ---------------
398D3897-5B04-4380-A710-5922AE017D71 <my-ip> Disconnected P0DT0H6M19S  P0DT0H1M55S

And after that, any subsequent invocations on RunspacePool fail with 400 bad request:

2020-04-16 13:18:38,779 - pypsrp.powershell - INFO - Initialising PowerShell in remote Runspace Pool
2020-04-16 13:18:38,779 - pypsrp.powershell - INFO - Beginning remote Pipeline invocation
2020-04-16 13:18:38,783 - pypsrp.messages - DEBUG - Packing PSRP message: <Obj RefId="0"><MS><B N="NoInput">true</B><Obj N="ApartmentState" RefId="1"><TN RefId="0"><T>System.Management.Automation.Runspaces.ApartmentState</T><T>System.Enum</T><T>System.ValueType</T><T>System.Object</T></TN><ToString>UNKNOWN</ToString><I32>2</I32></Obj><Obj N="RemoteStreamOptions" RefId="2"><TN RefId="1"><T>System.Management.Automation.Runspaces.RemoteStreamOptions</T><T>System.Enum</T><T>System.ValueType</T><T>System.Object</T></TN><ToString>AddInvocationInfo</ToString><I32>15</I32></Obj><B N="AddToHistory">false</B><Obj N="HostInfo" RefId="3"><MS><B N="_isHostNull">true</B><B N="_isHostUINull">true</B><B N="_isHostRawUINull">true</B><B N="_useRunspaceHost">true</B></MS></Obj><Obj N="PowerShell" RefId="4"><MS><B N="IsNested">false</B><Nil N="ExtraCmds" /><Obj N="Cmds" RefId="5"><TN RefId="2"><T>System.Collections.Generic.List`1[[System.Management.Automation.PSObject, System.Management.Automation, Version=1.0.0.0, Culture=neutral, PublicKeyToken=31bf3856ad364e35]]</T><T>System.Object</T></TN><LST><Obj RefId="6"><MS><S N="Cmd">Get-FileHash -Path ([System.IO.Path]::GetTempPath()+'Test.PsModules.zip') -Algorithm SHA256 | Format-Table -AutoSize -Property Path,Hash -HideTableHeaders | Out-String -Width 20480 </S><B N="IsScript">true</B><Nil N="UseLocalScope" /><Obj N="MergeMyResult" RefId="7"><TN RefId="3"><T>System.Management.Automation.Runspaces.PipelineResultTypes</T><T>System.Enum</T><T>System.ValueType</T><T>System.Object</T></TN><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeToResult" RefId="8"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergePreviousResults" RefId="9"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="Args" RefId="10"><TNRef RefId="2" /><LST /></Obj><Obj N="MergeError" RefId="11"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeWarning" RefId="12"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeVerbose" RefId="13"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeDebug" RefId="14"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeInformation" RefId="15"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj></MS></Obj><Obj RefId="16"><MS><S N="Cmd">Out-String</S><B N="IsScript">false</B><Nil N="UseLocalScope" /><Obj N="MergeMyResult" RefId="17"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeToResult" RefId="18"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergePreviousResults" RefId="19"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="Args" RefId="20"><TNRef RefId="2" /><LST><Obj RefId="21"><MS><S N="N">Stream</S><Nil N="V" /></MS></Obj></LST></Obj><Obj N="MergeError" RefId="22"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeWarning" RefId="23"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeVerbose" RefId="24"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeDebug" RefId="25"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj><Obj N="MergeInformation" RefId="26"><TNRef RefId="3" /><ToString>None</ToString><I32>0</I32></Obj></MS></Obj></LST></Obj><Nil N="History" /><B N="RedirectShellErrorOutputPipe">false</B></MS></Obj><B N="IsNested">false</B></MS></Obj>
2020-04-16 13:18:38,783 - pypsrp.wsman - DEBUG - Creating WSMan header (Action: http://schemas.microsoft.com/wbem/wsman/1/windows/shell/Command, Resource URI: http://schemas.microsoft.com/powershell/Microsoft.PowerShell, Option Set: {'WINRS_SKIP_CMD_SHELL': 'False'}, Selector Set: {'ShellId': '398D3897-5B04-4380-A710-5922AE017D71'}
2020-04-16 13:18:38,784 - pypsrp.wsman - DEBUG - Sending message: b'<s:Envelope xmlns:rsp="http://schemas.microsoft.com/wbem/wsman/1/windows/shell" xmlns:s="http://www.w3.org/2003/05/soap-envelope" xmlns:wsa="http://schemas.xmlsoap.org/ws/2004/08/addressing" xmlns:wsman="http://schemas.dmtf.org/wbem/wsman/1/wsman.xsd" xmlns:wsmv="http://schemas.microsoft.com/wbem/wsman/1/wsman.xsd"><s:Header><wsa:Action s:mustUnderstand="true">http://schemas.microsoft.com/wbem/wsman/1/windows/shell/Command</wsa:Action><wsmv:DataLocale s:mustUnderstand="false" xml:lang="en-US" /><wsman:Locale s:mustUnderstand="false" xml:lang="en-US" /><wsman:MaxEnvelopeSize s:mustUnderstand="true">512000</wsman:MaxEnvelopeSize><wsa:MessageID>uuid:158848C9-6C94-48CE-8F53-949128878551</wsa:MessageID><wsman:OperationTimeout>PT20S</wsman:OperationTimeout><wsa:ReplyTo><wsa:Address s:mustUnderstand="true">http://schemas.xmlsoap.org/ws/2004/08/addressing/role/anonymous</wsa:Address></wsa:ReplyTo><wsman:ResourceURI s:mustUnderstand="true">http://schemas.microsoft.com/powershell/Microsoft.PowerShell</wsman:ResourceURI><wsmv:SessionId s:mustUnderstand="false">uuid:0C773405-EA36-4275-918E-998B42A8E403</wsmv:SessionId><wsa:To>http://<windows-server-ip>:5985/wsman</wsa:To><wsman:OptionSet s:mustUnderstand="true"><wsman:Option Name="WINRS_SKIP_CMD_SHELL">False</wsman:Option></wsman:OptionSet><wsman:SelectorSet><wsman:Selector Name="ShellId">398D3897-5B04-4380-A710-5922AE017D71</wsman:Selector></wsman:SelectorSet></s:Header><s:Body><rsp:CommandLine CommandId="DE92F305-F703-480D-97FE-91AD75DBBD64"><rsp:Command /><rsp:Arguments>AAAAAAAAABMAAAAAAAAAAAMAAA1TAgAAAAYQAgCXOI05BFuAQ6cQWSKuAX1xBfOS3gP3DUiX/pGtddu9ZDxPYmogUmVmSWQ9IjAiPjxNUz48QiBOPSJOb0lucHV0Ij50cnVlPC9CPjxPYmogTj0iQXBhcnRtZW50U3RhdGUiIFJlZklkPSIxIj48VE4gUmVmSWQ9IjAiPjxUPlN5c3RlbS5NYW5hZ2VtZW50LkF1dG9tYXRpb24uUnVuc3BhY2VzLkFwYXJ0bWVudFN0YXRlPC9UPjxUPlN5c3RlbS5FbnVtPC9UPjxUPlN5c3RlbS5WYWx1ZVR5cGU8L1Q+PFQ+U3lzdGVtLk9iamVjdDwvVD48L1ROPjxUb1N0cmluZz5VTktOT1dOPC9Ub1N0cmluZz48STMyPjI8L0kzMj48L09iaj48T2JqIE49IlJlbW90ZVN0cmVhbU9wdGlvbnMiIFJlZklkPSIyIj48VE4gUmVmSWQ9IjEiPjxUPlN5c3RlbS5NYW5hZ2VtZW50LkF1dG9tYXRpb24uUnVuc3BhY2VzLlJlbW90ZVN0cmVhbU9wdGlvbnM8L1Q+PFQ+U3lzdGVtLkVudW08L1Q+PFQ+U3lzdGVtLlZhbHVlVHlwZTwvVD48VD5TeXN0ZW0uT2JqZWN0PC9UPjwvVE4+PFRvU3RyaW5nPkFkZEludm9jYXRpb25JbmZvPC9Ub1N0cmluZz48STMyPjE1PC9JMzI+PC9PYmo+PEIgTj0iQWRkVG9IaXN0b3J5Ij5mYWxzZTwvQj48T2JqIE49Ikhvc3RJbmZvIiBSZWZJZD0iMyI+PE1TPjxCIE49Il9pc0hvc3ROdWxsIj50cnVlPC9CPjxCIE49Il9pc0hvc3RVSU51bGwiPnRydWU8L0I+PEIgTj0iX2lzSG9zdFJhd1VJTnVsbCI+dHJ1ZTwvQj48QiBOPSJfdXNlUnVuc3BhY2VIb3N0Ij50cnVlPC9CPjwvTVM+PC9PYmo+PE9iaiBOPSJQb3dlclNoZWxsIiBSZWZJZD0iNCI+PE1TPjxCIE49IklzTmVzdGVkIj5mYWxzZTwvQj48TmlsIE49IkV4dHJhQ21kcyIgLz48T2JqIE49IkNtZHMiIFJlZklkPSI1Ij48VE4gUmVmSWQ9IjIiPjxUPlN5c3RlbS5Db2xsZWN0aW9ucy5HZW5lcmljLkxpc3RgMVtbU3lzdGVtLk1hbmFnZW1lbnQuQXV0b21hdGlvbi5QU09iamVjdCwgU3lzdGVtLk1hbmFnZW1lbnQuQXV0b21hdGlvbiwgVmVyc2lvbj0xLjAuMC4wLCBDdWx0dXJlPW5ldXRyYWwsIFB1YmxpY0tleVRva2VuPTMxYmYzODU2YWQzNjRlMzVdXTwvVD48VD5TeXN0ZW0uT2JqZWN0PC9UPjwvVE4+PExTVD48T2JqIFJlZklkPSI2Ij48TVM+PFMgTj0iQ21kIj5HZXQtRmlsZUhhc2ggLVBhdGggKFtTeXN0ZW0uSU8uUGF0aF06OkdldFRlbXBQYXRoKCkrJ0lQc29mdC5Qc01vZHVsZXMuemlwJykgLUFsZ29yaXRobSBTSEEyNTYgfCBGb3JtYXQtVGFibGUgLUF1dG9TaXplIC1Qcm9wZXJ0eSBQYXRoLEhhc2ggLUhpZGVUYWJsZUhlYWRlcnMgfCBPdXQtU3RyaW5nIC1XaWR0aCAyMDQ4MCA8L1M+PEIgTj0iSXNTY3JpcHQiPnRydWU8L0I+PE5pbCBOPSJVc2VMb2NhbFNjb3BlIiAvPjxPYmogTj0iTWVyZ2VNeVJlc3VsdCIgUmVmSWQ9IjciPjxUTiBSZWZJZD0iMyI+PFQ+U3lzdGVtLk1hbmFnZW1lbnQuQXV0b21hdGlvbi5SdW5zcGFjZXMuUGlwZWxpbmVSZXN1bHRUeXBlczwvVD48VD5TeXN0ZW0uRW51bTwvVD48VD5TeXN0ZW0uVmFsdWVUeXBlPC9UPjxUPlN5c3RlbS5PYmplY3Q8L1Q+PC9UTj48VG9TdHJpbmc+Tm9uZTwvVG9TdHJpbmc+PEkzMj4wPC9JMzI+PC9PYmo+PE9iaiBOPSJNZXJnZVRvUmVzdWx0IiBSZWZJZD0iOCI+PFROUmVmIFJlZklkPSIzIiAvPjxUb1N0cmluZz5Ob25lPC9Ub1N0cmluZz48STMyPjA8L0kzMj48L09iaj48T2JqIE49Ik1lcmdlUHJldmlvdXNSZXN1bHRzIiBSZWZJZD0iOSI+PFROUmVmIFJlZklkPSIzIiAvPjxUb1N0cmluZz5Ob25lPC9Ub1N0cmluZz48STMyPjA8L0kzMj48L09iaj48T2JqIE49IkFyZ3MiIFJlZklkPSIxMCI+PFROUmVmIFJlZklkPSIyIiAvPjxMU1QgLz48L09iaj48T2JqIE49Ik1lcmdlRXJyb3IiIFJlZklkPSIxMSI+PFROUmVmIFJlZklkPSIzIiAvPjxUb1N0cmluZz5Ob25lPC9Ub1N0cmluZz48STMyPjA8L0kzMj48L09iaj48T2JqIE49Ik1lcmdlV2FybmluZyIgUmVmSWQ9IjEyIj48VE5SZWYgUmVmSWQ9IjMiIC8+PFRvU3RyaW5nPk5vbmU8L1RvU3RyaW5nPjxJMzI+MDwvSTMyPjwvT2JqPjxPYmogTj0iTWVyZ2VWZXJib3NlIiBSZWZJZD0iMTMiPjxUTlJlZiBSZWZJZD0iMyIgLz48VG9TdHJpbmc+Tm9uZTwvVG9TdHJpbmc+PEkzMj4wPC9JMzI+PC9PYmo+PE9iaiBOPSJNZXJnZURlYnVnIiBSZWZJZD0iMTQiPjxUTlJlZiBSZWZJZD0iMyIgLz48VG9TdHJpbmc+Tm9uZTwvVG9TdHJpbmc+PEkzMj4wPC9JMzI+PC9PYmo+PE9iaiBOPSJNZXJnZUluZm9ybWF0aW9uIiBSZWZJZD0iMTUiPjxUTlJlZiBSZWZJZD0iMyIgLz48VG9TdHJpbmc+Tm9uZTwvVG9TdHJpbmc+PEkzMj4wPC9JMzI+PC9PYmo+PC9NUz48L09iaj48T2JqIFJlZklkPSIxNiI+PE1TPjxTIE49IkNtZCI+T3V0LVN0cmluZzwvUz48QiBOPSJJc1NjcmlwdCI+ZmFsc2U8L0I+PE5pbCBOPSJVc2VMb2NhbFNjb3BlIiAvPjxPYmogTj0iTWVyZ2VNeVJlc3VsdCIgUmVmSWQ9IjE3Ij48VE5SZWYgUmVmSWQ9IjMiIC8+PFRvU3RyaW5nPk5vbmU8L1RvU3RyaW5nPjxJMzI+MDwvSTMyPjwvT2JqPjxPYmogTj0iTWVyZ2VUb1Jlc3VsdCIgUmVmSWQ9IjE4Ij48VE5SZWYgUmVmSWQ9IjMiIC8+PFRvU3RyaW5nPk5vbmU8L1RvU3RyaW5nPjxJMzI+MDwvSTMyPjwvT2JqPjxPYmogTj0iTWVyZ2VQcmV2aW91c1Jlc3VsdHMiIFJlZklkPSIxOSI+PFROUmVmIFJlZklkPSIzIiAvPjxUb1N0cmluZz5Ob25lPC9Ub1N0cmluZz48STMyPjA8L0kzMj48L09iaj48T2JqIE49IkFyZ3MiIFJlZklkPSIyMCI+PFROUmVmIFJlZklkPSIyIiAvPjxMU1Q+PE9iaiBSZWZJZD0iMjEiPjxNUz48UyBOPSJOIj5TdHJlYW08L1M+PE5pbCBOPSJWIiAvPjwvTVM+PC9PYmo+PC9MU1Q+PC9PYmo+PE9iaiBOPSJNZXJnZUVycm9yIiBSZWZJZD0iMjIiPjxUTlJlZiBSZWZJZD0iMyIgLz48VG9TdHJpbmc+Tm9uZTwvVG9TdHJpbmc+PEkzMj4wPC9JMzI+PC9PYmo+PE9iaiBOPSJNZXJnZVdhcm5pbmciIFJlZklkPSIyMyI+PFROUmVmIFJlZklkPSIzIiAvPjxUb1N0cmluZz5Ob25lPC9Ub1N0cmluZz48STMyPjA8L0kzMj48L09iaj48T2JqIE49Ik1lcmdlVmVyYm9zZSIgUmVmSWQ9IjI0Ij48VE5SZWYgUmVmSWQ9IjMiIC8+PFRvU3RyaW5nPk5vbmU8L1RvU3RyaW5nPjxJMzI+MDwvSTMyPjwvT2JqPjxPYmogTj0iTWVyZ2VEZWJ1ZyIgUmVmSWQ9IjI1Ij48VE5SZWYgUmVmSWQ9IjMiIC8+PFRvU3RyaW5nPk5vbmU8L1RvU3RyaW5nPjxJMzI+MDwvSTMyPjwvT2JqPjxPYmogTj0iTWVyZ2VJbmZvcm1hdGlvbiIgUmVmSWQ9IjI2Ij48VE5SZWYgUmVmSWQ9IjMiIC8+PFRvU3RyaW5nPk5vbmU8L1RvU3RyaW5nPjxJMzI+MDwvSTMyPjwvT2JqPjwvTVM+PC9PYmo+PC9MU1Q+PC9PYmo+PE5pbCBOPSJIaXN0b3J5IiAvPjxCIE49IlJlZGlyZWN0U2hlbGxFcnJvck91dHB1dFBpcGUiPmZhbHNlPC9CPjwvTVM+PC9PYmo+PEIgTj0iSXNOZXN0ZWQiPmZhbHNlPC9CPjwvTVM+PC9PYmo+</rsp:Arguments></rsp:CommandLine></s:Body></s:Envelope>'
2020-04-16 13:18:38,784 - pypsrp.encryption - DEBUG - Wrapping message for host: <windows-server-ip>
2020-04-16 13:18:38,784 - pypsrp.encryption - DEBUG - Created wrapped message of content type multipart/encrypted
2020-04-16 13:18:38,823 - pypsrp.spnego - DEBUG - SSPI or GSSAPI is not available, using ntlm-auth as the auth backend
2020-04-16 13:18:38,824 - pypsrp.spnego - DEBUG - NTLM Negotiate message: b'4e544c4d5353500001000000329088e20300030028000000000000002b0000000601b11d0000000f646576'
2020-04-16 13:18:38,825 - pypsrp.negotiate - DEBUG - Sending http request with new auth token
2020-04-16 13:18:38,851 - pypsrp.spnego - DEBUG - NTLM: Parsing Challenge message and generating Authenticate message: b'4e544c4d53535000020000000300030038000000368289e2d70f755cc736e2440000000000000000ac00ac003b0000000a0039380000000f4445560200060044004500560001001600440045004d004f002d00570049004e002d003000310004001c006400650076002e006900700073006f00660074002e006e006500740003003400440065006d006f002d00570069006e002d00300031002e006400650076002e006900700073006f00660074002e006e006500740005001c006400650076002e006900700073006f00660074002e006e00650074000700080067791dc7e013d60100000000'
2020-04-16 13:18:38,853 - pypsrp.negotiate - DEBUG - Sending http request with new auth token
2020-04-16 13:18:38,894 - pypsrp.negotiate - DEBUG - Did not receive a http response with an auth response, stopping authentication process
2020-04-16 13:18:38,895 - pypsrp.wsman - DEBUG - Received message: 
2020-04-16 13:18:38,896 - pypsrp.wsman - ERROR - Failed to parse WSManFault message on WinRM error response, raising original WinRMTransportError

I tried to work-around it with pool.disconnect() and pool.connect() but it also fails on .disconnect()
And if I make new WsMan instance, old session is still in Disconnected state on the windows server and that quickly hits a limit of PS shells / connections on the server.

@relgames
Copy link

Is there a way to keep a RunspacePool Connected?

Seems like CleanupInterval controls when unused pool is closed? But I don't see how to set it in pypsrp. Not sure it's what I need though.
https://docs.microsoft.com/en-us/dotnet/api/system.management.automation.runspaces.runspacepool.cleanupinterval?view=pscore-6.2.0#System_Management_Automation_Runspaces_RunspacePool_CleanupInterval

@yajatns
Copy link

yajatns commented Aug 23, 2023

@relgames Were you able to workaround this issue where after sometime the Sunspace tool fails with 400 bad error exception?

@relgames
Copy link

relgames commented Sep 11, 2023

@yajatns yes, added a custom logic to detect such state and open a new shell, and kill the old one:

    def __reconnect(self):
        # WSMan connections go into Disconnected state after few minutes.
        # There is no way at this moment to reconnect, doing so results in HTTP 400 Bad Request
        # https://github.com/jborean93/pypsrp/issues/21

        # A workaround is to connect a new RunspacePool and kill the previously hanging session

        old_shell_id = self.session.shell.id

        try:
            logger.debug("Trying to reconnect to host %s", self.host)
            self.session = self.create_session(self.host, self.username, self.password)
        except (WinRMTransportError, WSManFaultError) as e:
            logger.error("Could not reconnect to host %s: %s", self.host, e.message)
            raise e

        try:
            self.__kill_shell(old_shell_id)
        except (WinRMTransportError, WSManFaultError) as e:
            logger.error("Could not kill old shell %s on host %s: %s", old_shell_id, self.host, e.message)

    def __kill_shell(self, shell_id):
        logger.debug("Killing Shell %s on host %s", shell_id, self.host)
        self.run_scriptblock(
            "Remove-WSManInstance -ConnectionURI 'http://localhost:5985/wsman' shell @{ShellId='%s'}" % shell_id)

@miniagarwal0910
Copy link

miniagarwal0910 commented Apr 7, 2024

This issue still exists, is there any workaround available apart from explicitly calling Remove-WSManInstance?
@relgames @yajatns

@adamkbmc
Copy link

adamkbmc commented Nov 7, 2024

I've been hitting this issue off and on for a while and I've implemented the "kill shell" workaround which sometimes works but can still fail when you try to recreate the connection (Bad HTTP response returned from the server. Code: 400, Content:'')

I am currently using 0.8.1, has anyone tried with the 1.0.0 betas? On that point, is the 1.0.0 ever going to be released? Its been two years since b1 (according to the CHANGELOG) and I am somewhat worried this project is no longer being maintained?

Also there is https://github.com/diyan/pywinrm which @jborean93 is contributing to ... is that the new hotness? I tried using that for some scripting tasks but it failed with "The command line is too long" (its quite a big PS script but not that large ...)

@jborean93
Copy link
Owner

pywinrm is certainly older and while I do contribute to it it's only on a maintenance basis. I'm still wanting to get back to the 1.0.0 release and I have some changes in a branch that simplify the dependencies a bit but unfortunately just haven't had the time to get back to it for a while. Hopefully I can clear it out soon and get the 1.0.0 release back on track.

@adamkbmc
Copy link

adamkbmc commented Nov 8, 2024

Glad to hear that psrp is alive and well and I fully understand the lack of time! Thanks for the info

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

7 participants