search

bucardo / dbdpg

Perl Postgres driver DBD::Pg aka dbdpg
48 stars 36 forks source link

Mysterious failures with DBI@1.634 #62

Closed ribasushi closed 4 years ago

ribasushi commented 5 years ago

One of DBIC's tests causes interpreter corruption when run against DBI@1.634 and DBD::Pg 3.10.0 ( specifically due to commit: https://github.com/bucardo/dbdpg/commit/81b518137a08a ). The exit code is 255 and the The exact error is:

~$ perl -Ilib t/72pg.t
...
ok 256 - Auto-PK for sequence without default: First primary key set manually
ok 257 - with_deferred_fk_checks code survived
ok 258 - code in with_deferred_fk_checks worked
ok 259 - with_deferred_fk_checks is off outside of TXN
ok 260 - Still expected exception on deferred failure at commit time
ok 261 - No warnings on deferred rollback
Use of freed value in iteration at t/72pg.t line 489.

ASAN instrumentation sadly does not reveal anything, however one of DBD::Pg's own tests fails like so:

PGINITDB="/usr/lib/postgresql/9.5/bin/initdb" PERL_DL_NONLAZY=1 "/home/rabbit/perl5/perlbrew/perls/5.24.3_asan/bin/perl" "-MExtUtils::Command::MM" "-MTest::Harness" "-e" "undef *Test::Harness::Switches; test_harness(0, 'blib/lib', 'blib/arch')" t/*.t
t/00_release.t ......... skipped: Test skipped unless environment variable RELEASE_TESTING is set
t/00_signature.t ....... skipped: Set the environment variable TEST_SIGNATURE to enable this test
t/00basic.t ............ ok   
t/01connect.t .......... Please wait, creating new database (version 9.5) for testing
t/01connect.t .......... 15/15 # 
# DBI                         Version 1.634
# DBD::Pg                     Version 3.10.0
# Perl                        Version 5.24.3
# OS                          linux
# PostgreSQL (compiled)       90503
# PostgreSQL (target)         90503
# PostgreSQL (reported)       PostgreSQL 9.5.3 on x86_64-pc-linux-gnu, compiled by gcc (Debian 5.3.1-19) 5.3.1 20160509, 64-bit
# Default port                5432
# DBI_DSN                     dbi:Pg:db="postgres";port=5440;host=<pwd>/dbdpg_test_database/data/socket
# DBI_USER                    rabbit
# Test schema                 dbd_pg_testschema
# LANG                        C
# array_nulls                 on
# backslash_quote             safe_encoding
# client_encoding             UTF8
# server_encoding             UTF8
# standard_conforming_strings on
# Adjusted:                   initdb
t/01connect.t .......... ok     
t/01constants.t ........ ok     
t/02attribs.t .......... ok       
t/03dbmethod.t ......... ok       
t/03smethod.t .......... ok       
t/04misc.t ............. ok       
t/06bytea.t ............ ok     
t/07copy.t ............. ok     
t/08async.t ............ ok     
t/09arrays.t ........... 186/201 =================================================================
==3554==ERROR: AddressSanitizer: heap-use-after-free on address 0x612000049cc0 at pc 0x7fd0f6ff001c bp 0x7fff0bac5310 sp 0x7fff0bac5308
READ of size 4 at 0x612000049cc0 thread T0
    #0 0x7fd0f6ff001b in pg_st_destroy /home/rabbit/devel/dbic/dbdpg/dbdimp.c:3972
    #1 0x7fd0f6fafbb6 in XS_DBD__Pg__st_DESTROY Pg.xsi:799
    #2 0x7fd0f727892a in XS_DBI_dispatch /home/rabbit/.cpanm/work/1571091303.2816/DBI-1.634/DBI.xs:3748
    #3 0x60d72c in Perl_pp_entersub /home/rabbit/perl5/perlbrew/build/perl-5.24.3/pp_hot.c:3988
    #4 0x47379d in Perl_call_sv /home/rabbit/perl5/perlbrew/build/perl-5.24.3/perl.c:2807
    #5 0x61bcc3 in S_curse /home/rabbit/perl5/perlbrew/build/perl-5.24.3/sv.c:6853
    #6 0x61da8f in Perl_sv_clear /home/rabbit/perl5/perlbrew/build/perl-5.24.3/sv.c:6457
    #7 0x61e75e in Perl_sv_free2 /home/rabbit/perl5/perlbrew/build/perl-5.24.3/sv.c:6954
    #8 0x618381 in S_visit /home/rabbit/perl5/perlbrew/build/perl-5.24.3/sv.c:476
    #9 0x61f7bb in Perl_sv_clean_objs /home/rabbit/perl5/perlbrew/build/perl-5.24.3/sv.c:627
    #10 0x47b9f2 in perl_destruct /home/rabbit/perl5/perlbrew/build/perl-5.24.3/perl.c:816
    #11 0x421ae0 in main /home/rabbit/perl5/perlbrew/build/perl-5.24.3/perlmain.c:127
    #12 0x7fd0fa7f6b44 in __libc_start_main (/lib/x86_64-linux-gnu/libc.so.6+0x21b44)
    #13 0x4220b4 (/home/rabbit/perl5/perlbrew/perls/5.24.3_asan/bin/perl+0x4220b4)

0x612000049cc0 is located 0 bytes inside of 266-byte region [0x612000049cc0,0x612000049dca)
freed by thread T0 here:
    #0 0x7fd0fb948527 in __interceptor_free (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x54527)
    #1 0x61cd19 in Perl_sv_clear /home/rabbit/perl5/perlbrew/build/perl-5.24.3/sv.c:6652

previously allocated by thread T0 here:
    #0 0x7fd0fb94873f in malloc (/usr/lib/x86_64-linux-gnu/libasan.so.1+0x5473f)
    #1 0x59d231 in Perl_safesysmalloc /home/rabbit/perl5/perlbrew/build/perl-5.24.3/util.c:153

SUMMARY: AddressSanitizer: heap-use-after-free /home/rabbit/devel/dbic/dbdpg/dbdimp.c:3972 pg_st_destroy
Shadow bytes around the buggy address:
  0x0c2480001340: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c2480001350: fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa fa
  0x0c2480001360: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
  0x0c2480001370: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c2480001380: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
=>0x0c2480001390: fa fa fa fa fa fa fa fa[fd]fd fd fd fd fd fd fd
  0x0c24800013a0: fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd fd
  0x0c24800013b0: fd fd fd fd fd fd fd fd fd fd fa fa fa fa fa fa
  0x0c24800013c0: fa fa fa fa fa fa fa fa 00 00 00 00 00 00 00 00
  0x0c24800013d0: 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
  0x0c24800013e0: 00 00 00 00 00 00 00 00 00 fa fa fa fa fa fa fa
Shadow byte legend (one shadow byte represents 8 application bytes):
  Addressable:           00
  Partially addressable: 01 02 03 04 05 06 07 
  Heap left redzone:       fa
  Heap right redzone:      fb
  Freed heap region:       fd
  Stack left redzone:      f1
  Stack mid redzone:       f2
  Stack right redzone:     f3
  Stack partial redzone:   f4
  Stack after return:      f5
  Stack use after scope:   f8
  Global redzone:          f9
  Global init order:       f6
  Poisoned by user:        f7
  Contiguous container OOB:fc
  ASan internal:           fe
==3554==ABORTING
t/09arrays.t ........... Dubious, test returned 1 (wstat 256, 0x100)
All 201 subtests passed 
t/10_pg_error_field.t .. ok     
t/12placeholders.t ..... NOTICE:  drop cascades to table dbd_pg_testschema.dbdpg_error_field_test
t/12placeholders.t ..... ok       
t/20savepoints.t ....... ok   
t/30unicode.t .......... ok     
t/99_lint.t ............ skipped: Test skipped unless environment variable AUTHOR_TESTING is set
t/99_perlcritic.t ...... skipped: Test skipped unless environment variable AUTHOR_TESTING is set
t/99_pod.t ............. skipped: Test skipped unless environment variable AUTHOR_TESTING is set
t/99_spellcheck.t ...... skipped: Test skipped unless environment variable AUTHOR_TESTING is set
t/99_yaml.t ............ skipped: Test skipped unless environment variable RELEASE_TESTING is set
t/99cleanup.t .......... ok   

Test Summary Report
-------------------
t/09arrays.t         (Wstat: 256 Tests: 201 Failed: 0)
  Non-zero exit status: 1
Files=23, Tests=2845, 60 wallclock secs ( 1.50 usr  0.20 sys + 17.94 cusr  3.64 csys = 23.28 CPU)
Result: FAIL
turnstep commented 4 years ago

Thanks for the report, I'm investigating some crash-on-free errors right now, hopefully whatever fixes come out of it will clear this up too.

turnstep commented 4 years ago

Can you try version 3.10.3 or better? I'm hoping it fixes this.

turnstep commented 4 years ago

Closing for now, as there has been much work on memory freeing problems since the original report. Please re-open if still seen on recent versions of DBD::Pg

ribasushi commented 4 years ago

The ASAN issue is gone, but the Use of freed value in iteration at t/72pg.t line 489. is still there. Likely no point reopening, may be a DBI bug instead that Pg tickles.

esabol commented 4 years ago

The ASAN issue is gone, but the Use of freed value in iteration at t/72pg.t line 489. is still there.

There’s nothing on line 489 in the version linked above. It’s blank. I looked at the current version, and line 489 there is like $@ ....

Could you try narrowing down 72pg.t to be just the code which causes the error and posting it here? That might be help track down the cause.

If it’s not fixed, it should be reopened, IMHO.

ribasushi commented 4 years ago

@esabol the source line is likely misleading due to internal corruption. The problem is still there, reproducible on 4 separate perls: https://travis-ci.com/github/Perl5/DBIx-Class/builds/173364908 Key is an older version of DBI with a current version of DBD::Pg. This is why I am not that interested in digging into it further. You can certainly take this onwards, would be much appreciated!

esabol commented 4 years ago

Key is an older version of DBI with a current version of DBD::Pg.

So you’re saying there is no error with the current version of DBI and the current version of DBD::Pg? If so, I agree there’s no point in digging further.

turnstep commented 4 years ago

FWIW I am doing some heavy testing across various versions of DBI and Postgres. Nothing related found yet (but did flush out some other minor bugs)

ribasushi commented 4 years ago

@turnstep note that this is something I can easily reproduce on any system. That particular DBI version with latest DBD::Pg. Should fail the same way for you too...

turnstep commented 4 years ago

@ribasushi Hmm I cannot get DBIx::Class to work (separate issue). I will try to duplicate everything else as much as I can with regards to the DBD::Pg test output posted above. Perhaps its related to more than just the DBI/DBD::Pg combo.

ribasushi commented 4 years ago

I cannot get DBIx::Class to work (separate issue).

Huh... things should install without fail these days. Could you please file a bugreport ( just email bug-DBIx-Class@rt.cpan.org ) Thanks!

In any case: I will reduce the test to a standalone DBIC-less script later today, reproducing the above.

turnstep commented 4 years ago

It's probably me, not the software. I can git checkout the repo, but when I run perl Makefile.PL it complains about line 201, with WriteAll line, despite having Module::AutoInstall installed.

ribasushi commented 4 years ago

@turnstep I'd say a git clean -fxd will fix it. There is likely something in your checkout dir...

turnstep commented 4 years ago

Sweet, that unblocked things! Will let you know if I can dupe that bug now.

turnstep commented 4 years ago

Cannot dupe on 72pg.t or 09arrays.t: used DBI 1.642, DBD::Pg 3.10.0, and Postgres 9.5.18 (was not able to compile 9.5.3). Perl was a little newer, 5.26.3. Thus, going to leave this closed. If anyone can duplicate and run on a newer version of Postgres 9.5 (latest is 9.5.22), that would be good to rule out the possibility it's a bug related to 9.5.3.