Bug #101934 for Test-Valgrind: t/20-bad.t failing on armv7hl

Wed Feb 04 10:50:03 2015 paul [...] city-fan.org - Ticket created

Subject:

t/20-bad.t failing on armv7hl

The test seems to die for some reason before running the last two tests in t/20-bad.t: $ make test TEST_VERBOSE=1 PERL_DL_NONLAZY=1 "/usr/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(1, 'blib/lib', 'blib/arch')" t/*.t # Testing Test::Valgrind 1.14, Perl 5.020001, /usr/bin/perl t/00-load.t ................... 1..1 ok 1 - use Test::Valgrind::Suppressions; ok # Using valgrind 3.10.1 located at /usr/bin/valgrind # Generating suppressions... # Suppressions for this perl stored in /builddir/.perl/Test-Valgrind/suppressions/1.14/memcheck-3.10.1-a3fef44d7e505b615ff0b4c945125f0f.supp # Using suppression file /builddir/.perl/Test-Valgrind/suppressions/1.14/memcheck-3.10.1-a3fef44d7e505b615ff0b4c945125f0f.supp t/10-good.t ................... 1..15 ok 1 - InvalidFree ok 2 - MismatchedFree ok 3 - InvalidRead ok 4 - InvalidWrite ok 5 - InvalidJump ok 6 - Overlap ok 7 - InvalidMemPool ok 8 - UninitCondition ok 9 - UninitValue ok 10 - SyscallParam ok 11 - ClientCheck ok 12 - Leak_DefinitelyLost ok 13 - Leak_IndirectlyLost ok 14 - Leak_PossiblyLost ok 15 - Leak_StillReachable ok # Using valgrind 3.10.1 located at /usr/bin/valgrind # Using suppression file /builddir/.perl/Test-Valgrind/suppressions/1.14/memcheck-3.10.1-a3fef44d7e505b615ff0b4c945125f0f.supp # Looks like you planned 17 tests but ran 15. t/20-bad.t .................... 1..17 ok 1 - InvalidFree ok 2 - MismatchedFree ok 3 - InvalidRead ok 4 - InvalidWrite ok 5 - InvalidJump ok 6 - Overlap ok 7 - InvalidMemPool ok 8 - UninitCondition ok 9 - UninitValue ok 10 - SyscallParam ok 11 - ClientCheck ok 12 - Leak_DefinitelyLost ok 13 - Leak_IndirectlyLost ok 14 - Leak_PossiblyLost ok 15 - Leak_StillReachable Dubious, test returned 255 (wstat 65280, 0xff00) Failed 2/17 subtests t/70-session.t ................ 1..7 ok 1 - no search_dirs ok 2 - nonexistant valgrind ok 3 - old valgrind ok 4 - new valgrind ok 5 - 'new valgrind isa Test::Valgrind::Session' isa 'Test::Valgrind::Session' ok 6 - old and new valgrind ok 7 - 'old and new valgrind isa Test::Valgrind::Session' isa 'Test::Valgrind::Session' ok # 8 suppressions, of which 8 are not empty t/80-suppressions.t ........... 1..4 ok 1 - suppression file is correctly named ok 2 - suppression file exists ok 3 - suppression file is readable ok 4 - Could open the suppression file ok t/81-suppressions-demangle.t .. 1..14 ok 1 - not encoded does not croak as expected ok 2 - not encoded ok 3 - VG_Z croaks as expected ok 4 - VG_Z ok 5 - no function name croaks as expected ok 6 - no function name ok 7 - soname encoded does not croak as expected ok 8 - soname encoded ok 9 - soname encoded 2 does not croak as expected ok 10 - soname encoded 2 ok 11 - function name encoded does not croak as expected ok 12 - function name encoded ok 13 - function name with invalid escapes croaks as expected ok 14 - function name with invalid escapes ok Test Summary Report ------------------- t/20-bad.t (Wstat: 65280 Tests: 15 Failed: 0) Non-zero exit status: 255 Parse errors: Bad plan. You planned 17 tests but ran 15. Files=6, Tests=56, 37 wallclock secs ( 0.13 usr 0.01 sys + 36.14 cusr 1.28 csys = 37.56 CPU) Result: FAIL Failed 1/6 test programs. 0/56 subtests failed. make: *** [test_dynamic] Error 255 Any ideas what this might be or how to go about debugging it?

Sat Oct 31 09:10:14 2015 paul [...] city-fan.org - Correspondence added

From:

paul [...] city-fan.org

With 1.15: $ make test PERL_DL_NONLAZY=1 "/usr/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(0, 'blib/lib', 'blib/arch')" t/*.t # Testing Test::Valgrind 1.15, Perl 5.022000, /usr/bin/perl t/00-load.t ................... ok # Using valgrind 3.11.0 located at /usr/bin/valgrind # Generating suppressions... # Suppressions for this perl stored in /builddir/.perl/Test-Valgrind/suppressions/1.15/memcheck-3.11.0-c5eee5b927f5836052ca21376f804d44.supp # Using suppression file /builddir/.perl/Test-Valgrind/suppressions/1.15/memcheck-3.11.0-c5eee5b927f5836052ca21376f804d44.supp # Using valgrind 3.11.0 located at /usr/bin/valgrind # Found 8 distinct suppressions # 1..1 # not ok 1 - dummy test in the child, should not interfere with the actual TAP stream # # # Failed test 'dummy test in the child, should not interfere with the actual TAP stream' # # at t/10-good.t line 30. # # Looks like you failed 1 test of 1. t/10-good.t ................... ok # Using valgrind 3.11.0 located at /usr/bin/valgrind # Using suppression file /builddir/.perl/Test-Valgrind/suppressions/1.15/memcheck-3.11.0-c5eee5b927f5836052ca21376f804d44.supp # dummy run-time exception, should not cause the test to fail at t/12-good-run-exception.t line 20. t/12-good-run-exception.t ..... ok # Using valgrind 3.11.0 located at /usr/bin/valgrind # Using suppression file /builddir/.perl/Test-Valgrind/suppressions/1.15/memcheck-3.11.0-c5eee5b927f5836052ca21376f804d44.supp # # leaking some bytes! # Failed test 'caught one extra leak' # at /builddir/build/BUILD/Test-Valgrind-1.15/blib/lib/Test/Valgrind.pm line 280. # got: '0' # expected: '1' # Failed test 'no extra leak caught, hence no bytes leaked' # at /builddir/build/BUILD/Test-Valgrind-1.15/blib/lib/Test/Valgrind.pm line 280. # Failed test 'no extra leak caught, hence no block leaked' # at /builddir/build/BUILD/Test-Valgrind-1.15/blib/lib/Test/Valgrind.pm line 280. # Looks like you failed 3 tests of 18. t/20-bad.t .................... Dubious, test returned 3 (wstat 768, 0x300) Failed 3/18 subtests t/70-session.t ................ ok # 8 suppressions, of which 8 are not empty t/80-suppressions.t ........... ok t/81-suppressions-demangle.t .. ok Test Summary Report ------------------- t/20-bad.t (Wstat: 768 Tests: 18 Failed: 3) Failed tests: 16-18 Non-zero exit status: 3 Files=7, Tests=74, 49 wallclock secs ( 0.15 usr 0.01 sys + 46.54 cusr 1.63 csys = 48.33 CPU) Result: FAIL Failed 1/7 test programs. 3/74 subtests failed.

Sat Oct 31 10:05:57 2015 vpit [...] cpan.org - Correspondence added

Hello and sorry for not answering sooner. Here are a few things that me may try out to get an idea about what's going on there : - What's the output of your perl -V ? - Could you attach the contents of the file /builddir/.perl/Test-Valgrind/suppressions/1.15/memcheck-3.11.0-c5eee5b927f5836052ca21376f804d44.supp to this ticket? It should contain no sensitive information about your setup. Note that if it has been destroyed (because builddir is temporary or whatnot) then it is enough to build the distribution and run "make test" to have it regenerated. - Can you try to build the distribution by running "perl Makefile.PL" from the unpacked tarball, and then run : /usr/bin/valgrind --leak-check=full --show-reachable=yes --leak-resolution=high --suppressions=/builddir/.perl/Test-Valgrind/suppressions/1.15/memcheck-3.11.0-c5eee5b927f5836052ca21376f804d44.supp /usr/bin/perl -Mblib -e'use Perl::Destruct::Level level => 3; use XSLoader; XSLoader::load("Test::Valgrind", "1.15"); Test::Valgrind::leak()' and attach the output? Thanks. Vincent

Sat Oct 31 10:05:57 2015 The RT System itself - Status changed from 'new' to 'open'

Sat Oct 31 12:19:27 2015 vpit [...] cpan.org - Correspondence added

Show quoted text

> - Can you try to build the distribution by running "perl Makefile.PL" > from the unpacked tarball, and then run : > > /usr/bin/valgrind --leak-check=full --show-reachable=yes --leak- > resolution=high --suppressions=/builddir/.perl/Test- > Valgrind/suppressions/1.15/memcheck-3.11.0- > c5eee5b927f5836052ca21376f804d44.supp /usr/bin/perl -Mblib -e'use > Perl::Destruct::Level level => 3; use XSLoader; > XSLoader::load("Test::Valgrind", "1.15"); Test::Valgrind::leak()' > > and attach the output?

Sorry, I forgot to tell you to run "make" after "perl Makefile.PL" and before the valgrind command. Vincent

Sat Oct 31 16:17:33 2015 paul [...] city-fan.org - Correspondence added

From:

paul [...] city-fan.org

armv7hl build: https://kojipkgs.fedoraproject.org//work/tasks/3180/11653180/build.log same package build on x86_64 for comparison: https://kojipkgs.fedoraproject.org//work/tasks/3181/11653181/build.log

Tue Nov 03 07:08:17 2015 vpit [...] cpan.org - Correspondence added

Thanks for the feedback. It appears that the suppression file generated by the module only contains generic stack frames and no reference whatsoever to any perl related symbol. This is why the malloc() call in the test XS code is ignored by valgrind, hence t/20-bad.t fails. This probably happens because your perl binary was stripped. The module has no chance to work with such a perl, because either it ignores the suppressions but reports perl internal leaks, or it uses the bogus suppression file and will never report anything (what happens now). I think the module should just skip the tests when no perl-related suppression is found in either the default or the user-supplied suppression files. I'll implement this whenever I have time, but given that it will not change anything regarding the usability of the module with these perls (the test will no longer fail, but the module will always skip Test::Valgrind test files), it has dropped pretty low on my priority list. Vincent

Tue Nov 03 09:07:46 2015 paul [...] city-fan.org - Correspondence added

From:

paul [...] city-fan.org

On Tue Nov 03 07:08:17 2015, VPIT wrote: Show quoted text

> Thanks for the feedback. > > It appears that the suppression file generated by the module only > contains generic stack frames and no reference whatsoever to any perl > related symbol. This is why the malloc() call in the test XS code is > ignored by valgrind, hence t/20-bad.t fails. > > This probably happens because your perl binary was stripped. The > module has no chance to work with such a perl, because either it > ignores the suppressions but reports perl internal leaks, or it uses > the bogus suppression file and will never report anything (what > happens now).

Is this the case just for the armv7hl build, as in theory it should be the same as the x86_64 build. If they're different, that would point to a toolchain issue that I could take up with the perl/gcc maintainers to see why the armv7hl build doesn't have the necessary information. In Fedora, the general approach to builds is that they're done with "-g" and then at the end of the build, the debug information (and only that) is stripped out and packaged in separate "debuginfo" packages. There's no general stripping out of binaries other than that.

Tue Nov 10 07:48:43 2015 vpit [...] cpan.org - Correspondence added

Show quoted text

> Is this the case just for the armv7hl build, as in theory it should be > the same as the x86_64 build. If they're different, that would point > to a toolchain issue that I could take up with the perl/gcc > maintainers to see why the armv7hl build doesn't have the necessary > information. > > In Fedora, the general approach to builds is that they're done with "- > g" and then at the end of the build, the debug information (and only > that) is stripped out and packaged in separate "debuginfo" packages. > There's no general stripping out of binaries other than that.

Then maybe you can run : nm /usr/bin/perl | grep -c "Perl_" to see whether the symbols are still visible, and : /usr/bin/valgrind --leak-check=full --show-reachable=yes --leak-resolution=high /usr/bin/perl -Mblib -e'use Perl::Destruct::Level level => 3; use XSLoader; XSLoader::load("Test::Valgrind", "1.15"); Test::Valgrind::leak()' to check if valgrind can see them.

Tue Nov 10 09:01:31 2015 paul [...] city-fan.org - Correspondence added

From:

paul [...] city-fan.org

On Tue Nov 10 07:48:43 2015, VPIT wrote: Show quoted text

> > Is this the case just for the armv7hl build, as in theory it should > > be > > the same as the x86_64 build. If they're different, that would point > > to a toolchain issue that I could take up with the perl/gcc > > maintainers to see why the armv7hl build doesn't have the necessary > > information. > > > > In Fedora, the general approach to builds is that they're done with > > "- > > g" and then at the end of the build, the debug information (and only > > that) is stripped out and packaged in separate "debuginfo" packages. > > There's no general stripping out of binaries other than that.

> > Then maybe you can run : > > nm /usr/bin/perl | grep -c "Perl_" > > to see whether the symbols are still visible, and : > > /usr/bin/valgrind --leak-check=full --show-reachable=yes --leak- > resolution=high /usr/bin/perl -Mblib -e'use Perl::Destruct::Level > level => 3; use XSLoader; XSLoader::load("Test::Valgrind", "1.15"); > Test::Valgrind::leak()' > > to check if valgrind can see them.

There's definitely a difference between the arches, but it's not the symbols - no symbols are found for *any* arch, yet i686 and x86_64 work OK: x86_64: https://kojipkgs.fedoraproject.org//work/tasks/1683/11771683/build.log i686: https://kojipkgs.fedoraproject.org//work/tasks/1684/11771684/build.log armv7hl: https://kojipkgs.fedoraproject.org//work/tasks/1682/11771682/build.log $ nm /usr/bin/perl nm: /usr/bin/perl: no symbols $ /usr/bin/valgrind --leak-check=full --show-reachable=yes --leak-resolution=high /usr/bin/perl -Mblib -e 'use Perl::Destruct::Level level => 3; use XSLoader; XSLoader::load("Test::Valgrind", "1.15"); Test::Valgrind::leak()' ==28714== Memcheck, a memory error detector ==28714== Copyright (C) 2002-2015, and GNU GPL'd, by Julian Seward et al. ==28714== Using Valgrind-3.11.0 and LibVEX; rerun with -h for copyright info ==28714== Command: /usr/bin/perl -Mblib -e use\ Perl::Destruct::Level\ level\ =\>\ 3;\ use\ XSLoader;\ XSLoader::load("Test::Valgrind",\ "1.15");\ Test::Valgrind::leak() ==28714== ==28714== Invalid read of size 4 ==28714== at 0x401C504: index (in /usr/lib/ld-2.22.90.so) ==28714== Address 0x4ed4c74 is 0 bytes after a block of size 44 alloc'd ==28714== at 0x484BC98: realloc (in /usr/lib/valgrind/vgpreload_memcheck-arm-linux.so) ==28714== ==28714== Conditional jump or move depends on uninitialised value(s) ==28714== at 0x401C504: index (in /usr/lib/ld-2.22.90.so) ==28714== ==28714== Conditional jump or move depends on uninitialised value(s) ==28714== at 0x401C508: index (in /usr/lib/ld-2.22.90.so) ==28714== ==28714== Conditional jump or move depends on uninitialised value(s) ==28714== at 0x4016B00: dl_open_worker (in /usr/lib/ld-2.22.90.so) ==28714== ==28714== Conditional jump or move depends on uninitialised value(s) ==28714== at 0x400972C: _dl_map_object (in /usr/lib/ld-2.22.90.so) ==28714== by 0x4016B5B: dl_open_worker (in /usr/lib/ld-2.22.90.so) ==28714== ==28714== ==28714== HEAP SUMMARY: ==28714== in use at exit: 12,634 bytes in 14 blocks ==28714== total heap usage: 15,994 allocs, 15,980 frees, 2,722,468 bytes allocated ==28714== ==28714== 2,262 bytes in 7 blocks are still reachable in loss record 1 of 2 ==28714== at 0x484BA38: calloc (in /usr/lib/valgrind/vgpreload_memcheck-arm-linux.so) ==28714== ==28714== 10,372 bytes in 7 blocks are still reachable in loss record 2 of 2 ==28714== at 0x4849498: malloc (in /usr/lib/valgrind/vgpreload_memcheck-arm-linux.so) ==28714== ==28714== LEAK SUMMARY: ==28714== definitely lost: 0 bytes in 0 blocks ==28714== indirectly lost: 0 bytes in 0 blocks ==28714== possibly lost: 0 bytes in 0 blocks ==28714== still reachable: 12,634 bytes in 14 blocks ==28714== suppressed: 0 bytes in 0 blocks ==28714== ==28714== For counts of detected and suppressed errors, rerun with: -v ==28714== Use --track-origins=yes to see where uninitialised values come from ==28714== ERROR SUMMARY: 14 errors from 5 contexts (suppressed: 0 from 0)

Tue Nov 10 09:28:14 2015 vpit [...] cpan.org - Correspondence added

My guess is that valgrind on arm, which is still pretty young, isn't able to get the symbols from the separate splitdebug file. Unfortunately there isn't much we can do about that, except gracefully skipping the test when the suppressions are empty.

Tue Nov 10 09:38:48 2015 paul [...] city-fan.org - Correspondence added

From:

paul [...] city-fan.org

On Tue Nov 10 09:28:14 2015, VPIT wrote: Show quoted text

> My guess is that valgrind on arm, which is still pretty young, isn't > able to get the symbols from the separate splitdebug file. > Unfortunately there isn't much we can do about that, except gracefully > skipping the test when the suppressions are empty.

That looks reasonable. FWIW, you can track the issue I've raised in Fedora's bugzilla here: https://bugzilla.redhat.com/show_bug.cgi?id=1090505 It's moved on a bit from the original report I filed but I'm keeping it up to date in case the valgrind guys have any ideas.

Mon Nov 16 10:03:00 2015 vpit [...] cpan.org - Correspondence added

This should have been fixed with version 1.16.

Mon Nov 16 10:03:37 2015 vpit [...] cpan.org - Status changed from 'open' to 'resolved'

Mon Nov 16 10:03:44 2015 vpit [...] cpan.org - Severity Normal added

Mon Nov 16 10:03:44 2015 vpit [...] cpan.org - Fixed in 1.16 added

Mon Nov 16 10:03:45 2015 vpit [...] cpan.org - Broken in 1.14 deleted