Recording with Output Timer sometimes stops on its own

[dege13]

I am recording several hundred VHS tapes. I always use Output Timer (great feature). However, about every 10 -20 times when I click Start for recording, OBS Studio will stop recording right away (but the Output Timer thinks it is still recording). OBS Studio creates a ~750kb MKV recording file.

Log:

08:46:16.158: ---------------------------------
08:46:16.158: [FFmpeg aac encoder: 'Track1'] bitrate: 160, channels: 2, channel_layout: stereo
08:46:16.158:
08:46:16.170: ==== Recording Start ===============================================
08:46:16.170: [ffmpeg muxer: 'adv_file_output'] Writing file 'C:/Users/chew/Videos/2023-02-25 08-46-16.mkv'...
08:46:16.709: [ffmpeg muxer: 'adv_file_output'] Output of file 'C:/Users/chew/Videos/2023-02-25 08-46-16.mkv' stopped
08:46:16.709: Output 'adv_file_output': stopping
08:46:16.709: Output 'adv_file_output': Total frames output: 1
08:46:16.709: Output 'adv_file_output': Total drawn frames: 13
08:46:16.710: ==== Recording Stop ================================================
08:46:16.739: warning: 2 frames left in the queue on closing
08:48:37.906: ==== Shutting down ==================================================
08:48:38.180: WASAPI: Device 'Line (Roxio Video Capture USB)' Terminated
08:48:38.228: All scene data cleared
08:48:38.228: ------------------------------------------------
08:48:38.359: [obs-websocket] [obs_module_unload] Shutting down...
08:48:38.360: [obs-websocket] [obs_module_unload] Finished shutting down.
08:48:38.362: [Scripting] Total detached callbacks: 0
08:48:38.362: Freeing OBS context data

What do you think is happening?
Is there any way to increase the logging level to get more detail? I would love to get a screen recording of the issue but it happens so seldom that it would be hard to catch.

 

[dege13]

It happened again.

Here is what OBS looks like when it happens. Note the Stop button, but Start Recording on the main OBS window.

Here is the important part of log (full log attached):
{code}
07:44:49.010: ==== Recording Start ===============================================
07:44:49.010: [ffmpeg muxer: 'adv_file_output'] Writing file 'C:/Users/chew/Videos/2023-02-27 07-44-48.mkv'...
07:44:49.548: [ffmpeg muxer: 'adv_file_output'] Output of file 'C:/Users/chew/Videos/2023-02-27 07-44-48.mkv' stopped
07:44:49.548: Output 'adv_file_output': stopping
07:44:49.548: Output 'adv_file_output': Total frames output: 1
07:44:49.548: Output 'adv_file_output': Total drawn frames: 13
07:44:49.548: ==== Recording Stop ================================================
07:44:49.577: warning: 2 frames left in the queue on closing
08:01:42.834: ==== Shutting down ==================================================
{code}

I have also attached the 705kb KMV file which was generated when the issue happened (inside the ZIP file).

It could be possible that the mouse is doing a very fast double click and the Output Timer's Start button does not handle that correctly. However I cannot reproduce that when I try (and click Start on the Output Timer over and over again quickly). This appears to be something else causing OBS to stop recording, and not tell the Output Timer that the recording failed or stopped.

Any help with this issue would be appreciated.

 

[dege13]

It has happened two more times in the last 24 hours. Two different computers.

 

[dege13]

It has happened again and again on three different computers. Does anyone have any ideas?
One of he computers is even running OBS Studio 27 becasue it has Windows 2008 R2, and it still sees this same issue. It has a 1.5GB log file as well, which is no fun to try to look through for an error.

I suspect ffmpeg muxer is crashing when it is called, but have no idea why. I am just guessing based on the log line:
{code}ffmpeg muxer: 'adv_file_output'] Output of file 'C:/Users/chew/Videos/2023-02-27 07-44-48.mkv' stopped{code}

Is there a away to get debug logging output from obs-ffmpeg without attaching a debugger like WinDBG?

When it is in the broken state, if I try to record again OBS will hang seemingly forever. I never let it finish because I have to get on with the work that needs to be sone after all. SO I kill OBS, launch it again and try again. It usually works again for about 2 days, give or take, per computer.

 

[Suslik V]

When it is in the broken state, if I try to record again OBS will hang seemingly forever...

This is encoder error. OBS cannot recover in case encoder fails. In your case, highly likely, this is caused by the video encoder fail.

 

[dege13]

This is encoder error. OBS cannot recover in case encoder fails. In your case, highly likely, this is caused by the video encoder fail.

Two of the PCs are set top use NVENC, third one is software x264. Any ideas how to troubleshoot it?

 

[dege13]

It has happened several times since I last posted logs. Figured more of the same data doesn't really help.
However, it just happened and here is the log as OBS sat there for a minute after closing after the issue. Perhaps this help find a cause?

09:09:09.253: ==== Recording Start ===============================================
09:09:09.253: [ffmpeg muxer: 'adv_file_output'] Writing file 'C:/Users/dege1/Videos/2023-03-05 09-09-09.mkv'...
09:09:10.291: [ffmpeg muxer: 'adv_file_output'] Output of file 'C:/Users/dege1/Videos/2023-03-05 09-09-09.mkv' stopped
09:09:10.291: Output 'adv_file_output': stopping
09:09:10.291: Output 'adv_file_output': Total frames output: 1
09:09:10.291: Output 'adv_file_output': Total drawn frames: 32
09:09:10.291: ==== Recording Stop ================================================
09:09:10.327: warning: 2 frames left in the queue on closing
09:09:53.206: ==== Shutting down ==================================================
09:09:53.223: WASAPI: Device 'SAMSUNG (NVIDIA High Definition Audio)' Terminated
09:09:53.237: WASAPI: Device 'Microphone (AT2020USB+)' Terminated
09:10:26.470: All scene data cleared
09:10:26.470: ------------------------------------------------
09:10:26.983: [obs-websocket] [obs_module_unload] Shutting down...
09:10:26.985: [obs-websocket] [WebSocketServer::ServerRunner] IO thread exited.
09:10:26.986: [obs-websocket] [WebSocketServer::Stop] Server stopped successfully
09:10:26.986: [obs-websocket] [obs_module_unload] Finished shutting down.
09:10:26.989: [Scripting] Total detached callbacks: 0
09:10:26.989: Freeing OBS context data
09:10:26.989:     1 output(s) were remaining
09:10:27.025: == Profiler Results =============================
09:10:27.025: run_program_init: 3179.02 ms
09:10:27.025:  ┣OBSApp::AppInit: 26.234 ms
09:10:27.025:  ┃ ┗OBSApp::InitLocale: 3.902 ms
09:10:27.025:  ┗OBSApp::OBSInit: 3097.83 ms
09:10:27.025:    ┣obs_startup: 7.313 ms
09:10:27.025:    ┗OBSBasic::OBSInit: 2798.47 ms
09:10:27.025:      ┣OBSBasic::InitBasicConfig: 0.704 ms
09:10:27.025:      ┣OBSBasic::ResetAudio: 0.289 ms
09:10:27.025:      ┣OBSBasic::ResetVideo: 1364.06 ms
09:10:27.025:      ┣OBSBasic::InitOBSCallbacks: 0.007 ms
09:10:27.025:      ┣OBSBasic::InitHotkeys: 0.041 ms
09:10:27.025:      ┣obs_load_all_modules2: 590.42 ms
09:10:27.025:      ┃ ┣obs_init_module(aja-output-ui.dll): 1.618 ms
09:10:27.025:      ┃ ┣obs_init_module(aja.dll): 0.884 ms
09:10:27.025:      ┃ ┣obs_init_module(coreaudio-encoder.dll): 1.143 ms
09:10:27.025:      ┃ ┣obs_init_module(decklink-captions.dll): 0 ms
09:10:27.025:      ┃ ┣obs_init_module(decklink-output-ui.dll): 0 ms
09:10:27.025:      ┃ ┣obs_init_module(decklink.dll): 2.152 ms
09:10:27.025:      ┃ ┣obs_init_module(enc-amf.dll): 30.416 ms
09:10:27.025:      ┃ ┣obs_init_module(frontend-tools.dll): 7.418 ms
09:10:27.025:      ┃ ┣obs_init_module(image-source.dll): 0.006 ms
09:10:27.025:      ┃ ┣obs_init_module(logi_obs_plugin_x64.dll): 1.606 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-browser.dll): 4.992 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-ffmpeg.dll): 220.212 ms
09:10:27.025:      ┃ ┃ ┗nvenc_check: 1.437 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-filters.dll): 1.473 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-outputs.dll): 0.007 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-qsv11.dll): 37.384 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-text.dll): 0.7 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-transitions.dll): 0.009 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-vst.dll): 0.001 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-websocket.dll): 10.421 ms
09:10:27.025:      ┃ ┣obs_init_module(obs-x264.dll): 0.002 ms
09:10:27.025:      ┃ ┣obs_init_module(rtmp-services.dll): 5.068 ms
09:10:27.025:      ┃ ┣obs_init_module(text-freetype2.dll): 0.047 ms
09:10:27.025:      ┃ ┣obs_init_module(vlc-video.dll): 0.039 ms
09:10:27.025:      ┃ ┣obs_init_module(win-capture.dll): 78.006 ms
09:10:27.025:      ┃ ┣obs_init_module(win-dshow.dll): 1.876 ms
09:10:27.025:      ┃ ┣obs_init_module(win-mf.dll): 0 ms
09:10:27.025:      ┃ ┣obs_init_module(win-wasapi.dll): 0.012 ms
09:10:27.025:      ┃ ┗reset_win32_symbol_paths: 0.177 ms
09:10:27.025:      ┣OBSBasic::ResetOutputs: 0.814 ms
09:10:27.025:      ┣OBSBasic::CreateHotkeys: 0.06 ms
09:10:27.025:      ┣OBSBasic::InitService: 3.993 ms
09:10:27.025:      ┣OBSBasic::InitPrimitives: 0.133 ms
09:10:27.025:      ┗OBSBasic::Load: 396.397 ms
09:10:27.025: obs_hotkey_thread(25 ms): min=0.003 ms, median=0.006 ms, max=108.027 ms, 99th percentile=0.121 ms, 99.9998% below 25 ms
09:10:27.025: audio_thread(Audio): min=0.005 ms, median=0.295 ms, max=98.743 ms, 99th percentile=0.528 ms
09:10:27.025:  ┗receive_audio: min=0.001 ms, median=0.255 ms, max=8.764 ms, 99th percentile=0.413 ms, 0.625842 calls per parent call
09:10:27.025:    ┣buffer_audio: min=0 ms, median=0.001 ms, max=0.95 ms, 99th percentile=0.002 ms
09:10:27.025:    ┗do_encode: min=0.015 ms, median=0.251 ms, max=8.761 ms, 99th percentile=0.407 ms
09:10:27.025:      ┣encode(Track1): min=0.015 ms, median=0.23 ms, max=2.941 ms, 99th percentile=0.371 ms
09:10:27.025:      ┗send_packet: min=0.002 ms, median=0.015 ms, max=8.465 ms, 99th percentile=0.062 ms
09:10:27.025: obs_graphics_thread(33.3667 ms): min=0.069 ms, median=0.389 ms, max=204.339 ms, 99th percentile=0.825 ms, 99.9995% below 33.367 ms
09:10:27.025:  ┣tick_sources: min=0.001 ms, median=0.009 ms, max=204.218 ms, 99th percentile=0.023 ms
09:10:27.025:  ┣output_frame: min=0.056 ms, median=0.299 ms, max=109.405 ms, 99th percentile=0.634 ms
09:10:27.025:  ┃ ┗gs_context(video->graphics): min=0.056 ms, median=0.298 ms, max=109.405 ms, 99th percentile=0.633 ms
09:10:27.025:  ┃   ┣render_video: min=0.002 ms, median=0.263 ms, max=109.297 ms, 99th percentile=0.582 ms
09:10:27.025:  ┃   ┃ ┣render_main_texture: min=0.001 ms, median=0.103 ms, max=108.986 ms, 99th percentile=0.236 ms
09:10:27.025:  ┃   ┃ ┣render_convert_texture: min=0.005 ms, median=0.011 ms, max=0.556 ms, 99th percentile=0.029 ms, 0.625848 calls per parent call
09:10:27.025:  ┃   ┃ ┗output_gpu_encoders: min=0 ms, median=0.037 ms, max=1.367 ms, 99th percentile=0.088 ms, 0.625848 calls per parent call
09:10:27.025:  ┃   ┗gs_flush: min=0.003 ms, median=0.038 ms, max=82.941 ms, 99th percentile=0.17 ms
09:10:27.025:  ┗render_displays: min=0 ms, median=0.087 ms, max=47.022 ms, 99th percentile=0.168 ms
09:10:27.025: send_packet: min=0.001 ms, median=0.012 ms, max=6.599 ms, 99th percentile=0.052 ms
09:10:27.025: =================================================
09:10:27.025: == Profiler Time Between Calls ==================
09:10:27.025: obs_hotkey_thread(25 ms): min=24.024 ms, median=25.008 ms, max=132.635 ms, 87.2262% within ±2% of 25 ms (0.037024% lower, 12.7367% higher)
09:10:27.025: obs_graphics_thread(33.3667 ms): min=0.265 ms, median=33.367 ms, max=204.342 ms, 99.989% within ±2% of 33.367 ms (0.00548585% lower, 0.00556204% higher)
09:10:27.025: =================================================
09:10:27.261: Number of memory leaks: 1

 

[Suslik V]

...Any ideas how to troubleshoot it?

No.

Few times I was able to hang the OBS UI with small html page: https://obsproject.com/forum/thread...t-play-music-in-headphones.164572/post-604343 (it calls pause/stop recording etc) on page access permissions change. But that's all. And I don't think it is related to your issue.

If developers will be able to reproduce your issue with the Output Timer, then it will be fixed. I think so.
For now, I can only recommend to try some standalone clock/watch with alarm, smartphone's timer etc.

 

[dege13]

Unfortunately I am recording 4-6 hour VHS tapes, so I cannot always watch it and stop it on time. That is why I need to use the Output Timer. I have now done over 250 tapes with OBS. I have another 450 to record still. This bug is a significant time waster for me. I will work on trying to reproduce the issue on another computer. I will post here if I find more details on how to reproduce. I suspect it will have no problem reproducing on another PC if I try a bunch of short recordings in a row. It does not seem version of PC or even encoder specific so far with my current data set.

If I am able to give reliable steps to reproduce, do you suggest creating an issue in GitHub to get it looked at?

 

[Suslik V]

...If I am able to give reliable steps to reproduce, do you suggest creating an issue in GitHub to get it looked at?

Yes.

But don't expect much, development is slow process and job can be done before the issue will be fixed. Some small mistakes are fixed in years. Also, look for workarounds: hotkeys + autohotkey scripts (don't forget to hold keydown state for ~10...50ms or OBS can skip it, here was example of howto - https://obsproject.com/forum/thread...rking-on-windows-obs-studio.54472/post-239288). Don't forget about automation via lua, python, external plugins like Advanced Scene Switcher from the https://obsproject.com/forum/plugins/ section of the forum (it has timer events, and despite the original name - it is very powerful tool).

 

