Too many different dynamic events crash server
----------------------------------------------
Key: CORE-3859
URL: http://tracker.firebirdsql.org/browse/CORE-3859
Project: Firebird Core
Issue Type: Bug
Components: Engine
Affects Versions: 2.0.7, 2.1.4, 2.0.6, 2.1.3, 2.1.5
Environment: CentOS 5 (5.5 and 5.8)
Reporter: Pete Cervasio
A recent change to how our software is using triggers to create dynamic events
has been found to crash the firebird server.
Our software is watching for changes to a 'PLAYLIST' table which has entries
containing station number and date and time values. Since the system doesn't
care about changes that are not within the immediate time frame a dynamic set
of events was created in the form of 'PLAYLIST_INSERTED_x_yyyy-mm-dd_hh' where
'x' is a station number, 'yyyy-mm-dd' is the contents of a date field, and 'hh'
is the first two characters of the scheduled time field. At the start of each
hour, the program registers interest in the current and next hours.
After approximately 616 event registrations and event occurrences, the Firebird
server will crash. Changing the length of the event names to use a single
character 'I' instead of 'PLAYLIST_INSERTED_' makes that number jump a bit
higher, but the crash still happens.
Operating system : CentOS 5.8 (but also tested on 5.5)
Firebird server : Tested on versions 2.0.6, 2.0.7, 2.1.4 and 2.1.5 release
candidate (from 22 May 2012)
Server log when the crash happens:
~>tail /opt/firebird/firebird.log
serv1-0000.sbcglobal.net (Client) Mon May 28 14:26:04 2012
/opt/firebird/bin/fbguard: /opt/firebird/bin/fbserver terminated
abnormally (-1)
serv1-0000.sbcglobal.net (Client) Mon May 28 14:26:04 2012
/opt/firebird/bin/fbguard: guardian starting bin/fbserver
Sample database:
-- ------------------------------------------------------------
-- ISQL scriptlet:
create database '/tmp/event_fail.fdb';
-- A table with the bare minimum to show this problem:
create table playlist (
station_number integer not null,
scheduled_date date not null,
scheduled_time varchar(12) not null
);
-- Two triggers to go with it:
set term ;!!
create trigger pe_playlist_deleted for playlist
active after delete position 0 as
begin
post_event 'PLAYLIST_DELETED_' || old.station_number || '_' ||
old.scheduled_date || '_' || substring(old.scheduled_time from 1 for 2);
end !!
create trigger pe_playlist_inserted for playlist
active after insert position 0 as
begin
post_event 'PLAYLIST_INSERTED_' || new.station_number || '_' ||
new.scheduled_date || '_' || substring(new.scheduled_time from 1 for 2);
end !!
-- Two stored procedure with same params as our regular ones
create procedure insert_log_entry (
station_num integer,
dt date,
tm varchar(12),
id varchar(250),
cluster integer,
mandatory varchar(1))
returns
(curr integer)
as
begin
insert into playlist values (:station_num, :dt, :tm);
curr = 0;
end !!
-- Unused in perl script, my pascal calls on it, though
create procedure remove_log_entry (
station_num integer,
curr integer)
returns
(next integer)
as
begin
delete from playlist where station_number = :station_num;
next = 0;
end !!
set term ;!!
commit;
You might want to add that to your aliases:
echo "event_fail = /tmp/event_fail.fdb" >> /opt/firebird/aliases.conf
And here is a perl script which will show the error. I'm sure real perl
programmers will cringe at this.
#!/usr/bin/perl -w
#
# Note: This needs DBI::InterBase. It might work with DBI::Firebird
# but I haven't tried it.
#
# Usage: $0 dbserver:database
use strict;
use DBI;
use POSIX qw(strftime mktime);
my $dsn = shift; # $ARGV[0] - Specified as dbhost:dbname.
my $DB_USER = 'sysdba';
my $DB_PASS = 'masterkey';
my ($dbhost, $dbname) = split ':', $dsn;
my $db = "dbi:InterBase:db=$dbname;host=$dbhost;ib_dialect=3";
my $dbi = DBI->connect($db, $DB_USER, $DB_PASS, { PrintError => 0,
RaiseError => 0,
AutoCommit => 1 })
or die "FATAL ERROR: DBI->connect to $dsn failed";
# Counter for events.
my $want_events = 0;
# -----------------------------------------------------
# Event callback function
# -----------------------------------------------------
sub handle_event {
my $pe = shift;
while (my ($k, $v) = each %$pe) {
print "Got event $k\n";
}
$want_events--;
1;
}
my $station = 1;
my $curr_date = mktime(0, 0, 0, 1, 0, 110); # 01 Jan 2010 @00:00
my $end_date = mktime(0, 0, 0, 1, 0, 111); # 01 Jan 2011 @00:00
my $sql;
my $ev1 = "";
my $ev2 = "";
while ($curr_date < $end_date) {
my ($sec,$min,$hour,$mday,$mon,$year,$wday,$yday) = localtime($curr_date);
my $dd = strftime ('%F', localtime($curr_date));
my $hh = sprintf ('%.2d', $hour);
my $tt = "${hh}:000:00.00";
# Only using one here. Kylix test program (and real application)
# use both of these, so this script registers for both.
$ev1 = "PLAYLIST_INSERTED_${station}_${dd}_${hh}";
$ev2 = "PLAYLIST_DELETED_${station}_${dd}_${hh}";
my $evh = $dbi->func($ev1, $ev2, 'ib_init_event');
# Set the callback
$dbi->func($evh, \&handle_event, 'ib_register_callback');
$want_events = 1;
$sql = "execute procedure insert_log_entry (?, ?, ?, ?, ?, ?)";
my $sth = $dbi->prepare($sql);
my $res = $sth->execute($station, $dd, $tt, 'Event Test Entry', 0, 'N');
print "Inserted $dd $hh\n";
$sth->finish;
while ($want_events > 0) {
sleep 1;
}
$dbi->func($evh, 'ib_cancel_callback');
# Bump to next hour and repeat
$curr_date += 3600;
}
$dbi->disconnect;
When I run the above perl, I get this as output:
~ $perl event_test.pl "serv1-0000:event_fail"
Inserted 2010-01-01 00
Got event PLAYLIST_INSERTED_1_2010-01-01_00
Inserted 2010-01-01 01
Got event PLAYLIST_INSERTED_1_2010-01-01_01
............much elided.....
Inserted 2010-01-13 17
Got event PLAYLIST_INSERTED_1_2010-01-13_17
Inserted 2010-01-13 18
Got event PLAYLIST_INSERTED_1_2010-01-13_18
DBD::InterBase::db::ib_register_callback() -- ev is not a blessed SV reference
at event_test.pl line 91.
Can't call method "execute" on an undefined value at event_test.pl line 97.
Broken pipe
and over on the server is another instance of terminating abnormally.
Things I've tried:
a). Making the event names shorter as in PI_{date}_{hour}
b). Table modification to store hour as an integer value and having the trigger
use that instead of calling on substring.
Both of those changes were for naught.
--
This message is automatically generated by JIRA.
-
If you think it was sent incorrectly contact one of the administrators:
http://tracker.firebirdsql.org/secure/Administrators.jspa
-
For more information on JIRA, see: http://www.atlassian.com/software/jira
------------------------------------------------------------------------------
Live Security Virtual Conference
Exclusive live event will cover all the ways today's security and
threat landscape has changed and how IT managers can respond. Discussions
will include endpoint security, mobile security and the latest in malware
threats. http://www.accelacomm.com/jaw/sfrnl04242012/114/50122263/
Firebird-Devel mailing list, web interface at
https://lists.sourceforge.net/lists/listinfo/firebird-devel
