This error was encountered when converting an SVG file to PNG. At first it looked like it was related to our changes of exiftool calling, but in reality it turns out that when rsvg-convert encounters a file with some formatting it doesn't like (such as CSS parsing issues, quite common) on buster it will now output the error messages to stdout where it previously output them to stderr.
Image path: /wikipedia/commons/thumb/0/01/Logo_Belvedere_Vodka.svg/1920px-Logo_Belvedere_Vodka.svg.png
error:
2023-04-14 11:18:43,872 ???? thumbor:DEBUG [SWIFT_LOADER] writing 13342 bytes to temp file
2023-04-14 11:18:43,878 ???? thumbor:DEBUG [SWIFT_LOADER] return_contents: /tmp/tmpatf10hrv
2023-04-14 11:18:43,879 ???? thumbor:DEBUG [Proxy] load: '.svg'
2023-04-14 11:18:43,879 ???? thumbor:DEBUG [Proxy] Looking for a svg engine
2023-04-14 11:18:43,885 ???? thumbor:DEBUG [BWE] Found source file in context
2023-04-14 11:18:43,892 ???? thumbor:DEBUG [ShellRunner] Command: ['/usr/bin/timeout', '--foreground', '59', '/usr/bin/rsvg-convert', '/tmp/tmpatf10hrv', '-u', '-f', 'png', '-w', '1920']
2023-04-14 11:18:44,014 ???? thumbor:DEBUG [ShellRunner] Stdout: <too long to display (56042 bytes)>
2023-04-14 11:18:44,021 ???? thumbor:DEBUG [ShellRunner] Stderr: b''
2023-04-14 11:18:44,027 ???? thumbor:DEBUG [ShellRunner] Return code: 0
2023-04-14 11:18:44,033 ???? thumbor:DEBUG [ShellRunner] Duration: 121.43299999999999
2023-04-14 11:18:44,039 ???? thumbor:DEBUG [IM] Dumping buffer into temp file
2023-04-14 11:18:44,046 ???? thumbor:DEBUG [IM] Could not read EXIF with pyexiv2
2023-04-14 11:18:44,053 ???? thumbor:DEBUG [ExiftoolRunner] command: ['/usr/bin/exiftool', '-j', '-ImageSize', '-ProfileDescription', '-ColorType', '-FileType', '-Transparency', '-Artist', '-Copyright', '-ImageDescription', '-m', '-q', '-q', '/tmp/tmpjf2txa8x']
2023-04-14 11:18:44,059 ???? 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/tmpjf2txa8x']
2023-04-14 11:18:44,189 ???? thumbor:DEBUG [ShellRunner] Stdout: b'[{\n "SourceFile": "/tmp/tmpjf2txa8x"\n}]\n'
2023-04-14 11:18:44,195 ???? thumbor:DEBUG [ShellRunner] Stderr: b'Error: Unknown file type - /tmp/tmpjf2txa8x\n'
2023-04-14 11:18:44,201 ???? thumbor:DEBUG [ShellRunner] Return code: 1
2023-04-14 11:18:44,207 ???? thumbor:DEBUG [ShellRunner] Duration: 128.577
2023-04-14 11:18:44,214 ???? thumbor:ERROR [ExiftoolRunner] error: b'Error: Unknown file type - /tmp/tmpjf2txa8x\n'
2023-04-14 11:18:44,220 ???? thumbor:DEBUG [IM] EXIF: {'SourceFile': '/tmp/tmpjf2txa8x'}
2023-04-14 11:18:44,226 ???? thumbor:DEBUG [IM] File has no ICC profile
2023-04-14 11:18:44,233 ???? thumbor:DEBUG [IM] reorientate
2023-04-14 11:18:44,239 ???? thumbor:DEBUG [IM] resize: 1920.0 1920.0
2023-04-14 11:18:44,247 ???? thumbor:ERROR KeyError: 'ImageSize'
2023-04-14 11:18:44,247 ???? thumbor:ERROR ERROR: Traceback (most recent call last):
File "/opt/lib/python/site-packages/tornado/web.py", line 1713, in _execute
result = await result
File "/opt/lib/python/site-packages/thumbor/handlers/imaging.py", line 119, in get
return await self.check_image(kw)
File "/srv/service/wikimedia_thumbor/handler/images/images.py", line 464, in check_image
await self.execute_image_operations()
File "/opt/lib/python/site-packages/thumbor/handlers/__init__.py", line 203, in execute_image_operations
await self.get_image()
File "/opt/lib/python/site-packages/thumbor/handlers/__init__.py", line 300, in get_image
await self.context.transformer.transform()
File "/opt/lib/python/site-packages/thumbor/transformer.py", line 38, in transform
await self.do_image_operations()
File "/opt/lib/python/site-packages/thumbor/transformer.py", line 221, in do_image_operations
operation=self.img_operation_worker,
File "/opt/lib/python/site-packages/thumbor/threadpool.py", line 53, in queue
return await self._execute_in_foreground(operation, *args)
File "/opt/lib/python/site-packages/thumbor/threadpool.py", line 45, in _execute_in_foreground
return operation(*args)
File "/opt/lib/python/site-packages/thumbor/transformer.py", line 243, in img_operation_worker
self.resize()
File "/opt/lib/python/site-packages/thumbor/transformer.py", line 357, in resize
self.target_width or 1, self.target_height or 1
File "/srv/service/wikimedia_thumbor/engine/proxy/proxy.py", line 179, in resize
return self.__getattr__('resize')(width, height)
File "/srv/service/wikimedia_thumbor/engine/imagemagick/imagemagick.py", line 385, in resize
exif_image_size = self.exif_dict['ImageSize']
KeyError: 'ImageSize'
2023-04-14 11:18:44,247 ???? tornado.access:ERROR 500 GET /wikipedia/commons/thumb/0/01/Logo_Belvedere_Vodka.svg/1920px-Logo_Belvedere_Vodka.svg.png (10.64.16.55) 810.10msOn Buster:
root@3550d84927cc:/srv/service# /usr/bin/rsvg-convert Logo_Belvedere_Vodka.svg -u -f png -w 1920 > /tmp/output.png root@3550d84927cc:/srv/service# head -n2 /tmp/output.png CSS parsing error PNG root@3550d84927cc:/srv/service# rsvg-convert --version rsvg-convert version 2.44.10
exiftool does not like the above file because it's not a valid png with the extra text.
On stretch:
hnowlan@thumbor1001:~$ rsvg-convert Logo_Belvedere_Vodka.svg -u -f png -w 1920 > Logo_Belvedere_Vodka.svg.png (rsvg-convert:4019): librsvg-WARNING **: CSS parsing error hnowlan@thumbor1001:~$ head -n2 Logo_Belvedere_Vodka.svg.png PNG hnowlan@thumbor1001:~$ rsvg-convert --version rsvg-convert version 2.40.21
Capturing output from stdout is somewhat brittle anyway when we can use an explicit -o handler, so we should do that. But this also seems like a bug with the upstream tool itself.