Still broken.

https://grafana.wikimedia.org/d/000000142/mediawiki-bouncehandler?orgId=1&from=now-5y&to=now

BounceHandler logs in the last 90 days are all POST received from restricted IP <internal appserver ip>. Some process wants to process bounces, but cannot because it's not an mx server.

I'm not aware of a way to escalate unowned code other than via MediaWiki-Engineering intake. This isn't great, but it does need to be looked at. Tagging here to start, acknowleding that we may end up delegating it elsewhere in the org.

In summary: For over a year now, the BounceHandler has not been counting any bounces or unsubs. The hope is that this is limited to a bad metric, and not actually broken functionally. However, the code hasn't changed in ~7 years and the statsd code is known to be stable and hasn't affected other others. Which means it seems likely not to be "just" a metric issue.

The BounceHandler extension exists to notify users about malfunctioning email addresses, so that contributors can find out sooner rather than later, and thus correct this mistake instead of e.g. months later and end up locked out of their account if they cannot reset their password. The extension also unsubscribes the undeliverable address from our servers so that WMF does not keep sending emails to an unresponsive address, which might be affect positive reputation of Wikimedia's MX servers if we don't do this over a long period of time (to be verified, unsure).

Well, it think it's official. It's down.

(x1.wikishared)> SELECT br_id,br_timestamp,br_reason FROM bounce_records ORDER BY br_timestamp DESC LIMIT 1;
+--------+----------------+----------------------------------------------------+
| br_id  | br_timestamp   | br_reason                                          |
+--------+----------------+----------------------------------------------------+
| 599213 | 20220228094419 | Mail delivery failed : returning message to sender |
+--------+----------------+----------------------------------------------------+
1 row in set (0.001 sec)

Quick query against puppet found this change to mx around the same time: https://gerrit.wikimedia.org/r/c/operations/puppet/+/766571

Could the migration to https (possibly, addition of Envoy as a proxy) be interfering with the request IP check?

The check is done using Webrequest::getIP() which uses REMOTE_ADDR as a source for the address, and then overrides that using X-Forwarded-For only for trusted proxies.

Given the MX server doesn't set X-F-F, REMOTE_ADDR is used.

REMOTE_ADDR is sadly the IP address that apache sees a connection from, and there isn't a way around it in the apache configuration. On the other hand, HTTP_X_CLIENT_IP is where you can find the IP originating the request injected by the edge. But this request doesn't originate at the edge, and we don't set it, so that's not set either.

See https://phabricator.wikimedia.org/T297613#7577140 for more details.

Edit: the simplest way to fix this seems to be to add the X-Client-IP header to the request.

Change #1070805 had a related patch set uploaded (by Giuseppe Lavagetto; author: Giuseppe Lavagetto):

[operations/puppet@production] exim: fix VERP handling for mediawiki

https://gerrit.wikimedia.org/r/1070805

Change #1070805 merged by Giuseppe Lavagetto:

[operations/puppet@production] exim: fix VERP handling for mediawiki

https://gerrit.wikimedia.org/r/1070805

I still see the errors in the logs, and it's baffling. In fact, I've tried the command now listed in exim's configuration:

without the -H 'X-Client-IP` it results in the error we are familiar with:

mx1001 $ /usr/bin/curl -H 'Host: meta.wikimedia.org' https://mw-api-int.discovery.wmnet:4446/w/api.php -d "action=bouncehandler" -d 'format=json' -d 'email=here@spamhere.lots'

{"error":
   {"code":"invalid-ip",
    "info":"This API module is for internal use only.",
    "*":"See https://meta.wikimedia.org/w/api.php for API usage. Subscribe to the mediawiki-api-announce mailing list at <https://lists.wikimedia.org/postorius/lists/mediawiki-api-announce.lists.wikimedia.org/> for notice of API deprecations and breaking changes."},
   "servedby":"mw-api-int.eqiad.canary-68c997fb45-5rm88"
 }
}

