PHP Notice: Undefined index: frameCount
Closed, ResolvedPublicPRODUCTION ERROR
Actions

Assigned To

Authored By

	dduvall
	Jun 23 2021, 7:58 PM

Description

Error

mwversion: 1.37.0-wmf.11
reqId: 8345cdef-e0d3-4b99-accd-57164c5646fc
Find reqId in Logstash
Find normalized_message in Logstash

normalized_message

[{reqId}] {exception_url}   PHP Notice: Undefined index: frameCount

exception.trace

from /srv/mediawiki/php-1.37.0-wmf.11/includes/media/PNGHandler.php(153)
#0 /srv/mediawiki/php-1.37.0-wmf.11/includes/media/PNGHandler.php(153): MWExceptionHandler::handleError(integer, string, string, integer, array)
#1 /srv/mediawiki/php-1.37.0-wmf.11/includes/filerepo/file/File.php(2388): PNGHandler->getLongDesc(LocalFile)
#2 /srv/mediawiki/php-1.37.0-wmf.11/includes/page/ImagePage.php(518): File->getLongDesc()
#3 /srv/mediawiki/php-1.37.0-wmf.11/includes/page/ImagePage.php(142): ImagePage->openShowImage()
#4 /srv/mediawiki/php-1.37.0-wmf.11/includes/actions/ViewAction.php(74): ImagePage->view()
#5 /srv/mediawiki/php-1.37.0-wmf.11/includes/MediaWiki.php(536): ViewAction->show()
#6 /srv/mediawiki/php-1.37.0-wmf.11/includes/MediaWiki.php(320): MediaWiki->performAction(ImagePage, Title)
#7 /srv/mediawiki/php-1.37.0-wmf.11/includes/MediaWiki.php(917): MediaWiki->performRequest()
#8 /srv/mediawiki/php-1.37.0-wmf.11/includes/MediaWiki.php(551): MediaWiki->main()
#9 /srv/mediawiki/php-1.37.0-wmf.11/index.php(53): MediaWiki->run()
#10 /srv/mediawiki/php-1.37.0-wmf.11/index.php(46): wfIndexMain()
#11 /srv/mediawiki/w/index.php(3): require(string)
#12 {main}

Impact

No user-facing impact, however a significant increase in log spam during group1 promotion of 1.37.0-wmf.11. Set to UBN as it blocks train.

Notes

Possibly related to risky patch https://gerrit.wikimedia.org/r/c/mediawiki/core/+/693298 noted in T281152: 1.37.0-wmf.11 deployment blockers. A similar report already exists as T173360: PHP Notice: Undefined index: frameCount but backtrace differs possibly due to refactoring.

Details

Request URL: https://commons.wikimedia.org/wiki/File:57519-Obervisse-Sols.png?uselang=*

Related Changes in Gerrit:

Subject	Repo	Branch	Lines +/-
media: Make the file metadata "_error" check looser	mediawiki/core	wmf/1.37.0-wmf.11	+2 -10
media: Make the file metadata "_error" check looser	mediawiki/core	master	+2 -10
Check for _error in getting metadata array in PNGHandler	mediawiki/core	master	+5 -1
Check for _error in getting metadata array in GIFHandler	mediawiki/core	master	+5 -1
Check for _error in getting metadata array in GIFHandler	mediawiki/core	wmf/1.37.0-wmf.11	+5 -1
Check for _error in getting metadata array in PNGHandler	mediawiki/core	wmf/1.37.0-wmf.11	+5 -1

Customize query in gerrit

Related Objects
Search...

		Status	Subtype	Assigned	Task
		Resolved	Release	dduvall	T281152 1.37.0-wmf.11 deployment blockers
		Resolved	PRODUCTION ERROR	Ladsgroup	T285431 PHP Notice: Undefined index: frameCount

Event Timeline

dduvall created this task.Jun 23 2021, 7:58 PM

dduvall triaged this task as Unbreak Now! priority.

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptJun 23 2021, 7:58 PM

dduvall added a parent task: T281152: 1.37.0-wmf.11 deployment blockers.Jun 23 2021, 8:01 PM

I'll handle it after eating dinner if no one beats me to it

Restricted Application added a project: User-Ladsgroup. · View Herald TranscriptJun 23 2021, 8:07 PM

It seems in PNGMetadataExtractor, $frameCount is always defined and declared in the metadata array, no matter how strange the file is. So it's odd that it can sometimes be undefined. We probably don't want isset() checks everywhere for every key, so perhaps this is an error scenario that we failed to catch before the code in question is reached?

Okay, I found the problem. Not sure how to fix though.

What you said was a great help actually but the problem is that PNGMetadataExtractor extracts the metadata in upload from the file and this shows the metadata from database, there has been lots of cases that in the database they were saved as empty:

wikiadmin@10.64.32.156(commonswiki)> select img_metadata from image where img_name = '57519-Obervisse-Sols.png';
+--------------+
| img_metadata |
+--------------+
| 0            |
+--------------+
1 row in set (0.00 sec)

Fixing it requires running maintenance/refreshImageMetadata.php on every file, that will take a while. Funnily enough, running it on the file on wmf.9 doesn't change metadata in the database (maybe the class returns zero in case of really broken metadata on file?) but it returns a:1:{s:6:"_error";s:1:"0";} on wmf.11 (progress?)

I feel writing defensively is our only option for now. I'm looking at why PNGMetadataExtractor returns zero sometimes. You can also try it on any of the files in the logs.

