How to identify the actual framerate/see frame loss of a recorded video in OBS?

[Gene90]

Hello again, dear OBS Community and the OBS Team!

Before i get into my question a bit more detailed, i do want to apologize if this question was asked before. I did a bit of searching on the forum but haven't quite found
a thread that would suit my question - people generally ask A LOT about frames being lost when STREAMING, I on the other hand am curious about frames being lost during recording, not streaming.

So just a bit of an introduction: I want to describe some things so that you may understand more clearly the question that i have in mind. I have been using primarily OBS to record video gaming footage and i love the program, but now and then i did try out some other software - one example would be DXtory, it had this whole lossless codec feature that i thought OBS didn't have (i was wrong), so i used that program for a bit. One interesting feature that I noticed that DXtory has is this bottleneck overlay; any time you start recording gameplay footage and something goes wrong it shows the actual framedrop and what's causing it. This way you know that you were planning to make a let's say 60 FPS video but you are now fully aware that certain parts of it are 30-40FPS instead due to a slow hard drive or something along those lines.

Now, I know that OBS has a very detailed log and I am fairly confident that if a video recording did have some stutters, it's going to be shown in the log? My questions are essentially: Does this log only apply to frames lost during streaming or does this apply also to recording? (I sure hope so). And how do you pinpoint how much frames you lost if any? Is this defined by the "Total frames output" and "Total frames drawn" or is there more to it?

I uploaded my log of a 40 minute gameplay video on lossless quality - the video looks smooth but i just want to make sure that if any frames were in fact lost, i will know about it so that i can adjust my gear or settings.

Thank you for your answers in advance and forgive me my annoyance :)

 

[Gene90]

Sorry for the bump, but if possible, can someone clarify these two questions that i had? I think it is important in the long run for other people who do recordings as well.

1: Whenever the log refers to any dropped frames, are the dropped frames exclusive to streaming or can this be applied to recording as well?
2: What parts of the generated log file can indicate how many frames were properly processed and just in general, how can a user pinpoint this, knowing with certainty that the recording was unhampered by faulty hardware, software, etc... I do understand that when there is a drastic frame loss then it will be obvious in the video itself, but let's say that you got 50 frames instead of 60 - It's not something that will be easily distinguishable.

Again, my apologies for the bump and tremendous gratitude for any answers in advance.

 

[dmemphis]

Good questions. I think posing this will help a lot of OBS users if it is responded to.
There are probably several areas in OBS where its not clear what is specific to the stream vs record... and add to that the Decklink outputs too.

 

[Gene90]

