From perlbug@plan9.de

Created by perlbug@plan9.de

It seems that $| and autoflush ability is lost on the first EAGAIN.

Here is a test program that might or might not work (it should be run
under a terminal emulator, and it likely works best under linux because I
tested it with that kernel) that illustrates the problem​:

  !/usr/bin/perl

  use Fcntl;

  open my $fh, ">&1" or die;
  fcntl $fh, F_SETFL, O_NONBLOCK or die;

  $|=1;

  print "-";
  syswrite $fh, "\x00" x 8192;
  print "+";
  sleep 1;
  print "*";
  sleep 60;

Here is an explanation of what the program does​:

1. get another filehandle for stdout
2. make it nonblocking (this also makes fd 1 nonblocking)
3. print a "-", which gets printed immediately.
4. write 8192 bytes, which is hopefully more than the tty supports
5. print a single "+", causing a write(), but results in EAGAIN
6. wait a while, print "*", which should cause a write(), but doesn't
7. give us time to look at the output.

Here is what I expect​:

  -* <---cursor here

  (-+* is another expected possibility)

here is what I usually get​:

  - <---cursor here

If I strace the program (carefully), I get (among others), this​:

  write(1, "-", 1) = 1
  write(3, "\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"..., 8192) = 4095
  write(1, "+", 1) = -1 EAGAIN (Resource temporarily unavailable)
  nanosleep({1, 0}, {1, 0}) = 0
  nanosleep({60, 0}, ...

As you can see, "-" gets printed, then our 8k dump fills the tty buffer,
then "+" gets written, but gets EAGAIN.

After a second, we write another "*", but perl will not even attempt the
write.

This is IMHO a bug, as $| should cause a flush, and thus a write().

Doing $|=0;$|=1 flushes the buffer, and the "*" appears, but subsequent
writes will still be buffered, and I found no way of resurrecting STDOUT
with autoflush, short of closing and reopening it.

Please note that I didn't investigate this further (it could quite likely
be stdio that would change buffering modes on EAGAIN, for example, and it
took me some days to locate the code that causes this behaviour and to
write a testcase).

I still think perl most be involved somehow, as an explicit flush (setting
$|=1) actually prints the buffer out fully - if perl would do a flush
after every print, as documented, I would expect it to still just work,
regardless of what stdio thinks about buffering.

Please also note that the "+" usually gets lost, which is somehow expected
or not, but the "*" and all subsequent prints get buffered internally and
will be written on excplit flush (setting $|) but will not be autoflushed.

Flags:
    category=core
    severity=low

Site configuration information for perl v5.8.8:

Configured by Marc Lehmann at Sat May 13 14:13:02 CEST 2006.

Summary of my perl5 (revision 5 version 8 subversion 8) configuration:
  Platform:
    osname=linux, osvers=2.6.16.11, archname=amd64-linux
    uname='linux fuji 2.6.16.11 #2 preempt thu may 4 14:20:31 cest 2006 i686 gnulinux '
    config_args='-Duselargefiles -Uuse64bitint -Uuse64bitall -Dusemymalloc=y -Dcc=gcc-4.0 -Dccflags=-ggdb -Dcppflags=-D_GNU_SOURCE -I/opt/include -Doptimize=-O4 -march=pentium3 -mtune=pentium3 -funroll-loops -fno-strict-aliasing -Dcccdlflags=-fPIC -Dldflags=-L/opt/perl/lib -L/opt/lib -Dlibs=-ldl -lm -lcrypt -Darchname=amd64-linux -Dprefix=/opt/perl -Dprivlib=/opt/perl/lib/perl5 -Darchlib=/opt/perl/lib/perl5 -Dvendorprefix=/opt/perl -Dvendorlib=/opt/perl/lib/perl5 -Dvendorarch=/opt/perl/lib/perl5 -Dsiteprefix=/opt/perl -Dsitelib=/opt/perl/lib/perl5 -Dsitearch=/opt/perl/lib/perl5 -Dsitebin=/opt/perl/bin -Dman1dir=/opt/perl/man/man1 -Dman3dir=/opt/perl/man/man3 -Dsiteman1dir=/opt/perl/man/man1 -Dsiteman3dir=/opt/perl/man/man3 -Dman1ext=1 -Dman3ext=3 -Dpager=/usr/bin/less -Uafs -Uusesfio -Uusenm -Uuseshrplib -Dd_dosuid -Dusethreads=undef -Duse5005threads=undef -Duseithreads=undef -Dusemultiplicity=undef -Demail=perl-binary@plan9.de -Dcf_email=perl-binary@plan9.de -Dcf_by=Marc Lehmann -Dlocincpth=/opt/perl/include /opt/include -Dmyhostname=localhost -Dmultiarch=undef -Dbin=/opt/perl/bin -des'
    hint=recommended, useposix=true, d_sigaction=define
    usethreads=undef use5005threads=undef useithreads=undef usemultiplicity=undef
    useperlio=define d_sfio=undef uselargefiles=define usesocks=undef
    use64bitint=undef use64bitall=undef uselongdouble=undef
    usemymalloc=y, bincompat5005=undef
  Compiler:
    cc='gcc-4.0', ccflags ='-ggdb -fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/opt/include -D_LARGEFILE_SOURCE -D_FILE_OFFSET_BITS=64',
    optimize='-O4 -march=pentium3 -mtune=pentium3 -funroll-loops -fno-strict-aliasing',
    cppflags='-D_GNU_SOURCE -I/opt/include -ggdb -fno-strict-aliasing -pipe -Wdeclaration-after-statement -I/opt/include'
    ccversion='', gccversion='4.0.3 (Debian 4.0.3-1)', gccosandvers=''
    intsize=4, longsize=4, ptrsize=4, doublesize=8, byteorder=1234
    d_longlong=define, longlongsize=8, d_longdbl=define, longdblsize=12
    ivtype='long', ivsize=4, nvtype='double', nvsize=8, Off_t='off_t', lseeksize=8
    alignbytes=4, prototype=define
  Linker and Libraries:
    ld='gcc-4.0', ldflags ='-L/opt/perl/lib -L/opt/lib -L/usr/local/lib'
    libpth=/usr/local/lib /lib /usr/lib /usr/ucblib
    libs=-ldl -lm -lcrypt
    perllibs=-ldl -lm -lcrypt
    libc=/lib/libc-2.3.6.so, so=so, useshrplib=false, libperl=libperl.a
    gnulibc_version='2.3.6'
  Dynamic Linking:
    dlsrc=dl_dlopen.xs, dlext=so, d_dlsymun=undef, ccdlflags='-Wl,-E'
    cccdlflags='-fPIC', lddlflags='-shared -L/opt/perl/lib -L/opt/lib -L/usr/local/lib'

