magicdude4eva / port25-bouncehandler

Port25 PowerMTA bounce handler for Interspire and MailWizz
MIT License
73 stars 42 forks source link

worked, but stopped working; all records = skipped #23

Closed rritz66 closed 6 years ago

rritz66 commented 6 years ago

I had the bouncehandler working till Jan 20 I changed nothing but it stopped working

when I do the manual processing, I get this:

cat /var/log/pmta/acct-2018-02-18-0000.csv | /usr/bin/php /opt/pmta/bouncehandler/bouncehandler.php --debug [18/Feb/2018:15:42:47] ------------------------------------------------------------------ [18/Feb/2018:15:42:47] Port25 PowerMTA bounce-handler [18/Feb/2018:15:42:47] (C) 2016 Gerd Naschenweng http://github.com/magicdude4eva [18/Feb/2018:15:42:47] ------------------------------------------------------------------ [18/Feb/2018:15:42:47] Handling bounce categories=bad-mailbox,bad-domain,routing-errors,inactive-mailbox,spam-related [18/Feb/2018:15:42:47] Bounce-provider: Interspire, initialising [18/Feb/2018:15:42:47] Skipped - not configured! [18/Feb/2018:15:42:47] Bounce-provider: Interspire, complete [18/Feb/2018:15:42:47] Bounce-provider: MailWizz, initialising [18/Feb/2018:15:42:47] Endpoint-URL=mydomain [18/Feb/2018:15:42:47] MailWizz enabled! [18/Feb/2018:15:42:47] Bounce-provider: MailWizz, complete [18/Feb/2018:15:42:47] Feedback-provider: initialising [18/Feb/2018:15:42:47] Feedback-provider: complete [18/Feb/2018:15:42:47] Starting bounce processing [18/Feb/2018:15:42:47] Completed bounce processing! Total records=19, processed=0, skipped=19

In /var/log/pmta/pmta-bounce-handler.log there's this: (I replaced my email address with xxxxx and other addresses too)

Starting bounce processing [22/Jan/2018:23:36:10] Bounce: inactive-mailbox from=xxxxxx via pmta-vmta0/xxx@yahoo.com [22/Jan/2018:23:38:12] Bounce: inactive-mailbox from=xxxxxx via pmta-vmta0/yyy@yahoo.com [26/Jan/2018:19:02:00] Bounce: inactive-mailbox from=xxxxxx via pmta-vmta0/zzz@yahoo.com [26/Jan/2018:19:03:01] Bounce: inactive-mailbox from=xxxxxx via pmta-vmta0/www@yahoo.com [27/Jan/2018:13:45:39] Bounce: routing-errors from=xxxxxx via pmta-vmta0/admin@example.com [03/Feb/2018:17:53:23] Bounce: inactive-mailbox from=xxxx via pmta-vmta0/vvv@yahoo.com [03/Feb/2018:17:59:25] Bounce: inactive-mailbox from=xxxxx via pmta-vmta0/uuu@yahoo.com

....

[18/Feb/2018:10:15:47] Bounce: bad-domain from=xxxxxx via pmta-vmta0/fff@dr.comm [18/Feb/2018:14:58:47] Bounce: spam-related from=xxxxxx via pmta-vmta0/aaaa

None of these bounces ever showed up in mailwizz

Can you please help me understand what's happening and why do these records get skipped in manual processing, and why did bouncehandler stop working? Where to start debugging this?

Running php 5.6.32 on CentOS6_x64 pmta 4.5v8

rritz66 commented 6 years ago

@magicdude4eva please could you look into my issue as well?

If you could explain why records get skipped And where and how I could start debugging Thank you

magicdude4eva commented 6 years ago

Can you delete /var/log/pmta/pmta-bounce-handler.log and then run a simple manual bounce with just one email and then attach output of console as well as log file?

rritz66 commented 6 years ago

@magicdude4eva sorry I just saw this

Here's the log file contents: [06/May/2018:13:02:25] ------------------------------------------------------------------ [06/May/2018:13:02:25] Port25 PowerMTA bounce-handler [06/May/2018:13:02:25] (C) 2016 Gerd Naschenweng http://github.com/magicdude4eva [06/May/2018:13:02:25] ------------------------------------------------------------------ [06/May/2018:13:02:25] Handling bounce categories=bad-mailbox,bad-domain,routing-errors,inactive-mailbox,spam-related [06/May/2018:13:02:25] Bounce-provider: Interspire, initialising [06/May/2018:13:02:25] Skipped - not configured! [06/May/2018:13:02:25] Bounce-provider: Interspire, complete [06/May/2018:13:02:25] Bounce-provider: MailWizz, initialising [06/May/2018:13:02:25] Endpoint-URL=http://mydomain/api/index.php [06/May/2018:13:02:25] MailWizz enabled! [06/May/2018:13:02:25] Bounce-provider: MailWizz, complete [06/May/2018:13:02:25] Feedback-provider: initialising [06/May/2018:13:02:25] Feedback-provider: complete [06/May/2018:13:02:25] Starting bounce processing [06/May/2018:13:02:25] Completed bounce processing! Total records=1, processed=0, skipped=1