But if I add the -H X-Client-IP it gives a different error (I'm sending spurious data in email@)

mx1001:~$ /usr/bin/curl -H 'Host: meta.wikimedia.org' -H 'X-Client-IP: 208.80.153.45' https://mw-api-int.discovery.wmnet:4446/w/api.php -d "action=bouncehandler" -d 'format=json' -d 'email=here@spamhere.lots' 

{"bouncehandler":{"submitted":"failure"}}

and I don't find the corresponding line in the logs, so I am clearly missing something :)

Change #1070858 had a related patch set uploaded (by Giuseppe Lavagetto; author: Giuseppe Lavagetto):

[operations/puppet@production] postfix: add X-Client-IP to VERP handler

https://gerrit.wikimedia.org/r/1070858

Change #1070858 merged by Giuseppe Lavagetto:

[operations/puppet@production] postfix: add X-Client-IP to VERP handler

https://gerrit.wikimedia.org/r/1070858

Change #1070879 had a related patch set uploaded (by Giuseppe Lavagetto; author: Giuseppe Lavagetto):

[operations/mediawiki-config@master] BounceHandler: add IPs for the new mx servers

https://gerrit.wikimedia.org/r/1070879

Change #1070879 merged by jenkins-bot:

[operations/mediawiki-config@master] BounceHandler: add IPs for the new mx servers

https://gerrit.wikimedia.org/r/1070879

Mentioned in SAL (#wikimedia-operations) [2024-09-05T09:26:04Z] <oblivian@deploy1003> Started scap sync-world: Backport for [[gerrit:1070879|BounceHandler: add IPs for the new mx servers (T338761)]]

Mentioned in SAL (#wikimedia-operations) [2024-09-05T09:32:39Z] <oblivian@deploy1003> oblivian: Backport for [[gerrit:1070879|BounceHandler: add IPs for the new mx servers (T338761)]] synced to the testservers (https://wikitech.wikimedia.org/wiki/Mwdebug)

Mentioned in SAL (#wikimedia-operations) [2024-09-05T09:37:20Z] <oblivian@deploy1003> Finished scap sync-world: Backport for [[gerrit:1070879|BounceHandler: add IPs for the new mx servers (T338761)]] (duration: 11m 16s)

I'm finally seeing bounces get processed in logstash https://logstash.wikimedia.org/goto/3d34190bb82088f19669b0c66331d7c9

I've documented the following on Wikitech: https://wikitech.wikimedia.org/wiki/BounceHandler

From BounceHandler - Wikitech § How it works:

MediaWiki sends outgoing email to account holders, such as for notifications from their Watchlist, Recent changes, Echo events, account management, and more. MediaWiki sends these via php-sendmail. The BounceHandler extension adds VERP headers to each email.

If someone's inbox bounces for any other reason, the recipient mail server may send us a bounce mail. Upon receipt of such a bounce, Postfix is configured to send a POST request to the MediaWiki BounceHandler API.

The BounceHandler API validates the request (wgBounceHandlerInternalIPs) and queues a job to the JobQueue to handle the bounce.

The job then records the bounce event for this address is in its database (x1). If the bounce count for a given email address reaches a predefined threshold (wgBounceRecordLimit), the email address is marked as "unconfirmed". This effectively unsubscribes the address from all future email, and prevents our servers from sending more undeliverable emails for this address to the recipient's mail server. The account in question is also notified via the *Echo**xtension of this fact, which the user will see next time they login or otherwise browse on the wiki.

The Grafana dashboard was not very usable due to plotting .count (see extended properties) which has no defined unit, it changes meaning depending zoom level and date range. It also had "connect null values" enabled, which lead to the appearance of continuos bounces instead of rendering 0 when there are 0.

Fixed to use rates instead which are stable with a defined unit, and historical bar charts daily totals.

Before:

After:
Grafana: MediaWiki BounceHandler dashboard

It looks like we're processing around the same number of bounces as before the outage, and performing around the same number of unsubscriptions as well. This suggests it's working end to end with no major faults, losses, or gaps (e.g. by country, email provider, wiki, or some other aspect that would affect a large proportion).

Change #1071064 had a related patch set uploaded (by Krinkle; author: Krinkle):

[mediawiki/extensions/BounceHandler@master] BounceHandlerActions: Simplify and clean up code

https://gerrit.wikimedia.org/r/1071064

Change #1071064 merged by jenkins-bot:

[mediawiki/extensions/BounceHandler@master] BounceHandlerActions: Simplify and clean up code

https://gerrit.wikimedia.org/r/1071064