Understanding OBS Studio log

Understanding OBS Studio log

This is a short description of OBS log and the info contained in each section.
I´m not a programmer, just an OBS enthusiast. So, if any OBS developer or advanced user can correct my mistakes, we can make a complete guide to help auto diagnose of problems with OBS Studio (For example, "Profiler results" section is still a black box for me)

I have mixed several logs, so timestamps are not exactly correlative

Info in each section depends on your own scenary: system, OS, OBS Configuration, devices in use...

Also, when you change settings in OBS, log registers those changes. Some examples included.

So, here it is the guide:

==================================================

COMPUTER DESCRIPTION, OPERATING SYSTEM AND OBS VERSION IN USE

11:58:21.087: CPU Name: Intel(R) Core(TM) i7-5700HQ CPU @ 2.70GHz
11:58:21.087: CPU Speed: 2694MHz
11:58:21.087: Physical Cores: 4, Logical Cores: 8
11:58:21.087: Physical Memory: 8107MB Total, 3697MB Free
11:58:21.087: Windows Version: 10.0 Build 10586 (revision: 589; 64-bit)
11:58:21.087: Running as administrator: false
11:58:21.087: Aero is Enabled (Aero is always on for windows 8 and above)
11:58:21.088: Portable mode: false
11:58:21.100: OBS 0.16.6 (64bit, windows)
11:58:21.100: ---------------------------------


AUDIO CONFIGURATION

11:58:21.100: ---------------------------------
11:58:21.100: audio settings reset:
11:58:21.100: samples per sec: 48000
11:58:21.100: speakers: 2


OPENGL WARNING
(only present when OpenGL renderer is selected)

21:51:05.842: Warning: The OpenGL renderer is currently in use. On windows, the OpenGL renderer can decrease capture performance due to the lack of specific features used to maximize capture performance. The Direct3D 11 renderer is recommended instead.

11:58:21.138: ---------------------------------


DIRECT3D 11 VIDEO ADAPTERS AND OBS WORKING ADAPTER
(only present when DIRECT3D 11 renderer is selected)

11:58:21.138: Initializing D3D11..
11:58:21.138: Available Video Adapters:
11:58:21.140: Adapter 1: Intel(R) HD Graphics 5600
11:58:21.140: Dedicated VRAM: 134217728
11:58:21.140: Shared VRAM: 4250439680
11:58:21.141: output 1: pos={0, 0}, size={1920, 1080}, attached=true
11:58:21.141: Adapter 2: NVIDIA GeForce GTX 960M
11:58:21.141: Dedicated VRAM: 2092826624
11:58:21.141: Shared VRAM: 4250439680
11:58:21.143: Loading up D3D11 on adapter Intel(R) HD Graphics 5600 (0)
11:58:21.149: D3D11 loaded sucessfully, feature level used: 45056
11:58:21.753: ---------------------------------


VIDEO SETTINGS


11:58:21.753: video settings reset:
11:58:21.753: base resolution: 1920x1080
11:58:21.753: output resolution: 1280x720
11:58:21.753: downscale filter: Bicubic
11:58:21.753: fps: 30/1
11:58:21.753: format: NV12
11:58:21.754: ---------------------------------


AUDIO AND VIDEO ENCODERS


