Might be related to Scribunto's ustring pattern regex cache, the Parser, or the language name cache?

Change 176515 merged by jenkins-bot:
Verify parameter for MapCacheLRU::has() can be passed to array_key_exists()

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

Change 201886 had a related patch set uploaded (by Alex Monk):
Verify parameter for MapCacheLRU::has() can be passed to array_key_exists()

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

I'm concerned about this being deployed in its current state.

Previously the warning was quite innocent. The logic still worked as expected. The key could not exist and returned false. A warning ends up written to our logs. The patch essentially turns that warning into a fatal exception causing the user's whatever action to be aborted in place.

Have we found where this gets triggered and have fixed those? Especially considering this was raised from the logs by frequency, I don't think we should turn that into an exception as a way to find out where it's being triggered – at the cost of users.

Well, we could deploy only the MapCacheLRU part so we get the warnings. Assuming the way it actually ends up logging in production provides us with the problematic caller in some way.

In T76305#1180527, @Krenair wrote:

Well, we could deploy only the MapCacheLRU part so we get the warnings. Assuming the way it actually ends up logging in production provides us with the problematic caller in some way.

PHP itself already emitted a warning. So it'd be one warning for another. With PHP warnings at least MWExceptionHandler is able to provide a stacktrace (though that's currently disabled in production). wfWarn does not have any strack trace ability (and its intended purpose shouldn't need it).

Change 201886 abandoned by Alex Monk:
Verify parameter for MapCacheLRU::has() can be passed to array_key_exists()

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

Change 218669 had a related patch set uploaded (by Krinkle):
Enable logging for T76305

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

Change 218669 merged by jenkins-bot:
Enable logging for T76305

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

Change 188987 had a related patch set uploaded (by Krinkle):
Title: Throw if newFromText is given non-string value

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

Change 250882 had a related patch set uploaded (by Krinkle):
Title: Add warning if newFromText is given non-string/non-null value

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

Change 250883 had a related patch set uploaded (by Krinkle):
Title: Add warning if newFromText is given non-string/non-null value

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

Change 250882 merged by jenkins-bot:
Title: Add warning if newFromText is given non-string/non-null value

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

Change 250883 merged by jenkins-bot:
Title: Add warning if newFromText is given non-string/non-null value

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

For the past 24 hours there are 100 log entries for the warnings.

Some common ones which don't yet seem to have an open bug in the blocker section:

• Linker::formatLinksInComment/Title::newFromText (various callers)
• SpecialExport->execute/SpecialExport->doExport/SpecialExport->getTemplates/SpecialExport->getLinks/Title::newFromText

I wonder if Title::newFromText could be a bit smarter and convert integers to strings? I suspect a lot of these log entries are caused by integers being passed into Title::newFromText (e.g. 123 instead of "123"). That seems to be the cause of the SpecialExport one, from what I can see.

That doesn't sound like a good idea. I looked at SpecialExport and it not obvious to me at all why there would be integers.

In T76305#1920257, @Nikerabbit wrote:

That doesn't sound like a good idea. I looked at SpecialExport and it not obvious to me at all why there would be integers.

It's because page titles are being used as array keys. When you use a numeric string as an array key, PHP automatically casts it to an integer.

Sure, you could fix SpecialExport, but it just seems saner to fix Title::newFromText.

Change 267023 had a related patch set uploaded (by TTO):
Title::newFromText: Cast integers to strings

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

Change 267023 merged by jenkins-bot:
Title::newFromText: Cast integers to strings

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

Could someone with relevant access please check the logs to see if these messages are still being generated? If the blockers are correct, this should now only be coming from the Collection extension since the last deployment.

krenair@fluorine:/a/mw-log$ grep "text must be a string" exception.log  -c
154

All I see are opensearch ones like this:

2016-03-14 21:48:53 mw1229 enwiki 1.27.0-wmf.16 exception ERROR: [634c6a7b] /w/api.php?action=opensearch&[other url params]   InvalidArgumentException from line 272 of /srv/mediawiki/php-1.27.0-wmf.16/includes/Title.php: $text must be a string. {"exception_id":"634c6a7b"} 
[Exception InvalidArgumentException] (/srv/mediawiki/php-1.27.0-wmf.16/includes/Title.php:272) $text must be a string.
  #0 /srv/mediawiki/php-1.27.0-wmf.16/includes/search/SearchEngine.php(591): Title::newFromText(CirrusSearch)
  #1 /srv/mediawiki/php-1.27.0-wmf.16/includes/search/SearchEngine.php(761): SearchEngine->normalizeNamespaces(CirrusSearch)
  #2 /srv/mediawiki/php-1.27.0-wmf.16/includes/specialpage/SpecialPage.php(348): SearchEngine->defaultPrefixSearch(CirrusSearch)
  #3 /srv/mediawiki/php-1.27.0-wmf.16/includes/specials/SpecialPrefixindex.php(306): SpecialPage->prefixSearchString(CirrusSearch, integer, integer)
  #4 /srv/mediawiki/php-1.27.0-wmf.16/includes/PrefixSearch.php(197): SpecialPrefixindex->prefixSearchSubpages(string, integer, integer)
  #5 /srv/mediawiki/php-1.27.0-wmf.16/includes/PrefixSearch.php(270): PrefixSearch->specialSearch(string, integer, integer)
  #6 /srv/mediawiki/php-1.27.0-wmf.16/includes/search/SearchEngine.php(774): PrefixSearch->defaultSearchBackend(array, string, integer, integer)
  #7 /srv/mediawiki/php-1.27.0-wmf.16/includes/search/SearchEngine.php(643): SearchEngine->simplePrefixSearch(string)
  #8 /srv/mediawiki/php-1.27.0-wmf.16/extensions/CirrusSearch/includes/CirrusSearch.php(574): SearchEngine->completionSearchBackend(string)
  #9 /srv/mediawiki/php-1.27.0-wmf.16/includes/search/SearchEngine.php(658): CirrusSearch->completionSearchBackend(string)
  #10 /srv/mediawiki/php-1.27.0-wmf.16/extensions/CirrusSearch/includes/CirrusSearch.php(608): SearchEngine->completionSearch(string)
  #11 /srv/mediawiki/php-1.27.0-wmf.16/includes/api/ApiOpenSearch.php(130): CirrusSearch->completionSearchWithVariants(string)
  #12 /srv/mediawiki/php-1.27.0-wmf.16/includes/api/ApiOpenSearch.php(98): ApiOpenSearch->search(string, integer, array, boolean, array)
  #13 /srv/mediawiki/php-1.27.0-wmf.16/includes/api/ApiMain.php(1359): ApiOpenSearch->execute()
  #14 /srv/mediawiki/php-1.27.0-wmf.16/includes/api/ApiMain.php(462): ApiMain->executeAction()
  #15 /srv/mediawiki/php-1.27.0-wmf.16/includes/api/ApiMain.php(433): ApiMain->executeActionWithErrorHandling()
  #16 /srv/mediawiki/php-1.27.0-wmf.16/api.php(83): ApiMain->execute()
  #17 /srv/mediawiki/w/api.php(3): include(string)
  #18 {main}

Hm, that's possibly a new issue, although probably closely related to T121707.

I was actually referring to the T76305 log channel. What's been coming in there lately?

Not a lot:

krenair@fluorine:/a/mw-log$ ls T76305.lg
ls: cannot access T76305.lg: No such file or directory
krenair@fluorine:/a/mw-log$ ls archive/T76305.log-20160313.gz 
archive/T76305.log-20160313.gz
krenair@fluorine:/a/mw-log$ zcat archive/T76305.log-20160313.gz
2016-03-12 16:08:01 mw1237 cswiki 1.27.0-wmf.16 T76305 INFO: EducationProgram\EditAction->onSuccess/EducationProgram\EditAction->getReturnToTitle/EducationProgram\EditAction->getIdentifierFromRequestArgs/EducationProgram\PageTable->getTitleFor/Title::newFromText  
krenair@fluorine:/a/mw-log$ zcat archive/T76305.log-20160312.gz
2016-03-11 14:58:33 mw1256 zhwiki 1.27.0-wmf.15 T76305 INFO: Linker::commentBlock/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText

the log for the 11th contains a lot of this: Linker::commentBlock/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText, and a couple of these: ImageHistoryList->imageHistoryLine/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText

OK, the Linker fix went out with wmf.16, so we can ignore those. The EducationProgram one is new, filed a blocker for that.

Last three archives:

• T76305.log-20160312.gz
• T76305.log-20160313.gz
• T76305.log-20160401.gz

Nothing between March 13 and April 1st. Nothing between April 2nd and April 6th (today).

$ zcat T76305.log-2016{0312,0313,0401}.gz
2016-03-11 14:58:33 mw1256 zhwiki 1.27.0-wmf.15 T76305 INFO: Linker::commentBlock/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText
2016-03-12 16:08:01 mw1237 cswiki 1.27.0-wmf.16 T76305 INFO: EducationProgram\EditAction->onSuccess/EducationProgram\EditAction->getReturnToTitle/EducationProgram\EditAction->getIdentifierFromRequestArgs/EducationProgram\PageTable->getTitleFor/Title::newFromText
2016-03-30 16:09:41 [bc5d8186e3edbb855bd6e346] mw1240 hewiki 1.27.0-wmf.18 T76305 INFO: EducationProgram\EditAction->onSuccess/EducationProgram\EditAction->getReturnToTitle/EducationProgram\EditAction->getIdentifierFromRequestArgs/EducationProgram\PageTable->getTitleFor/Title::newFromText

All of March/April combined for more rare entries:

$ zcat T76305.log-20160{3,4}* | cut -d':' -f4- | sort | uniq -c | sort -r
    761  Linker::commentBlock/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText  
    101  MobileSpecialPageFeed->formatComment/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText  
     84  ImageHistoryList->imageHistoryLine/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText  
     52  FeedUtils::formatDiffRow/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText  
     10  SpecialMobileWatchlist->formatComment/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText  
      8  EducationProgram\EditAction->onSuccess/EducationProgram\EditAction->getReturnToTitle/EducationProgram\EditAction->getIdentifierFromRequestArgs/EducationProgram\PageTable->getTitleFor/Title::newFromText  
      6  ApiQueryRevisionsBase->extractRevisionInfo/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText  
      4  ImageListPager->formatValue/Linker::formatComment/Linker::formatLinksInComment/Closure$Linker::formatLinksInComment/Title::newFromText 

It seems all blocking tasks are closed. What remains to do to close this task? Only review of https://gerrit.wikimedia.org/r/#/c/188987/ ?

Change 188987 merged by jenkins-bot:
Title: Throw if newFromText is given an invalid value

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