develooper Front page | perl.perl5.porters | Postings from February 2006

[PATCH] PERL_TRACK_MEMPOOL cripples environment after exit()

Thread Next
From:
Marcus Holland-Moritz
Date:
February 26, 2006 11:50
Subject:
[PATCH] PERL_TRACK_MEMPOOL cripples environment after exit()
Message ID:
20060226204721.00be2bff@r2d2
Using the bleeding edge version of perl for your everyday
development is fun. It almost always keeps you from doing
real work. Instead, you find yourself digging in the perl
core because something seems odd. ;)

Today I've been doing (or better: I wanted to do) coverage
analysis with gcov for one of my XS modules again, and noticed
something strange:

  mhx@r2d2 ~/src/perl/Convert-Binary-C/Current-moretags $ make test
  PERL_DL_NONLAZY=1 /home/mhx/perl/blead-debug/bin/perl "-Iblib/lib" "-Iblib/arch" test.pl
  tests/001_init...........ok                                                  
  tests/101_basic..........ok                                                  
  tests/201_config.........dubious                                             
          Test returned status 0 (wstat 11, 0xb)
          after all the subtests completed successfully
  tests/202_misc...........dubious                                             
          Test returned status 0 (wstat 11, 0xb)
          after all the subtests completed successfully
  tests/203_warnings.......dubious                                             
          Test returned status 0 (wstat 11, 0xb)
          after all the subtests completed successfully
  tests/204_enum...........dubious                                             
          Test returned status 0 (wstat 11, 0xb)
          after all the subtests completed successfully
  [...]

So, the tests were doing fine, but they died anyway.
Running each test on their own was fine, too.
However, setting PERL_DL_NONLAZY=1 made them segfault:

  mhx@r2d2 $ PERL_DL_NONLAZY=1 bleadperl-debug -Mblib tests/202_misc.t >/dev/null
  Speicherzugriffsfehler

Changing the locale made the segfault go away.
Running under gdb, the segfault was gone, too.
I love those errors.

