ssh: Prevent timeout from deadlock

[JoshuaWatt]

Using Popen.wait() on a process that has output sent to a pipe can potentially deadlock if the process produces enough output to fill the pipe, since it will stall and never terminate waiting for the pipe to have more space.

Instead, use Popen.communicate() with the timeout parameter. This will consume all output until EOF (preventing the process from stalling due to a full pipe), and then check the return code. In the event of a timeout error, Popen.communicate() doesn't loose any data, so it's safe to call it again after the Popen.kill() in the exception handler.

This likely was done this way because the timeout parameter was new in Python 3.3, but this shouldn't be a concern anymore

Description

Checklist

• Documentation for the feature
• Tests for the feature

• The arguments and description in doc/configuration.rst have been updated

• Add a section on how to use the feature to doc/usage.rst

• Add a section on how to use the feature to doc/development.rst

• PR has been tested

• Man pages have been regenerated

[codecov]

Codecov Report

Patch coverage: 66.6% and project coverage change: -0.1% ⚠️

Comparison is base (2dcc631) 63.0% compared to head (b8f059f) 63.0%.

Additional details and impacted files

@@           Coverage Diff            @@
##           master   #1265     +/-   ##
========================================
- Coverage    63.0%   63.0%   -0.1%     
========================================
  Files         160     160             
  Lines       11848   11849      +1     
========================================
  Hits         7472    7472             
- Misses       4376    4377      +1     

Files Changed	Coverage Δ
labgrid/driver/sshdriver.py	56.1% <50.0%> (-0.2%)	⬇️
labgrid/util/ssh.py	91.4% <100.0%> (ø)

☔ View full report in Codecov by Sentry.
📢 Have feedback on the report? Share it here.

[Bastian-Krause]

Looks good, thanks!

[jluebbe]

@JoshuaWatt Did you actually experience the deadlock?

[JoshuaWatt]

We have seen timeouts and the speculation was that it was the deadlock. I don't think we've seen any since this patch merged..... but ya we also encountered the SSH <8.5 bug unfortunately.

[JoshuaWatt]

And unfortunately, the default SSH on Ubuntu 20.04 has the problem where it doesn't close stdout and there isn't an easy work-around, so it's hard to avoid :(

[jluebbe]

I've never seen SSH control master startup produce significant output (i.e. more than 8k), so I'm skeptical if a pipe deadlock is the cause.

In b8f059f you speculate:

This likely was done this way because the timeout parameter was new in Python 3.3, but this shouldn't be a concern anymore

A wait() with timeout was used since the initial implementation: e4862fa#diff-9d05d7cbdae8b8ebd1d2d5d387c295c966943c5133258be844cb4d38aefd90e8R41

We wanted to make sure that we don't depend on the state of the pipes, so use of wait() was intentional, as it directly covers the interesting cases:

• immediate abort (due to a config error or similar)
• normal startup (parent process exits after fork)
• hang (via wait timeout)

A way to keep this behavior while handling a full pipe would be to use communicate with a very short timeout to start the reader threads and then using wait() to wait for the fork (instead of waiting for pipe closure).

[JoshuaWatt]

I've never seen SSH control master startup produce significant output (i.e. more than 8k), so I'm skeptical if a pipe deadlock is the cause.

In b8f059f you speculate:

This likely was done this way because the timeout parameter was new in Python 3.3, but this shouldn't be a concern anymore

A wait() with timeout was used since the initial implementation: e4862fa#diff-9d05d7cbdae8b8ebd1d2d5d387c295c966943c5133258be844cb4d38aefd90e8R41

We wanted to make sure that we don't depend on the state of the pipes, so use of wait() was intentional, as it directly covers the interesting cases:

* immediate abort (due to a config error or similar)

* normal startup (parent process exits after fork)

* hang (via wait timeout)

A way to keep this behavior while handling a full pipe would be to use communicate with a very short timeout to start the reader threads and then using wait() to wait for the fork (instead of waiting for pipe closure).

It feels like that's relying on internal implementation details (that the threads stick reading data after communicate() times out) a little too much. Not sure if that worse than the SSH version check though. The version check at least is pretty clear when it can be dropped.

[jluebbe]

OK. Still, what we want here is not "read until pipes are closed" but "read until the process has forked (or failed)"

So how about a helper communicate_until_fork, which loops over wait() with a short timeout and then communicate() with another short timeout until .returncode is no longer None.

[JoshuaWatt]

Ya, that seems reasonable

[jluebbe]

Or, alternatively, I think adding a timeout argument to ProcessWrapper.check_output() would do what we need here. But that's an even bigger change...