Okay, I have an idea. Let me try.

Change 701179 had a related patch set uploaded (by Ladsgroup; author: Ladsgroup):

[mediawiki/core@master] Check for values of metadata in PNGHandler

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

gerritbot added a project: Patch-For-Review.Jun 23 2021, 9:45 PM

Change 701186 had a related patch set uploaded (by Ladsgroup; author: Ladsgroup):

[mediawiki/core@wmf/1.37.0-wmf.11] Check for _error in getting metadata array in PNGHandler

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

I neglected to include this in the report, but a similar notice was occurring for GIFHandler as well, albeit at a much lower rate of error. The exception.file for that one is /srv/mediawiki/php-1.37.0-wmf.11/includes/media/GIFHandler.php:167. Let me know if you'd rather have a full separate bug report and I'll file one.

Change 701182 had a related patch set uploaded (by Ladsgroup; author: Ladsgroup):

[mediawiki/core@master] Check for _error in getting metadata array in GIFHandler

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

Change 701179 merged by jenkins-bot:

[mediawiki/core@master] Check for _error in getting metadata array in PNGHandler

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

Change 701186 merged by jenkins-bot:

[mediawiki/core@wmf/1.37.0-wmf.11] Check for _error in getting metadata array in PNGHandler

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

Change 701187 had a related patch set uploaded (by Ladsgroup; author: Ladsgroup):

[mediawiki/core@wmf/1.37.0-wmf.11] Check for _error in getting metadata array in GIFHandler

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

Mentioned in SAL (#wikimedia-operations) [2021-06-23T22:42:36Z] <ladsgroup@deploy1002> Synchronized php-1.37.0-wmf.11/includes/media/PNGHandler.php: Backport: [[gerrit:701186|Check for _error in getting metadata array in PNGHandler (T285431)]] (duration: 01m 06s)

ReleaseTaggerBot added a project: MW-1.37-notes (1.37.0-wmf.12; 2021-06-28).Jun 23 2021, 11:00 PM

Change 701182 merged by jenkins-bot:

[mediawiki/core@master] Check for _error in getting metadata array in GIFHandler

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

Change 701187 merged by jenkins-bot:

[mediawiki/core@wmf/1.37.0-wmf.11] Check for _error in getting metadata array in GIFHandler

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

Mentioned in SAL (#wikimedia-operations) [2021-06-23T23:05:14Z] <ladsgroup@deploy1002> Synchronized php-1.37.0-wmf.11/includes/media/GIFHandler.php: Backport: [[gerrit:701187|Check for _error in getting metadata array in GIFHandler (T285431)]] (duration: 01m 06s)

Maintenance_bot removed a project: Patch-For-Review.Jun 23 2021, 11:10 PM

Mentioned in SAL (#wikimedia-operations) [2021-06-23T23:19:21Z] <dduvall> rolling back 1.37.0-wmf.11 from group1 (T281152) due to reoccurrence of "PHP Notice: Undefined index: frameCount" now at PNGHandler.php:156 (T285431)

ReleaseTaggerBot edited projects, added MW-1.37-notes (1.37.0-wmf.11; 2021-06-21); removed MW-1.37-notes (1.37.0-wmf.12; 2021-06-28).Jun 24 2021, 12:00 AM

Change 701216 had a related patch set uploaded (by Ladsgroup; author: Ladsgroup):

[mediawiki/core@master] Make the check for broken metadata looser

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

gerritbot added a project: Patch-For-Review.Jun 24 2021, 12:32 AM

I made the patch but it's too late for me to deploy, anyone feeling like deploying it is more than welcome. Otherwise I can get it deployed tomorrow.

Change 701191 had a related patch set uploaded (by Krinkle; author: Ladsgroup):

[mediawiki/core@wmf/1.37.0-wmf.11] media: Make the file metadata "_error" check looser

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

Change 701216 merged by jenkins-bot:

[mediawiki/core@master] media: Make the file metadata "_error" check looser

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

ReleaseTaggerBot edited projects, added MW-1.37-notes (1.37.0-wmf.12; 2021-06-28); removed MW-1.37-notes (1.37.0-wmf.11; 2021-06-21).Jun 24 2021, 2:00 AM

Change 701191 merged by jenkins-bot:

[mediawiki/core@wmf/1.37.0-wmf.11] media: Make the file metadata "_error" check looser

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

Mentioned in SAL (#wikimedia-operations) [2021-06-24T09:02:33Z] <ladsgroup@deploy1002> Synchronized php-1.37.0-wmf.11/includes: Backport: [[gerrit:701191|media: Make the file metadata "_error" check looser (T285431)]] (duration: 01m 12s)

This is handled on dev side, we can roll the train forward IMO.

ReleaseTaggerBot edited projects, added MW-1.37-notes (1.37.0-wmf.11; 2021-06-21); removed MW-1.37-notes (1.37.0-wmf.12; 2021-06-28).Jun 24 2021, 10:00 AM

Re-rolled to group1 at 1700 and I've seen no notices since. Thanks for the fix!

Krinkle moved this task from Untriaged to June 2021 on the Wikimedia-production-error board.Mar 22 2022, 2:10 PM

Maintenance_bot moved this task from Incoming to Done on the User-Ladsgroup board.Mar 22 2022, 2:15 PM

PHP Notice: Undefined index: frameCountClosed, ResolvedPublicPRODUCTION ERRORActions