Can't send messages to list
http://mail.python.org/pipermail/mailman-users/2006-August/thread.html#52865
Hello, I have similar problem as was discussed in link i just gave. When i send email to the list. It get's received,
Oct 16 14:11:12 localhost postfix/qmgr[1153]: BECCC25C12A: from=<email...>, size=203906, nrcpt=1 (queue active) Oct 16 14:11:13 localhost postfix/pipe[13741]: BECCC25C12A: to=<list@lists.example>, relay=mailman, delay=3, status=sent (lists.example.com) Oct 16 14:11:13 localhost postfix/qmgr[1153]: BECCC25C12A: removed
then it gets archived and then it tries to sent it out.
/var/log/mailman/smtp-failure says Oct 18 11:47:06 2006 (29893) delivery to email@email failed with code -1: (110, 'Connection timed out')
/var/log/mailman/smtp says: Oct 18 11:47:06 2006 (29893) <804e5c70610161138j444c3757j7e406a9b9ac81a65@mail.gmail.com> smtp for 34 recips, completed in 378.081 seconds
when i do
mail my@email.com ...etc
/var/log/mail.log says: Oct 18 12:01:03 localhost postfix/qmgr[29672]: 2EE1025C0C2: from=<lucas@example.com>, size=317, nrcpt=1 (queue active) Oct 18 12:01:04 localhost postfix/smtp[29961]: 2EE1025C0C2: to=<myadress@site.org>, relay=smtp.sbcglobal.yahoo.com[68.142.229.41], delay=1, status=sent (250 ok 1161194556 qp 85909) Oct 18 12:01:04 localhost postfix/qmgr[29672]: 2EE1025C0C2: removed
compname:/var/lib/mailman/locks# ls master-qrunner master-qrunner.compname.29686
and /var/lib/mailman/qfiles/out and retry has files in it
My setup is here: http://acm.cs.uic.edu/modules/mediawiki/index.php/Debian#Mailman_on_Debian_w...
OS: Debian stable/ postfix/ mailman with relay through sbcglobal
Permisions for mailman folder are:
drwxrwsr-x 4 root list 4096 2006-06-16 13:02 archives lrwxrwxrwx 1 root root 20 2006-10-18 10:44 bin -> /usr/lib/mailman/bin lrwxrwxrwx 1 root root 24 2006-10-18 10:44 cgi-bin -> /usr/lib/cgi-bin/mailman lrwxrwxrwx 1 root root 21 2006-10-18 10:44 cron -> /usr/lib/mailman/cron drwxrwsr-x 2 root list 4096 2006-10-18 11:59 data lrwxrwxrwx 1 root root 25 2006-10-18 10:44 icons -> /usr/share/images/mailman drwxrwsr-x 5 root list 4096 2006-06-23 17:37 lists lrwxrwxrwx 1 root root 18 2006-10-18 10:44 locks -> ../../lock/mailman lrwxrwxrwx 1 root root 17 2006-10-18 10:44 logs -> ../../log/mailman lrwxrwxrwx 1 root root 21 2006-10-18 10:44 mail -> /usr/lib/mailman/mail lrwxrwxrwx 1 root root 24 2006-10-18 10:44 Mailman -> /usr/lib/mailman/Mailman drwxrwsr-x 29 root list 4096 2006-06-16 13:02 messages drwxrwsr-x 11 list list 4096 2006-06-16 13:05 qfiles lrwxrwxrwx 1 root root 24 2006-10-18 10:44 scripts -> /usr/lib/mailman/scripts drwxrwsr-x 2 root list 4096 2006-03-29 13:58 spam lrwxrwxrwx 1 root root 12 2006-10-18 10:44 templates -> /etc/mailman drwxrwsr-x 4 root list 4096 2006-10-18 10:44 tests
Could you guys tell me what might be the problem? Lucas
Lukasz Szybalski wrote:
/var/log/mailman/smtp-failure says Oct 18 11:47:06 2006 (29893) delivery to email@email failed with code -1: (110, 'Connection timed out')
/var/log/mailman/smtp says: Oct 18 11:47:06 2006 (29893) <804e5c70610161138j444c3757j7e406a9b9ac81a65@mail.gmail.com> smtp for 34 recips, completed in 378.081 seconds
when i do
mail my@email.com ...etc
/var/log/mail.log says: Oct 18 12:01:03 localhost postfix/qmgr[29672]: 2EE1025C0C2: from=<lucas@example.com>, size=317, nrcpt=1 (queue active) Oct 18 12:01:04 localhost postfix/smtp[29961]: 2EE1025C0C2: to=<myadress@site.org>, relay=smtp.sbcglobal.yahoo.com[68.142.229.41], delay=1, status=sent (250 ok 1161194556 qp 85909) Oct 18 12:01:04 localhost postfix/qmgr[29672]: 2EE1025C0C2: removed
What's in mail.log for the failed transactions?
See <http://www.python.org/cgi-bin/faqw-mm.py?req=show&file=faq04.073.htp> (which I just wrote) for further debugging hints.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 10/18/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
/var/log/mailman/smtp-failure says Oct 18 11:47:06 2006 (29893) delivery to email@email failed with code -1: (110, 'Connection timed out')
/var/log/mailman/smtp says: Oct 18 11:47:06 2006 (29893) <804e5c70610161138j444c3757j7e406a9b9ac81a65@mail.gmail.com> smtp for 34 recips, completed in 378.081 seconds
when i do
mail my@email.com ...etc
/var/log/mail.log says: Oct 18 12:01:03 localhost postfix/qmgr[29672]: 2EE1025C0C2: from=<lucas@example.com>, size=317, nrcpt=1 (queue active) Oct 18 12:01:04 localhost postfix/smtp[29961]: 2EE1025C0C2: to=<myadress@site.org>, relay=smtp.sbcglobal.yahoo.com[68.142.229.41], delay=1, status=sent (250 ok 1161194556 qp 85909) Oct 18 12:01:04 localhost postfix/qmgr[29672]: 2EE1025C0C2: removed
What's in mail.log for the failed transactions? It didn't say anything. There was no record of any failure.
See <http://www.python.org/cgi-bin/faqw-mm.py?req=show&file=faq04.073.htp> (which I just wrote) for further debugging hints.
One issue was a domain. I am not sure why it has worked before and one day it stopped, but to continue on; i still have a problem.
http://mail.python.org/pipermail/mailman-users/2005-May/044742.html I did following test which showed me that when i use my SMTPHOST='example.com' i would not connect, which explains the time out.
I have added my webpage address to /etc/hosts (example.com was not there before)
fixed hosts file looks like: mycomputer:/home/lucas# cat /etc/hosts 127.0.0.1 localhost example.com mycomputer
I have tested it by(would be nice to have this test included with mailman as testmailman.py or something like that):
su list python
import smtplib SMTPHOST = 'localhost' SMTPPORT = 0 x = smtplib.SMTP() x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close <bound method SMTP.close of <smtplib.SMTP instance at 0x4021a5ec>> x.close() SMTPHOST = 'example.com' x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close() SMTPHOST = 'mycomp' x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close()
now it seemd to work for a second, it sent few mails but now: cat /var/log/mail.log says: Oct 23 10:55:36 localhost postfix/smtpd[11974]: connect from localhost[127.0.0.1] Oct 23 10:55:36 localhost postfix/smtpd[11974]: 3F54C25C0C3: client=localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/smtpd[11974]: timeout after DATA from localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/smtpd[11974]: disconnect from localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/cleanup[11977]: 3F54C25C0C3: message-id=<20061023155536.3F54C25C0C3@mycomp.example.com>
I changed the Mailman/Handlers/SMTPDirect.py as follows. def __connect(self): self.__conn = smtplib.SMTP() self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION and add a line so it becomes def __connect(self): self.__conn = smtplib.SMTP() self.__conn.set_debuglevel(1) self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
cat /var/log/mailman/smtp-fail says: Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70610201400r16756b9bm3ec9275c73984168@mail.gmail.com> Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor
qrunner says: Oct 23 06:25:35 2006 (1491) Master watcher caught SIGHUP. Re-opening log files.Oct 23 06:25:35 2006 (1492) ArchRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1493) BounceRunner qrunner caught SIGHUP. Reopening logs.Oct 23 06:25:35 2006 (1494) CommandRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1495) IncomingRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1496) NewsRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1497) OutgoingRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1498) VirginRunner qrunner caught SIGHUP. Reopening logs.Oct 23 06:25:35 2006 (1499) RetryRunner qrunner caught SIGHUP. Reopening logs.
What could be causing the problem?
Side note: is file permission like this normal? /var/lib/mailman/bin py files are in group list but pyo or pyc are in group root
-rwxr-xr-x 1 root list 1499 2006-09-20 07:18 convert.py -rw-r--r-- 1 root root 1148 2006-10-18 10:44 convert.pyc -rw-r--r-- 1 root root 1148 2006-10-18 10:44 convert.pyo -rwxr-xr-x 1 root list 3238 2006-09-20 07:18 discard -rwxr-xr-x 1 root list 4399 2006-09-20 07:18 dumpdb -rwxr-xr-x 1 root list 4951 2006-09-20 07:18 find_member -rwxr-xr-x 1 root list 2633 2006-09-20 07:18 fix_url.py -rw-r--r-- 1 root root 2491 2006-10-18 10:44 fix_url.pyc -rw-r--r-- 1 root root 2491 2006-10-18 10:44 fix_url.pyo
Lukasz Szybalski wrote:
One issue was a domain. I am not sure why it has worked before and one day it stopped, but to continue on; i still have a problem.
http://mail.python.org/pipermail/mailman-users/2005-May/044742.html I did following test which showed me that when i use my SMTPHOST='example.com' i would not connect, which explains the time out.
Which is why the default SMTPHOST is 'localhost'.
I have tested it by(would be nice to have this test included with mailman as testmailman.py or something like that):
su list python
import smtplib SMTPHOST = 'localhost' SMTPPORT = 0 x = smtplib.SMTP() x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close <bound method SMTP.close of <smtplib.SMTP instance at 0x4021a5ec>> x.close() SMTPHOST = 'example.com' x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close() SMTPHOST = 'mycomp' x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close()
now it seemd to work for a second, it sent few mails but now: cat /var/log/mail.log says: Oct 23 10:55:36 localhost postfix/smtpd[11974]: connect from localhost[127.0.0.1] Oct 23 10:55:36 localhost postfix/smtpd[11974]: 3F54C25C0C3: client=localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/smtpd[11974]: timeout after DATA from localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/smtpd[11974]: disconnect from localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/cleanup[11977]: 3F54C25C0C3: message-id=<20061023155536.3F54C25C0C3@mycomp.example.com>
I changed the Mailman/Handlers/SMTPDirect.py as follows. def __connect(self): self.__conn = smtplib.SMTP() self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION and add a line so it becomes def __connect(self): self.__conn = smtplib.SMTP() self.__conn.set_debuglevel(1) self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
cat /var/log/mailman/smtp-fail says: Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70610201400r16756b9bm3ec9275c73984168@mail.gmail.com> Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor
The above patch puts additional debugging info in Mailman's 'error' log. If you aren't seeing this, see below.
qrunner says: Oct 23 06:25:35 2006 (1491) Master watcher caught SIGHUP. Re-opening log files.Oct 23 06:25:35 2006 (1492) ArchRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1493) BounceRunner qrunner caught SIGHUP. Reopening logs.Oct 23 06:25:35 2006 (1494) CommandRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1495) IncomingRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1496) NewsRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1497) OutgoingRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1498) VirginRunner qrunner caught SIGHUP. Reopening logs.Oct 23 06:25:35 2006 (1499) RetryRunner qrunner caught SIGHUP. Reopening logs.
This indicates you did 'bin/mailmanctl reopen' (or sent mailmanctl a SIGHUP). You need to do 'bin/mailmanctl reopen' (or send mailmanctl a SIGINT) in order to reload the patched SMTPDirect.py module.
What could be causing the problem?
Side note: is file permission like this normal? /var/lib/mailman/bin py files are in group list but pyo or pyc are in group root
-rwxr-xr-x 1 root list 1499 2006-09-20 07:18 convert.py -rw-r--r-- 1 root root 1148 2006-10-18 10:44 convert.pyc -rw-r--r-- 1 root root 1148 2006-10-18 10:44 convert.pyo -rwxr-xr-x 1 root list 3238 2006-09-20 07:18 discard -rwxr-xr-x 1 root list 4399 2006-09-20 07:18 dumpdb -rwxr-xr-x 1 root list 4951 2006-09-20 07:18 find_member -rwxr-xr-x 1 root list 2633 2006-09-20 07:18 fix_url.py -rw-r--r-- 1 root root 2491 2006-10-18 10:44 fix_url.pyc -rw-r--r-- 1 root root 2491 2006-10-18 10:44 fix_url.pyo
This is normal. The various discard, dumpdb, etc files are the command line scripts and are normally installed with the owner/group and permissions as above (assuming you ran the install as root). convert.py and fix_url.py are 'withlist' scripts designed to be imported by 'bin/withlist -r'. only the .py file is normally installed. The .pyc (and .pyo if any) files are created by Python when withlist imports the module. They will normally have the owner:group of whoever ran the withlist command that imported them.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 10/23/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
One issue was a domain. I am not sure why it has worked before and one day it stopped, but to continue on; i still have a problem.
http://mail.python.org/pipermail/mailman-users/2005-May/044742.html I did following test which showed me that when i use my SMTPHOST='example.com' i would not connect, which explains the time out.
Which is why the default SMTPHOST is 'localhost'.
I have tested it by(would be nice to have this test included with mailman as testmailman.py or something like that):
su list python
import smtplib SMTPHOST = 'localhost' SMTPPORT = 0 x = smtplib.SMTP() x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close <bound method SMTP.close of <smtplib.SMTP instance at 0x4021a5ec>> x.close() SMTPHOST = 'example.com' x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close() SMTPHOST = 'mycomp' x.connect(SMTPHOST, SMTPPORT) (220, 'mycomp.example.com ESMTP Postfix (Debian/GNU)') x.close()
now it seemd to work for a second, it sent few mails but now: cat /var/log/mail.log says: Oct 23 10:55:36 localhost postfix/smtpd[11974]: connect from localhost[127.0.0.1] Oct 23 10:55:36 localhost postfix/smtpd[11974]: 3F54C25C0C3: client=localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/smtpd[11974]: timeout after DATA from localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/smtpd[11974]: disconnect from localhost[127.0.0.1] Oct 23 11:00:36 localhost postfix/cleanup[11977]: 3F54C25C0C3: message-id=<20061023155536.3F54C25C0C3@mycomp.example.com>
I changed the Mailman/Handlers/SMTPDirect.py as follows. def __connect(self): self.__conn = smtplib.SMTP() self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION and add a line so it becomes def __connect(self): self.__conn = smtplib.SMTP() self.__conn.set_debuglevel(1) self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
cat /var/log/mailman/smtp-fail says: Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70610201400r16756b9bm3ec9275c73984168@mail.gmail.com> Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 11:00:36 2006 (1497) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor
The above patch puts additional debugging info in Mailman's 'error' log. If you aren't seeing this, see below.
qrunner says: Oct 23 06:25:35 2006 (1491) Master watcher caught SIGHUP. Re-opening log files.Oct 23 06:25:35 2006 (1492) ArchRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1493) BounceRunner qrunner caught SIGHUP. Reopening logs.Oct 23 06:25:35 2006 (1494) CommandRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1495) IncomingRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1496) NewsRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1497) OutgoingRunner qrunner caught SIGHUP. Reopening logs. Oct 23 06:25:35 2006 (1498) VirginRunner qrunner caught SIGHUP. Reopening logs.Oct 23 06:25:35 2006 (1499) RetryRunner qrunner caught SIGHUP. Reopening logs.
This indicates you did 'bin/mailmanctl reopen' (or sent mailmanctl a SIGHUP). You need to do 'bin/mailmanctl reopen' (or send mailmanctl a SIGINT) in order to reload the patched SMTPDirect.py module.
What could be causing the problem?
Side note: is file permission like this normal? /var/lib/mailman/bin py files are in group list but pyo or pyc are in group root
-rwxr-xr-x 1 root list 1499 2006-09-20 07:18 convert.py -rw-r--r-- 1 root root 1148 2006-10-18 10:44 convert.pyc -rw-r--r-- 1 root root 1148 2006-10-18 10:44 convert.pyo -rwxr-xr-x 1 root list 3238 2006-09-20 07:18 discard -rwxr-xr-x 1 root list 4399 2006-09-20 07:18 dumpdb -rwxr-xr-x 1 root list 4951 2006-09-20 07:18 find_member -rwxr-xr-x 1 root list 2633 2006-09-20 07:18 fix_url.py -rw-r--r-- 1 root root 2491 2006-10-18 10:44 fix_url.pyc -rw-r--r-- 1 root root 2491 2006-10-18 10:44 fix_url.pyo
This is normal. The various discard, dumpdb, etc files are the command line scripts and are normally installed with the owner/group and permissions as above (assuming you ran the install as root). convert.py and fix_url.py are 'withlist' scripts designed to be imported by 'bin/withlist -r'. only the .py file is normally installed. The .pyc (and .pyo if any) files are created by Python when withlist imports the module. They will normally have the owner:group of whoever ran the withlist command that imported them.
Why do i get this error in smtp-failure? Any ideas?
Oct 23 20:30:31 2006 (13510) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161642951.1495.listname@lists.example.com> Oct 23 20:33:30 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161643730.13036.lists@lists.example.com>
mail.info says: Oct 23 20:25:31 localhost postfix/smtpd[13513]: connect from localhost[127.0.0.1] Oct 23 20:25:31 localhost postfix/smtpd[13513]: 0CA9A25C0C3: client=localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: timeout after DATA from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: disconnect from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/cleanup[13514]: 0CA9A25C0C3: message-id=<20061024012531.0CA9A25C0C3@mycomp.example.com>
Lukasz Szybalski wrote:
Why do i get this error in smtp-failure? Any ideas?
Oct 23 20:30:31 2006 (13510) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161642951.1495.listname@lists.example.com> Oct 23 20:33:30 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161643730.13036.lists@lists.example.com>
mail.info says: Oct 23 20:25:31 localhost postfix/smtpd[13513]: connect from localhost[127.0.0.1] Oct 23 20:25:31 localhost postfix/smtpd[13513]: 0CA9A25C0C3: client=localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: timeout after DATA from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: disconnect from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/cleanup[13514]: 0CA9A25C0C3: message-id=<20061024012531.0CA9A25C0C3@mycomp.example.com>
You say you changed SMTPDirect.py.
I changed the Mailman/Handlers/SMTPDirect.py as follows. def __connect(self): self.__conn = smtplib.SMTP() self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION and add a line so it becomes def __connect(self): self.__conn = smtplib.SMTP() self.__conn.set_debuglevel(1) self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
Then be sure you have done
bin/mailmanctl restart
and report what is in Mailman's 'error' log with the same timestamps as the 'smtp-failure' log entries.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 10/23/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
Why do i get this error in smtp-failure? Any ideas?
Oct 23 20:30:31 2006 (13510) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) delivery to email@email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161642951.1495.listname@lists.example.com> Oct 23 20:33:30 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161643730.13036.lists@lists.example.com>
mail.info says: Oct 23 20:25:31 localhost postfix/smtpd[13513]: connect from localhost[127.0.0.1] Oct 23 20:25:31 localhost postfix/smtpd[13513]: 0CA9A25C0C3: client=localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: timeout after DATA from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: disconnect from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/cleanup[13514]: 0CA9A25C0C3: message-id=<20061024012531.0CA9A25C0C3@mycomp.example.com>
You say you changed SMTPDirect.py.
I changed the Mailman/Handlers/SMTPDirect.py as follows. def __connect(self): self.__conn = smtplib.SMTP() self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION and add a line so it becomes def __connect(self): self.__conn = smtplib.SMTP() self.__conn.set_debuglevel(1) self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) self.__numsessions = mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
Then be sure you have done
bin/mailmanctl restart
and report what is in Mailman's 'error' log with the same timestamps as the 'smtp-failure' log entries.
mailman has been restarted many times...and here are the outputs: It seems as some messages go through after few hours. I created test mailing list subscribed users, and 4 hours later subscription emal went through...but here is the errior with the same time stamps.
smtp-failure: Oct 24 08:15:37 2006 (18268) delivery to mylist-owner@lists.example.com failed with code -1: [Errno 9] Bad file descriptor Oct 24 08:15:37 2006 (18268) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70610201400r16756b9bm3ec9275c73984168@mail.gmail.com>
mail.log: Oct 24 08:10:37 localhost postfix/smtpd[19990]: connect from localhost[127.0.0.1] Oct 24 08:10:37 localhost postfix/smtpd[19990]: 25AE325C0C3: client=localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/smtpd[19990]: timeout after DATA from localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/smtpd[19990]: disconnect from localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/cleanup[19993]: 25AE325C0C3: message-id=<20061024131037.25AE325C0C3@mycomp.example.com> Oct 24 08:15:37 localhost postfix/smtpd[19990]: connect from localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/smtpd[19990]: 768C925C0C3: client=localhost[127.0.0.1]
mail.info: Oct 24 08:15:37 localhost postfix/smtpd[19990]: timeout after DATA from localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/smtpd[19990]: disconnect from localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/cleanup[19993]: 25AE325C0C3: message-id=<20061024131037.25AE325C0C3@mycomp.example.com> Oct 24 08:15:37 localhost postfix/smtpd[19990]: connect from localhost[127.0.0.1] Oct 24 08:15:37 localhost postfix/smtpd[19990]: 768C925C0C3: client=localhost[127.0.0.1]
Thanks, Lucas
Lukasz Szybalski wrote:
mailman has been restarted many times...and here are the outputs: It seems as some messages go through after few hours. I created test mailing list subscribed users, and 4 hours later subscription emal went through...but here is the errior with the same time stamps.
smtp-failure: Oct 24 08:15:37 2006 (18268) delivery to mylist-owner@lists.example.com failed with code -1: [Errno 9] Bad file descriptor Oct 24 08:15:37 2006 (18268) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70610201400r16756b9bm3ec9275c73984168@mail.gmail.com>
Once again - in the same directory as you find the 'smtp-failure' log above, there is a log file named 'error'. That is where the debug output from Python's smtplib is found. What is in that log?
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 10/24/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
mailman has been restarted many times...and here are the outputs: It seems as some messages go through after few hours. I created test mailing list subscribed users, and 4 hours later subscription emal went through...but here is the errior with the same time stamps.
smtp-failure: Oct 24 08:15:37 2006 (18268) delivery to mylist-owner@lists.example.com failed with code -1: [Errno 9] Bad file descriptor Oct 24 08:15:37 2006 (18268) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70610201400r16756b9bm3ec9275c73984168@mail.gmail.com>
Once again - in the same directory as you find the 'smtp-failure' log above, there is a log file named 'error'. That is where the debug output from Python's smtplib is found. What is in that log?
error: (doesn't have much there)
Oct 23 20:50:42 2006 mailmanctl(13642): The master qrunner lock could not be acquired because it appears as if another master qrunner is already running. I was restarting mailman..
Oct 23 20:50:42 2006 mailmanctl(13642): Oct 23 20:59:39 2006 (13656) Cannot connect to SMTP server localhost on port smtp Oct 24 08:36:36 2006 (18268) Cannot connect to SMTP server localhost on port smtp not sure about these 2 other than, my postfix is working since i can send and receive emails. I assume it had to be somewhat connected with the timeout in previous error.
Lucas
Lukasz Szybalski wrote:
error: (doesn't have much there)
Oct 23 20:50:42 2006 mailmanctl(13642): The master qrunner lock could not be acquired because it appears as if another master qrunner is already running. I was restarting mailman..
'restart' won't issue this message. This message comes from doing 'mailmanctl start' without first doing 'mailmanctl stop' and waithing for everything to stop.
Oct 23 20:50:42 2006 mailmanctl(13642): Oct 23 20:59:39 2006 (13656) Cannot connect to SMTP server localhost on port smtp Oct 24 08:36:36 2006 (18268) Cannot connect to SMTP server localhost on port smtp not sure about these 2 other than, my postfix is working since i can send and receive emails. I assume it had to be somewhat connected with the timeout in previous error.
This is an exception reported by OutgoingRunner when SMTPDirect encounters an uncaught socket.error exception.
There is no debug output from smtplib.
Which Mailman/Handlers/SMTPDirect.py did you patch? is there a SMTPDirect.pyc in the same directory with a timestamp later than SMTPDirect.py? The timestamp on SMTPDirect.pyc should be the time of the first 'mailmanctl restart' following the change to SMTPDirect.py.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Lukasz Szybalski wrote:
Why do i get this error in smtp-failure? Any ideas?
Oct 23 20:30:31 2006 (13510) delivery to email at email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) delivery to email at email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161642951.1495.listname at lists.example.com> Oct 23 20:33:30 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161643730.13036.lists at lists.example.com>
mail.info says: Oct 23 20:25:31 localhost postfix/smtpd[13513]: connect from localhost[127.0.0.1] Oct 23 20:25:31 localhost postfix/smtpd[13513]: 0CA9A25C0C3: client=localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: timeout after DATA from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: disconnect from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/cleanup[13514]: 0CA9A25C0C3: message-id=<20061024012531.0CA9A25C0C3 at mycomp.example.com>
I looked at this a bit deeper, and I see the '[Errno 9] Bad file descriptor' originates in the Python socket library when smtplib attempts to send or receive on a closed connection.
Therefore, it appears the scenario is something like the following:
- Mailman attempts to send
- The SMTP transaction proceeds to the point where smtplib sends DATA
- Something happens (or doesn't happen) here and the MTA times out (after waiting 5 minutes) and disconnects (closes the socket).
- smtplib sends or receives on the closed socket and gets the error 9.
We still don't know what causes the timeout. The smtplib debugging info would help.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 10/24/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
Why do i get this error in smtp-failure? Any ideas?
Oct 23 20:30:31 2006 (13510) delivery to email at email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) delivery to email at email.com failed with code -1: [Errno 9] Bad file descriptor Oct 23 20:30:31 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161642951.1495.listname at lists.example.com> Oct 23 20:33:30 2006 (13510) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <mailman.1.1161643730.13036.lists at lists.example.com>
mail.info says: Oct 23 20:25:31 localhost postfix/smtpd[13513]: connect from localhost[127.0.0.1] Oct 23 20:25:31 localhost postfix/smtpd[13513]: 0CA9A25C0C3: client=localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: timeout after DATA from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/smtpd[13513]: disconnect from localhost[127.0.0.1] Oct 23 20:30:31 localhost postfix/cleanup[13514]: 0CA9A25C0C3: message-id=<20061024012531.0CA9A25C0C3 at mycomp.example.com>
-rw-r--r-- 1 root list 16282 2006-10-18 17:38 SMTPDirect.py -rw-r--r-- 1 root root 10009 2006-10-23 21:18 SMTPDirect.pyc -rw-r--r-- 1 root root 10009 2006-10-23 21:18 SMTPDirect.pyo
I looked at this a bit deeper, and I see the '[Errno 9] Bad file descriptor' originates in the Python socket library when smtplib attempts to send or receive on a closed connection.
Therefore, it appears the scenario is something like the following:
- Mailman attempts to send
- The SMTP transaction proceeds to the point where smtplib sends DATA
- Something happens (or doesn't happen) here and the MTA times out (after waiting 5 minutes) and disconnects (closes the socket).
- smtplib sends or receives on the closed socket and gets the error 9.
We still don't know what causes the timeout. The smtplib debugging info would help.
Where would i find it or how would i get it. Error, smtp, smtp-failure, syslog has only what i have pasted in.
Lukasz Szybalski wrote:
On 10/24/06, Mark Sapiro <msapiro@value.net> wrote:
We still don't know what causes the timeout. The smtplib debugging info would help.
Where would i find it or how would i get it. Error, smtp, smtp-failure, syslog has only what i have pasted in.
The patch to SMTPDirect.py which you say you installed causes Pythons smtplib to write debugging info to stderr which in a normal Mailman environment is logged to Mailman's error log. Since you are not getting the debugging information in Mailman's error log, either you haven't applied the patch correctly or you haven't patched the correct file (see the last paragraph of <http://mail.python.org/pipermail/mailman-users/2006-October/054017.html>) or something is going wrong with logging of stderr writes to the error log.
I don't think it's likely that the problem is in the logging of stderr unless this is a Debian issue that I don't know about.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 10/24/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
On 10/24/06, Mark Sapiro <msapiro@value.net> wrote:
We still don't know what causes the timeout. The smtplib debugging info would help.
Where would i find it or how would i get it. Error, smtp, smtp-failure, syslog has only what i have pasted in.
The patch to SMTPDirect.py which you say you installed causes Pythons smtplib to write debugging info to stderr which in a normal Mailman environment is logged to Mailman's error log. Since you are not getting the debugging information in Mailman's error log, either you haven't applied the patch correctly or you haven't patched the correct file (see the last paragraph of <http://mail.python.org/pipermail/mailman-users/2006-October/054017.html>) or something is going wrong with logging of stderr writes to the error log. That is the file i patched SMTPDirect.py
57 class Connection: 58 def __init__(self): 59 self.__conn = None 60 61 def __connect(self): 62 self.__conn = smtplib.SMTP() 63 self.__conn.set_debuglevel(1) 64 self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) 65 self.__numsessions=mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
So after playing with it for a while...I figured the exception is here...
381 except (socket.error, IOError, smtplib.SMTPException), e: 382 # MTA not responding, or other socket problems, or any other kind of 383 # SMTPException. In that case, nothing got delivered, so treat this 384 # as a temporary failure. 385 syslog('smtp-failure', 'Low level smtp error: %s, msgid: %s', e, msgid) 386 error = str(e) 387 for r in recips: 388 refused[r] = (-1, error)
Is there a way to manually get the debug info from smtplib (conversation with postfix) within this file? debuglevel works if i do it by hand...
I could add something like this, its just where? syslog('smtp-failure', 'conversation with smtplib: %s', e)
Also, the emails seem to go through. Then they stop and then go after i do reopen.
Oct 25 12:51:39 localhost postfix/qmgr[1956]: 3B83225C0C9: from=<email@site.org>, size=1070, nrcpt=1 (queue active) Oct 25 12:51:39 localhost postfix/smtpd[2479]: disconnect from xxx.net[207.115.57.84] Oct 25 12:51:39 localhost postfix/local[2483]: 3B83225C0C9: to=<test@example.com>, relay=local, delay=0, status=sent (delivered to command: /var/lib/mailman/mail/mailman post test) Oct 25 12:51:39 localhost postfix/qmgr[1956]: 3B83225C0C9: removed Oct 25 12:51:40 localhost postfix/smtpd[2479]: connect from localhost[127.0.0.1]Oct 25 12:51:40 localhost postfix/smtpd[2479]: EE11A25C0C9: client=localhost[127.0.0.1] Oct 25 12:51:40 localhost postfix/cleanup[2482]: EE11A25C0C9: message-id=<453F6C2C.21928.1A7A5A2D@email.site.org> Oct 25 12:51:41 localhost postfix/qmgr[1956]: EE11A25C0C9: from=<test-bounces@example.com>, size=2078, nrcpt=4 (queue active) Oct 25 12:51:41 localhost postfix/smtpd[2479]: disconnect from localhost[127.0.0.1] Oct 25 12:51:41 localhost postfix/local[2483]: EE11A25C0C9: to=<lucas@example.com>, relay=local, delay=1, status=sent (delivered to command: procmail -a "$EXTENSION") Oct 25 12:51:41 localhost postfix/local[2483]: EE11A25C0C9: to=<lucas@example.com>, orig_to=<webmaster@example.com>, relay=local, delay=1, status=sent (delivered to command: procmail -a "$EXTENSION") Oct 25 12:51:41 localhost postfix/smtp[2486]: EE11A25C0C9: to=<example@gmail.com>, relay=smtp.sbcglobal.yahoo.com[68.142.229.41], delay=1, status=sent (250 ok 1161802397 qp 24637) Oct 25 12:51:41 localhost postfix/smtp[2486]: EE11A25C0C9: to=<email_pl@hotmail.com>, relay=smtp.sbcglobal.yahoo.com[68.142.229.41], delay=1, status=sent (250 ok 1161802397 qp 24637) Oct 25 12:51:41 localhost postfix/qmgr[1956]: EE11A25C0C9: removed
Oct 25 12:55:20 localhost postfix/smtpd[2501]: connect from localhost[127.0.0.1]Oct 25 12:55:20 localhost postfix/smtpd[2501]: 525DB25C0C9: client=localhost[127.0.0.1]
Doing : mailmanctrl reopen after 20 sec.
Oct 25 12:55:46 localhost postfix/smtpd[2501]: lost connection after DATA from localhost[127.0.0.1] Oct 25 12:55:46 localhost postfix/smtpd[2501]: disconnect from localhost[127.0.0.1] Oct 25 12:55:46 localhost postfix/cleanup[2504]: 525DB25C0C9: message-id=<20061025175520.525DB25C0C9@mycomp.example.com> Oct 25 12:55:46 localhost postfix/smtpd[2501]: connect from localhost[127.0.0.1]Oct 25 12:55:46 localhost postfix/smtpd[2501]: 45FD325C0C9: client=localhost[127.0.0.1] Oct 25 12:55:46 localhost postfix/cleanup[2504]: 45FD325C0C9: message-id=<453F6C2C.21928.1A7A5A2D@email.site.org> Oct 25 12:55:46 localhost postfix/qmgr[1956]: 45FD325C0C9: from=<test-bounces@example.com>, size=2106, nrcpt=1 (queue active) Oct 25 12:55:46 localhost postfix/smtpd[2501]: disconnect from localhost[127.0.0.1] Oct 25 12:55:46 localhost postfix/smtp[2508]: 45FD325C0C9: to=<email@site.org>, relay=smtp.sbcglobal.yahoo.com[68.142.229.41], delay=0, status=sent (250 ok 1161802643 qp 89987) Oct 25 12:55:46 localhost postfix/qmgr[1956]: 45FD325C0C9: removed
Thanks, Lucas
I don't think it's likely that the problem is in the logging of stderr unless this is a Debian issue that I don't know about.
Lukasz Szybalski wrote:
That is the file i patched SMTPDirect.py
57 class Connection: 58 def __init__(self): 59 self.__conn = None 60 61 def __connect(self): 62 self.__conn = smtplib.SMTP() 63 self.__conn.set_debuglevel(1) 64 self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) 65 self.__numsessions=mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
But is it the correct Mailman/Handlers/SMTPDirect.py. I.e. is it the one in the running Mailman installation, and not one in some unpack or build directory?
Did you check the timestamp on the Mailman/Handlers/SMTPDirect.pyc on the same path (if there is one) to be sure it is the one being imported by Mailman after you do a 'restart'
So after playing with it for a while...I figured the exception is here...
381 except (socket.error, IOError, smtplib.SMTPException), e: 382 # MTA not responding, or other socket problems, or any other kind of 383 # SMTPException. In that case, nothing got delivered, so treat this 384 # as a temporary failure. 385 syslog('smtp-failure', 'Low level smtp error: %s, msgid: %s', e, msgid) 386 error = str(e) 387 for r in recips: 388 refused[r] = (-1, error)
Is there a way to manually get the debug info from smtplib (conversation with postfix) within this file? debuglevel works if i do it by hand...
What do you mean 'do it by hand'? Presumably, whatever you do by hand doesn't fail. What is that?
I could add something like this, its just where? syslog('smtp-failure', 'conversation with smtplib: %s', e)
You can't. The error occurs in the processing of
refused = conn.sendmail(envsender, recips, msgtext)in bulk_deliver and the exception is already caught and all available information is reported. That's why you have to enable smtplib debugging to get more information than you already have.
Also, the emails seem to go through. Then they stop and then go after i do reopen.
'reopen' is not the same as 'restart'. Have you ever done a 'restart'? All 'reopen' does is tell the runners to close and reopen their log files. It doesn't reload any edited modules.
And, why they stop is what we're trying to figure out, and I can't tell you any more than I already have without additional information.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Lukasz Szybalski wrote: /var/lib/mailman/Mailman/Handlers/SMTPDirect.py
That is the file i patched SMTPDirect.py
57 class Connection: 58 def __init__(self): 59 self.__conn = None 60 61 def __connect(self): 62 self.__conn = smtplib.SMTP() 63 self.__conn.set_debuglevel(1) 64 self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) 65 self.__numsessions=mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
Is there a way to manually get the debug info from smtplib (conversation with postfix) within this file?
Temporary SOLUTION.
After placing a bug report in debian, i have been given two files to make debug information work.
"replacements for /usr/lib/python2.3/smtplib.py and /usr/lib/mailman/Mailman/Logging/Utils.py that will enable smtplib-debugging to work (you still have to patch SMTPDirect.py) "
I went in and renamed smtplib.py to smtplib.py.1 put the new file in and deleted smtplib.pyc ad smtplib.pyo Then renamed /usr/lib/mailman/Mailman/Logging/Utils.py to Utils.py.1 (make sure its this one...there is at least 5 files called Utils.py) put the new file in and deleted Utils.pyc and Utils.pyo
then /etc/init.d/mailman restart tail -f /var/log/mailman/error
while i was watching this i sent an emial to my testing group, etc.
Long story short. I replaced these files, removed pyc and pyo and suddenly everything works like magic again. No more timeouts. I'll try to get originals back in place and see how that works. I'll keep you posted.
You can get the files from.... http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=395493
Lukasz
And, why they stop is what we're trying to figure out, and I can't tell you any more than I already have without additional information.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Lukasz Szybalski wrote:
After placing a bug report in debian, i have been given two files to make debug information work.
"replacements for /usr/lib/python2.3/smtplib.py and /usr/lib/mailman/Mailman/Logging/Utils.py that will enable smtplib-debugging to work (you still have to patch SMTPDirect.py) "
I have looked at the bug report and the two files. I now see I was mistaken in that I was all along looking at the Python 2.4 smtplib.py. It turns out that Python 2.3 smtplib.py does write debug output to stdout, not stderr which explains why you weren't seeing it.
Long story short. I replaced these files, removed pyc and pyo and suddenly everything works like magic again. No more timeouts. I'll try to get originals back in place and see how that works. I'll keep you posted.
The change to Logging/Utils.py only affects logging of stderr, thus I wouldn't expect this to affect the original issue.
It would be interesting to see the differences between the original smtplib.py (now named smtplib.py.1) and the replacement. Do they only add "import sys" and replace "print" with "print >> sys.stderr,", or are there other changes. If there are no other changes, I am guessing that the real problem is some kind of corruption in the .pyc or .pyo files that you deleted.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 11/3/06, Lukasz Szybalski <szybalski@gmail.com> wrote:
Lukasz Szybalski wrote: /var/lib/mailman/Mailman/Handlers/SMTPDirect.py
That is the file i patched SMTPDirect.py
57 class Connection: 58 def __init__(self): 59 self.__conn = None 60 61 def __connect(self): 62 self.__conn = smtplib.SMTP() 63 self.__conn.set_debuglevel(1) 64 self.__conn.connect(mm_cfg.SMTPHOST, mm_cfg.SMTPPORT) 65 self.__numsessions=mm_cfg.SMTP_MAX_SESSIONS_PER_CONNECTION
Is there a way to manually get the debug info from smtplib (conversation with postfix) within this file?
Temporary SOLUTION.
After placing a bug report in debian, i have been given two files to make debug information work.
"replacements for /usr/lib/python2.3/smtplib.py and /usr/lib/mailman/Mailman/Logging/Utils.py that will enable smtplib-debugging to work (you still have to patch SMTPDirect.py) "
I went in and renamed smtplib.py to smtplib.py.1 put the new file in and deleted smtplib.pyc ad smtplib.pyo Then renamed /usr/lib/mailman/Mailman/Logging/Utils.py to Utils.py.1 (make sure its this one...there is at least 5 files called Utils.py) put the new file in and deleted Utils.pyc and Utils.pyo
then /etc/init.d/mailman restart tail -f /var/log/mailman/error
while i was watching this i sent an emial to my testing group, etc.
Long story short. I replaced these files, removed pyc and pyo and suddenly everything works like magic again. No more timeouts. I'll try to get originals back in place and see how that works. I'll keep you posted.
I put the original smtplib.py file back in /varlib/python.3/smtplib.py and i get the same problem again.
Nov 08 16:41:31 2006 (13973) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70611081443y26603704gdecfae9847cf64f4@xxx.xxxx.com> Nov 08 16:46:31 2006 (13973) delivery to xxxxx@xxx.com failed with code -1: [Errno 9] Bad file descriptor Nov 08 16:46:31 2006 (13973) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <455209CD.20560.1BA7A89@xxxx.xxxx.org> Nov 08 16:46:31 2006 (13973) delivery to xxxx@xxxx.com failed with code -1: [Errno 9] Bad file descriptor
So i guess i will stick with the file i got from debian bug
You can get the files from.... http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=395493
Lukasz
And, why they stop is what we're trying to figure out, and I can't tell you any more than I already have without additional information.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
-- Universal Information Crawler http://uicrawler.sourceforge.net/
Lukasz Szybalski wrote:
I put the original smtplib.py file back in /varlib/python.3/smtplib.py and i get the same problem again.
Nov 08 16:41:31 2006 (13973) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70611081443y26603704gdecfae9847cf64f4@xxx.xxxx.com> Nov 08 16:46:31 2006 (13973) delivery to xxxxx@xxx.com failed with code -1: [Errno 9] Bad file descriptor Nov 08 16:46:31 2006 (13973) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <455209CD.20560.1BA7A89@xxxx.xxxx.org> Nov 08 16:46:31 2006 (13973) delivery to xxxx@xxxx.com failed with code -1: [Errno 9] Bad file descriptor
So i guess i will stick with the file i got from debian bug
Please post a 'diff -u' between the smtplib.py that works and the one that doesn't work.
Lionel says that effectively all he changed in your working version was writing debug output to sys.stderr instead of stdout, and when I diffed Lionel's version with the Python 2.3.4 base, that's the only change I saw, but there must be something else in your case or else simply enabling the debug prints causes the problem because of the writes to stdout, but then what caused the original problem.
In any case, I am very interested to see if there is some other change in your original smtplib.py that is causing it to fail.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Mark:
I made the changes that Lucaz mentioned, with the two files, replacing them and now mailman SEEMS to be working. It is sending out to my list anyway.
I am not sure that everything is working quite right though so I'll test things more, for a few days.
Scott
On 11/8/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
I put the original smtplib.py file back in /varlib/python.3/smtplib.py and i get the same problem again.
Nov 08 16:41:31 2006 (13973) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <804e5c70611081443y26603704gdecfae9847cf64f4@xxx.xxxx.com> Nov 08 16:46:31 2006 (13973) delivery to xxxxx@xxx.com failed with code -1: [Errno 9] Bad file descriptor Nov 08 16:46:31 2006 (13973) Low level smtp error: [Errno 9] Bad file descriptor, msgid: <455209CD.20560.1BA7A89@xxxx.xxxx.org> Nov 08 16:46:31 2006 (13973) delivery to xxxx@xxxx.com failed with code -1: [Errno 9] Bad file descriptor
So i guess i will stick with the file i got from debian bug
Please post a 'diff -u' between the smtplib.py that works and the one that doesn't work.
Lionel says that effectively all he changed in your working version was writing debug output to sys.stderr instead of stdout, and when I diffed Lionel's version with the Python 2.3.4 base, that's the only change I saw, but there must be something else in your case or else simply enabling the debug prints causes the problem because of the writes to stdout, but then what caused the original problem.
In any case, I am very interested to see if there is some other change in your original smtplib.py that is causing it to fail.
Please not the smtlib.py is the one given to me and smtlib.py.1 is the original one causing the problem. I posted the whole file to debian bug report also. xxx@xxx:/usr/lib/python2.3$ diff -u smtplib.py smtplib.py.1 --- smtplib.py 2006-11-03 11:35:49.000000000 -0600 +++ smtplib.py.1 2006-11-03 12:41:55.000000000 -0600 @@ -41,7 +41,6 @@ # # This was modified from the Python 1.5 library HTTP lib. -import sys import socket import re import rfc822 @@ -283,17 +282,17 @@ except ValueError: raise socket.error, "nonnumeric port" if not port: port = SMTP_PORT - if self.debuglevel > 0: print >> sys.stderr, 'connect:', (host, port) + if self.debuglevel > 0: print 'connect:', (host, port) msg = "getaddrinfo returns an empty list" self.sock = None for res in socket.getaddrinfo(host, port, 0, socket.SOCK_STREAM): af, socktype, proto, canonname, sa = res try: self.sock = socket.socket(af, socktype, proto) - if self.debuglevel > 0: print >> sys.stderr, 'connect:', (host, port) + if self.debuglevel > 0: print 'connect:', (host, port) self.sock.connect(sa) except socket.error, msg: - if self.debuglevel > 0: print >> sys.stderr, 'connect fail:', (host, port) + if self.debuglevel > 0: print 'connect fail:', (host, port) if self.sock: self.sock.close() self.sock = None @@ -302,12 +301,12 @@ if not self.sock: raise socket.error, msg (code, msg) = self.getreply() - if self.debuglevel > 0: print >> sys.stderr, "connect:", msg + if self.debuglevel > 0: print "connect:", msg return (code, msg) def send(self, str): """Send `str' to the server.""" - if self.debuglevel > 0: print >> sys.stderr, 'send:', `str` + if self.debuglevel > 0: print 'send:', `str` if self.sock: try: self.sock.sendall(str) @@ -346,7 +345,7 @@ if line == '': self.close() raise SMTPServerDisconnected("Connection unexpectedly closed") - if self.debuglevel > 0: print >> sys.stderr, 'reply:', `line` + if self.debuglevel > 0: print 'reply:', `line` resp.append(line[4:].strip()) code=line[:3] # Check that the error code is syntactically correct. @@ -362,7 +361,7 @@ errmsg = "\n".join(resp) if self.debuglevel > 0: - print >> sys.stderr, 'reply: retcode (%s); Msg: %s' % (errcode,errmsg) + print 'reply: retcode (%s); Msg: %s' % (errcode,errmsg) return errcode, errmsg def docmd(self, cmd, args=""): @@ -475,7 +474,7 @@ """ self.putcmd("data") (code,repl)=self.getreply() - if self.debuglevel >0 : print >> sys.stderr, "data:", (code,repl) + if self.debuglevel >0 : print "data:", (code,repl) if code != 354: raise SMTPDataError(code,repl) else: @@ -485,7 +484,7 @@ q = q + "." + CRLF self.send(q) (code,msg)=self.getreply() - if self.debuglevel >0 : print >> sys.stderr, "data:", (code,msg) + if self.debuglevel >0 : print "data:", (code,msg) return (code,msg) def verify(self, address): xxx@xxx:/usr/lib/python2.3$ http://bugs.debian.org/cgi-bin/bugreport.cgi?bug=395493 -- Universal Information Crawler http://uicrawler.sourceforge.net/
Lukasz Szybalski wrote:
Please not the smtlib.py is the one given to me and smtlib.py.1 is the original one causing the problem. I posted the whole file to debian bug report also.
Your diff and the smtplib.py (the file you refer to above as smtplib.py.1) you posted to the bug report confirm that this file is essentially unchanged from the Python 2.3 base smtplib.py.
Therefore, I have to conclude that the symptom you see when you put this in the Python library is due to the debug writes being to stdout instead of stderr.
Thus, I think you still have the added
self.__conn.set_debuglevel(1)line in SMTPDirect.py. I think if you remove this line and then put the original smtplib.py back in the python library (and to be sure, remove the smtplib.pyc and smtplib.pyo to force a recompile), Mailman will continue to send OK.
If this is the case, the original problem will have magically disappeared. The only reason I can think of for this is that the update that caused the problem may have had a corrupted smtplib.pyc and/or smtplib.pyo.
-- Mark Sapiro <msapiro@value.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
On 11/10/06, Mark Sapiro <msapiro@value.net> wrote:
Lukasz Szybalski wrote:
Please not the smtlib.py is the one given to me and smtlib.py.1 is the original one causing the problem. I posted the whole file to debian bug report also.
Your diff and the smtplib.py (the file you refer to above as smtplib.py.1) you posted to the bug report confirm that this file is essentially unchanged from the Python 2.3 base smtplib.py.
Therefore, I have to conclude that the symptom you see when you put this in the Python library is due to the debug writes being to stdout instead of stderr.
Thus, I think you still have the added
self.__conn.set_debuglevel(1)line in SMTPDirect.py. I think if you remove this line and then put the original smtplib.py back in the python library (and to be sure, remove the smtplib.pyc and smtplib.pyo to force a recompile), Mailman will continue to send OK.
If this is the case, the original problem will have magically disappeared. The only reason I can think of for this is that the update that caused the problem may have had a corrupted smtplib.pyc and/or smtplib.pyo.
I just put back the original file, removed debug level line, and everything seems to be working. I guess the bug is solved for me.
Thank you very much for your help. Sincerely, Lukasz Szybalski
-Signoff-
participants (3)
-
Dr. Scott S. Jones -
Lukasz Szybalski -
Mark Sapiro