search

perl5-dbi / DBD-mysql

MySQL driver for the Perl5 Database Interface (DBI)
https://metacpan.org/module/DBD::mysql
Other
63 stars 73 forks source link

SIGSEGV with fastcgi #421

Open dveeden opened 8 months ago

dveeden commented 8 months ago

DBD::mysql version

5.003

MySQL client version

mysql80-client-8.0.35 from pkg repository.

Server version

8.0.35?

Operating system version

FreeBSD 14.0-RELEASE-p5

What happened?

https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=275100#c10

I have problem with proposed patch to DBD-mysql 5.003 in fatscgi app.

First request - ok, but on second - SIGSEGV.

pid 25640 (perl), jid 7, uid 1001: exited on signal 11 (no core dump - bad address)

Cut from ktrace & kdump:

 25640 perl     1.212731815 RET   recvfrom 23/0x17
 25640 perl     1.212884538 CALL  getpid
 25640 perl     1.212889746 RET   getpid 25640/0x6428
 25640 perl     1.212911504 CALL  sendto(0x6,0x8036c2800,0xb8,0,0,0)
 25640 perl     1.212926587 GIO   fd 6 wrote 184 bytes
...
SELECT query
...
 25640 perl     1.212929827 RET   sendto 184/0xb8
 25640 perl     1.212933261 CALL  recvfrom(0x6,0x8036a2c40,0x4000,0,0,0)
 25640 perl     1.213150127 GIO   fd 6 read 820 bytes
...
query result
...
 25640 perl     1.213162841 RET   recvfrom 820/0x334
 25640 perl     1.213262487 CALL  fstatat(AT_FDCWD,0x7fffffffde60,0x7fffffffdc70,0)
 25640 perl     1.213276137 NAMI  "/usr/local/share/mysql/charsets/Index.xml"
 25640 perl     1.213283888 STRU  struct stat {dev=17992529080455138850, ino=104834, mode=0100644, nlink=1, uid=0, gid=0, rdev=18446744073709551615, atime=0, mtime=1697111101, ctime=1710822993.085053000, birthtime=1697111101, size=19475, blksize=19968, blocks=13, flags=0x800 }
 25640 perl     1.213286687 RET   fstatat 0
 25640 perl     1.213303822 CALL  openat(AT_FDCWD,0x7fffffffde60,0<O_RDONLY>)
 25640 perl     1.213307599 NAMI  "/usr/local/share/mysql/charsets/Index.xml"
 25640 perl     1.213313081 RET   openat 8
 25640 perl     1.213323880 PSIG  SIGSEGV SIG_DFL code=SEGV_MAPERR

I have no problem with 4.050 from pkg repository or ports tree (even with small patch no problem).

Other information

No response

iHeadRu commented 8 months ago

Hi! It was me. 14.0-RELEASE-p5 mysql80-client-8.0.35 from pkg repository.

I have two such apps, but SIGSEGV only one. Opening/Closing database connection on each request not helps.

dveeden commented 8 months ago

Do you happen do have a simple way to reproduce this? Do you have a backtrace?

iHeadRu commented 8 months ago

I can reproduce problem. I don't have normal backtrace. app is launched by apache httpd mod_fastcgi. I have perl.core.

(gdb) core perl.core [New LWP 101036] Core was generated by `/usr/local/bin/perl /home/***/work.fcgi'. Program terminated with signal SIGSEGV, Segmentation fault. Address not mapped to object.

0 0x00000008007f8fa4 in ?? ()

(gdb) bt

0 0x00000008007f8fa4 in ?? ()

1 0x0000000000000001 in ?? ()

2 0x00000008007b76cd in ?? ()

3 0x0000000800aa6001 in ?? ()

4 0x0000000800aa6408 in ?? ()

5 0x00007fffffffdae0 in ?? ()

6 0x00000008025bc926 in ?? ()

7 0x0000000000000029 in ?? ()

8 0x00007fffffffde60 in ?? ()

9 0x000000000000002a in ?? ()

10 0x0000000000000410 in ?? ()

11 0x737f828eff9ffbce in ?? ()

12 0x0000000000000001 in ?? ()

13 0xffffffffffff693b in ?? ()

14 0x0000000801d4ca58 in ?? ()

15 0x0000000801d4ca40 in ?? ()

16 0x0000000000000080 in ?? ()

17 0x00007fffffffdb80 in ?? ()

18 0x00000008025bb0d9 in ?? ()

19 0x00007fffffffde60 in ?? ()

20 0x0000000100000069 in ?? ()

21 0x0000000801d4ca40 in ?? ()

22 0x0000000802961450 in ?? ()

23 0x0000000802250a92 in ?? ()

24 0x00007fff000000c2 in ?? ()

25 0x737f828eff9ffbce in ?? ()

26 0x0000000000000008 in ?? ()

27 0x0000000000000000 in ?? ()

How to get full backtrace? :)

iHeadRu commented 8 months ago

gdb /usr/local/bin/perl perl.core GNU gdb (GDB) 13.2 [GDB v13.2 for FreeBSD] Copyright (C) 2023 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later http://gnu.org/licenses/gpl.html This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-portbld-freebsd14.0". Type "show configuration" for configuration details. For bug reporting instructions, please see: https://www.gnu.org/software/gdb/bugs/. Find the GDB manual and other documentation resources online at: http://www.gnu.org/software/gdb/documentation/.

For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/local/bin/perl... (No debugging symbols found in /usr/local/bin/perl) [New LWP 100939] Core was generated by `/usr/local/bin/perl /home/***/work.fcgi'. Program terminated with signal SIGSEGV, Segmentation fault. Address not mapped to object.

0 0x0000000800d3ffa4 in ?? () from /lib/libc.so.7

(gdb) bt

0 0x0000000800d3ffa4 in ?? () from /lib/libc.so.7

1 0x00000008029bb0d9 in file_info::RegisterFilename(int, char const*, file_info::OpenType) () from /usr/local/lib/mysql/libmysqlclient.so.21

2 0x00000008029bcf97 in my_open(char const*, int, int) () from /usr/local/lib/mysql/libmysqlclient.so.21

3 0x00000008029b2b9f in ?? () from /usr/local/lib/mysql/libmysqlclient.so.21

4 0x00000008029b0bb3 in ?? () from /usr/local/lib/mysql/libmysqlclient.so.21

5 0x00000008032b9f9d in std::1::call_once(unsigned long volatile&, void, void ()(void*)) () from /lib/libc++.so.1

6 0x00000008029b1612 in my_charset_get_by_name(MY_CHARSET_LOADER, char const, unsigned int, int) () from /usr/local/lib/mysql/libmysqlclient.so.21

7 0x00000008029b181b in get_charset_by_csname(char const*, unsigned int, int) () from /usr/local/lib/mysql/libmysqlclient.so.21

8 0x00000008029486d4 in read_ok_ex () from /usr/local/lib/mysql/libmysqlclient.so.21

9 0x000000080294c659 in cli_read_rows(MYSQL, MYSQL_FIELD, unsigned int) () from /usr/local/lib/mysql/libmysqlclient.so.21

10 0x00000008029516e4 in mysql_store_result () from /usr/local/lib/mysql/libmysqlclient.so.21

11 0x00000008003d6ce6 in mysql_st_internal_execute () from /usr/local/lib/perl5/site_perl/mach/5.36/auto/DBD/mysql/mysql.so

12 0x00000008003d7720 in mysql_st_execute () from /usr/local/lib/perl5/site_perl/mach/5.36/auto/DBD/mysql/mysql.so

13 0x00000008003ddbdd in ?? () from /usr/local/lib/perl5/site_perl/mach/5.36/auto/DBD/mysql/mysql.so

14 0x00000008003b0683 in XS_DBI_dispatch () from /usr/local/lib/perl5/site_perl/mach/5.36/auto/DBI/DBI.so

15 0x0000000800952dd9 in Perl_pp_entersub () from /usr/local/lib/perl5/5.36/mach/CORE/libperl.so.5.36

16 0x00000008008bc1d3 in Perl_runops_debug () from /usr/local/lib/perl5/5.36/mach/CORE/libperl.so.5.36

17 0x000000080071e190 in ?? () from /usr/local/lib/perl5/5.36/mach/CORE/libperl.so.5.36

18 0x000000080071d272 in perl_run () from /usr/local/lib/perl5/5.36/mach/CORE/libperl.so.5.36

19 0x0000000000201f49 in main ()

