2/3 of non-email push notifications seem to not go through

[babolivier]

(it might be email as well but we don't have enough stats for them)

We've received report that some users weren't receiving push notifications either via email or on their devices (i.e. via APNS or FCM). The graph for HTTP push (the latter category) on matrix.org seems to show a 2/3 drop on February 27th:

The pusher worker's logs seem to indicate the same trend:

$ zgrep "Received response to POST http://[SYGNAL'S IP]/_matrix/push/v1/notify" pusher1.log-20200218.gz | wc -l
3153656

(on Feb 18th)

$ zgrep "Received response to POST http://[SYGNAL'S IP]/_matrix/push/v1/notify" pusher1.log-20200310.gz | wc -l
931077

(on Mar 10th)

Feb 27th seems to match with a deployment of Synapse matrix.org, so it seems fair to say this is probably a Synapse issue and the cause should be a changed that happened between then and Feb 19th (the previous deployment, which didn't seem to have that bug). #6964 seems like a likely suspect, though I didn't get far enough in my investigation to confirm this theory.

According to what @manuroe told me, it seems like a user can temporarily fix this issue by restarting their client, which causes it to re-register the pusher. But it turns out it's only a temporary fix because a device fixed like this can stop receiving notifications again after a short while (I think @dbkr experienced that).

Another point of interest is that, while investigating @jryans's missing email notifs (which I thought might be coming from the same issue, but I have no evidence to confirm nor deny this theory right now), I could see that Synapse's database (in the pushers table) claimed to have that the last successful email notification was sent to his address two days ago while he hasn't received any since Feb 27th. It might be unrelated, but the fact that the date coincides with this bug and that email pushes don't seem to be entirely broken (I managed to get an email notif sent to an address associated with my matrix.org account earlier today), I thought it worth it to mention it here.

My first hunch was that the pusher wasn't replicated correctly from the master to the pusher worker, and that hunch was coming from the fact that for Ryan's account, the replication notifier would log "Streaming: pushers -> [PUSHER ID]" for the HTTP pusher(s) but not the email one (which was the problematic one), but it looks like it only logs that for HTTP pushers so it's might not be coming from there.

[clokep]

Feb 27th seems to match with a deployment of Synapse matrix.org, so it seems fair to say this is probably a Synapse issue and the cause should be a changed that happened between then and Feb 19th (the previous deployment, which didn't seem to have that bug). #6964

I went back through and it seems like the range of commits to look at is: e3d811e...69111a8

There's quite a bit in there (130 files changed, +1.7k, -2.9k). The PRs that seemed to touch push things are:

• Merge a number of workers together. #6964 (as noted above)
• Clarify list/set/dict/tuple comprehensions and enforce via flake8 #6957
• Stop using room alias events to calculate room name #6966

[clokep]

A few notes from today (unsure if these are useful, but want to write them down):

• The incoming data rate for the pusher work does not seem to have changed:
  

• The amount of badge updates that were processed seems to also dip around the same time as HTTP pushes dip (see graph in the description):
  

[richvdh]

It looks like, since https://github.com/matrix-org/synapse/pull/6964/files#diff-9b951d362503f8f7a6b4fd290f703601L216, we are no longer calling PusherPool.start.

It's unclear why push was working at all, but still: #7104 should fix it.