search

glitch-soc / mastodon

A glitchy but lovable microblogging server
https://glitch-soc.github.io/docs/
GNU Affero General Public License v3.0
690 stars 184 forks source link

GIFs are not being properly converted to videos #1537

Closed lunaisnotaboy closed 3 years ago

lunaisnotaboy commented 3 years ago

Whenever I try to upload a GIF, it uploads fine, but the server returns a 500 error.

I looked in the logs (attached below), and it appears FFmpeg exited with the error code 159.

Is this something with FFmpeg, or is it something wrong with Mastodon, because this has happened on two of my systems now.

Logs (errors for some reason don't show up):

[paperclip] copying media_attachments/files/106/229/197/491/384/406/original/48ee18675b942e3a.gif to local file /tmp/ef35763773174e76b026bead8938691120210513-1141711-17ymgdo.gif
[paperclip] Trying to link /tmp/ef35763773174e76b026bead8938691120210513-1141711-17ymgdo.gif to /tmp/ef35763773174e76b026bead8938691120210513-1141711-164wwr8.gif
Command :: file -b --mime '/tmp/ef35763773174e76b026bead8938691120210513-1141711-164wwr8.gif'
Command :: ffmpeg -nostdin -i '/tmp/ef35763773174e76b026bead8938691120210513-1141711-17ymgdo.gif' -loglevel 'fatal' -movflags 'faststart' -pix_fmt 'yuv420p' -vf 'scale='\''trunc(iw/2)*2:trunc(ih/2)*2'\''' -vsync 'cfr' -c:v 'h264' -maxrate '1300K' -bufsize '1300K' -frames:v '10800' -crf '18' -map_metadata '-1' -acodec 'aac' -strict 'experimental' -y '/tmp/ef35763773174e76b026bead8938691120210513-1141711-17ymgdo20210513-1141711-xmsexj.mp4'
[paperclip] copying media_attachments/files/106/229/197/491/384/406/original/48ee18675b942e3a.gif to local file /tmp/ef35763773174e76b026bead8938691120210513-1141711-y0cxcu.gif
[paperclip] Trying to link /tmp/ef35763773174e76b026bead8938691120210513-1141711-y0cxcu.gif to /tmp/ef35763773174e76b026bead8938691120210513-1141711-1yygdks.gif
Command :: file -b --mime '/tmp/ef35763773174e76b026bead8938691120210513-1141711-1yygdks.gif'
Command :: ffmpeg -nostdin -i '/tmp/ef35763773174e76b026bead8938691120210513-1141711-y0cxcu.gif' -loglevel 'fatal' -movflags 'faststart' -pix_fmt 'yuv420p' -vf 'scale='\''trunc(iw/2)*2:trunc(ih/2)*2'\''' -vsync 'cfr' -c:v 'h264' -maxrate '1300K' -bufsize '1300K' -frames:v '10800' -crf '18' -map_metadata '-1' -acodec 'aac' -strict 'experimental' -y '/tmp/ef35763773174e76b026bead8938691120210513-1141711-y0cxcu20210513-1141711-1wp17f8.mp4'

The GIF in question:

AW3945234_00

ClearlyClaire commented 3 years ago

I cannot reproduce this, I successfully uploaded this GIF file to my instance :/

lunaisnotaboy commented 3 years ago

@ClearlyClaire I figured. From what I can see, there's nothing unusual about this (or any other GIF I tried).

The thing is, external GIFs are processed correctly (e.g. cached) and are converted without error.

ClearlyClaire commented 3 years ago

So, do you still have an issue uploading GIFs? If you do get a 500 again, could you check mastodon-web's logs? There should be a traceback

lunaisnotaboy commented 3 years ago

@ClearlyClaire yeah, give me a minute. Rails' logs are acting weird

lunaisnotaboy commented 3 years ago

@ClearlyClaire The error is now 422: Error processing thumbnail for uploaded media.

Here are the logs, sorry it took so long:

May 15 11:43:15 glimmerhq.com bundle[1227024]: 2021-05-15T15:43:15.988Z pid=1227024 tid=qpd8 class=PostProcessMediaWorker jid=f32ecf3e18f49a85ebd91149 INFO: start
May 15 11:43:16 glimmerhq.com bundle[1227024]: 2021-05-15T15:43:16.471Z pid=1227024 tid=qpd8 class=PostProcessMediaWorker jid=f32ecf3e18f49a85ebd91149 elapsed=0.483 INFO: fail
May 15 11:43:16 glimmerhq.com bundle[1227024]: 2021-05-15T15:43:16.471Z pid=1227024 tid=qpd8 WARN: {"context":"Job raised exception","job":{"retry":1,"queue":"default","dead":false,"class":"PostProcessMediaWorker","args":[106239976783734323],"jid":"f32ecf3e18f49a85ebd91149","created_at":1621093395.9871142,"enqueued_at":1621093395.987422},"jobstr":"{\"retry\":1,\"queue\":\"default\",\"dead\":false,\"class\":\"PostProcessMediaWorker\",\"args\":[106239976783734323],\"jid\":\"f32ecf3e18f49a85ebd91149\",\"created_at\":1621093395.9871142,\"enqueued_at\":1621093395.987422}"}
May 15 11:43:16 glimmerhq.com bundle[1227024]: 2021-05-15T15:43:16.471Z pid=1227024 tid=qpd8 WARN: Paperclip::Error: Error while transcoding 9c6cc578f96689c02a21c57fd3834d8020210515-1227024-negrsy: Command 'ffmpeg -nostdin -i '/tmp/9c6cc578f96689c02a21c57fd3834d8020210515-1227024-negrsy.gif' -loglevel 'fatal' -movflags 'faststart' -pix_fmt 'yuv420p' -vf 'scale='\''trunc(iw/2)*2:trunc(ih/2)*2'\''' -vsync 'cfr' -c:v 'h264' -maxrate '1300K' -bufsize '1300K' -frames:v '10800' -crf '18' -map_metadata '-1' -acodec 'aac' -strict 'experimental' -y '/tmp/9c6cc578f96689c02a21c57fd3834d8020210515-1227024-negrsy20210515-1227024-yfrw8d.mp4'' returned 159. Expected 0
May 15 11:43:16 glimmerhq.com bundle[1227024]: Here is the command output: STDOUT:
May 15 11:43:16 glimmerhq.com bundle[1227024]: STDERR:
May 15 11:43:16 glimmerhq.com bundle[1227024]: Bad system call (core dumped)
May 15 11:43:16 glimmerhq.com bundle[1227024]: 2021-05-15T15:43:16.472Z pid=1227024 tid=qpd8 WARN: /home/deploy/mastodon/releases/20210515152642/lib/paperclip/transcoder.rb:52:in `rescue in make'
May 15 11:43:16 glimmerhq.com bundle[1227024]: /home/deploy/mastodon/releases/20210515152642/lib/paperclip/transcoder.rb:48:in `make'
May 15 11:43:16 glimmerhq.com bundle[1227024]: /home/deploy/mastodon/shared/bundle/ruby/2.7.0/gems/paperclip-6.0.0/lib/paperclip/processor.rb:34:in `make'
lunaisnotaboy commented 3 years ago

I'm assuming it's a problem with FFmpeg, but I cannot find any documentation on the error code 159. I have tried reinstalling FFmpeg from the source, but that did not help.

I also reinstalled Ubuntu from scratch, but that did not help either.

lunaisnotaboy commented 3 years ago

@ClearlyClaire just checking in here, have you seen the logs? Apologies if I seem irritating.

ClearlyClaire commented 3 years ago

oops sorry ffmpeg is crashing, I guess it might be due to the sandboxing in the systemd unit files? What's your /etc/systemd/system/mastodon-web.service like?

lunaisnotaboy commented 3 years ago

@ClearlyClaire the contents of mastodon-web.service:

[Unit]
Description=mastodon-web
After=network.target

[Service]
Type=simple
User=deploy
WorkingDirectory=/home/deploy/mastodon/current
Environment="RAILS_ENV=production"
Environment="PORT=3000"
ExecStart=/home/deploy/.rbenv/shims/bundle exec puma -C config/puma.rb
ExecReload=/bin/kill -SIGUSR1 $MAINPID
TimeoutSec=15
Restart=always
# Capabilities
CapabilityBoundingSet=
# Security
NoNewPrivileges=true
# Sandboxing
ProtectSystem=strict
PrivateTmp=true
PrivateDevices=true
PrivateUsers=true
ProtectHostname=true
ProtectKernelLogs=true
ProtectKernelModules=true
ProtectKernelTunables=true
ProtectControlGroups=true
RestrictAddressFamilies=AF_INET
RestrictAddressFamilies=AF_INET6
RestrictAddressFamilies=AF_NETLINK
RestrictAddressFamilies=AF_UNIX
RestrictNamespaces=true
LockPersonality=true
RestrictRealtime=true
RestrictSUIDSGID=true
PrivateMounts=true
ProtectClock=true
# System Call Filtering
SystemCallArchitectures=native
SystemCallFilter=~@clock @cpu-emulation @debug @keyring @module @mount @obsolete @reboot @resources @setuid @swap

[Install]
WantedBy=multi-user.target
ClearlyClaire commented 3 years ago

can you add @raw-io in the SystemCallFilter field, do the same for mastodon-sidekiq.service, do systemctl daemon-reload and restart both of the services?

lunaisnotaboy commented 3 years ago

Yeah, give me a minute.

lunaisnotaboy commented 3 years ago

Still gives the same error, I even tried another GIF.

May 23 10:43:26 glimmerhq.com bundle[2941548]: 2021-05-23T14:43:26.171Z pid=2941548 tid=1rox8 class=PostProcessMediaWorker jid=49803b9186f3e05c79aa4730 INFO: start
May 23 10:43:28 glimmerhq.com bundle[2941548]: 2021-05-23T14:43:28.989Z pid=2941548 tid=1rox8 class=PostProcessMediaWorker jid=49803b9186f3e05c79aa4730 elapsed=2.818 INFO: fail
May 23 10:43:28 glimmerhq.com bundle[2941548]: 2021-05-23T14:43:28.989Z pid=2941548 tid=1rox8 WARN: {"context":"Job raised exception","job":{"retry":1,"queue":"default","dead":false,"class":"PostProcessMediaWorker","args":[106285039996737563],"jid":"49803b9186f3e05c79aa4730","created_at":1621781006.1703336,"enqueued_at":1621781006.170547},"jobstr":"{\"retry\":1,\"queue\":\"default\",\"dead\":false,\"class\":\"PostProcessMediaWorker\",\"args\":[106285039996737563],\"jid\":\"49803b9186f3e05c79aa4730\",\"created_at\":1621781006.1703336,\"enqueued_at\":1621781006.170547}"}
May 23 10:43:28 glimmerhq.com bundle[2941548]: 2021-05-23T14:43:28.989Z pid=2941548 tid=1rox8 WARN: Paperclip::Error: Error while transcoding 684fde8896720c217f1262cdeb0ce1c420210523-2941548-1c8pwki: Command 'ffmpeg -nostdin -i '/tmp/684fde8896720c217f1262cdeb0ce1c420210523-2941548-1c8pwki.gif' -loglevel 'fatal' -movflags 'faststart' -pix_fmt 'yuv420p' -vf 'scale='\''trunc(iw/2)*2:trunc(ih/2)*2'\''' -vsync 'cfr' -c:v 'h264' -maxrate '1300K' -bufsize '1300K' -frames:v '10800' -crf '18' -map_metadata '-1' -acodec 'aac' -strict 'experimental' -y '/tmp/684fde8896720c217f1262cdeb0ce1c420210523-2941548-1c8pwki20210523-2941548-ov9rpl.mp4'' returned 159. Expected 0
May 23 10:43:28 glimmerhq.com bundle[2941548]: Here is the command output: STDOUT:
May 23 10:43:28 glimmerhq.com bundle[2941548]: STDERR:
May 23 10:43:28 glimmerhq.com bundle[2941548]: Bad system call (core dumped)
May 23 10:43:28 glimmerhq.com bundle[2941548]: 2021-05-23T14:43:28.989Z pid=2941548 tid=1rox8 WARN: /home/deploy/mastodon/releases/20210515152642/lib/paperclip/transcoder.rb:52:in `rescue in make'
May 23 10:43:28 glimmerhq.com bundle[2941548]: /home/deploy/mastodon/releases/20210515152642/lib/paperclip/transcoder.rb:48:in `make'
May 23 10:43:28 glimmerhq.com bundle[2941548]: /home/deploy/mastodon/shared/bundle/ruby/2.7.0/gems/paperclip-6.0.0/lib/paperclip/processor.rb:34:in `make'
ClearlyClaire commented 3 years ago

hm :/

what if you remove everything below # Capabilities?

lunaisnotaboy commented 3 years ago

in both web and sidekiq?

ClearlyClaire commented 3 years ago

yeah

lunaisnotaboy commented 3 years ago

Including security and the others?

ClearlyClaire commented 3 years ago

yes

lunaisnotaboy commented 3 years ago

@ClearlyClaire It works!!!

Thanks for the help!

ClearlyClaire commented 3 years ago

Sorry for bringing that up again, but while you could work around the issue, well, there still seem to be an issue somewhere in the provided unit files… which version of ffmpeg are you using? On which version of Ubuntu? On what architecture?

lunaisnotaboy commented 3 years ago

@ClearlyClaire oh, no problem

$ lsb_release -a
No LSB modules are available.
Distributor ID: Ubuntu
Description:    Ubuntu 20.04.2 LTS
Release:        20.04
Codename:       focal
$ ffmpeg -version
ffmpeg version 4.2.4-1ubuntu0.1 Copyright (c) 2000-2020 the FFmpeg developers
built with gcc 9 (Ubuntu 9.3.0-10ubuntu2)
configuration: --prefix=/usr --extra-version=1ubuntu0.1 --toolchain=hardened --libdir=/usr/lib/x86_64-linux-gnu --incdir=/usr/include/x86_64-linux-gnu --arch=amd64 --enable-gpl --disable-stripping --enable-avresample --disable-filter=resample --enable-avisynth --enable-gnutls --enable-ladspa --enable-libaom --enable-libass --enable-libbluray --enable-libbs2b --enable-libcaca --enable-libcdio --enable-libcodec2 --enable-libflite --enable-libfontconfig --enable-libfreetype --enable-libfribidi --enable-libgme --enable-libgsm --enable-libjack --enable-libmp3lame --enable-libmysofa --enable-libopenjpeg --enable-libopenmpt --enable-libopus --enable-libpulse --enable-librsvg --enable-librubberband --enable-libshine --enable-libsnappy --enable-libsoxr --enable-libspeex --enable-libssh --enable-libtheora --enable-libtwolame --enable-libvidstab --enable-libvorbis --enable-libvpx --enable-libwavpack --enable-libwebp --enable-libx265 --enable-libxml2 --enable-libxvid --enable-libzmq --enable-libzvbi --enable-lv2 --enable-omx --enable-openal --enable-opencl --enable-opengl --enable-sdl2 --enable-libdc1394 --enable-libdrm --enable-libiec61883 --enable-nvenc --enable-chromaprint --enable-frei0r --enable-libx264 --enable-shared
libavutil      56. 31.100 / 56. 31.100
libavcodec     58. 54.100 / 58. 54.100
libavformat    58. 29.100 / 58. 29.100
libavdevice    58.  8.100 / 58.  8.100
libavfilter     7. 57.100 /  7. 57.100
libavresample   4.  0.  0 /  4.  0.  0
libswscale      5.  5.100 /  5.  5.100
libswresample   3.  5.100 /  3.  5.100
libpostproc    55.  5.100 / 55.  5.100
$ uname -a
Linux glimmerhq.com 5.8.0-50-generic #56~20.04.1-Ubuntu SMP Mon Apr 12 21:46:35 UTC 2021 x86_64 x86_64 x86_64 GNU/Linux

I switched to deploying via Capistrano instead of doing it manually, but the problem was there before.