Skip to content
This repository has been archived by the owner on Apr 26, 2024. It is now read-only.

builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/[…]' #4379

Closed
ArchangeGabriel opened this issue Jan 12, 2019 · 16 comments · Fixed by #8236
Closed

builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/[…]' #4379

ArchangeGabriel opened this issue Jan 12, 2019 · 16 comments · Fixed by #8236
Labels
A-Media-Repository Uploading, downloading images and video, thumbnailing

Comments

@ArchangeGabriel
Copy link
Contributor

Description

Synapse log are spitting errors related to two images in local_content. They are both SVG.

Full excerpt:

synapse.http.server: [GET-9] Failed handle request via <function ThumbnailResource._async_render_GET at 0x6ecff9720d90>: <XForwardedForRequest at 0x6ecff5202320 method='GET' uri='/_matrix/media/v1/thumbnail/activis.me/TducGElbUrnYortubeohKFae?width=48&height=48&method=crop' clientproto='HTTP/1.1' site=8008>: Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 171, in _select_or_generate_local_thumbnail
    url_cache=media_info["url_cache"],
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1613, in unwindGenerator
    return _cancellableInlineCallbacks(gen)
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1529, in _cancellableInlineCallbacks
    _inlineCallbacks(None, g, status)
--- <exception caught here> ---
  File "/usr/lib/python3.7/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
    yield h(self, request)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 67, in _async_render_GET
    request, media_id, width, height, method, m_type
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 171, in _select_or_generate_local_thumbnail
    url_cache=media_info["url_cache"],
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/media_repository.py", line 466, in generate_local_exact_thumbnail
    thumbnailer = Thumbnailer(input_path)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnailer.py", line 32, in __init__
    self.image = Image.open(input_path)
  File "/usr/lib/python3.7/site-packages/PIL/Image.py", line 2657, in open
    % (filename if filename else fp))
builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/Td/uc/GElbUrnYortubeohKFae'
synapse.http.server: [GET-10] Failed handle request via <function ThumbnailResource._async_render_GET at 0x6ecff9720d90>: <XForwardedForRequest at 0x6ecff5202828 method='GET' uri='/_matrix/media/v1/thumbnail/activis.me/VryPzhdsbZOaAjkFUhTmRfqr?width=48&height=48&method=crop' clientproto='HTTP/1.1' site=8008>: Traceback (most recent call last):
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 171, in _select_or_generate_local_thumbnail
    url_cache=media_info["url_cache"],
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1613, in unwindGenerator
    return _cancellableInlineCallbacks(gen)
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1529, in _cancellableInlineCallbacks
    _inlineCallbacks(None, g, status)
--- <exception caught here> ---
  File "/usr/lib/python3.7/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
    yield h(self, request)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 67, in _async_render_GET
    request, media_id, width, height, method, m_type
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 171, in _select_or_generate_local_thumbnail
    url_cache=media_info["url_cache"],
  File "/usr/lib/python3.7/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
    result = g.send(result)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/media_repository.py", line 466, in generate_local_exact_thumbnail
    thumbnailer = Thumbnailer(input_path)
  File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnailer.py", line 32, in __init__
    self.image = Image.open(input_path)
  File "/usr/lib/python3.7/site-packages/PIL/Image.py", line 2657, in open
    % (filename if filename else fp))
builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/Vr/yP/zhdsbZOaAjkFUhTmRfqr'

Version information

  • Homeserver: mine
  • Version: 0.34.1.1
  • Install method: Package manager
  • Platform: ArchLinux
@ArchangeGabriel ArchangeGabriel changed the title builtins.OSError: cannot identify image file builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/[…]' builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/[…]' Jan 12, 2019
@ArchangeGabriel
Copy link
Contributor Author

Over 5 days, I have 25 MB of logs filled with those errors and some other ones related to the psql db used by synapse.

@ArchangeGabriel ArchangeGabriel mentioned this issue Feb 6, 2019
Closed
@Rilgamon
Copy link

Rilgamon commented Mar 3, 2019

Still happens in 0.99.2

