Missing exit_status

[otstrel]

Hello,

I'm having weird problem with server randomly not sending exit status, my simplest repro looks like this:

In [244]: c = await asyncssh.connect('hostname', options=asyncssh.SSHClientConnectionOptions(username='username'))

In [245]: await c.run('exit 1')
DEBUG:asyncssh:[conn=7, chan=1] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=7, chan=1] Requesting new SSH session
DEBUG:asyncssh:[conn=7, chan=1]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=7, chan=1]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=7, chan=1]   Command: exit 1
DEBUG:asyncssh:[conn=7, chan=1] Reading from channel started
INFO:asyncssh:[conn=7, chan=1] Received exit status 1
INFO:asyncssh:[conn=7, chan=1] Received channel close
INFO:asyncssh:[conn=7, chan=1] Channel closed
Out[245]: SSHCompletedProcess(env=mappingproxy({}), command='exit 1', subsystem=None, exit_status=1, exit_signal=None, returncode=1, stdout='', stderr='')

In [246]: await c.run('exit 1')
DEBUG:asyncssh:[conn=7, chan=2] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=7, chan=2] Requesting new SSH session
DEBUG:asyncssh:[conn=7, chan=2]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=7, chan=2]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=7, chan=2]   Command: exit 1
DEBUG:asyncssh:[conn=7, chan=2] Reading from channel started
INFO:asyncssh:[conn=7, chan=2] Received channel close
INFO:asyncssh:[conn=7, chan=2] Channel closed
Out[246]: SSHCompletedProcess(env=mappingproxy({}), command='exit 1', subsystem=None, exit_status=None, exit_signal=None, returncode=None, stdout='', stderr='')

I tried doing create_process/wait but results are pretty much the same:

In [250]: p = await c.create_process("exit 1"); await p.wait()
DEBUG:asyncssh:[conn=8, chan=0] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=8, chan=0] Requesting new SSH session
DEBUG:asyncssh:[conn=8, chan=0]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=8] Received unknown global request: [email protected]
DEBUG:asyncssh:[conn=8, chan=0]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=8, chan=0]   Command: exit 1
DEBUG:asyncssh:[conn=8, chan=0] Reading from channel started
INFO:asyncssh:[conn=8, chan=0] Received channel close
INFO:asyncssh:[conn=8, chan=0] Channel closed
Out[250]: SSHCompletedProcess(env=mappingproxy({}), command='exit 1', subsystem=None, exit_status=None, exit_signal=None, returncode=None, stdout='', stderr='')

In [251]: p = await c.create_process("exit 1"); await p.wait()
DEBUG:asyncssh:[conn=8, chan=1] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=8, chan=1] Requesting new SSH session
DEBUG:asyncssh:[conn=8, chan=1]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=8, chan=1]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=8, chan=1]   Command: exit 1
DEBUG:asyncssh:[conn=8, chan=1] Reading from channel started
INFO:asyncssh:[conn=8, chan=1] Received exit status 1
INFO:asyncssh:[conn=8, chan=1] Received channel close
INFO:asyncssh:[conn=8, chan=1] Channel closed
Out[251]: SSHCompletedProcess(env=mappingproxy({}), command='exit 1', subsystem=None, exit_status=1, exit_signal=None, returncode=1, stdout='', stderr='')

I tried adding drain and communicate before wait, no luck. Adding sleep and extra output to the command didn't make any difference either.

This looks more like server issue rather than asyncssh issue but I was hoping for any pointers towards better workaround than the one I came up with:

In [260]: await c.run('$(exit 1) || printf failed >&2')
DEBUG:asyncssh:[conn=9, chan=5] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=9, chan=5] Requesting new SSH session
DEBUG:asyncssh:[conn=9, chan=5]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=9, chan=5]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=9, chan=5]   Command: $(exit 1) || printf failed >&2
DEBUG:asyncssh:[conn=9, chan=5] Reading from channel started
DEBUG:asyncssh:[conn=9, chan=5] Received 6 data bytes from STDERR
INFO:asyncssh:[conn=9, chan=5] Received channel close
INFO:asyncssh:[conn=9, chan=5] Channel closed
Out[260]: SSHCompletedProcess(env=mappingproxy({}), command='$(exit 1) || printf failed >&2', subsystem=None, exit_status=None, exit_signal=None, returncode=None, stdout='', stderr='failed')

Thanks!

[ronf]

This is a bit of a long shot, but do you see a difference if you set term_type='ansi'? This will cause the remote system to allocate a pseudo-tty, which changes the behavior in various ways. A downside to this is that you'd no longer have separate stdout and stderr streams, but you might not need that if it fixes the problem with exit status not showing up reliably.

[otstrel]

Unfortunately, no, behavior is still the same. My code is talking to some appliance which enables access to secure network so my guess it does some clever SSH proxying randomly losing exit status in the process. I'll ask our admins to open support ticket with the vendor and with some luck we may have some resolution to this mystery.

Thank you for looking into this issue, I very much appreciate it especially since it is clearly not related to your code!

[ronf]

Happy to try and help. The PTY thing was a long shot, but I figured it was worth a try just to see if the behavior changed.

