Endless loop when using encoding layer on STDERR
From @eserte
The following script goes into an endless loop for all modern perl versions (5.8.9 .. 5.21.7, seen on FreeBSD and Linux):
#!/usr/bin/perl
my $extra_len = shift || 1022; # may be somewhat smaller, down to 970 or so binmode \*STDERR, ":encoding(US-ASCII)"; my $foo = "\x{dc}" . "x" x $extra_len; alarm 3; warn "$foo\n";
__END__
My guess: the inEncodeCall hack in PerlIO/encoding.xs was triggered, and maybe some file pointer was not advanced.
Regards, Slaven
From @jkeenan
On Tue Dec 23 14:23:50 2014, slaven@rezic.de wrote:
The following script goes into an endless loop for all modern perl versions (5.8.9 .. 5.21.7, seen on FreeBSD and Linux):
#!/usr/bin/perl
my $extra_len = shift || 1022; # may be somewhat smaller, down to 970 or so binmode \*STDERR, ":encoding(US-ASCII)"; my $foo = "\x{dc}" . "x" x $extra_len; alarm 3; warn "$foo\n";
__END__
My guess: the inEncodeCall hack in PerlIO/encoding.xs was triggered, and maybe some file pointer was not advanced.
Regards, Slaven
On Linux/amd64 (Ubuntu 14.04 LTS), find that if I run the code above I get the alarm after 3 seconds.
##### $ perl 123489-loop.pl Alarm clock #####
However, when I edit the file to insert a print to STDERR statement after the assignment to $foo, I get the endless loop.
##### $ cat 123489-loop.pl my $extra_len = shift || 1022; # may be somewhat smaller, down to 970 or so binmode \*STDERR, ":encoding(US-ASCII)"; my $foo = "\x{dc}" . "x" x $extra_len; print STDERR "$foo\n"; alarm 3; warn "$foo\n"; ##### $ perl 123489-loop.pl ^C #####
If, however, I print that line to STDOUT, I get the line, then the alarm in a few seconds.
Thank you very much.
-- James E Keenan (jkeenan@cpan.org)
The RT System itself - Status changed from 'new' to 'open'
From @eserte
Dana Uto 23. Pro 2014, 14:50:28, jkeenan reče:
On Tue Dec 23 14:23:50 2014, slaven@rezic.de wrote:
The following script goes into an endless loop for all modern perl versions (5.8.9 .. 5.21.7, seen on FreeBSD and Linux):
#!/usr/bin/perl
my $extra_len = shift || 1022; # may be somewhat smaller, down to 970 or so binmode \*STDERR, ":encoding(US-ASCII)"; my $foo = "\x{dc}" . "x" x $extra_len; alarm 3; warn "$foo\n";
__END__
My guess: the inEncodeCall hack in PerlIO/encoding.xs was triggered, and maybe some file pointer was not advanced.
Regards, Slaven
On Linux/amd64 (Ubuntu 14.04 LTS), find that if I run the code above I get the alarm after 3 seconds.
This is already the bug reproduced, unless you have a very (!) slow CPU which needs longer than three seconds for one warn() statement :-). The alarm clock is just there in case somebody wants to turn this into a test script which must not hang.
From @Leont
On Tue, Dec 23, 2014 at 11:23 PM, slaven@rezic.de <perlbug-followup@perl.org
wrote:
The following script goes into an endless loop for all modern perl versions (5.8.9 .. 5.21.7, seen on FreeBSD and Linux):
#!/usr/bin/perl
my $extra_len = shift || 1022; # may be somewhat smaller, down to 970 or so binmode \*STDERR, ":encoding(US-ASCII)"; my $foo = "\x{dc}" . "x" x $extra_len; alarm 3; warn "$foo\n";
__END__
My guess: the inEncodeCall hack in PerlIO/encoding.xs was triggered, and maybe some file pointer was not advanced.
This sounds like a duplicate of #117537
Leon
From @eserte
Dana Tue, 23 Dec 2014 14:23:50 -0800, slaven@rezic.de reče:
The following script goes into an endless loop for all modern perl versions (5.8.9 .. 5.21.7, seen on FreeBSD and Linux):
#!/usr/bin/perl
my $extra_len = shift || 1022; # may be somewhat smaller, down to 970 or so binmode \*STDERR, ":encoding(US-ASCII)"; my $foo = "\x{dc}" . "x" x $extra_len; alarm 3; warn "$foo\n";
__END__
My guess: the inEncodeCall hack in PerlIO/encoding.xs was triggered, and maybe some file pointer was not advanced.
Good news: starting with perl 5.29.9 the script does not hang anymore (checked on various FreeBSD and Linux systems).
A very similar issue was recently reported at https://bugs.debian.org/1104726 . I suspect the underlying bug is the same but this is just a different way to trigger it. The main difference is that this needs the -w option to happen.
This variant reliably hangs for me under Debian Linux with all recent Perl versions including current bleadperl.
perl -w -e 'binmode(STDERR, ":encoding(us-ascii)"); warn "\x{ff}" x 100)
The required length varies a bit but generally 30 or so seems to be enough.
I bisected it down to v5.13.4-306-g83c5555649
83c555564918110c20f99f55c77d9dfc27f217fb is the first bad commit commit 83c555564918110c20f99f55c77d9dfc27f217fb Author: Father Chrysostomos [email protected] Date: Thu Sep 16 14:07:50 2010 +0200
Fix warn to respect utf8-encoded scalars [perl #45549]t/op/warn.t | 26 +++++++++++++++++++++++++- util.c | 4 +--- 2 files changed, 26 insertions(+), 4 deletions(-)
and here's a backtrace from blead (commit 11de3f792e035101cd109b4e92e64036fe72a4f2) with -DDEBUGGING -DOptimize="-g -O0" when interrupted with Ctrl-C. Hope it helps a bit.
(gdb) run -Ilib -we 'binmode(STDERR, ":encoding(us-ascii)"); warn "\x{ff}" x 100'
Starting program: /home/ntyni/tmp/perl5/perl -Ilib -we 'binmode(STDERR, ":encoding(us-ascii)"); warn "\x{ff}" x 100'
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
^C
Program received signal SIGINT, Interrupt.
PerlIOBuf_write (f=0x555555c68380, vbuf=0x555555e3e4a0, count=37) at perlio.c:4580
4580 PerlIOBase(f)->flags |= PERLIO_F_WRBUF;
(gdb) bt
#0 PerlIOBuf_write (f=0x555555c68380, vbuf=0x555555e3e4a0, count=37) at perlio.c:4580
#1 0x00007ffff7c911db in PerlIOEncode_write (f=0x555555c68380, vbuf=0x555555e3e4a0, count=47)
at /home/ntyni/tmp/perl5/ext/PerlIO-encoding/encoding.xs:607
#2 0x00005555556c3072 in Perl_PerlIO_write (f=0x555555c68380, vbuf=0x555555e3e4a0, count=47) at perlio.c:2010
#3 0x000055555596f0bf in Perl_do_print (sv=0x555555c82d78, fp=0x555555c68380) at doio.c:2260
#4 0x000055555595496b in Perl_write_to_stderr (msv=0x555555c82d78) at util.c:1692
#5 0x0000555555955c8f in Perl_vwarn (pat=0x7ffff7c819c8 "\"\\x{%04lx}\" does not map to %s",
args=0x7fffffffd9c0) at util.c:2054
#6 0x00005555559563d3 in Perl_vwarner (err=44, pat=0x7ffff7c819c8 "\"\\x{%04lx}\" does not map to %s",
args=0x7fffffffd9c0) at util.c:2233
#7 0x000055555595609a in Perl_warner (err=44, pat=0x7ffff7c819c8 "\"\\x{%04lx}\" does not map to %s")
at util.c:2218
#8 0x00007ffff7c780f3 in encode_method (enc=0x7ffff7c85ba0 <ascii_encoding>, dir=0x7ffff7c854e0 <utf8_ascii>,
src=0x555555c519c0, s=0x555555c7f8e2 'ÿ' <repeats 83 times>, " at -e line 1.\n\"\\x{00ff}\" does not"...,
slen=0, check=2322, offset=0x0, term=0x0, retcode=0x0, fallback_cb=0x555555c47538 <PL_sv_immortals+24>)
at /home/ntyni/tmp/perl5/cpan/Encode/Encode.xs:244
#9 0x00007ffff7c7d5dd in XS_Encode__XS_encode (cv=0x555555ca9f00)
at /home/ntyni/tmp/perl5/cpan/Encode/Encode.xs:876
#10 0x000055555573800e in Perl_rpp_invoke_xs (cv=0x555555ca9f00) at /home/ntyni/tmp/perl5/inline.h:1176
#11 0x000055555575a093 in Perl_pp_entersub () at pp_hot.c:6540
#12 0x000055555563212c in Perl_runops_debug () at dump.c:3003
#13 0x00005555555ed211 in Perl_call_sv (sv=0x555555c75db0, arg_flags=130) at perl.c:3235
#14 0x00005555555ecd55 in Perl_call_method (methname=0x7ffff7c92f60 "encode", flags=2) at perl.c:3132
#15 0x00007ffff7c8f62b in PerlIOEncode_flush (f=0x555555c68380)
at /home/ntyni/tmp/perl5/ext/PerlIO-encoding/encoding.xs:429
#16 0x00005555556c31ee in Perl_PerlIO_flush (f=0x555555c68380) at perlio.c:2033
#17 0x00005555556c7449 in PerlIOBuf_write (f=0x555555c68380, vbuf=0x555555de0840, count=0) at perlio.c:4588
#18 0x00007ffff7c911db in PerlIOEncode_write (f=0x555555c68380, vbuf=0x555555de0840, count=215)
at /home/ntyni/tmp/perl5/ext/PerlIO-encoding/encoding.xs:607
#19 0x00005555556c3072 in Perl_PerlIO_write (f=0x555555c68380, vbuf=0x555555de0840, count=215) at perlio.c:2010
#20 0x000055555596f0bf in Perl_do_print (sv=0x555555c51618, fp=0x555555c68380) at doio.c:2260
#21 0x000055555595496b in Perl_write_to_stderr (msv=0x555555c51618) at util.c:1692
#22 0x0000555555955c12 in Perl_warn_sv (baseex=0x555555c75cf0) at util.c:2032
#23 0x00005555557902a6 in Perl_pp_warn () at pp_sys.c:580
#24 0x000055555563212c in Perl_runops_debug () at dump.c:3003
#25 0x00005555555ebb30 in S_run_body (oldscope=1) at perl.c:2883
#26 0x00005555555eb126 in perl_run (my_perl=0x555555c4f2a0) at perl.c:2798
#27 0x000055555559f175 in main (argc=4, argv=0x7fffffffeaa8, env=0x7fffffffead0) at perlmain.c:127
The required length varies a bit but generally 30 or so seems to be enough.
Yeah you would need a flush to trigger this so you'd need to fill the buffer first.
What I think we need here is an encoding option to suppress the warning, and to enable that for STDERR. Or maybe something else to prevent this kind of loop in general; this area is a bag of razors.