Addons-frontend: Increased 500 errors after 2019.02.14-2 release

[bqbn]

Describe the problem and steps to reproduce it:

We have seen increased 500 errors after 2019.02.14-2 release. Please see the sceenshot below:

Even thought the absolute rate (<0.06 per second) seems to be low, but it is considered 3 times more than before. So unless something has changed and this is expected, this much increase is definitely an indication of some issue.

What happened?

We are not sure yet. Operation conditions haven't changed for this release. And the increase of 500 happened immediate after the push finishes (judging by the time on the screenshot).

The disco-recommendations waffle was enabled for this release, but not sure it's related or not.

What did you expect to happen?

If the increase of 500 is not expected due to some code changes, we should probably figure out a way to reduce it to its normal level.

Anything else we should know?

n/a

---

For QA: please make sure "not found" pages are displayed correctly for the following locales:

• de
• en-US
• pt-BR

Not found pages are the ones that are displayed for an unknown add-on for instance (or a random url for a page that does not exist).

[bqbn]

Below are the 500 in the past hour on one of the nginx proxy instance (there're 6 in total):

"GET /pt-BR/firefox/addon/gtranslate/ HTTP/1.1" 500 4314 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.052 0.052 "-"
"GET /pt-BR/firefox/addon/gmail-smime/reviews/526182/ HTTP/1.1" 500 4340 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.108 0.108 "-"
"GET /pt-BR/android/addon/webpage-to-pdf/ HTTP/1.1" 500 4339 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.052 0.052 "-"
"GET /pt-BR/firefox/addon/636/ HTTP/1.1" 500 4308 "-" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" 0.057 0.057 "-"
"GET /pt-BR/firefox/user/naichog/ HTTP/1.1" 500 4310 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.058 0.058 "-"
"GET /pt-BR/android/user/bianmunsse/ HTTP/1.1" 500 4334 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.070 0.070 "-"
"GET /pt-BR/firefox/addon/youtube-video-preview/reviews/ HTTP/1.1" 500 4338 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.056 0.056 "-"
"GET /pt-BR/firefox/addon/read-it-later/reviews/191256/ HTTP/1.1" 500 4347 "-" "Sogou web spider/4.0(+http://www.sogou.com/docs/help/webmasters.htm#07)" 0.070 0.070 "-"
"GET /pt-BR/firefox/addon/settingsanity/ HTTP/1.1" 500 4317 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.126 0.126 "-"
"GET /pt-BR/firefox/addon/s3google-translator/ HTTP/1.1" 500 4319 "https://www.reddit.com/r/firefox/comments/8vgwyl/is_there_any_translator_addon_on_firefox_as_good/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 0.070 0.070 "-"
"GET /pt-BR/firefox/user/%C3%A8%E2%84%A2%C5%BE%C3%A6%C2%B5%C2%B7/?page=1 HTTP/1.1" 500 4333 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.047 0.047 "-"
"GET /pt-BR/firefox/addon/auto-liker-brasil/ HTTP/1.1" 500 4388 "-" "Mozilla/5.0 (Windows NT 6.1; WOW64; rv:60.0) Gecko/20100101 Firefox/60.0" 0.079 0.079 "-"
"GET /pt-BR/firefox/addon/website-blocker/?src=search HTTP/1.1" 500 4486 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 11_0 like Mac OS X) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/41.0.3764.503 Mobile Safari/537.36" 0.058 0.058 "-"
"GET /pt-BR/firefox/addon/stop-tube/ HTTP/1.1" 500 4435 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/69.0.3497.92 Safari/537.36" 0.139 0.139 "-"
"GET /pt-BR/firefox/addon/6647/ HTTP/1.1" 500 4308 "-" "Mozilla/5.0 (compatible; AhrefsBot/6.1; +http://ahrefs.com/robot/)" 0.059 0.059 "-"
"GET /pt-BR/firefox/addon/rein/?src=cb-dl-rating HTTP/1.1" 500 4495 "-" "Mozilla/5.0 (Linux; Android 6.0; Nexus 5 Build/MRA58N) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/47.0.2771.510 Mobile Safari/537.36" 0.050 0.050 "-"
"GET /pt-BR/firefox/user/tevofo/ HTTP/1.1" 500 4309 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.055 0.055 "-"
"GET /pt-BR/firefox/addon/tangofox/reviews/210248/ HTTP/1.1" 500 4488 "-" "Mozilla/5.0 (Linux; Android 5.0; SM-G900P Build/LRX21T) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/53.0.6944.871 Mobile Safari/537.36" 0.072 0.072 "-"
"GET /pt-BR/firefox/addon/hide-tabbar/reviews/778256/ HTTP/1.1" 500 4340 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.072 0.072 "-"
"GET /pt-BR/firefox/addon/conquery/reviews/217623/ HTTP/1.1" 500 4337 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.109 0.109 "-"
"GET /pt-BR/firefox/addon/no-resource-uri-leak/reviews/841935/ HTTP/1.1" 500 4349 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.113 0.113 "-"
"GET /pt-BR/firefox/user/14474299/ HTTP/1.1" 500 4443 "https://addons.mozilla.org/zh-TW/firefox/user/14474299/" "Mozilla/4.0 (compatible; MSIE 7.0; Windows NT 6.1; Trident/6.0; SLCC2; .NET CLR 2.0.50727; .NET CLR 3.5.30729; .NET CLR 3.0.30729; .NET CLR 1.1.4322)" 0.057 0.057 "-"
"GET /pt-BR/firefox/addon/encontre-seu-pacote/ HTTP/1.1" 500 4419 "-" "Mozilla/5.0 (compatible; Cloudflare-AMP/1.0; +https://amp.cloudflare.com/doc/fetcher.html) AppleWebKit/534.34" 0.051 0.051 "-"
"GET /pt-BR/firefox/addon/addictive-typing-lessons/ HTTP/1.1" 500 4450 "https://canaltech.com.br/software/9-programas-para-voce-aprender-a-digitar-mais-rapido/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/72.0.3626.96 Safari/537.36" 0.076 0.076 "-"
"GET /pt-BR/firefox/addon/youtube-all-html5/reviews/732818/ HTTP/1.1" 500 4346 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.064 0.064 "-"
"GET /pt-BR/firefox/addon/mp3-search-1/ HTTP/1.1" 500 4422 "-" "Mozilla/5.0 (Windows NT 6.1) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/58.0.2988.0 Safari/537.36" 0.057 0.057 "-"
"GET /pt-BR/firefox/addon/youtube-html5-player/reviews/622832/ HTTP/1.1" 500 4349 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.065 0.065 "-"
"GET /pt-BR/firefox/addon/bugmenot/reviews/561572/ HTTP/1.1" 500 4337 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.062 0.062 "-"
"GET /pt-BR/firefox/user/HakanEr/ HTTP/1.1" 500 4310 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.053 0.053 "-"
"GET /pt-BR/firefox/addon/f-397916-1/ HTTP/1.1" 500 4314 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.066 0.066 "-"
"GET /pt-BR/firefox/addon/download-youtube/ HTTP/1.1" 500 4323 "-" "Mozilla/5.0 (compatible; Exabot/3.0; +http://www.exabot.com/go/robot)" 0.089 0.089 "-"
"GET /pt-BR/firefox/addon/downthemall/ HTTP/1.1" 500 4387 "https://www.downthemall.org/downthemall-3-0-7/" "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 0.080 0.080 "-"
"GET /pt-BR/firefox/addon/reminderfox/reviews/865510/ HTTP/1.1" 500 4340 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.065 0.065 "-"
"GET /pt-BR/firefox/user/kypa/ HTTP/1.1" 500 4307 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.056 0.056 "-"
"GET /pt-BR/firefox/addon/quickframe/reviews/ HTTP/1.1" 500 4327 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.062 0.062 "-"
66.249.83.39" "GET /pt-BR/firefox/addon/super-start/?src=cb-dl-users HTTP/1.1" 500 4479 "-" "Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/49.0.2623.75 Safari/537.36 Google Favicon" 0.058 0.058 "-"
"GET /pt-BR/firefox/addon/castle-age-monster-code-opener/ HTTP/1.1" 500 4335 "-" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" 0.060 0.060 "-"
"GET /pt-BR/firefox/addon/cookies-exportimport/?src=api HTTP/1.1" 500 4417 "https://cookiesnetflixsite.wordpress.com/mozilla-firefox/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 0.059 0.059 "-"
"GET /pt-BR/firefox/addon/mailtowebmails/?src=hp-dl-featured HTTP/1.1" 500 4363 "-" "Mozilla/5.0 (compatible; SputnikBot/2.3; +http://corp.sputnik.ru/webmaster)" 0.074 0.074 "-"
"GET /pt-BR/firefox/user/7638120/ HTTP/1.1" 500 4310 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.077 0.077 "-"
"GET /pt-BR/firefox/addon/firebug/ HTTP/1.1" 500 4454 "https://blog.getfirebug.com/category/firebug-releases/" "Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/71.0.3578.98 Safari/537.36 OPR/58.0.3135.65" 0.062 0.062 "-"
"GET /pt-BR/firefox/addon/proxmate/?src=search HTTP/1.1" 500 4483 "http://www.carlosromero.com.br/2011/07/videos-de-antigos-seriados-de-tv.html" "Mozilla/5.0 (SMART-TV; Linux; Tizen 3.0) AppleWebKit/537.36 (KHTML, like Gecko) SamsungBrowser/2.0 Chrome/47.0.2526.69 TV safari/537.36" 0.077 0.077 "-"
"GET /pt-BR/firefox/addon/cookies-exterminator/ HTTP/1.1" 500 4327 "-" "Mozilla/5.0 (compatible; Exabot/3.0; +http://www.exabot.com/go/robot)" 0.081 0.081 "-"
"GET /pt-BR/firefox/themes/game/ HTTP/1.1" 500 4383 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 0.059 0.059 "-"
"GET /pt-BR/firefox/addon/mkiosk/ HTTP/1.1" 500 4377 "-" "Mozilla/5.0 (iPhone; CPU iPhone OS 10_0 like Mac OS X) AppleWebKit/602.1.38 (KHTML, like Gecko) Version/10.0 Mobile/14A300 Safari/602.1" 0.061 0.061 "-"
"GET /pt-BR/firefox/addon/fifty-shades-freed-sub-title/ HTTP/1.1" 500 4332 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.061 0.061 "-"
"GET /pt-BR/firefox/addon/sothink-web-video-downloader/ HTTP/1.1" 500 4325 "-" "Mozilla/5.0 (compatible; YandexBot/3.0; +http://yandex.com/bots)" 0.056 0.056 "-"
"GET /pt-BR/firefox/addon/tabrenamizer/ HTTP/1.1" 500 4319 "-" "Mozilla/5.0 (compatible; Exabot/3.0; +http://www.exabot.com/go/robot)" 0.099 0.088 "-"
"GET /pt-BR/firefox/addon/consulta-ticket-app/?src=search HTTP/1.1" 500 4355 "-" "Mozilla/5.0 (compatible; SemrushBot-SA/0.97; +http://www.semrush.com/bot.html)" 0.055 0.055 "-"
"GET /pt-BR/firefox/addon/fast-video-download-with-searc/ HTTP/1.1" 500 4335 "-" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" 0.094 0.094 "-"
"GET /pt-BR/firefox/addon/isgd-creator/reviews/107660/ HTTP/1.1" 500 4344 "-" "Mozilla/5.0 (compatible; Exabot/3.0; +http://www.exabot.com/go/robot)" 0.067 0.067 "-"
"GET /pt-BR/firefox/addon/isgd-creator/reviews/183540/ HTTP/1.1" 500 4344 "-" "Mozilla/5.0 (compatible; Exabot/3.0; +http://www.exabot.com/go/robot)" 0.081 0.081 "-"
"GET /pt-BR/firefox/addon/emeilir/reviews/497871/ HTTP/1.1" 500 4337 "-" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" 0.072 0.072 "-"
"POST /ja/developers/addon/submit/upload-unlisted HTTP/1.1" 500 22571 "https://addons.mozilla.org/ja/developers/addon/submit/upload-unlisted" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 2.570 2.570 "-"
"GET /pt-BR/firefox/addon/vista-mail/reviews/286282/ HTTP/1.1" 500 4340 "-" "Mozilla/5.0 (compatible; Googlebot/2.1; +http://www.google.com/bot.html)" 0.062 0.062 "-"
"GET /pt-BR/firefox/addon/flashblock/ HTTP/1.1" 500 4448 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36" 0.079 0.079 "-"
"GET /pt-BR/firefox/addon/betterfox/ HTTP/1.1" 500 4447 "-" "Mozilla/5.0 (Macintosh; Intel Mac OS X 10_13_6) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/68.0.3440.106 Safari/537.36" 0.065 0.065 "-"
"GET /pt-BR/firefox/addon/preserve-download-modification/ HTTP/1.1" 500 4387 "http://blog.mhavila.com.br" "Mozilla/5.0 (compatible; MSIE 9.0; Windows NT 6.1; WOW64; Trident/5.0)" 0.057 0.057 "-"
"GET /pt-BR/firefox/addon/downthemall/?src=userprofile HTTP/1.1" 500 4424 "-" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 0.067 0.067 "-"
"GET /pt-BR/firefox/addon/typing-vietnamese/ HTTP/1.1" 500 4324 "-" "Mozilla/5.0 (compatible; Exabot/3.0; +http://www.exabot.com/go/robot)" 0.068 0.068 "-"
"GET /pt-BR/firefox/addon/flashgot/?src=search HTTP/1.1" 500 4411 "https://support.mozilla.org/pt-BR/questions/1075295" "Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:65.0) Gecko/20100101 Firefox/65.0" 0.055 0.055 "-"
"GET /pt-BR/firefox/addon/close-tabs-to-the-left/reviews/ HTTP/1.1" 500 4339 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.064 0.064 "-"
"GET /pt-BR/firefox/addon/seo-site-tools-analysis/versions/ HTTP/1.1" 500 4341 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.097 0.097 "-"
"GET /pt-BR/firefox/addon/httpfox/versions/ HTTP/1.1" 500 4399 "https://www.youtube.com/" "Mozilla/5.0 (Windows NT 6.3; Win64; x64; rv:51.0) Gecko/20100101 Firefox/51.0" 0.060 0.060 "-"
"GET /pt-BR/firefox/addon/el-tiempo-de-espa%E5%B8%BDa/?src=search HTTP/1.1" 500 4467 "https://addons.mozilla.org/pt-BR/firefox/addon/el-tiempo-de-espa%E5%B8%BDa/?src=search" "Mozilla/5.0 (Windows NT 6.1; WOW64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/45.0.2454.101 Safari/537.36" 0.043 0.043 "-"
"GET /pt-BR/firefox/user/amulyakhare/ HTTP/1.1" 500 4314 "-" "Mozilla/5.0 (compatible; bingbot/2.0; +http://www.bing.com/bingbot.htm)" 0.052 0.052 "-"