Mar  3 11:59:38 my python[25802]: 2019-03-03 11:59:38,829 - synapse.http.server - 112 - ERROR - GET-431147- Failed handle request via 'ThumbnailResource': <SynapseRequest at 0x7f8dbc81d9e8 method='GET' uri='/_matrix/media/v1/thumbnail/kittenface.studio/LrFAxxyhBrbssLBlDaqohZYs?width=36&height=36&method=crop' clientproto='HTTP/1.0' site=8008>
Mar  3 11:59:38 my python[25802]: Traceback (most recent call last):
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Mar  3 11:59:38 my python[25802]:     result = g.send(result)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/storage/_base.py", line 460, in runWithConnection
Mar  3 11:59:38 my python[25802]:     defer.returnValue(result)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Mar  3 11:59:38 my python[25802]:     raise _DefGen_Return(val)
Mar  3 11:59:38 my python[25802]: twisted.internet.defer._DefGen_Return: []
Mar  3 11:59:38 my python[25802]: During handling of the above exception, another exception occurred:
Mar  3 11:59:38 my python[25802]: Traceback (most recent call last):
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Mar  3 11:59:38 my python[25802]:     result = g.send(result)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/storage/_base.py", line 418, in runInteraction
Mar  3 11:59:38 my python[25802]:     defer.returnValue(result)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Mar  3 11:59:38 my python[25802]:     raise _DefGen_Return(val)
Mar  3 11:59:38 my python[25802]: twisted.internet.defer._DefGen_Return: []
Mar  3 11:59:38 my python[25802]: During handling of the above exception, another exception occurred:
Mar  3 11:59:38 my python[25802]: Traceback (most recent call last):
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
Mar  3 11:59:38 my python[25802]:     yield h(self, request)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 78, in _async_render_GET
Mar  3 11:59:38 my python[25802]:     width, height, method, m_type
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 221, in _select_or_generate_remote_thumbnail
Mar  3 11:59:38 my python[25802]:     desired_height, desired_method, desired_type
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Mar  3 11:59:38 my python[25802]:     result = g.send(result)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/media_repository.py", line 509, in generate_remote_exact_thumbnail
Mar  3 11:59:38 my python[25802]:     thumbnailer = Thumbnailer(input_path)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/synapse/rest/media/v1/thumbnailer.py", line 32, in __init__
Mar  3 11:59:38 my python[25802]:     self.image = Image.open(input_path)
Mar  3 11:59:38 my python[25802]:   File "/opt/venvs/matrix-synapse/lib/python3.5/site-packages/PIL/Image.py", line 2687, in open
Mar  3 11:59:38 my python[25802]:     % (filename if filename else fp))
Mar  3 11:59:38 my python[25802]: OSError: cannot identify image file '/var/lib/matrix-synapse/media/remote_content/kittenface.studio/rZ/uS/OsBZwVpMVbbPWjWSDbAW'


root@grml:~# file /var/lib/matrix-synapse/media/remote_content/kittenface.studio/rZ/uS/OsBZwVpMVbbPWjWSDbAW
/var/lib/matrix-synapse/media/remote_content/kittenface.studio/rZ/uS/OsBZwVpMVbbPWjWSDbAW: SVG Scalable Vector Graphics image

@2Belette
Copy link

Not sure it is related but I have a similar here : #4594

@ArchangeGabriel ArchangeGabriel mentioned this issue Mar 19, 2019
Closed
@spantaleev
Copy link
Contributor

I can reproduce this with a png image file saved by GIMP 2.10.10.

Synapse is running in the official Docker image (matrixdotorg/synapse:v0.99.3-py3).

Here's the image file causing the problem:
synapse-cannot-identify-image (tiny gray image).

Traceback is like this:

