Hi,
We’re running 3.6.1 in production (the same applies to 3.6.3 in test), and Pg
version 8.1.8, and FastCGI (mod_fcgi-2.4.2), and Perl 5.8.7.
Sometimes we experience tickets that only shows ticket metadata, and not the
whole ticket including history. Everything looks ‘ok’ in the database:
rttest=# SELECT a.id,a.type,b.name,a.created from transactions a left
join users b on a.creator = b.id where a.objectid = ‘71963’ order by
a.created;
id | type | name | created
284098 | Create | user | 2005-09-27 09:05:15
1391471 | Create | user | 2007-01-10 13:33:44
1391473 | EmailRecord | RT_System | 2007-01-10 13:33:45
1391472 | EmailRecord | RT_System | 2007-01-10 13:33:45
1391487 | Take | user | 2007-01-10 13:36:27
1391489 | Set | user | 2007-01-10 13:36:42
1391603 | EmailRecord | RT_System | 2007-01-10 13:49:25
1391602 | Status | RT_System | 2007-01-10 13:49:25
1391601 | Correspond | user | 2007-01-10 13:49:25
1392035 | Correspond | user | 2007-01-10 15:00:02
1392036 | EmailRecord | RT_System | 2007-01-10 15:00:03
1396227 | Comment | user | 2007-01-11 13:18:34
1396228 | CommentEmailRecord | RT_System | 2007-01-11 13:18:35
1396300 | Correspond | user | 2007-01-11 13:29:39
1396301 | EmailRecord | RT_System | 2007-01-11 13:29:40
1396329 | EmailRecord | RT_System | 2007-01-11 13:37:11
1396328 | Give | user | 2007-01-11 13:37:11
1399462 | Correspond | user | 2007-01-12 09:07:58
1399463 | EmailRecord | RT_System | 2007-01-12 09:07:59
(19 rows)
This is a serious problem.
A short excerpt from thestrace of the mason handler process (only
one running for the test) when a certain problem ticket try to load in
a web-browser. When the mason handler process segfault’s, a new one is
created.
→
time(NULL) = 1174556708
time(NULL) = 1174556708
stat64(“/site/rt-3.6.3/local/lib/Text/Quoted.pmc”, 0xbfffa550) = -1 ENOENT
(No such file or directory)
open(“/site/rt-3.6.3/local/lib/Text/Quoted.pm”, O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/rt-3.6.3/lib/Text/Quoted.pmc”, 0xbfffa550) = -1 ENOENT (No
such file or directory)
open(“/site/rt-3.6.3/lib/Text/Quoted.pm”, O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Quoted.pmc”,
0xbfffa550) = -1
ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Quoted.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/Text/Quoted.pmc”, 0xbfffa550) = -1
ENOENT (No
such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/Text/Quoted.pm”, O_RDONLY|O_LARGEFILE) =
-1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/site_perl/5.8.7/i686-linux/Text/Quoted.pmc”,
0xbfffa550) = -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/site_perl/5.8.7/i686-linux/Text/Quoted.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/site_perl/5.8.7/Text/Quoted.pmc”, 0xbfffa550)
= -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/site_perl/5.8.7/Text/Quoted.pm”,
O_RDONLY|O_LARGEFILE) = 9
ioctl(9, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfffa358) = -1 ENOTTY
(Inappropriate ioctl for device)
_llseek(9, 0, [0], SEEK_CUR) = 0
read(9, “package Text::Quoted;\nour $VERSI”…, 4096) = 4096
stat64(“/site/rt-3.6.3/local/lib/Text/Autoformat.pmc”, 0xbfffa0a0) = -1
ENOENT (No such file or directory)
open(“/site/rt-3.6.3/local/lib/Text/Autoformat.pm”, O_RDONLY|O_LARGEFILE)
= -1 ENOENT (No such file or directory)
stat64(“/site/rt-3.6.3/lib/Text/Autoformat.pmc”, 0xbfffa0a0) = -1 ENOENT
(No such file or directory)
open(“/site/rt-3.6.3/lib/Text/Autoformat.pm”, O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Autoformat.pmc”,
0xbfffa0a0) = -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Autoformat.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/Text/Autoformat.pmc”, 0xbfffa0a0) = -1
ENOENT
(No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/Text/Autoformat.pm”,
O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/site_perl/5.8.7/i686-linux/Text/Autoformat.pmc”,
0xbfffa0a0) = -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/site_perl/5.8.7/i686-linux/Text/Autoformat.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/site_perl/5.8.7/Text/Autoformat.pmc”,
0xbfffa0a0) =
-1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/site_perl/5.8.7/Text/Autoformat.pm”,
O_RDONLY|O_LARGEFILE) = 11
ioctl(11, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfff9ea8) = -1 ENOTTY
(Inappropriate i
octl for device)
_llseek(11, 0, [0], SEEK_CUR) = 0
read(11, “package Text::Autoformat;\n\nuse s”…, 4096) = 4096
stat64(“/site/rt-3.6.3/local/lib/Text/Reform.pmc”, 0xbfff9bf0) = -1 ENOENT
(No such file or directory)
open(“/site/rt-3.6.3/local/lib/Text/Reform.pm”, O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/rt-3.6.3/lib/Text/Reform.pmc”, 0xbfff9bf0) = -1 ENOENT (No
such file or directory)
open(“/site/rt-3.6.3/lib/Text/Reform.pm”, O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Reform.pmc”,
0xbfff9bf0) = -1
ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Reform.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/Text/Reform.pmc”, 0xbfff9bf0) = -1
ENOENT (No
such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/Text/Reform.pm”, O_RDONLY|O_LARGEFILE) =
-1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/site_perl/5.8.7/i686-linux/Text/Reform.pmc”,
0xbfff9bf0) = -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/site_perl/5.8.7/i686-linux/Text/Reform.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/site_perl/5.8.7/Text/Reform.pmc”, 0xbfff9bf0)
= -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/site_perl/5.8.7/Text/Reform.pm”,
O_RDONLY|O_LARGEFILE) = 12
ioctl(12, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfff99f8) = -1 ENOTTY
(Inappropriate ioctl for device)
llseek(12, 0, [0], SEEK_CUR) = 0
read(12, “package Text::Reform;\n\nuse stric”…, 4096) = 4096
brk(0) = 0xab0d000
brk(0xab2e000) = 0xab2e000
read(12, “ess $config->{numeric} =~ m/\bAl”…, 4096) = 4096
read(12, “$config->{footer}, $config->{pag”…, 4096) = 4096
brk(0) = 0xab2e000
brk(0xab4f000) = 0xab4f000
read(12, "]}||""\n\t\t\t\t: ${$[$startidx++]}|“…, 4096) = 4096
read(12, “oter.="\n"\n\t\t\t\tif $lastfooter &&”…, 4096) = 4096
_llseek(12, 19355, [19355], SEEK_SET) = 0
_llseek(12, 0, [19355], SEEK_CUR) = 0
close(12) = 0
read(11, “;\n\n\t# SPECIAL IGNORANCE…\n\tif (”…, 4096) = 4096
stat64(”/site/rt-3.6.3/local/lib/Text/Tabs.pmc", 0xbfff9bf0) = -1 ENOENT
(No such file or directory)
open(“/site/rt-3.6.3/local/lib/Text/Tabs.pm”, O_RDONLY|O_LARGEFILE) = -1
ENOENT (No such file or directory)
stat64(“/site/rt-3.6.3/lib/Text/Tabs.pmc”, 0xbfff9bf0) = -1 ENOENT (No
such file
or directory)
open(“/site/rt-3.6.3/lib/Text/Tabs.pm”, O_RDONLY|O_LARGEFILE) = -1 ENOENT
(No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Tabs.pmc”, 0xbfff9bf0)
= -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Tabs.pm”,
O_RDONLY|O_LARGEFILE)
= -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/Text/Tabs.pmc”, 0xbfff9bf0) = -1 ENOENT
(No such file or directory)
or directory)
open(“/site/rt-3.6.3/lib/Text/Tabs.pm”, O_RDONLY|O_LARGEFILE) = -1 ENOENT
(No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Tabs.pmc”, 0xbfff9bf0)
= -1 ENOENT (No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/i686-linux/Text/Tabs.pm”,
O_RDONLY|O_LARGEFILE) = -1 ENOENT (No such file or directory)
stat64(“/site/perl-5.8.7/lib/5.8.7/Text/Tabs.pmc”, 0xbfff9bf0) = -1 ENOENT
(No such file or directory)
open(“/site/perl-5.8.7/lib/5.8.7/Text/Tabs.pm”, O_RDONLY|O_LARGEFILE) = 12
ioctl(12, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbfff99f8) = -1 ENOTTY
(Inappropriate ioctl for device)
_llseek(12, 0, [0], SEEK_CUR) = 0
read(12, “\npackage Text::Tabs;\n\nrequire Ex”…, 4096) = 2291
brk(0) = 0xab4f000
brk(0xab70000) = 0xab70000
_llseek(12, 1098, [1098], SEEK_SET) = 0
_llseek(12, 0, [1098], SEEK_CUR) = 0
close(12) = 0
read(11, “\t}\n\t\t\tif ($args{case} =~ /highli”…, 4096) = 4096
read(11, “$tfield";\n\t\t $newtext = (!$pa”…, 4096) = 4096
read(11, “ngth $2;\n\tmy $aindent = length $”…, 4096) = 4096
brk(0) = 0xab70000
brk(0xab91000) = 0xab91000
read(11, “ev) {\t# going down level(s)\n\t\tfo”…, 4096) = 4096
_llseek(11, 22231, [22231], SEEK_SET) = 0
_llseek(11, 0, [22231], SEEK_CUR) = 0
close(11) = 0
read(9, "low" where we are right\n "…, 4096) = 3601
read(9, “”, 4096) = 0
close(9) = 0
— SIGSEGV (Segmentation fault) @ 0 (0) —
←
This was testet using mod_fastcgi. We also tested mod_fcgi (latest
snapshot) to see if we could reproduce the problem.
It behaved different. Instead of only showing metadata as the mod_fastcgi
did, we just got an “Internal Server Error” in web browser testing the
same
ticket.
The httpd.conf configuration for fcgid:
This is for mod_fastcgi
Tell FastCGI to put its temporary files somewhere sane.
FastCgiIpcDir /tmp
FastCgiServer /site/rttest/bin/mason_handler.fcgi -idle-timeout 300 -processes 1
This is for mod_fcgid
SocketPath /tmp/fcgidsock
SharememPath /tmp/fcgidshm
DefaultInitEnv RAILS_ENV production
IdleTimeout 300
MaxProcessCount 1
FCGIWrapper “/site/rttest/bin/mason_handler.fcgi” .fcgi
From Apache error.log:
→
[Fri Mar 23 10:29:16 2007] [warn] mod_fcgid: Read data error, fastcgi
server has close connection
[Fri Mar 23 10:29:16 2007] [warn] (32)Broken pipe: mod_fcgid:
ap_pass_brigade failed in handle_request function
[Fri Mar 23 10:30:44 2007] [warn] mod_fcgid: Read data error, fastcgi
server has close connection
[Fri Mar 23 10:30:44 2007] [warn] (32)Broken pipe: mod_fcgid:
ap_pass_brigade failed in handle_request function
[Fri Mar 23 10:32:43 2007] [warn] mod_fcgid: Read data error, fastcgi
server has close connection
[Fri Mar 23 10:32:43 2007] [warn] (32)Broken pipe: mod_fcgid:
ap_pass_brigade failed in handle_request function
[Fri Mar 23 10:41:00 2007] [warn] mod_fcgid: Read data error, fastcgi
server has close connection
[Fri Mar 23 10:41:00 2007] [warn] (32)Broken pipe: mod_fcgid:
ap_pass_brigade failed in handle_request function
←
Anyone with similar experience or suggestions?
We have not tested the problem ticket crashing Fast CGI modules on
mod_perl yet. It seems that there may be some strange combination in
tichet that perhaps could crash Fast CGI??
All comments are appreciated a lot!
best regards and cheers,
Tomas
Tomas A. P. Olaj, email: tomas.olaj@usit.uio.no, web: folk.uio.no/tomaso
University of Oslo / USIT (Center for Information Technology Services)
System- and Application Management / Applications Management Group