Here's the console output, but it's exactly the ame as the log file:

cat /var/log/pmta/acct-2018-05-06-0000.csv | /usr/bin/php /opt/pmta/bouncehandler/bouncehandler.php --debug [06/May/2018:13:19:04] ------------------------------------------------------------------ [06/May/2018:13:19:04] Port25 PowerMTA bounce-handler [06/May/2018:13:19:04] (C) 2016 Gerd Naschenweng http://github.com/magicdude4eva [06/May/2018:13:19:04] ------------------------------------------------------------------ [06/May/2018:13:19:04] Handling bounce categories=bad-mailbox,bad-domain,routing-errors,inactive-mailbox,spam-related [06/May/2018:13:19:04] Bounce-provider: Interspire, initialising [06/May/2018:13:19:04] Skipped - not configured! [06/May/2018:13:19:04] Bounce-provider: Interspire, complete [06/May/2018:13:19:04] Bounce-provider: MailWizz, initialising [06/May/2018:13:19:04] Endpoint-URL=http://mydomain/api/index.php [06/May/2018:13:19:04] MailWizz enabled! [06/May/2018:13:19:04] Bounce-provider: MailWizz, complete [06/May/2018:13:19:04] Feedback-provider: initialising [06/May/2018:13:19:04] Feedback-provider: complete [06/May/2018:13:19:04] Starting bounce processing [06/May/2018:13:19:04] Completed bounce processing! Total records=1, processed=0, skipped=1

rritz66 commented 6 years ago

all the records are skipped, always

droidman85 commented 6 years ago

same problem with me. only is working for 1 user account on mailwizz, all other accounts are always skipped. anyone found a fix for this ?

magicdude4eva commented 6 years ago

Running the bounce-processing in manual mode, you can not cat the PMTA accounting file. The manual bounce processing needs to be a simple CSV with one email per line - i.e.

a@a.com
b@b.com
c@c.com

You can then run cat /tmp/bounce.csv | /usr/bin/php /opt/pmta/bouncehandler/bouncehandler.php --debug which will produce the following:

[26/Jun/2018 19:05:05] ------------------------------------------------------------------
[26/Jun/2018 19:05:05] Port25 PowerMTA bounce-handler
[26/Jun/2018 19:05:05] (C) 2016-2017 Gerd Naschenweng  https://github.com/magicdude4eva
[26/Jun/2018 19:05:05] ------------------------------------------------------------------
[26/Jun/2018 19:05:05] Handling bounce categories=bad-mailbox,bad-domain,routing-errors,inactive-mailbox,spam-related,policy-related
[26/Jun/2018 19:05:05] Soft-bounce categories=bad-configuration,bad-connection,content-related,invalid-sender,other,policy-related,quota-issues,spam-related,virus-related
[26/Jun/2018 19:05:05] Bounce-provider: Interspire, initialising
[26/Jun/2018 19:05:05]    Skipped - not configured!
[26/Jun/2018 19:05:05] Bounce-provider: MailWizz, initialising
[26/Jun/2018 19:05:05]    Endpoint-URL=https://hermes.bidorbuy.co.za/api
[26/Jun/2018 19:05:05]    MailWizz enabled!
[26/Jun/2018 19:05:05] Bounce-provider: MailWizz, complete
[26/Jun/2018 19:05:05] Bounce-provider: Bidorbuy, initialising
[26/Jun/2018 19:05:05] Bounce-provider: Bidorbuy, complete
[26/Jun/2018 19:05:05] Feedback-provider: initialising
[26/Jun/2018 19:05:05] Feedback-provider: complete
[26/Jun/2018 19:05:05] Initialising RRD reporting via /var/log/pmta/pmta.rrd
[26/Jun/2018 19:05:05] Starting bounce processing
[26/Jun/2018 19:05:06]    MailWizz: Skipping a@a.com, already unsubscribed!
[26/Jun/2018 19:05:06]    MailWizz: Skipping b@b.com, already unsubscribed!
[26/Jun/2018 19:05:06]    MailWizz: Skipping c@c.com, already unsubscribed!
[26/Jun/2018 19:05:06] Completed bounce processing! Total records=4, processed=3, skipped=1

The PMTA accounting-file can only be processed via PMTA piping as described - your setup would look like this in PMTA config:

<acct-file |/usr/bin/php /opt/pmta/bouncehandler/bouncehandler.php>
    records b
    record-fields b timeQueued,bounceCat,vmta,orig,rcpt,srcMta,dlvSourceIp,jobId,dsnStatus,dsnMta,dsnDiag