[dege13]

Thanks for the tips. I have worked in software for over 15 years, I realize a fix can take a while or never happen if its an edge case. You are right, I probably should look at my own automation for stopping the recording if the OBS one is unreliable.

 

[dege13]

I was able to reproduce it easily on another computer I tried.

Steps to reproduce:
Open OBS studio
Open Output Timer
Set record timer for 10 seconds (just to make repeating fast)
Start recording with output timer
Wait for the issue to happen or the timer to stop
Repeat until the issue happens
(You can identify the issue by the Output Timer showing the Stop button for recording, but the main OBS window showing the Start Recording button)

I found that it happens every time I try these steps within 5 to 12 recordings.
I have recorded screen recording, got the OBS log, and will reproduce again with a debugger attached to see if I can find any more specifics for the developers.

 

[Suslik V]

It seems that this issue was addressed by next PRs (was fixed in most recent OBS):

obs-ffmpeg: Initialize stopping member variable to false by RytoEX · Pull Request #9900 · obsproject/obs-studio

Description If an output has already stopped, but its StopRecording function was called again, then ffmpeg_mux_stop would be called and set stopping to true. On the next output start, OBS would o...

github.com

frontend-tools: Fix multiple signal-slot connections on output timer by matt818 · Pull Request #9813 · obsproject/obs-studio

Description This will fix the output timer bug from issue #6558. If you use the output timer too many times in a run of the program, issues start happening where on every other run of the output ti...

github.com

(original issue on github was never reflected in this thread, but now it is).