500 errors with "duplicate key value" on remote_media_cache_thumbnails when dynamic_thumbnails enabled

[turt2live]

Error is at the end of this issue (it's a long one).

The following URLs produce similar errors to the one included here:

• https://t2bot.io/_matrix/media/v1/thumbnail/matrix.org/HtRqOXgQyGkcePuSgsuBrLcx?width=128&height=128&method=crop
• https://t2bot.io/_matrix/media/v1/thumbnail/matrix.org/ARfYZMTdGlRCAGXurhYSZGwT?width=128&height=128&method=crop
• https://t2bot.io/_matrix/media/v1/thumbnail/matrix.org/pFUfshTtyiLsZAODtmHOOLop?width=128&height=128&method=crop

There may be more, however those 3 are easily noticed.

Changing the method to scale does not result in an error. This does not appear to affect local media.

I tried to delete the files and records from the database in varying combinations (delete files & delete records, only delete records, only delete files) in various running states of synapse (running, shut down, restart after). I tried various combinations of deleting data from the two tables (from both remote_media_cache and remote_media_cache_thumbnails, only _thumbnails, only _cache). No luck.

The error continues and does not go away. If I'm missing a step, please let me know. Otherwise, this appears to be a very specific and strange bug.

Synapse version: v0.20.0

2017-05-02 20:35:23,067 - synapse.access.http.8008 - 59 - INFO - GET-753- <IP REDACTED> - 8008 - Received request: GET /_matrix/media/v1/thumbnail/matrix.org/ARfYZMTdGlRCAGXurhYSZGwT?width=128&height=128&method=crop
2017-05-02 20:35:23,068 - synapse.util.async - 201 - INFO - GET-753- Acquired linearizer lock 'media_remote' for key ('matrix.org', 'ARfYZMTdGlRCAGXurhYSZGwT')
2017-05-02 20:35:23,079 - synapse.util.async - 208 - INFO - GET-753- Releasing linearizer lock 'media_remote' for key ('matrix.org', 'ARfYZMTdGlRCAGXurhYSZGwT')
2017-05-02 20:35:23,083 - synapse.metrics - 162 - INFO - - Collecting gc 0
2017-05-02 20:35:23,106 - synapse.rest.media.v1.thumbnailer - 93 - INFO - - Stored thumbnail in file u'/root/synapse/media_store/remote_thumbnail/matrix.org/Sg/El/RAnfzhTBOJHxWANIWpBP/128-128-image-png'
2017-05-02 20:35:23,118 - synapse.metrics - 162 - INFO - - Collecting gc 0
2017-05-02 20:35:23,120 - synapse.http.server - 139 - ERROR - GET-753- Failed handle request synapse.rest.media.v1.thumbnail_resource._async_render_GET on <synapse.rest.media.v1.thumbnail_resource.ThumbnailResource instance at 0x7f3e179dabd8>: <XForwardedForRequest at 0x7f3dcf04b6c8 method=GET uri=/_matrix/media/v1/thumbnail/matrix.org/ARfYZMTdGlRCAGXurhYSZGwT?width=128&height=128&method=crop clientproto=HTTP/1.0 site=8008>
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/dist-packages/synapse/http/server.py", line 118, in wrapped_request_handler
    yield request_handler(self, request)
  File "/usr/local/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1299, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/failure.py", line 393, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/local/lib/python2.7/dist-packages/synapse/rest/media/v1/thumbnail_resource.py", line 71, in _async_render_GET
    width, height, method, m_type
  File "/usr/local/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1299, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/failure.py", line 393, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/local/lib/python2.7/dist-packages/synapse/rest/media/v1/thumbnail_resource.py", line 194, in _select_or_generate_remote_thumbnail
    desired_height, desired_method, desired_type
  File "/usr/local/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1299, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/failure.py", line 393, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/local/lib/python2.7/dist-packages/synapse/rest/media/v1/media_repository.py", line 318, in generate_remote_exact_thumbnail
    t_width, t_height, t_type, t_method, t_len
  File "/usr/local/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1299, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/failure.py", line 393, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 406, in _simple_insert
    self._simple_insert_txn, table, values,
  File "/usr/local/lib/python2.7/dist-packages/twisted/internet/defer.py", line 1299, in _inlineCallbacks
    result = result.throwExceptionIntoGenerator(g)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/failure.py", line 393, in throwExceptionIntoGenerator
    return g.throw(self.type, self.value, self.tb)
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 319, in runInteraction
    inner_func, *args, **kwargs
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/threadpool.py", line 250, in inContext
    result = inContext.theWork()
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/threadpool.py", line 266, in <lambda>
    inContext.theWork = lambda: context.call(ctx, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/context.py", line 122, in callWithContext
    return self.currentContext().callWithContext(ctx, func, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/twisted/python/context.py", line 85, in callWithContext
    return func(*args,**kw)
  File "/usr/local/lib/python2.7/dist-packages/twisted/enterprise/adbapi.py", line 307, in _runWithConnection
    compat.reraise(excValue, excTraceback)
  File "/usr/local/lib/python2.7/dist-packages/twisted/enterprise/adbapi.py", line 298, in _runWithConnection
    result = func(conn, *args, **kw)
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 313, in inner_func
    func, *args, **kwargs
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 242, in _new_transaction
    r = func(txn, *args, **kwargs)
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 426, in _simple_insert_txn
    txn.execute(sql, vals)
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 80, in execute
    self._do_execute(self.txn.execute, sql, *args)
  File "/usr/local/lib/python2.7/dist-packages/synapse/storage/_base.py", line 110, in _do_execute
    sql, *args
IntegrityError: 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, ARfYZMTdGlRCAGXurhYSZGwT, 128, 128, image/png) already exists.

[jkolo]

This is the reason I made pull request #1946

[Half-Shot]

This continues to bite me all the time on riot-android and the toasts that keep popping up are getting annoying.

[TildeSlashC0re]

I can confirm that I experience the same bug!

Seems to only apply to specific remote thumnails.

EDIT:

DELETE FROM remote_media_cache_thumbnails;

during stopped state, then restarting did the trick for me!

[Half-Shot]

Still experiencing this. It's a pretty awful experience for some avatars to load and some to fail.

[tleydxdy]

Same in 0.31.1

[ananace]

The issue can be solved without doing full table migrations - at least on PostgreSQL, technically without even requiring downtime.

ALTER TABLE remote_media_cache_thumbnails DROP CONSTRAINT remote_media_cache_thumbnails_media_origin_media_id_thumbna_key;
CREATE INDEX remote_media_cache_thumbnails_media_origin_media_id_thumbna_key ON remote_media_cache_thumbnails (media_origin, media_id, thumbnail_width, thumbnail_height, thumbnail_type, thumbnail_method);

[zzottel]

Just had the same after enabling dynamic thumbnails on my Synapse.

Can confirm that the SQL posted by ananace helps, but what is the consequence? That now multiple thumbs of the same size are allowed, right?

But why does Synapse even try to create its own dynamically if there's already one present for the desired resolution?

[TildeSlashC0re]

Dropping by to confirm that @ananace workaround did the trick!

[console-cowboy]

This remains an issue as of the 0.33.4 Release. The @ananace workaround provides the relief others have mentioned though.

[ArchangeGabriel]

Could some dev comment on @ananace workaround consequences? Should we just do that?

[msrd0]

Still an issue on 0.99.1.1, @ananace's workaround still works. Would be nice to know how that affects my server though. Does that mean I store a new thumbnail every time a client asks for one?