Bug#871562: perl-base: Perl binary crashes with SIGSEGV when used for SVN access in "git svn" tests

Sun Aug 20 19:26:42 UTC 2017

Control: found -1 5.26.0-5

On Wed, Aug 09, 2017 at 05:31:24PM +0300, Niko Tyni wrote:
> On Wed, Aug 09, 2017 at 11:16:03AM +0200, Alex Riesen wrote:
> > Package: perl-base
> > Version: 5.24.1-3+deb9u1
> > Severity: normal
> 
> > when I run the test suite (Git (the VCS, master branch), the perl binary
> > sometimes crashes in one of its tests. I used the commands below to reproduce
> > the problem (just let it run, it'll crash eventually):

> Anyway, I'll see if I can reproduce this when I find the time.

It's reproducible and happens on 5.26 too, but is indeed
nondeterministic. It's not specific to any particular git-svn command.
I've been experimenting with a loop like

 while ~/tmp/git/git-svn branch -t tag-$i; do i=$(expr $i + 1); done

which seems to crash every few hundred runs or so on my system. That's
rare enough that distilling a minimized test case is very hard.

Running with /usr/bin/debugperl from perl-debug (which is not optimized
and has assertions and the like enabled), I got the backtrace below.
I also got at least once these messages:

 error closing pipe: Bad file descriptor at /home/niko/tmp/git/git-svn line 0.
 Attempt to free unreferenced scalar: SV 0x3fbc6949d0, Perl interpreter: 0x3fbb4a4010 at /usr/share/perl5/Git.pm line 1108 during global destruction.

Valgrind doesn't help much, trace below too. I don't see any earlier
out of bound writes or anything like that. Running with strace shows
mainly that it crashes at the very end, but we knew that already.

It looks to me like this happens during global destruction cleanup
when file handles get closed, and it's probably triggered by a specific
order of the DESTROY method calls (which is undefined and random.)

The abovementioned Git.pm:1108 is the last line of
_close_cat_blob(). Running with debugperl -DD (log attached) shows that
it crashes when cleaning 'cat_blob_out' of a Git object. That makes
me think it should be possible to reproduce it somehow just by running
Git::cat_blob() or so, but I haven't managed that yet.

I'm running out of steam for now so I thought it best to document the
current state of the investigations. The main thing missing is a smaller
test case, and it still seems at least possible that the svn bindings
are doing something naughty on the C side that causes this.

gdb backtrace:
=========================================================================
Core was generated by `/usr/bin/debugperl /home/niko/tmp/git/git-svn branch -t tag-8354'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000000bb84712cd1 in Perl_PerlIO_error (my_perl=my_perl at entry=0xbb8599e010, f=0xbb86b90c38)
    at perlio.c:1696
1696    perlio.c: No such file or directory.
(gdb) bt
#0  0x000000bb84712cd1 in Perl_PerlIO_error (my_perl=my_perl at entry=0xbb8599e010, f=0xbb86b90c38)
    at perlio.c:1696
#1  0x000000bb846cfe7b in Perl_io_close (my_perl=0xbb8599e010, io=io at entry=0xbb86caafd0, gv=gv at entry=0x0, not_implicit=not_implicit at entry=true, warn_on_fail=warn_on_fail at entry=false) at doio.c:1124
#2  0x000000bb846d007d in Perl_do_close (my_perl=my_perl at entry=0xbb8599e010, gv=<optimized out>, 
    gv at entry=0xbb86c506d8, not_implicit=not_implicit at entry=true) at doio.c:1083
#3  0x000000bb846af1d9 in Perl_pp_close (my_perl=0xbb8599e010) at pp_sys.c:683
#4  0x000000bb845dbc9a in Perl_runops_debug (my_perl=0xbb8599e010) at dump.c:2451
#5  0x000000bb845383be in Perl_call_sv (my_perl=my_perl at entry=0xbb8599e010, sv=sv at entry=0xbb85f67a40, flags=flags at entry=45) at perl.c:2848
#6  0x000000bb84629c1a in S_curse (my_perl=my_perl at entry=0xbb8599e010, sv=sv at entry=0xbb869b6388, check_refcnt=check_refcnt at entry=true) at sv.c:6972
#7  0x000000bb8462a5ad in Perl_sv_clear (my_perl=my_perl at entry=0xbb8599e010, orig_sv=orig_sv at entry=0xbb869b6388)
    at sv.c:6576
#8  0x000000bb8462b695 in Perl_sv_free2 (my_perl=0xbb8599e010, sv=0xbb869b6388, rc=<optimized out>) at sv.c:7073
#9  0x000000bb8462750b in S_visit (my_perl=0xbb8599e010, f=0xbb8462bd30 <do_clean_objs>, flags=2048, mask=2048)
    at sv.c:476
#10 0x000000bb8462c2a6 in Perl_sv_clean_objs (my_perl=my_perl at entry=0xbb8599e010) at sv.c:627
#11 0x000000bb8453d10a in perl_destruct (my_perl=0xbb8599e010) at perl.c:856
#12 0x000000bb84509fc5 in main (argc=<optimized out>, argv=<optimized out>, env=<optimized out>)
    at perlmain.c:134
=========================================================================

valgrind:
=========================================================================
28055== Invalid read of size 8
==28055==    at 0x33FCC9: Perl_PerlIO_error (perlio.c:1696)
==28055==    by 0x2FCD86: Perl_io_close (doio.c:1115)
==28055==    by 0x2FD07C: Perl_do_close (doio.c:1083)
==28055==    by 0x2DC1D8: Perl_pp_close (pp_sys.c:683)
==28055==    by 0x208C99: Perl_runops_debug (dump.c:2451)
==28055==    by 0x1653BD: Perl_call_sv (perl.c:2848)
==28055==    by 0x256C19: S_curse (sv.c:6972)
==28055==    by 0x2575AC: Perl_sv_clear (sv.c:6576)
==28055==    by 0x258694: Perl_sv_free2 (sv.c:7073)
==28055==    by 0x25450A: S_visit (sv.c:476)
==28055==    by 0x2592A5: Perl_sv_clean_objs (sv.c:627)
==28055==    by 0x16A109: perl_destruct (perl.c:856)
==28055==  Address 0x30 is not stack'd, malloc'd or (recently) free'd
==28055==
==28055==
==28055== Process terminating with default action of signal 11 (SIGSEGV): dumping core
==28055==  Access not within mapped region at address 0x30
==28055==    at 0x33FCC9: Perl_PerlIO_error (perlio.c:1696)
==28055==    by 0x2FCD86: Perl_io_close (doio.c:1115)
==28055==    by 0x2FD07C: Perl_do_close (doio.c:1083)
==28055==    by 0x2DC1D8: Perl_pp_close (pp_sys.c:683)
==28055==    by 0x208C99: Perl_runops_debug (dump.c:2451)
==28055==    by 0x1653BD: Perl_call_sv (perl.c:2848)
==28055==    by 0x256C19: S_curse (sv.c:6972)
==28055==    by 0x2575AC: Perl_sv_clear (sv.c:6576)
==28055==    by 0x258694: Perl_sv_free2 (sv.c:7073)
==28055==    by 0x25450A: S_visit (sv.c:476)
==28055==    by 0x2592A5: Perl_sv_clean_objs (sv.c:627)
==28055==    by 0x16A109: perl_destruct (perl.c:856)
==28055==  If you believe this happened as a result of a stack
==28055==  overflow in your program's main thread (unlikely but
==28055==  possible), you can try to increase the size of the
==28055==  main thread stack using the --main-stacksize= flag.
==28055==  The main thread stack size used in this run was 8388608.
==28055==
=========================================================================

(Compressed debugperl -DD output is attached.)
-- 
Niko Tyni   ntyni at debian.org
-------------- next part --------------
A non-text attachment was scrubbed...
Name: DD.crash.gz
Type: application/gzip
Size: 3302 bytes
Desc: not available
URL: <http://lists.alioth.debian.org/pipermail/perl-maintainers/attachments/20170820/4ab46806/attachment.bin>