Question / Help Suddenly "Frames skipped due to encoder lag"

C

clark

New Member
I've been streaming using the same settings and the same hardware for months, but for some reason today I've started seeing "WARNING: Taking too long to encode, skipping frames". It's happened several times today. I've attached one of the logs, see 14:32:13.

Why would this suddenly start happening when I haven't changed anything?

Code: 
11:17:38: =====Stream Start: 2014-06-01, 11:17:38===============================================
11:17:38:   Multithreaded optimizations: On
11:17:38:   Base resolution: 1280x720
11:17:38:   Output resolution: 1280x720
11:17:38: ------------------------------------------
11:17:38: Loading up D3D10 on AMD Radeon HD 6800 Series (Adapter 1)...
11:17:38: ------------------------------------------
11:17:38: Audio Format: 48000 Hz
11:17:38: ------------------------------------------
11:17:38: Audio Channels: 2 Ch
11:17:38: Playback device Default
11:17:38: ------------------------------------------
11:17:38: Using desktop audio input: Speakers (Realtek High Definition Audio)
11:17:38: ------------------------------------------
11:17:38: Audio Encoding: AAC
11:17:38:     bitrate: 128
11:17:38: Using Window Capture
11:17:38: Using bitmap image
11:17:38: ------------------------------------------
11:17:38:     device: Logitech HD Webcam C270,
11:17:38:     device id \\?\usb#vid_046d&pid_0825&mi_00#6&27bc71e9&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{bbefb6c7-2fc4-4139-bb8b-a58bba724083},
11:17:38:     chosen type: I420, usingFourCC: false, res: 640x360 - 640x360, frameIntervals: 333333-2000000
11:17:38:     use buffering: true - 17000000, fourCC: 'I420'
11:17:38:     audio device: Microphone (HD Webcam C270),
11:17:38:     audio device id (null),
11:17:38:
11:17:38:     device audio info - bits per sample: 16, channels: 2, samples per sec: 44100, block size: 4
11:17:38: Using directshow input
11:17:43: Using bitmap image
11:17:43: Using text output
11:17:43: ------------------------------------------
11:17:43:     device: Elgato Game Capture HD,
11:17:43:     device id {39F50F4C-99E1-464a-B6F9-D605B4FB5918},
11:17:43:     chosen type: UYVY, usingFourCC: false, res: 1280x720 - 1280x720, frameIntervals: 333333-333333
11:17:43:     use buffering: false - 0, fourCC: 'UYVY'
11:17:43:
11:17:43:     device audio info - bits per sample: 16, channels: 2, samples per sec: 48000, block size: 4
11:17:44: Using directshow input
11:17:44: Scene buffering time set to 700
11:17:44: ------------------------------------------
11:17:44: Video Encoding: x264
11:17:44:     fps: 30
11:17:44:     width: 1280, height: 720
11:17:44:     preset: veryfast
11:17:44:     profile: main
11:17:44:     keyint: 60
11:17:44:     CBR: yes
11:17:44:     CFR: yes
11:17:44:     max bitrate: 2500
11:17:44:     buffer size: 2500
11:17:44: ------------------------------------------
11:17:46: Using RTMP service: Twitch / Justin.tv
11:17:46:   Server selection: rtmp://live.justin.tv/app
11:17:46:   Interface: Intel(R) Ethernet Connection I217-V (ethernet, 1000 mbps)
11:17:46: Completed handshake with rtmp://live.justin.tv/app in 138 ms.
11:17:47: SO_SNDBUF was at 8192
11:17:47: SO_SNDBUF is now 65536
11:17:48: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 131072 (buffer: 16519 / 335872)
11:17:50: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 262144 (buffer: 49191 / 335872)
11:17:54: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 524288 (buffer: 0 / 335872)
11:18:11: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 10
11:25:33: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 490
11:26:19: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 270
12:21:42: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 250
12:23:20: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 260
12:23:43: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 270
12:31:14: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 220
12:40:29: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 290
12:56:55: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 1048576 (buffer: 0 / 335872)
13:01:03: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 550
13:18:38: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 560
14:32:13: Total frames encoded: 350068, total frames duplicated: 54254 (15.50%)
14:32:13: Number of frames skipped due to encoder lag: 46424 (13.26%)
14:32:13: Total frames rendered: 302248, number of late frames: 2410 (0.80%) (it's okay for some frames to be late)
14:32:13: RTMPPublisher::SocketLoop: Graceful loop exit
14:32:13: Average send payload: 6218 bytes, average send interval: 18 ms
14:32:13: Number of times waited to send: 0, Waited for a total of 0 bytes
14:32:13: Number of b-frames dropped: 0 (0%), Number of p-frames dropped: 0 (0%), Total 0 (0%)
14:32:13: Number of bytes sent: 3842604384
14:32:16:
14:32:16: Profiler time results:
14:32:16:
14:32:16: ==============================================================
14:32:16: video thread frame - [100%] [avg time: 4.992 ms] [children: 71.3%] [unaccounted: 28.7%]
14:32:16: | scene->Preprocess - [59.9%] [avg time: 2.992 ms]
14:32:16: | GPU download and conversion - [11.4%] [avg time: 0.567 ms] [children: 11%] [unaccounted: 0.401%]
14:32:16: | | flush - [9.17%] [avg time: 0.458 ms]
14:32:16: | | CopyResource - [1.72%] [avg time: 0.086 ms]
14:32:16: | | conversion to 4:2:0 - [0.0601%] [avg time: 0.003 ms]
14:32:16: Convert444Thread - [100%] [avg time: 1.203 ms] [children: 99.2%] [unaccounted: 0.831%]
14:32:16: | Convert444toNV12 - [99.2%] [avg time: 1.193 ms]
14:32:16: encoder thread frame - [100%] [avg time: 6.429 ms] [children: 0.918%] [unaccounted: 99.1%]
14:32:16: | sending stuff out - [0.918%] [avg time: 0.059 ms]
14:32:16: ==============================================================
14:32:16:
14:32:16:
14:32:16: Profiler CPU results:
14:32:16:
14:32:16: ==============================================================
14:32:16: video thread frame - [cpu time: avg 2.628 ms, total 794404 ms] [avg calls per frame: 1]
14:32:16: | scene->Preprocess - [cpu time: avg 2.13 ms, total 643863 ms] [avg calls per frame: 1]
14:32:16: | GPU download and conversion - [cpu time: avg 0.087 ms, total 26567 ms] [avg calls per frame: 1]
14:32:16: | | flush - [cpu time: avg 0.046 ms, total 14196.1 ms] [avg calls per frame: 1]
14:32:16: | | CopyResource - [cpu time: avg 0.018 ms, total 5694.04 ms] [avg calls per frame: 1]
14:32:16: | | conversion to 4:2:0 - [cpu time: avg 0.003 ms, total 1060.81 ms] [avg calls per frame: 1]
14:32:16: Convert444Thread - [cpu time: avg 1.104 ms, total 333920 ms] [avg calls per frame: 1]
14:32:16: | Convert444toNV12 - [cpu time: avg 1.099 ms, total 332376 ms] [avg calls per frame: 1]
14:32:16: encoder thread frame - [cpu time: avg 1.201 ms, total 420579 ms] [avg calls per frame: 1]
14:32:16: | sending stuff out - [cpu time: avg 0.043 ms, total 15069.7 ms] [avg calls per frame: 1]
14:32:16: ==============================================================
14:32:16:
14:32:16: =====Stream End: 2014-06-01, 14:32:16=================================================
14:32:19: Memory Leaks Were Detected.
14:32:19:
 
Last edited:
R

rakunvar

Member
Just from the quick log anaylze you should try "You do not have buffering enabled on your Elgato. This is known to cause audio desync. Check the "Use buffering" box in the Elgato source properties and set the amount to 0 ms."

You probably should also post the other info above the "
17:38: =====Stream Start: 2014-06-01, 11:17:38===============================================" So everyone can see CPU/GPU/Modules/etc.

I know sometimes the server I connect to gives me weird issues and I swap it. Looks like some weird issues with the Webcam and connection perhaps? You using a wired connection? There's a small program to check your ping to the different twitch servers etc I think is under tools here perhaps..

Hope something helps lol, bored atm so trying to lend a hand around.
 
C

clark

New Member
Switched to a different twitch server, no improvement. Yes, I'm using a wired connection. I just don't understand why it suddenly started doing this when I didn't change anything. Here is the first part of that same log:
Code: 
11:04:38: Open Broadcaster Software v0.613b - 32bit (´・ω・｀)
11:04:38: -------------------------------
11:04:38: CPU Name: Intel(R) Core(TM) i3-4130 CPU @ 3.40GHz
11:04:38: CPU Speed: 3392MHz
11:04:38: Physical Memory:  4095MB Total, 4095MB Free
11:04:38: stepping id: 3, model 60, family 6, type 0, extmodel 1, extfamily 0, HTT 1, logical cores 4, total cores 2
11:04:38: monitor 1: pos={-1920, 0}, size={1920, 1080}
11:04:38: monitor 2: pos={0, 0}, size={1920, 1080}
11:04:38: Windows Version: 6.1 Build 7601 S
11:04:38: Aero is Enabled
11:04:38: -------------------------------
11:04:38: OBS Modules:
11:04:38: Base Address     Module
11:04:38: 01210000         OBS.exe
11:04:38: 71A60000         OBSApi.dll
11:04:38: 71A20000         DShowPlugin.dll
11:04:38: 71A00000         GraphicsCapture.dll
11:04:38: 71990000         NoiseGate.dll
11:04:38: 719E0000         PSVPlugin.dll
11:04:38: ------------------------------------------
11:04:38: Adapter 1
11:04:38:   Video Adapter: AMD Radeon HD 6800 Series
11:04:38:   Video Adapter Dedicated Video Memory: 1060839424
11:04:38:   Video Adapter Shared System Memory: 3994353664
11:04:38:   Video Adapter Output 1: pos={0, 0}, size={1920, 1080}, attached=true
11:04:38:   Video Adapter Output 2: pos={-1920, 0}, size={1920, 1080}, attached=true
11:04:38: =====Stream Start: 2014-06-01, 11:04:38===============================================
11:04:38:   Multithreaded optimizations: On
11:04:38:   Base resolution: 1280x720
11:04:38:   Output resolution: 1280x720
11:04:38: ------------------------------------------
11:04:38: Loading up D3D10 on AMD Radeon HD 6800 Series (Adapter 1)...
11:04:38: ------------------------------------------
11:04:38: Audio Format: 48000 Hz
11:04:38: ------------------------------------------
11:04:38: Audio Channels: 2 Ch
11:04:38: Playback device Default
11:04:38: ------------------------------------------
11:04:38: Using desktop audio input: Speakers (Realtek High Definition Audio)
11:04:38: ------------------------------------------
11:04:38: Audio Encoding: AAC
11:04:38:     bitrate: 128
11:04:38: Using Window Capture
11:04:38: Using bitmap image
11:04:38: ------------------------------------------
11:04:38:     device: Logitech HD Webcam C270,
11:04:38:     device id \\?\usb#vid_046d&pid_0825&mi_00#6&27bc71e9&0&0000#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{bbefb6c7-2fc4-4139-bb8b-a58bba724083},
11:04:38:     chosen type: I420, usingFourCC: false, res: 640x360 - 640x360, frameIntervals: 333333-2000000
11:04:38:     use buffering: true - 17000000, fourCC: 'I420'
11:04:38:     audio device: Microphone (HD Webcam C270),
11:04:38:     audio device id (null),
11:04:38: 
11:04:38:     device audio info - bits per sample: 16, channels: 2, samples per sec: 44100, block size: 4
11:04:38: Using directshow input
11:04:44: Using bitmap image
11:04:44: Using text output
11:04:44: ------------------------------------------
11:04:44:     device: Elgato Game Capture HD,
11:04:44:     device id {39F50F4C-99E1-464a-B6F9-D605B4FB5918},
11:04:44:     chosen type: UYVY, usingFourCC: false, res: 1280x720 - 1280x720, frameIntervals: 333333-333333
11:04:44:     use buffering: false - 0, fourCC: 'UYVY'
11:04:44: 
11:04:44:     device audio info - bits per sample: 16, channels: 2, samples per sec: 48000, block size: 4
11:04:44: Using directshow input
11:04:44: Scene buffering time set to 700
11:04:44: ------------------------------------------
11:04:44: Video Encoding: x264
11:04:44:     fps: 30
11:04:44:     width: 1280, height: 720
11:04:44:     preset: veryfast
11:04:44:     profile: main
11:04:44:     keyint: 60
11:04:44:     CBR: yes
11:04:44:     CFR: yes
11:04:44:     max bitrate: 2500
11:04:44:     buffer size: 2500
11:04:44: ------------------------------------------
11:12:31: Audio timestamp for device 'Logitech HD Webcam C270' was behind target timestamp by 300
11:16:34: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 20
11:16:35: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 10
11:16:37: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 220
11:16:39: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 70
11:16:40: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 30
11:16:42: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 70
11:16:43: Audio timestamp for device 'Elgato Game Capture HD' was behind target timestamp by 100
11:16:51: Total frames encoded: 21788, total frames duplicated: 313 (1.44%)
11:16:51: Number of frames skipped due to encoder lag: 12 (0.06%)
11:16:51: Total frames rendered: 21737, number of late frames: 37 (0.17%) (it's okay for some frames to be late)
11:16:55: 
11:16:55: Profiler time results:
11:16:55: 
11:16:55: ==============================================================
11:16:55: video thread frame - [100%] [avg time: 5.775 ms] [children: 74.2%] [unaccounted: 25.8%]
11:16:55: | scene->Preprocess - [60.3%] [avg time: 3.484 ms]
11:16:55: | GPU download and conversion - [13.9%] [avg time: 0.801 ms] [children: 13.2%] [unaccounted: 0.675%]
11:16:55: | | flush - [12.5%] [avg time: 0.719 ms]
11:16:55: | | CopyResource - [0.641%] [avg time: 0.037 ms]
11:16:55: | | conversion to 4:2:0 - [0.104%] [avg time: 0.006 ms]
11:16:55: Convert444Thread - [100%] [avg time: 2.41 ms] [children: 99.2%] [unaccounted: 0.788%]
11:16:55: | Convert444toNV12 - [99.2%] [avg time: 2.391 ms]
11:16:55: encoder thread frame - [100%] [avg time: 3.29 ms] [children: 0.365%] [unaccounted: 99.6%]
11:16:55: | sending stuff out - [0.365%] [avg time: 0.012 ms]
11:16:55: ==============================================================
11:16:55: 
11:16:55: 
11:16:55: Profiler CPU results:
11:16:55: 
11:16:55: ==============================================================
11:16:55: video thread frame - [cpu time: avg 3.621 ms, total 78718.1 ms] [avg calls per frame: 1]
11:16:55: | scene->Preprocess - [cpu time: avg 2.864 ms, total 62275.6 ms] [avg calls per frame: 1]
11:16:55: | GPU download and conversion - [cpu time: avg 0.137 ms, total 2995.22 ms] [avg calls per frame: 1]
11:16:55: | | flush - [cpu time: avg 0.086 ms, total 1887.61 ms] [avg calls per frame: 1]
11:16:55: | | CopyResource - [cpu time: avg 0.023 ms, total 514.804 ms] [avg calls per frame: 1]
11:16:55: | | conversion to 4:2:0 - [cpu time: avg 0.006 ms, total 140.402 ms] [avg calls per frame: 1]
11:16:55: Convert444Thread - [cpu time: avg 2.317 ms, total 50325.9 ms] [avg calls per frame: 1]
11:16:55: | Convert444toNV12 - [cpu time: avg 2.305 ms, total 50060.7 ms] [avg calls per frame: 1]
11:16:55: encoder thread frame - [cpu time: avg 2.365 ms, total 51480.3 ms] [avg calls per frame: 1]
11:16:55: | sending stuff out - [cpu time: avg 0.005 ms, total 124.801 ms] [avg calls per frame: 1]
11:16:55: ==============================================================
11:16:55: 
11:16:55: =====Stream End: 2014-06-01, 11:16:55=================================================
 
You must log in or register to reply here.
Top