Question / Help Growing Stream Delay

[FerretBomb]

I have had an ongoing issue where the longer a viewer watches my stream, the greater the delay between what they see and what is happening becomes. A refresh of the page brings them back to sync (6-10sec delay, normal) but the delay grows by approximately 20 seconds for every 30 minutes a viewer watches. It can be reset to 6-10 sec with another refresh at that point.

I'm assuming that this issue is on Twitch's end (with the refresh 'resetting' it temporarily), but wanted to see if there was anything I could do to mitigate, resolve, or at least minimize the effect of this growing delay behaviour on my end. Log file included below.

23:50:30: Video Source Plugin strings not found, dynamically loading 38 strings
23:50:58: Open Broadcaster Software v0.571b - 64bit (　^ω^)
23:50:58: -------------------------------
23:50:58: CPU Name: Intel(R) Core(TM) i7 CPU         920  @ 2.67GHz
23:50:58: CPU Speed: 2672MHz
23:50:58: Physical Memory:  49143MB Total, 38007MB Free
23:50:58: stepping id: 4, model 10, family 6, type 0, extmodel 0, extfamily 0, HTT 1, logical cores 8, total cores 4
23:50:58: monitor 1: pos={-1920, 0}, size={1920, 1080}
23:50:58: monitor 2: pos={0, 0}, size={1920, 1080}
23:50:58: monitor 3: pos={1920, 0}, size={1920, 1080}
23:50:58: Windows Version: 6.1 Build 7601 S
23:50:58: Aero is Enabled
23:50:58: -------------------------------
23:50:58: OBS Modules:
23:50:58: Base Address     Module
23:50:58: 000000003FB80000 OBS.exe
23:50:58: 00000000F7490000 OBSApi.dll
23:50:58: 00000000F9420000 DShowPlugin.dll
23:50:58: 00000000F9690000 GraphicsCapture.dll
23:50:58: 00000000FAF20000 NoiseGate.dll
23:50:58: 00000000F9760000 PSVPlugin.dll
23:50:58: 00000000FAE10000 scenesw.dll
23:50:58: 00000000FB4C0000 VideoSourcePluginWrapper.dll
23:50:58: 00000000F92F0000 WebSocketAPIPlugin.dll
23:50:58: ------------------------------------------
23:50:58: Adapter 1
23:50:58:   Video Adapter: AMD Radeon HD 6800 Series
23:50:58:   Video Adapter Dedicated Video Memory: 1018916864
23:50:58:   Video Adapter Shared System Memory: 4021870592
23:50:58: =====Stream Start: 2013-10-03, 23:50:58===============================================
23:50:58:   Multithreaded optimizations: On
23:50:58:   Base resolution: 1920x1080
23:50:58:   Output resolution: 1280x720
23:50:58: ------------------------------------------
23:50:58: Loading up D3D10 on AMD Radeon HD 6800 Series...
23:50:59: ------------------------------------------
23:50:59: Audio Format: 44100hz
23:50:59: Playback device Default
23:50:59: ------------------------------------------
23:50:59: Using desktop audio input: Speakers (SoundMAX Integrated Digital HD Audio)
23:50:59: ------------------------------------------
23:50:59: Using auxilary audio input: Microphone (USB Audio CODEC )
23:50:59: Using Mic QPC timestamps
23:50:59: ------------------------------------------
23:50:59: Audio Encoding: AAC
23:50:59:     bitrate: 128
23:50:59: Using bitmap image
23:50:59: ------------------------------------------
23:50:59:     device: Logitech HD Pro Webcam C920,
23:50:59:     device id \\?\usb#vid_046d&pid_082d&mi_00#6&3361f4d&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{bbefb6c7-2fc4-4139-bb8b-a58bba724083},
23:50:59:     chosen type: I420, usingFourCC: false, res: 1920x1080 - 1920x1080, frameIntervals: 333333-2000000, fourCC: 'I420'
23:50:59:     audio device: Disable,
23:50:59:     audio device id Disabled,
23:50:59: 
23:50:59: Using directshow input
23:51:00: Using Window Capture
23:51:00: Using bitmap image
23:51:00: Using text output
23:51:00: Using graphics capture
23:51:00: ------------------------------------------
23:51:00: Video Encoding: x264
23:51:00:     fps: 60
23:51:00:     width: 1280, height: 720
23:51:00:     preset: veryfast
23:51:00:     profile: high
23:51:00:     keyint: 60
23:51:00:     CBR: yes
23:51:00:     CFR: yes
23:51:00:     max bitrate: 2700
23:51:00:     buffer size: 2700
23:51:00: ------------------------------------------
23:51:00: MMDeviceAudioSource: Frequency for device 'Speakers (SoundMAX Integrated Digital HD Audio)' is 384000, samples per sec is 48000
23:51:00: MMDeviceAudioSource: Frequency for device 'Microphone (USB Audio CODEC )' is 352800, samples per sec is 44100
23:51:00: Syncing audio to video time (WARNING: you should not be doing this if you are just having webcam desync, that's a separate issue)
23:51:00: SharedTexCapture hooked
23:51:03: Total frames encoded: 186, total frames duplicated: 2 (1.08%)
23:51:03: Total frames rendered: 194, number of late frames: 0 (0.00%) (it's okay for some frames to be late)
23:51:04: 
23:51:04: Profiler time results:
23:51:04: 
23:51:04: ==============================================================
23:51:04: video thread frame - [100%] [avg time: 3.207 ms] [children: 76.4%] [unaccounted: 23.6%]
23:51:04: | scene->Preprocess - [76.4%] [avg time: 2.449 ms]
23:51:04: GPU download and conversion - [100%] [avg time: 0.235 ms] [children: 94.5%] [unaccounted: 5.53%]
23:51:04: | flush - [88.1%] [avg time: 0.207 ms]
23:51:04: | CopyResource - [5.11%] [avg time: 0.012 ms]
23:51:04: | conversion to 4:2:0 - [1.28%] [avg time: 0.003 ms]
23:51:04: Convert444Threads - [100%] [avg time: 0.888 ms] [children: 99.3%] [unaccounted: 0.676%]
23:51:04: | Convert444toNV12 - [99.3%] [avg time: 0.882 ms]
23:51:04: encoder thread frame - [100%] [avg time: 1.328 ms]
23:51:04: ==============================================================
23:51:04: 
23:51:04: 
23:51:04: Profiler CPU results:
23:51:04: 
23:51:04: ==============================================================
23:51:04: video thread frame - [cpu time: avg 2.171 ms, total 421.202 ms] [avg calls per frame: 1]
23:51:04: | scene->Preprocess - [cpu time: avg 1.849 ms, total 358.802 ms] [avg calls per frame: 1]
23:51:04: GPU download and conversion - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
23:51:04: | flush - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
23:51:04: | CopyResource - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
23:51:04: | conversion to 4:2:0 - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
23:51:04: Convert444Threads - [cpu time: avg 0.534 ms, total 187.2 ms] [avg calls per frame: 2]
23:51:04: | Convert444toNV12 - [cpu time: avg 0.49 ms, total 171.6 ms] [avg calls per frame: 2]
23:51:04: encoder thread frame - [cpu time: avg 0.537 ms, total 93.6 ms] [avg calls per frame: 1]
23:51:04: ==============================================================
23:51:04: 
23:51:04: =====Stream End: 2013-10-03, 23:51:04=================================================
00:13:13: =====Stream Start: 2013-10-04, 00:13:13===============================================
00:13:13:   Multithreaded optimizations: On
00:13:13:   Base resolution: 1920x1080
00:13:13:   Output resolution: 1280x720
00:13:13: ------------------------------------------
00:13:13: Loading up D3D10 on AMD Radeon HD 6800 Series...
00:13:13: ------------------------------------------
00:13:13: Audio Format: 44100hz
00:13:13: Playback device Default
00:13:13: ------------------------------------------
00:13:13: Using desktop audio input: Speakers (SoundMAX Integrated Digital HD Audio)
00:13:13: ------------------------------------------
00:13:13: Using auxilary audio input: Microphone (USB Audio CODEC )
00:13:13: Using Mic QPC timestamps
00:13:13: ------------------------------------------
00:13:13: Audio Encoding: AAC
00:13:13:     bitrate: 128
00:13:14: Using Window Capture
00:13:14: ------------------------------------------
00:13:14:     device: Logitech HD Pro Webcam C920,
00:13:14:     device id \\?\usb#vid_046d&pid_082d&mi_00#6&3361f4d&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{bbefb6c7-2fc4-4139-bb8b-a58bba724083},
00:13:14:     chosen type: I420, usingFourCC: false, res: 1920x1080 - 1920x1080, frameIntervals: 333333-2000000, fourCC: 'I420'
00:13:14:     audio device: Disable,
00:13:14:     audio device id Disabled,
00:13:14: 
00:13:14: Using directshow input
00:13:14: Using bitmap image
00:13:14: ------------------------------------------
00:13:14: Video Encoding: x264
00:13:14:     fps: 60
00:13:14:     width: 1280, height: 720
00:13:14:     preset: veryfast
00:13:14:     profile: high
00:13:14:     keyint: 60
00:13:14:     CBR: yes
00:13:14:     CFR: yes
00:13:14:     max bitrate: 2700
00:13:14:     buffer size: 2700
00:13:14: ------------------------------------------
00:13:14: MMDeviceAudioSource: Frequency for device 'Speakers (SoundMAX Integrated Digital HD Audio)' is 384000, samples per sec is 48000
00:13:14: MMDeviceAudioSource: Frequency for device 'Microphone (USB Audio CODEC )' is 352800, samples per sec is 44100
00:13:14: Syncing audio to video time (WARNING: you should not be doing this if you are just having webcam desync, that's a separate issue)
00:13:24: Total frames encoded: 591, total frames duplicated: 0 (0.00%)
00:13:24: Total frames rendered: 600, number of late frames: 1 (0.17%) (it's okay for some frames to be late)
00:13:25: 
00:13:25: Profiler time results:
00:13:25: 
00:13:25: ==============================================================
00:13:25: video thread frame - [100%] [avg time: 2.9 ms] [children: 80.7%] [unaccounted: 19.3%]
00:13:25: | scene->Preprocess - [80.7%] [avg time: 2.341 ms]
00:13:25: GPU download and conversion - [100%] [avg time: 0.493 ms] [children: 96.8%] [unaccounted: 3.25%]
00:13:25: | flush - [93.5%] [avg time: 0.461 ms]
00:13:25: | CopyResource - [2.64%] [avg time: 0.013 ms]
00:13:25: | conversion to 4:2:0 - [0.609%] [avg time: 0.003 ms]
00:13:25: Convert444Threads - [100%] [avg time: 0.895 ms] [children: 99.4%] [unaccounted: 0.559%]
00:13:25: | Convert444toNV12 - [99.4%] [avg time: 0.89 ms]
00:13:25: encoder thread frame - [100%] [avg time: 1.261 ms]
00:13:25: ==============================================================
00:13:25: 
00:13:25: 
00:13:25: Profiler CPU results:
00:13:25: 
00:13:25: ==============================================================
00:13:25: video thread frame - [cpu time: avg 1.82 ms, total 1092.01 ms] [avg calls per frame: 1]
00:13:25: | scene->Preprocess - [cpu time: avg 1.638 ms, total 982.806 ms] [avg calls per frame: 1]
00:13:25: GPU download and conversion - [cpu time: avg 0.104 ms, total 62.401 ms] [avg calls per frame: 1]
00:13:25: | flush - [cpu time: avg 0.104 ms, total 62.401 ms] [avg calls per frame: 1]
00:13:25: | CopyResource - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
00:13:25: | conversion to 4:2:0 - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
00:13:25: Convert444Threads - [cpu time: avg 1.035 ms, total 1201.21 ms] [avg calls per frame: 2]
00:13:25: | Convert444toNV12 - [cpu time: avg 1.035 ms, total 1201.21 ms] [avg calls per frame: 2]
00:13:25: encoder thread frame - [cpu time: avg 0.943 ms, total 546.003 ms] [avg calls per frame: 1]
00:13:25: ==============================================================
00:13:25: 
00:13:25: =====Stream End: 2013-10-04, 00:13:25=================================================
00:13:27: =====Stream Start: 2013-10-04, 00:13:27===============================================
00:13:27:   Multithreaded optimizations: On
00:13:27:   Base resolution: 1920x1080
00:13:27:   Output resolution: 1280x720
00:13:27: ------------------------------------------
00:13:27: Loading up D3D10 on AMD Radeon HD 6800 Series...
00:13:28: ------------------------------------------
00:13:28: Audio Format: 44100hz
00:13:28: Playback device Default
00:13:28: ------------------------------------------
00:13:28: Using desktop audio input: Speakers (SoundMAX Integrated Digital HD Audio)
00:13:28: ------------------------------------------
00:13:28: Using auxilary audio input: Microphone (USB Audio CODEC )
00:13:28: Using Mic QPC timestamps
00:13:28: ------------------------------------------
00:13:28: Audio Encoding: AAC
00:13:28:     bitrate: 128
00:13:28: Using Window Capture
00:13:28: ------------------------------------------
00:13:28:     device: Logitech HD Pro Webcam C920,
00:13:28:     device id \\?\usb#vid_046d&pid_082d&mi_00#6&3361f4d&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{bbefb6c7-2fc4-4139-bb8b-a58bba724083},
00:13:28:     chosen type: I420, usingFourCC: false, res: 1920x1080 - 1920x1080, frameIntervals: 333333-2000000, fourCC: 'I420'
00:13:28:     audio device: Disable,
00:13:28:     audio device id Disabled,
00:13:28: 
00:13:28: Using directshow input
00:13:28: Using bitmap image
00:13:28: ------------------------------------------
00:13:28: Video Encoding: x264
00:13:28:     fps: 60
00:13:28:     width: 1280, height: 720
00:13:28:     preset: veryfast
00:13:28:     profile: high
00:13:28:     keyint: 60
00:13:28:     CBR: yes
00:13:28:     CFR: yes
00:13:28:     max bitrate: 2700
00:13:28:     buffer size: 2700
00:13:28: ------------------------------------------
00:13:28: MMDeviceAudioSource: Frequency for device 'Speakers (SoundMAX Integrated Digital HD Audio)' is 384000, samples per sec is 48000
00:13:28: MMDeviceAudioSource: Frequency for device 'Microphone (USB Audio CODEC )' is 352800, samples per sec is 44100
00:13:28: Syncing audio to video time (WARNING: you should not be doing this if you are just having webcam desync, that's a separate issue)
00:13:58: Total frames encoded: 1742, total frames duplicated: 5 (0.29%)
00:13:58: Total frames rendered: 1751, number of late frames: 1 (0.06%) (it's okay for some frames to be late)
00:13:58: 
00:13:58: Profiler time results:
00:13:58: 
00:13:58: ==============================================================
00:13:58: video thread frame - [100%] [avg time: 2.832 ms] [children: 82.3%] [unaccounted: 17.7%]
00:13:58: | scene->Preprocess - [82.3%] [avg time: 2.331 ms]
00:13:58: GPU download and conversion - [100%] [avg time: 0.266 ms] [children: 95.1%] [unaccounted: 4.89%]
00:13:58: | flush - [89.1%] [avg time: 0.237 ms]
00:13:58: | CopyResource - [4.51%] [avg time: 0.012 ms]
00:13:58: | conversion to 4:2:0 - [1.5%] [avg time: 0.004 ms]
00:13:58: Convert444Threads - [100%] [avg time: 0.89 ms] [children: 99.3%] [unaccounted: 0.674%]
00:13:58: | Convert444toNV12 - [99.3%] [avg time: 0.884 ms]
00:13:58: encoder thread frame - [100%] [avg time: 1.247 ms]
00:13:58: ==============================================================
00:13:58: 
00:13:58: 
00:13:58: Profiler CPU results:
00:13:58: 
00:13:58: ==============================================================
00:13:58: video thread frame - [cpu time: avg 1.906 ms, total 3338.42 ms] [avg calls per frame: 1]
00:13:58: | scene->Preprocess - [cpu time: avg 1.683 ms, total 2948.42 ms] [avg calls per frame: 1]
00:13:58: GPU download and conversion - [cpu time: avg 0.035 ms, total 62.401 ms] [avg calls per frame: 1]
00:13:58: | flush - [cpu time: avg 0.008 ms, total 15.6 ms] [avg calls per frame: 1]
00:13:58: | CopyResource - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
00:13:58: | conversion to 4:2:0 - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
00:13:58: Convert444Threads - [cpu time: avg 0.86 ms, total 2979.62 ms] [avg calls per frame: 2]
00:13:58: | Convert444toNV12 - [cpu time: avg 0.86 ms, total 2979.62 ms] [avg calls per frame: 2]
00:13:58: encoder thread frame - [cpu time: avg 0.865 ms, total 1497.61 ms] [avg calls per frame: 1]
00:13:58: ==============================================================
00:13:58: 
00:13:58: =====Stream End: 2013-10-04, 00:13:58=================================================
00:14:13: Using fixed low latency mode, factor 20
00:14:13: =====Stream Start: 2013-10-04, 00:14:13===============================================
00:14:13:   Multithreaded optimizations: On
00:14:13:   Base resolution: 1920x1080
00:14:13:   Output resolution: 1280x720
00:14:13: ------------------------------------------
00:14:13: Loading up D3D10 on AMD Radeon HD 6800 Series...
00:14:14: ------------------------------------------
00:14:14: Audio Format: 44100hz
00:14:14: Playback device Default
00:14:14: ------------------------------------------
00:14:14: Using desktop audio input: Speakers (SoundMAX Integrated Digital HD Audio)
00:14:14: ------------------------------------------
00:14:14: Using auxilary audio input: Microphone (USB Audio CODEC )
00:14:14: Using Mic QPC timestamps
00:14:14: ------------------------------------------
00:14:14: Audio Encoding: AAC
00:14:14:     bitrate: 128
00:14:14: Using bitmap image
00:14:14: ------------------------------------------
00:14:14: Video Encoding: x264
00:14:14:     fps: 60
00:14:14:     width: 1280, height: 720
00:14:14:     preset: veryfast
00:14:14:     profile: high
00:14:14:     keyint: 60
00:14:14:     CBR: yes
00:14:14:     CFR: yes
00:14:14:     max bitrate: 2700
00:14:14:     buffer size: 2700
00:14:14: ------------------------------------------
00:14:14: MMDeviceAudioSource: Frequency for device 'Speakers (SoundMAX Integrated Digital HD Audio)' is 384000, samples per sec is 48000
00:14:14: MMDeviceAudioSource: Frequency for device 'Microphone (USB Audio CODEC )' is 352800, samples per sec is 44100
00:14:14: Syncing audio to video time (WARNING: you should not be doing this if you are just having webcam desync, that's a separate issue)
00:14:15: Using RTMP service: Twitch / Justin.tv
00:14:15:   Server selection: rtmp://live-dfw.justin.tv/app
00:14:15:   Interface: Marvell Yukon 88E8056 PCI-E Gigabit Ethernet Controller (ethernet, 1000 mbps)
00:14:15: Completed handshake with rtmp://live-dfw.justin.tv/app in 133 ms.
00:14:16: SO_SNDBUF was at 8192
00:14:16: SO_SNDBUF is now 65536
00:15:38: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
00:15:38:   New Scene
00:15:38: Using Window Capture
00:15:38: ------------------------------------------
00:15:38:     device: Logitech HD Pro Webcam C920,
00:15:38:     device id \\?\usb#vid_046d&pid_082d&mi_00#6&3361f4d&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{bbefb6c7-2fc4-4139-bb8b-a58bba724083},
00:15:38:     chosen type: I420, usingFourCC: false, res: 1920x1080 - 1920x1080, frameIntervals: 333333-2000000, fourCC: 'I420'
00:15:38:     audio device: Disable,
00:15:38:     audio device id Disabled,
00:15:38: 
00:15:39: Using directshow input
00:15:39: Using bitmap image
00:15:39: PERFORMANCE WARNING: Scene change took 895 ms, maybe some sources should be global sources?
00:27:23: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
00:27:23:   New Scene
00:27:23: Using bitmap image
00:27:23: Using Window Capture
00:27:23: Using bitmap image
00:27:23: Using text output
00:27:23: Using graphics capture
00:27:24: PERFORMANCE WARNING: Scene change took 915 ms, maybe some sources should be global sources?
00:27:24: SharedTexCapture hooked
00:59:18: Using bitmap image
01:00:28: Using bitmap image
01:12:42: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
01:12:42:   New Scene
01:12:42: Using Window Capture
01:12:42: Using bitmap image
01:12:54: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
01:12:54:   New Scene
01:12:54: Using bitmap image
01:12:55: Using Window Capture
01:12:55: Using bitmap image
01:12:55: Using text output
01:12:55: Using graphics capture
01:12:55: PERFORMANCE WARNING: Scene change took 958 ms, maybe some sources should be global sources?
01:12:55: SharedTexCapture hooked
01:31:24: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
01:31:24:   New Scene
01:31:24: Using Window Capture
01:31:24: Using bitmap image
01:31:41: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
01:31:41:   New Scene
01:31:41: Using bitmap image
01:31:41: Using Window Capture
01:31:41: Using bitmap image
01:31:41: Using text output
01:31:41: Using graphics capture
01:31:42: PERFORMANCE WARNING: Scene change took 1076 ms, maybe some sources should be global sources?
01:31:42: SharedTexCapture hooked
02:18:21: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
02:18:21:   New Scene
02:18:21: Using Window Capture
02:18:21: Using bitmap image
02:27:48: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
02:27:48:   New Scene
02:27:48: Using bitmap image
02:27:48: Using Window Capture
02:27:48: Using bitmap image
02:27:48: Using text output
02:27:48: Using graphics capture
02:27:49: PERFORMANCE WARNING: Scene change took 973 ms, maybe some sources should be global sources?
02:27:49: SharedTexCapture hooked
03:26:27: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
03:26:27:   New Scene
03:26:27: Using Window Capture
03:26:27: Using bitmap image
03:26:37: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
03:26:37:   New Scene
03:26:37: Using bitmap image
03:26:37: Using Window Capture
03:26:37: Using bitmap image
03:26:37: Using text output
03:26:37: Using graphics capture
03:26:38: PERFORMANCE WARNING: Scene change took 955 ms, maybe some sources should be global sources?
03:26:38: SharedTexCapture hooked
05:06:47: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
05:06:47:   New Scene
05:06:47: Using Window Capture
05:06:47: Using bitmap image
05:06:58: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
05:06:58:   New Scene
05:06:59: Using bitmap image
05:06:59: Using Window Capture
05:06:59: Using bitmap image
05:06:59: Using text output
05:06:59: Using graphics capture
05:06:59: PERFORMANCE WARNING: Scene change took 807 ms, maybe some sources should be global sources?
05:06:59: SharedTexCapture hooked
05:24:02: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
05:24:02:   New Scene
05:24:02: Using Window Capture
05:24:02: Using bitmap image
05:26:29: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
05:26:29:   New Scene
05:26:29: Using bitmap image
05:26:29: Using Window Capture
05:26:29: Using bitmap image
05:26:29: Using text output
05:26:29: Using graphics capture
05:26:30: PERFORMANCE WARNING: Scene change took 1043 ms, maybe some sources should be global sources?
05:26:30: SharedTexCapture hooked
06:41:07: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
06:41:07:   New Scene
06:41:07: Using Window Capture
06:41:08: Using bitmap image
06:41:22: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
06:41:22:   New Scene
06:41:22: Using bitmap image
06:41:22: Using Window Capture
06:41:22: Using bitmap image
06:41:22: Using text output
06:41:22: Using graphics capture
06:41:23: PERFORMANCE WARNING: Scene change took 1012 ms, maybe some sources should be global sources?
06:41:23: SharedTexCapture hooked
07:40:43: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
07:40:43:   New Scene
07:40:43: Using Window Capture
07:40:44: Using bitmap image
07:40:50: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
07:40:50:   New Scene
07:40:50: Using bitmap image
07:40:50: Using Window Capture
07:40:50: Using bitmap image
07:40:50: Using text output
07:40:50: Using graphics capture
07:40:51: PERFORMANCE WARNING: Scene change took 975 ms, maybe some sources should be global sources?
07:40:51: SharedTexCapture hooked
07:46:05: Exit signal received, terminating capture
07:46:07: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
07:46:07:   New Scene
07:46:07: Using Window Capture
07:46:07: Using bitmap image
07:47:48: ++++++++++++++++++++++++++++++++++++++++++++++++++++++
07:47:48:   New Scene
07:47:48: Using bitmap image
07:49:08: Total frames encoded: 1640673, total frames duplicated: 35891 (2.19%)
07:49:08: Total frames rendered: 1640604, number of late frames: 31 (0.00%) (it's okay for some frames to be late)
07:49:09: RTMPPublisher::SocketLoop: Graceful loop exit
07:49:09: Average send payload: 17781 bytes, average send interval: 50 ms
07:49:09: Number of times waited to send: 0, Waited for a total of 0 bytes
07:49:09: Number of b-frames dropped: 0 (0%), Number of p-frames dropped: 0 (0%), Total 0 (0%)
07:49:09: Number of bytes sent: 9700516283
07:49:09: 
07:49:09: Profiler time results:
07:49:09: 
07:49:09: ==============================================================
07:49:09: video thread frame - [100%] [avg time: 3.829 ms] [children: 77%] [unaccounted: 23%]
07:49:09: | scene->Preprocess - [77%] [avg time: 2.948 ms]
07:49:09: GPU download and conversion - [100%] [avg time: 5.57 ms] [children: 193%] [unaccounted: -93%]
07:49:09: | flush - [193%] [avg time: 10.731 ms]
07:49:09: | CopyResource - [0.287%] [avg time: 0.016 ms]
07:49:09: | conversion to 4:2:0 - [0.0718%] [avg time: 0.004 ms]
07:49:09: Convert444Threads - [100%] [avg time: 74.283 ms] [children: 1.31%] [unaccounted: 98.7%]
07:49:09: | Convert444toNV12 - [1.31%] [avg time: 0.974 ms]
07:49:09: encoder thread frame - [100%] [avg time: 4.034 ms]
07:49:09: ==============================================================
07:49:09: 
07:49:09: 
07:49:09: Profiler CPU results:
07:49:09: 
07:49:09: ==============================================================
07:49:09: video thread frame - [cpu time: avg 2.517 ms, total 4.13047e+006 ms] [avg calls per frame: 1]
07:49:09: | scene->Preprocess - [cpu time: avg 1.929 ms, total 3.1651e+006 ms] [avg calls per frame: 1]
07:49:09: GPU download and conversion - [cpu time: avg 0.095 ms, total 157296 ms] [avg calls per frame: 1]
07:49:09: | flush - [cpu time: avg 0.05 ms, total 82649.4 ms] [avg calls per frame: 1]
07:49:09: | CopyResource - [cpu time: avg 0.017 ms, total 28938.2 ms] [avg calls per frame: 1]
07:49:09: | conversion to 4:2:0 - [cpu time: avg 0.003 ms, total 5943.64 ms] [avg calls per frame: 1]
07:49:09: Convert444Threads - [cpu time: avg 0.926 ms, total 3.04044e+006 ms] [avg calls per frame: 2]
07:49:09: | Convert444toNV12 - [cpu time: avg 0.922 ms, total 3.02789e+006 ms] [avg calls per frame: 2]
07:49:09: encoder thread frame - [cpu time: avg 1.029 ms, total 1.68896e+006 ms] [avg calls per frame: 1]
07:49:09: ==============================================================
07:49:09: 
07:49:09: =====Stream End: 2013-10-04, 07:49:09=================================================
07:49:12: Video Source Plugin instance deleted; removing dynamically loaded localization strings


Last game capture log:
2013-10-03, 23:51:00: we're booting up: 
23:51:00: D3D9EndScene called
23:51:00: D3DPRESENT_PARAMETERS {
23:51:00: 	BackBufferWidth: 1
23:51:00: 	BackBufferHeight: 1
23:51:00: 	BackBufferFormat: D3DFMT_X8R8G8B8
23:51:00: 	BackBufferCount: 1
23:51:00: 	MultiSampleType: D3DMULTISAMPLE_NONE
23:51:00: 	MultiSampleQuality: 0
23:51:00: 23:51:00: 	SwapEffect: D3D9 PresentD3DSWAPEFFECT_DISCARD

23:51:00: 	hDeviceWindow: 2887316
23:51:00: 	Windowed: true
23:51:00: 	EnableAutoDepthStencil: false
23:51:00: 	AutoDepthStencilFormat: D3DFMT_UNKNOWN
23:51:00: 	Flags: None
23:51:00: 	FullScreen_RefreshRateInHz: 0
23:51:00: 	PresentationInterval: 2147483648
23:51:00: };
23:51:00: successfully set up d3d9 hooks
23:51:00: DXGI Present
23:51:00: (half life scientist) everything..  seems to be in order
23:51:00: D3D9SwapPresent called
23:51:00: DoD3D9GPUHook: success
23:51:00: D3DSURFACE_DESC {
23:51:00: 	Format: D3DFMT_X8R8G8B8
23:51:00: 	Type: D3DRTYPE_SURFACE
23:51:00: 	Usage: D3DUSAGE_RENDERTARGET 
23:51:00: 	Pool: D3DPOOL_DEFAULT
23:51:00: 	MultiSampleType: D3DMULTISAMPLE_NONE
23:51:00: 	MultiSampleQuality: 0
23:51:00: 	Width: 1920
23:51:00: 	Height: 1080
23:51:00: };
23:51:00: successfully capturing d3d9 frames via GPU
23:51:04: ---------------------- Cleared D3D9 Capture ----------------------
23:51:04: D3D9EndScene called
23:51:04: D3D9SwapPresent called
00:08:03: D3D9Reset called
00:08:03: ---------------------- Cleared D3D9 Capture ----------------------
00:08:03: D3DPRESENT_PARAMETERS {
00:08:03: 	BackBufferWidth: 1
00:08:03: 	BackBufferHeight: 1
00:08:03: 	BackBufferFormat: D3DFMT_X8R8G8B8
00:08:03: 	BackBufferCount: 1
00:08:03: 	MultiSampleType: D3DMULTISAMPLE_NONE
00:08:03: 	MultiSampleQuality: 0
00:08:03: 	SwapEffect: D3DSWAPEFFECT_DISCARD
00:08:03: 	hDeviceWindow: 2887316
00:08:03: 	Windowed: true
00:08:03: 	EnableAutoDepthStencil: false
00:08:03: 	AutoDepthStencilFormat: D3DFMT_UNKNOWN
00:08:03: 	Flags: None
00:08:03: 	FullScreen_RefreshRateInHz: 0
00:08:03: 	PresentationInterval: 2147483648
00:08:03: };
00:08:03: successfully set up d3d9 hooks
00:08:04: D3D9EndScene called
00:08:05: D3D9SwapPresent called
00:27:24: received restart event, capturing
00:27:24: DoD3D9GPUHook: success
00:27:24: D3DSURFACE_DESC {
00:27:24: 	Format: D3DFMT_X8R8G8B8
00:27:24: 	Type: D3DRTYPE_SURFACE
00:27:24: 	Usage: D3DUSAGE_RENDERTARGET 
00:27:24: 	Pool: D3DPOOL_DEFAULT
00:27:24: 	MultiSampleType: D3DMULTISAMPLE_NONE
00:27:24: 	MultiSampleQuality: 0
00:27:24: 	Width: 1920
00:27:24: 	Height: 1080
00:27:24: };
00:27:24: successfully capturing d3d9 frames via GPU
01:12:42: ---------------------- Cleared D3D9 Capture ----------------------
01:12:42: D3D9EndScene called
01:12:42: D3D9SwapPresent called
01:12:55: received restart event, capturing
01:12:55: DoD3D9GPUHook: success
01:12:55: D3DSURFACE_DESC {
01:12:55: 	Format: D3DFMT_X8R8G8B8
01:12:55: 	Type: D3DRTYPE_SURFACE
01:12:55: 	Usage: D3DUSAGE_RENDERTARGET 
01:12:55: 	Pool: D3DPOOL_DEFAULT
01:12:55: 	MultiSampleType: D3DMULTISAMPLE_NONE
01:12:55: 	MultiSampleQuality: 0
01:12:55: 	Width: 1920
01:12:55: 	Height: 1080
01:12:55: };
01:12:55: successfully capturing d3d9 frames via GPU
01:31:25: ---------------------- Cleared D3D9 Capture ----------------------
01:31:25: D3D9EndScene called
01:31:25: D3D9SwapPresent called
01:31:42: received restart event, capturing
01:31:42: DoD3D9GPUHook: success
01:31:42: D3DSURFACE_DESC {
01:31:42: 	Format: D3DFMT_X8R8G8B8
01:31:42: 	Type: D3DRTYPE_SURFACE
01:31:42: 	Usage: D3DUSAGE_RENDERTARGET 
01:31:42: 	Pool: D3DPOOL_DEFAULT
01:31:42: 	MultiSampleType: D3DMULTISAMPLE_NONE
01:31:42: 	MultiSampleQuality: 0
01:31:42: 	Width: 1920
01:31:42: 	Height: 1080
01:31:42: };
01:31:42: successfully capturing d3d9 frames via GPU
02:18:21: ---------------------- Cleared D3D9 Capture ----------------------
02:18:21: D3D9EndScene called
02:18:21: D3D9SwapPresent called
02:27:49: received restart event, capturing
02:27:49: DoD3D9GPUHook: success
02:27:49: D3DSURFACE_DESC {
02:27:49: 	Format: D3DFMT_X8R8G8B8
02:27:49: 	Type: D3DRTYPE_SURFACE
02:27:49: 	Usage: D3DUSAGE_RENDERTARGET 
02:27:49: 	Pool: D3DPOOL_DEFAULT
02:27:49: 	MultiSampleType: D3DMULTISAMPLE_NONE
02:27:49: 	MultiSampleQuality: 0
02:27:49: 	Width: 1920
02:27:49: 	Height: 1080
02:27:49: };
02:27:49: successfully capturing d3d9 frames via GPU
03:26:27: ---------------------- Cleared D3D9 Capture ----------------------
03:26:27: D3D9EndScene called
03:26:27: D3D9SwapPresent called
03:26:38: received restart event, capturing
03:26:38: DoD3D9GPUHook: success
03:26:38: D3DSURFACE_DESC {
03:26:38: 	Format: D3DFMT_X8R8G8B8
03:26:38: 	Type: D3DRTYPE_SURFACE
03:26:38: 	Usage: D3DUSAGE_RENDERTARGET 
03:26:38: 	Pool: D3DPOOL_DEFAULT
03:26:38: 	MultiSampleType: D3DMULTISAMPLE_NONE
03:26:38: 	MultiSampleQuality: 0
03:26:38: 	Width: 1920
03:26:38: 	Height: 1080
03:26:38: };
03:26:38: successfully capturing d3d9 frames via GPU
05:06:47: ---------------------- Cleared D3D9 Capture ----------------------
05:06:47: D3D9EndScene called
05:06:47: D3D9SwapPresent called
05:06:59: received restart event, capturing
05:06:59: DoD3D9GPUHook: success
05:06:59: D3DSURFACE_DESC {
05:06:59: 	Format: D3DFMT_X8R8G8B8
05:06:59: 	Type: D3DRTYPE_SURFACE
05:06:59: 	Usage: D3DUSAGE_RENDERTARGET 
05:06:59: 	Pool: D3DPOOL_DEFAULT
05:06:59: 	MultiSampleType: D3DMULTISAMPLE_NONE
05:06:59: 	MultiSampleQuality: 0
05:06:59: 	Width: 1920
05:06:59: 	Height: 1080
05:06:59: };
05:06:59: successfully capturing d3d9 frames via GPU
05:24:02: ---------------------- Cleared D3D9 Capture ----------------------
05:24:02: D3D9EndScene called
05:24:02: D3D9SwapPresent called
05:26:30: received restart event, capturing
05:26:30: DoD3D9GPUHook: success
05:26:30: D3DSURFACE_DESC {
05:26:30: 	Format: D3DFMT_X8R8G8B8
05:26:30: 	Type: D3DRTYPE_SURFACE
05:26:30: 	Usage: D3DUSAGE_RENDERTARGET 
05:26:30: 	Pool: D3DPOOL_DEFAULT
05:26:30: 	MultiSampleType: D3DMULTISAMPLE_NONE
05:26:30: 	MultiSampleQuality: 0
05:26:30: 	Width: 1920
05:26:30: 	Height: 1080
05:26:30: };
05:26:30: successfully capturing d3d9 frames via GPU
06:41:08: ---------------------- Cleared D3D9 Capture ----------------------
06:41:08: D3D9EndScene called
06:41:08: D3D9SwapPresent called
06:41:23: received restart event, capturing
06:41:23: DoD3D9GPUHook: success
06:41:23: D3DSURFACE_DESC {
06:41:23: 	Format: D3DFMT_X8R8G8B8
06:41:23: 	Type: D3DRTYPE_SURFACE
06:41:23: 	Usage: D3DUSAGE_RENDERTARGET 
06:41:23: 	Pool: D3DPOOL_DEFAULT
06:41:23: 	MultiSampleType: D3DMULTISAMPLE_NONE
06:41:23: 	MultiSampleQuality: 0
06:41:23: 	Width: 1920
06:41:23: 	Height: 1080
06:41:23: };
06:41:23: successfully capturing d3d9 frames via GPU
07:40:44: ---------------------- Cleared D3D9 Capture ----------------------
07:40:44: D3D9EndScene called
07:40:44: D3D9SwapPresent called
07:40:51: received restart event, capturing
07:40:51: DoD3D9GPUHook: success
07:40:51: D3DSURFACE_DESC {
07:40:51: 	Format: D3DFMT_X8R8G8B8
07:40:51: 	Type: D3DRTYPE_SURFACE
07:40:51: 	Usage: D3DUSAGE_RENDERTARGET 
07:40:51: 	Pool: D3DPOOL_DEFAULT
07:40:51: 	MultiSampleType: D3DMULTISAMPLE_NONE
07:40:51: 	MultiSampleQuality: 0
07:40:51: 	Width: 1920
07:40:51: 	Height: 1080
07:40:51: };
07:40:51: successfully capturing d3d9 frames via GPU

 

[Lain]

When the connection has instabilities it can cause data to buffer. However it's usually accompanied by frame drops. That could just be user -> twitch, or it could be streamer -> twitch. For example if it's user -> twitch then if they refresh the stream it can fix the problem, but if it's streamer -> twitch then there's not much you can do about it.

That's just my best guess however, I don't know all the details of how the servers and such are set up.

 

[FerretBomb]

Yeah, no frame drops on my end. Almost no late frames. Happens to people who see no stutter at all. It's maddening as I'm the only one I've seen who gets this problem, and Twitch has no idea either (or hasn't responded).
Especially odd as it happens to people watching the transcoded quality levels as well, which pretty well cements it as a Twitch issue in my mind. Ah well. If I figure out anything I can do on my end to help reduce/eliminate it, I'll post here again.

Really need to give another streaming service a try, and see if the issue is duplicated there.

 

[Lain]

Yea, please do. I unfortunately don't always have all the answers, I can only hypothesize the various reasons why this could happen.

Do you know if refreshing the stream while watching "catches" it up? Because if so, then it's viewer buffering, not your fault, and probably not twitch's fault. If the delay stays the same regardless of refreshing, then that at least gives more of a potential hint that it may be streamer and/or server.

 

[FerretBomb]

Yup, mentioned that in my initial post (I know you glance over them quick, no worries); a refresh of the page, or stopping the player for about 10-20 seconds (closing the connection and forcing a fresh stream, assumedly) brings it back to the 6-10 second delay, at which point it starts growing again at the same rate.

Happens either on Source, or on low/med/high transcoding (which is confusing, as that should be standardized output!) on browser, mobile, or console.

Maddening, as I know a few other OBS streamers who don't get this, and can't figure out exactly what the difference is between my and their setup. May just have to bite the lemon and see if it still happens on XSplit, for testing purposes.

 

[Boildown]

07:49:08: Total frames encoded: 1640673, total frames duplicated: 35891 (2.19%)
07:49:08: Total frames rendered: 1640604, number of late frames: 31 (0.00%) (it's okay for some frames to be late)

Doesn't this mean your CPU is having a bit of trouble keeping up? Its not a lot yet, not noticeable, but maybe try doing something to lower CPU impact for testing purposes, and see if the problem goes away. Lower your FPS, or go to SuperFast preset. And you have a hyperthreaded quad core, which means x264 will use 12 threads, which in my testing isn't ideal... try setting "threads=10".

If the duplicated frames number goes towards zero and the problem still exists, then I'm stumped.

00:14:14: Video Encoding: x264
00:14:14: fps: 60
00:14:14: width: 1280, height: 720
00:14:14: preset: veryfast
00:14:14: profile: high
00:14:14: keyint: 60

Oh yeah, why isn't your keyint double your FPS when streaming to Twitch? You have it set even lower... which is weird. Normally people want it higher, not lower. Maybe that has something to do with it?

 

[FerretBomb]

Nope, if the CPU was having issues, I'd be getting late (lagged) frames; and 31 late out of 1640604 I can deal with (and most likely is due to scene switching or other momentary system 'hiccups'). :)
No idea on the duplicated frames bit. One guess would be that as my game is running at 60fps and the stream is too, if the game dropped below 60 at any point it'd send a duplicated frame. That's just spitballing though.

My keyint is equal to my FPS because I got tired of Twitch mis-identifying my key interval as 2.06 or 2.40, so instead of a key every 2 seconds, I said screw it and am sending one every second. Keyint is how many frames to render before sending another keyframe, so lower = more often. Slightly more work for the system, but as I stick between 60-80% utilization at all times, I have the headroom to do it... and if it keeps me consistently at 'Excellent' on the Twitch stream quality auto-detect, it's worth it.
Also should help cut down (slightly) on the time spent correcting from a dropped frame issue on the client-side, AFAIK (the bit where the motion is retained, but the pixels aren't updated, so you end up with a section of wall animating as someone's face for example... if you've watched digital TV, you've likely seen this at least once).

 

[Lain]

Yea, if the refresh of the stream resets it then I think this might be something beyond your control, as that's twitch->user rather than streamer->twitch. At least it should be, the only other possible cause would be your computer's internal timer is very slightly off, usually due to improper overclocks. Outside of that though, if it's twitch->user it's probably either the user/twitch having congestion issues

 

[FerretBomb]

Damn. Well, at least good to get confirmation of that. Thanks much, man!

Yeah, no overclocks. Was considering it, but I already get desktop audio drift unless I force sound to use video timestamps, and need to swap my stock heatsink out for the upgraded one I've had on the shelf for a couple years (PITA to take everything apart just to attach that backplate, and clean off all the melted paraffin from the stock pad). Even if I do, it's just going to be mild... more than enough performance for the moment, and I'd rather retain the longevity of a stock-clocked system.

Out of curiosity, what DO the duplicated frames mean? I've been seeing that, but no idea what causes it or if it should be a source of concern.

 

[Lain]

Wait you have to use that option? Hm, it feels like that problem might correlate, though I'd have to see the computer directly to really understand what's going on

 

[FerretBomb]

Yeah, no idea why but if I leave it off, about half the time the desktop audio and video drift out of sync one way or the other.
If I can send along any helpful info or testing cases with debug-level logging, do let me know (would be kind of difficult to see the actual machine after all).