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

Consecutive remote media thumbnail requests with different methods fails #8649

Closed
vurpo opened this issue Oct 25, 2020 · 15 comments · Fixed by #9725
Closed

Consecutive remote media thumbnail requests with different methods fails #8649

vurpo opened this issue Oct 25, 2020 · 15 comments · Fixed by #9725
Labels
z-bug (Deprecated Label) Z-Help-Wanted We know exactly how to fix this issue, and would be grateful for any contribution

Comments

@vurpo
Copy link

vurpo commented Oct 25, 2020

Description

It seems like the method column is missing on the unique constraint on remote_media_cache_thumbnails, causing internal server errors when trying to fetch the same size of the same thumbnail with different methods.

Steps to reproduce

  • Fetch a thumbnail of a remote image using some specific size and method (scale or crop).

  • Fetch a thumbnail of the same image and same size, but specify a different method.

  • Receive M_UNKNOWN, Internal server error

Here's the error from server logs:

2020-10-22 16:04:50,858 - synapse.http.server - 85 - ERROR - GET-1786524 - Failed handle request via 'ThumbnailResource': <XForwardedForRequest at 0x7fc446756320 method='GET'
 uri='/_matrix/media/r0/thumbnail/remote-server.tld/XXXXXXX_removed_file_id?width=44&height=44&method=crop' clientproto='HTTP/1.0' site=8008>
Traceback (most recent call last):
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/http/server.py", line 230, in _async_render_wrapper
    callback_return = await self._async_render(request)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/http/server.py", line 258, in _async_render
    callback_return = await raw_callback_return
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 67, in _async_render_GET
    request, server_name, media_id, width, height, method, m_type
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 232, in _select_or_generate_remote_thumbnail
    desired_type,
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/rest/media/v1/media_repository.py", line 597, in generate_remote_exact_thumbnail
    t_len,
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/databases/main/media_repository.py", line 374, in store_remote_media_thumbnail
    desc="store_remote_media_thumbnail",
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 727, in simple_insert
    await self.runInteraction(desc, self.simple_insert_txn, table, values)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 577, in runInteraction
    **kwargs
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 647, in runWithConnection
    self._db_pool.runWithConnection(inner_func, *args, **kwargs)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 306, in _runWithConnection
    compat.reraise(excValue, excTraceback)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/python/compat.py", line 464, in reraise
    raise exception.with_traceback(traceback)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/twisted/enterprise/adbapi.py", line 297, in _runWithConnection
    result = func(conn, *args, **kw)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 641, in inner_func
    return func(conn, *args, **kwargs)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 447, in new_transaction
    r = func(cursor, *args, **kwargs)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 748, in simple_insert_txn
    txn.execute(sql, vals)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 212, in execute
    self._do_execute(self.txn.execute, sql, *args)
  File "/opt/venvs/matrix-synapse/lib/python3.7/site-packages/synapse/storage/database.py", line 238, in _do_execute
    return func(sql, *args)
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "remote_media_cache_thumbnails_media_origin_media_id_thumbna_key"
DETAIL:  Key (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type)=(remote-server.tld, XXXXXXX_removed_file_id, 44, 44, image/png) already e
xists.

Added comments from tulir:

"someone forgot the thumbnail_method from the unique constraint"

"wait no, there are two unique constraints, one with and one without thumbnail_method? :D"

synapse=# \d remote_media_cache_thumbnails
        Table "public.remote_media_cache_thumbnails"
      Column      |  Type   | Collation | Nullable | Default 
------------------+---------+-----------+----------+---------
 media_origin     | text    |           |          | 
 media_id         | text    |           |          | 
 thumbnail_width  | integer |           |          | 
 thumbnail_height | integer |           |          | 
 thumbnail_method | text    |           |          | 
 thumbnail_type   | text    |           |          | 
 thumbnail_length | integer |           |          | 
 filesystem_id    | text    |           |          | 
