run_email2trac crashes intermittently

[bsilverman@…]

I'm running run_email2trac with the following command in /etc/aliases:

sw: "|/usr/local/bin/run_email2trac -d -f /usr/local/etc/email2trac.conf"

Unfortunately, it crashes in the email2trac script. If I run the email to trac script directly (but as root), using:

cat foo | sudo /usr/local/bin/email2trac -d -f /usr/local/etc/email2trac.conf"

(where foo is a saved email of mine), then the program runs fully without error, and I get a new ticket in the trac database.

The error I get in /var/log/mail.log shows the command failing, but doesn't print enough output to show all the debug info:

Jan 13 11:17:19 iv-eng-vm postfix/smtpd[24168]: connect from wisrv001.westonlan.com[10.0.20.20]
Jan 13 11:17:20 iv-eng-vm postfix/smtpd[24168]: C7EAD2B28BA: client=wisrv001.westonlan.com[10.0.20.20]
Jan 13 11:17:20 iv-eng-vm postfix/cleanup[24172]: C7EAD2B28BA: message-id=<98EC3A86-C519-4774-A868-BBD063036E9B@iveia.com>
Jan 13 11:17:20 iv-eng-vm postfix/qmgr[3160]: C7EAD2B28BA: from=<bsilverman@iveia.com>, size=24112, nrcpt=1 (queue active)
Jan 13 11:17:20 iv-eng-vm postfix/smtpd[24168]: disconnect from wisrv001.westonlan.com[10.0.20.20]
Jan 13 11:17:21 iv-eng-vm postfix/local[24173]: C7EAD2B28BA: to=<sw@trac.iveia.com>, relay=local, delay=1.5, delays=0.35/0.01/0/1.2, dsn=5.3.0, status=bounced (Command died with status 1: "/usr/local/bin/run_email2trac -d -f /usr/local/etc/email2trac.conf". Command output: 2014-01-13 11:17:20,573 email2trac titan: Found trac version: 1.0 2014-01-13 11:17:20,730 email2trac titan: Loading environment /var/local/trac/titan 2014-01-13 11:17:21,163 email2trac titan: Main function parse 2014-01-13 11:17:21,167 email2trac titan: saving email to /tmp/tmp6GecYV.titan.email2trac 2014-01-13 11:17:21,172 email2trac titan: function get_message_parts() 2014-01-13 11:17:21,172 email2trac titan:   Message part: Main-Type: multipart 2014-01-13 11:17:21,172 email2trac titan:   Message part: Content-Type: multipart/alternative 2014-01-13 11:17:21,172 email2trac titan:   Message part: Main-Type: text 2014-01-13 11:17:21,172 email2trac titan:   Message part: Content-Type: text/plain 2014-01-13 11:17:21,172 email2trac titan: function 
Jan 13 11:17:21 iv-eng-vm postfix/cleanup[24172]: 5603A2B2904: message-id=<20140113161721.5603A2B2904@trac.iveia.com>
Jan 13 11:17:21 iv-eng-vm postfix/qmgr[3160]: 5603A2B2904: from=<>, size=34660, nrcpt=1 (queue active)
Jan 13 11:17:21 iv-eng-vm postfix/bounce[24176]: C7EAD2B28BA: sender non-delivery notification: 5603A2B2904
Jan 13 11:17:21 iv-eng-vm postfix/qmgr[3160]: C7EAD2B28BA: removed
Jan 13 11:17:21 iv-eng-vm postfix/smtp[24177]: 5603A2B2904: to=<bsilverman@iveia.com>, relay=iveia.com[10.0.20.20]:25, delay=0.13, delays=0.01/0.01/0.01/0.11, dsn=2.6.0, status=sent (250 2.6.0  <20140113161721.5603A2B2904@trac.iveia.com> Queued mail for delivery)
Jan 13 11:17:21 iv-eng-vm postfix/qmgr[3160]: 5603A2B2904: removed

However, I added the following just after "logger" is instantiated so that I can see all the debug info:

fh = logging.FileHandler('/tmp/spam.log')
fh.setLevel(logging.DEBUG)
logger.addHandler(fh)

when I do that, I see more info - and email2trac appears to just exit. For example:

Found trac version: 1.0
Loading environment /var/local/trac/titan
Main function parse
saving email to /tmp/tmptnqS54.titan.email2trac
function get_message_parts()
	 Message part: Main-Type: multipart
	 Message part: Content-Type: multipart/alternative
	 Message part: Main-Type: text
	 Message part: Content-Type: text/plain
function inline_part()
	 unicode filename: None
	 raw filename: None
function check_filename_length: 
function inline_properties
	 Message part: Main-Type: text
	 Message part: Content-Type: text/html
function inline_part()
	 Skipping alternative HTML message
function unique_attachment_names()
function get_body_text()
function debug_body:
writing body to /tmp/tmptnqS54.titan.email2trac.body
function debug_attachments
function get_sender_info
function email_to_unicode
	 email name: Brian Silverman, email address: bsilverman@iveia.com
	get_sender_info: found registered user: bsilverman
function email_header_acl: white_list
	 white_list not defined, all messages are allowed.
function email_header_acl: black_list
function email_header_acl: recipient_list
	 recipient_list not defined, all messages are allowed.
function spam
function spam
function email_to_unicode
subject: u'test23'
function ticket_update_by_subject
function new_ticket
function set_cc_fields
function set_ticket_fields
before
trac[summary] = 
after
before
trac[reporter] = 
after
before
trac[owner] = < default >
after
used owner = < default >
before
trac[description] = 
after
before
trac[type] = defect
after
used type = defect
before
trac[status] = 
after
before
trac[priority] = none
Traceback (most recent call last):

The file doesn't include a traceback. Note: the "before" and "after" were added by me as debug messages.

Finally, when adding/removing debug messages, I have once seen the command work and actually insert a ticket in the trac database.

More info - I am using:

• Trac 1.0,
• email2trac

  SVN Info:
          $Id: email2trac.py.in 628 2013-06-18 10:05:30Z bas $
  

• Ubuntu:

  bri@iv-eng-vm:~/e2t/email2trac-2.7.0$ lsb_release -a
  No LSB modules are available.
  Distributor ID:	Ubuntu
  Description:	Ubuntu 9.04
  Release:	9.04
  Codename:	jaunty
  

[bas]

From the logs i can see that you are using postfix. You do not need run_email2trac:

• https://oss.trac.surfsara.nl/email2trac/wiki/Email2tracMta#Postfix

The -d flag is only used for debuing. I never put this the /etc/aliases file. In the email2trac package there is a test msg. Does ths produce an error:

• email2trac -n -d -p <name> < msg.txt

It looks like if you configure the wrong user id's for trac user and web user. run_email2trac does not report this if it is wrong. I will fix this. To enable it use:

• ./configure DEBUG=1

And maybe you hit this problem: (I will shortly release a new version)

 strip_quotes printed to stdout instead of using the logger function. Due this error
    run_email2trac will break, closes #325

[bas]

Just commited [648]. That will make it easier to debug run_email2trac

[bsilverman@…]

Thanks for the update and info.

I was using run_email2trac because a previous sysadmin had set it up this way (and it did work at one time). I had tried email2trac alone, but as you say in the link you posted, that runs as user "nobody" - but that user doesn't have permissions to edit the trac database so email2trac fails.

run_email2trac is setuid root, and therefore doesn't have an issue with permissions.

What is your suggested way to run email2trac such that it can edit the trac database?

[bsilverman@…]

Replying to bas:

The -d flag is only used for debuing. I never put this the /etc/aliases file. In the email2trac package there is a test msg. Does ths produce an error:

• email2trac -n -d -p <name> < msg.txt

Just to be clear - yes, the above does produce an error, and its a permissions problem:

2014-01-14 09:36:57,053 email2trac titan: Found trac version: 1.0
2014-01-14 09:36:57,218 email2trac titan: Loading environment /var/local/trac/titan
2014-01-14 09:36:57,227 email2trac titan: trac error: [Errno 13] Permission denied: u'/var/local/trac/titan/log/trac.log'

If I run as root, I have no issue. But I don't see how to run as root from a command in /etc/aliases (sudo doesn't work there) - there must be a better way?

