If FFMPEG cuts video slowly things can fall over

[aza547]

Describe the bug
A user in discord reported this. In their logs, ffmpeg took 3 mins to cut the video. They pulled the boss before this time elapsed and the app fell over.

Expected behavior
The ffmpeg cutting the video should be async in respect to the recorder process. Currently, the recording buffer does not restart until the cutting is done. That's bad logic. See the code in recorder.stop, particularly await this.finalizeVideo(metadata, outputFilename);.

Quoting from Discord

huh this is an interesting one and is definitely a bug in our code
the problem seems to be that it took your PC ~3 mins to cut one of your pantheon pulls to size
in that time, the app isn't ready to start another recording, but you pulled again in that time
so it fell over
as for why it took so long to cut the video to size, that's very strange and I'm not sure. Was your PC super busy? Anything notable going on?
Regardless of how long it takes, we shouldn't require it completes before the next pull so there is some code fixes I can make to help this.
The cutting of the video usually takes 2-3 seconds in normal circumstances so probably just never hit this before as no one manages to pull within that window.

ahk@DESKTOP-C6ME3UB:/mnt/c/Users/alexa/Downloads$ grep "ENCOUNTER_" "WoWCombatLog-100322_173442.txt"  | grep -i panth
10/3 18:17:17.722  ENCOUNTER_START,2544,"Prototype Pantheon",16,20,2481
10/3 18:21:51.041  ENCOUNTER_END,2544,"Prototype Pantheon",16,20,0,273279
10/3 18:23:54.541  ENCOUNTER_START,2544,"Prototype Pantheon",16,20,2481
10/3 18:27:53.051  ENCOUNTER_END,2544,"Prototype Pantheon",16,20,1,238500

[2022-10-03 18:22:06.060] [info]  [OBS] obsRecorder: stop
[2022-10-03 18:22:06.091] [debug] [OBS] Asserted OBS signal: stopping
[2022-10-03 18:22:06.638] [debug] [OBS] Asserted OBS signal: stop
[2022-10-03 18:22:06.684] [debug] [OBS] Asserted OBS signal: wrote
[2022-10-03 18:22:08.442] [info]  [Util] Ready to cut video.
[2022-10-03 18:22:08.443] [info]  [Util] Initial duration: 572.45 Desired duration: 288 Calculated start time: 284
[2022-10-03 18:22:13.390] [info]  [Config Service] Set in config store: selectedCategory 5
[2022-10-03 18:22:13.396] [info]  [Config Service] Set in config store: selectedCategory 5
[2022-10-03 18:23:54.543] [info]  [Logutils] Start recording a video for category: Raids
[2022-10-03 18:23:54.544] [info]  [Recorder] Start recording by cancelling buffer restart
[2022-10-03 18:25:04.535] [info]  [Util] FFmpeg cut video succeeded
[2022-10-03 18:25:04.548] [info]  [Recorder] Finalized video E:\wowrecordings\2022-10-03 18-12-33 - Raids Sepulcher of the First Ones, Pantheon (Wipe).mp4
[2022-10-03 18:25:04.549] [debug] [Size Monitor] Running (max size = 805.3 GB)
[2022-10-03 18:25:04.562] [info]  [Size Monitor] Unprotected file(s) considered 20, total size = 108.5 GB
[2022-10-03 18:25:04.563] [info]  [Util] Deleting: E:\wowrecordings\.temp\2022-10-03 18-04-20.mp4
[2022-10-03 18:25:09.554] [info]  [Recorder] Start recording buffer
[2022-10-03 18:25:09.555] [info]  [OBS] obsRecorder: start
[2022-10-03 18:25:09.839] [debug] [OBS] Asserted OBS signal: start

Things all go downhill from here, as we previously cancelled the recording buffer (which was actually a no-op), so we get a buffer restart inside a genuine recording. Full log is attached.

WarcraftRecorder-2022-10-03 (3).log

[aza547]

User is recording in high res (4k?) and to a HDD.

[aza547]

The video cutting is consistently slow but only causes a problem when a following pull happens during the cut (so if they take 10 mins on trash its fine, but if they wipe and quick re-pull its not).

[aza547]

User also had 120k bit rate videos - so very large, with a slow disk.

Two fixes to make here:

• Deal with video sizes once and for all, we've been meaning to do this for a while.
• Make cutting async.

[aza547]

Will be fixed in 2.9.0.