Running under valgrind, I saw these errors:

  ==16389== Invalid read of size 4
  ==16389==    at 0x412ED60: getenv (in /lib/libc-2.3.5.so)
  ==16389==    by 0x4723F18: gcov_exit (libgcov.c:198)
  ==16389==    by 0x412F4A1: exit (in /lib/libc-2.3.5.so)
  ==16389==    by 0x806063D: main (perlmain.c:115)
  ==16389==  Address 0x4235554 is 12 bytes inside a block of size 268 free'd
  ==16389==    at 0x401C319: free (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==16389==    by 0x80F1272: Perl_safesysfree (util.c:250)
  ==16389==    by 0x8065660: perl_free (perl.c:1294)
  ==16389==    by 0x80605FA: main (perlmain.c:107)
  [...]

I don't know how I could ever live without valgrind.

This reminded me of a problem I "fixed" a couple of days ago in
my small embedded memory checker that was using getenv() in an
atexit() routine. It seemed gcov was doing the same, and so I
assembled a small test case (see attached module).

This module does nothing but register an atexit() routine that
calls getenv(). And it promptly segfaults when you run "make test".
However, whether it segfaults or not depends on your environment.

Running under valgrind shows the same errors as above:

  mhx@r2d2 ~/src/perl/XS-Test/Current $ valgrind bleadperl-debug -Mblib t/test.t 
  ==16898== Memcheck, a memory error detector.
  ==16898== Copyright (C) 2002-2005, and GNU GPL'd, by Julian Seward et al.
  ==16898== Using LibVEX rev 1471, a library for dynamic binary translation.
  ==16898== Copyright (C) 2004-2005, and GNU GPL'd, by OpenWorks LLP.
  ==16898== Using valgrind-3.1.0, a dynamic binary instrumentation framework.
  ==16898== Copyright (C) 2000-2005, and GNU GPL'd, by Julian Seward et al.
  ==16898== For more details, rerun with: -v
  ==16898== 
  1..1
  # Running under perl version 5.009004 for linux
  # Current time local: Sun Feb 26 13:37:19 2006
  # Current time GMT:   Sun Feb 26 12:37:19 2006
  # Using Test.pm version 1.25
  ok 1
  ==16898== Invalid read of size 4
  ==16898==    at 0x412ED60: getenv (in /lib/libc-2.3.5.so)
  ==16898==    by 0x403513F: bye (stuff.c:6)
  ==16898==    by 0x412F4A1: exit (in /lib/libc-2.3.5.so)
  ==16898==    by 0x806063D: main (perlmain.c:115)
  ==16898==  Address 0x4235554 is 12 bytes inside a block of size 268 free'd
  ==16898==    at 0x401C319: free (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==16898==    by 0x80F1272: Perl_safesysfree (util.c:250)
  ==16898==    by 0x8065660: perl_free (perl.c:1294)
  ==16898==    by 0x80605FA: main (perlmain.c:107)
  ==16898== 
  ==16898== Invalid read of size 2
  ==16898==    at 0x412ED70: getenv (in /lib/libc-2.3.5.so)
  ==16898==    by 0x403513F: bye (stuff.c:6)
  ==16898==    by 0x412F4A1: exit (in /lib/libc-2.3.5.so)
  ==16898==    by 0x806063D: main (perlmain.c:115)
  ==16898==  Address 0x4235694 is 12 bytes inside a block of size 316 free'd
  ==16898==    at 0x401C319: free (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==16898==    by 0x80F1272: Perl_safesysfree (util.c:250)
  ==16898==    by 0x8065660: perl_free (perl.c:1294)
  ==16898==    by 0x80605FA: main (perlmain.c:107)
  ==16898== 
  ==16898== Invalid read of size 4
  ==16898==    at 0x412ED7C: getenv (in /lib/libc-2.3.5.so)
  ==16898==    by 0x403513F: bye (stuff.c:6)
  ==16898==    by 0x412F4A1: exit (in /lib/libc-2.3.5.so)
  ==16898==    by 0x806063D: main (perlmain.c:115)
  ==16898==  Address 0x4235558 is 16 bytes inside a block of size 268 free'd
  ==16898==    at 0x401C319: free (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==16898==    by 0x80F1272: Perl_safesysfree (util.c:250)
  ==16898==    by 0x8065660: perl_free (perl.c:1294)
  ==16898==    by 0x80605FA: main (perlmain.c:107)
  # FOO=[<undef>]
  ==16898== 
  ==16898== ERROR SUMMARY: 127 errors from 3 contexts (suppressed: 29 from 2)
  ==16898== malloc/free: in use at exit: 76,749 bytes in 2,208 blocks.
  ==16898== malloc/free: 30,485 allocs, 28,277 frees, 1,806,374 bytes allocated.
  ==16898== For counts of detected errors, rerun with: -v
  ==16898== searching for pointers to 2,208 not-freed blocks.
  ==16898== checked 553,060 bytes.
  ==16898== 
  ==16898== LEAK SUMMARY:
  ==16898==    definitely lost: 71,337 bytes in 2,189 blocks.
  ==16898==      possibly lost: 2,788 bytes in 2 blocks.
  ==16898==    still reachable: 2,624 bytes in 17 blocks.
  ==16898==         suppressed: 0 bytes in 0 blocks.
  ==16898== Use --leak-check=full to see details of leaked memory.

To reproduce this, you need a perl built with -DPERL_TRACK_MEMPOOL.

Interestingly, the error vanishes when you set PERL_DESTRUCT_LEVEL
to 1 or 2.

I wanted to find out where the block in question was actually
allocated (something I'd love valgrind to tell me), and more
interestingly, running with -Dm gives lots of other valgrind
errors, for example:

  ==17274== Memcheck, a memory error detector.
  ==17274== Copyright (C) 2002-2005, and GNU GPL'd, by Julian Seward et al.
  ==17274== Using LibVEX rev 1471, a library for dynamic binary translation.
  ==17274== Copyright (C) 2004-2005, and GNU GPL'd, by OpenWorks LLP.
  ==17274== Using valgrind-3.1.0, a dynamic binary instrumentation framework.
  ==17274== Copyright (C) 2000-2005, and GNU GPL'd, by Julian Seward et al.
  ==17274== For more details, rerun with: -v
  ==17274== 
  0x423bcb8: (00000) malloc 20 bytes
  ==17274== Invalid write of size 4
  ==17274==    at 0x80F0E09: Perl_safesysmalloc (util.c:111)
  ==17274==    by 0x8128D8B: Perl_sv_grow (sv.c:1449)
  ==17274==    by 0x8132B9B: Perl_sv_setpvn (sv.c:3731)
  ==17274==    by 0x813BC91: Perl_newSVpvn (sv.c:6634)
  ==17274==    by 0x81F6198: PerlIO_vprintf (perlio.c:4938)
  ==17274==    by 0x81F62AC: PerlIO_printf (perlio.c:4962)
  ==17274==    by 0x80F0FCE: Perl_safesysrealloc (util.c:181)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8133DEE: Perl_sv_catpv (sv.c:4141)
  ==17274==    by 0x806BF85: Perl_moreswitches (perl.c:3167)
  ==17274==    by 0x8066311: S_parse_body (perl.c:1662)
  ==17274==    by 0x8065EE9: perl_parse (perl.c:1570)
  ==17274==  Address 0x423BCBC is 4 bytes inside a block of size 20 free'd
  ==17274==    at 0x401CC8F: realloc (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==17274==    by 0x80F0F3A: Perl_safesysrealloc (util.c:178)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8133DEE: Perl_sv_catpv (sv.c:4141)
  ==17274==    by 0x806BF85: Perl_moreswitches (perl.c:3167)
  ==17274==    by 0x8066311: S_parse_body (perl.c:1662)
  ==17274==    by 0x8065EE9: perl_parse (perl.c:1570)
  ==17274==    by 0x80605C7: main (perlmain.c:101)
  ==17274== 
  ==17274== Invalid read of size 4
  ==17274==    at 0x80F0EC8: Perl_safesysrealloc (util.c:162)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8142B6A: Perl_sv_vcatpvfn (sv.c:9027)
  ==17274==    by 0x813F3C2: Perl_sv_vcatpvf (sv.c:7896)
  ==17274==    by 0x81F61BB: PerlIO_vprintf (perlio.c:4947)
  ==17274==    by 0x81F62AC: PerlIO_printf (perlio.c:4962)
  ==17274==    by 0x80F0FCE: Perl_safesysrealloc (util.c:181)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8133DEE: Perl_sv_catpv (sv.c:4141)
  ==17274==    by 0x806BF85: Perl_moreswitches (perl.c:3167)
  ==17274==    by 0x8066311: S_parse_body (perl.c:1662)
  ==17274==    by 0x8065EE9: perl_parse (perl.c:1570)
  ==17274==  Address 0x423BCBC is 4 bytes inside a block of size 20 free'd
  ==17274==    at 0x401CC8F: realloc (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==17274==    by 0x80F0F3A: Perl_safesysrealloc (util.c:178)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8133DEE: Perl_sv_catpv (sv.c:4141)
  ==17274==    by 0x806BF85: Perl_moreswitches (perl.c:3167)
  ==17274==    by 0x8066311: S_parse_body (perl.c:1662)
  ==17274==    by 0x8065EE9: perl_parse (perl.c:1570)
  ==17274==    by 0x80605C7: main (perlmain.c:101)
  ==17274== 
  ==17274== Invalid write of size 4
  ==17274==    at 0x80F10B8: Perl_safesysrealloc (util.c:197)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8142B6A: Perl_sv_vcatpvfn (sv.c:9027)
  ==17274==    by 0x813F3C2: Perl_sv_vcatpvf (sv.c:7896)
  ==17274==    by 0x81F61BB: PerlIO_vprintf (perlio.c:4947)
  ==17274==    by 0x81F62AC: PerlIO_printf (perlio.c:4962)
  ==17274==    by 0x80F0FCE: Perl_safesysrealloc (util.c:181)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8133DEE: Perl_sv_catpv (sv.c:4141)
  ==17274==    by 0x806BF85: Perl_moreswitches (perl.c:3167)
  ==17274==    by 0x8066311: S_parse_body (perl.c:1662)
  ==17274==    by 0x8065EE9: perl_parse (perl.c:1570)
  ==17274==  Address 0x423BCBC is 4 bytes inside a block of size 20 free'd
  ==17274==    at 0x401CC8F: realloc (in /usr/lib/valgrind/x86-linux/vgpreload_memcheck.so)
  ==17274==    by 0x80F0F3A: Perl_safesysrealloc (util.c:178)
  ==17274==    by 0x8128D7B: Perl_sv_grow (sv.c:1446)
  ==17274==    by 0x8133DEE: Perl_sv_catpv (sv.c:4141)
  ==17274==    by 0x806BF85: Perl_moreswitches (perl.c:3167)
  ==17274==    by 0x8066311: S_parse_body (perl.c:1662)
  ==17274==    by 0x8065EE9: perl_parse (perl.c:1570)
  ==17274==    by 0x80605C7: main (perlmain.c:101)
  [...]

The list continues until finally...

  ==17274== 
  ==17274== More than 100000 total errors detected.  I'm not reporting any more.
  ==17274== Final error counts will be inaccurate.  Go fix your program!
  ==17274== Rerun with --error-limit=no to disable this cutoff.  Note
  ==17274== that errors may occur in your program without prior warning from
  ==17274== Valgrind, because errors are no longer being displayed.
  ==17274== 

*sigh*

[BTW, why isn't it possible to just have a dwimmy printf()
somewhere in the perl core that doesn't depend on perlio?]

Well, I quickly hacked my own version of -Dm (by implementing
my_debug_printf(), and #undef'ing vfprintf and stderr before).

The memory block valgrind is complaining about was allocated from:

  #0  0x080f116b in Perl_safesysrealloc (where=0x8253098, size=272) at util.c:210
  #1  0x080f4ed5 in Perl_my_setenv (my_perl=0x823cdd0, nam=0x82660ac "REGRESSION_TEST", 

This somehow makes sense. It reallocs the (global) environment, but
adds the allocated block to the list of blocks to free at thread
exit. It then frees that block at thread exit, but doesn't restore
the old value of the environment.

And it's also clear now why setting PERL_DESTRUCT_LEVEL helps: There's
code to explicitly restore the original environment upon destruction.

So this is not a problem for extra threads (since they are always
completely destroyed prior to perl_free()), but only for the main
thread.

I'm not quite sure how and where this should be fixed without duplicating
too much old code or adding too much new code. However, the following
patchlet seemed straightforward to me, works nicely and doesn't seems to
introduce new test failures.

-----------8<-----------------------------------------------------------

--- miniperlmain.c.orig 2006-02-26 17:00:03.000000000 +0100
+++ miniperlmain.c      2006-02-26 17:20:52.000000000 +0100
@@ -106,6 +106,19 @@
 
     perl_free(my_perl);
 
+#if defined(USE_ENVIRON_ARRAY) && defined(PERL_TRACK_MEMPOOL)
+    /*
+     * The old environment may have been freed by perl_free()
+     * when PERL_TRACK_MEMPOOL is defined, but without having
+     * been restored by perl_destruct() before (this is only
+     * done if destruct_level > 0).
+     *
+     * It is important to have a valid environment for atexit()
+     * routines that are eventually called.
+     */
+    environ = env;
+#endif
+
 #ifdef PERL_GLOBAL_STRUCT
     free_global_struct(plvarsp);
 #endif /* PERL_GLOBAL_STRUCT */

-----------8<-----------------------------------------------------------

While being there, I wondered why free_global_struct() is being passed
an interpreter context argument when the only interpreter has just been
freed?

I think free_global_struct() uses free() instead of Safefree() (or any
other internal free routine) just because there is no valid interpreter
context at this point.

Marcus

-- 
    #else /* !STDSTDIO */     /* The big, slow, and stupid way */
            --Larry Wall in str.c from the perl source code

Thread Next


nntp.perl.org: Perl Programming lists via nntp and http.
Comments to Ask Bjørn Hansen at ask@perl.org | Group listing | About