Modify

Opened 7 years ago

Closed 6 years ago

#2454 closed defect (fixed)

Do not add new topic - SMTPDataError: (553, '5.5.2 Bad Message ID')

Reported by: tonal@… Owned by: Blackhex
Priority: normal Component: DiscussionPlugin
Severity: normal Keywords:
Cc: Trac Release: 0.11

Description

How to Reproduce

While doing a POST operation on /discussion/1, Trac issued an internal error.

In latest revisions Trac & DiscussionPlugin I do not add new topic.
Afte click Submit button I see error page.

Request parameters:

{'__FORM_TOKEN': u'c15d2f510dd4199aea3e9fe9',
 'author': u'tonal',
 'body': u'Enter your message here...',
 'discussion_action': u'post-add',
 'forum': u'1',
 'subject': u'Test',
 'submit': u'Submit'}

System Information

Trac 0.11dev-r6399
Python 2.5.1 (r251:54863, Oct 5 2007, 13:36:32)
[GCC 4.1.3 20070929 (prerelease) (Ubuntu 4.1.2-16ubuntu2)]
setuptools 0.6c7
SQLite 3.4.2
pysqlite 2.3.4
Genshi 0.5dev-r789
Pygments 0.9
Subversion 1.4.4 (r25188)

Python Traceback

Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/web/main.py", line 406, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/web/main.py", line 195, in dispatch
    resp = chosen_handler.process_request(req)
  File "build/bdist.linux-i686/egg/tracdiscussion/core.py", line 77, in process_request
    return api.process_discussion(context) + (None,)
  File "build/bdist.linux-i686/egg/tracdiscussion/api.py", line 47, in process_discussion
    is_moderator)
  File "build/bdist.linux-i686/egg/tracdiscussion/api.py", line 567, in _do_action
    notifier.notify(context, mode, forum, new_topic, None, to, cc)
  File "build/bdist.linux-i686/egg/tracdiscussion/notification.py", line 84, in notify
    NotifyEmail.notify(self, id, subject)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/notification.py", line 239, in notify
    Notify.notify(self, resid)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/notification.py", line 129, in notify
    self.send(torcpts, ccrcpts)
  File "build/bdist.linux-i686/egg/tracdiscussion/notification.py", line 123, in send
    NotifyEmail.send(self, torcpts, ccrcpts, header)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/notification.py", line 404, in send
    self.server.sendmail(msg['From'], recipients, msgtext)
  File "smtplib.py", line 699, in sendmail
    raise SMTPDataError(code, resp)
SMTPDataError: (553, '5.5.2 Bad Message ID')

Attachments (0)

Change History (8)

comment:1 Changed 7 years ago by Blackhex

  • Status changed from new to assigned

Hello.

This seems as too strict spam filtering rules at your SMTP server. Can you use e-mail notification in Trac tickets or it's only caused by DiscussionPlugin? I was searching a little about this kind of error message but I dind't find anything direct yet. For some weird reason many undirect references was originally from Russia, so this would be some local problem. I'll search a bit aggain or I'll consult this problem with Trac developers lately. Can you see what is printed in your log with debug level loggin? There sould be printed whole e-mail content, IIRC.

comment:2 Changed 7 years ago by Blackhex

I found this http://www.opennet.ru/base/net/sendmail_regex.txt.html. Even if I can read azbuka, I can't understand russian much. Are there some usefull informations?

comment:3 Changed 7 years ago by tonal@…

I recive notifycation for trac topic change.
Bat I do not create forum topic.
Maybe plagin forget commit transaction after save data to base?

Full trac log for error:

