#241 closed defect (fixed)
Strange error on CentOS-5.5, email2trac-2.0.2, python-2.5
Reported by: | edward.b.matheson@… | Owned by: | bas |
---|---|---|---|
Priority: | blocker | Milestone: | |
Component: | email2trac | Version: | 2.0.2 |
Keywords: | Cc: |
Description
Getting
Apr 11 13:03:02 ipcontrol1 postfix/local[27214]: 3397AF38130: to=<d318-support@ipcontrol1.atol>, relay=local, delay=0.86, delays=0.07/0.01/0/0.78, dsn=5.3.0, status=bounced (Command died with status 1: " /usr/local/bin/email2trac --project=atol --ticket_prefix=d318support". Command output: Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush()
- Currently have postfix setup with /var/trac/aliases owned by the 'apache' user, which is how trac runs.
- running Python 2.5.5
- aliases file looks like
trac: "| /usr/local/bin/email2trac --project=atol" d318-support: "| /usr/local/bin/email2trac --project=atol --ticket_prefix=d318support"
- trac is installed in /var/trac/atol
- db file is writable by user 'apache'
- world has r-x perms on all dirs
- I *CAN* get it working as root using your msg.txt:
root@myhost # /usr/local/bin/email2trac < /tmp/msg.txt saving email to /tmp/tmpdeh4T6.email2trac writing body to /tmp/tmp2DcydZ.email2trac
- but does *nothing* using run_email2trac j
- selinux is disabled
- email2trac.conf is simple
DEFAULT] project: /var/trac/atol debug: 1 log_type: file log_level: debug log_file: /tmp/email2trac.log umask: 022 spam_level: 5 reply_all : 0 mailto_link: 0 umask: 022 email_header: 0 trac_version: 0.12 enable_syslog : 1 alternate_notify_template : alternate_notify_template_update : drop_spam : 0 verbatim_format: 1 strip_signature: 0 email_quote: > strip_quotes: 0 ignore_trac_user_settings: 0 black_list: MAILER-DAEMON@ drop_alternative_html_version: 1 ticket_update: 1 strip_signature: 1 html2text_cmd: /usr/bin/html2text -nobs [atol] spam_level : 1 d318support_component : Branch_Support d318support_ttd : D318-support atolsupport_ttd : atol-support
I've spent quite a bit of time trying to solve this .. and am truly flummoxed. I've tried the system /usr/bin/python ( Python 2.4.3 ) .. didn't make any difference. I am not getting enough info from the error to find the problem. Any suggestions on how i can get more info out? The response in the mail is long and just repeats:
"/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOE
- All I get in the output log is
email2trac atol: Found trac version: 0.12 email2trac atol: Loading environment /var/trac/atol
Please Help ;-)
Attachments (2)
Change History (11)
comment:1 Changed 12 years ago by bas
- Status changed from new to assigned
comment:2 Changed 12 years ago by edward.b.matheson@…
Here's the response email:
Received: from ipcontrol1.atol (localhost.localdomain [127.0.0.1]) by ipcontrol1.atol (Postfix) with ESMTP id 03E78F3812B for <d318-support@ipcontrol1.atol>; Mon, 25 Apr 2011 10:11:17 -0400 (EDT) Received: (from root@localhost) by ipcontrol1.atol (8.13.8/8.13.8/Submit) id p3PEBGGW018508 for d318-support@ipcontrol1.atol; Mon, 25 Apr 2011 10:11:16 -0400 Date: Mon, 25 Apr 2011 10:11:16 -0400 From: root <root@ipcontrol1.atol> Message-ID: <201104251411.p3PEBGGW018508@ipcontrol1.atol> To: <d318-support@ipcontrol1.atol> Subject: test MIME-Version: 1.0 Content-Type: text/plain Reporting-MTA: dns; ipcontrol1.atol Final-recipient: RFC822; d318-support@ipcontrol1.atol Action: failed Status: 5.3.0 X-Supplementary-Info: < #5.3.0 x-unix; Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOE> From: root <root@ipcontrol1.atol> Date: April 25, 2011 10:11:16 AM EDT To: "d318-support@ipcontrol1.atol" <d318-support@ipcontrol1.atol> Subject: test test
comment:3 Changed 12 years ago by bas
how big is the log file (ls -lh):
/tmp/email2trac.log
It seems that the log file is too big. Can you comment the log_* entries in email2trac.conf.
comment:4 Changed 12 years ago by anonymous
[BACKUP] ematheso@ipcontrol1 > ls -l /tmp/email2trac.log -rw------- 1 apache apache 94 Apr 25 10:10 /tmp/email2trac.log
small ;-)
comment:5 Changed 12 years ago by anonymous
Also .. I checked with the following commenting:
[BACKUP] root@ipcontrol1 # grep log /usr/local/etc/email2trac.conf #log_type: file #log_level: debug #log_file: /tmp/email2trac.log # enable_syslog : 1 [BACKUP] root@ipcontrol1 # ls -l !$ [BACKUP] root@ipcontrol1 # ls -l /usr/local/etc/email2trac.conf -rw-r--r-- 1 root root 664 Apr 26 07:26 /usr/local/etc/email2trac.conf
Still getting
Apr 26 07:26:46 ipcontrol1 postfix/local[8132]: 19767F3812B: to=<d318-support@ipcontrol1.atol>, relay=local, delay=0.83, delays=0.07/0.01/0/0.75, dsn=5.3.0, status=bounced (Command died with status 1: " /usr/local/bin/email2trac --project=atol --ticket_prefix=d318support". Command output: Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush() IOError: [Errno 27] File too large Traceback (most recent call last): File "/usr/local/lib/python2.5/logging/__init__.py", line 753, in emit self.flush() File "/usr/local/lib/python2.5/logging/__init__.py", line 731, in flush self.stream.flush()
comment:6 Changed 12 years ago by anonymous
I am wondering if it's something with python on centos .. I've made sure selinux is off.
[BACKUP] ematheso@ipcontrol1 > sestatus SELinux status: disabled
and checked the processes for ownership:
[BACKUP] ematheso@ipcontrol1 > gps httpd 5 S root 12991 1 0 78 0 - 7046 stext Apr25 ? 00:00:00 /usr/sbin/httpd -k start 5 S apache 15753 12991 0 78 0 - 12960 semtim Apr25 ? 00:00:34 /usr/sbin/httpd -k start 5 S apache 15754 12991 0 78 0 - 13045 semtim Apr25 ? 00:00:31 /usr/sbin/httpd -k start 5 S apache 15755 12991 0 78 0 - 12967 semtim Apr25 ? 00:00:32 /usr/sbin/httpd -k start 5 S apache 15756 12991 0 78 0 - 13160 stext Apr25 ? 00:00:32 /usr/sbin/httpd -k start 5 S apache 15757 12991 0 78 0 - 13072 semtim Apr25 ? 00:00:33 /usr/sbin/httpd -k start 5 S apache 15758 12991 0 78 0 - 13136 semtim Apr25 ? 00:00:32 /usr/sbin/httpd -k start 5 S apache 15759 12991 0 80 0 - 13041 semtim Apr25 ? 00:00:30 /usr/sbin/httpd -k start 5 S apache 15760 12991 0 76 0 - 13075 semtim Apr25 ? 00:00:29 /usr/sbin/httpd -k start 5 S apache 20524 12991 0 78 0 - 13035 semtim Apr25 ? 00:00:21 /usr/sbin/httpd -k start 5 S apache 26666 12991 0 78 0 - 12941 semtim Apr25 ? 00:00:10 /usr/sbin/httpd -k start [BACKUP] ematheso@ipcontrol1 > gps postfix 4 S postfix 6928 17098 0 78 0 - 1754 stext 06:18 ? 00:00:00 pickup -l -t fifo -u 4 S postfix 7558 17098 0 78 0 - 1784 stext 06:58 ? 00:00:00 cleanup -z -t unix -u 4 S postfix 7885 17098 0 78 0 - 1752 stext 07:20 ? 00:00:00 anvil -l -t unix -u 4 S postfix 7891 17098 0 77 0 - 1795 stext 07:20 ? 00:00:00 smtp -n relay -t unix -u -o fallback_relay 4 S postfix 8156 17098 0 78 0 - 1851 stext 07:28 ? 00:00:00 smtpd -n smtp -t inet -u 4 S root 17098 1 0 75 0 - 1738 stext Apr25 ? 00:00:02 /usr/libexec/postfix/master 4 S postfix 18700 17098 0 78 0 - 2334 stext Apr25 ? 00:00:02 qmgr -l -t fifo -u
built it appropriately:
[BACKUP] root@ipcontrol1 # head config.log | grep with-trac $ ./configure --with-trac_user=apache --with-mta_user=postfix
So I am really stumped. I did just notice the umask for root is rather anal .. so gonna start checking installed eggs and such.. see if I missed something there. Is there some way to have python run the same way as a bash -XV ? So I can see where it's dying. The init stuff doesn't really tell me anything .. cause I can't backtrace to the call.
comment:7 Changed 12 years ago by bas
It is strange, How big is the trac log file of the project atol?
I think the apache user is ok, but for postfix it is mostly user : nobody. You can check it By replacing the script:
!#/bin/bash id >> /var/tmp/postfix_id
aliases:
trac: "| /usr/local/bin/postfix_id"
comment:8 Changed 12 years ago by anonymous
- Resolution set to fixed
- Status changed from assigned to closed
So the trac log is big:
[BACKUP] ematheso@ipcontrol1 > ls -ld /var/trac/atol/log/trac.log -rw-rw-rw- 1 apache trac 309686974 Apr 26 08:07 /var/trac/atol/log/trac.log You have new mail.
And POW! ... zeroed that .. and things are working again..
[BACKUP] root@ipcontrol1 # grep 0BD37F3812B /var/log/maillog Apr 26 08:09:56 ipcontrol1 postfix/smtpd[8447]: 0BD37F3812B: client=localhost.localdomain[127.0.0.1] Apr 26 08:09:56 ipcontrol1 postfix/cleanup[8699]: 0BD37F3812B: message-id=<201104261209.p3QC9tDP008866@ipcontrol1.atol> Apr 26 08:09:56 ipcontrol1 sendmail[8866]: p3QC9tDP008866: to=d318-support@ipcontrol1.atol, ctladdr=ematheso (10652/20), delay=00:00:01, xdelay=00:00:00, mailer=relay, pri=30054, relay=[127.0.0.1] [127.0.0.1], dsn=2.0.0, stat=Sent (Ok: queued as 0BD37F3812B) Apr 26 08:09:56 ipcontrol1 postfix/qmgr[18700]: 0BD37F3812B: from=<ematheso@ipcontrol1.atol>, size=575, nrcpt=1 (queue active) Apr 26 08:09:57 ipcontrol1 postfix/local[8869]: 0BD37F3812B: to=<d318-support@ipcontrol1.atol>, relay=local, delay=1.6, delays=0.07/0.01/0/1.5, dsn=2.0.0, status=sent (delivered to command: /usr/local/bin/email2trac --project=atol --ticket_prefix=d318support) Apr 26 08:09:57 ipcontrol1 postfix/qmgr[18700]: 0BD37F3812B: removed
So that is the problem .. that logfile is too big. I will setup rotation, however, we should add somethign to the wiki here about it ;-)
Thanks SO much for the assistance .. it's funny ... I wasn't even thinking about that log .. but the error message really was pointing at it as the problem. I hate issues like that.
comment:9 Changed 12 years ago by bas
i am glad that the trac log file was the problem. It is strange that centos as now large file support enabled in the kernel. Maybe i can catch the exception and exit with a proper error in the syslog.
Can you run this command for me with the test email that is included:
This must output something!