ekisu / mpv-webm

Simple WebM maker for mpv, with no external dependencies.
MIT License
556 stars 33 forks source link

Script randomly stops encoding #63

Closed Nogooduser closed 4 years ago

Nogooduser commented 5 years ago

mpv version and platform

mpv mpv 0.29.0-353-g65b1c2d065 on Windows 10

Description

Essentially what the title says. I've used this script for as long as I can remember but after updating it to the most recent version it occasionally stops working.

Sometimes it will encode one or two clips, then the third one won't work, sometimes not even the first one works, sometimes it always works, it's completely random and I cannot discover what is causing the issue in the first place

The behavior is always the same, I can open the webm menu, change encoding options and press e, the difference is that sometimes it will simply not encode anything.

I know it's doing something in the background because when the scritp does fail and I close mpv the program takes a lot longer to close, meaning it's likely interrupting something in the background, but beyond that I don't know what's wrong since I get no errors.

Log file

log.txt

ekisu commented 5 years ago

Well, the log file don't seem to tell much about this. I see that the encoding subprocess gets spawned...

[  52.068][i][webm] Encoding to E:\webm/[HorribleSubs] Symphogear XV - 03 [1080p]-[08.42.772-09.24.981]-audio.webm 
[  52.068][v][webm] Command line: mpv E:\Anime\[HorribleSubs] Symphogear XV - 03 [1080p].mkv --start=0:08:42.772 --end=0:09:24.981 --ovc=libvpx --oac=libvorbis --loop-file=no --vid=1 --aid=1 --sid=1 --sub-ass-override=yes --sub-auto=exact --sub-delay=0.000000 --video-rotate=0 --vf-add=lavfi-colormatrix=bt709:bt601 --vf-add=lavfi-scale=-2:480 --ovcopts-add=threads=4 --ovcopts-add=b=1421k --ovcopts-add=crf=10 -o=E:\webm/[HorribleSubs] Symphogear XV - 03 [1080p]-[08.42.772-09.24.981]-audio.webm 
[  52.069][d][cplayer] Run command: show-text, flags=64, args=[ýStarted encode..., 5000, 0]
[  52.069][d][cplayer] Run command: subprocess, flags=64, args=[mpv,E:\Anime\[HorribleSubs] Symphogear XV - 03 [1080p].mkv,--start=0:08:42.772,--end=0:09:24.981,--ovc=libvpx,--oac=libvorbis,--loop-file=no,--vid=1,--aid=1,--sid=1,--sub-ass-override=yes,--sub-auto=exact,--sub-delay=0.000000,--video-rotate=0,--vf-add=lavfi-colormatrix=bt709:bt601,--vf-add=lavfi-scale=-2:480,--ovcopts-add=threads=4,--ovcopts-add=b=1421k,--ovcopts-add=crf=10,-o=E:\webm/[HorribleSubs] Symphogear XV - 03 [1080p]-[08.42.772-09.24.981]-audio.webm, no, 67108864, yes, no]

...and that when you close mpv, the subprocess indeed gets killed, and we show an error message (for a splitsecond though, as the player gets closed shortly after):

[  71.387][i][cplayer] Exiting... (Quit)
(other scripts exiting...)
[  73.387][v][webm] Command failed! Reason:  killed  Killed by us?  yes 
[  73.387][v][webm] Command stdout:  
[  73.387][v][webm] The version option can't be used in a config file.
[  73.387][v][webm] Error parsing option version (option parameter could not be parsed)
[  73.387][v][webm] C:/MPV/mpv/mpv.conf:11: setting option version='' failed.
[  73.387][v][webm] Playing: E:\Anime\[HorribleSubs] Symphogear XV - 03 [1080p].mkv
[  73.387][v][webm]  (+) Video --vid=1 (*) (h264 1920x1080 23.976fps)
[  73.387][v][webm]  (+) Audio --aid=1 --alang=jpn (*) (aac 2ch 44100Hz)
[  73.387][v][webm]  (+) Subs  --sid=1 --slang=eng (*) (ass)
[  73.387][v][webm]  
[  73.387][d][cplayer] Run command: show-text, flags=64, args=[ýEncode failed! Check the logs for details., 5000, 0]
[  73.388][v][webm] Exiting...