2008-01-23 12:52:51,824 Trac[main] DEBUG: Dispatching <Request "POST u'/admin/general/logging'">
2008-01-23 12:52:51,856 Trac[session] DEBUG: Retrieving session for ID u'tonal'
2008-01-23 12:52:51,881 Trac[main] DEBUG: Dispatching <Request "GET u'/admin/general/logging'">
2008-01-23 12:52:51,937 Trac[chrome] DEBUG: Prepare chrome data for request
2008-01-23 12:52:51,965 Trac[session] DEBUG: Retrieving session for ID u'tonal'
2008-01-23 12:53:12,457 Trac[main] DEBUG: Dispatching <Request "GET u'/discussion'">
2008-01-23 12:53:12,482 Trac[api] DEBUG: realm: discussion-core, action: None, preview: False, submit: False
2008-01-23 12:53:12,483 Trac[api] DEBUG: ['forum-list']
2008-01-23 12:53:12,488 Trac[session] DEBUG: Retrieving session for ID u'tonal'
2008-01-23 12:53:12,492 Trac[api] DEBUG: SELECT COUNT(f.id) FROM forum f WHERE f.forum_group = 0
2008-01-23 12:53:12,494 Trac[api] DEBUG: SELECT g.id, g.name, g.description, f.forums FROM  forum_group g LEFT JOIN (SELECT COUNT(id) AS forums,  forum_group FROM forum GROUP BY forum_group) f ON g.id =  f.forum_group ORDER BY g.id ASC
2008-01-23 12:53:12,496 Trac[api] DEBUG: SELECT f.id, f.name, f.author, f.time, f.moderators, f.forum_group, f.subject, f.description, ta.topics, ta.replies, ta.lasttopic, ta.lastreply FROM forum f LEFT JOIN (SELECT COUNT(t.id) AS topics, MAX(t.time) AS lasttopic, SUM(ma.replies) AS replies, MAX(ma.lastreply) AS lastreply, t.forum AS forum FROM  topic t LEFT JOIN (SELECT COUNT(m.id) AS replies, MAX(m.time) AS lastreply, m.topic AS topic FROM message m GROUP BY m.topic) ma ON t.id = ma.topic GROUP BY forum) ta ON f.id = ta.forum ORDER BY f.id ASC
2008-01-23 12:53:12,589 Trac[api] DEBUG: SELECT COUNT(id) FROM topic t WHERE t.forum = 1 AND t.time > 1201071099
2008-01-23 12:53:12,591 Trac[api] DEBUG: SELECT id FROM topic t WHERE t.forum = 1
2008-01-23 12:53:12,593 Trac[chrome] DEBUG: Prepare chrome data for request
2008-01-23 12:53:12,621 Trac[api] DEBUG: {'topic': None, 'group': None, 'forum': None, 'time': u'23.01.2008 12:53:12', 'is_moderator': True, 'mode': 'forum-list', 'groups': [{'description': 'No Group', 'forums': 1, 'id': 0, 'name': 'None'}], 'authname': u'tonal', 'realm': 'discussion-core', 'message': None, 'forums': [{'new_topics': 0, 'group': 0, 'name': u'import', 'author': u'tonal', 'description': <Markup u''>, 'replies': 0, 'topics': 0, 'moderators': <Markup u'tonal'>, 'lastreply': 'No replies', 'time': u'22.01.2008 16:44:33', 'new_replies': 0, 'lasttopic': 'No topics', 'id': 1, 'subject': <Markup u'\u041e\u0431\u0441\u0443\u0436\u0434\u0435\u043d\u0438\u0435 \u0438\u043c\u043f\u043e\u0440\u0442\u0430'>}], 'order': 'id', 'desc': None}
2008-01-23 12:53:16,049 Trac[main] DEBUG: Dispatching <Request "GET u'/discussion/1'">
2008-01-23 12:53:16,072 Trac[api] DEBUG: SELECT id, forum_group, name, subject, time, moderators, description FROM forum WHERE id = 1
2008-01-23 12:53:16,074 Trac[api] DEBUG: realm: discussion-core, action: None, preview: False, submit: False
2008-01-23 12:53:16,075 Trac[api] DEBUG: ['topic-list']
2008-01-23 12:53:16,076 Trac[session] DEBUG: Retrieving session for ID u'tonal'
2008-01-23 12:53:16,084 Trac[api] DEBUG: SELECT t.id, t.forum, t.time, t.subject, t.body, t.author, m.replies, m.lastreply FROM topic t LEFT JOIN (SELECT COUNT(id) AS replies, MAX(time) AS lastreply, topic FROM message GROUP BY topic) m ON t.id = m.topic WHERE t.forum = 1 ORDER BY t.id ASC
2008-01-23 12:53:16,093 Trac[chrome] DEBUG: Prepare chrome data for request
2008-01-23 12:53:16,121 Trac[api] DEBUG: {'topic': None, 'group': None, 'forum': {'group': 0, 'name': <Markup u'import'>, 'description': <Markup u''>, 'moderators': [u'tonal'], 'time': u'22.01.2008 16:44:33', 'id': 1, 'subject': <Markup u'\u041e\u0431\u0441\u0443\u0436\u0434\u0435\u043d\u0438\u0435 \u0438\u043c\u043f\u043e\u0440\u0442\u0430'>}, 'topics': [], 'time': u'23.01.2008 12:53:16', 'is_moderator': True, 'mode': 'topic-list', 'authname': u'tonal', 'realm': 'discussion-core', 'message': None, 'order': 'id', 'desc': None}
2008-01-23 12:53:19,394 Trac[main] DEBUG: Dispatching <Request "POST u'/discussion/1'">
2008-01-23 12:53:19,418 Trac[api] DEBUG: SELECT id, forum_group, name, subject, time, moderators, description FROM forum WHERE id = 1
2008-01-23 12:53:19,420 Trac[api] DEBUG: realm: discussion-core, action: add, preview: False, submit: False
2008-01-23 12:53:19,420 Trac[api] DEBUG: ['topic-add']
2008-01-23 12:53:19,421 Trac[session] DEBUG: Retrieving session for ID u'tonal'
2008-01-23 12:53:19,432 Trac[chrome] DEBUG: Prepare chrome data for request
2008-01-23 12:53:19,460 Trac[api] DEBUG: {'topic': None, 'group': None, 'forum': {'group': 0, 'name': <Markup u'import'>, 'description': <Markup u''>, 'moderators': [u'tonal'], 'time': u'22.01.2008 16:44:33', 'id': 1, 'subject': <Markup u'\u041e\u0431\u0441\u0443\u0436\u0434\u0435\u043d\u0438\u0435 \u0438\u043c\u043f\u043e\u0440\u0442\u0430'>}, 'time': u'23.01.2008 12:53:19', 'is_moderator': True, 'mode': 'topic-add', 'authname': u'tonal', 'realm': 'discussion-core', 'message': None}
2008-01-23 12:53:25,455 Trac[main] DEBUG: Dispatching <Request "POST u'/discussion/1'">
2008-01-23 12:53:25,479 Trac[api] DEBUG: SELECT id, forum_group, name, subject, time, moderators, description FROM forum WHERE id = 1
2008-01-23 12:53:25,481 Trac[api] DEBUG: realm: discussion-core, action: post-add, preview: False, submit: True
2008-01-23 12:53:25,482 Trac[api] DEBUG: ['topic-post-add', 'topic-list']
2008-01-23 12:53:25,483 Trac[session] DEBUG: Retrieving session for ID u'tonal'
2008-01-23 12:53:25,491 Trac[api] DEBUG: (u'aaa', u'Enter your message here...')
2008-01-23 12:53:25,492 Trac[api] DEBUG: INSERT INTO topic (forum, subject, time, author, body) VALUES (1, aaa, 1201071205, tonal, Enter your message here...)
2008-01-23 12:53:25,494 Trac[api] DEBUG: SELECT id, forum, subject, time, author, body FROM topic WHERE time = 1201071205
2008-01-23 12:53:25,495 Trac[api] DEBUG: SELECT t.author FROM topic t WHERE t.id = 1 UNION SELECT m.author FROM message m WHERE m.topic = 1
2008-01-23 12:53:25,603 Trac[chrome] DEBUG: Prepare chrome data for request
2008-01-23 12:53:25,720 Trac[notification] INFO: Sending SMTP notification to mail.nsib.ru:25 to [u'tonal@promsoft.ru']
2008-01-23 12:53:25,863 Trac[__init__] ERROR: (553, '5.5.2 Bad Message ID')
Traceback (most recent call last):
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/web/main.py", line 406, in _dispatch_request
    dispatcher.dispatch(req)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/web/main.py", line 195, in dispatch
    resp = chosen_handler.process_request(req)
  File "build/bdist.linux-i686/egg/tracdiscussion/core.py", line 77, in process_request
    return api.process_discussion(context) + (None,)
  File "build/bdist.linux-i686/egg/tracdiscussion/api.py", line 47, in process_discussion
    is_moderator)
  File "build/bdist.linux-i686/egg/tracdiscussion/api.py", line 567, in _do_action
    notifier.notify(context, mode, forum, new_topic, None, to, cc)
  File "build/bdist.linux-i686/egg/tracdiscussion/notification.py", line 84, in notify
    NotifyEmail.notify(self, id, subject)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/notification.py", line 239, in notify
    Notify.notify(self, resid)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/notification.py", line 129, in notify
    self.send(torcpts, ccrcpts)
  File "build/bdist.linux-i686/egg/tracdiscussion/notification.py", line 123, in send
    NotifyEmail.send(self, torcpts, ccrcpts, header)
  File "/usr/lib/python2.5/site-packages/Trac-0.11dev_r6399-py2.5.egg/trac/notification.py", line 404, in send
    self.server.sendmail(msg['From'], recipients, msgtext)
  File "smtplib.py", line 699, in sendmail
    raise SMTPDataError(code, resp)
SMTPDataError: (553, '5.5.2 Bad Message ID')

comment:4 Changed 7 years ago by anonymous

in addition to tonal@… - we have not spam filter for our smtp server.
And, Trac notification for tickets work smoothly.

comment:5 Changed 7 years ago by Blackhex

Yes, database is commited after notification is sent and if notification fails commit is not done. I'll make a change that error in notification is not critical (just displayed in GUI). Message ID is set in form <forum_id>-<topic_id>-<message_id>. Is there any reason why it is refused?

comment:6 Changed 7 years ago by tonal@…

Maybe You generate incorrect Message-ID?
see RFC 2822, email.utils.make_msgid or trac.ticket.notification.TicketNotifyEmail.get_message_id()

comment:7 Changed 7 years ago by Blackhex

Please try if r3160 fixed this. It should be RFC 2822 aware now.

comment:8 Changed 6 years ago by tonal@…

  • Resolution set to fixed
  • Status changed from assigned to closed

Problem fixed!

Add Comment

Modify Ticket

Action
as closed .
as The resolution will be set. Next status will be 'closed'.
to The owner will be changed from Blackhex. Next status will be 'closed'.
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.