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

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 @​cmd = «
    ssh
    \-o Protocol=2
    \-o ControlMaster=auto
    \-o ControlPath=master\-%l\-%h\-%r
    \-o ControlPersist=30
»;
@​cmd\.append\('root@​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

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

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