Aside from an invalid option set in your mpv.conf file, which (I think) shouldn't matter in this case, this just tells me the subprocess gets stuck. Could you try running just the subprocess, and see if it works? This command:

mpv "E:\Anime\[HorribleSubs] Symphogear XV - 03 [1080p].mkv" --start=0:08:42.772 --end=0:09:24.981 --ovc=libvpx --oac=libvorbis --loop-file=no --vid=1 --aid=1 --sid=1 --sub-ass-override=yes --sub-auto=exact --sub-delay=0.000000 --video-rotate=0 --vf-add=lavfi-colormatrix=bt709:bt601 --vf-add=lavfi-scale=-2:480 --ovcopts-add=threads=4 --ovcopts-add=b=1421k --ovcopts-add=crf=10 "-o=E:\webm/[HorribleSubs] Symphogear XV - 03 [1080p]-[08.42.772-09.24.981]-audio.webm"
Nogooduser commented 5 years ago

Command ran fine and output the webm clip in the right directory.

Here's what showed up on cmd


Playing: E:\Anime\[HorribleSubs] Symphogear XV - 03 [1080p].mkv
 (+) Video --vid=1 (*) (h264 1920x1080 23.976fps)
 (+) Audio --aid=1 --alang=jpn (*) (aac 2ch 44100Hz)
 (+) Subs  --sid=1 --slang=eng (*) (ass)
[ao/lavc] Opening encoder: libvorbis [libvorbis]
AO: [lavc] 44100Hz stereo 2ch floatp
VO: [lavc] 854x480 => 854x480 yuv420p
[vo/lavc] Opening encoder: libvpx VP8 [libvpx]
[encode] Opening output file: E:\webm/[HorribleSubs] Symphogear XV - 03 [1080p]-[08.42.772-09.24.981]-audio.webm
[encode] Opening muxer: WebM [webm]
AV: 00:09:24 / 00:23:40 (39%) A-V:  0.011 {0.0min 35.9fps 6.8MB}

[encode] video: encoded 6620070 bytes
[encode] audio: encoded 535739 bytes
[encode] muxing overhead 28391 bytes

Exiting... (End of file)
ekisu commented 5 years ago

Welp, I legit have no clue on what might be causing this. Isn't there anything that triggers the bug?

Nogooduser commented 5 years ago

As far as I know not really. I mean there has to be something but I have not been able to pinpoint what it might be since it happens so randonly.

Like when I was first writing this issue I wanted to produce a log file from when an encode failed, and I ended up encoding SIX files before it finally failed.

Yet, before that, I had it fail literally on the second attempt...

The biggest issue is that I do absolutely nothing in between encodes, I'm just watching the file play as it encodes most of the time, sometimes checking the output folder to see if the encoding failed, and sometimes it works and other times it doesn't.

This bug never occurred when I had mpv installed on my hard drive, I've only been getting it ever since I changed to an SSD. That's really the only clue I have but I don't think my SSD could cause this, right?

ekisu commented 5 years ago

My mpv install is also on a SSD, although my video files are on an HD. Anyway, this shouldn't matter. I've tried to reproduce the bug, and created around ~20 clips of the same file - all of them worked.

As you said that older versions of the script worked, maybe bisecting and finding the commit that introduced the bug is the fastest way to fix this. What's the latest version that worked for you?

Nogooduser commented 5 years ago

I don't know the exact version since I didn't keep up with the updates regularly, but I know I spent a long time without updating the script, so I was probably using a fairly old version.

I remember the version I was using didn't have the [[ ]] brackets for the output directory, so it was a version before March 2019, that's about as much as I can tell you.

Also here's a video of the bug happening, just so you can see I'm not making this up. This one failed on the very first attempt. Then after I stopped recording and tried again it worked again and hasn't failed yet. It's really that inconsistent (edit: it failed again after a few attempts).

Edit2: I also tried using a completely default version of the script with no modifications and same bug happens. Also tried removing all my other scripts (which are just 2) and same thing.

ekisu commented 5 years ago

We need to establish a good commit, at least. Maybe the commit that introduced the encode progress meter on OS X/Linux could be the problematic one. This build (from this commit) was the one before it. Does it works? If it doesn't, does this build, one of the very first versions, work?

I'll have to leave for a few hours so, sorry for making you try so many things.

