Hi @CDanis! This must be related to our new widgets, which request an update at device local midnight. The easiest thing for us would be to pick a random minute within the midnight hour to update instead of at the top of the hour, as you suggested. I also think we could audit the feeds that are updated - currently we do our standard background explore feed refresh, but all of those sources aren't necessary for the widgets (like page/random/summary).

Thanks so much @Tsevener !

Another thing I wanted to ask, while we're on the topic, is if the iOS app performs exponential backoff when it sees failures on background requests (if it retries them at all).

@CDanis we can definitely smear the requests - is there a minimum smear time you would suggest for considering this fixed on your end? If it's an hour that's fine, but if we could do any less that would be better for the user to limit the delta between midnight and seeing updated data in the widgets for the next day's content.

@CDanis If the widgets don't have what they need when we request a refresh, it tells the system to try again in 2 hours. But there's no failure trigger to try again immediately. Also note we did have an update request loop bug in 6.7.0 (unrelated to request failures), that was fixed in 6.7.1.

In T264881#6526357, @Tsevener wrote:

@CDanis If the widgets don't have what they need when we request a refresh, it tells the system to try again in 2 hours. But there's no failure trigger to try again immediately. Also note we did have an update request loop bug in 6.7.0 (unrelated to request failures), that was fixed in 6.7.1.

Okay, great, 2 hours is more than long enough where I don't think we need to get fancy here, especially once we smear the initial requests.

In T264881#6526320, @Tsevener wrote:

@CDanis we can definitely smear the requests - is there a minimum smear time you would suggest for considering this fixed on your end? If it's an hour that's fine, but if we could do any less that would be better for the user to limit the delta between midnight and seeing updated data in the widgets for the next day's content.

I'm doing a little modelling on this, although it's complicated because I need to figure out how quickly these requests get cached in the CDN.

This is also something we might want to tune over time, as we both change how expensive these API calls are on the various backends and as the install base of the app grows.

How much drudgery is it to do a new release? Right now I can tell you that a 30 minute interval is almost definitely safe, but I don't think I could vouch for a tighter interval before at least tomorrow.

It's not difficult but it does take a couple of days before it'll be out there once we're in code freeze. 1 day for smoke testing & testing with beta users as well as the App Store review process can take a day or two.

I don't know if this has been considered or not and I admit I don't know the wikifeeds and iOS well enough to be sure but if it's causing 1.2M requests and lots of them make it to the appservers, maybe it just needs more aggressive caching on the server-side (like in restbase, I'm fairly certain restbase caches the requests but why so many pass that?). Mostly because for example "On this day" is not going to change much from device to device.

This can be a longer term solution though.

In T264881#6527486, @Ladsgroup wrote:

I don't know if this has been considered or not and I admit I don't know the wikifeeds and iOS well enough to be sure but if it's causing 1.2M requests and lots of them make it to the appservers, maybe it just needs more aggressive caching on the server-side (like in restbase, I'm fairly certain restbase caches the requests but why so many pass that?). Mostly because for example "On this day" is not going to change much from device to device.

This can be a longer term solution though.

Yeah, that's a good thought. FWIW these responses are being cached at the edge CDN, but enough request volume seems to still make its way to the backends to be harmful. My guess is this is in the very initial stages of the flood of requests. I'll have firmer data on this tomorrow.

We are publishing v6.7.2 (1780) of the app as I write, which has our initial smear. Users tend to update over a few days, although the weekends tend to be the prime app update time, so we may get quick uptake. At any rate the client side remediation should be noticeable by Monday and conintue to improve over the week. If we're not seeing that, or the remediation isn't sufficient, just let us know and we'll iterate.

Thanks to everyone jumping on this ticket!

Really great to see this happen so quickly! Thanks so much :)

I'll do some tracking of how well smearing is working once we start seeing the release deployed, and we can iterate on a tighter interval.

When the 22:00 traffic spike happened today, it was a bit more impactful than usual. In doing a bit of investigation, @RLazarus and I had a sudden realization, one of those epiphanies that are so obvious in retrospect: all of these URLs are cached by our edge CDN, except the random page summary. Very likely, that call alone is responsible for the vast majority of the load that makes it through the CDN to the backend servers.

