Maniphest T331995

Error reading image metadata: unhashable type: 'slice'
Closed, ResolvedPublic
Actions

Assigned To

Authored By

	hnowlan
	Mar 14 2023, 12:50 PM

Description

This error is showing up in Thumbor logs.

This error text comes from Thumbor itself.

Details

	Subject	Repo	Branch	Lines +/-
	thumbor: bump image	operations/deployment-charts	master	+1 -1
	imagemagick: rename self.exif to self.exif_dict	operations/software/thumbor-plugins	master	+25 -25

Customize query in gerrit

Related Objects

Mentioned In: T332686: Reevaluate EXIF behaviours in imagemagick.py

Event Timeline

hnowlan created this task.Mar 14 2023, 12:50 PM

Restricted Application added a subscriber: Aklapper. · View Herald TranscriptMar 14 2023, 12:50 PM

hnowlan claimed this task.Mar 14 2023, 12:51 PM

hnowlan added a project: Platform Team Workboards (Platform Engineering Reliability).

hnowlan moved this task from Backlog to Onboarding 🚀 on the Platform Team Workboards (Platform Engineering Reliability) board.Mar 14 2023, 1:45 PM

This is possibly a non-fatal error that has been happening all along but was otherwise ignored until we bumped thumbor version. This error comes from a call to piexif, which was introduced in a more recent version. It appears that we only induce this error during the intermediate step of conversion - for example seen here between jpg and png:

2023-03-20 12:51:08,809 ???? thumbor:DEBUG [Proxy] load: '.jpg'
2023-03-20 12:51:08,809 ???? thumbor:DEBUG [Proxy] Looking for a jpg engine
2023-03-20 12:51:08,816 ???? thumbor:DEBUG [IM] Grabbing filename from context                                                                                                                                                                                                                                                                                              2023-03-20 12:51:08,823 ???? thumbor:DEBUG [ExiftoolRunner] command: ['/usr/bin/exiftool', '-j', '-ImageSize', '-ProfileDescription', '-ColorType', '-FileType', '-Transparency', '-Artist', '-Copyright', '-ImageDescription', '-m', '-q', '-q', '/tmp/tmpx1ji0ybl']
2023-03-20 12:51:08,829 ???? thumbor:DEBUG [ShellRunner] Command: ['/usr/bin/timeout', '--foreground', '59', '/usr/bin/exiftool', '-j', '-ImageSize', '-ProfileDescription', '-ColorType', '-FileType', '-Transparency', '-Artist', '-Copyright', '-ImageDescription', '-m', '-q', '-q', '/tmp/tmpx1ji0ybl']
2023-03-20 12:51:08,981 ???? thumbor:DEBUG [ShellRunner] Stdout: b'[{\n  "SourceFile": "/tmp/tmpx1ji0ybl",\n  "ImageSize": "2847x1197",\n  "FileType": "JPEG",\n  "ImageDescription": ""\n}]\n'
2023-03-20 12:51:08,990 ???? thumbor:DEBUG [ShellRunner] Stderr: b''
2023-03-20 12:51:08,997 ???? thumbor:DEBUG [ShellRunner] Return code: 0
2023-03-20 12:51:09,003 ???? thumbor:DEBUG [ShellRunner] Duration: 142.049
2023-03-20 12:51:09,009 ???? thumbor:DEBUG [IM] EXIF: {'Pyexiv2Orientation': 1, 'SourceFile': '/tmp/tmpx1ji0ybl', 'ImageSize': '2847x1197', 'FileType': 'JPEG', 'ImageDescription': ''}
2023-03-20 12:51:09,015 ???? thumbor:DEBUG [IM] File has no ICC profile
2023-03-20 12:51:09,015 ???? thumbor:ERROR Error reading image metadata: unhashable type: 'slice'
2023-03-20 12:51:09,021 ???? thumbor:DEBUG [IM] reorientate
2023-03-20 12:51:09,027 ???? thumbor:DEBUG [IM] resize: 240.0 101.0
2023-03-20 12:51:09,033 ???? thumbor:DEBUG [IM] jpeg:size hint: '480x202'
2023-03-20 12:51:09,039 ???? thumbor:DEBUG [IM] Queued operators: ['-define', 'jpeg:size=480x202', '-resize', '240x101^', '-gravity', 'center', '-extent', '240x101']
2023-03-20 12:51:09,039 ???? thumbor:DEBUG [conditional_sharpen] width fallback
2023-03-20 12:51:09,039 ???? thumbor:DEBUG [conditional_sharpen] height fallback
2023-03-20 12:51:09,039 ???? thumbor:DEBUG [conditional_sharpen] Original size: 2847x1197 Target size: 240x101
2023-03-20 12:51:09,039 ???? thumbor:DEBUG [conditional_sharpen] apply unsharp mask
2023-03-20 12:51:09,045 ???? thumbor:DEBUG [IM] Queued operators: ['-define', 'jpeg:size=480x202', '-resize', '240x101^', '-gravity', 'center', '-extent', '240x101', '-unsharp', '0.000000x0.800000+1.000000+0.000000']
2023-03-20 12:51:09,045 ???? thumbor:DEBUG Format specified: png
2023-03-20 12:51:09,046 ???? thumbor:DEBUG Image format specified as .png.
2023-03-20 12:51:09,046 ???? thumbor:DEBUG Content Type of image/png detected.
2023-03-20 12:51:09,052 ???? thumbor:DEBUG [IM] read: .png 87
2023-03-20 12:51:09,057 ???? thumbor:DEBUG [IM] Chroma subsampling: '4:2:0'
2023-03-20 12:51:09,063 ???? thumbor:DEBUG [IM] Generating image with quality 95
2023-03-20 12:51:09,069 ???? thumbor:DEBUG [IM] Queued operators: ['-define', 'jpeg:size=480x202', '-resize', '240x101^', '-gravity', 'center', '-extent', '240x101', '-unsharp', '0.000000x0.800000+1.000000+0.000000', '-quality', '95', '-sampling-factor', '4:2:0']
2023-03-20 12:51:09,075 ???? thumbor:DEBUG [ShellRunner] Command: ['/usr/bin/timeout', '--foreground', '59', '/usr/bin/convert', '-define', 'tiff:exif-properties=no', '-define', 'jpeg:size=480x202', '-resize', '240x101^', '-gravity', 'center', '-extent', '240x101', '-unsharp', '0.000000x0.800000+1.000000+0.000000', '-quality', '95', '-sampling-factor', '4:2:0',
'/tmp/tmpx1ji0ybl[0]', 'png:-']

Contrary to the initial report, this issue _is_ reproducible in staging. Note the error appears after the image has been converted once, showing much simpler exif data in the [IM] EXIF line. Even if this turns out to be a relatively harmless error, it's noise that is consistently showing up in the production logs and is potentially misleading.

hnowlan updated the task description. (Show Details)Mar 20 2023, 12:58 PM

We're accidentally triggering this code path by populating self.exif in engine.imagemagick. We load self.exif with the output of exiftool as a dictionary - this was fine up until we bumped Thumbor. self.exif is now used as part of the load() function (although self.exif was previously used elsewhere and we could have hit this before now) and there is a type clash. We should rename self.exif to something like self.exif_dict in thumbor-plugins to remedy this.