Locally applied patches:
    MAINT27284


@INC for perl v5.8.8:
    /root/src/sex
    /opt/perl/lib/perl5
    /opt/perl/lib/perl5
    /opt/perl/lib/perl5
    /opt/perl/lib/perl5
    /opt/perl/lib/perl5
    /opt/perl/lib/perl5
    /opt/perl/lib/perl5
    .


Environment for perl v5.8.8:
    HOME=/root
    LANG (unset)
    LANGUAGE (unset)
    LC_CTYPE=de_DE.UTF-8
    LD_LIBRARY_PATH (unset)
    LOGDIR (unset)
    PATH=/root/s2:/root/s:/opt/bin:/opt/sbin:/bin:/sbin:/usr/bin:/usr/sbin:/usr/X11/bin:/usr/games:/root/src/uunet:.
    PERL5LIB=/root/src/sex
    PERL5_CPANPLUS_CONFIG=/root/.cpanplus/config
    PERLDB_OPTS=ornaments=0
    PERL_BADLANG (unset)
    PERL_UNICODE=EAL
    SHELL=/bin/bash

From @dcollinsn

I get some very inconsistent results from this​:

dcollins@​nightshade64​:~/toolchain$ perl5.25.0 41043.pl
-^C
dcollins@​nightshade64​:~/toolchain$ exit
Script done, file is /dev/null
dcollins@​nightshade64​:~/toolchain$ script /dev/null
Script started, file is /dev/null
dcollins@​nightshade64​:~/toolchain$ perl5.25.0 41043.pl
-+*^C
dcollins@​nightshade64​:~/toolchain$ perl5.25.0 41043.pl
-^C

Which is also what 5.8.8 does​:

dcollins@​nightshade64​:~/toolchain$ perl5.8.8 41043.pl
-+*^C
dcollins@​nightshade64​:~/toolchain$ perl5.8.8 41043.pl
-^C

Even a `reset` doesn't get back to the original behavior, but Ctrl-D, script /dev/null does. What is going on here?

--
Respectfully,
Dan Collins

From [Unknown Contact. See original ticket]

I get some very inconsistent results from this​:

dcollins@​nightshade64​:~/toolchain$ perl5.25.0 41043.pl
-^C
dcollins@​nightshade64​:~/toolchain$ exit
Script done, file is /dev/null
dcollins@​nightshade64​:~/toolchain$ script /dev/null
Script started, file is /dev/null
dcollins@​nightshade64​:~/toolchain$ perl5.25.0 41043.pl
-+*^C
dcollins@​nightshade64​:~/toolchain$ perl5.25.0 41043.pl
-^C

Which is also what 5.8.8 does​:

dcollins@​nightshade64​:~/toolchain$ perl5.8.8 41043.pl
-+*^C
dcollins@​nightshade64​:~/toolchain$ perl5.8.8 41043.pl
-^C

Even a `reset` doesn't get back to the original behavior, but Ctrl-D, script /dev/null does. What is going on here?

