Question / Help Synchronisation problems with Avermedia devices

M

maikyyy

New Member
hello,

last time i have a big problem with synchronisation. when audio is desynched, stream begins to lag and dropping frames while the nginx server is trying to resync the stream.

i have running two pcs for capturing tv channels and restream to multiple rooms in my house. everything works fine about 3 months, and now i have big problems. have tried to fix this with internal nginx server (without internet) in my lan network, but there is no difference. my internet is not the problem.

first

i7 4770k @4400 mhz
asus z87 pro
2x 4gb ram 2400 mhz
2x avermedia game capture hd (C127)

capturing tv 1280x720@50

second

i7 3770k @4500mhz
gigabyte z77x-d3h
2x 4gb ram 1600 mhz
2x avermedia h727 hdmi capture

capturing tv 1280x720@50

both systems has the same issue with desynched audio timestamps.

i have 2 internet connections with 20mbits upload.

tested with obs 0.625b and latest test build.

Code: 
09:49:38: Failed loading CUDA dll
09:53:03: Settings::Video: Enabling Aero
09:57:11: Open Broadcaster Software v0.63b (test build 3) - 64bit ( ^?^)
09:57:11: -------------------------------
09:57:11: CPU Name: Intel(R) Core(TM) i7-3770K CPU @ 3.50GHz
09:57:11: CPU Speed: 3504MHz
09:57:11: Physical Memory:  7889MB Total, 6655MB Free
09:57:11: stepping id: 9, model 58, family 6, type 0, extmodel 1, extfamily 0, HTT 1, logical cores 8, total cores 4
09:57:11: monitor 1: pos={0, 0}, size={1280, 720}
09:57:11: Windows Version: 6.1 Build 7601 S
09:57:11: Aero is Enabled
09:57:11: -------------------------------
09:57:11: OBS Modules:
09:57:11: Base Address  Module
09:57:11: 000000003F770000 OBS.exe
09:57:11: 00000000EDE40000 OBSApi.dll
09:57:11: 00000000EF680000 DShowPlugin.dll
09:57:11: 00000000EF5D0000 GraphicsCapture.dll
09:57:11: 00000000F1A00000 NoiseGate.dll
09:57:11: 00000000EFCB0000 PSVPlugin.dll
09:57:11: ------------------------------------------
09:57:11: Adapter 1
09:57:11:  Video Adapter: Intel(R) HD Graphics 4000
09:57:11:  Video Adapter Dedicated Video Memory: 268435456
09:57:11:  Video Adapter Shared System Memory: 1577058304
09:57:11:  Video Adapter Output 1: pos={0, 0}, size={1280, 720}, attached=true
10:06:52: =====Stream Start: 2014-09-02, 10:06:52===============================================
10:06:52:  Multithreaded optimizations: On
10:06:52:  Base resolution: 1280x720
10:06:52:  Output resolution: 1280x720
10:06:52: ------------------------------------------
10:06:52: Loading up D3D10 on Intel(R) HD Graphics 4000 (Adapter 1)...
10:06:52: ------------------------------------------
10:06:52: Audio Format: 48000 Hz
10:06:52: ------------------------------------------
10:06:52: Audio Channels: 2 Ch
10:06:52: Playback device Default
10:06:52: ------------------------------------------
10:06:52: Using desktop audio input: Lautsprecher (VIA HD Audio)
10:06:52: Global Audio time adjust: 0
10:06:52: ------------------------------------------
10:06:52: Audio Encoding: AAC
10:06:52:  bitrate: 96
10:06:52: ------------------------------------------
10:06:52:  device: AVerMedia BDA Analog Capture Secondary (2),
10:06:52:  device id \\?\pci#ven_1a0a&dev_6202&subsys_62111461&rev_01#4&355a308d&0&00e1#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{ede957b0-eaa5-4bf4-acf3-6e10cb4836c3},
10:06:52:  chosen type: YUY2, usingFourCC: false, res: 1280x720 - 1280x720, frameIntervals: 200000-200000
10:06:52:  use buffering: false - 0, fourCC: 'YUY2'
10:06:52:
10:06:52:  device audio info - bits per sample: 16, channels: 2, samples per sec: 48000, block size: 4
10:06:52: Using directshow input
10:06:52: Scene buffering time set to 700
10:06:52: ------------------------------------------
10:06:52: Video Encoding: x264
10:06:52:  fps: 50
10:06:52:  width: 1280, height: 720
10:06:52:  preset: veryfast
10:06:52:  profile: high
10:06:52:  keyint: 250
10:06:52:  CBR: yes
10:06:52:  CFR: no
10:06:52:  max bitrate: 2500
10:06:52:  buffer size: 2500
10:06:52: ------------------------------------------
10:06:52:
10:06:52: Profiler result for the last frame:
10:06:52: ==============================================================
10:06:52: video thread frame - [time: 1.707 ms (cpu time: 0 ms)]
10:06:52: | scene->Preprocess - [time: 1.531 ms (cpu time: 0 ms)]
10:06:52: | GPU download and conversion - [time: 0.077 ms (cpu time: 0 ms)]
10:06:52: | | flush - [time: 0.072 ms (cpu time: 0 ms)]
10:06:52: ==============================================================
10:06:52:
10:06:53:  Interface: Qualcomm Atheros AR8161/8165 PCI-E Gigabit Ethernet Controller (NDIS 6.20) (ethernet, 1000 mbps)
10:06:54: Completed handshake with rtmp://**.**.**.**:***/wWsCNPH9XUZpbK3EQ9CC in 85 ms.
10:06:54: SO_SNDBUF was at 8192
10:06:54: SO_SNDBUF is now 65536
10:06:56: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 131072 (buffer: 0 / 331776)
10:08:06: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 70
10:09:28: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 262144 (buffer: 0 / 331776)
10:10:33: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 90
10:11:47: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 100
10:14:15: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 110
10:15:29: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 120
10:17:56: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 130
10:20:24: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 140
10:22:52: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 150
10:26:33: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 160
10:29:01: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 170
10:32:42: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 180
10:35:10: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 190
10:35:51: FlushBufferedVideo: Flushing 13 packets over 240 ms
10:35:51: Total frames encoded: 86833, total frames duplicated: 0 (0.00%)
10:35:51: Total frames rendered: 86862, number of late frames: 1 (0.00%) (it's okay for some frames to be late)
10:35:51: RTMPPublisher::SocketLoop: Graceful loop exit
10:35:51: Average send payload: 5879 bytes, average send interval: 18 ms
10:35:51: Number of times waited to send: 0, Waited for a total of 0 bytes
10:35:51: Number of b-frames dropped: 0 (0%), Number of p-frames dropped: 0 (0%), Total 0 (0%)
10:35:51: Number of bytes sent: 564784733
10:35:51:
10:35:51: Profiler time results:
10:35:51:
10:35:51: ==============================================================
10:35:51: video thread frame - [100%] [avg time: 1.76 ms] [children: 96.3%] [unaccounted: 3.69%]
10:35:51: | scene->Preprocess - [91.7%] [avg time: 1.614 ms]
10:35:51: | GPU download and conversion - [4.6%] [avg time: 0.081 ms] [children: 4.2%] [unaccounted: 0.398%]
10:35:51: | | flush - [3.52%] [avg time: 0.062 ms]
10:35:51: | | CopyResource - [0.568%] [avg time: 0.01 ms]
10:35:51: | | conversion to 4:2:0 - [0.114%] [avg time: 0.002 ms]
10:35:51: Convert444Threads - [100%] [avg time: 0.475 ms] [children: 99.6%] [unaccounted: 0.421%]
10:35:51: | Convert444toNV12 - [99.6%] [avg time: 0.473 ms]
10:35:51: encoder thread frame - [100%] [avg time: 0.694 ms] [children: 3.17%] [unaccounted: 96.8%]
10:35:51: | sending stuff out - [3.17%] [avg time: 0.022 ms]
10:35:51: ==============================================================
10:35:51:
10:35:51:
10:35:51: Profiler CPU results:
10:35:51:
10:35:51: ==============================================================
10:35:51: video thread frame - [cpu time: avg 1.086 ms, total 94349.4 ms] [avg calls per frame: 1]
10:35:51: | scene->Preprocess - [cpu time: avg 1.038 ms, total 90199.8 ms] [avg calls per frame: 1]
10:35:51: | GPU download and conversion - [cpu time: avg 0.029 ms, total 2574.02 ms] [avg calls per frame: 1]
10:35:51: | | flush - [cpu time: avg 0.025 ms, total 2215.21 ms] [avg calls per frame: 1]
10:35:51: | | CopyResource - [cpu time: avg 0.003 ms, total 265.203 ms] [avg calls per frame: 1]
10:35:51: | | conversion to 4:2:0 - [cpu time: avg 0 ms, total 0 ms] [avg calls per frame: 1]
10:35:51: Convert444Threads - [cpu time: avg 0.917 ms, total 159402 ms] [avg calls per frame: 2]
10:35:51: | Convert444toNV12 - [cpu time: avg 0.916 ms, total 159215 ms] [avg calls per frame: 2]
10:35:51: encoder thread frame - [cpu time: avg 0.017 ms, total 1528.81 ms] [avg calls per frame: 1]
10:35:51: | sending stuff out - [cpu time: avg 0.003 ms, total 312.005 ms] [avg calls per frame: 1]
10:35:51: ==============================================================
10:35:51:
10:35:51: =====Stream End: 2014-09-02, 10:35:51=================================================
 
Sapiens

Sapiens

Forum Moderator
Go to the video capture source properties for your H727 and check the "Use buffering" box, see if that helps.
 
M

maikyyy

New Member
i read this and other workarounds about past 2 weeks here, it does not help. i think now i have to downgrade to older versions like 0613b or older one.

im not alone with this problem...

the system load is about 10 percent, 18 percent when streaming 2 channels at the same time.

cpu idle
gpu idle
ram idle

all good, but streams are laggy because the server try to resync video/audio permanently every 300 milliseconds.
 
Last edited:
Boildown

Boildown

Active Member
If you can get it to work with an older version, then do so, and post log files from each. That way someone can take a look and see what changed.

At least fall back to the latest stable version instead of the test version.

Turn Constant Frame Rate back on.

Why is your framerate set to 50? What is your input video framerate? If your input video's framerate really is 50, does that capture card support it?
 
M

maikyyy

New Member
avermedia h727 and newer obs builds timestamp problem seems to be fixed by plug h727 cards into pciex x16 and x8 slot with direct pciex line to ivy bridge cpu. not through the intel z77x chipset.

testing this with c127 cards and haswell/z87-pro later.


EDIT: not really fixed, now i have one audio timestamp behind video every second hour. it may be that obs has a problem with avermedia drivers on x64 systems?

Code: 
13:36:55: =====Stream Start: 2014-09-03, 13:36:55===============================================
13:36:55:  Multithreaded optimizations: On
13:36:55:  Base resolution: 1280x720
13:36:55:  Output resolution: 1280x720
13:36:55: ------------------------------------------
13:36:55: Loading up D3D10 on Intel(R) HD Graphics 4000 (Adapter 1)...
13:36:55: ------------------------------------------
13:36:55: Audio Format: 48000 Hz
13:36:55: ------------------------------------------
13:36:55: Audio Channels: 2 Ch
13:36:55: Playback device Default
13:36:55: ------------------------------------------
13:36:55: Using desktop audio input: Lautsprecher (VIA HD Audio)
13:36:55: Global Audio time adjust: 0
13:36:55: ------------------------------------------
13:36:55: Audio Encoding: AAC
13:36:55:  bitrate: 48
13:36:55: ------------------------------------------
13:36:55:  device: AVerMedia BDA Analog Capture Secondary (2),
13:36:55:  device id \\?\pci#ven_1a0a&dev_6202&subsys_62111461&rev_01#4&b77c4c1&0&0008#{65e8773d-8f56-11d0-a3b9-00a0c9223196}\{ede957b0-eaa5-4bf4-acf3-6e10cb4836c3},
13:36:55:  chosen type: YUY2, usingFourCC: false, res: 1280x720 - 1280x720, frameIntervals: 200000-200000
13:36:55:  use buffering: false - 0, fourCC: 'YUY2'
13:36:55:
13:36:55:  device audio info - bits per sample: 16, channels: 2, samples per sec: 48000, block size: 4
13:36:55: Using directshow input
13:36:55: Scene buffering time set to 700
13:36:55: ------------------------------------------
13:36:55: Video Encoding: x264
13:36:55:  fps: 50
13:36:55:  width: 1280, height: 720
13:36:55:  preset: veryfast
13:36:55:  profile: high
13:36:55:  keyint: 250
13:36:55:  CBR: yes
13:36:55:  CFR: yes
13:36:55:  max bitrate: 2200
13:36:55:  buffer size: 2200
13:36:55: ------------------------------------------
13:36:55:
13:36:55: Profiler result for the last frame:
13:36:55: ==============================================================
13:36:55: video thread frame - [time: 2.511 ms (cpu time: 0 ms)]
13:36:55: | scene->Preprocess - [time: 2.323 ms (cpu time: 0 ms)]
13:36:55: | GPU download and conversion - [time: 0.081 ms (cpu time: 0 ms)]
13:36:55: | | flush - [time: 0.07 ms (cpu time: 0 ms)]
13:36:55: ==============================================================
13:36:55:
13:36:57:  Interface: Qualcomm Atheros AR8161/8165 PCI-E Gigabit Ethernet Controller (NDIS 6.20) (ethernet, 1000 mbps)
13:36:57: Completed handshake with rtmp://192.168.1.25:9501/wWsCNPH9XUZpbK3EQ9CC in 25 ms.
13:36:58: SO_SNDBUF was at 8192
13:36:58: SO_SNDBUF is now 65536
13:36:59: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 131072 (buffer: 17602 / 287744)
13:36:59: RTMPPublisher::SocketLoop: Increasing send buffer to ISB 262144 (buffer: 0 / 287744)
14:14:02: RTMPPublisher::SocketLoop: Stalled for 2777 ms to write 284663 bytes (buffer: 0 / 287744), unstable connection?
14:14:05: RTMPPublisher::SocketLoop: Stalled for 2541 ms to write 287575 bytes (buffer: 0 / 287744), unstable connection?
16:40:22: Audio timestamp for device 'AVerMedia BDA Analog Capture Secondary' was behind target timestamp by 70
17:14:06: FlushBufferedVideo: Flushing 14 packets over 260 ms
17:14:06: Total frames encoded: 651498, total frames duplicated: 0 (0.00%)
17:14:06: Total frames rendered: 651526, number of late frames: 1 (0.00%) (it's okay for some frames to be late)
17:14:06: RTMPPublisher::SocketLoop: Graceful loop exit
17:14:07: Average send payload: 5851 bytes, average send interval: 20 ms
17:14:07: Number of times waited to send: 14, Waited for a total of 50733 bytes
17:14:07: Number of b-frames dropped: 114 (0.018%), Number of p-frames dropped: 120 (0.018%), Total 234 (0.036%)
17:14:07: Number of bytes sent: 3746541899
17:14:07:
17:14:07: Profiler time results:
17:14:07:
17:14:07: ==============================================================
17:14:07: video thread frame - [100%] [avg time: 2.419 ms] [children: 97%] [unaccounted: 3.02%]
17:14:07: | scene->Preprocess - [93.3%] [avg time: 2.258 ms]
17:14:07: | GPU download and conversion - [3.64%] [avg time: 0.088 ms] [children: 3.14%] [unaccounted: 0.496%]
17:14:07: | | flush - [2.6%] [avg time: 0.063 ms]
17:14:07: | | CopyResource - [0.455%] [avg time: 0.011 ms]
17:14:07: | | conversion to 4:2:0 - [0.0827%] [avg time: 0.002 ms]
17:14:07: Convert444Threads - [100%] [avg time: 0.578 ms] [children: 99.5%] [unaccounted: 0.519%]
17:14:07: | Convert444toNV12 - [99.5%] [avg time: 0.575 ms]
17:14:07: encoder thread frame - [100%] [avg time: 1.117 ms] [children: 2.78%] [unaccounted: 97.2%]
17:14:07: | sending stuff out - [2.78%] [avg time: 0.031 ms]
17:14:07: ==============================================================
17:14:07:
17:14:07:
17:14:07: Profiler CPU results:
17:14:07:
17:14:07: ==============================================================
17:14:07: video thread frame - [cpu time: avg 1.938 ms, total 1.26267e+006 ms] [avg calls per frame: 1]
17:14:07: | scene->Preprocess - [cpu time: avg 1.899 ms, total 1.23777e+006 ms] [avg calls per frame: 1]
17:14:07: | GPU download and conversion - [cpu time: avg 0.014 ms, total 9516.07 ms] [avg calls per frame: 1]
17:14:07: | | flush - [cpu time: avg 0.01 ms, total 6817.25 ms] [avg calls per frame: 1]
17:14:07: | | CopyResource - [cpu time: avg 0.002 ms, total 1326 ms] [avg calls per frame: 1]
17:14:07: | | conversion to 4:2:0 - [cpu time: avg 0 ms, total 187.201 ms] [avg calls per frame: 1]
17:14:07: Convert444Threads - [cpu time: avg 0.401 ms, total 523305 ms] [avg calls per frame: 2]
17:14:07: | Convert444toNV12 - [cpu time: avg 0.399 ms, total 521106 ms] [avg calls per frame: 2]
17:14:07: encoder thread frame - [cpu time: avg 0.454 ms, total 296386 ms] [avg calls per frame: 1]
17:14:07: | sending stuff out - [cpu time: avg 0.115 ms, total 75176.9 ms] [avg calls per frame: 1]
17:14:07: ==============================================================
17:14:07:
17:14:07: =====Stream End: 2014-09-03, 17:14:07=================================================

i dont know why there are dropped frames and unstable connection warnings. connection is fine, local area network with 24 port gigabit ethernet switch behind a patch panel.
 
Last edited:
Sapiens

Sapiens

Forum Moderator
Having single audio timestamps behind every hour or two is totally fine. Older versions of OBS simply don't report that in the same way (or at all). Dropped frames are frames that couldn't be sent to the ingest server for any number of reasons, it relies on far more than just how good your LAN connection is. You have a negligible number of dropped frames so that's not worth worrying about.
 
You must log in or register to reply here.
Top