No answer as of yet? :(

This is very, very unfortunate - an answer from a competent user would give us clarity. Maybe there is no way to determine the frame loss after all? At least we would know this for certain if someone would confirm it.

 

[koala]

In the View menu, there is the "Stats" window:

It's also available as dock, so you can pin it along with the other docks like this:

You see 3 counters for lost frames. "Frames missed due to rendering lag" counts dropped frames during composition. Composition is the process of overlaying, filtering and rendering all sources onto the canvas. It also takes place if you have only one source and actually nothing to composite. Frames dropped here means, it takes longer to acquire (capture) a frame from all sources and put it into the canvas frame buffer. Having dropped frames here is an indication of GPU overload.

"Skipped frames due to encoding lag" is the next counter. If the encoder needs more time to encode a frame than the available time between frames, it has to skip the next frame. Having dropped frames here is an indication of encoder circuit overload (if hardware encoder) or CPU overload (if software encoder).

The third counter is "Dropped Frames (Network)". It is relevant only if you stream. It counts data packets OBS needs to skip due to network bandwidth congestion. It's an indication of a bad or slow internet connection to the server you are streaming to.

All these counters are logged in the logfile at the end of a recording or streaming session, if they are greater than 0. If they are 0, they are not logged. The exception is ffmpeg custom output: for this, no stats and no recording details are written - only that recording started and ended. Perhaps it is because all of the different encoders within ffmpeg have different means of returning such statistics, and it is too much work to collect that all. But simple and advanced output do write encoder statistics.

To help debugging, OBS writes a statistics footer on program exit. It looks like this:

17:03:19.320: == Profiler Results =============================
17:03:19.320: run_program_init: 5341.98 ms
17:03:19.320:  ┣OBSApp::AppInit: 43.713 ms
17:03:19.320:  ┃ ┗OBSApp::InitLocale: 6.961 ms
17:03:19.320:  ┗OBSApp::OBSInit: 5187.46 ms
17:03:19.320:    ┣obs_startup: 4.458 ms
17:03:19.320:    ┗OBSBasic::OBSInit: 4577.82 ms
17:03:19.320:      ┣OBSBasic::InitBasicConfig: 0.434 ms
17:03:19.320:      ┣OBSBasic::ResetAudio: 0.174 ms
17:03:19.320:      ┣OBSBasic::ResetVideo: 529.045 ms
17:03:19.320:      ┣OBSBasic::InitOBSCallbacks: 0.006 ms
17:03:19.320:      ┣OBSBasic::InitHotkeys: 0.037 ms
17:03:19.320:      ┣obs_load_all_modules: 1294.98 ms
17:03:19.320:      ┃ ┣obs_init_module(coreaudio-encoder.dll): 1.632 ms
17:03:19.320:      ┃ ┣obs_init_module(decklink-captions.dll): 0.022 ms
17:03:19.320:      ┃ ┣obs_init_module(decklink-ouput-ui.dll): 0.469 ms
17:03:19.320:      ┃ ┣obs_init_module(enc-amf.dll): 42.67 ms
17:03:19.320:      ┃ ┣obs_init_module(frontend-tools.dll): 266.56 ms
17:03:19.320:      ┃ ┣obs_init_module(image-source.dll): 0.005 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-browser.dll): 0.36 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-ffmpeg.dll): 1.236 ms
17:03:19.320:      ┃ ┃ ┗nvenc_check: 1.187 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-filters.dll): 0.078 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-outputs.dll): 0.012 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-qsv11.dll): 68.282 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-text.dll): 0.284 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-transitions.dll): 0.011 ms
17:03:19.320:      ┃ ┣obs_init_module(obs-vst.dll): 0.002 ms
17:03:19.321:      ┃ ┣obs_init_module(obs-x264.dll): 0.001 ms
17:03:19.321:      ┃ ┣obs_init_module(rtmp-services.dll): 5.441 ms
17:03:19.321:      ┃ ┣obs_init_module(StreamFX.dll): 187.198 ms
17:03:19.321:      ┃ ┣obs_init_module(text-freetype2.dll): 0.077 ms
17:03:19.321:      ┃ ┣obs_init_module(vlc-video.dll): 9.689 ms
17:03:19.321:      ┃ ┣obs_init_module(win-capture-audio.dll): 0.003 ms
17:03:19.321:      ┃ ┣obs_init_module(win-capture.dll): 63.001 ms
17:03:19.321:      ┃ ┣obs_init_module(win-decklink.dll): 3.783 ms
17:03:19.321:      ┃ ┣obs_init_module(win-dshow.dll): 1.743 ms
17:03:19.321:      ┃ ┣obs_init_module(win-mf.dll): 0 ms
17:03:19.321:      ┃ ┣obs_init_module(win-wasapi.dll): 0.015 ms
17:03:19.321:      ┃ ┗reset_win32_symbol_paths: 0.439 ms
17:03:19.321:      ┣OBSBasic::ResetOutputs: 2.818 ms
17:03:19.321:      ┣OBSBasic::CreateHotkeys: 0.04 ms
17:03:19.321:      ┣OBSBasic::InitService: 9.629 ms
17:03:19.321:      ┣OBSBasic::InitPrimitives: 588.815 ms
17:03:19.321:      ┗OBSBasic::Load: 1710.46 ms
17:03:19.321: obs_hotkey_thread(25 ms): min=0.004 ms, median=0.01 ms, max=2.926 ms, 99th percentile=0.283 ms, 100% below 25 ms
17:03:19.321: audio_thread(Audio): min=0 ms, median=0.035 ms, max=2.25 ms, 99th percentile=0.152 ms
17:03:19.321: obs_graphics_thread(33.3333 ms): min=0.118 ms, median=0.426 ms, max=1141.3 ms, 99th percentile=1.772 ms, 99.8347% below 33.333 ms
17:03:19.321:  ┣tick_sources: min=0.001 ms, median=0.022 ms, max=1117.79 ms, 99th percentile=0.07 ms
17:03:19.321:  ┣output_frame: min=0.072 ms, median=0.207 ms, max=593.369 ms, 99th percentile=0.698 ms
17:03:19.321:  ┃ ┗gs_context(video->graphics): min=0.072 ms, median=0.207 ms, max=593.368 ms, 99th percentile=0.696 ms
17:03:19.321:  ┃   ┣render_video: min=0.002 ms, median=0.011 ms, max=3.05 ms, 99th percentile=0.256 ms
17:03:19.321:  ┃   ┃ ┗render_main_texture: min=0.002 ms, median=0.007 ms, max=3.048 ms, 99th percentile=0.249 ms
17:03:19.321:  ┃   ┗gs_flush: min=0.068 ms, median=0.192 ms, max=593.354 ms, 99th percentile=0.531 ms
17:03:19.321:  ┗render_displays: min=0.001 ms, median=0.174 ms, max=4.278 ms, 99th percentile=1.031 ms
17:03:19.321: OBSBasic::ResetVideo: min=22.996 ms, median=30.731 ms, max=41.483 ms, 99th percentile=41.483 ms
17:03:19.321: obs_graphics_thread(16.6667 ms): min=0.298 ms, median=0.502 ms, max=2.924 ms, 99th percentile=1.47 ms, 100% below 16.667 ms
17:03:19.321:  ┣tick_sources: min=0.017 ms, median=0.023 ms, max=2.568 ms, 99th percentile=0.054 ms
17:03:19.321:  ┣output_frame: min=0.129 ms, median=0.256 ms, max=1.372 ms, 99th percentile=0.655 ms
17:03:19.321:  ┃ ┗gs_context(video->graphics): min=0.129 ms, median=0.256 ms, max=1.37 ms, 99th percentile=0.654 ms
17:03:19.321:  ┃   ┣render_video: min=0.021 ms, median=0.032 ms, max=0.868 ms, 99th percentile=0.239 ms
17:03:19.321:  ┃   ┃ ┗render_main_texture: min=0.018 ms, median=0.028 ms, max=0.854 ms, 99th percentile=0.232 ms
17:03:19.321:  ┃   ┗gs_flush: min=0.083 ms, median=0.218 ms, max=1.165 ms, 99th percentile=0.526 ms
17:03:19.321:  ┗render_displays: min=0.138 ms, median=0.206 ms, max=1.607 ms, 99th percentile=0.814 ms
17:03:19.321: obs_graphics_thread(16.6667 ms): min=0.288 ms, median=0.643 ms, max=4.947 ms, 99th percentile=2.422 ms, 100% below 16.667 ms
17:03:19.321:  ┣tick_sources: min=0.016 ms, median=0.022 ms, max=0.448 ms, 99th percentile=0.057 ms
17:03:19.321:  ┣output_frame: min=0.099 ms, median=0.26 ms, max=2.625 ms, 99th percentile=0.708 ms
17:03:19.321:  ┃ ┗gs_context(video->graphics): min=0.099 ms, median=0.26 ms, max=2.625 ms, 99th percentile=0.706 ms
17:03:19.321:  ┃   ┣render_video: min=0.007 ms, median=0.029 ms, max=2.357 ms, 99th percentile=0.273 ms
17:03:19.321:  ┃   ┃ ┗render_main_texture: min=0.004 ms, median=0.026 ms, max=2.353 ms, 99th percentile=0.267 ms
17:03:19.321:  ┃   ┗gs_flush: min=0.081 ms, median=0.225 ms, max=1.372 ms, 99th percentile=0.558 ms
17:03:19.321:  ┗render_displays: min=0.127 ms, median=0.343 ms, max=4.16 ms, 99th percentile=1.734 ms
17:03:19.321: OBSBasic::ResetOutputs: 0.294 ms
17:03:19.321: obs_graphics_thread(16.6667 ms): min=0.111 ms, median=0.779 ms, max=94.361 ms, 99th percentile=2.477 ms, 99.9921% below 16.667 ms
17:03:19.321:  ┣tick_sources: min=0.002 ms, median=0.023 ms, max=54.733 ms, 99th percentile=0.063 ms
17:03:19.321:  ┣output_frame: min=0.087 ms, median=0.295 ms, max=64.731 ms, 99th percentile=0.812 ms
17:03:19.321:  ┃ ┗gs_context(video->graphics): min=0.087 ms, median=0.295 ms, max=64.731 ms, 99th percentile=0.811 ms
17:03:19.321:  ┃   ┣render_video: min=0.004 ms, median=0.048 ms, max=12.008 ms, 99th percentile=0.301 ms
17:03:19.321:  ┃   ┃ ┗render_main_texture: min=0.002 ms, median=0.044 ms, max=12.005 ms, 99th percentile=0.295 ms
17:03:19.321:  ┃   ┗gs_flush: min=0.073 ms, median=0.241 ms, max=62.721 ms, 99th percentile=0.597 ms
17:03:19.321:  ┗render_displays: min=0.001 ms, median=0.453 ms, max=3.704 ms, 99th percentile=1.719 ms
17:03:19.321: =================================================
17:03:19.321: == Profiler Time Between Calls ==================
17:03:19.321: obs_hotkey_thread(25 ms): min=24.769 ms, median=25.452 ms, max=54.497 ms, 54.2166% within ±2% of 25 ms (0% lower, 45.7834% higher)
17:03:19.321: obs_graphics_thread(33.3333 ms): min=6.619 ms, median=33.333 ms, max=1141.31 ms, 99.6693% within ±2% of 33.333 ms (0.165358% lower, 0.165358% higher)
17:03:19.321: obs_graphics_thread(16.6667 ms): min=16.501 ms, median=16.667 ms, max=16.833 ms, 100% within ±2% of 16.667 ms (0% lower, 0% higher)
17:03:19.321: obs_graphics_thread(16.6667 ms): min=16.395 ms, median=16.667 ms, max=16.94 ms, 100% within ±2% of 16.667 ms (0% lower, 0% higher)
17:03:19.321: obs_graphics_thread(16.6667 ms): min=5.63 ms, median=16.667 ms, max=94.372 ms, 99.9724% within ±2% of 16.667 ms (0.0137975% lower, 0.0137975% higher)
17:03:19.321: =================================================