Apr 15 10:39:46: Traceback (most recent call last):
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Apr 15 10:39:46: result = g.send(result)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/storage/_base.py", line 460, in runWithConnection
Apr 15 10:39:46: defer.returnValue(result)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Apr 15 10:39:46: raise _DefGen_Return(val)
Apr 15 10:39:46: twisted.internet.defer._DefGen_Return: None
Apr 15 10:39:46: During handling of the above exception, another exception occurred:
Apr 15 10:39:46: Traceback (most recent call last):
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Apr 15 10:39:46: result = g.send(result)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/storage/_base.py", line 418, in runInteraction
Apr 15 10:39:46: defer.returnValue(result)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Apr 15 10:39:46: raise _DefGen_Return(val)
Apr 15 10:39:46: twisted.internet.defer._DefGen_Return: None
Apr 15 10:39:46: During handling of the above exception, another exception occurred:
Apr 15 10:39:46: Traceback (most recent call last):
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Apr 15 10:39:46: result = g.send(result)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/storage/_base.py", line 524, in _simple_insert
Apr 15 10:39:46: defer.returnValue(True)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Apr 15 10:39:46: raise _DefGen_Return(val)
Apr 15 10:39:46: twisted.internet.defer._DefGen_Return: True
Apr 15 10:39:46: During handling of the above exception, another exception occurred:
Apr 15 10:39:46: Traceback (most recent call last):
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
Apr 15 10:39:46: yield h(self, request)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/rest/media/v1/upload_resource.py", line 95, in _async_render_POST
Apr 15 10:39:46: content_length, requester.user
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/rest/media/v1/media_repository.py", line 176, in create_content
Apr 15 10:39:46: None, media_id, media_id, media_type,
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Apr 15 10:39:46: result = g.send(result)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/rest/media/v1/media_repository.py", line 570, in _generate_thumbnails
Apr 15 10:39:46: thumbnailer = Thumbnailer(input_path)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/synapse/rest/media/v1/thumbnailer.py", line 32, in __init__
Apr 15 10:39:46: self.image = Image.open(input_path)
Apr 15 10:39:46: File "/usr/local/lib/python3.6/site-packages/PIL/Image.py", line 2687, in open
Apr 15 10:39:46: % (filename if filename else fp))
Apr 15 10:39:46: OSError: cannot identify image file '/matrix-media-store-parent/media-store/local_content/lv/MA/btpWBozlbXrTznCOvRvf'

@olmari
Copy link
Contributor

olmari commented Jun 10, 2019

I don't know is our problem related, but we get very similar result when a user through self-hosted appservice-slack tries to upload image to an bridged room.. TravisR from #bridging:matrix.org suggested this issue might relate, hence I tag along.

Our synapse side log from the event:

Jun 10 17:44:39 matrix matrix-synapse[2854]: 2019-06-10 17:44:39,673 - synapse.http.server - 112 - ERROR - POST-945159- Failed handle request via 'UploadResource': <XForwardedForRequest at 0x7f3fa03ab390 method='POST' uri='/_matrix/media/v1/upload?filename=lvl4_sysadmin.jpg&access_token=<redacted>&user_id=%40slack_helsinkihacklab_U4WGM6FNG%3Ahacklab.fi' clientproto='HTTP/1.1' site=8008>
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/storage/_base.py", line 527, in runWithConnection
Jun 10 17:44:39 matrix matrix-synapse[2854]:     defer.returnValue(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Jun 10 17:44:39 matrix matrix-synapse[2854]:     raise _DefGen_Return(val)
Jun 10 17:44:39 matrix matrix-synapse[2854]: twisted.internet.defer._DefGen_Return: None
Jun 10 17:44:39 matrix matrix-synapse[2854]: During handling of the above exception, another exception occurred:
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/storage/_base.py", line 487, in runInteraction
Jun 10 17:44:39 matrix matrix-synapse[2854]:     defer.returnValue(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Jun 10 17:44:39 matrix matrix-synapse[2854]:     raise _DefGen_Return(val)
Jun 10 17:44:39 matrix matrix-synapse[2854]: twisted.internet.defer._DefGen_Return: None
Jun 10 17:44:39 matrix matrix-synapse[2854]: During handling of the above exception, another exception occurred:
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/storage/_base.py", line 586, in _simple_insert
Jun 10 17:44:39 matrix matrix-synapse[2854]:     defer.returnValue(True)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Jun 10 17:44:39 matrix matrix-synapse[2854]:     raise _DefGen_Return(val)
Jun 10 17:44:39 matrix matrix-synapse[2854]: twisted.internet.defer._DefGen_Return: True
Jun 10 17:44:39 matrix matrix-synapse[2854]: During handling of the above exception, another exception occurred:
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
Jun 10 17:44:39 matrix matrix-synapse[2854]:     yield h(self, request)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/upload_resource.py", line 95, in _async_render_POST
Jun 10 17:44:39 matrix matrix-synapse[2854]:     content_length, requester.user
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/media_repository.py", line 176, in create_content
Jun 10 17:44:39 matrix matrix-synapse[2854]:     None, media_id, media_id, media_type,
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/media_repository.py", line 573, in _generate_thumbnails
Jun 10 17:44:39 matrix matrix-synapse[2854]:     thumbnailer = Thumbnailer(input_path)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/thumbnailer.py", line 43, in __init__
Jun 10 17:44:39 matrix matrix-synapse[2854]:     self.image = Image.open(input_path)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/PIL/Image.py", line 2705, in open
Jun 10 17:44:39 matrix matrix-synapse[2854]:     % (filename if filename else fp))
Jun 10 17:44:39 matrix matrix-synapse[2854]: OSError: cannot identify image file '/var/lib/matrix-synapse-media/local_content/au/Bj/lkdbqqEnaipXMHZPyerb'
Jun 10 17:44:39 matrix matrix-synapse[2854]: 2019-06-10 17:44:39,735 - synapse.http.server - 112 - ERROR - POST-945160- Failed handle request via 'UploadResource': <XForwardedForRequest at 0x7f3f6d6987b8 method='POST' uri='/_matrix/media/v1/upload?filename=lvl4_sysadmin.jpg_thumb.jpeg&access_token=<redacted>&user_id=%40slack_helsinkihacklab_U4WGM6FNG%3Ahacklab.fi' clientproto='HTTP/1.1' site=8008>
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/storage/_base.py", line 527, in runWithConnection
Jun 10 17:44:39 matrix matrix-synapse[2854]:     defer.returnValue(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Jun 10 17:44:39 matrix matrix-synapse[2854]:     raise _DefGen_Return(val)
Jun 10 17:44:39 matrix matrix-synapse[2854]: twisted.internet.defer._DefGen_Return: None
Jun 10 17:44:39 matrix matrix-synapse[2854]: During handling of the above exception, another exception occurred:
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/storage/_base.py", line 487, in runInteraction
Jun 10 17:44:39 matrix matrix-synapse[2854]:     defer.returnValue(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Jun 10 17:44:39 matrix matrix-synapse[2854]:     raise _DefGen_Return(val)
Jun 10 17:44:39 matrix matrix-synapse[2854]: twisted.internet.defer._DefGen_Return: None
Jun 10 17:44:39 matrix matrix-synapse[2854]: During handling of the above exception, another exception occurred:
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/storage/_base.py", line 586, in _simple_insert
Jun 10 17:44:39 matrix matrix-synapse[2854]:     defer.returnValue(True)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1362, in returnValue
Jun 10 17:44:39 matrix matrix-synapse[2854]:     raise _DefGen_Return(val)
Jun 10 17:44:39 matrix matrix-synapse[2854]: twisted.internet.defer._DefGen_Return: True
Jun 10 17:44:39 matrix matrix-synapse[2854]: During handling of the above exception, another exception occurred:
Jun 10 17:44:39 matrix matrix-synapse[2854]: Traceback (most recent call last):
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/http/server.py", line 81, in wrapped_request_handler
Jun 10 17:44:39 matrix matrix-synapse[2854]:     yield h(self, request)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/upload_resource.py", line 95, in _async_render_POST
Jun 10 17:44:39 matrix matrix-synapse[2854]:     content_length, requester.user
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/media_repository.py", line 176, in create_content
Jun 10 17:44:39 matrix matrix-synapse[2854]:     None, media_id, media_id, media_type,
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
Jun 10 17:44:39 matrix matrix-synapse[2854]:     result = g.send(result)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/media_repository.py", line 573, in _generate_thumbnails
Jun 10 17:44:39 matrix matrix-synapse[2854]:     thumbnailer = Thumbnailer(input_path)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/thumbnailer.py", line 43, in __init__
Jun 10 17:44:39 matrix matrix-synapse[2854]:     self.image = Image.open(input_path)
Jun 10 17:44:39 matrix matrix-synapse[2854]:   File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/PIL/Image.py", line 2705, in open
Jun 10 17:44:39 matrix matrix-synapse[2854]:     % (filename if filename else fp))
Jun 10 17:44:39 matrix matrix-synapse[2854]: OSError: cannot identify image file '/var/lib/matrix-synapse-media/local_content/uo/FG/LfUqgFyXxJoZiiUXjMDf'

and same event stuff from appservice-slack log:

Jun 10 17:44:38 matrix node[7689]: Jun-10 17:44:38.870 INFO SlackGhost Updating user information for U4WGM6FNG
Jun 10 17:44:38 matrix node[7689]: Jun-10 17:44:38.870 INFO substitutions running substitutions on: filu
Jun 10 17:44:39 matrix node[7689]: Returning the raw JSON from uploadContent(). Future versions of the js-sdk will change this default, to return the parsed object. Set opts.rawResponse=false to change this behaviour now.
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.659 INFO bridge [-] POST http://localhost:8008/_matrix/media/v1/upload (@slack_helsinkihacklab_U4WGM6FNG:hacklab.fi) Body: {"type":"Buffer","data":[60,33,68,79,67,84,89,80,69,32,104,116,109,108,62,60,104
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.681 ERROR bridge [-] POST http://localhost:8008/_matrix/media/v1/upload (@slack_helsinkihacklab_U4WGM6FNG:hacklab.fi) HTTP 500 Error: "{\"errcode\":\"M_UNKNOWN\",\"error\":\"Internal server error\"}"
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.682 ERROR SlackGhost Failed to upload content:
Jun 10 17:44:39 matrix node[7689]: %s { [M_UNKNOWN: Internal server error]
Jun 10 17:44:39 matrix node[7689]:   errcode: 'M_UNKNOWN',
Jun 10 17:44:39 matrix node[7689]:   name: 'M_UNKNOWN',
Jun 10 17:44:39 matrix node[7689]:   message: 'Internal server error',
Jun 10 17:44:39 matrix node[7689]:   data: { errcode: 'M_UNKNOWN', error: 'Internal server error' },
Jun 10 17:44:39 matrix node[7689]:   httpStatus: 500 }
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.682 ERROR SlackEventHandler Failed to handle slack event:  { [M_UNKNOWN: Internal server error]
Jun 10 17:44:39 matrix node[7689]:   errcode: 'M_UNKNOWN',
Jun 10 17:44:39 matrix node[7689]:   name: 'M_UNKNOWN',
Jun 10 17:44:39 matrix node[7689]:   message: 'Internal server error',
Jun 10 17:44:39 matrix node[7689]:   data: { errcode: 'M_UNKNOWN', error: 'Internal server error' },
Jun 10 17:44:39 matrix node[7689]:   httpStatus: 500 }
Jun 10 17:44:39 matrix node[7689]: Returning the raw JSON from uploadContent(). Future versions of the js-sdk will change this default, to return the parsed object. Set opts.rawResponse=false to change this behaviour now.
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.720 INFO bridge [-] POST http://localhost:8008/_matrix/media/v1/upload (@slack_helsinkihacklab_U4WGM6FNG:hacklab.fi) Body: {"type":"Buffer","data":[60,33,68,79,67,84,89,80,69,32,104,116,109,108,62,60,104
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.740 ERROR bridge [-] POST http://localhost:8008/_matrix/media/v1/upload (@slack_helsinkihacklab_U4WGM6FNG:hacklab.fi) HTTP 500 Error: "{\"errcode\":\"M_UNKNOWN\",\"error\":\"Internal server error\"}"
Jun 10 17:44:39 matrix node[7689]: Jun-10 17:44:39.741 ERROR SlackGhost Failed to upload content:
Jun 10 17:44:39 matrix node[7689]: %s { [M_UNKNOWN: Internal server error]
Jun 10 17:44:39 matrix node[7689]:   errcode: 'M_UNKNOWN',
Jun 10 17:44:39 matrix node[7689]:   name: 'M_UNKNOWN',
Jun 10 17:44:39 matrix node[7689]:   message: 'Internal server error',
Jun 10 17:44:39 matrix node[7689]:   data: { errcode: 'M_UNKNOWN', error: 'Internal server error' },
Jun 10 17:44:39 matrix node[7689]:   httpStatus: 500 }
Jun 10 17:44:39 matrix node[7689]: Unhandled rejection M_UNKNOWN: Internal server error

@lnicola
Copy link

lnicola commented Jun 11, 2019

See also element-hq/element-web#10010, which may or may not be related.

@olmari
Copy link
Contributor

olmari commented Jun 11, 2019

I don't just want to delete my post, so I'll do status update for our thing which might not be related after all: I think our situation is somehow appservice-slack bot user having no correct rights to show nor get files, this it pushes "log in to slack" webpage into the image file to be.. and everything failing because of that....

@Torxed
Copy link

Torxed commented Aug 20, 2019 •
edited
Loading

Same error still. version 0.34.1.1

2019-08-20 12:43:56 - synapse.http.server - 112 - ERROR - POST-420375- Failed to handle request via <function UploadResource._async_render_POST at 0x00000>: <SynapseRequest at 0x000 method='POST' uri='/_matrix_media/v1/upload?filename=2019-08-20-124159_scrot.png' clientproto='HTTP/1.0' site=8008>: Traceback:

File "/usr/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnailer.py", line 32, in __init__
    self.image = Image.open(input_path)
File "/usr/lib/python3.7/site-packages/PIL/Image.py", line 2687, in open
    % (filename if filename else fp))
builtins.OSError: cannot identify image file '/var/lib/synapse/media_store/local_content/JQ/LQ/iBuKdmLxMQ'

I should mention that this is only happening on some devices, my phone works (been logged in since forever), my dual-boot PC works on one OS but not the other. It seams tied to when you logged in with the account. Older logins work.

@spantaleev
Copy link
Contributor

@Torxed, that's a pretty old Synapse version.

Upgrading to Synapse v1.0+ is of grave importance, especially if you expect your server to federate with others.

Perhaps the above error has been fixed there, due to some dependency getting upgraded, etc.
Perhaps not.. In any case, bug reports from such outdated versions are not very useful.

@Torxed
Copy link

Torxed commented Aug 20, 2019 •
edited
Loading

@Torxed, that's a pretty old Synapse version.

Upgrading to Synapse v1.0+ is of grave importance, especially if you expect your server to federate with others.

Perhaps the above error has been fixed there, due to some dependency getting upgraded, etc.
Perhaps not.. In any case, bug reports from such outdated versions are not very useful.

Done, same issue. now running version 1.2.1-1 :)