[bas]

There are two scenarios for postfix, see provided link:

• run_email2trac will switch from the postfix user to the trac user. You have to supply the right users. That is not something you can ignore. Mostly postfix uses nobody and trac user if run under apache,www-data. Note: ls -l trac.log will give you a hint.

You have installed everything in /usr/local/bin. Is this filesystem allowed to run a set uid program?

[bas]

Can your try the trunk version. Gives you a better insight of the run_email2trac problem

[bsilverman@…]

Replying to bas:

Can your try the trunk version. Gives you a better insight of the run_email2trac problem

Just tried the latest version (and added the logger lines I posted previously so I could see the output). The output is basically the same:

Found trac version: 1.0
Loading environment /var/local/trac/titan
Main function parse
saving email to /tmp/tmpP1VDwd.titan.email2trac
function get_message_parts()
	 Message part: Main-Type: multipart
	 Message part: Content-Type: multipart/alternative
	 Message part: Main-Type: text
	 Message part: Content-Type: text/plain
function inline_part()
function email_to_unicode
	 unicode filename: None
	 raw filename: None
function inline_properties
	 Message part: Main-Type: text
	 Message part: Content-Type: text/html
function inline_part()
	 Skipping alternative HTML message
function unique_attachment_names()
function get_body_text()
function debug_body:
writing body to /tmp/tmpP1VDwd.titan.email2trac.body
function debug_attachments
function get_sender_info
function email_to_unicode
	 email name: Brian Silverman, email address: bsilverman@iveia.com
	get_sender_info: found registered user: bsilverman
function email_header_acl: white_list
	 white_list not defined, all messages are allowed.
function email_header_acl: black_list
function email_header_acl: recipient_list
	 recipient_list not defined, all messages are allowed.