</acct-file>

I have upgraded to MailWizz 1.5.7 over the weekend and just looked at the PMTA bounce-logs and everything continues to work as it has since 2016:

more /var/log/pmta/pmta-bounce-handler.log
[01/Jun/2016:08:05:58] Port25 PowerMTA bounce-handler
[01/Jun/2016:08:05:58] (C) 2016 Gerd Naschenweng  http://github.com/magicdude4eva
[01/Jun/2016:08:05:58] ------------------------------------------------------------------
[01/Jun/2016:08:05:58] Handling bounce categories=bad-mailbox,bad-domain,routing-errors,inactive-mailbox
[01/Jun/2016:08:05:58] Bounce-provider: Interspire, initialising
...
...
...
[21/Jun/2018 12:17:58] ------------------------------------------------------------------
[21/Jun/2018 12:17:58] Port25 PowerMTA bounce-handler
[21/Jun/2018 12:17:58] (C) 2016-2017 Gerd Naschenweng  https://github.com/magicdude4eva
[21/Jun/2018 12:17:58] ------------------------------------------------------------------
[21/Jun/2018 12:17:58] Handling bounce categories=bad-mailbox,bad-domain,routing-errors,inactive-mailbox,spam-related,policy-related
[21/Jun/2018 12:17:58] Soft-bounce categories=bad-configuration,bad-connection,content-related,invalid-sender,other,policy-related,quota-issues,spam-related,virus-related
[21/Jun/2018 12:17:58] Bounce-provider: Interspire, initialising
[21/Jun/2018 12:17:58]    Skipped - not configured!
[21/Jun/2018 12:17:58] Bounce-provider: MailWizz, initialising
[21/Jun/2018 12:17:58]    Endpoint-URL=[REDACTED]
[21/Jun/2018 12:17:59]    MailWizz enabled!
[21/Jun/2018 12:17:59] Bounce-provider: MailWizz, complete
[21/Jun/2018 12:17:59] Bounce-provider: Bidorbuy, initialising
[21/Jun/2018 12:17:59] Bounce-provider: Bidorbuy, complete
[21/Jun/2018 12:17:59] Feedback-provider: initialising
[21/Jun/2018 12:17:59] Feedback-provider: complete
[21/Jun/2018 12:17:59] Initialising RRD reporting via /var/log/pmta/pmta.rrd
[21/Jun/2018 12:17:59] Starting bounce processing
[21/Jun/2018 12:20:51] Bounce: bad-mailbox from=[REDACTED]
[21/Jun/2018 12:30:58] Bounce: bad-mailbox from=[REDACTED]
[21/Jun/2018 12:32:01] Bounce: routing-errors from=[REDACTED] via [REDACTED] jobId=questions-messages-to-seller, dsnStatus=5.4.4 (unable to route: no mail hosts for domain)
[21/Jun/2018 12:32:01]    bidorbuy: Failed unsubscribing user [REDACTED] with error=400, message=Already unsubscribed!
[21/Jun/2018 12:32:02]    MailWizz: unsubscribe for [REDACTED]:
[21/Jun/2018 12:32:02]    - skipped: Spring Sale Sellers
[21/Jun/2018 12:32:02]    - skipped: NPS Sellers March 2017 test
[21/Jun/2018 12:32:02]    - skipped: Sellers List - Nov 2017
[21/Jun/2018 12:32:02]    - skipped: Sellers List - Feb 2018
[21/Jun/2018 12:40:53] Bounce: bad-mailbox from=[REDACTED] via [REDACTED] jobId=, dsnStatus=5.1.1 (bad destination mailbox address)
[21/Jun/2018 12:40:54] Bounce: bad-mailbox from=[REDACTED] jobId=, dsnStatus=5.1.1 (bad destination mailbox address)
[21/Jun/2018 12:49:42] Bounce: bad-mailbox from=[REDACTED] via [REDACTED] jobId=welcome-confirm, dsnStatus=5.1.1 (bad destination mailbox address)
[21/Jun/2018 12:49:42]    bidorbuy: Unsubscribed user [REDACTED]
[21/Jun/2018 12:49:43]    MailWizz: unsubscribe for [REDACTED]:
[21/Jun/2018 12:49:43]    - success: za#m#Deal of the Week
[21/Jun/2018 12:49:43]    - success: za#m#R1 Flash Auctions & Sales
[21/Jun/2018 12:49:43]    - success: za#m#Crazy Wednesday (R1 auctions)
[21/Jun/2018 12:49:43]    - success: za#m#Snap Friday (R1 auctions)
[21/Jun/2018 12:49:43]    - success: za - Specials and Promotions
[21/Jun/2018 12:49:43]    - success: za - Weekend Specials