You can see a statistical overview about the time needed for the several capture, rendering and encoding subroutines.

 

[dmemphis]

Very informative, thanks!

 

[Gene90]

Thank you tremendously for the informative and thorough answer, koala - i really do appreciate it!

I'm probably going to make a dummy out of myself by asking this, but at the end of the recording, this footer looks quite detailed - is there a way to calculate and "convert" all of this information into something that could be perceived as an average fps of the entire recording?

 

[Gene90]

Also, Koala, I have found some of your previous answers in this thread, trying to grasp everything as much as i can despite not really having a knack for it. One very important question that i also now have is: If you look at my logfile, the "obs_graphics_thread" seems to show okayish (?) results, however - the "obs_graphics_thread" under the "Time Between Calls" shows entirely different, seemingly bad results. Is it supposed to be that way or am i misunderstanding something? Again, thank you so much for your expertise in advance!

 

[Gene90]

Sorry, can't edit my previous post, this is the earlier thread that i was referring to, i forgot to paste the link

Question / Help - Recording in (a very) high Frame Rate

I have a project requiring recording in a very high frame rate. On OBS Settings/Video I can see that it is possible to increase frame rate. "Fractional FPS Value" provides unlimited frame rate value. I'm not familiar with such issues so if someone can enlight me, it would be most appreciated. -...

