Page MenuHomePhabricator

PHP Notice: Undefined index: frameCount
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error
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.

Event Timeline

dduvall triaged this task as Unbreak Now! priority.Jun 23 2021, 7:58 PM
dduvall created this task.

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

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

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)

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)

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)

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

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

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.

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