Sadly I can't copy paste text for some reason at the moment.
So against my better judgement, here's a traceback in the shape of a PNG file:

2019-08-20-130245_2580x1004_scrot

Looking at the file that was "uploaded", the contents of it is:

function stream() { [native code] }

So I'm guessing it's the front-end that's messing things up. Because that's some JavaScript jibberish.

@Torxed
Copy link

Torxed commented Aug 20, 2019

Yepp, updating the UI (front-end) solved the problem.
No idea what fixed it, since the patch notes doesn't seam to mention anything about this issue.

@ArchangeGabriel
Copy link
Contributor Author

The issue is not fixed for me, on Synapse 1.2.1 too.

@swedneck
Copy link

Just ran into this as well, image is a PNG exported by gimp 2.10.12

@volka
Copy link

volka commented Aug 23, 2019 •
edited
Loading

I see the same issue when uploading a file via Chrome. Uploading the same image file in Firefox works just fine, so I guess it's not a problem of the image data.

Client is riot 1.2.1, server synapse 1.3.1. (updated: tested with riot 1.3.3, same result)

Here is the trace of the error:

2019-08-23 15:20:03,477 - synapse.access.http.8008 - 233 - INFO - POST-5064- ::ffff:127.0.0.1 - 8008 - Received request: POST /_matrix/media/v1/upload?filename=test.png
2019-08-23 15:20:03,483 - synapse.rest.media.v1.media_repository - 162 - INFO - POST-5064- Stored local media in file '/var/lib/matrix-synapse/media/local_content/Md/PY/LtseHjYDIqYqotlVIikN'
2019-08-23 15:20:03,502 - synapse.http.server - 108 - ERROR - POST-5064- Failed handle request via 'UploadResource': <SynapseRequest at 0x7f7d1a4c9b38 method='POST' uri='/_matrix/media/v1/upload?filename=test.png' clientproto='HTTP/1.0' site=8008>
Traceback (most recent call last):
File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
result = g.send(result)
StopIteration

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
result = g.send(result)
StopIteration

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/twisted/internet/defer.py", line 1418, in _inlineCallbacks
result = g.send(result)
StopIteration: True

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/http/server.py", line 76, in wrapped_request_handler
await h(self, request)
File "/opt/venvs/matrix-synapse/lib/python3.6/site-packages/synapse/rest/media/v1/upload_resource.py", line 82, in _async_render_POST
media_type, upload_name, request.content, content_length, requester.user
OSError: cannot identify image file '/var/lib/matrix-synapse/media/local_content/Md/PY/LtseHjYDIqYqotlVIikN'