obsproject.com

 

[koala]

Your logfile shows no issues with lost frames, because you used ffmpeg custom output. So no info here.
The footer also doesn't show any issues. You need to correctly interpret the values. If you don't know what all the numbers mean, don't guess - just ignore the footer.

To explain some of the terminology.
min= is the minimum time encountered for one frame
max= is the maximum time encountered for one frame
median= Exactly half of all processed frames took less than this value, and the other half took more than this value.
99th percentile= 99% of all processed frames are lower than this value

How to use median and 99th percentile:
Median gives an idea about the common time required for a frame. You might think the average would be a better measure, but the average is weighted, so rarer values get less significance, and if it comes to lags, even rare lags are visually significant.

99th percentile is a means to exclude statistical outliers. It excludes the highest 1% of the values. Values that are very rare and not significant. If the 99th percentile is within the allowed time for a frame, it can be considered ok.

If the max values are very high (more than 20-30 times the time allowed for a frame), although median and 99th percentile seem to look good, it's a sign of system overload.
If the min values are are near the time allowed for a frame, it's a sign of OBS using all resources the hardware is able to provide.

As far as I know (I'm not exactly sure, since there is no explicit documentation about this):
tick_sources is the time required for reading all the sources.
output_frame is the time required to composite and output the composited frame to the encoder.
render_displays is probably the time required to render the preview window or projectors of OBS
The subroutines below output_frame are the several internal processing steps: compositing, filtering, copy to encoder, encode.

What you should do is using some other encoder, so you will see the statistics of lost and lagged frames. It seems you're using lossless encoding, which will use utvideo codec, which will not write these statistics. Use something different in simple or advanced output mode.

 

[Gene90]

I see, so that "Simple" mode, Lossless quality setting does not provide adequate information in terms of the bitrate. Well, i made one more log, this time i chose "Advanced" mode and a Lossless rate control. As the Encoder, i chose NVIDIA HVENC. Would this setup differ in terms of video quality from the simple lossless setting?

Also, i am uploading the log and it does seem like there might be a strain on the system despite the video looking pretty smooth. The max value is "562.736 ms" whereas the median is "0.654 ms". The game is pretty old and seems to stutter from time to time, whether im recording or not (this isn't OBS related in other words).

And that last question again relating to the "Profiler Time Between Calls" in the footer section, i guess it's not related to the overall stats? Because the obs_graphics_thread shows different numbers, but i presume it has to be that way?

 

[koala]

If Nvidia lossless is as lossless as utvideo lossless (the codec used if you use it in simple mode), depends on your point of view. Both have in common that no detail is removed.
If it comes to your question, sorry, but I don't really understand what you mean. The profiler section in the log is an extension to the ingame stats. It tells about the timing and may help detect bottlenecks. The stats window just does reporting, but gives no analysis detail.

The duplicated entries in the bottommost part correspond to changes in the output settings. If you change the output settings, for example a different encoder or a different fps, an extra obs_graphics_thread entry is shown for every setting you used.

 

[Gene90]

If Nvidia lossless is as lossless as utvideo lossless (the codec used if you use it in simple mode), depends on your point of view. Both have in common that no detail is removed.
If it comes to your question, sorry, but I don't really understand what you mean. The profiler section in the log is an extension to the ingame stats. It tells about the timing and may help detect bottlenecks. The stats window just does reporting, but gives no analysis detail.

The duplicated entries in the bottommost part correspond to changes in the output settings. If you change the output settings, for example a different encoder or a different fps, an extra obs_graphics_thread entry is shown for every setting you used.

Sorry for not properly defining my question, Koala. Im am simply wondering why:

obs_graphics_thread(16.6667 ms): min=0.052 ms, median=0.654 ms, max=562.736 ms, 99th percentile=1.054 ms, 99.9969% below 16.667 ms (seemingly good results?)

Whereas:

== Profiler Time Between Calls ==================
17:03:23.592: obs_hotkey_thread(25 ms): min=24.789 ms, median=25.541 ms, max=460.54 ms, 47.2808% within ±2% of 25 ms (0% lower, 52.7192% higher)
17:03:23.592: obs_graphics_thread(16.6667 ms): min=3.927 ms, median=16.667 ms, max=562.739 ms, 99.9938% within ±2% of 16.667 ms (0.00307754% lower, 0.00307754% higher)

The median here is completely different?

 

[koala]

These are different threads that do different work. A thread is kind of a mini-process within OBS, running independently from (and working together with) other threads within OBS. The thread that watches the hotkeys seems to "tick" every 25 ms, while the thread that performs video composition ticks with the framerate, in this case for 60 fps 1/60 s = 16.667 ms.

 

[Gene90]

I see, thank you for all of your comprehensive answers, Koala!