| 3 Aug 2022 |
Andreas Rammhold | Interesting. I updated the server yesterday. | 11:59:57 |
Andreas Rammhold | To this supposedly stable NixOS (very experimental distro, not sure if you heard of it ;-)) | 12:00:16 |
Andreas Rammhold | It certainly logs a ton about remote media fetching | 12:02:00 |
Andreas Rammhold | I'll try to give this a closer look in the evening. | 12:03:39 |
| 15 Aug 2022 |
aciceri | same problem here | 10:11:38 |
andi- | mhmm | 10:13:04 |
andi- | I'll give this another look. Kinda busy these days :( | 10:13:16 |
andi- | [pid 2176054] mkdir("/persist/synapse/media_store/remote_content/matrix.org/GA/IC", 0777) = 0
[pid 2176054] openat(AT_FDCWD, "/persist/synapse/media_store/remote_content/matrix.org/GA/IC/QcaoFfMrZVjPzVMmGdMS", O_WRONLY|O_CREAT|O_TRUNC|O_CLOEXEC, 0666) = 220
[pid 2176054] close(220) = 0
[pid 2176054] unlink("/persist/synapse/media_store/remote_content/matrix.org/GA/IC/QcaoFfMrZVjPzVMmGdMS") = 0
It tries to create the thumbnails whenever you request them. Then for some reason unlinks them. The log isn't really helpful :/
| 13:16:47 |
andi- | Retrival seems to work just fine..
download/kack.it/lhUtWiwebKiPYXZCWEpPBglQ?allow_remote=false
Aug 15 13:20:35 matrix synapse[2176054]: synapse.http.server: [GET-5857] <XForwardedForRequest at 0x7fa72ec4fc10 method='GET' uri='/_matrix/media/r0/thumbnail/kack.it/lhUtWiwebKiPYXZ
CWEpPBglQ?width=100&height=100&method=crop' clientproto='HTTP/1.0' site='8448'> SynapseError: 404 - Not found
Aug 15 13:20:35 matrix synapse[2176054]: synapse.access.http.8448: [GET-5857] ..... - 8448 - {None} Processed request: 0.076sec/0.001sec (0.008sec, 0.001sec) (0.003sec/0.003sec/3) 45
B 404 "GET /_matrix/media/r0/thumbnail/kack.it/lhUtWiwebKiPYXZCWEpPBglQ?width=100&height=100&method=crop HTTP/1.0" "Mozilla/5.0 (X11; Linux x86_64; rv:103.0) Gecko/20100101 Firefox/1
03.0" [0 dbevts]
| 13:21:45 |
andi- | Just whatever it does to the thumbnails afterwards (maybe the cropping?!?) doesn't work | 13:22:10 |
Andreas Rammhold | Hah, the config has "dynamic_thumbnails = false". .. lets see if toggling this fixes it | 13:23:06 |
andi- | Nope :( | 13:25:10 |
andi- | Sorry for all the restart of the service... binary search through the call stack :| | 14:10:37 |
Andreas Rammhold | Aug 15 15:18:48 matrix synapse[2181664]: synapse.rest.media.v1.thumbnail_resource: [GET-24790] Retrieving remote media info
Aug 15 15:18:49 matrix synapse[2181664]: synapse.http.matrixfederationclient: [GET-24790] {GET-O-27641} [matrix.org] Completed: 200 OK [104209 bytes] GET matrix://matrix.org/_matrix/media/r0/download/matrix.org/srlqxFAKBkrEcrXIZfXemWPp?allow_remote=false
Aug 15 15:18:49 matrix synapse[2181664]: synapse.rest.media.v1.thumbnail_resource: [GET-24790] Failed to retrieve remote media info: 404: Not found
Added a bunch of logging and apparently it doesn't reach out to the remote server but fails to find it locally. Perhaps the database think it still has a copy but there isn't one.. Will continue later.
| 15:19:42 |
andi- | Finally a proper backtrace :|
Aug 15 18:08:06 matrix synapse[2186199]: synapse.rest.media.v1.thumbnail_resource: [GET-232] Failed to retrieve remote media info: 404: Not found
Traceback (most recent call last):
File "/nix/store/kxnc94gdrd9r8dh7cfy2dgpfcyzpr7cv-python3.9-Twisted-22.4.0/lib/python3.9/site-packages/twisted/internet/defer.py", line 1660, in _inlineCallbacks
result = current_context.run(gen.send, result)
StopIteration: {'media_type': 'image/jpeg', 'media_length': 30382, 'upload_name': '638836.jpg', 'created_ts': 1625419217683, 'filesystem_id': 'OhNgumzWouNcFiHqjTArWbPX', 'quarantined_by': None}
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/nix/store/mp9vi8b1hqnfxi7bpdc30g22j1kdxiax-matrix-synapse-1.64.0/lib/python3.9/site-packages/synapse/rest/media/v1/thumbnail_resource.py", line 205, in _select_or_generate_remote_thumbnail
media_info = await self.media_repo.get_remote_media_info(server_name, media_id)
File "/nix/store/mp9vi8b1hqnfxi7bpdc30g22j1kdxiax-matrix-synapse-1.64.0/lib/python3.9/site-packages/synapse/rest/media/v1/media_repository.py", line 328, in get_remote_media_info
responder, media_info = await self._get_remote_media_impl(
File "/nix/store/mp9vi8b1hqnfxi7bpdc30g22j1kdxiax-matrix-synapse-1.64.0/lib/python3.9/site-packages/synapse/rest/media/v1/media_repository.py", line 403, in _get_remote_media_impl
await self._generate_thumbnails(
File "/nix/store/mp9vi8b1hqnfxi7bpdc30g22j1kdxiax-matrix-synapse-1.64.0/lib/python3.9/site-packages/synapse/rest/media/v1/media_repository.py", line 739, in _generate_thumbnails
input_path = await self.media_storage.ensure_media_is_in_local_cache(
File "/nix/store/mp9vi8b1hqnfxi7bpdc30g22j1kdxiax-matrix-synapse-1.64.0/lib/python3.9/site-packages/synapse/rest/media/v1/media_storage.py", line 262, in ensure_media_is_in_local_cache
raise NotFoundError()
synapse.api.errors.NotFoundError: 404: Not found
| 18:08:49 |
Andreas Rammhold | This sounds vaguely related: https://github.com/matrix-org/synapse/commit/7b67e93d499cb45f7217e9dfea046ed8b5c455fd | 21:11:57 |
Andreas Rammhold | I'll investigate more tomorrow.. | 21:12:03 |
| 16 Aug 2022 |
| Andreas Rammhold set a profile picture. | 10:49:02 |
Andreas Rammhold | lassulus: do you see your own avatar? | 10:49:33 |
lassulus | nope | 10:50:03 |
Andreas Rammhold | Do you see my new test avatar? | 10:50:13 |
lassulus | but I see yours now | 10:50:17 |
Andreas Rammhold | Weird. | 10:50:22 |
Andreas Rammhold | I suspect something went terribly wrong due to dynamic thumbnails being off in the past and during some upgrade things got weird. | 10:50:44 |
Andreas Rammhold | Might have to purge some media caches... if there is a way | 10:51:04 |
Andreas Rammhold | [root@matrix:/persist/synapse]# ls -l1 media*
media:
total 168
drwx------ 397 matrix-synapse matrix-synapse 12288 Jul 31 13:34 local_content
drwx------ 185 matrix-synapse matrix-synapse 4096 Jul 31 13:34 local_thumbnails
drwx------ 2282 matrix-synapse matrix-synapse 69632 Aug 2 18:39 remote_content
drwx------ 2153 matrix-synapse matrix-synapse 69632 Aug 2 18:40 remote_thumbnail
drwx------ 5 matrix-synapse matrix-synapse 4096 Aug 2 00:12 url_cache
drwx------ 115 matrix-synapse matrix-synapse 4096 Aug 2 00:12 url_cache_thumbnails
media_store:
total 40
drwx------ 84 matrix-synapse matrix-synapse 4096 Aug 16 10:48 local_content
drwx------ 17 matrix-synapse matrix-synapse 4096 Aug 16 10:48 local_thumbnails
drwx------ 678 matrix-synapse matrix-synapse 20480 Aug 16 05:00 remote_content
drwx------ 138 matrix-synapse matrix-synapse 4096 Aug 15 19:32 remote_thumbnail
drwx------ 5 matrix-synapse matrix-synapse 4096 Aug 16 00:02 url_cache
drwx------ 5 matrix-synapse matrix-synapse 4096 Aug 16 00:02 url_cache_thumbnails
This is suspicious . Why was is it called media_store now?!
| 10:55:40 |
Andreas Rammhold | I'll merge the two folders in a bit and restart the server. That should fix the issue... | 11:01:01 |
lassulus | avatars start appearing again, thanks! | 11:12:39 |
Andreas Rammhold | Whats an okay-ish object storage provider from a privacy perspective? Preferably somewhere in the EU. | 11:17:47 |
Andreas Rammhold | I am thinking that the 50 GiB of images that I'm caching now shouldn't be on the disk in the first place... | 11:18:06 |