Page MenuHomePhabricator

'NoneType' object has no attribute 'start'
Closed, ResolvedPublicBUG REPORT

Description

AttributeError: 'NoneType' object has no attribute 'start'

  File "/opt/lib/python/site-packages/flask/app.py", line 2073, in wsgi_app
    response = self.full_dispatch_request()
  File "/opt/lib/python/site-packages/flask/app.py", line 1518, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/opt/lib/python/site-packages/flask/app.py", line 1516, in full_dispatch_request
    rv = self.dispatch_request()
  File "/opt/lib/python/site-packages/flask/app.py", line 1502, in dispatch_request
    return self.ensure_sync(self.view_functions[rule.endpoint])(**req.view_args)
  File "/srv/app/app.py", line 252, in query
    sections_to_exclude=data["sections_to_exclude"][:25],
  File "/srv/app/src/query.py", line 54, in run
    sections_to_exclude=sections_to_exclude,
  File "/srv/app/src/scripts/utils.py", line 425, in process_page
    i1_sub = match.start()

Spotted when looking at the service logs after deployment (but the error was from earlier). Just a single instance.

Event Timeline

Started happening in production today, on the scale of 1000/hour.

Screenshot Capture - 2022-05-30 - 21-50-38.png (205×416 px, 7 KB)

kostajh triaged this task as High priority.Jun 1 2022, 10:31 AM
kostajh subscribed.

Seems like a high priority item, @Tgr correct me if I'm wrong. I assume the impact of this is a failed request/response, right?

HTTP 400 errors, it seems. Only a small fraction of total requests, so this is not a "servers are on fire" situation, but I agree it should be high priority, at least until we figure out exactly which requests are affected (might be configuration issues with a single wiki, for example).

[urbanecm@mwmaint1002 /var/log/mediawiki]$ grep '500 Internal Server Error' mediawiki_job_growthexperiments-refreshLinkRecommendations-s*/syslog.log | grep -o '[a-z]*wiki:' | tr -d : | sort -u
azwiki
[urbanecm@mwmaint1002 /var/log/mediawiki]$

Looks to affect only azwiki. Example failing request:

urbanecm@notebook  ~
$ curl --silent 'https://api.wikimedia.org/service/linkrecommendation/v1/linkrecommendations/wikipedia/az/Rufus_(personaj)' | jq .
{
  "code": 500,
  "name": "Internal Server Error",
  "description": "The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application."
}
urbanecm@notebook  ~
$
[urbanecm@mwmaint1002 /var/log/mediawiki]$ grep '500 Internal Server Error' mediawiki_job_growthexperiments-refreshLinkRecommendations-s*/syslog.log | grep -o '[a-z]*wiki:' | tr -d : | sort -u
azwiki
[urbanecm@mwmaint1002 /var/log/mediawiki]$

Looks to affect only azwiki. Example failing request:

urbanecm@notebook  ~
$ curl --silent 'https://api.wikimedia.org/service/linkrecommendation/v1/linkrecommendations/wikipedia/az/Rufus_(personaj)' | jq .
{
  "code": 500,
  "name": "Internal Server Error",
  "description": "The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application."
}
urbanecm@notebook  ~
$

Thanks for that tip! I can reproduce this locally.

[urbanecm@mwmaint1002 /var/log/mediawiki]$ grep '500 Internal Server Error' mediawiki_job_growthexperiments-refreshLinkRecommendations-s*/syslog.log | grep -o '[a-z]*wiki:' | tr -d : | sort -u
azwiki
[urbanecm@mwmaint1002 /var/log/mediawiki]$

Looks to affect only azwiki. Example failing request:

urbanecm@notebook  ~
$ curl --silent 'https://api.wikimedia.org/service/linkrecommendation/v1/linkrecommendations/wikipedia/az/Rufus_(personaj)' | jq .
{
  "code": 500,
  "name": "Internal Server Error",
  "description": "The server encountered an internal error and was unable to complete your request. Either the server is overloaded or there is an error in the application."
}
urbanecm@notebook  ~
$

Thanks for that tip! I can reproduce this locally.

The bit that fails is:

match = mention_regex_i.search(
    page_wikicode_init_substr.lower()
)

If I query for wikipedia/az/Rufus_(personaj) locally:

print(page_wikicode_init_substr.lower())
rufus tüksüz köstəbəkdir. meqa maqada yaşayırdı. ronun atasının tüklərə qarşı allergiyası var idi. bu səbəbdən ron rufusu özünə götürür. rufus adi köstəbək deyildir. rufusun beyni insanın beyninə çox yaxındır. i̇nsan kimi 2 ayaqları üzərində dayana bilir. rufusun boyu 30 sm-dir. çəkisi 1,8 kq-dır. gözləri qaradır. bədəninin rəngi çəhrayıdır. saçları yoxdur. köstəbəklər nümayəndəsinə daxildir. i̇lk mövsümdə 2 yaşı, dördüncü mövsümdə isə 4 yaşı vardır. i̇ngiliscə danışığı yaxşı bilir. başa çatdırılmamış cümlələri tamamlaya bilir. rufus balaca varlıqdır. o qədər balacadır ki, insanların ciblərinə asanlıqla girə bilir. ron onu həmişə cibində saxlayır. bueno naçoda yalnız naçodan dadmağı xoşlayır. bütün serial boyu rufus yalnız ronun cibində qalır. rufus həmişə həm rona, həm də kim possibla dar gündə kömək edir.
print(mention_regex_i)
re.compile('(?<!\\[\\[)(?<!-->)\\bİngiliscə\\b(?![\\w\\s]*[\\]\\]])', re.IGNORECASE)