AUDIO AAC ENCODER:
11:58:21.757: [CoreAudio encoder]: Adding CoreAudio AAC encoder --> IF NOT: [CoreAudio encoder]: CoreAudio AAC encoder not installed on the system or couldn't be loaded
AMD GPU CODEC:
11:58:21.757: [AMF Encoder] Version 1.4.2.3
11:58:21.758: [AMF Encoder] Runtime Library is on Version 1;3;0;5;1.2;201611151603. --> IF NOT: [AMF Encoder] Unable to load 'amfrt64.dll', error code 126.
11:58:21.758: [AMF Encoder] Runtime is on Version 1.3.0.5, compiled against Version 1.3.0.5. --> IF NOT: [AMF Encoder] Uncaught Exception: Unable to load 'amfrt64.dll', error code 126.
OpenGL: (never seen a "positive" result in this section) NOTE: found one. If you have those DLLs these 3 lines are not present in your log QUESTION FOR DEVELOPERS: What are these DLL for?
** These are Browser Source DLLs. Failed to load because those DLLs are not a plugin.
11:58:21.767: Required module function 'obs_module_load' in module '../../obs-plugins/64bit/libcef.dll' not found, loading of module failed
11:58:21.768: Required module function 'obs_module_load' in module '../../obs-plugins/64bit/libEGL.dll' not found, loading of module failed
11:58:21.768: Required module function 'obs_module_load' in module '../../obs-plugins/64bit/libGLESv2.dll' not found, loading of module failed
11:58:21.769: Failed to load 'en-US' text for module: 'obs-browser.dll'
11:58:21.769: [browser_source: 'Version: 1.26.0']
NVIDIA GPU CODEC:
11:58:21.771: NVENC supported --> IF NOT: LoadLibrary failed for 'nvEncodeAPI64.dll': (null) (126)
11:58:21.785: VLC found, VLC video source enabled --> IF NOT: Couldn't find VLC installation, VLC video source disabled NOTE: if you run OBS 64 bits, you need VLC 64 bits. Same for 32 bits.
11:58:21.803: No blackmagic support : No Blackmagic devices attached.
11:58:22.201: ---------------------------------

OBS MODULES

11:58:22.201: Loaded Modules:
11:58:22.201: win-wasapi.dll
11:58:22.201: win-mf.dll
11:58:22.201: win-dshow.dll
11:58:22.201: win-decklink.dll
11:58:22.201: win-capture.dll
11:58:22.201: vlc-video.dll
11:58:22.201: text-freetype2.dll
11:58:22.201: rtmp-services.dll
11:58:22.201: obs-x264.dll
11:58:22.201: obs-transitions.dll
11:58:22.201: obs-text.dll
11:58:22.201: obs-qsv11.dll
11:58:22.202: obs-outputs.dll
11:58:22.202: obs-filters.dll
11:58:22.202: obs-ffmpeg.dll
11:58:22.202: obs-browser.dll
11:58:22.202: image-source.dll
11:58:22.202: frontend-tools.dll
11:58:22.202: enc-amf.dll
11:58:22.202: coreaudio-encoder.dll
11:58:22.202: ==== Startup complete ===============================================

11:58:22.204: All scene data cleared

AUDIO DEVICES IN USE

Successful
21:18:49.854: WASAPI: Device 'Altavoces (Realtek High Definition Audio)' initialized
21:18:49.901: adding 23 milliseconds of audio buffering, total audio buffering is now 23 milliseconds
21:18:49.930: WASAPI: Device 'Micrófono (Realtek High Definition Audio)' initialized

Successful and using a game capture device
16:33:27.780: WASAPI: Device 'Turtle Beach Headset (Turtle Beach Ear Force Atlas)' initialized
16:33:27.801: WASAPI: Device 'Microphone (Yeti Stereo Microphone)' initialized
16:33:27.822: adding 46 milliseconds of audio buffering, total audio buffering is now 46 milliseconds
16:33:42.779: [game-capture: 'Game Capture 2'] error acquiring, scale is bad
16:33:44.278: warning: deprecated pixel format used, make sure you did set range correctly
16:33:44.447: warning: deprecated pixel format used, make sure you did set range correctly

Unsuccessful
11:58:22.204: ------------------------------------------------
11:58:22.221: [WASAPISource::TryInitialize]:[Speakers (Realtek High Definition Audio)] Failed to get initialize audio client: 88890008
11:58:22.221: [WASAPISource::WASAPISource] Device '{0.0.0.00000000}.{418f18a5-9993-4fbb-a6e6-ba7e9a7c9e0f}' not found. Waiting for device
11:58:22.272: WASAPI: Device 'Microphone (Realtek High Definition Audio)' initialized
11:58:22.276: [WASAPISource::TryInitialize]:[Speakers (Realtek High Definition Audio)] Failed to get initialize audio client: 88890008
11:58:22.276: [WASAPISource::WASAPISource] Device 'default' not found. Waiting for device
11:58:22.310: adding 21 milliseconds of audio buffering, total audio buffering is now 21 milliseconds