[diox]

Those URLs (all pt-BR, all bingbot requests... except for /ja/developers/addon/submit/upload-unlisted which doesn't seem related) are frontend URLs, which should not be served by addons-server anymore. Should this be an addons-frontend issue ?

[diox]

Looks like it's https://sentry.prod.mozaws.net/operations/addons-frontend-amo-prod/issues/5219460/?query=is:unresolved

[willdurand]

The 500 error is caused by an error in the NotFound component (404 error page). This error comes from a localized string that has two sets of linkStart/linkEnd parameters:

"%(linkStart)sextensions%(linkEnd)s or %(secondLinkStart)sthemes%(secondLinkEnd)s."

The locale file contains a translated string that is valid (according to our linter) but the sets are inverted:

"%(secondLinkStart)stemas%(secondLinkEnd)s ou %(linkStart)sextensões%(linkEnd)s disponíveis."

I believe it does not really matter to have the first link before or after the second link, especially for this particular case but our code should be able to deal with that, i.e. it should not throw an error and ideally use the localized string no matter the order of these sets of link parameters.

[willdurand]

I opened a PR to fix the locale file: https://github.com/mozilla/addons-frontend/pull/7598.

Let's try to fix our code now...

[willdurand]

@bqbn we can push a hotfix if you want to reduce the number of 500. The patch is harmless given that it is a locale file that has been fixed.

[willdurand]

This would be the commit to cherry-pick as a hotfix: https://github.com/mozilla/addons-frontend/commit/05b8987c5ec67b5169dabbb135cb2a0a40e239e4 (cc @kumar303)

[bqbn]

I think next week is fine now that we've identified the issue and have a fix.

Next, can QA help re-produce this in -stage and verify the fix before pushing it to -prod?

[kumar303]

@willdurand thanks for the quick fix

The 500 error is caused by an error in the NotFound component
...
https://sentry.prod.mozaws.net/operations/addons-frontend-amo-prod/issues/5219460/?query=is:unresolved

Sigh, yeah. We decided to throw an error there because the way it relied on slicing made the code very fragile. It's probably still a good idea to throw but I'm not sure.

[AlexandraMoga]

I've navigated around various pages on AMO stage using pt-BR but I haven't run into 500 errors. I'm not sure how else I should try to reproduce the issue.

[willdurand]

@AlexandraMoga could you try a page that returns a 404? Like an add-on detail page with an non-existent slug.

[AlexandraMoga]

@willdurand thanks for the tip. I was able to reproduce the 500 error on stage with multiple pages that should be returning a 404 instead.

The issue looks fixed on -dev.

[willdurand]

Sigh, yeah. We decided to throw an error there because the way it relied on slicing made the code very fragile. It's probably still a good idea to throw but I'm not sure.

It is even more fragile with two links in the same string 😞 I am not sure what to do here to be honest, I spent some time trying to find a better way to handle two links into a string, but I don't like the code I wrote for that.

I also think we should throw (as it is currently). Yet, I believe the i18n linter catches issues when a linkStart or linkEnd is missing. It did not catch any issue here because there is no issue with the localized string itself, it is the code that deals with the two links that is problematic. Maybe we should just detect which link comes first 🤷‍♂️

[kumar303]

To recap, the quick fix preventing 500s landed in https://github.com/mozilla/addons-frontend/pull/7598

The next step is to try and come up with a way to prevent this kind of localization problem from occurring again.

[kumar303]

Could you add some steps for QA? I think it's just a matter of checking for regressions in some localizations.

[willdurand]

ah, I forgot to update this issue. I'll add a quick note related to the NotFound component, thanks!

[ioanarusiczki]

@willdurand I verified on both AMO stage and AMO prod for 500 errors for Not Found- 404 pages in the de, pt-BR and en-US but I couldn't generate a 500.
Verified with FF66(Win10).