Page MenuHomePhabricator

Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData]
Closed, ResolvedPublicPRODUCTION ERROR

Description

Error message
Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData]
Impact

Log spam.

Notes

Related to T263592: Use of Language::commafy with a non-numeric string was deprecated in MediaWiki 1.36. [Called from Language::formatNum] and T266677: Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData]. This time in ExifBitmapHandler?

Details

Request ID
e4dbe964-e9fa-4f91-9e57-2a78aa36c24a
Stack Trace
#0 [internal function]: MWExceptionHandler::handleError(integer, string, string, string, array)
#1 /srv/mediawiki/php-1.36.0-wmf.16/includes/debug/MWDebug.php(329): trigger_error(string, integer)
#2 /srv/mediawiki/php-1.36.0-wmf.16/includes/debug/MWDebug.php(305): MWDebug::sendRawDeprecated(string, boolean, string)
#3 /srv/mediawiki/php-1.36.0-wmf.16/includes/debug/MWDebug.php(234): MWDebug::deprecatedMsg(string, string, string, integer)
#4 /srv/mediawiki/php-1.36.0-wmf.16/includes/GlobalFunctions.php(1029): MWDebug::deprecated(string, string, string, integer)
#5 /srv/mediawiki/php-1.36.0-wmf.16/includes/media/FormatMetadata.php(1382): wfDeprecated(string, string)
#6 /srv/mediawiki/php-1.36.0-wmf.16/includes/media/FormatMetadata.php(1066): FormatMetadata->formatNum(string)
#7 /srv/mediawiki/php-1.36.0-wmf.16/includes/media/FormatMetadata.php(92): FormatMetadata->makeFormattedData(array)
#8 /srv/mediawiki/php-1.36.0-wmf.16/includes/media/MediaHandler.php(568): FormatMetadata::getFormattedData(array, RequestContext)
#9 /srv/mediawiki/php-1.36.0-wmf.16/includes/media/ExifBitmapHandler.php(138): MediaHandler->formatMetadataHelper(array, RequestContext)
#10 /srv/mediawiki/php-1.36.0-wmf.16/includes/filerepo/file/File.php(1919): ExifBitmapHandler->formatMetadata(LocalFile, RequestContext)
#11 /srv/mediawiki/php-1.36.0-wmf.16/includes/page/ImagePage.php(131): File->formatMetadata(RequestContext)
#12 /srv/mediawiki/php-1.36.0-wmf.16/includes/actions/ViewAction.php(74): ImagePage->view()
#13 /srv/mediawiki/php-1.36.0-wmf.16/includes/MediaWiki.php(530): ViewAction->show()
#14 /srv/mediawiki/php-1.36.0-wmf.16/includes/MediaWiki.php(316): MediaWiki->performAction(ImagePage, Title)
#15 /srv/mediawiki/php-1.36.0-wmf.16/includes/MediaWiki.php(943): MediaWiki->performRequest()
#16 /srv/mediawiki/php-1.36.0-wmf.16/includes/MediaWiki.php(546): MediaWiki->main()
#17 /srv/mediawiki/php-1.36.0-wmf.16/index.php(53): MediaWiki->run()
#18 /srv/mediawiki/php-1.36.0-wmf.16/index.php(46): wfIndexMain()
#19 /srv/mediawiki/w/index.php(3): require(string)
#20 {main}

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes
RhinosF1 triaged this task as Unbreak Now! priority.Nov 5 2020, 9:14 PM
RhinosF1 subscribed.

Train blocker = UBN!

These all seem to be triggered from .jpg images shot on a Nikon COOLPIX AW100 camera, which apparently uses a bogus non-numeric value for the EXIF GPSAltitudeRef tag, which is *supposed* to be set to either 0 and 1: https://exiftool.org/TagNames/GPS.html

As far as I can tell, the COOLPIX didn't even have GPS, so I don't know why it would be generating this tag in the first place. Anyway, patch forthcoming.

Change 639635 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[mediawiki/core@master] media: Support GPSAltitudeRef exif tag

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

Change 639505 had a related patch set uploaded (by Brennen Bearnes; owner: C. Scott Ananian):
[mediawiki/core@wmf/1.36.0-wmf.16] media: Support GPSAltitudeRef exif tag

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

