No documented way to check that channel has closed #621

Closed
nolar opened this Issue Nov 13, 2015 · 2 comments

Projects

None yet

2 participants

@nolar
nolar commented Nov 13, 2015

Briefly:

SSH sends exit status before the stdout data, and there is no documented way to properly check that the channel has actually finished.

Detailed:

SSH can have exit status sent before stdout data. The typical approach in real-time streaming is to check if channel is recv_ready, recv_stderr_ready or exit_status_ready. There are no other documented ways to check the channel has actually finished.

        # Read if it still executes silently, or there are data left to read.
        while channel.recv_ready() or channel.recv_stderr_ready() or not channel.exit_status_ready():
            select.select([channel], [], [channel], 60)

            if channel.recv_ready():
                out = channel.recv(9999999)
            if channel.recv_stderr_ready():
                out = channel.recv_stderr(9999999)

        exit_code = channel.recv_exit_status()

With this script iterated infinitely, it fails on an attempt number 40-120 (randomly):

        iteration = 0
        while True:
            iteration += 1
            stdout = run("{ sleep 1 ; echo 'itr=%s' ; } &" % iteration).stdout
            assert stdout != ''

The hexdump looks like this (note the timing in seconds!):

2015-11-13 13:38:07,936 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: A2 7F 59 EF 57 2D 5C 3D A8 54 72 F5 96 CC E6 91    ..Y.W-\=.Tr.....
2015-11-13 13:38:07,936 [Thread-3  ] [DEBUG]  [paramiko.transp]  Got payload (28 bytes, 18 padding)
2015-11-13 13:38:07,937 [Thread-3  ] [DEBUG]  [paramiko.transp]  Read packet <channel-window-adjust>, length 9

2015-11-13 13:38:07,937 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 00 00 00 0C 06 63 00 00 00 22 87 B2 83 6E 05 7F    .....c..."...n..
2015-11-13 13:38:07,937 [Thread-3  ] [DEBUG]  [paramiko.transp]  Got payload (12 bytes, 6 padding)
2015-11-13 13:38:07,937 [Thread-3  ] [DEBUG]  [paramiko.transp]  Read packet <channel-success>, length 5
2015-11-13 13:38:07,937 [Thread-3  ] [DEBUG]  [paramiko.transp]  [chan 34] Sesch channel 34 request ok

2015-11-13 13:38:07,939 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 00 00 00 2C 12 62 00 00 00 22 00 00 00 0B 65 78    ...,.b..."....ex
2015-11-13 13:38:07,939 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 69 74 2D 73 74 61 74 75 73 00 00 00 00 00 57 C1    it-status.....W.
2015-11-13 13:38:07,939 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: DC AB EB E4 E0 53 7F B6 34 6F 74 64 F8 4E F5 58    .....S..4otd.N.X
2015-11-13 13:38:07,940 [Thread-3  ] [DEBUG]  [paramiko.transp]  Got payload (44 bytes, 18 padding)
2015-11-13 13:38:07,940 [Thread-3  ] [DEBUG]  [paramiko.transp]  Read packet <channel-request>, length 25

2015-11-13 13:38:08,940 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 00 00 00 1C 0B 5E 00 00 00 22 00 00 00 07 69 74    .....^..."....it
2015-11-13 13:38:08,940 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 72 3D 33 34 0A FF CA AC 4D DF 85 B6 B8 97 7B C9    r=34....M.....{.
2015-11-13 13:38:08,940 [Thread-3  ] [DEBUG]  [paramiko.transp]  Got payload (28 bytes, 11 padding)
2015-11-13 13:38:08,941 [Thread-3  ] [DEBUG]  [paramiko.transp]  Read packet <channel-data>, length 16

2015-11-13 13:38:08,941 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 00 00 00 0C 06 60 00 00 00 22 AC C1 45 F0 AA BC    .....`..."..E...
2015-11-13 13:38:08,941 [Thread-3  ] [DEBUG]  [paramiko.transp]  Got payload (12 bytes, 6 padding)
2015-11-13 13:38:08,942 [Thread-3  ] [DEBUG]  [paramiko.transp]  Read packet <channel-eof>, length 5
2015-11-13 13:38:08,942 [Thread-3  ] [DEBUG]  [paramiko.transp]  [chan 34] EOF received (34)

2015-11-13 13:38:08,942 [Thread-3  ] [DEBUG]  [paramiko.transp]  IN: 00 00 00 0C 06 61 00 00 00 22 6C 38 5F 18 5C 5E    .....a..."l8_.\^
2015-11-13 13:38:08,942 [Thread-3  ] [DEBUG]  [paramiko.transp]  Got payload (12 bytes, 6 padding)
2015-11-13 13:38:08,943 [Thread-3  ] [DEBUG]  [paramiko.transp]  Read packet <channel-close>, length 5
2015-11-13 13:38:08,943 [MainThread] [DEBUG]  [paramiko.transp]  [chan 34] EOF sent (34)

If you are unlucky enough to start your 1st iteration of the while cycle when the exit status is already there (can be simulated with time.sleep), you do not even enter the cycle's body, and go straight to recv_exit_status().

Solution?

But there is undocumented field channel.closed, which can be used to fix this issue. This line works fine:

        while channel.recv_ready() or channel.recv_stderr_ready() or not channel.closed:
            ...

Please make it documented, or add some other way to check that the channel has actually finished.

PS:

$ python --version
Python 2.7.10

$ pip freeze
ecdsa==0.13
netaddr==0.7.18
paramiko==1.15.3
pycrypto==2.6.1
requests==2.8.0
@bitprophet bitprophet added this to the 1.16.1 milestone Nov 19, 2015
@bitprophet
Member

Thanks for the thorough report! I don't know offhand what the status of .closed is and whether it was intended to be a private method. Paramiko uses a lot of _underscored_methods, though, so my guess would be it's a documentation oversight.

Will take a look during next release cycle.

@bitprophet
Member

Seems the practice has simply not been to document any class parameters whatsoever. Sphinx supports doing so, so I'm experimenting with slapping basic descriptions on what I perceive as the most useful/effectively-public attributes, including .closed.

Ideally I'd go around and do this to all classes but don't have time at the moment; will probably still merge for Channel for now.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment