perl5-dbi / DBD-MariaDB

Perl MariaDB driver
Other
32 stars 17 forks source link

SIGPIPE ignored, resulting in: "Unable to flush stdout: Broken pipe" #170

Open bugfood opened 2 years ago

bugfood commented 2 years ago

When DBD::MariaDB (or DBD::mysql) is used to connect to a database, the perl program thereafter fails to handle SIGPIPE as expected. I do not think this is necessarily the fault of DBD::MariaDB, but this might be the best place to handle it.

Here is an example test program:

#!/usr/bin/perl

use DBI;

my $dsn = "DBI:MariaDB:database=test";
# This is also reproducible with the mysql driver.
#my $dsn = "DBI:mysql:test";

if (@ARGV && $ARGV[0] eq 'fail') {
    my $dbh = DBI->connect($dsn, 'test', 'test');

    # This is not necessary to reproduce the problem, but it occurs either way.
    $dbh->disconnect;

    if (@ARGV > 1 && $ARGV[1] eq 'fix') {
        $SIG{PIPE} = undef;
    }
}

# There is a race condition of some sort; for me, roughly:
# < 2200 iterations succeeds
# 2200-2500 iterations is unreliable
# > 2500 iterations fails
foreach my $i (1..10000) {
    print "foo\n";
}

Without any arguments, the program does not connect and behaves as expected:

$ ./test.pl | head -n 1
foo

The program prints lines until the pipe closes, then exits cleanly.

When directed to, the program will fail by connecting (and disconnecting) before printing lines:

$ ./test.pl fail | head -n 1
foo
Unable to flush stdout: Broken pipe

This message is described here: https://stackoverflow.com/questions/50507849/weird-error-after-perl-upgrade-unable-to-flush-stdout

An strace reveals that SIGPIPE is indeed being ignored:

$ grep -E 'SIGPIPE|EPIPE' /tmp/strace-bad.log 
368030 rt_sigaction(SIGPIPE, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f695a1ac920}, {sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
368030 write(1, "foo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\n"..., 8192) = -1 EPIPE (Broken pipe)
368030 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=368030, si_uid=1000} ---
368030 write(1, "foo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\n"..., 8192) = -1 EPIPE (Broken pipe)
368030 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=368030, si_uid=1000} ---
368030 write(1, "foo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\n"..., 8192) = -1 EPIPE (Broken pipe)
368030 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=368030, si_uid=1000} ---
368030 rt_sigaction(SIGPIPE, NULL, {sa_handler=SIG_IGN, sa_mask=[PIPE], sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f695a1ac920}, 8) = 0
368030 write(1, "foo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\nfoo\n"..., 7232) = -1 EPIPE (Broken pipe)
368030 --- SIGPIPE {si_signo=SIGPIPE, si_code=SI_USER, si_pid=368030, si_uid=1000} ---

This appears to be coming from this commit in the C connector: https://github.com/mariadb-corporation/mariadb-connector-c/commit/1cefbbecb929b4b4a67b0ac23058ab0167e1c6d6#diff-478b1bbb2170532b687be58bd28e9850ccc0b9a6aec137eb8fff7b8e6d1107bbR3460

I can't tell what is the reason for this behavior; the commit message is rather cryptic.

The test program demonstrates good behavior again after resetting the default action for SIGPIPE:

$ ./test.pl fail fix | head -n 1
foo

This is about as far as I can troubleshoot the issue myself; I think somebody more familiar with the C connector would need to either: a. Tell me this is bad behavior and I should file a bug upstream for the C connector. b. Work around this behavior be saving/resetting the SIGPIPE action within DBD::MariaDB

Thanks, Corey

pali commented 2 years ago

Unconditionally overwriting signal handlers in external libraries (like in MariaDB C Connector) is really bad thing and obviously cause issues. I did not know that MariaDB C Connector is doing it. It is really an issue in MariaDB C Connector, so please report this bug.

We can add hack workaround into DBD::MariaDB to restore SIGPIPE handler after calling initialization of MariaDB C Connector from affected version. But this is just another hack which does not solve the root of the issue.

bugfood commented 2 years ago

That makes sense. I have a workaround in my local wrapper to restore the handler now, but if this doesn't get changed upstream, then I think it would be best for DBD::MariaDB to do so.

I did file a bug upstream now: https://jira.mariadb.org/browse/CONC-591

Thanks, Corey

pali commented 1 year ago

As there is no response from MariaDB bug tracker for more than year, I prepared a simple workaround for this issue in pull request https://github.com/perl5-dbi/DBD-MariaDB/pull/196

@bugfood Please look at it.

bugfood commented 1 year ago

Thank you. The PR tests out ok for me.

pali commented 1 year ago

Unfortunately simple workaround does not work, needs lot of more changes, explanation is in the pull request #196. This issue should be really fixed in the MariaDB client library (C connector).