What is the status of Postfix at particular time? Before starting mwes manually see its backend running processes first.
Mail log is producing any errors?
Mailwasher Entreprise with postfix
- ajt
- would rather be watching cricket
- Contact:
- Location: Auckland, New Zealand
- chquek
- Student Sheep
Post
Re: Mailwasher Entreprise with postfix
The Postfix didn't seems to be affected by that. I tried doing a smtp when Mailwasher was down and the mail was send to the recipent without any problem.
I did "ps -aux |grep mwes" and the result is as below:
root 9219 4.0 0.0 3008 776 pts/1 S+ 23:47 0:00 grep mwes
Below is the mail log at that point of time and it seems alright to me.
mail log
Mar 21 14:10:39 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<nigel@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=29, delays=27/0.84/0.13/1.7, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <nigel@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:39 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<nigeldd@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=29, delays=27/0.84/0.13/1.9, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <nigeldd@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:39 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<ong@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=30, delays=27/0.84/0.13/2.2, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <ong@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:40 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<pang.hueyfan@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=30, delays=27/0.84/0.13/2.5, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <pang.hueyfan@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:40 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<nancyong@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=30, delays=27/0.84/0.13/2.7, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 425BD8322C7)
Mar 21 14:10:40 sg1-mwes01 postfix/cleanup[11486]: 90F6212325: message-id=<20090321061040.90F6212325@sg1-mwes01.kodaltd.com>
Mar 21 14:10:41 sg1-mwes01 postfix/qmgr[6026]: 90F6212325: from=<>, size=6078, nrcpt=1 (queue active)
Mar 21 14:10:41 sg1-mwes01 postfix/bounce[11493]: 42D85122F1: sender non-delivery notification: 90F6212325
Mar 21 14:10:41 sg1-mwes01 postfix/qmgr[6026]: 42D85122F1: removed
Mar 21 14:10:44 sg1-mwes01 postfix/qmgr[6026]: 1780B122F5: from=<respitekc83@healthandwellnesscoaching.com>, size=1752, nrcpt=6 (queue active)
Mar 21 14:10:45 sg1-mwes01 postfix/smtpd[11479]: disconnect from unknown[119.64.119.13]
Mar 21 14:10:46 sg1-mwes01 postfix/smtp[11491]: 90F6212325: to=<fermentstn7@originalfinish.com>, relay=mx10.originalfinish.com[202.65.12.138]:25, delay=6.3, delays=0.63/0.62/2.5/2.6, dsn=5.7.1, status=bounced (host mx10.originalfinish.com[202.65.12.138] said: 554 5.7.1 <fermentstn7@originalfinish.com>: Relay access denied (in reply to RCPT TO command))
Mar 21 14:10:47 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<ucynthia@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=31, delays=28/1.6/0.13/0.41, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <ucynthia@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:47 sg1-mwes01 postfix/qmgr[6026]: 90F6212325: removed
Mar 21 14:10:47 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<wng@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=31, delays=28/1.6/0.13/1.2, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <wng@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<sooni@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<suras.kumar@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<wkteh@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<yonglee@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/cleanup[11470]: 62919122F1: message-id=<20090321061048.62919122F1@sg1-mwes01.kodaltd.com>
Mar 21 14:10:49 sg1-mwes01 postfix/qmgr[6026]: 62919122F1: from=<>, size=4475, nrcpt=1 (queue active)
Mar 21 14:10:49 sg1-mwes01 postfix/bounce[11493]: 1780B122F5: sender non-delivery notification: 62919122F1
Mar 21 14:10:49 sg1-mwes01 postfix/qmgr[6026]: 1780B122F5: removed
Mar 21 14:10:50 sg1-mwes01 postfix/smtp[11491]: 62919122F1: to=<respitekc83@healthandwellnesscoaching.com>, relay=p.nsm.ctmail.com[216.163.188.57]:25, delay=1.9, delays=0.62/0.22/0.53/0.48, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 77A496A124DA3)
Mar 21 14:10:50 sg1-mwes01 postfix/qmgr[6026]: 62919122F1: removed
Mar 21 14:11:04 sg1-mwes01 postfix/smtp[11481]: connect to mail2.siteamerica.com[209.67.50.14]:25: Connection timed out
Mar 21 14:11:04 sg1-mwes01 postfix/smtp[11481]: 13D4D12291: to=<modestestc71@separationmanagement.com>, relay=none, delay=48966, delays=48913/21/32/0, dsn=4.4.1, status=deferred (connect to mail2.siteamerica.com[209.67.50.14]:25: Connection timed out)
Mar 21 14:13:04 sg1-mwes01 postfix/smtpd[11497]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Mar 21 14:13:04 sg1-mwes01 postfix/smtpd[11497]: connect from unknown[unknown]
Mar 21 14:13:05 sg1-mwes01 postfix/smtpd[11497]: warning: milter inet:127.0.0.1:4049: can't read SMFIC_CONNECT reply packet header: Success
Mar 21 14:13:06 sg1-mwes01 postfix/smtpd[11497]: lost connection after CONNECT from unknown[unknown]
Mar 21 14:13:06 sg1-mwes01 postfix/smtpd[11497]: disconnect from unknown[unknown]
Mar 21 14:15:07 sg1-mwes01 postfix/qmgr[6026]: 50D1C121F7: from=<>, size=3869, nrcpt=1 (queue active)
Mar 21 14:15:12 sg1-mwes01 postfix/qmgr[6026]: 4495D12217: from=<>, size=5701, nrcpt=1 (queue active)
Mar 21 14:15:19 sg1-mwes01 postfix/qmgr[6026]: 4DA90121EE: from=<>, size=4859, nrcpt=1 (queue active)
Mar 21 14:15:21 sg1-mwes01 postfix/smtp[11539]: 50D1C121F7: lost connection with q0.netfirms.com[70.42.30.139] while receiving the initial server greeting
Mar 21 14:15:22 sg1-mwes01 postfix/smtp[11539]: 50D1C121F7: lost connection with q0.netfirms.com[70.42.30.11] while receiving the initial server greeting
I did "ps -aux |grep mwes" and the result is as below:
root 9219 4.0 0.0 3008 776 pts/1 S+ 23:47 0:00 grep mwes
Below is the mail log at that point of time and it seems alright to me.
mail log
Mar 21 14:10:39 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<nigel@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=29, delays=27/0.84/0.13/1.7, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <nigel@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:39 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<nigeldd@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=29, delays=27/0.84/0.13/1.9, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <nigeldd@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:39 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<ong@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=30, delays=27/0.84/0.13/2.2, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <ong@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:40 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<pang.hueyfan@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=30, delays=27/0.84/0.13/2.5, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <pang.hueyfan@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:40 sg1-mwes01 postfix/smtp[11485]: 42D85122F1: to=<nancyong@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=30, delays=27/0.84/0.13/2.7, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 425BD8322C7)
Mar 21 14:10:40 sg1-mwes01 postfix/cleanup[11486]: 90F6212325: message-id=<20090321061040.90F6212325@sg1-mwes01.kodaltd.com>
Mar 21 14:10:41 sg1-mwes01 postfix/qmgr[6026]: 90F6212325: from=<>, size=6078, nrcpt=1 (queue active)
Mar 21 14:10:41 sg1-mwes01 postfix/bounce[11493]: 42D85122F1: sender non-delivery notification: 90F6212325
Mar 21 14:10:41 sg1-mwes01 postfix/qmgr[6026]: 42D85122F1: removed
Mar 21 14:10:44 sg1-mwes01 postfix/qmgr[6026]: 1780B122F5: from=<respitekc83@healthandwellnesscoaching.com>, size=1752, nrcpt=6 (queue active)
Mar 21 14:10:45 sg1-mwes01 postfix/smtpd[11479]: disconnect from unknown[119.64.119.13]
Mar 21 14:10:46 sg1-mwes01 postfix/smtp[11491]: 90F6212325: to=<fermentstn7@originalfinish.com>, relay=mx10.originalfinish.com[202.65.12.138]:25, delay=6.3, delays=0.63/0.62/2.5/2.6, dsn=5.7.1, status=bounced (host mx10.originalfinish.com[202.65.12.138] said: 554 5.7.1 <fermentstn7@originalfinish.com>: Relay access denied (in reply to RCPT TO command))
Mar 21 14:10:47 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<ucynthia@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=31, delays=28/1.6/0.13/0.41, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <ucynthia@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:47 sg1-mwes01 postfix/qmgr[6026]: 90F6212325: removed
Mar 21 14:10:47 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<wng@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=31, delays=28/1.6/0.13/1.2, dsn=5.1.1, status=bounced (host 202.42.148.86[202.42.148.86] said: 550 5.1.1 <wng@kodaltd.com>: Recipient address rejected: User unknown in virtual mailbox table (in reply to RCPT TO command))
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<sooni@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<suras.kumar@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<wkteh@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/smtp[11485]: 1780B122F5: to=<yonglee@kodaltd.com>, relay=202.42.148.86[202.42.148.86]:25, delay=32, delays=28/1.6/0.13/1.4, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as D7C9B8322C7)
Mar 21 14:10:48 sg1-mwes01 postfix/cleanup[11470]: 62919122F1: message-id=<20090321061048.62919122F1@sg1-mwes01.kodaltd.com>
Mar 21 14:10:49 sg1-mwes01 postfix/qmgr[6026]: 62919122F1: from=<>, size=4475, nrcpt=1 (queue active)
Mar 21 14:10:49 sg1-mwes01 postfix/bounce[11493]: 1780B122F5: sender non-delivery notification: 62919122F1
Mar 21 14:10:49 sg1-mwes01 postfix/qmgr[6026]: 1780B122F5: removed
Mar 21 14:10:50 sg1-mwes01 postfix/smtp[11491]: 62919122F1: to=<respitekc83@healthandwellnesscoaching.com>, relay=p.nsm.ctmail.com[216.163.188.57]:25, delay=1.9, delays=0.62/0.22/0.53/0.48, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 77A496A124DA3)
Mar 21 14:10:50 sg1-mwes01 postfix/qmgr[6026]: 62919122F1: removed
Mar 21 14:11:04 sg1-mwes01 postfix/smtp[11481]: connect to mail2.siteamerica.com[209.67.50.14]:25: Connection timed out
Mar 21 14:11:04 sg1-mwes01 postfix/smtp[11481]: 13D4D12291: to=<modestestc71@separationmanagement.com>, relay=none, delay=48966, delays=48913/21/32/0, dsn=4.4.1, status=deferred (connect to mail2.siteamerica.com[209.67.50.14]:25: Connection timed out)
Mar 21 14:13:04 sg1-mwes01 postfix/smtpd[11497]: warning: dict_nis_init: NIS domain name not set - NIS lookups disabled
Mar 21 14:13:04 sg1-mwes01 postfix/smtpd[11497]: connect from unknown[unknown]
Mar 21 14:13:05 sg1-mwes01 postfix/smtpd[11497]: warning: milter inet:127.0.0.1:4049: can't read SMFIC_CONNECT reply packet header: Success
Mar 21 14:13:06 sg1-mwes01 postfix/smtpd[11497]: lost connection after CONNECT from unknown[unknown]
Mar 21 14:13:06 sg1-mwes01 postfix/smtpd[11497]: disconnect from unknown[unknown]
Mar 21 14:15:07 sg1-mwes01 postfix/qmgr[6026]: 50D1C121F7: from=<>, size=3869, nrcpt=1 (queue active)
Mar 21 14:15:12 sg1-mwes01 postfix/qmgr[6026]: 4495D12217: from=<>, size=5701, nrcpt=1 (queue active)
Mar 21 14:15:19 sg1-mwes01 postfix/qmgr[6026]: 4DA90121EE: from=<>, size=4859, nrcpt=1 (queue active)
Mar 21 14:15:21 sg1-mwes01 postfix/smtp[11539]: 50D1C121F7: lost connection with q0.netfirms.com[70.42.30.139] while receiving the initial server greeting
Mar 21 14:15:22 sg1-mwes01 postfix/smtp[11539]: 50D1C121F7: lost connection with q0.netfirms.com[70.42.30.11] while receiving the initial server greeting
- ajt
- would rather be watching cricket
- Contact:
- Location: Auckland, New Zealand
Post
Re: Mailwasher Entreprise with postfix
Could you enable mwes logging in debug mode and send its logs? Change log_level=1 in /etc/mwes.conf and restart mwes!
In mwes log you posted:
2009-03-21 14:10:44 [3066911632] Info: Processed = 347 - 3, Emails(ok) = 51 - 2, FA = 175 - 0, RBL = 121 - 2, Black listed = 0 - 0, Custom filter = 0 - 0, FA(IP) = 0 - 0, Empty Email Body = 0 - 0, Uploaded = 121 - 2,
Following entry shows mwes starting again. Is this when you manually start mwes after seeing it hanged up?
2009-03-21 20:11:05 [3084130624] Info: starting mwes version 2.6.3 {U}
Cheers
In mwes log you posted:
2009-03-21 14:10:44 [3066911632] Info: Processed = 347 - 3, Emails(ok) = 51 - 2, FA = 175 - 0, RBL = 121 - 2, Black listed = 0 - 0, Custom filter = 0 - 0, FA(IP) = 0 - 0, Empty Email Body = 0 - 0, Uploaded = 121 - 2,
Following entry shows mwes starting again. Is this when you manually start mwes after seeing it hanged up?
2009-03-21 20:11:05 [3084130624] Info: starting mwes version 2.6.3 {U}
Cheers
- chquek
- Student Sheep
Post
Re: Mailwasher Entreprise with postfix
Hi,
Yes I did a restart previously.
Below is the mwes.log after switching it to debug mode. Pls note that I only copied the initial start of Mailwasher and before stopped as it is a very long list.
Let know if it will be sufficient.
2009-03-25 00:16:28 [3083471168] Info: starting mwes version 2.6.3 {U}
2009-03-25 00:16:28 [3083471168] Info: environment....
2009-03-25 00:16:28 [3083471168] Info: database_location::/opt/mwes
2009-03-25 00:16:28 [3083471168] Info: listen_port::4044
2009-03-25 00:16:28 [3083471168] Info: log_level::1
2009-03-25 00:16:28 [3083471168] Info: logging::/var/log/mwes/
2009-03-25 00:16:28 [3083471168] Info: milter_port::inet:4049@127.0.0.1
2009-03-25 00:16:28 [3083471168] Info: root_document::/opt/mwes/mwes/
2009-03-25 00:16:28 [3083471168] Info: Initialising WebManager....
2009-03-25 00:16:29 [3083471168] Info: Initialising database....
2009-03-25 00:16:29 [3083471168] Info: Initialising database configure table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database white listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database black listing table....
2009-03-25 00:16:29 [3083471168] Info: Not written... Initialising database filter white listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database filter black listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database rbl listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database quarantined table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database gray listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database white listing ip table....
2009-03-25 00:16:29 [3083471168] Info: DatabaseManager::UpgradeDatabase - version 8 ok
2009-03-25 00:16:29 [3083471168] Info: Starting StatThread....
2009-03-25 00:16:29 [3083471168] Info: Starting FilterManagerThreads....
2009-03-25 00:16:29 [3083471168] Info: Starting UploadManagerThread....
2009-03-25 00:16:29 [3083471168] Info: Starting ExchangeConduitThread....
2009-03-25 00:16:29 [3083471168] Info: Starting MilterConduitThread....
2009-03-25 00:16:29 [3083471168] Info: Starting HouseKeepingTask....
2009-03-25 00:18:03 [3066682256] Info: Processed = 1 - 1, Emails(ok) = 0 - 0, FA = 0 - 0, RBL = 0 - 0, Black listed = 0 - 0, Custom filter = 0 - 0, FA(IP) = 0 - 0, Empty Email Body = 0 - 0, Uploaded = 0 - 0,
2009-03-25 00:18:03 [3007933328] Debug: Start Processing Email ID(1)...
2009-03-25 00:18:03 [3007933328] Debug: Successfully added email ID (1) to FilterManagerThread Queue...
2009-03-25 00:18:06 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 00:18:06 [3058289552] Debug: Email ID (1) Not found in CFS...
2009-03-25 00:18:06 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 00:18:07 [3007933328] Debug: Email ID (1) Known as SPAM in RBL(zen.spamhaus.org) IP[190.135.61.133]...
2009-03-25 00:18:07 [3007933328] Debug: added (1) RBL IP(190.135.61.133) to cache...
2009-03-25 00:18:07 [3007933328] Debug: Email ID (1) (found in RBL)...
2009-03-25 00:18:07 [3007933328] Debug: RBL [190.135.61.133,r190-135-61-133.dialup.adsl.anteldata.net.uy,<tourniquetse968@sexcrimereporting.com>, <sooni@kodaltd.com>]
2009-03-25 00:18:07 [3007933328] Debug: QuarantinedTable Email ID (1) added to database...
2009-03-25 00:18:07 [3007933328] Debug: QuarantinedTable Email ID (1) added to cache...
2009-03-25 00:18:07 [3007933328] Debug: End Processing Email ID(1) DISCARD...
2009-03-25 00:18:09 [3049896848] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 00:18:10 [3049896848] Debug: Email ID (1) Uploaded
2009-03-25 00:18:10 [3049896848] Debug: Successfully disconnected from CFS...
Skipped to the time before it stopped:
2009-03-25 01:43:31 [2997877648] Debug: Start Processing Email ID(115)...
2009-03-25 01:43:31 [2997877648] Debug: Successfully added email ID (115) to FilterManagerThread Queue...
2009-03-25 01:43:33 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:43:34 [3058289552] Debug: Email ID (115) Known as SPAM in CFS...
2009-03-25 01:43:34 [3058289552] Debug: Email ID (115) added to cache...
2009-03-25 01:43:34 [3058289552] Debug: added Email ID(115) (52) FA IP(201.95.14.217) to cache...
2009-03-25 01:43:34 [2997877648] Debug: FA [201.95.14.217,201-95-14-217.dsl.telesp.net.br,<shinobut@freshdrop.net>, <wkteh@kodaltd.com>]
2009-03-25 01:43:34 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 01:43:34 [2997877648] Debug: QuarantinedTable Email ID (115) added to database...
2009-03-25 01:43:34 [2997877648] Debug: QuarantinedTable Email ID (115) added to cache...
2009-03-25 01:43:34 [2997877648] Debug: End Processing Email ID(115) DISCARD...
2009-03-25 01:43:48 [2997877648] Debug: Start Processing Email ID(116)...
2009-03-25 01:43:48 [2997877648] Debug: Successfully added email ID (116) to FilterManagerThread Queue...
2009-03-25 01:43:50 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:43:51 [3058289552] Debug: Email ID (116) Not found in CFS...
2009-03-25 01:43:51 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 01:43:51 [2997877648] Debug: Email ID (116) Known as SPAM in RBL(zen.spamhaus.org) IP[78.96.118.28]...
2009-03-25 01:43:51 [2997877648] Debug: added (25) RBL IP(78.96.118.28) to cache...
2009-03-25 01:43:51 [2997877648] Debug: Email ID (116) (found in RBL)...
2009-03-25 01:43:51 [2997877648] Debug: RBL [78.96.118.28,xxx-392630e019d,<kefwyowildlifediz@wyowildlife.com>, <koda.malaysia@kodaltd.com> <koda@kodaltd.com>]
2009-03-25 01:43:51 [2997877648] Debug: QuarantinedTable Email ID (116) added to database...
2009-03-25 01:43:51 [2997877648] Debug: QuarantinedTable Email ID (116) added to cache...
2009-03-25 01:43:51 [2997877648] Debug: End Processing Email ID(116) DISCARD...
2009-03-25 01:43:53 [3049896848] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:43:54 [3049896848] Debug: Email ID (116) Uploaded
2009-03-25 01:43:54 [3049896848] Debug: Successfully disconnected from CFS...
2009-03-25 01:45:37 [3066682256] Info: Processed = 117 - 2, Emails(ok) = 5 - 0, FA = 86 - 1, RBL = 25 - 1, Black listed = 0 - 0, Custom filter = 0 - 0, FA(IP) = 0 - 0, Empty Email Body = 0 - 0, Uploaded = 25 - 1,
2009-03-25 01:45:37 [2997877648] Debug: Start Processing Email ID(117)...
2009-03-25 01:45:37 [2997877648] Debug: Successfully added email ID (117) to FilterManagerThread Queue...
2009-03-25 01:45:40 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:45:40 [3058289552] Debug: Email ID (117) Not found in CFS...
2009-03-25 01:45:40 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 01:45:41 [2997877648] Debug: Email ID (117) Known as SPAM in RBL(zen.spamhaus.org) IP[83.131.223.142]...
2009-03-25 01:45:41 [2997877648] Debug: added (26) RBL IP(83.131.223.142) to cache...
2009-03-25 01:45:41 [2997877648] Debug: Email ID (117) (found in RBL)...
2009-03-25 01:45:41 [2997877648] Debug: RBL [83.131.223.142,83-131-223-142.adsl.net.t-com.hr,<ghwjbotsecg@brandbox.com>, <nelsoh@kodaltd.com>]
2009-03-25 01:45:41 [2997877648] Debug: QuarantinedTable Email ID (117) added to database...
2009-03-25 01:45:41 [2997877648] Debug: QuarantinedTable Email ID (117) added to cache...
2009-03-25 01:45:41 [2997877648] Debug: End Processing Email ID(117) DISCARD...
Yes I did a restart previously.
Below is the mwes.log after switching it to debug mode. Pls note that I only copied the initial start of Mailwasher and before stopped as it is a very long list.
Let know if it will be sufficient.
2009-03-25 00:16:28 [3083471168] Info: starting mwes version 2.6.3 {U}
2009-03-25 00:16:28 [3083471168] Info: environment....
2009-03-25 00:16:28 [3083471168] Info: database_location::/opt/mwes
2009-03-25 00:16:28 [3083471168] Info: listen_port::4044
2009-03-25 00:16:28 [3083471168] Info: log_level::1
2009-03-25 00:16:28 [3083471168] Info: logging::/var/log/mwes/
2009-03-25 00:16:28 [3083471168] Info: milter_port::inet:4049@127.0.0.1
2009-03-25 00:16:28 [3083471168] Info: root_document::/opt/mwes/mwes/
2009-03-25 00:16:28 [3083471168] Info: Initialising WebManager....
2009-03-25 00:16:29 [3083471168] Info: Initialising database....
2009-03-25 00:16:29 [3083471168] Info: Initialising database configure table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database white listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database black listing table....
2009-03-25 00:16:29 [3083471168] Info: Not written... Initialising database filter white listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database filter black listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database rbl listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database quarantined table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database gray listing table....
2009-03-25 00:16:29 [3083471168] Info: Initialising database white listing ip table....
2009-03-25 00:16:29 [3083471168] Info: DatabaseManager::UpgradeDatabase - version 8 ok
2009-03-25 00:16:29 [3083471168] Info: Starting StatThread....
2009-03-25 00:16:29 [3083471168] Info: Starting FilterManagerThreads....
2009-03-25 00:16:29 [3083471168] Info: Starting UploadManagerThread....
2009-03-25 00:16:29 [3083471168] Info: Starting ExchangeConduitThread....
2009-03-25 00:16:29 [3083471168] Info: Starting MilterConduitThread....
2009-03-25 00:16:29 [3083471168] Info: Starting HouseKeepingTask....
2009-03-25 00:18:03 [3066682256] Info: Processed = 1 - 1, Emails(ok) = 0 - 0, FA = 0 - 0, RBL = 0 - 0, Black listed = 0 - 0, Custom filter = 0 - 0, FA(IP) = 0 - 0, Empty Email Body = 0 - 0, Uploaded = 0 - 0,
2009-03-25 00:18:03 [3007933328] Debug: Start Processing Email ID(1)...
2009-03-25 00:18:03 [3007933328] Debug: Successfully added email ID (1) to FilterManagerThread Queue...
2009-03-25 00:18:06 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 00:18:06 [3058289552] Debug: Email ID (1) Not found in CFS...
2009-03-25 00:18:06 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 00:18:07 [3007933328] Debug: Email ID (1) Known as SPAM in RBL(zen.spamhaus.org) IP[190.135.61.133]...
2009-03-25 00:18:07 [3007933328] Debug: added (1) RBL IP(190.135.61.133) to cache...
2009-03-25 00:18:07 [3007933328] Debug: Email ID (1) (found in RBL)...
2009-03-25 00:18:07 [3007933328] Debug: RBL [190.135.61.133,r190-135-61-133.dialup.adsl.anteldata.net.uy,<tourniquetse968@sexcrimereporting.com>, <sooni@kodaltd.com>]
2009-03-25 00:18:07 [3007933328] Debug: QuarantinedTable Email ID (1) added to database...
2009-03-25 00:18:07 [3007933328] Debug: QuarantinedTable Email ID (1) added to cache...
2009-03-25 00:18:07 [3007933328] Debug: End Processing Email ID(1) DISCARD...
2009-03-25 00:18:09 [3049896848] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 00:18:10 [3049896848] Debug: Email ID (1) Uploaded
2009-03-25 00:18:10 [3049896848] Debug: Successfully disconnected from CFS...
Skipped to the time before it stopped:
2009-03-25 01:43:31 [2997877648] Debug: Start Processing Email ID(115)...
2009-03-25 01:43:31 [2997877648] Debug: Successfully added email ID (115) to FilterManagerThread Queue...
2009-03-25 01:43:33 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:43:34 [3058289552] Debug: Email ID (115) Known as SPAM in CFS...
2009-03-25 01:43:34 [3058289552] Debug: Email ID (115) added to cache...
2009-03-25 01:43:34 [3058289552] Debug: added Email ID(115) (52) FA IP(201.95.14.217) to cache...
2009-03-25 01:43:34 [2997877648] Debug: FA [201.95.14.217,201-95-14-217.dsl.telesp.net.br,<shinobut@freshdrop.net>, <wkteh@kodaltd.com>]
2009-03-25 01:43:34 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 01:43:34 [2997877648] Debug: QuarantinedTable Email ID (115) added to database...
2009-03-25 01:43:34 [2997877648] Debug: QuarantinedTable Email ID (115) added to cache...
2009-03-25 01:43:34 [2997877648] Debug: End Processing Email ID(115) DISCARD...
2009-03-25 01:43:48 [2997877648] Debug: Start Processing Email ID(116)...
2009-03-25 01:43:48 [2997877648] Debug: Successfully added email ID (116) to FilterManagerThread Queue...
2009-03-25 01:43:50 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:43:51 [3058289552] Debug: Email ID (116) Not found in CFS...
2009-03-25 01:43:51 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 01:43:51 [2997877648] Debug: Email ID (116) Known as SPAM in RBL(zen.spamhaus.org) IP[78.96.118.28]...
2009-03-25 01:43:51 [2997877648] Debug: added (25) RBL IP(78.96.118.28) to cache...
2009-03-25 01:43:51 [2997877648] Debug: Email ID (116) (found in RBL)...
2009-03-25 01:43:51 [2997877648] Debug: RBL [78.96.118.28,xxx-392630e019d,<kefwyowildlifediz@wyowildlife.com>, <koda.malaysia@kodaltd.com> <koda@kodaltd.com>]
2009-03-25 01:43:51 [2997877648] Debug: QuarantinedTable Email ID (116) added to database...
2009-03-25 01:43:51 [2997877648] Debug: QuarantinedTable Email ID (116) added to cache...
2009-03-25 01:43:51 [2997877648] Debug: End Processing Email ID(116) DISCARD...
2009-03-25 01:43:53 [3049896848] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:43:54 [3049896848] Debug: Email ID (116) Uploaded
2009-03-25 01:43:54 [3049896848] Debug: Successfully disconnected from CFS...
2009-03-25 01:45:37 [3066682256] Info: Processed = 117 - 2, Emails(ok) = 5 - 0, FA = 86 - 1, RBL = 25 - 1, Black listed = 0 - 0, Custom filter = 0 - 0, FA(IP) = 0 - 0, Empty Email Body = 0 - 0, Uploaded = 25 - 1,
2009-03-25 01:45:37 [2997877648] Debug: Start Processing Email ID(117)...
2009-03-25 01:45:37 [2997877648] Debug: Successfully added email ID (117) to FilterManagerThread Queue...
2009-03-25 01:45:40 [3058289552] Debug: Successfully Connected to CFS on URL (native.first-alert.net)...
2009-03-25 01:45:40 [3058289552] Debug: Email ID (117) Not found in CFS...
2009-03-25 01:45:40 [3058289552] Debug: Successfully disconnected from CFS...
2009-03-25 01:45:41 [2997877648] Debug: Email ID (117) Known as SPAM in RBL(zen.spamhaus.org) IP[83.131.223.142]...
2009-03-25 01:45:41 [2997877648] Debug: added (26) RBL IP(83.131.223.142) to cache...
2009-03-25 01:45:41 [2997877648] Debug: Email ID (117) (found in RBL)...
2009-03-25 01:45:41 [2997877648] Debug: RBL [83.131.223.142,83-131-223-142.adsl.net.t-com.hr,<ghwjbotsecg@brandbox.com>, <nelsoh@kodaltd.com>]
2009-03-25 01:45:41 [2997877648] Debug: QuarantinedTable Email ID (117) added to database...
2009-03-25 01:45:41 [2997877648] Debug: QuarantinedTable Email ID (117) added to cache...
2009-03-25 01:45:41 [2997877648] Debug: End Processing Email ID(117) DISCARD...
- ajt
- would rather be watching cricket
- Contact:
- Location: Auckland, New Zealand
Post
Re: Mailwasher Entreprise with postfix
We need more information to diagnose this issue . Could you tar or zip mail.log & mwes.log files and send it to ali@firetrust.com
Kindly cross check if you are running any cronjob or backup script which may disrupt postfix or mwes processes. What are the specs of your box.
Mwes 2.63 running on Ubuntu 8.0.4.2 LTS with Postfix 2.5.1 + Box has 64 Bit processor+512 MB RAM and it is handling 300000 mails/24 hours.
Kindly cross check if you are running any cronjob or backup script which may disrupt postfix or mwes processes. What are the specs of your box.
Mwes 2.63 running on Ubuntu 8.0.4.2 LTS with Postfix 2.5.1 + Box has 64 Bit processor+512 MB RAM and it is handling 300000 mails/24 hours.
- chquek
- Student Sheep
Post
Re: Mailwasher Entreprise with postfix
Hi,
Sorry for the delay.
I have just sent you the log file for both the mail and mwes.
Currently I only have the follow items in the cron.daily:
apt aptitude bsdmainutils dspam find logrotate man-db ntpdate standard sysklogd
Is MWES related to dspam?
I am running this in a VM which has 1 Duo-Core Intel Pentium D 3.00GHz and 2 GB of memory. At the moment I only have 2 VMs running and should not be resource intensive.
Sorry for the delay.
I have just sent you the log file for both the mail and mwes.
Currently I only have the follow items in the cron.daily:
apt aptitude bsdmainutils dspam find logrotate man-db ntpdate standard sysklogd
Is MWES related to dspam?
I am running this in a VM which has 1 Duo-Core Intel Pentium D 3.00GHz and 2 GB of memory. At the moment I only have 2 VMs running and should not be resource intensive.
- chquek
- Student Sheep
Post
Re: Mailwasher Entreprise with postfix
My apology. I was looking at the wrong server.
What I have in the cron.daily are as follow:
apt aptitude bsdmainutils logrotate man-db mlocate ntp standard sysklogd
What I have done now is that I created a cron job which will start mwesd every hourly. (Keepin my fingers cross)
What I have in the cron.daily are as follow:
apt aptitude bsdmainutils logrotate man-db mlocate ntp standard sysklogd
What I have done now is that I created a cron job which will start mwesd every hourly. (Keepin my fingers cross)
- nick.bolton
- The Big Cheese
Post
Re: Mailwasher Entreprise with postfix
In the config file can you please add the following
Linux: /etc/mwes.conf
log_level=1
cfs_max_cache_size=1000
rbl_max_cache_size=1000
use_quarantine_cache=0
This seems to have fixed a similar problem with another user.
Linux: /etc/mwes.conf
log_level=1
cfs_max_cache_size=1000
rbl_max_cache_size=1000
use_quarantine_cache=0
This seems to have fixed a similar problem with another user.
- chquek
- Student Sheep
Post
Re: Mailwasher Entreprise with postfix
So far so good, mwes is still running.
Seems good. I will continue to monitor.
Thanks for your help.
Seems good. I will continue to monitor.
Thanks for your help.
- chquek
- Student Sheep
Post
Re: Mailwasher Entreprise with postfix
mwes stopped again after approximately 6 hours.
Will it helps if I increase both max cache to maybe 4000 help? Any impact to the system if i do that?
Will it helps if I increase both max cache to maybe 4000 help? Any impact to the system if i do that?
- nick.bolton
- The Big Cheese
Post
Re: Mailwasher Entreprise with postfix
Should be fine, the default before this was much higher. If you want to wait, then i'll get the definitive answer from the developers in about 4 hours (not at work yet)
- nick.bolton
- The Big Cheese
Post
Re: Mailwasher Entreprise with postfix
Can you please send me your logs to nick.bolton*firetrust.com (replacing * with @)
The changed logging level we set should give us more information about what went wrong. Developers said not to worry about increasing the cache size
Logs in
/var/logs/mwes
Thanks
The changed logging level we set should give us more information about what went wrong. Developers said not to worry about increasing the cache size
Logs in
/var/logs/mwes
Thanks
- nick.bolton
- The Big Cheese
Post
Re: Mailwasher Entreprise with postfix
We've got a new update here which hopefully fixes the problem (and increases the amount of logging). Can you please try it
http://s3.amazonaws.com/Firetrust/mwes/mwes-264.tar.gz
Thanks
http://s3.amazonaws.com/Firetrust/mwes/mwes-264.tar.gz
Thanks