STARTUP SCENE

11:58:22.484: Switched to scene 'Scene'


SCENES DEFINITION

11:58:22.485: ------------------------------------------------
11:58:22.485: Loaded scenes:
11:58:22.485: - scene 'Scene':
11:58:22.485: - source: 'Client' (window_capture)
11:58:22.485: - source: 'Game Capture' (game_capture)
11:58:22.485: - source: 'Facecam' (dshow_input)
11:58:22.485: - source: 'Desktop Audio' (wasapi_output_capture)
11:58:22.485: ------------------------------------------------present)

CAPTURE DEVICES

11:58:22.503: ---------------------------------
11:58:22.506: [DShow Device: 'Facecam'] settings updated:
11:58:22.506: video device: BisonCam, NB Pro
11:58:22.506: video path: \\?\usb#vid_5986&pid_014c&mi_00#7&1ab720b2&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global
11:58:22.506: resolution: 320x240
11:58:22.506: fps: 30.00 (interval: 333333)
11:58:22.506: format: YUY2

Another case:
22:07:57.177: [DShow Device: 'Video Capture Device'] settings updated:
22:07:57.177: video device: USB2.0 1.3M UVC WebCam
22:07:57.177: video path: \\?\usb#vid_04f2&pid_b033&mi_00#6&3a7fe718&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\global
22:07:57.177: resolution: 640x480
22:07:57.177: fps: 30.00 (interval: 333333)
22:07:57.177: format: YUY2

Another case:
22:57:29.081: [DShow Device: 'Capture Card'] settings updated:
22:57:29.081: video device: Elgato Game Capture HD
22:57:29.081: video path: __elgato
22:57:29.081: resolution: 1280x720
22:57:29.081: fps: 60.00 (interval: 166666)
22:57:29.081: format: UYVY
22:57:29.081: using video device audio: yes
22:57:29.081: sample rate: 48000
22:57:29.081: channels: 2
22:57:29.081: audio type: Capture

OBS UPDATE CHECK
11:58:22.903: Update check: last known remote version is 0.16.6

DURING THE SESSION; USER CHANGED AUDIO SETTINGS

11:58:50.250: [WASAPISource::TryInitialize]:[Speakers (Realtek High Definition Audio)] Failed to get initialize audio client: 88890008
11:58:50.250: [WASAPISource::WASAPISource] Device 'default' not found. Waiting for device
11:58:50.254: Settings changed (audio)
11:58:50.254: ------------------------------------------------
11:58:59.076: [WASAPISource::WASAPISource] Device '{0.0.0.00000000}.{418f18a5-9993-4fbb-a6e6-ba7e9a7c9e0f}' not found. Waiting for device

OTHER EXAMPLE OF CHANGE DURING SESSION

21:54:36.123: ------------------------------------------------
22:07:55.918: User added source 'Video Capture Device' (dshow_input) to scene 'Escena'
22:07:56.288: Video Capture Device: DecodeDeviceId failed
22:07:56.288: Video Capture Device: Video configuration failed
22:07:57.177: ---------------------------------
........
22:28:28.494: User Removed source 'Video Capture Device' (dshow_input) from scene 'Escena'


STREAMING SESSION INFO

