5.10 showstopper? Memory corruption with heavy module loading in threads

Jerry D. Hedden wrote:
> There seems to be a memory corruption problem that
manifests
> itself when several threads try to load a whole bunch
of
> modules at the same time.

I would consider this bug a showstopper.  While the
supplied
script uses threads to evoke the bug, it seems to me that
the memory corruption problem could occur even with
non-threaded scripts.  (Or am I just being paranoid?)

Jerry D. Hedden wrote:
> Jerry D. Hedden wrote:
>> There seems to be a memory corruption problem that
manifests
>> itself when several threads try to load a whole
bunch of
>> modules at the same time.
> 
> I would consider this bug a showstopper.  While the
supplied
> script uses threads to evoke the bug, it seems to me
that
> the memory corruption problem could occur even with
> non-threaded scripts.  (Or am I just being paranoid?)

As 5.8.8 cores, too, I would rate this as "no worse
than 5.8.8" and thus not a
stopper.

BTW  The fireworks with bleadperl sure are pretty...

$ bleadperl ~/Downloads/fetch_bug.pl
bleadperl(5440,0x190de00) malloc: ***  Deallocation of a
pointer not malloced:
0x4f26c0; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x190de00) malloc: ***  Deallocation of a
pointer not malloced:
0x46a050; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x190de00) malloc: ***  Deallocation of a
pointer not malloced:
0x46a050; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x190de00) malloc: ***  Deallocation of a
pointer not malloced:
0x46a050; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x190de00) malloc: ***  Deallocation of a
pointer not malloced:
0x1196150; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x190de00) malloc: ***  Deallocation of a
pointer not malloced:
0x1196150; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x18c4800) malloc: *** error for object
0x1197870: double free
bleadperl(5440,0x18c4800) malloc: *** set a breakpoint in
szone_error to debug
bleadperl(5440,0x18c4800) malloc: *** error for object
0x1197be0: double free
bleadperl(5440,0x18c4800) malloc: *** set a breakpoint in
szone_error to debug
bleadperl(5440,0x190de00) malloc: *** error for object
0x11962d0: double free
bleadperl(5440,0x190de00) malloc: *** set a breakpoint in
szone_error to debug
bleadperl(5440,0x18c4800) malloc: ***  Deallocation of a
pointer not malloced:
0x1196150; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
bleadperl(5440,0x18c4800) malloc: ***  Deallocation of a
pointer not malloced:
0x1196150; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
Unbalanced string table refcount: (1) for
"SO_CHAMELEON" during global
destruction.
Unbalanced string table refcount: (1) for
"AF_GOSIP" during global destruction.
Unbalanced string table refcount: (1) for
"SO_ATTACH_FILTER" during global
destruction.
Unbalanced string table refcount: (1) for
"AF_OSINET" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_WIRE" during global destruction.
Unbalanced string table refcount: (1) for "PF_CTF"
during global destruction.
Unbalanced string table refcount: (1) for
"SCM_CONNECT" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_URG" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_MCAST" during global destruction.
Unbalanced string table refcount: (1) for
"SO_XOPEN" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_CTLFLAGS" during global
destruction.
Unbalanced string table refcount: (1) for
"PF_USER" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_FIN" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_SYN" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_CTLIGNORE" during global
destruction.
Unbalanced string table refcount: (1) for
"SO_PROTOCOL" during global destruction.
Unbalanced string table refcount: (1) for
"SO_DONTLINGER" during global
destruction.
Unbalanced string table refcount: (1) for
"UIO_MAXIOV" during global destruction.
Unbalanced string table refcount: (1) for
"TCP_STDURG" during global destruction.
Unbalanced string table refcount: (1) for
"SO_PEERCRED" during global destruction.
Unbalanced string table refcount: (1) for "AF_WAN"
during global destruction.
Unbalanced string table refcount: (1) for
"SO_FAMILY" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_ETAG" during global destruction.
Unbalanced string table refcount: (1) for "PF_X25"
during global destruction.
Unbalanced string table refcount: (1) for
"SCM_CREDENTIALS" during global
destruction.
Unbalanced string table refcount: (1) for "PF_AAL"
during global destruction.
Unbalanced string table refcount: (1) for
"MSG_BCAST" during global destruction.
Unbalanced string table refcount: (1) for "AF_X25"
during global destruction.
Unbalanced string table refcount: (1) for
"SO_STATE" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_RST" during global destruction.
Unbalanced string table refcount: (1) for "AF_802"
during global destruction.
Unbalanced string table refcount: (1) for
"AF_LAST" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_MAXIOVLEN" during global
destruction.
Unbalanced string table refcount: (1) for
"MSG_BTAG" during global destruction.
Unbalanced string table refcount: (1) for
"AF_USER" during global destruction.
Unbalanced string table refcount: (1) for
"PF_GOSIP" during global destruction.
Unbalanced string table refcount: (1) for
"SO_PROTOTYPE" during global
destruction.
Unbalanced string table refcount: (1) for
"SO_SECURITY_ENCRYPTION_NETWORK"
during global destruction.
Unbalanced string table refcount: (1) for "PF_NIT"
during global destruction.
Unbalanced string table refcount: (1) for
"SO_DETACH_FILTER" during global
destruction.
Unbalanced string table refcount: (1) for "SO_XSE"
during global destruction.
Unbalanced string table refcount: (1) for
"PF_LAST" during global destruction.
Unbalanced string table refcount: (1) for
"SO_BACKLOG" during global destruction.
Unbalanced string table refcount: (1) for "AF_NIT"
during global destruction.
Unbalanced string table refcount: (1) for
"SO_SECURITY_ENCRYPTION_TRANSPORT"
during global destruction.
Unbalanced string table refcount: (1) for "AF_KEY"
during global destruction.
Unbalanced string table refcount: (1) for "AF_AAL"
during global destruction.
Unbalanced string table refcount: (1) for
"SO_SECURITY_AUTHENTICATION" during
global destruction.
Unbalanced string table refcount: (1) for "AF_CTF"
during global destruction.
Unbalanced string table refcount: (1) for "AF_NBS"
during global destruction.
Unbalanced string table refcount: (1) for
"MSG_ERRQUEUE" during global
destruction.
Unbalanced string table refcount: (1) for
"TCP_MAXRT" during global destruction.
Unbalanced string table refcount: (1) for
"SO_PASSCRED" during global destruction.
Unbalanced string table refcount: (1) for
"MSG_PROXY" during global destruction.
Unbalanced string table refcount: (1) for "PF_802"
during global destruction.
Unbalanced string table refcount: (1) for
"MSG_NOSIGNAL" during global
destruction.
Unbalanced string table refcount: (1) for "PF_NBS"
during global destruction.
Unbalanced string table refcount: (1) for
"PF_OSINET" during global destruction.
Unbalanced string table refcount: (1) for
"SO_DGRAM_ERRIND" during global
destruction.
Unbalanced string table refcount: (1) for "PF_WAN"
during global destruction.
Unbalanced string table refcount: (1) for
"SO_PASSIFNAME" during global
destruction.
bleadperl(5440,0x187b600) malloc: ***  Deallocation of a
pointer not malloced:
0x4320d0; This could be a double free(), or free() called
with the middle of
an allocated block; Try setting environment variable
MallocHelp to see tools
to help debug
Attempt to free non-existent shared string 'SO_BACKLOG',
Perl interpreter:
0x18c4c00 during global destruction.
Attempt to free non-existent shared string
'SO_DETACH_FILTER', Perl
interpreter: 0x18c4c00 during global destruction.
Attempt to free non-existent shared string 'PF_NBS', Perl
interpreter:
0x18c4c00 during global destruction.
Attempt to free non-existent shared string 'PF_WAN', Perl
interpreter:
0x18c4c00 during global destruction.
Attempt to free non-existent shared string 'PF_AAL', Perl
interpreter:
0x18c4c00 during global destruction.
Attempt to free non-existent shared string 'SO_PASSIFNAME',
Perl interpreter:
0x18c4c00 during global destruction.
Bus error (core dumped)