function spam
function spam
function email_to_unicode
subject: u'test35'
function parse_delivered_to_field
function parse_subject_header
function ticket_update_by_subject
function new_ticket
function set_cc_fields
function set_ticket_fields
trac[summary] = 
trac[reporter] = 
trac[owner] = < default >
used owner = < default >
trac[description] = 
trac[type] = defect
used type = defect
trac[status] = 
trac[priority] = none
used priority = none
trac[milestone] = triage
used milestone = triage
trac[component] = iv other
used component = iv other
trac[version] = 
trac[resolution] = None
trac[keywords] = 
Traceback (most recent call last):

Note: I am configuring the trac user as root via:

./configure --with-mta-user=nobody --with-trac-user=root

[bas]

You do no need the logger lines that is strange. How did you installed trac? As standalone or via webserver. To run with trac_user is strange. There is nothing in the syslog about failures for run_email2trac

[bsilverman@…]

Replying to bas:

You do no need the logger lines that is strange. How did you installed trac? As standalone or via webserver. To run with trac_user is strange. There is nothing in the syslog about failures for run_email2trac

I've only added the logger lines because I'm running it through postfix and can't see all the output. That is, I'm emailing to our server, and the server is running run_email2trac because its setup in my /etc/aliases. The output of the command is shown in /var/log/mail.log, but only a few lines of it is shown. I use the logger lines so I can see all of the output.

Trac was installed from the command-line (easy_install). It is accessed and configured through the web interface. The permissions on all files in the trac directory are user root, group root. Perhaps that is the issue? What user/group is your trac installed with?

[bas]

what kind of software do you use for webserver:

• apache --> ps -eaf | grep apache --> debian == www-data

So my apache/trac setup uses nobody for postfix and www-data for trac user

[bsilverman@…]

Replying to bas:

what kind of software do you use for webserver:

• apache --> ps -eaf | grep apache --> debian == www-data

So my apache/trac setup uses nobody for postfix and www-data for trac user

Apache:

bri@iv-eng-vm:~/e2t/s/trunk$ ps -eaf | grep apache
root      3462     1  0  2013 ?        00:00:40 /usr/sbin/apache2 -k start
www-data 20810  3462  0 Jan12 ?        00:00:00 /usr/sbin/apache2 -k start
www-data 20818  3462  0 Jan12 ?        00:00:00 /usr/sbin/apache2 -k start
www-data 20824  3462  0 Jan12 ?        00:00:00 /usr/sbin/apache2 -k start
bri      22223 17669  0 11:10 pts/1    00:00:00 grep apache

And here's my trac project dir:

bri@iv-eng-vm:~/e2t/s/trunk$ ls -l /var/local/trac/titan
total 48
drwxr-xr-x 2 root root 4096 2013-08-28 15:58 conf
drwxr-xr-x 2 root root 4096 2014-01-14 11:05 db
drwxr-xr-x 3 root root 4096 2013-03-05 06:57 files
drwxr-xr-x 2 root root 4096 2012-09-13 15:58 gvcache
drwxr-xr-x 2 root root 4096 2012-09-01 23:13 htdocs
drwxr-xr-x 2 root root 4096 2009-07-09 15:45 images
drwxr-xr-x 2 root root 4096 2013-03-05 07:40 log
drwxr-xr-x 2 root root 4096 2013-08-28 15:48 plugins
-rw-r--r-- 1 root root   98 2008-03-31 13:30 README
drwxr-xr-x 2 root root 4096 2012-03-10 22:27 templates
drwxr-xr-x 3 root root 4096 2011-09-13 09:13 upload
-rw-r--r-- 1 root root   27 2008-03-31 13:30 VERSION

What are the permissions on your trac project dir?

[bas]

Everything is writeable by www-data. But maybe your organization have some kind of security model. I really do not know. Can you submit tickets + attachments via the webinterface?

-rw-r--r-- 1 www-data www-data   27 Dec  5  2006 VERSION
-rw-r--r-- 1 www-data www-data   98 Dec  5  2006 README
drwxr-xr-x 2 www-data www-data    6 Dec  5  2006 htdocs
drwxr-xr-x 2 www-data www-data   52 Jul  2  2008 plugins
drwxr-xr-x 2 www-data www-data  103 Jul 12  2010 templates
drwxr-xr-x 2 www-data www-data   21 Aug  2  2011 log
drwxr-xr-x 3 www-data www-data   24 Nov 19  2012 files
drwxr-xr-x 3 www-data www-data   19 Nov 19  2012 attachments
drwxr-xr-x 2 www-data www-data   74 Jan 14 14:22 conf
drwxr-xr-x 2 www-data www-data 4096 Jan 14 17:15 db

[bsilverman@…]

Replying to bas:

Everything is writeable by www-data. But maybe your organization have some kind of security model. I really do not know. Can you submit tickets + attachments via the webinterface?

Interesting - I suspect this is where the problem lies. I don't recall when/who installed trac originally (it was me or one other guy), and perhaps the issue was simply that it was installed as root, and permissions were never changed.

Yes, I can submit tickets, attachements, edit the wiki, use the admin interface, etc all from trac's web interface.

I suspect I'm going to have to try changing the permissions. I'd rather do this when I can take down trac - not right now.

Thanks for all your help.

[bas]

I will close this ticket.