Output settings
12:24:33.523: [x264 encoder: 'streaming_h264'] preset: veryfast
12:24:33.523: [x264 encoder: 'streaming_h264'] profile: main
12:24:33.525: [x264 encoder: 'streaming_h264'] settings:
12:24:33.525: rate_control: CBR
12:24:33.525: bitrate: 3500
12:24:33.525: buffer size: 3500
12:24:33.525: crf: 0
12:24:33.525: fps_num: 60
12:24:33.525: fps_den: 1
12:24:33.525: width: 1280
12:24:33.525: height: 720
12:24:33.525: keyint: 120
12:24:33.525: vfr: off
12:24:33.525:
12:24:33.525: [x264 encoder: 'streaming_h264'] custom settings: scenecut=0
Audio settings
12:24:33.534: [Media Foundation AAC: 'Track1']: encoder created
12:24:33.534: bitrate: 128
12:24:33.534: channels: 2
12:24:33.534: sample rate: 48000
12:24:33.534: bits-per-sample: 16
12:24:33.534:
Connection to streaming service
12:24:33.535: [rtmp stream: 'adv_stream'] Connecting to RTMP URL rtmp://live-jfk.twitch.tv/app...
12:24:33.547: [rtmp stream: 'adv_stream'] Interface: Killer e2200 Gigabit Ethernet Controller (ethernet, 1000 mbps)
12:24:34.704: [rtmp stream: 'adv_stream'] Connection to rtmp://live-jfk.twitch.tv/app successful
12:24:34.710: ==== Streaming Start ===============================================
12:25:12.857: [rtmp stream: 'adv_stream'] User stopped the stream
12:25:12.857: Output 'adv_stream': stopping
12:25:12.857: Output 'adv_stream': Total encoded frames: 2359
12:25:12.857: Output 'adv_stream': Total drawn frames: 2359

ONLY PRESENT WITH LAG/STALLS:
14:53:13.698: Output 'adv_stream': Number of skipped frames due to encoding lag: 4735 (7.7%)
14:53:13.698: Output 'adv_stream': Number of lagged frames due to rendering lag/stalls: 76 (0.1%)
14:53:13.698: Output 'adv_stream': Number of dropped frames due to insufficient bandwidth/connection stalls: 70 (0.1%)

12:25:12.859: ==== Streaming Stop ================================================


RECORDING SESSION INFO

Output settings
18:30:06.541: [x264 encoder: 'recording_h264'] preset: veryfast
18:30:06.541: [x264 encoder: 'recording_h264'] profile: high
18:30:06.542: [x264 encoder: 'recording_h264'] settings:
18:30:06.542: rate_control: CRF
18:30:06.542: bitrate: 0
18:30:06.542: buffer size: 0
18:30:06.542: crf: 20
18:30:06.542: fps_num: 60
18:30:06.542: fps_den: 1
18:30:06.542: width: 1920
18:30:06.542: height: 1080
18:30:06.542: keyint: 120
18:30:06.542: vfr: off
18:30:06.542:
Audio settings
18:30:06.552: [Media Foundation AAC: 'Stream Audio']: encoder created
18:30:06.552: bitrate: 160
18:30:06.552: channels: 2
18:30:06.552: sample rate: 44100
18:30:06.552: bits-per-sample: 16
18:30:06.552:
18:30:06.553: ---------------------------------
18:30:06.553: [FFmpeg aac encoder: 'Microphone'] bitrate: 320, channels: 2
18:30:06.586: ==== Recording Start ===============================================
18:30:06.586: [ffmpeg muxer: 'adv_file_output'] Writing file 'D:/PC Gameplays/2016-12-16 18-30-06.mp4'...
18:30:38.256: [ffmpeg muxer: 'adv_file_output'] Output of file 'D:/PC Gameplays/2016-12-16 18-30-06.mp4' stopped
18:30:38.256: Output 'adv_file_output': stopping
18:30:38.256: Output 'adv_file_output': Total encoded frames: 1882
18:30:38.256: Output 'adv_file_output': Total drawn frames: 1901

ONLY PRESENT WITH LAG/STALLS:
18:30:38.256: Output 'adv_file_output': Number of skipped frames due to encoding lag: 779 (41.4%)
18:30:38.256: Output 'adv_file_output': Number of lagged frames due to rendering lag/stalls: 1 (0.1%)
18:30:38.256: ==== Recording Stop ================================================


OBS CLOSING INFO

11:59:02.939: ==== Shutting down ==================================================
11:59:02.948: Switched to scene '(null)'
11:59:03.078: WASAPI: Device 'Microphone (Realtek High Definition Audio)' Terminated
11:59:03.085: All scene data cleared
11:59:03.085: ------------------------------------------------
11:59:03.192: Freeing OBS context data