-- 
The interface should be as clean as newly fallen snow and
its behavior
as explicit as Japanese eel porn.

Jerry D. Hedden wrote:
> There seems to be a memory corruption problem that
manifests
> itself when several threads try to load a whole bunch
of
> modules at the same time.
>
> I would consider this bug a showstopper.  While the
supplied
> script uses threads to evoke the bug, it seems to me
that
> the memory corruption problem could occur even with
> non-threaded scripts.  (Or am I just being paranoid?)

Michael G Schwern wrote:
> As 5.8.8 cores, too, I would rate this as "no
worse than
> 5.8.8" and thus not a stopper.

It may be that the problem is not new to 5.9, but the ease
with which it can be evoked is very disturbing.  The test
script is a simple LWP::Simple get() in a thread.  If
that's
unstable, there will be a lot of bug reports when 5.10 goes
out.

On Wed, Sep 05, 2007 at 02:06:25PM -0400, Jerry D. Hedden
wrote:
> Jerry D. Hedden wrote:
> > There seems to be a memory corruption problem that
manifests
> > itself when several threads try to load a whole
bunch of
> > modules at the same time.
> >
> > I would consider this bug a showstopper.  While
the supplied
> > script uses threads to evoke the bug, it seems to
me that
> > the memory corruption problem could occur even
with
> > non-threaded scripts.  (Or am I just being
paranoid?)
> 
> Michael G Schwern wrote:
> > As 5.8.8 cores, too, I would rate this as "no
worse than
> > 5.8.8" and thus not a stopper.
> 
> It may be that the problem is not new to 5.9, but the
ease
> with which it can be evoked is very disturbing.  The
test
> script is a simple LWP::Simple get() in a thread.  If
that's
> unstable, there will be a lot of bug reports when 5.10
goes