Same file uploaded from Firefox:

2019-08-23 15:24:45,304 - synapse.access.http.8008 - 233 - INFO - POST-5574- ::ffff:127.0.0.1 - 8008 - Received request: POST /_matrix/media/v1/upload
2019-08-23 15:24:45,307 - synapse.rest.media.v1.media_repository - 162 - INFO - POST-5574- Stored local media in file '/var/lib/matrix-synapse/media/local_content/Hw/CN/ICRiomnKyRWGtKDkvdqr'
2019-08-23 15:24:45,576 - synapse.rest.media.v1.upload_resource - 85 - INFO - POST-5574- Uploaded content with URI 'mxc://matrix.xxx.de/HwCNICRiomnKyRWGtKDkvdqr'
2019-08-23 15:24:45,577 - synapse.access.http.8008 - 302 - INFO - POST-5574- ::ffff:127.0.0.1 - 8008 - {@xxx:matrix.xxxde} Processed request: 0.272sec/0.000sec (0.184sec, 0.001sec) (0.002sec/0.059sec/6) 68B 200 "POST /_matrix/media/v1/upload HTTP/1.0" "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0" [0 dbevts]
2019-08-23 15:24:45,732 - synapse.access.http.8008 - 233 - INFO - POST-5575- ::ffff:127.0.0.1 - 8008 - Received request: POST /_matrix/media/v1/upload?filename=test.png
2019-08-23 15:24:45,734 - synapse.rest.media.v1.media_repository - 162 - INFO - POST-5575- Stored local media in file '/var/lib/matrix-synapse/media/local_content/pI/Dl/fLAZlVnAIYqMrsiZSgcR'
2019-08-23 15:24:46,005 - synapse.rest.media.v1.upload_resource - 85 - INFO - POST-5575- Uploaded content with URI 'mxc://matrix.xxx.de/pIDlfLAZlVnAIYqMrsiZSgcR'
2019-08-23 15:24:46,006 - synapse.access.http.8008 - 302 - INFO - POST-5575- ::ffff:127.0.0.1 - 8008 - {@xxx:matrix.xxx.de} Processed request: 0.274sec/0.000sec (0.216sec, 0.005sec) (0.002sec/0.028sec/6) 68B 200 "POST /_matrix/media/v1/upload?filename=test.png HTTP/1.0" "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0" [0 dbevts]
2019-08-23 15:24:46,123 - synapse.access.http.8008 - 233 - INFO - GET-5576- ::ffff:127.0.0.1 - 8008 - Received request: GET /_matrix/media/v1/thumbnail/matrix.xxx.de/pIDlfLAZlVnAIYqMrsiZSgcR?width=800&height=600
2019-08-23 15:24:46,128 - synapse.access.http.8008 - 302 - INFO - GET-5576- ::ffff:127.0.0.1 - 8008 - {None} Processed request: 0.005sec/-0.000sec (0.001sec, 0.000sec) (0.001sec/0.002sec/2) 205002B 200 "GET /_matrix/media/v1/thumbnail/matrix.xxx.de/pIDlfLAZlVnAIYqMrsiZSgcR?width=800&height=600 HTTP/1.0" "Mozilla/5.0 (Windows NT 6.1; Win64; x64; rv:68.0) Gecko/20100101 Firefox/68.0" [0 dbevts]
2019-08-23 15:24:46,158 - synapse.access.http.8008 - 233 - INFO - PUT-5577- ::ffff:127.0.0.1 - 8008 - Received request: PUT /_matrix/client/r0/rooms/!OKXdIjyQauPsuaqqvS%3Amatrix.xxx.de/send/m.room.message/m1566566686387.0

This seems to be reproducibly bound to the browser / client doing the upload.

@gfiury
Copy link

gfiury commented Dec 13, 2019

At some point the OS cannot identify the files anymore. https://stackoverflow.com/questions/56968200/python-oserror-cannot-identify-image-file.

Matrix writes the file, but it is corrupt (empty I think), so the PLI cannot identify an image or pdf (no matter the extension). Microsoft Edge works fine uploading the file, but not for Chrome and Firefox.

We have two servers that were working fine for several months and suddenly this error came out. We didn't change the configuration or permissions. The only thing that changed were the Browsers versions.

We are going to keep investigating

@xsteadfastx
Copy link
Contributor

anything new about this?

@richvdh richvdh added the A-Media-Repository Uploading, downloading images and video, thumbnailing label Apr 24, 2020
@clokep clokep mentioned this issue Sep 2, 2020
Merged
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
A-Media-Repository Uploading, downloading images and video, thumbnailing
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

Do not error when thumbnailing invalid files matrix-org/synapse