Modify

Opened 11 years ago

Closed 11 years ago

Last modified 11 years ago

#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)

email2trac.txt (4.2 KB) - added by edward.b.matheson@… 11 years ago.
email2trac as requested ... run as root.
email2trac.2.txt (4.2 KB) - added by edward.b.matheson@… 11 years ago.
This is using the postfix account

Download all attachments as: .zip

Change History (11)

comment:1 Changed 11 years ago by bas

  • Status changed from new to assigned

Can you run this command for me with the test email that is included:

  • email2trac -n -v -d < msg.txt

This must output something!

Changed 11 years ago by edward.b.matheson@…

email2trac as requested ... run as root.

Changed 11 years ago by edward.b.matheson@…

This is using the postfix account

comment:2 Changed 11 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 11 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 11 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 11 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 11 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 11 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 11 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 11 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.

Add Comment

Modify Ticket

Change Properties
Action
as closed The owner will remain bas.
The resolution will be deleted. Next status will be 'reopened'.
Author


E-mail address and user name can be saved in the Preferences.

 
Note: See TracTickets for help on using tickets.