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

run hangs on slurp-rest with :out and :err if command runs background process #5142

Open
p6rt opened this issue Feb 18, 2016 · 4 comments
Open

run hangs on slurp-rest with :out and :err if command runs background process #5142

p6rt opened this issue Feb 18, 2016 · 4 comments
Labels
Bug

Comments

@p6rt
Copy link

@p6rt p6rt commented Feb 18, 2016

Migrated from rt.perl.org#127566 (status was 'open')

Searchable as RT127566$

@p6rt

This comment has been minimized.

Copy link
Author

@p6rt p6rt commented Feb 18, 2016

From simon@ruderich.org

Hello,

I'm having a weird problem with run. In the following sample,
Perl6 waits after "slurping err" when the ssh mux process gets
spawned in the background on the initial connection. It waits
until the ssh mux process terminates on its own and then prints
the output (stdout/stderr) correctly. If the ssh mux process is
already running, everthing works fine.

  my @​cmd = «
  ssh
  -o Protocol=2
  -o ControlMaster=auto
  -o ControlPath=master-%l-%h-%r
  -o ControlPersist=30
  »;
  @​cmd.append('root@​steep', 'ls');

  my $p = run @​cmd, :!in, :out, :err;

  say "slurping out";
  my $out = $p.out.slurp-rest;
  say "slurping err";
  my $err = $p.err.slurp-rest;
  $p.out.close;
  $p.err.close;

  say "STDOUT​: {$out}";
  say "STDERR​: {$err}";

Removing either or both close doesn't help, however if I don't
use :err (and thus don't read from $err), everything works fine
as well.

Regards
Simon
--
+ privacy is necessary
+ using gnupg http://gnupg.org
+ public key id​: 0x92FEFDB7E44C32F9

@p6rt

This comment has been minimized.

Copy link
Author

@p6rt p6rt commented Feb 19, 2016

From roam@ringlet.net

On Thu, Feb 18, 2016 at 12​:02​:48PM -0800, Simon Ruderich wrote​:

# New Ticket Created by Simon Ruderich
# Please include the string​: [perl #​127566]
# in the subject line of all future correspondence about this issue.
# <URL​: https://rt-archive.perl.org/perl6/Ticket/Display.html?id=127566 >

Hello,

I'm having a weird problem with run. In the following sample,
Perl6 waits after "slurping err" when the ssh mux process gets
spawned in the background on the initial connection. It waits
until the ssh mux process terminates on its own and then prints
the output (stdout/stderr) correctly. If the ssh mux process is
already running, everthing works fine.

my @&#8203;cmd = «
    ssh
    \-o Protocol=2
    \-o ControlMaster=auto
    \-o ControlPath=master\-%l\-%h\-%r
    \-o ControlPersist=30
»;
@&#8203;cmd\.append\('root@&#8203;steep', 'ls'\);

I don't think this is a Perl problem; I believe it may be a real
OpenSSH bug (or, at least, unexpected behavior).

The problem is that when your SSH client decides to start the mux
process, the latter *does not close* its standard error stream;
it keeps file descriptor 2 open to whatever the original SSH client
had it open to - usually this is the user's terminal, but in your
case, it's the pipe back to your program. Even though the original
SSH client process exited, the pipe is still open (to another process,
yet still open anyway), and Perl is absolutely correct to wait for
everything that has the pipe open to close it. This does not even
come from Perl, it's your OS's kernel doing it - but, since there is
a process still using the pipe, it's correct to do it that way :(

As far as I can see, this behavior - leaving fd 2 open to the original
client's standard error stream - is not explicitly documented in
either the ssh(1) manual page or the ssh_config(5) one. I've even
tried passing the -E option to send the debug logs to someplace else,
but it does indeed only affect the debug logs, not the actual standard
error stream :(

I wonder if it might be worthwhile to raise this with the OpenSSH
developers; I could do that if you'd like me to.

G'luck,
Peter

--
Peter Pentchev roam@​ringlet.net roam@​FreeBSD.org pp@​storpool.com
PGP key​: http://people.FreeBSD.org/~roam/roam.key.asc
Key fingerprint 2EE7 A7A5 17FC 124C F115 C354 651E EFB0 2527 DF13

@p6rt

This comment has been minimized.

Copy link
Author

@p6rt p6rt commented Feb 19, 2016

The RT System itself - Status changed from 'new' to 'open'

@p6rt

This comment has been minimized.

Copy link
Author

@p6rt p6rt commented Feb 23, 2016

From simon@ruderich.org

On Fri, Feb 19, 2016 at 02​:07​:36PM -0800, Peter Pentchev via RT wrote​:

The problem is that when your SSH client decides to start the mux
process, the latter *does not close* its standard error stream;
it keeps file descriptor 2 open to whatever the original SSH client
had it open to - usually this is the user's terminal, but in your
case, it's the pipe back to your program. Even though the original
SSH client process exited, the pipe is still open (to another process,
yet still open anyway), and Perl is absolutely correct to wait for
everything that has the pipe open to close it. This does not even
come from Perl, it's your OS's kernel doing it - but, since there is
a process still using the pipe, it's correct to do it that way :(

As far as I can see, this behavior - leaving fd 2 open to the original
client's standard error stream - is not explicitly documented in
either the ssh(1) manual page or the ssh_config(5) one. I've even
tried passing the -E option to send the debug logs to someplace else,
but it does indeed only affect the debug logs, not the actual standard
error stream :(

Hello Peter,

Thank you for this detailed analysis! I saw the open file
descriptor in the debug log but didn't think that it could be the
reason for the delay.

I wonder if it might be worthwhile to raise this with the OpenSSH
developers; I could do that if you'd like me to.

If you'd like to that would be great.

Thank you for your quick help.

Regards
Simon
--
+ privacy is necessary
+ using gnupg http://gnupg.org
+ public key id​: 0x92FEFDB7E44C32F9

@p6rt p6rt added the Bug label Jan 5, 2020
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
1 participant
You can’t perform that action at this time.