So, a couple quick followup questions for the iOS team:

• Does the 6.7.2 release remove the fetches against /api/rest_v1/page/random/summary as part of the daily widget update?
• Do you have any objections to SRE installing a ratelimit for fetches against that API call by the app? We'd pick a very high threshold, never exceeded at normal times, and remove said limit after the new app is mostly rolled out.

(Also, to be clear, the smearing is a good idea anyway, even once we get this piece fixed and all the daily requests are cacheable.)

I think some form of ratelimiting for that should be present in restbase, and in general, we should ratelimit calls to uncachable URLs to volumes we can support.

But more specifically, it's probably a good idea to ratelimit that endpoint for now if it's causing user-noticeable issues to our users.

@CDanis we didn't remove fetches against /api/rest_v1/page/random/summary from the widgets - it would have required a bit of rework which would have delayed a quick release. I can file a followup task for us to consider it next week though. Rate limiting that API sounds fine, but can you get me a response example of what a rate limit looks like? Just want to test it right quick against the app to make sure we're handling it properly on our end.

In T264881#6532868, @Tsevener wrote:

@CDanis we didn't remove fetches against /api/rest_v1/page/random/summary from the widgets - it would have required a bit of rework which would have delayed a quick release. I can file a followup task for us to consider it next week though.

Sure, totally makes sense (& appreciated!), and the temporal smearing will still help us a lot here :)

Rate limiting that API sounds fine, but can you get me a response example of what a rate limit looks like? Just want to test it right quick against the app to make sure we're handling it properly on our end.

We can change this if needed, but the default would be an HTTP 429 response code with the response body "Too Many Requests". (A different response code, empty response body, or some other response body would also all be doable.)

@CDanis Thanks! That response is working fine in my testing, feel free to do what you need to with it.

Great! Thanks @Tsevener !

Change 633229 had a related patch set uploaded (by CDanis; owner: CDanis):
[operations/puppet@production] VCL: temp. ratelimit iOS app fetches of random page summary

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

Change 633229 merged by CDanis:
[operations/puppet@production] VCL: temp. ratelimit iOS app fetches of random page summary

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

Hi @Tsevener -- wanted to check in about something. Is the version of the app WikipediaApp/6.7.2.1780 the version expected to have smoothing of widget refreshes over the whole hour? As far as I can tell that isn't happening:

@CDanis darn - yes, that's the right version, and we limited it to 30 minutes instead of an hour. We're thinking of possible reasons & solutions on our end. I'll move this to our current board so it doesn't get lost. I have a couple of questions:

1. I assume the screenshot is only limited to those counts from 6.7.2, can you also post a separate screenshot of those from 6.7.1? I know the 6.7.2 spike is unacceptable but I wanted to compare and see if it's even slightly more gradual than 6.7.1. If so maybe we just need to spread it out more over say, 2 hours or so. If not maybe there's still a midnight trigger somewhere in our codebase that we missed.
2. Can you post a screenshot of the entire day's worth of data from both versions? We were discussing and wondering why you don't see spikes at the top of each hour throughout the day, since it's supposed to update near midnight device local time. Looking closer and it does seem like there might be spikes at each hour, only much smaller. So maybe at that tallest spike there's additional endpoints besides random that aren't cached, like that's the first time when that particular day's worth of On This Day data begins to be requested by the app.

@CDanis Sorry I just noticed you do mention in the description that it's also at the top of each hour. That makes sense, it does make me think that there will still be a spike (though surely less tall) if we remove random endpoint call. I think we need to do some digging to confirm there are no other midnight updates, and possibly increase the spread further if we don't find anything.

Thanks @Tsevener ! Detailed reply below -- and thanks for the questions, they were helpful! -- but here's a high-level summary of what I found and what I'm thinking right now:

• 6.7.2 greatly reduced the amplitude of the hourly peaks, although they're still present.
• If we do the following two things, this probably isn't nearly as big a deal:
  • Remove the calls to the random endpoint from the widget refreshes
  • Make sure we've fixed T266040 on Traffic's side, which is a long-extant misconfiguration that prevented us from caching the cacheable calls as quickly as they should have been.