--
Respectfully,
Dan Collins

From zefram@fysh.org

This can be tested more cleanly by creating a pipe and never reading
from it, rather than writing to a tty and hoping that it can't keep up.

The behaviour seen arises from the sticky error status of an I/O handle.
In itself, the sticky error status is an intentional feature, which
can avoid the need to put high-level error-handling code on every I/O
operation. The failed output of the "+" sets the sticky error flag.
The effect of the error flag is then that, even though outputting "*"
succeeds as far as adding it to the buffer, that output operation is
considered failed. Consequently the print op aborts​: it doesn't attempt
the flush operation that would normally result from the autoflush flag
(which remains set), and it returns false. (If it were ignoring the
autoflush flag and thought it had succeeded in outputting "*" just by
adding it to the buffer then it would return true.)

Further enlightenment can be gained by changing the print operations to
each print two things, from separate operands, as in 'print "*", "*"'.
The operands are written to PerlIO sequentially, and the autoflush
happens after all of them. That sequence initially manifests by "--"
being passed to the write syscall in one go. The effect of the sticky
error then becomes clearer at the "*" line. Writing the first "*" to
the buffer succeeds, but the operation is considered failed because of
the sticky error flag. The print op therefore aborts before outputting
the second operand, and so when a flush eventually happens (e.g., on
program end) only the one "*" will be passed to the syscall.

You can clear the sticky error flag by using the ->clearerr method
of IO​::Handle. This is the appropriate thing to do with errors that
you expect to be transitory, such as EAGAIN. This will restore the
autoflushing behaviour that you're expecting​: the next print op after
->clearerr will automatically flush. If you've already buffered some
output with the error flag set then ->clearerr won't flush it, but
you can do an explicit ->flush at the same time. However, when you're
expecting to handle an error from a specific operation, it's best to
complete the error handling and clear the error flag *before* you try
to output anything that you want to succeed independently of the error
you've handled.

This behaviour isn't a bug in perl. However, it might be less strange
(though still a bit confusing) if the sticky error flag made subsequent
I/O operations fail *before* they were attempted. In this ticket's test
case, that would cause the "*" to be lost entirely, not even reappearing
at the end-of-program implicit flush. ->clearerr would still be needed
to handle EAGAIN, but we wouldn't get half-done print ops when the error
is not cleared.

We could also probably document this better.

-zefram

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

From @cpansprout

On Sun, 26 Mar 2017 17​:01​:37 -0700, zefram@​fysh.org wrote​:

This behaviour isn't a bug in perl.

I still consider it unacceptable. (I reported a similar bug some years ago with the same underlying cause. I don’t know the number or remember the subject line.)

However, it might be less strange
(though still a bit confusing) if the sticky error flag made subsequent
I/O operations fail *before* they were attempted. In this ticket's test
case, that would cause the "*" to be lost entirely, not even reappearing
at the end-of-program implicit flush. ->clearerr would still be needed
to handle EAGAIN, but we wouldn't get half-done print ops when the error
is not cleared.

If print is going to do two separate print operations behind the scenes when given two arguments, then both operations should happen the same way.

I.e., what you suggested above (which is unhelpful), or print("a","b") should be equivalent to print("a"),print("b"). If it can print the "a" without checking the error status, it should be able to print the "b" the same way.

--

Father Chrysostomos

From zefram@fysh.org

Father Chrysostomos via RT wrote​:

or print("a","b") should be equivalent to print("a"),print("b").

With autoflush processing after the "a"? Someone's bound to be annoyed
by thus splitting output that's currently merged. And would that mean
that print() (with no operands to print) doesn't autoflush at all?

If it can print the "a" without checking the error status, it should be
able to print the "b" the same way.

If we go that way, presumably we'd also do the autoflush (whether once or
twice) even when errored. Effectively we'd be kicking the sticky-error
behaviour up to a higher level. But this doesn't compose nicely.

We could expect that user code would contain higher-level I/O sequences
that check for error returns and will abort early. So the same problem
that arose with print("a", "b") only printing "a" would just arise again,
with (print("a") && print("b")). Would we encourage rewriting that to
ignore errors from each operation, only checking the handle's error status
at the end? What about when a new error actually occurs during output​:
do we want to try to output subsequent things anyway and save the error
up to the end? What if there's an error in the middle of outputting the
string resulting from a single operand​: should we skip a byte and try
again to output the subsequent bytes? Usually we don't want any such
continuance​: aborting the whole sequence as soon as an error happens is
the right thing.

So I'd favour what I proposed​: that the sticky error state should
prevent further operations being attempted. This does compose nicely,
in that all levels of code naturally get the consistent behaviour of
aborting as soon as an error occurs and not doing any further I/O until
the error is cleared. The unusual case of wanting to handle and clear
an error should bear the burden of determining the granularity at which
operations are to be resumed or retried.

-zefram