Thinking about it a bit more, it's interesting that you're actually seeing 'failed' show up on stderr. That would suggest that the shell on the remote host somehow failed to run the "exit" command, and instead just returned some internal error status without triggering the shell to exit, allowing for the printf to run. Since "exit" should be a shell built-in, I'm not really sure how that would be possible, but if that did happen, it would explain why the remote SSH wasn't sending an exit status (causing AsyncSSH to report None).

Actually, I think maybe the reason for not seeing the exit status in the 'failed' example may be the use of $() around the exit command. That's going to create a sub shell and it'll return an exit status of 1 to the parent, triggering it to run the printf, but it wouldn't set an exit status in the parent shell. What do you see if you try to run the "exit 1" without a sub-shell, but keeping the printf?

[otstrel]

Yes, you are quite right, exit terminates only subshell and hands exit code over to parent where printf overrides it with its own:

In [4]: await c.run('$(exit 1) || printf failed >&2')
DEBUG:asyncssh:[conn=0, chan=0] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=0, chan=0] Requesting new SSH session
DEBUG:asyncssh:[conn=0, chan=0]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=0] Received unknown global request: [email protected]
DEBUG:asyncssh:[conn=0, chan=0]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=0, chan=0]   Command: $(exit 1) || printf failed >&2
DEBUG:asyncssh:[conn=0, chan=0] Reading from channel started
INFO:asyncssh:[conn=0, chan=0] Received exit status 0
DEBUG:asyncssh:[conn=0, chan=0] Received 6 data bytes from STDERR
INFO:asyncssh:[conn=0, chan=0] Received channel close
INFO:asyncssh:[conn=0, chan=0] Channel closed
Out[4]: SSHCompletedProcess(env=mappingproxy({}), command='$(exit 1) || printf failed >&2', subsystem=None, exit_status=0, exit_signal=None, returncode=0, stdout='', stderr='failed')

In [5]: await c.run('exit 1 || printf failed >&2')
DEBUG:asyncssh:[conn=0, chan=1] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=0, chan=1] Requesting new SSH session
DEBUG:asyncssh:[conn=0, chan=1]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=0, chan=1]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=0, chan=1]   Command: exit 1 || printf failed >&2
DEBUG:asyncssh:[conn=0, chan=1] Reading from channel started
INFO:asyncssh:[conn=0, chan=1] Received channel close
INFO:asyncssh:[conn=0, chan=1] Channel closed
Out[5]: SSHCompletedProcess(env=mappingproxy({}), command='exit 1 || printf failed >&2', subsystem=None, exit_status=None, exit_signal=None, returncode=None, stdout='', stderr='')

I guess we could try to preserve exit code with something like this:

In [15]: await c.run('$(exit 1); rc=$?; if [ $rc -ne 0 ]; then printf failed >&2; fi; exit $rc')
DEBUG:asyncssh:[conn=0, chan=11] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=0, chan=11] Requesting new SSH session
DEBUG:asyncssh:[conn=0, chan=11]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=0, chan=11]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=0, chan=11]   Command: $(exit 1); rc=$?; if [ $rc -ne 0 ]; then printf failed >&2; fi; exit $rc
DEBUG:asyncssh:[conn=0, chan=11] Reading from channel started
DEBUG:asyncssh:[conn=0, chan=11] Received 6 data bytes from STDERR
INFO:asyncssh:[conn=0, chan=11] Received channel close
INFO:asyncssh:[conn=0, chan=11] Channel closed
Out[15]: SSHCompletedProcess(env=mappingproxy({}), command='$(exit 1); rc=$?; if [ $rc -ne 0 ]; then printf failed >&2; fi; exit $rc', subsystem=None, exit_status=None, exit_signal=None, returncode=None, stdout='', stderr='failed')

In [16]: await c.run('$(exit 1); rc=$?; if [ $rc -ne 0 ]; then printf failed >&2; fi; exit $rc')
DEBUG:asyncssh:[conn=0, chan=12] Set write buffer limits: low-water=16384, high-water=65536
INFO:asyncssh:[conn=0, chan=12] Requesting new SSH session
DEBUG:asyncssh:[conn=0, chan=12]   Initial recv window 2097152, packet size 32768
DEBUG:asyncssh:[conn=0, chan=12]   Initial send window 2097152, packet size 32768
INFO:asyncssh:[conn=0, chan=12]   Command: $(exit 1); rc=$?; if [ $rc -ne 0 ]; then printf failed >&2; fi; exit $rc
DEBUG:asyncssh:[conn=0, chan=12] Reading from channel started
DEBUG:asyncssh:[conn=0, chan=12] Received 6 data bytes from STDERR
INFO:asyncssh:[conn=0, chan=12] Received exit status 1
INFO:asyncssh:[conn=0, chan=12] Received channel close
INFO:asyncssh:[conn=0, chan=12] Channel closed
Out[16]: SSHCompletedProcess(env=mappingproxy({}), command='$(exit 1); rc=$?; if [ $rc -ne 0 ]; then printf failed >&2; fi; exit $rc', subsystem=None, exit_status=1, exit_signal=None, returncode=1, stdout='', stderr='failed')

[ronf]

Yeah - that looks reasonable. Was that the issue in all of your tests, though? I thought one of your examples which failed was a plain "exit 1" not in a sub-shell. I think that may still be unexplained here.

[ronf]

Closing due to inactivity - feel free to open a new issue if there's anything further needed here.