Ideally, for distributed systems best-practice reasons, the app wouldn't be sending these bursts -- but once the above are fixed, I think the CDN should be able to properly soak the bursts that do remain after the fixes in 6.7.2. So if figuring out the other cause(s) of the top-of-the-hour spikes turns out to be too hard, that's probably okay.

In T264881#6573076, @Tsevener wrote:

@CDanis darn - yes, that's the right version, and we limited it to 30 minutes instead of an hour.

Got it, thanks. 30 minutes seems totally reasonable.

We're thinking of possible reasons & solutions on our end. I'll move this to our current board so it doesn't get lost. I have a couple of questions:

1. I assume the screenshot is only limited to those counts from 6.7.2, can you also post a separate screenshot of those from 6.7.1? I know the 6.7.2 spike is unacceptable but I wanted to compare and see if it's even slightly more gradual than 6.7.1. If so maybe we just need to spread it out more over say, 2 hours or so. If not maybe there's still a midnight trigger somewhere in our codebase that we missed.

Yeah, the graph I posted was filtered to just 6.7.2, and was also filtered to just the /api/rest_v1/feed/featured/2020/10/xx requests for that day.

I just realized that last time I forgot to post a link to Turnilo to go along with the screenshot -- I'll post links from now on. You're in the wmf LDAP group so you have access to this data as well, and if it'd be helpful I'd be happy to find some time next week to give you or others a brief demo of the tool.

It seems like the installbase of 6.7.1 has shrunk a lot, and as a result the recent data there is pretty noisy, so I went back two weeks ago to when the rollout was happening. That showed pretty clearly that the amplitude of the spikes were quite reduced by 6.7.2 -- which is great! -- but also that they're still present.

Here's traffic for all versions of the iOS app for that window: https://w.wiki/iFL

Here's only the 6.7.1 traffic: https://w.wiki/iFM

And here's only the 6.7.2 traffic (n.b. the y-axis change): https://w.wiki/iFN

Finally, here's the 6.7.2 data but broken down by the top 10 URL paths: https://w.wiki/iFP

And that same graph above, but zoomed into the time window around 22:00 UTC on Oct 10: https://w.wiki/iFQ

And finally, here's the top 25 URL paths fetched by 6.7.2 during the window from 22:00-22:03 UTC on Oct 10: https://w.wiki/iFS

That aside, it doesn't seem like there's other extremely popular request paths from the app at this time. Maybe there's some other code path also triggering the same updates right at local midnight?

2. Can you post a screenshot of the entire day's worth of data from both versions? We were discussing and wondering why you don't see spikes at the top of each hour throughout the day, since it's supposed to update near midnight device local time. Looking closer and it does seem like there might be spikes at each hour, only much smaller. So maybe at that tallest spike there's additional endpoints besides random that aren't cached, like that's the first time when that particular day's worth of On This Day data begins to be requested by the app.

BTW -- the data I've been showing here isn't just cache misses; it's total request volume, whether a hit or a miss in the CDN. Of course, misses are more impactful, but we still care about massively-synchronized spikes of requests -- even if they're all hits.

As you guessed, we do see small spikes at each hour -- 22:00 is merely the largest one. 04:00 (midnight US Eastern) is also quite prominent; same for 07:00 (US Pacific). The smaller spikes are much more noticeable in the 6.7.1 data though, where you can see spikes for most of the populated European and North American time zones. There's also tiny top-of-the-hour peaks visible at many hours of the day.

In both app versions, there's also some other interesting periodicity of requests on a 15-minute cycle which I haven't dug into, but I'm not concerned by as the amplitude is low.

Here's 11:55 Oct 8th -- 12:05 Oct 9th for 6.7.1: https://w.wiki/iFd

And this is 11:55 Oct 10th -- 12:05 Oct 11th for 6.7.2: https://w.wiki/iFf

I'm taking this off our active release board for now. We're discussing potential changes to the feed/widget caching model in general to mitigate further and particularly to reduce the need for random page selection. I'll ping this ticket with that task, once it is drafted, so we can confirm the changes we plan match what you're seeing/expecting.