| Subject: | Script DIEs with "connection to database lost while in transaction" error |
| Date: | Mon, 3 Feb 2020 10:32:52 +0200 |
| To: | bug-DBIx-RetryOverDisconnects [...] rt.cpan.org |
| From: | "Ou, Oakridge" <oakridge [...] oakridge.ee> |
Greetings,
I am struggling with a script which is supposed to maintain PostgrSQL
connection in an environment where DBMS restarts occur.
Environment:
Debian 3.2.89-1 x86_64
PERL 5.4.12
Posgtresql v11
Below is my test script which performs an endless loop with a SQL UPDATE
every 5 seconds, wrapping each command into a transaction.
#! /usr/bin/perl
#
# use strict; # funktsioonile viitamine ei luba seda teha
use warnings;
use utf8::all;
# use locale;
use DBIx::RetryOverDisconnects;
use Devel::StackTrace;
use POSIX qw(strftime);
use Data::Dumper;
use Time::HiRes qw( time );
use URI::Escape;
use Encode qw(encode);
use Sys::Hostname;
use Sys::Syslog;
BEGIN { $0 =~ s|.*/||; } # what is this?
# conf file contains $overload_connection, $conf
if (-e "new-listener.conf") {
require "new-listener.conf";
} else {
die "No new-listener.conf file";
}
my $overload_dbi;
my $sleep = 2;
my $overload_connection_string;
sub connect_db {
# ~/.pgpass is fallback source of connection parameters
$overload_connection_string =
"dbi:Pg:dbname=$overload_connection{'database'} ";
$overload_connection_string .= "port=$overload_connection{'port'} "
if $overload_connection{'port'};
$overload_connection_string .= "host=$overload_connection{'host'} "
if $overload_connection{'host'};
$overload_dbi = DBIx::RetryOverDisconnects->connect
($overload_connection_string, $overload_connection{'user'},
$overload_connection{'password'} || undef,
{ AutoCommit => 1,
ReconnectRetries => 5,
ReconnectInterval => 1,
ReconnectTimeout => 3,
TxnRetries => 3,
}) || die "Cannot connect to database
($overload_connection_string) as $overload_connection{'user'}!
\n$DBI::errstr";
logi ("Connected to database $overload_connection_string as
$overload_connection{'user'}");
}
local $SIG{__DIE__} = sub {
my $stack = Devel::StackTrace->new()->as_string();
$overload_dbi->disconnect if defined ($overload_dbi);
$logistika_dbi->disconnect if defined ($logistika_dbi);
open (ERRFILE, '>>', 'new-listener-'.(strftime "%Y-%m-%d",
localtime).'.log');
print ERRFILE strftime "%Y.%m.%d %H:%M:%S ERROR ", localtime;
print ERRFILE $_[0] . "\n";
close (ERRFILE);
die $_[0];
};
local $SIG{__WARN__} = sub {
my $stack = Devel::StackTrace->new()->as_string();
open (WARNFILE, '>>', 'new-listener-'.(strftime "%Y-%m-%d",
localtime).'.log');
print WARNFILE strftime "%Y.%m.%d %H:%M:%S WARNING ", localtime;
print WARNFILE $_[0] . "\n";
close (WARNFILE);
};
# WARN handler clone which we may call from our code w/o warning trapping
sub notify_sysadmin {
my ($subject, $message) = @_;
my $warning_address = $conf{'warnmail'} || 'sysadmin@on24.ee';
open (WARNFILE, '>>', 'new-listener-'.(strftime "%Y-%m-%d",
localtime).'.log');
print WARNFILE strftime "%Y.%m.%d %H:%M:%S WARNING", localtime;
print WARNFILE "$subject\n$message\n";
close (WARNFILE);
};
sub logi {
open (LOGFILE, '>>','new-listener-'.(strftime "%Y-%m-%d",
localtime).'.log');
print LOGFILE strftime "%Y.%m.%d %H:%M:%S ", localtime;
print LOGFILE $_[0] . "\n";
close (LOGFILE);
}
logi ('Started');
connect_db;
for (;;) {
logi('updating');
$overload_dbi->txn_do(sub
{
$overload_dbi->do("UPDATE ac.test set counter = counter+1 where
id =1");
}
);
sleep 5;
}
$overload_dbi->disconnect;
The log file produced as also enclosed:
2020.02.03 10:26:34 Started
2020.02.03 10:26:34 Connected to database dbi:Pg:dbname=overload port=5432
host=test-db11.on24.top as listener
2020.02.03 10:26:34 updating
2020.02.03 10:26:39 updating
2020.02.03 10:26:44 updating
2020.02.03 10:26:49 updating
2020.02.03 10:26:54 updating
2020.02.03 10:26:59 updating
2020.02.03 10:26:59 WARNING DBD::Pg::db do failed: FATAL: terminating
connection due to administrator command
SSL connection has been closed unexpectedly at
/usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm line 313.
2020.02.03 10:26:59 ERROR DBD::Pg::db do failed: FATAL: terminating
connection due to administrator command
SSL connection has been closed unexpectedly at
/usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm line 313.
2020.02.03 10:26:59 WARNING Disconnected!
2020.02.03 10:26:59 WARNING Reconnect try #1
2020.02.03 10:26:59 WARNING Reconnected!
2020.02.03 10:26:59 ERROR Connection to database lost while in transaction
Trace begun at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 223
DBIx::RetryOverDisconnects::db::exc_conn_trans('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)')
called at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm line 357
DBIx::RetryOverDisconnects::db::take_measures('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'DBIx::RetryOverDisconnects::Exception=HASH(0xfbcc18)', undef, '') called
at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm line 323
DBIx::RetryOverDisconnects::db::__ANON__('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'UPDATE ac.test set counter = counter+1 where id =1') called at
new-listener.pl line 100
main::__ANON__ at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 489
eval {...} at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 487
DBIx::RetryOverDisconnects::db::txn_do('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'CODE(0xf1bf78)') called at new-listener.pl line 102
2020.02.03 10:26:59 WARNING DBD::Pg::db do failed: Database handle has been
disconnected at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 313.
2020.02.03 10:26:59 ERROR DBD::Pg::db do failed: Database handle has been
disconnected at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 313.
2020.02.03 10:26:59 ERROR DBD::Pg::db do failed: Database handle has been
disconnected at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 313.
Trace begun at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 322
DBIx::RetryOverDisconnects::db::__ANON__('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'UPDATE ac.test set counter = counter+1 where id =1') called at
new-listener.pl line 100
main::__ANON__ at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 489
eval {...} at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 487
DBIx::RetryOverDisconnects::db::txn_do('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'CODE(0xf1bf78)') called at new-listener.pl line 102
2020.02.03 10:26:59 ERROR DBD::Pg::db do failed: Database handle has been
disconnected at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 313.
Trace begun at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 322
DBIx::RetryOverDisconnects::db::__ANON__('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'UPDATE ac.test set counter = counter+1 where id =1') called at
new-listener.pl line 100
main::__ANON__ at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 489
eval {...} at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 487
DBIx::RetryOverDisconnects::db::txn_do('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'CODE(0xf1bf78)') called at new-listener.pl line 102
(Rollback OK)
Trace begun at /usr/local/share/perl/5.14.2/DBIx/RetryOverDisconnects.pm
line 503
DBIx::RetryOverDisconnects::db::txn_do('DBIx::RetryOverDisconnects::db=HASH(0xfc5850)',
'CODE(0xf1bf78)') called at new-listener.pl line 102
Best regards / С уважением
Pavel Murnikov (Mr.)