The easiest thing would be to continue when match is None. But perhaps we should focus on fixing the regex so it doesn't fail to match in this scenario?

If we don't convert the page_wikicode_init_substr variable to lowercase:

match = mention_regex_i.search(
                                    page_wikicode_init_substr
                                )

Then the match succeeds:

{
  "links": [
    {
      "context_after": " danışığı ",
      "context_before": "ı vardır. ",
      "link_index": 0,
      "link_target": "İngilis dili",
      "link_text": "İngiliscə",
      "match_index": 0,
      "score": 0.6471115946769714,
      "wikitext_offset": 693
    }
  ],
  "links_count": 1,
  "meta": {
    "application_version": "1e8b6ff",
    "dataset_checksums": {},
    "format_version": 1
  },
  "page_title": "Rufus (personaj)",
  "pageid": 271505,
  "revid": 6024182
}

The lowercasing has been in the algorithm for a long while now (since rRMWA7f7c0a7bf18a: Improve the parsing of text into ngrams to generate candidate-anchors and earlier commits), so, cc @MGerlach in case you have some particular guidance here.

[urbanecm@mwmaint1002 /var/log/mediawiki]$ grep '500 Internal Server Error' mediawiki_job_growthexperiments-refreshLinkRecommendations-s*/syslog.log | grep -o '[a-z]*wiki:' | tr -d : | sort -u
azwiki
[urbanecm@mwmaint1002 /var/log/mediawiki]$

Looks to affect only azwiki.

I take this back, it affects more wikis (that said, azwiki appears to account for the highest number of errors). In case that's helpful, a couple of other problematic articles from other wikis:

python-dotted-i.png (80×147 px, 5 KB)

I guess without being told to use the correct locale, Python interprets İ as I plus combining dot, and lowercases to i plus combining dot, instead of just i as would be correct in Turkic languages. Not sure if that's a bug or the correct Unicode behavior, but the inverse is definitely going to fail without setting the locale - the lowercase of I is i in most Latin scripts but ı in Turkic ones where the dotted and dotless I are different characters.

The service probably needs to fetch the BCP-47 language code (usually but not always the same as the wiki domain, but should be available via the siteinfo or sitematrix API), set the locale at the beginning of the request and hope it doesn't have any detrimental side effects. Or maybe use PyICU which allows passing in the locale as a parameter to .lower()/.upper().

python-dotted-i.png (80×147 px, 5 KB)

I guess without being told to use the correct locale, Python interprets İ as I plus combining dot, and lowercases to i plus combining dot, instead of just i as would be correct in Turkic languages. Not sure if that's a bug or the correct Unicode behavior, but the inverse is definitely going to fail without setting the locale - the lowercase of I is i in most Latin scripts but ı in Turkic ones where the dotted and dotless I are different characters.

The service probably needs to fetch the BCP-47 language code (usually but not always the same as the wiki domain, but should be available via the siteinfo or sitematrix API), set the locale at the beginning of the request and hope it doesn't have any detrimental side effects. Or maybe use PyICU which allows passing in the locale as a parameter to .lower()/.upper().

Thanks for the analysis.

Let's try the BCP-47 code, although I would propose that the refreshLinkRecommendations.php script should send the code, rather than have the service make an HTTP request to fetch it.

Change 806563 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[research/mwaddlink@main] blubber: Add locales-all package

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

Change 806563 abandoned by Kosta Harlan:

[research/mwaddlink@main] blubber: Add locales-all package

Reason:

Not needed as PyICU can work without this.

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

Change 806858 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[research/mwaddlink@main] Use locale-specific lowercasing

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

Change 806861 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[research/mwaddlink@main] [WIP] tests: Add regression test for lowercasing wikitext

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

Change 807139 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[research/mwaddlink@main] tests: Add PyICU to test requirements

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

Change 807139 merged by jenkins-bot:

[research/mwaddlink@main] tests: Add PyICU to test requirements

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

Change 807496 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[mediawiki/extensions/GrowthExperiments@master] LinkRecommendation: Pass language code to the link recommendation service

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

Change 806861 abandoned by Kosta Harlan:

[research/mwaddlink@main] tests: Add regression test for lowercasing az wikitext

Reason:

squashed (better to have tests with the implementation patch)

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

Change 806858 merged by jenkins-bot:

[research/mwaddlink@main] Use locale-specific lowercasing

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

Change 807581 had a related patch set uploaded (by Kosta Harlan; author: Kosta Harlan):

[operations/deployment-charts@master] linkrecommendation: Bump version

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

Change 807581 merged by jenkins-bot:

[operations/deployment-charts@master] linkrecommendation: Bump version

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

Change 806858 merged by jenkins-bot:

[research/mwaddlink@main] Use locale-specific lowercasing

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

This code is now in production, so we should see that these errors disappear from Logstash.

The task is still in code review as https://gerrit.wikimedia.org/r/807496 still needs to be merged.

Change 807496 merged by jenkins-bot:

[mediawiki/extensions/GrowthExperiments@master] LinkRecommendation: Pass language code to the link recommendation service

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

Etonkovidova subscribed.

No errors have been reported after June 22/2022 - https://grafana.wikimedia.org/d/CI6JRnLMz/linkrecommendation?orgId=1&from=1655769600000&to=1656547199000&viewPanel=13.

Also, checked azwiki Homepage-Link recommendation tasks - all look good.