Change 639505 merged by jenkins-bot:
[mediawiki/core@wmf/1.36.0-wmf.16] media: Support GPSAltitudeRef exif tag

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

Mentioned in SAL (#wikimedia-operations) [2020-11-05T23:29:38Z] <brennen@deploy1001> Synchronized php-1.36.0-wmf.16/languages/i18n/exif: Backport: [[gerrit:639505|media: Support GPSAltitudeRef exif tag - i18n/exif files (T267370)]] (duration: 01m 08s)

Mentioned in SAL (#wikimedia-operations) [2020-11-05T23:38:27Z] <brennen@deploy1001> Synchronized php-1.36.0-wmf.16/includes/media/FormatMetadata.php: Backport: [[gerrit:639505|media: Support GPSAltitudeRef exif tag - FormatMetData.php (T267370)]] (duration: 07m 22s)

So I looked into this a bit more, without the time pressure of being a train blocker.
Turns out that the images in question have perfectly valid GPSAltitudeRef tags:

>>> $e2 = BitmapMetadataHandler::Jpeg('/home/cananian/Downloads/Melaleuca_calycina.jpg');

=> [
     "ImageDescription" => "OLYMPUS DIGITAL CAMERA         ",
     "Make" => "OLYMPUS CORPORATION    ",
     "Model" => "TG-4            ",
[...]
     "GPSLatitude" => -33.629423333333,
     "GPSLongitude" => 120.14593833333,
     "GPSAltitudeRef" => "\0",
     "GPSStatus" => "A",
     "GPSImgDirectionRef" => "M",
     "GPSImgDirection" => "2400/100",
     "GPSVersionID" => "0.0.3.2",
   ]

Granted, the value is being reported as \0 and/or \1 instead of 0 or 1, but that is similar to how other "byte" fields in EXIF are reported by PHP. However, look what happens when that same file is accessed via instant commons:

>>> $f2 = RepoGroup::singleton()->findFile(Title::newFromText('File:Melaleuca_calycina.jpg'));
=> ForeignAPIFile {#3599
     +repo: ForeignAPIRepo {#2741
       +fetchDescription: true,
       +descriptionCacheExpiry: 43200,
       +name: "wikimediacommons",
     },
   }
>>> unserialize($f2->getMetadata());
=> [
     "ImageDescription" => "OLYMPUS DIGITAL CAMERA         ",
     "Make" => "OLYMPUS CORPORATION    ",
     "Model" => "TG-4            ",
     "Orientation" => 1,
[...]
     "GPSLatitude" => -33.629423333333,
     "GPSLongitude" => 120.14593833333,
     "GPSAltitudeRef" => "�",
     "GPSStatus" => "A",
     "GPSImgDirectionRef" => "M",
     "GPSImgDirection" => "2400/100",
     "GPSVersionID" => "0.0.3.2",
     "MEDIAWIKI_EXIF_VERSION" => 2,
   ]
>>>

Apparently there are two things going on here:

  1. In Exif.php we have the following code:
		if ( isset( $this->mFilteredExifData['GPSAltitude'] )
			&& isset( $this->mFilteredExifData['GPSAltitudeRef'] )
		) {
			// We know altitude data is a <num>/<denom> from the validation
			// functions ran earlier. But multiplying such a string by -1
			// doesn't work well, so convert.
			list( $num, $denom ) = explode( '/', $this->mFilteredExifData['GPSAltitude'] );
			$this->mFilteredExifData['GPSAltitude'] = $num / $denom;

			if ( $this->mFilteredExifData['GPSAltitudeRef'] === "\1" ) {
				$this->mFilteredExifData['GPSAltitude'] *= -1;
			}
			unset( $this->mFilteredExifData['GPSAltitudeRef'] );
		}

but for these files GPSAltitude is reported as 0/0 (aka invalid/missing) and so is deleted. The way this conditional is written, if GPSAltitude is removed, then GPSAltitudeRef will always stick around.

  1. When fetching foreign file metadata using ForeignAPIFile, the metadata is fetched with:
		$data = $repo->fetchImageQuery( [
			'titles' => 'File:' . $title->getDBkey(),
			'iiprop' => self::getProps(),
			'prop' => 'imageinfo',
			'iimetadataversion' => MediaHandler::getMetadataVersion(),
			// extmetadata is language-dependant, accessing the current language here
			// would be problematic, so we just get them all
			'iiextmetadatamultilang' => 1,
		] );

and you can see the output at:
https://commons.wikimedia.org/w/api.php?action=query&format=json&prop=imageinfo&titles=File%3AMelaleuca_calycina.jpg&iiprop=timestamp%7Cuser%7Ccomment%7Curl%7Csize%7Csha1%7Cmetadata%7Cmime%7Cmediatype%7Cextmetadata

{
    "batchcomplete": "",
    "query": {
        "normalized": [
            {
                "from": "File:Melaleuca_calycina.jpg",
                "to": "File:Melaleuca calycina.jpg"
            }
        ],
        "pages": {
            "73667274": {
                "pageid": 73667274,
                "ns": 6,
                "title": "File:Melaleuca calycina.jpg",
                "imagerepository": "local",
                "imageinfo": [
                    {
                        "timestamp": "2018-10-17T02:25:50Z",
                        "user": "Gderrin",
                        "size": 2974608,
                        "width": 4608,
                        "height": 3456,
                        "comment": "User created page with UploadWizard",
                        "url": "https://upload.wikimedia.org/wikipedia/commons/9/9a/Melaleuca_calycina.jpg",
                        "descriptionurl": "https://commons.wikimedia.org/wiki/File:Melaleuca_calycina.jpg",
                        "descriptionshorturl": "https://commons.wikimedia.org/w/index.php?curid=73667274",
                        "sha1": "5e36db0fef7d2d1bf91b76797b9be2816f567127",
                        "metadata": [
                            {
                                "name": "ImageDescription",
                                "value": "OLYMPUS DIGITAL CAMERA         "
                            },
[...]
                            {
                                "name": "GPSLatitude",
                                "value": -33.629423333333335
                            },
                            {
                                "name": "GPSLongitude",
                                "value": 120.14593833333333
                            },
                            {
                                "name": "GPSAltitudeRef",
                                "value": "\ufffd"
                            },
                            {
                                "name": "GPSStatus",
                                "value": "A"
                            },
                            {
                                "name": "GPSImgDirectionRef",
                                "value": "M"
                            },
                            {
                                "name": "GPSImgDirection",
                                "value": "2400/100"
                            },
                            {
                                "name": "GPSVersionID",
                                "value": "0.0.3.2"
                            },
                            {
                                "name": "MEDIAWIKI_EXIF_VERSION",
                                "value": 1
                            }
                        ],
[...]

Note that the \0 from the original metadata array has been "corrupted" to \uFFFD by the action API (and this happens in JSON, XML, PHP, and other API formats).

Most likely we should just be deleting the GPSAltitudeRef tag unconditionally, since it is always being handled as part of GPSAltitude. But if there are other EXIF tags which raw byte values (type self::UNDEFINED in Exif.php) then they will need to be processed into a form that can survive the transit across the imageinfo API.

Change 639834 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[mediawiki/core@master] media: Filter out GPSAltitudeRef exif tag

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

Change 639635 merged by jenkins-bot:
[mediawiki/core@master] media: Support GPSAltitudeRef exif tag

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

Change 639834 merged by jenkins-bot:
[mediawiki/core@master] media: Filter out GPSAltitudeRef exif tag

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

Change 640247 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[mediawiki/core@master] media: EXIF SubSecTime* are text not numeric

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

Change 640249 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[mediawiki/core@master] Temporarily disable EXIF non-numeric tag value warnings

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

Change 640254 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[operations/mediawiki-config@master] Turn on formatnum logging

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

Change 640248 had a related patch set uploaded (by C. Scott Ananian; owner: C. Scott Ananian):
[mediawiki/core@master] media: Support Google panorama EXIF extensions

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

Change 640247 merged by jenkins-bot:
[mediawiki/core@master] media: EXIF SubSecTime* are text not numeric

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

Change 640248 merged by jenkins-bot:
[mediawiki/core@master] media: Support Google panorama XMP properties

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

Change 640488 had a related patch set uploaded (by Brennen Bearnes; owner: C. Scott Ananian):
[mediawiki/core@wmf/1.36.0-wmf.16] Downgrade the severity of the non-numeric argument to formatNum warnings

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

Change 640249 merged by jenkins-bot:
[mediawiki/core@master] Downgrade the severity of the non-numeric argument to formatNum warnings

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

Change 640488 merged by jenkins-bot:
[mediawiki/core@wmf/1.36.0-wmf.16] Downgrade the severity of the non-numeric argument to formatNum warnings

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

Change 640254 merged by jenkins-bot:
[operations/mediawiki-config@master] Turn on formatnum logging

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

Mentioned in SAL (#wikimedia-operations) [2020-11-10T20:10:41Z] <brennen@deploy1001> Synchronized wmf-config/InitialiseSettings.php: Config: [[gerrit:640254|Turn on formatnum logging (T267587, T267370)]] (duration: 01m 02s)

Mentioned in SAL (#wikimedia-operations) [2020-11-10T20:27:25Z] <brennen@deploy1001> Started scap: Backport: [[gerrit:640487|language: Honor $wgTranslateNumerals, even if PHP does digit translation(T267614)]] and [[gerrit:640488|Downgrade the severity of the non-numeric argument to formatNum warnings (T267370, T267587)]]

Mentioned in SAL (#wikimedia-operations) [2020-11-10T21:02:06Z] <brennen@deploy1001> Finished scap: Backport: [[gerrit:640487|language: Honor $wgTranslateNumerals, even if PHP does digit translation(T267614)]] and [[gerrit:640488|Downgrade the severity of the non-numeric argument to formatNum warnings (T267370, T267587)]] (duration: 34m 46s)

xd0bx renamed this task from Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData] to olg_Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData調用].Jan 11 2021, 8:33 PM
xd0bx assigned this task to 001Decimation.
xd0bx set Request URL to https://gerrit.wikimedia.org/.
xd0bx changed Request ID from e4dbe964-e9fa-4f91-9e57-2a78aa36c24a to log_e4dbe964-e9fa-4f91-9e57-2a78aa36c24a.
xd0bx set Phatality ID to xd0bx.
xd0bx set Final Story Points to 4.

@xd0bx: did you intend to assign this to another user? Have you discussed with them?

RhinosF1 renamed this task from olg_Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData調用] to Use of FormatMetadata::formatNum with non-numeric value was deprecated in MediaWiki 1.36. [Called from FormatMetadata::makeFormattedData].Jan 11 2021, 8:38 PM
RhinosF1 removed 001Decimation as the assignee of this task.
RhinosF1 changed Request ID from log_e4dbe964-e9fa-4f91-9e57-2a78aa36c24a to e4dbe964-e9fa-4f91-9e57-2a78aa36c24a.
RhinosF1 removed Phatality ID.
RhinosF1 removed Final Story Points.
RhinosF1 removed Request URL.
RhinosF1 added a subscriber: 001Decimation.

@xd0bx: did you intend to assign this to another user? Have you discussed with them?

I've reverted your changes for now as they don't seem appropriate.

This comment was removed by Reedy.
BPirkle claimed this task.
BPirkle subscribed.

Not seeing any occurrences of this in Dec 2020 or Jan 2021. Resolving task, please reopen if necessary.

daniel subscribed.

Seeing a lot of these now, see T285213: High frequency production warning: FormatMetadata::formatNum with non-numeric value. Re-opening here for attention, close or merge as seems useful.

tstarling claimed this task.
tstarling subscribed.

As a logspam bug, it matters what kind of log is spammed, and the current errors are not deprecation warnings as originally reported here. In c79d3289f87131d7675cc9c1ad4c4291a40c0de5, cscott changed these errors from deprecation warnings to their own special log channel, writing: "Downgrade the severity of these logs permanently so we can track down unknown EXIF tags w/o flooding our logs w/ every bad image uploaded to commons." So for clinic duty purposes, the solution is to stop caring. We can configure MediaWiki to send these log entries to /dev/null if they are overwhelming logstash or something.