Indexes:
    "remote_media_cache_thumbnails_media_origin_media_id_thumbna_key" UNIQUE CONSTRAINT, btree (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type)
    "remote_media_repository_thumbn_media_origin_id_width_height_met" UNIQUE, btree (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type, thumbnail_method)

Version information

  • Homeserver: hacklab.fi

  • Version: 1.21.2

@vurpo vurpo changed the title Consecutive thumbnail requests with different methods fails Consecutive remote media thumbnail requests with different methods fails Oct 25, 2020
@richvdh
Copy link
Member

richvdh commented Oct 26, 2020

looks like it didn't get correctly removed in #7124

@richvdh
Copy link
Member

richvdh commented Oct 26, 2020

https://github.com/matrix-org/synapse/pull/7124/files#diff-f05c2d0a285e2b60b93cbffe6283864c9b23c19984fe7e4511604797413acc06R83 tries to remove the old constraint but doesn't take into account the fact that (I think) the constraint might have a different name under postgres and sqlite.

@clokep clokep added the z-bug (Deprecated Label) label Oct 26, 2020
@clokep
Copy link
Member

clokep commented Oct 29, 2020

@deepbluev7 any chance you'd be willing to take a look at this?

@deepbluev7
Copy link
Contributor

@clokep I think removing both of the old constraints instead should work in that case? I had no idea, that the constraints could have different names and I still don't understand, why they would. I'm a bit busy currently though, so it may be easier for someone else to add a migration, that deletes both of the old indices, if they exist, since it will take me quite a while to context switch into synapse db migration code again.

@richvdh
Copy link
Member

richvdh commented Oct 29, 2020

I suspect they can end up with different names depending on whether you're using sqlite or postgres?

@pu11em
Copy link

pu11em commented Jan 2, 2021

Sorry to bringing this up, but has anyone found any workaround for this?? I have millions of lines on synapse's log file in the last month.

@callahad callahad added the Z-Help-Wanted We know exactly how to fix this issue, and would be grateful for any contribution label Jan 6, 2021
@clokep
Copy link
Member

clokep commented Jan 6, 2021

