Users are Unable to Follow Certain Users and Avatars/Media Are Not Updated

[cambrian-era]

My users have been reporting that they are unable to see/boost certain toots from certain users. Specifically, some avatars are out of date (I have run tootctl refresh) and media posts aren't showing. When I try to follow those users, I see the following error in our docker logs:

[e4b20574-0ab3-4583-a9c7-bac241a88093] [paperclip] Trying to link /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv to /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-hxmqyt.jpeg
[e4b20574-0ab3-4583-a9c7-bac241a88093] Command :: file -b --mime '/tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-hxmqyt.jpeg'
[e4b20574-0ab3-4583-a9c7-bac241a88093] [paperclip] Trying to link /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv to /tmp/fefab50e4f351b937d4e583cd4e2e58720181015-24-1j4o9y4 [e4b20574-0ab3-4583-a9c7-bac241a88093] [paperclip] Link failed with No such file or directory @ rb_file_s_link - (/tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv, /tmp/fefab50e4f351b937d4e583cd4e2e58720181015-24-1j4o9y4); copying link /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv to /tmp/fefab50e4f351b937d4e583cd4e2e58720181015-24-1j4o9y4
[e4b20574-0ab3-4583-a9c7-bac241a88093] method=POST path=/inbox format=html controller=ActivityPub::InboxesController action=create status=500 error='Errno::ENOENT: No such file or directory @ rb_sysopen - /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv' duration=2064.58 view=0.00 db=2.47
[e4b20574-0ab3-4583-a9c7-bac241a88093]
[e4b20574-0ab3-4583-a9c7-bac241a88093] Errno::ENOENT (No such file or directory @ rb_sysopen - /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv):
[e4b20574-0ab3-4583-a9c7-bac241a88093]
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/models/concerns/remotable.rb:39:in `block (2 levels) in remotable_attachment'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/lib/request.rb:48:in `perform'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/models/concerns/remotable.rb:24:in `block in remotable_attachment'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/process_account_service.rb:82:in `set_fetchable_attributes!'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/process_account_service.rb:61:in `update_account'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/process_account_service.rb:25:in `block in call'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/process_account_service.rb:18:in `call'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/fetch_remote_account_service.rb:25:in `call'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/fetch_remote_key_service.rb:37:in `find_account'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/services/activitypub/fetch_remote_key_service.rb:24:in `call'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/controllers/concerns/signature_verification.rb:124:in `account_from_key_id'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/controllers/concerns/signature_verification.rb:46:in `signed_request_account'
[e4b20574-0ab3-4583-a9c7-bac241a88093] app/controllers/activitypub/inboxes_controller.rb:9:in `create'

Any idea why this might be is appreciated.

---

• I searched or browsed the repo’s other issues to ensure this is not a duplicate.
• This bug happens on a tagged release and not on master (If you're a user, don't worry about this).

[cambrian-era]

Best as I can figure, it's trying to download the user's avatar and failing. According to this StackOverflow question, it seems to happen when it fails validation? https://stackoverflow.com/questions/49584973/why-is-paperclip-upload-giving-trying-to-link-error

[cambrian-era]

From what I can see by looking at the database, the remote avatar URL tends to be incorrect... but there's more to it than that...

[Gargron]

Errno::ENOENT (No such file or directory @ rb_sysopen - /tmp/8d777f385d3dfec8815d20f7496026dc20181015-24-1vl2ztv)

Means that paperclip couldn't open a tempfile it created itself. That's very strange. Are you out of disk space? Something with directory permissions?

[cambrian-era]

We've got a lot of disk space and use S3 for our media storage so it definitely shouldn't be a disk space issue. As far as directory permissions, we're running in docker, so I'm not sure where to look, but I definitely haven't touched anything that might effect that. Also strange that it seems to be per account.

[Rtzq0]

Some other logs/diagnostics that may be useful from the system side:
logs from s3 api calls (are you using s3fs? does mastodon use the s3api directly?)
output of df
output of df -i
output of mount
perhaps output of docker inspect on containers or volumes in use for the appropriate component.

All that being said my experience with application debugging encourages occams razor and suggests that if the file isn't there to be read the app never wrote it because it decided not to (and therefore your instincts around looking at the functioning of app components is probably a good one).

[cambrian-era]

mount-output.txt
df-output.txt

I'm not sure how to get the s3 api calls, I'm just doing it via mastodon.

Regardless, I've not seen this occur with local users or media, only remote ones, which is another part of why I suspect it's not an issue with the files themselves.

[Rtzq0]

If you wanted to get S3 logs you have to use cloudtrail. The methodology is like so https://docs.aws.amazon.com/AmazonS3/latest/user-guide/enable-cloudtrail-events.html

that'll get you log output like this
https://docs.aws.amazon.com/AmazonS3/latest/dev/LogFormat.html

in theory then you could then correlate your mastodon errors with S3 logs to see what was up from the backend perspective (IE ensure that the reason the error was occurring was because the file was not on S3 and was never created).

Typically speaking when trying to diagnose something in a black-box fashion like this my next step would be tracing tools (try to find out what the app is doing) but I highly suspect that it'll tell us that it's trying to read a file that isn't there (unhelpful).

I assume you haven't been able to replicate the issue by recreating aspects of an offending example?

[cambrian-era]

So, I actually was able to replicate it, by doing the following:
Going to my mastodon.social account, changing my avatar, then trying to follow that account again from my radical.town account. When I did this, it gave me the same error. Additionally, with the user creating the example above, I found her avatar's URL and put it in the database, which let me follow her but still refuses to refresh her avatar. This seems to occur almost exclusively with:
Remote accounts
With media, whether it's avatars or attached media. In the case of attached media, the toot just doesn't show.

This is as far as I've gotten in my digging.

[Rtzq0]

I had some ideas but they're all torpedoed by there being even 1 local examples. I'll reply back if I have a brainwave before you figure it out with your superior cranial horsepower :D

[cambrian-era]

I had some ideas but they're all torpedoed by there being even 1 local examples. I'll reply back if I have a brainwave before you figure it out with your superior cranial horsepower :D

Oh yeah, no, so far no local examples. ONLY remote media seems to cause this to occur. Something is failing but I haven't been able to trace what.

[Rtzq0]

The only other thing I can think of to narrow it down is whether it's related to a specific version or configuration on remotes or if it's just all remotes. Other than that I'm out of ideas right now.

[cambrian-era]

If it was all instances or all users, but it seems to be somewhat random. The only thing I've managed to confirm is that changing an avatar seems to get it 'stuck', but there's still plenty of media and I've still been able to follow other users so... I'm really baffled.

[cambrian-era]

I take it back: After moving off of S3 I had misconfigured our permissions, but when I fixed that everything worked again. So if anyone starts having this issue again I'd look at S3. It was just too inconsistent to nail down before.

[Gargron]

Glad you found the problem!

[cambrian-era]

This issue is back, even without AWS, which is very strange to me. It returned when I updated to 2.6.1...

[cambrian-era]

Ok, it seems this is an issue with Paperclip 6.1.0. I had unintentionally bumped the version when I had to rebuild the Gemfile.lock. It might be a good idea to lock the version at 6.0 unless you have a reason to update it since it's deprecated.

[nightpool]

You should definitely only ever use the Gemfile.lock that Mastodon ships with.