Bounces not being detected
Hi AllI have mailman-2.1.17 running on FreeBSD 9.1 along with postfix-2.11.0,1 I noticed that bad email addresses were not being cleared out so I downloaded get_bounce_info.py,saved it and ran it. No bounce info was displayed.I checked the postfix logs and the bounce info was there. A bit from the logs is below: status=bounced (host bla bla .com[x.x.x.x] said: 550 5.7.1 No mailbox found (in reply to RCPT TO command)) Shouldn't mailman detect these bounces? Does mailman detect from the smtp logs or some other method? Thanks for any help received.
On 06/20/2014 06:03 PM, Peter Fraser wrote:
Hi AllI have mailman-2.1.17 running on FreeBSD 9.1 along with postfix-2.11.0,1 I noticed that bad email addresses were not being cleared out so I downloaded get_bounce_info.py,saved it and ran it. No bounce info was displayed.I checked the postfix logs and the bounce info was there. A bit from the logs is below: status=bounced (host bla bla .com[x.x.x.x] said: 550 5.7.1 No mailbox found (in reply to RCPT TO command)) Shouldn't mailman detect these bounces?
Yes.
Does mailman detect from the smtp logs or some other method?
Bounces are detected in two ways. The bounce you refer to above may, depending on the Postfix configuration, result in a failed recipient with a "550" status being reported during the SMTP transaction between Mailman and Postfix. This should be logged in Mailman's smtp-failure log, queued as a bounce, processed by BounceRunner, scored and logged in Mailman's bounce log.
Alternatively, Postfix won't detect the problem during SMTP with Mailman and later, either (in this case) the local Postfix or some downstream MTA will return a failure DSN to the envelope sender which may be LISTNAME-bounces@your.domain or in the case of VERP, LISTNAME-bounces+user=example.com@your.domain. This DSN should be received by Mailman, processed by BounceRunner, recognized, scored and logged in Mailman's bounce log.
So first questions, is BounceRunner running? Is there anything in Mailman's qfiles/bounce/ queue or any bounce-events-*.pck files in Mailman's data/ directory?
Next, the above partial Postfix log message should also contain a queue ID and be followed by another log message of the form
postfix/bounce[pppp]: msg_queue_id: sender non-delivery notification: dsn_queue_id.
with the same msg_queue_id as that of the status=bounced log message.
What do the logs say about the DSN with queue ID dsn_queue_id?
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
I checked the data directory and saw some *.pck files Their names were along the lines of "heldmsg-<list_name>-727.pck"so I guess then bouncerunner should be running. All the .pck files have heldmsg in the name.
The way our setup is designed though, the mailman box isn't the mail smtp relay. It sits behind the firewall and just sends out. So I'm thinking that if a downstream box later bounced the messages, that wouldn't hit the mailman box, but would hit the main smtp relay and back to the exchange server box. I looked then at the logs of the main smtp relay and did see some bounces with dsn id's I'm hoping though that the bounces detected during the smtp transaction should be detected by postfix and then mailman.Maybe that accounts for those few .pck files? Not sure.
On 06/21/2014 11:00 AM, Peter Fraser wrote:
I checked the data directory and saw some *.pck files Their names were along the lines of "heldmsg-<list_name>-727.pck"so I guess then bouncerunner should be running. All the .pck files have heldmsg in the name.
These are all messages held waiting moderator action.
The way our setup is designed though, the mailman box isn't the mail smtp relay.
What Postfix logged the message you reported earlier?
It sits behind the firewall and just sends out. So I'm thinking that if a downstream box later bounced the messages, that wouldn't hit the mailman box, but would hit the main smtp relay and back to the exchange server box. I looked then at the logs of the main smtp relay and did see some bounces with dsn id's I'm hoping though that the bounces detected during the smtp transaction should be detected by postfix and then mailman.Maybe that accounts for those few .pck files? Not sure.
Downstream bounces should always be reported via DSN sent back to the envelope sender of the original message which is LISTNAME-bounces@list.domain or in the VERP case, LISTNAME-bounces+bouncing_user=users.domain@list.domain. These should get back to Mailman.
In general, some SMTP server gets a 5xx status from the next hop. That server sends a failure DSN back to the envelope sender. That DSN should get back to Mailman and be processed.
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
The message I showed earlier was the postfix on the same box as mailman. Mailman should detect those bounces. I was just thinking based on what you said about some smtp servers getting the 5xx status from downstream servers thatthose errors would not reach mailman the way things are set up here. I hadn't considered that.
So do those .pck files mean the bouncerunner is working?
On 06/21/2014 01:24 PM, Peter Fraser wrote:
The message I showed earlier was the postfix on the same box as mailman. Mailman should detect those bounces.
And what did that log show for the sender non-delivery notification message generated as a result of the undeliverable message.
And was there anything in Mailman's bounce log?
And is there anything in Mailman's qfiles/bounce/ directory?
I was just thinking based on what you said about some smtp servers getting the 5xx status from downstream servers thatthose errors would not reach mailman the way things are set up here. I hadn't considered that.
If list posts from outside your local network reach Mailman, then bounces should too unless you have delivery to Mailman set up in some way such that messages to LISTNAME@your.domain are delivered, but messages to the other 9 LISTNAME-*@your.domain addresses are not. The 9 values of * are admin, bounces, confirm, join, leave, owner, request, subscribe and unsubscribe, and all those addresses except 'admin' which is a deprecated synonym for 'bounces' must be deliverable to Mailman for Mailman to work as documented.
So do those .pck files mean the bouncerunner is working?
No. Each heldmsg-LISTNAME-nnnn.pck file is a message to the LISTNAME list waiting moderator action. They should all be visible in the admindb web UI for LISTNAME. They have nothing to do with bounces.
To see if BounceRunner is running, do
ps -fAw | grep BounceRunner
If that shows nothing other than the 'grep', BounceRunner is not running. More information may be available in Mailman's qrunner log and possibly Mailman's error log.
Also, in that case, you may see that there are queued bounces in Mailman's qfiles/bounce/ directory.
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Peter Fraser writes:
The message I showed earlier was the postfix on the same box as mailman. Mailman should detect those bounces. I was just thinking based on what you said about some smtp servers getting the 5xx status from downstream servers thatthose errors would not reach mailman the way things are set up here. I hadn't considered that.
So do those .pck files mean the bouncerunner is working?
No. The presence of .pck files means (a) some runner is behind in its work but will eventually get to them, (b) some runner is waiting for human intervention (moderations), or (c) some runner isn't running. Depending on the name and the directory where found, they correspond to different runners.
To find out if the bounce runner is running you use ps from the command line on the Mailman host. On Linux, the command
ps ax | grep BounceRunnerwill find it. If that command produces output, it's running (actually you need to check the status in the third column, if it's S or R the process is normal, if it's Z or T something bad has happened).
Wait a minute, I typed this command by force of habit, just realized that's not what you told me to type so I ran it again ps -ax | grep BounceRunner and the result is: 8138 ?? S 0:00.26 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=BounceRunner:0:1 -s
On 06/21/2014 07:23 PM, Peter Fraser wrote:
Wait a minute, I typed this command by force of habit, just realized that's not what you told me to type so I ran it again ps -ax | grep BounceRunner and the result is: 8138 ?? S 0:00.26 /usr/local/bin/python2.7 /usr/local/mailman/bin/qrunner --runner=BounceRunner:0:1 -s
So BounceRunner is running.
So, as I asked before:
On 06/21/2014 01:24 PM, Peter Fraser wrote:
The message I showed earlier was the postfix on the same box as mailman. Mailman should detect those bounces.
And what did that log show for the sender non-delivery notification message generated as a result of the undeliverable message.
And was there anything in Mailman's bounce log?
And if it appeared the message was delivered to Mailman, was there anything in Mailman's error log from the time of the delivery?
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
And what did that log show for the sender non-delivery notification message generated as a result of the undeliverable message. I looked at the postfix logs again and although I do see different type of bounces, I am not seeing anything delivered to mailman. Here are some examples: Jun 20 04:11:30 poseidon postfix/qmgr[95432]: B7E0A3AC890: from=<Listname@domain.com>, size=585098, nrcpt=500 (queue active) Jun 20 04:11:31 poseidon postfix/qmgr[95432]: B52323AC87E: from=<list name@domain.com>, status=expired, returned to sender Here's one where it seems to send the bounced message back to ExchangeJun 20 04:11:31 poseidon postfix/smtp[1539]: 35F9D3AC8A5: to=<listname@domain.com>, relay=hubtransport.domain.com[192.168.0.165]:25, delay=0.22, delays=0.08/0.04/0.01/0.1, dsn=2.6.0, status=sent (250 2.6.0 <20140620091131.35F9D3AC8A5@mail1.domain.com> Queued mail for delivery)
And was there anything in Mailman's bounce log? I looked in /usr/local/mailman/logs and only saw these files:root@poseidon:/usr/local/mailman/logs # lserror post qrunner smtp smtp-failure subscribe vette I didn't see any for bounces. The last entry in smtp-failure was for last year. smtp had nothing about bounces. And if it appeared the message was delivered to Mailman, was there anything in Mailman's error log from the time of the delivery?
No, I didn't even see anything in the error log for June 20 to correspond with the postfix log time and date. The last log entry in errorbefore that was in February.
On 06/21/2014 08:43 PM, Peter Fraser wrote:
And what did that log show for the sender non-delivery notification message generated as a result of the undeliverable message. I looked at the postfix logs again and although I do see different type of bounces, I am not seeing anything delivered to mailman. Here are some examples: Jun 20 04:11:30 poseidon postfix/qmgr[95432]: B7E0A3AC890: from=<Listname@domain.com>, size=585098, nrcpt=500 (queue active) Jun 20 04:11:31 poseidon postfix/qmgr[95432]: B52323AC87E: from=<list name@domain.com>, status=expired, returned to sender
First of all, these should be from=<listname-bounces@domain.com>, not from=<listname@domain.com>. If your posts are really being sent with envelope from <listname@domain.com>, that means bounces will be returned as list posts, not as bounces.
But, I'm still not seeing what I need to see. Taking the last above message as an example, do
grep B52323AC87E /var/log/maillog
or whatever the log file is. In the last few lines, you should see one that says
...postfix/bounce[...]: B52323AC87E sender non-delivery notification: xxxx
where xxx is another Postfix queue ID for the bounce DSN. Then grep the log for that Queue ID, and what do you see?
Here's one where it seems to send the bounced message back to ExchangeJun 20 04:11:31 poseidon postfix/smtp[1539]: 35F9D3AC8A5: to=<listname@domain.com>, relay=hubtransport.domain.com[192.168.0.165]:25, delay=0.22, delays=0.08/0.04/0.01/0.1, dsn=2.6.0, status=sent (250 2.6.0 <20140620091131.35F9D3AC8A5@mail1.domain.com> Queued mail for delivery)
If this is actually a report on one of those DSNs, it should be going to=<listname-bounces@domain.com>, not to=<listname@domain.com>. If the envelope from of your outgoing posts is really <listname@domain.com> and not <listname-bounces@domain.com>, that would explain why bounces are being processed and it might explain what the heldmsg files are (i.e. bounces returned to the list and being held as non-member posts).
It this is what's happening, something is rewriting the envelope sender. What, I have no idea.
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
Ok I went scouring through the logs trying to trace a particular message like you suggested and I did find some like this:
Here's one message I tracked.214CA3AC88D: from=<listname-bounces@domain.com>, size=585098, nrcpt=500 (queue active) then214CA3AC88D: to=<name@otherdomain.com>, relay=none, delay=32256, delays=32255/0.05/0.15/0, dsn=4.4.1, status=deferred (connect to mail1.otherdomain.com[x.x.x.x]:25: Connection refused then214CA3AC88D: from=<listname-bounces@domain.com>, size=585098, nrcpt=500 (queue active) then214CA3AC88D: sender non-delivery notification: 35F9D3AC8A5 then35F9D3AC8A5: from=<>, size=3771, nrcpt=1 (queue active) then35F9D3AC8A5: to=<listname-bounces@domain.com>, relay=hubtransport.domain.net[192.168.0.165]:25, delay=0.22, delays=0.08/0.04/0.01/0.1, dsn=2.6.0, status=sent (250 2.6.0 <20140620091131.35F9D3AC8A5@mail1.domain.com> Queued mail for delivery) then35F9D3AC8A5: removed
First of all, these should be from=<listname-bounces@domain.com>, not from=<listname@domain.com>. If your posts are really being sent with envelope from <listname@domain.com>, that means bounces will be returned as list posts, not as bounces.
But, I'm still not seeing what I need to see. Taking the last above message as an example, do
grep B52323AC87E /var/log/maillog
or whatever the log file is. In the last few lines, you should see one that says
...postfix/bounce[...]: B52323AC87E sender non-delivery notification: xxxx
where xxx is another Postfix queue ID for the bounce DSN. Then grep the log for that Queue ID, and what do you see?
Here's one where it seems to send the bounced message back to ExchangeJun 20 04:11:31 poseidon postfix/smtp[1539]: 35F9D3AC8A5: to=<listname@domain.com>, relay=hubtransport.domain.com[192.168.0.165]:25, delay=0.22, delays=0.08/0.04/0.01/0.1, dsn=2.6.0, status=sent (250 2.6.0 <20140620091131.35F9D3AC8A5@mail1.domain.com> Queued mail for delivery)
If this is actually a report on one of those DSNs, it should be going to=<listname-bounces@domain.com>, not to=<listname@domain.com>. If the envelope from of your outgoing posts is really <listname@domain.com> and not <listname-bounces@domain.com>, that would explain why bounces are being processed and it might explain what the heldmsg files are (i.e. bounces returned to the list and being held as non-member posts).
It this is what's happening, something is rewriting the envelope sender. What, I have no idea.
On 06/22/2014 09:36 PM, Peter Fraser wrote:
Ok I went scouring through the logs trying to trace a particular message like you suggested and I did find some like this:
Here's one message I tracked.214CA3AC88D: from=<listname-bounces@domain.com>, size=585098, nrcpt=500 (queue active) then214CA3AC88D: to=<name@otherdomain.com>, relay=none, delay=32256, delays=32255/0.05/0.15/0, dsn=4.4.1, status=deferred (connect to mail1.otherdomain.com[x.x.x.x]:25: Connection refused then214CA3AC88D: from=<listname-bounces@domain.com>, size=585098, nrcpt=500 (queue active) then214CA3AC88D: sender non-delivery notification: 35F9D3AC8A5 then35F9D3AC8A5: from=<>, size=3771, nrcpt=1 (queue active) then35F9D3AC8A5: to=<listname-bounces@domain.com>, relay=hubtransport.domain.net[192.168.0.165]:25, delay=0.22, delays=0.08/0.04/0.01/0.1, dsn=2.6.0, status=sent (250 2.6.0 <20140620091131.35F9D3AC8A5@mail1.domain.com> Queued mail for delivery) then35F9D3AC8A5: removed
OK. The failure DSN was sent to <listname-bounces@domain.com> via hubtransport.domain.net (local network IP 192.168.0.165) and accepted by the MTA there with the response (250 2.6.0 <20140620091131.35F9D3AC8A5@mail1.domain.com> Queued mail for delivery)
So look at the logs on that machine and see what it did with the message. And then continue to follow the message until you see it delivered to Mailman or not delivered and why.
-- Mark Sapiro <mark@msapiro.net> The highway is for gamblers, San Francisco Bay Area, California better use your sense - B. Dylan
participants (3)
-
Mark Sapiro -
Peter Fraser -
Stephen J. Turnbull