I think the thing to do here is check what the name of the old constraint is on sqlite and add a delta that removes that (similar to what was done in #7124).

@moritzdietz
Copy link
Contributor

From the Polynomial Supporters channel someone else and me noticed this problem today as well - the thumbnails for the flairs are missing and represented with the alt text instead.
When checking the synapse logs I could find this:

2021-04-01 12:36:19,519 - synapse.storage.database - 957 - WARNING - GET-136585 - IntegrityError when upserting into remote_media_cache_thumbnails; retrying: duplicate key value violates unique constraint "remote_media_cache_thumbnails_media_origin_media_id_thumbna_key"
DETAIL:  Key (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type)=(matrix.org, pKRnQRliCyKRqHecxWpPBohl, 16, 16, image/png) already exists.
2021-04-01 12:36:19,533 - synapse.http.server - 94 - ERROR - GET-136585 - Failed handle request via 'ThumbnailResource': <XForwardedForRequest at 0x7f8502a06670 method='GET' uri='/_matrix/media/r0/thumbnail/matrix.org/pKRnQRliCyKRqHecxWpPBohl?width=16&height=16&method=crop' clientproto='HTTP/1.1' site='8008'>
  File "/opt/venvs/matrix-synapse/lib/python3.8/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 80, in _async_render_GET
  File "/opt/venvs/matrix-synapse/lib/python3.8/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 232, in _select_or_generate_remote_thumbnail
    file_path = await self.media_repo.generate_remote_exact_thumbnail(
  File "/opt/venvs/matrix-synapse/lib/python3.8/site-packages/synapse/rest/media/v1/media_repository.py", line 632, in generate_remote_exact_thumbnail
    await self.store.store_remote_media_thumbnail(
  File "/opt/venvs/matrix-synapse/lib/python3.8/site-packages/synapse/storage/databases/main/media_repository.py", line 536, in store_remote_media_thumbnail
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "remote_media_cache_thumbnails_media_origin_media_id_thumbna_key"
DETAIL:  Key (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type)=(matrix.org, pKRnQRliCyKRqHecxWpPBohl, 16, 16, image/png) already exists.
2021-04-01 12:36:19,535 - synapse.access.http.8008 - 308 - INFO - GET-136585 - 2003:e9:271c:ae00:c4ba:ee0a:f3b2:1e33 - 8008 - {None} Processed request: 0.044sec/-0.000sec (0.006sec, 0.002sec) (0.003sec/0.019sec/7) 55B 500 "GET /_matrix/media/r0/thumbnail/matrix.org/pKRnQRliCyKRqHecxWpPBohl?width=16&height=16&method=crop HTTP/1.1" "Mozilla/5.0 (X11; Ubuntu; Linux x86_64; rv:87.0) Gecko/20100101 Firefox/87.0" [0 dbevts]

This is on Synapse 1.30.1.
Are there ways for me to manually fix this?
Can I help troubleshoot this by offering logs and reproduce things?

@richvdh
Copy link
Member

richvdh commented Apr 1, 2021

ugh this is one of those bugs that is one line to fix. I'll have a go at it now.

richvdh added a commit that referenced this issue Apr 1, 2021
The `remote_media_cache_thumbnails_media_origin_media_id_thumbna_key`
constraint is superceded by
`remote_media_repository_thumbn_media_origin_id_width_height_met` (which adds
`thumbnail_method` to the unique key).

PR #7124 made an attempt to remove the old constraint, but got the name wrong,
so it didn't work. Here we update the bg update and rerun it.

Fixex #8649.
@richvdh
Copy link
Member

richvdh commented Apr 1, 2021

There's a lot of chat in the above about sqlite. It was nothing to do with sqlite, because on sqlite we have a completely different implementation which rebuilds the tables (https://github.com/matrix-org/synapse/pull/7124/files#diff-fdc2e6526e108bf9b08a63532dc6f44e388d929ae3ea1a6863939f7fe1b9ef8eR36-R44). AFAICT this was a simple case of using the wrong name in the migration.

Those that want a manual workaround can run the following sql:

ALTER TABLE remote_media_cache_thumbnails
   DROP CONSTRAINT remote_media_cache_thumbnails_media_origin_media_id_thumbna_key;

@moritzdietz
Copy link
Contributor

Thank you!
I just ran the sql on my postgres and it fixed the issue. Going to https://matrix.moritzdietz.com/_matrix/media/r0/thumbnail/matrix.org/pKRnQRliCyKRqHecxWpPBohl?width=16&height=16&method=crop works again. :)

richvdh added a commit that referenced this issue Apr 6, 2021
The `remote_media_cache_thumbnails_media_origin_media_id_thumbna_key`
constraint is superceded by
`remote_media_repository_thumbn_media_origin_id_width_height_met` (which adds
`thumbnail_method` to the unique key).

PR #7124 made an attempt to remove the old constraint, but got the name wrong,
so it didn't work. Here we update the bg update and rerun it.

Fixes #8649.
@kyrias
Copy link
Contributor

kyrias commented May 11, 2021

I just noticed the same exceptions in the logs even after upgrading to 1.33.2, so there might be some edge-case in which that PR doesn't actually end up dropping the constraint?

Works fine after dropping it manually though.

@richvdh
Copy link
Member

richvdh commented May 12, 2021

@kyrias: can you confirm the exact text of the exception that you saw in the logs?

can you also share the results of SELECT * FROM background_updates ?

@kyrias
Copy link
Contributor

kyrias commented May 12, 2021

2021-05-11 16:59:31,575 - ERROR   - synapse.http.server:93 - GET-3301 - Failed handle request via 'ThumbnailResource': <XForwardedForRequest at 0x7f09215c4fa0 method='GET' uri='/_matrix/media/r0/thumbnail/matrix.org/CsiyNFAdaCrdhOMGMpXmYgqR?width=16&height=16&method=crop' clientproto='HTTP/1.0' site='8449'>
Traceback (most recent call last):
  File "/usr/lib/python3.9/site-packages/synapse/http/server.py", line 258, in _async_render_wrapper
    callback_return = await self._async_render(request)
  File "/usr/lib/python3.9/site-packages/synapse/http/server.py", line 286, in _async_render
    callback_return = await raw_callback_return
  File "/usr/lib/python3.9/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 79, in _async_render_GET
    await self._select_or_generate_remote_thumbnail(
  File "/usr/lib/python3.9/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 231, in _select_or_generate_remote_thumbnail
    file_path = await self.media_repo.generate_remote_exact_thumbnail(
  File "/usr/lib/python3.9/site-packages/synapse/rest/media/v1/media_repository.py", line 634, in generate_remote_exact_thumbnail
    await self.store.store_remote_media_thumbnail(
  File "/usr/lib/python3.9/site-packages/synapse/storage/databases/main/media_repository.py", line 550, in store_remote_media_thumbnail
    await self.db_pool.simple_upsert(
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 937, in simple_upsert
    return await self.runInteraction(
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 656, in runInteraction
    result = await self.runWithConnection(
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 739, in runWithConnection
    return await make_deferred_yieldable(
  File "/usr/lib/python3.9/site-packages/twisted/python/threadpool.py", line 238, in inContext
    result = inContext.theWork()  # type: ignore[attr-defined]
  File "/usr/lib/python3.9/site-packages/twisted/python/threadpool.py", line 254, in <lambda>
    inContext.theWork = lambda: context.call(  # type: ignore[attr-defined]
  File "/usr/lib/python3.9/site-packages/twisted/python/context.py", line 118, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/lib/python3.9/site-packages/twisted/python/context.py", line 83, in callWithContext
    return func(*args, **kw)
  File "/usr/lib/python3.9/site-packages/twisted/enterprise/adbapi.py", line 293, in _runWithConnection
    compat.reraise(excValue, excTraceback)
  File "/usr/lib/python3.9/site-packages/twisted/python/deprecate.py", line 298, in deprecatedFunction
    return function(*args, **kwargs)
  File "/usr/lib/python3.9/site-packages/twisted/python/compat.py", line 403, in reraise
    raise exception.with_traceback(traceback)
  File "/usr/lib/python3.9/site-packages/twisted/enterprise/adbapi.py", line 284, in _runWithConnection
    result = func(conn, *args, **kw)
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 734, in inner_func
    return func(db_conn, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 528, in new_transaction
    r = func(cursor, *args, **kwargs)
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 986, in simple_upsert_txn
    self.simple_upsert_txn_native_upsert(
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 1110, in simple_upsert_txn_native_upsert
    txn.execute(sql, list(allvalues.values()))
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 290, in execute
    self._do_execute(self.txn.execute, sql, *args)
  File "/usr/lib/python3.9/site-packages/synapse/storage/database.py", line 316, in _do_execute
    return func(sql, *args)
psycopg2.errors.UniqueViolation: duplicate key value violates unique constraint "remote_media_cache_thumbnails_media_origin_media_id_thumbna_key"
DETAIL:  Key (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type)=(matrix.org, CsiyNFAdaCrdhOMGMpXmYgqR, 16, 16, image/png) already exists.

And the background_updates table is currently empty:

 update_name | progress_json | depends_on | ordering 
-------------+---------------+------------+----------
(0 rows)

@richvdh
Copy link
Member

richvdh commented May 12, 2021

That's... odd. If you still have synapse logs for the point when you first upgraded to 1.32.0 or later, they might be interesting. Otherwise, 🤷‍♂️

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
z-bug (Deprecated Label) Z-Help-Wanted We know exactly how to fix this issue, and would be grateful for any contribution
Projects
None yet
Development

Successfully merging a pull request may close this issue.

8 participants