PROFILER RESULTS (I´m lost with this section, Anyone can give us some light? Please, developers, CORRECT my missinterpretations. Thank you!)
11:59:03.246: == Profiler Results =============================
OBS LOAD TIMES
Describes time needed to load OBS, showing info for each module

11:59:03.246: run_program_init: 1732.63 ms
11:59:03.246: ┣OBSApp::AppInit: 1.758 ms
11:59:03.246: ┃ ┗OBSApp::InitLocale: 0.91 ms
11:59:03.246: ┗OBSApp::OBSInit: 1513.52 ms
11:59:03.246: ┣obs_startup: 2.176 ms
11:59:03.246: ┗OBSBasic::OBSInit: 1483.04 ms
11:59:03.246: ┣OBSBasic::InitBasicConfig: 0.358 ms
11:59:03.246: ┣OBSBasic::ResetAudio: 0.994 ms
11:59:03.246: ┣OBSBasic::ResetVideo: 652.995 ms
11:59:03.246: ┣OBSBasic::InitOBSCallbacks: 0.014 ms
11:59:03.246: ┣OBSBasic::InitHotkeys: 0.048 ms
11:59:03.246: ┣obs_load_all_modules: 446.793 ms
11:59:03.246: ┃ ┣obs_init_module(coreaudio-encoder.dll): 0.793 ms
11:59:03.246: ┃ ┣obs_init_module(enc-amf.dll): 0.689 ms
11:59:03.246: ┃ ┣obs_init_module(frontend-tools.dll): 1.415 ms
11:59:03.246: ┃ ┣obs_init_module(image-source.dll): 0.005 ms
11:59:03.246: ┃ ┣obs_init_module(obs-browser.dll): 0.077 ms
11:59:03.246: ┃ ┣obs_init_module(obs-ffmpeg.dll): 0.818 ms
11:59:03.246: ┃ ┣obs_init_module(obs-filters.dll): 0.011 ms
11:59:03.246: ┃ ┣obs_init_module(obs-outputs.dll): 0.005 ms
11:59:03.246: ┃ ┣obs_init_module(obs-qsv11.dll): 6.141 ms
11:59:03.246: ┃ ┣obs_init_module(obs-text.dll): 0.488 ms
11:59:03.246: ┃ ┣obs_init_module(obs-transitions.dll): 0.008 ms
11:59:03.246: ┃ ┣obs_init_module(obs-x264.dll): 0.001 ms
11:59:03.246: ┃ ┣obs_init_module(rtmp-services.dll): 0.299 ms
11:59:03.246: ┃ ┣obs_init_module(text-freetype2.dll): 0.057 ms
11:59:03.247: ┃ ┣obs_init_module(vlc-video.dll): 0.076 ms
11:59:03.247: ┃ ┣obs_init_module(win-capture.dll): 0.198 ms
11:59:03.247: ┃ ┣obs_init_module(win-decklink.dll): 12.472 ms
11:59:03.247: ┃ ┣obs_init_module(win-dshow.dll): 2.249 ms
11:59:03.247: ┃ ┣obs_init_module(win-mf.dll): 385.739 ms
11:59:03.247: ┃ ┣obs_init_module(win-wasapi.dll): 0.005 ms
11:59:03.247: ┃ ┗reset_win32_symbol_paths: 0.669 ms
11:59:03.247: ┣OBSBasic::ResetOutputs: 0.332 ms
11:59:03.247: ┣OBSBasic::CreateHotkeys: 0.048 ms
11:59:03.247: ┣OBSBasic::InitService: 0.233 ms
11:59:03.247: ┣OBSBasic::InitPrimitives: 0.349 ms
11:59:03.247: ┗OBSBasic::Load: 282.372 ms
OBS HOTKEY THREAD
Time used per hotkey reading process

11:59:03.247: obs_hotkey_thread(25 ms): min=0.003 ms, median=0.009 ms, max=8.896 ms, 99th percentile=1.491 ms, 100% below 25 ms
OBS AUDIO THREAD
Time used for audio encoding process