Actually I've reduced the test case to:

    use threads;

    threads->create(&thr_fetch) for 1..20;
    warn "waiting for threads to finishn";
    $_->join for threads->list();

    sub thr_fetch
    {
	require dummy; 
    }

where dummy.pm just contains the single line "1;"

This gives a "panic: free from wrong pool".

I hope to track down this problem when I get a bit of free
time.

-- 
"Do not dabble in paradox, Edward, it puts you in
danger of fortuitous wit."
    -- Lady Croom, "Arcadia"

On Wed, Sep 12, 2007 at 10:53:36AM -0400, Jerry D. Hedden
wrote:
> I've reduced it yet again:
> 
>     use threads;
> 
>     threads->create(sub { eval '1' }) for 1..20;
>     print("Waiting for threads to
finishn");
>     $_->join() foreach (threads->list());

Turns out there are at least two bugs. The one above has
been fixed by
change #31864. However, the code in the bug report still
fails. I have
reduced that to:

    use threads;

    sub f {
	require IO;
    }

    my t;
    push t, threads->create(&f) for 1..80;
    $_->join for t;

which fails about 1 in 10 times. It might be associated with
creating const
subs via XS. I'll look further when I get time.

-- 
"You're so sadly neglected, and often ignored.
A poor second to Belgium, When going abroad."
    -- Monty Python, "Finland"

Jerry D. Hedden wrote:
> I've reduced it yet again:
>
>     use threads;
>
>     threads->create(sub { eval '1' }) for 1..20;
>     print("Waiting for threads to
finishn");
>     $_->join() foreach (threads->list());

Dave Mitchell wrote:
> Turns out there are at least two bugs. The one above
has been fixed by
> change #31864. However, the code in the bug report
still fails. I have
> reduced that to:
>
>     use threads;
>
>     sub f {
>         require IO;
>     }
>
>     my t;
>     push t, threads->create(&f) for 1..80;
>     $_->join for t;
>
> which fails about 1 in 10 times. It might be associated
with creating const
> subs via XS. I'll look further when I get time.

Any chance of tackling this before the code freeze, Dave?

On Fri, Sep 14, 2007 at 07:31:22PM +0100, Dave Mitchell
wrote:
> On Wed, Sep 12, 2007 at 10:53:36AM -0400, Jerry D.
Hedden wrote:
> > I've reduced it yet again:
> > 
> >     use threads;
> > 
> >     threads->create(sub { eval '1' }) for
1..20;
> >     print("Waiting for threads to
finishn");
> >     $_->join() foreach (threads->list());
> 
> Turns out there are at least two bugs. The one above
has been fixed by
> change #31864. However, the code in the bug report
still fails. I have
> reduced that to:
> 
>     use threads;
> 
>     sub f {
> 	require IO;
>     }
> 
>     my t;
>     push t, threads->create(&f) for 1..80;
>     $_->join for t;
> 
> which fails about 1 in 10 times. It might be associated
with creating const
> subs via XS. I'll look further when I get time.

Now fixed (hopefully) by #32091.

-- 
"Emacs isn't a bad OS once you get used to it.
It just lacks a decent editor."

Change 32091 by davemdavem-pigeon on 2007/10/10 15:03:16

	newCONTSUB() wasn't thread-safe ([perl #45053])

Affected files ...

... //depot/perl/ext/threads/t/problems.t#18 edit
... //depot/perl/op.c#958 edit

Differences ...

==== //depot/perl/ext/threads/t/problems.t#18 (text) ====

 -29,9
+29,9 
 
     $| = 1;
     if ($] == 5.008) {
-        print("1..11n");   ### Number of tests
that will be run ###
+        print("1..12n");   ### Number of tests
that will be run ###
     } else {
-        print("1..15n");   ### Number of tests
that will be run ###
+        print("1..16n");   ### Number of tests
that will be run ###
     }
 };
 
 -178,4
+178,20 
 $child = threads->create(sub { return
(scalar(keys(%h))); })->join;
 is($child, 1, "keys correct in child with restricted
hash");
 
+
+# [perl #45053] Memory corruption with heavy module loading
in threads
+#
+# run-time usage of newCONSTSUB (as done by the IO boot
code) wasn't
+# thread-safe - got occasional coredumps or malloc
corruption
+
+{
+    my t;
+    push t, threads->create( sub { require IO }) for
1..100;
+    $_->join for t;
+    print("ok $test - [perl #45053]n");
+    $test++;
+}
+
+
+
 # EOF

==== //depot/perl/op.c#958 (text) ====

 -5696,6
+5696,13 
 
     ENTER;
 
+    if (IN_PERL_RUNTIME) {
+	/* at runtime, it's not safe to manipulate PL_curcop: it
may be
+	 * an op shared between threads. Use a non-shared COP for
our
+	 * dirty work */
+	 SAVEVPTR(PL_curcop);
+	 PL_curcop = &PL_compiling;
+    }
     SAVECOPLINE(PL_curcop);
     CopLINE_set(PL_curcop, PL_parser ?
PL_parser->copline : NOLINE);
 

Jerry D. Hedden wrote:
> I've reduced it yet again:
>
>     use threads;
>
>     threads->create(sub { eval '1' }) for 1..20;
>     print("Waiting for threads to
finishn");
>     $_->join() foreach (threads->list());

Dave Mitchell wrote:
> Turns out there are at least two bugs. The one above
has been fixed by
> change #31864. However, the code in the bug report
still fails. I have
> reduced that to:
>
>     use threads;
>
>     sub f {
>       require IO;
>     }
>
>     my t;
>     push t, threads->create(&f) for 1..80;
>     $_->join for t;
>
> which fails about 1 in 10 times. It might be associated
with creating const
> subs via XS. I'll look further when I get time.

Dave Mitchell wrote:
> Now fixed (hopefully) by #32091.

Excellent.

> Affected files ...
>
> ... //depot/perl/ext/threads/t/problems.t#18 edit
> ... //depot/perl/op.c#958 edit

I think the test should go in t/op/threads.t because it is a
change to
core code, and not to the threads module code.  I'll submit
a patch
for this.