podia falar em português tbm né

Nogooduser commented 5 years ago

Haha, não sabia que falava português. Para mim tanto me faz.

Ok, agora algo está muito estranho, pois ambos os builds que me mandou causaram o mesmo bug, e eu sei que a versão que eu tinha antes era mais recente que essa antiga que você colocou ai pois tinha mais opções.

Isto faz-me querer que há algo de errado ou com o meu mpv ou com o meu PC. Só que é muito estranho pois esta build do MPV é uma que uso há uns anos (a build em questão), e instalei no meu SSD da mesma maneira que instalei no meu HDD antigo. O ficheiro mpv.conf também é o mesmo que eu tinha no meu HDD antigo, pois eu fiz um backup dele.

Agora é que estou mesmo a ficar sem ideias...

Nogooduser commented 5 years ago

Um update: Não sei se isto vai ajudar ou não, mas sempre que estou a gravar com o ShareX o script nunca funciona (i.e o bug ocorre 100% das vezes). Eu sei que o ShareX usa o ffmpeg.exe para gravar, mas não sei se isso estará relacionado ou não.

Edit: O que me está a irritar nisto é o quão inconsistente o bug é. Às vezes penso que mudei algo e finalmente arranjei o problema mas passado uns 15 clips o bug acontece outra vez (como agora, pensei que tinha arranjado ao mudar as opções do ShareX, mas depois voltou). Eu nem sequer faço assim tantos webms com este script, no maximo 3 ou 4 por video. Às vezes o bug nunca acontece, mas outras vezes o bug acontece à 2ª ou 3ª vez e nessas situações é que causa transtorno porque tenho de fechar e abrir o mpv para tentar novamente (e às vezes volta a falhar logo à primeira)

Por exemplo aqui fica um log.txt em que fiz 11 encodes até o bug acontecer.

ekisu commented 4 years ago

Atualizar o seu mpv não ajudaria? Lembro que teve um PR bem grande com coisas relacionadas a encoding um tempo atrás (que supostamente devia ter consertado 2-pass mas não consertou 😔), nunca se sabe.

Nogooduser commented 4 years ago

Essa é a coisa, eu atualizei o mpv ontem, mas tenho este bug desde que meti o script no meu PC novo...

mpv 0.29.0-353-g65b1c2d065 Copyright © 2000-2019 mpv/MPlayer/mplayer2 projects
 built on Sun Jul 14 20:16:49 +08 2019
ffmpeg library versions:
   libavutil       56.30.100
   libavcodec      58.53.101
   libavformat     58.28.102
   libswscale      5.4.101
   libavfilter     7.56.101
   libswresample   3.4.100
ffmpeg version: git-2019-07-13-f86f213a
ekisu commented 4 years ago

Hmm, parece que consegui reproduzir o bug. Tentei fazer os webms gravando a tela com o ShareX (não sei se é realmente necessário, e não foi de primeira), enquanto observava o gráfico de uso de CPU. Depois de algumas (umas 10, talvez?) tentativas, uma delas simplesmente travou.

Rodando o comando de encode no cmd várias vezes, também consegui obter o mesmo resultado - o encode simplesmente não começa, as vezes. Vou tentar ver se alguma flag específica causa isso, mas isso me parece muito mais algum tipo de regressão do mpv em sí.

Edit: após alguns testes, parece que o filtro de colormatrix causa esse bug. Retirando ele, consegui rodar o encode 300 vezes sem travar, e ele sozinho, com nenhuma das outras flags (tirando as obrigatórias), travou depois de ~40 tentativas.

Nogooduser commented 4 years ago

Boas, peço desculpa por só responder a isto agora mas não estive em casa nos ultimos 10 dias e não tinha internet.

Como é que removeu o filtro de colormatrix? Não encontrei nada sobre como o remover na documentação do mpv.

ekisu commented 4 years ago

Ah, este filtro não é aplicado pelo mpv em sí, mas por nós (para converter as cores no "formato" aceito pelos webm). Essa build não aplica o filtro.

Falando nisso, houveram alguns relatos que outros filtros do libavfilter causavam freezes também, mas que essas freezes tinham parado nas builds mais recentes. Tenho que testar ainda se isso consertou esse bug.

edit: não consertou, infelizmente. Por enquanto, vou desativar o filtro.