igoltz commented 6 months ago

Probably related to this. I do get segfaults sometimes on Linux with Apache and fastcgi. I can't exactly reproduce, it happens from time to time. Looks like on first request after the service run for some time (day?) without active client access.

[255725.896783] sympasoap11.fcg[1988]: segfault at 7fe3a3db0f0c ip 00007fe3a16e877d sp 00007ffc32e846e0 error 7 in libmysqlclient.so.21.2.36[7fe3a1653000+42c000] [255725.896885] Code: 74 43 55 48 89 e5 53 48 89 fb 48 83 ec 08 48 8b 47 e8 48 8b 57 f0 8b 7f e0 48 8d 70 20 48 8d 05 39 15 88 00 48 8b 00 ff 50 20 <c7> 43 e4 ad de 00 00 48 83 c4 08 48 8d 7b e0 5b 5d e9 fd 38 f9 ff New perlbrew build of perl 5.30.3 on alma linux 8 with mysql-*-8.0.36, DBD::mysql is 5.004

With older build and DBD::mysql 4.050 and mariadb-10.5.22 all works fine.

dveeden commented 5 months ago

I tried to reproduce this, but didn't manage to do so.

Versions I used:

Script:

#!/usr/local/bin/perl
use strict;
use CGI::Fast;
use DBI;

while (my $q = CGI::Fast->new) {
    print "Content-Type: text/plain\n\n";
    print "Perl CGI::Fast Hello World! pid=$$\n";

    my $dbh = DBI->connect("dbi:mysql:host=127.0.0.1","root","Root123@");
    print "mysql client version: $dbh->{mysql_clientversion}\n";
    print "mysql server version: $dbh->{mysql_serverversion}\n";

    my $sth = $dbh->prepare("SELECT CONNECTION_ID();");
    $sth->execute || die "Execute failed: " . $sth->errstr . "\n";

    while (my $ref = $sth->fetchrow_arrayref) {
        print "Result: " . $$ref[0] . "\n";
    }

    $sth->finish;

    $dbh->do('ROLLBACK RELEASE');
    $dbh->ping;

    my $sth = $dbh->prepare("SELECT CONNECTION_ID();");
    $sth->execute || die "Execute failed: " . $sth->errstr . "\n";

    while (my $ref = $sth->fetchrow_arrayref) {
        print "Result: " . $$ref[0] . "\n";
    }

    $sth->finish;
}

Output:

$ curl http://127.0.0.1/cgi-bin/mysql.fcgi
Perl CGI::Fast Hello World! pid=21903
mysql client version: 80035
mysql server version: 80400
Result: 36
Result: 37
igoltz commented 5 months ago

We use Apache, the workload is wwsympa from https://github.com/sympa-community/sympa 6.2.72 via spawn-fcgi I can't reproduce in a way that I can trigger the crash. It happens from time to time. Having a client connect every 5 min did not trigger but only once a day did. Looks like on first request after the service run for some time (day?) without active client access. On the exact same perlbrew I reinstalled DBD::mysql cpanm DBD::mysql~"<5" and the problem was gone. What could I provide to dig deeper?

dveeden commented 5 months ago

That sounds like it would use a TCP connection for which the underlying connection was already closed by the OS.

igoltz commented 4 months ago

How can we help to find the root cause? As it works with DBD::mysql <5 , what changed there related to TCP connections?

dveeden commented 4 months ago
  1. Could you try with v5.007 ?
  2. Did you try with DBD::mysql 4.x and 5.x both with the same version MySQL client libraries?
  3. If you know what the last working version is (4.050?) and what the first version is with the issue (5.001?) then we could use git bisect to try and find which commit introduced this.
  4. This could be b5d72db5efc85d07eb313bce54b038e4781677fe but there are also many others that could have caused this...
  5. Could you set DBI_TRACE=1 (or a higher level) ? This could give some info about what's happening.
iHeadRu commented 2 months ago

Hi!

I found that problem is reproduced when script makes second connection to another database on same server with DBI->connect_cached(...) and make some prepare and execute.

DBI->connect(...) works fine.

FreeBSD 14.1 p5-DBD-mysql-5.005 mysql80-server-8.0.35_1

dveeden commented 6 days ago

@iHeadRu could you post a script to reproduce this?