11:59:03.247: audio_thread(Audio): min=0 ms, median=0.05 ms, max=27.579 ms, 99th percentile=0.363 ms
OBS VIDEO THREAD
Time needed to compose, encode and transmit a frame
Summary:

11:59:03.247: obs_video_thread(33.3333 ms): min=1.341 ms, median=3.483 ms, max=160.496 ms, 99th percentile=46.314 ms, 95.2576% below 33.333 ms
Note: first numer, 33.3333 ms means OBS set to 30 FPS [1000/30] This is the maximum time to complete composing and encoding a frame. Any frame above this number means a lag frame. In this case, 95.2576% where good frames, the rest are lagged frames
Composing frame
11:59:03.247: ┣tick_sources: min=0.002 ms, median=0.178 ms, max=157.429 ms, 99th percentile=1.146 ms
This is the time used to collect all sources and generate a frame
Enconding frame
11:59:03.247: ┣render_displays: min=0.001 ms, median=0.931 ms, max=91.371 ms, 99th percentile=43.43 ms
This is the time needed to encode a frame. In this case: 43.43 ms > 33.3333 [1000/43.43 = 23 FPS] This is a clear case of lagging frames
Sending frame
11:59:03.247: ┗output_frame: min=1.023 ms, median=2.285 ms, max=13.091 ms, 99th percentile=4.757 ms
Time to upload a frame to streaming server. (Worst case 13.091 ms correspond qith 1000/13.091 = 76 FPS.So, no networ problems here)
11:59:03.247: ┣gs_context(video->graphics): min=0.16 ms, median=0.367 ms, max=10.378 ms, 99th percentile=1.851 ms
11:59:03.247: ┃ ┣render_video: min=0.109 ms, median=0.268 ms, max=6.593 ms, 99th percentile=1.077 ms
11:59:03.247: ┃ ┃ ┣render_main_texture: min=0.015 ms, median=0.117 ms, max=1.499 ms, 99th percentile=0.569 ms
11:59:03.247: ┃ ┃ ┣render_output_texture: min=0.013 ms, median=0.06 ms, max=6.481 ms, 99th percentile=0.455 ms
11:59:03.247: ┃ ┃ ┣render_convert_texture: min=0.002 ms, median=0.039 ms, max=5.92 ms, 99th percentile=0.222 ms
11:59:03.247: ┃ ┃ ┗stage_output_texture: min=0 ms, median=0.032 ms, max=1.244 ms, 99th percentile=0.192 ms
11:59:03.247: ┃ ┣download_frame: min=0 ms, median=0.013 ms, max=9.248 ms, 99th percentile=0.062 ms
11:59:03.247: ┃ ┗gs_flush: min=0.021 ms, median=0.068 ms, max=6.978 ms, 99th percentile=0.3 ms
11:59:03.247: ┗output_video_data: min=0.817 ms, median=1.847 ms, max=4.266 ms, 99th percentile=2.898 ms
OBS VIDEO THREAD
11:59:03.247: video_thread(video): min=0.001 ms, median=0.005 ms, max=0.134 ms, 99th percentile=0.023 ms
11:59:03.247: =================================================
11:59:03.247: == Profiler Time Between Calls ==================
11:59:03.247: obs_hotkey_thread(25 ms): min=24.625 ms, median=25.02 ms, max=105.573 ms, 95.4464% within ±2% of 25 ms (0% lower, 4.55362% higher)
11:59:03.247: obs_video_thread(33.3333 ms): min=8.479 ms, median=33.334 ms, max=160.547 ms, 94.599% within ±2% of 33.333 ms (0.490998% lower, 4.90998% higher)
11:59:03.247: =================================================

Number of c++ objects that was lost in the PC's RAM memory (application "forgets" them for some reason). The best value is 0 (nothing "forgotten"). Useful info for developers
11:59:03.299: Number of memory leaks: 1
Author
EBrito
First release
Last update
Rating
3.00 star(s) 2 ratings
Top