Hi all,
I recently changed the receivers of my VDR from two TeVii S660's to a Digital Devices Cine S2 + Duoflex card. Everything else remained unchanged on the VDR side of things. Since then, I encounter frequent (as in, once per day approx.) buffer overruns and resync probs. As it seems from the thread IDs, the TS or VNSI buffer threads seem to cause the problem. But I may be wrong.
Software versions: - Ubuntu 14.04.3 LTS with Wily kernel (4.2.0-latest) - vdr-2.0.3 (ubuntu) - vnsiserver-latest from git (from a couple of days ago) - Kodi 6.0 as in Openelec-current on RPi2 - dddvb driver 0.9.21 or 0.9.22 from Digital Devices git (current).
As shown by the kernel log, the DD card is initialized just fine:
[ 14.704506] dvb_core: module verification failed: signature and/or required key missing - tainting kernel [ 14.744728] Digital Devices PCIE bridge driver 0.9.21, Copyright (C) 2010-15 Digital Devices GmbH [ 14.744921] DDBridge driver detected: Digital Devices Cine S2 V6.5 DVB adapter [ 14.744938] DDBridge: HW 0001000d REGMAP 00010004 [ 14.744972] DDBridge: using 1 MSI interrupt(s) [ 14.746272] Port 0: Link 0, Link Port 0 (TAB 1): DUAL DVB-S2 [ 14.858090] Port 1: Link 0, Link Port 1 (TAB 2): DUAL DVB-S2 [ 14.859048] Port 2: Link 0, Link Port 2 (TAB 3): NO MODULE [ 14.860003] Port 3: Link 0, Link Port 3 (TAB 4): NO MODULE [ 14.861739] 0 netstream channels [ 14.861742] DVB: registering new adapter (DDBridge) [ 14.861744] DVB: registering new adapter (DDBridge) [ 14.861745] DVB: registering new adapter (DDBridge) [ 14.861746] DVB: registering new adapter (DDBridge) ... [ 15.407636] LNBx2x attached on addr=a [ 15.436794] stv6110x_attach: Attaching STV6110x [ 15.436799] attach tuner input 0 adr 60 [ 15.436871] ddbridge 0000:05:00.0: DVB: registering adapter 0 frontend 0 (STV090x Multistandard)... ... [ 15.472168] LNBx2x attached on addr=8 [ 15.472174] stv6110x_attach: Attaching STV6110x [ 15.472176] attach tuner input 1 adr 63 [ 15.472256] ddbridge 0000:05:00.0: DVB: registering adapter 1 frontend 0 (STV090x Multistandard)... ... [ 15.491106] LNB25 on 0c [ 15.640527] ddbridge 0000:05:00.0: DVB: registering adapter 2 frontend 0 (STV0910)... [ 15.642001] LNB25 on 0d [ 15.645682] ddbridge 0000:05:00.0: DVB: registering adapter 3 frontend 0 (STV0910)...
When running, after a while these error messages can be seen:
Jan 23 11:15:46 seneca vdr: [7888] VNSI: Successfully switched to channel 14 - KiKA HD Jan 23 11:15:46 seneca vdr: [7888] VNSI: Started streaming of channel KiKA HD (timeout 10 seconds) Jan 23 11:15:46 seneca vdr: [7891] cLiveStreamer stream processor thread started (pid=2593, tid=7891, prio=high) Jan 23 11:15:46 seneca vdr: [7892] TS buffer on device 2 thread started (pid=2593, tid=7892, prio=high) Jan 23 11:15:46 seneca vdr: [7890] VNSI: VideoInput: no pat/pmt within timeout, falling back to channel pids Jan 23 11:15:46 seneca vdr: [7890] VNSI: Video Input - new pmt, attaching receiver Jan 23 11:15:47 seneca vdr: [7891] VNSI: Created stream for pid=6610 and type=8 Jan 23 11:15:47 seneca vdr: [7891] VNSI: Created stream for pid=6622 and type=1 Jan 23 11:15:47 seneca vdr: [7891] VNSI: Created stream for pid=6620 and type=2 Jan 23 11:15:47 seneca vdr: [7891] VNSI: Created stream for pid=6621 and type=2 Jan 23 11:15:47 seneca vdr: [7891] VNSI: Created stream for pid=6631 and type=9 Jan 23 11:15:47 seneca vdr: [7891] VNSI: Created stream for pid=6630 and type=11 Jan 23 11:15:49 seneca vdr: [7892] i/o throttle activated, count = 1 (tid=7892) Jan 23 11:15:50 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:15:50 seneca vdr: [7892] buffer usage: 80% (tid=7889) Jan 23 11:15:50 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:15:50 seneca vdr: [2746] VNSI: Timers state changed (13) Jan 23 11:15:50 seneca vdr: [2746] VNSI: Requesting clients to reload timers Jan 23 11:15:52 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:15:52 seneca vdr: [7892] buffer usage: 80% (tid=7889) Jan 23 11:15:52 seneca vdr: [7892] buffer usage: 90% (tid=7889) Jan 23 11:15:53 seneca vdr: [7892] buffer usage: 100% (tid=7889) Jan 23 11:15:54 seneca vdr: [2746] VNSI: Timers state changed (14) Jan 23 11:15:54 seneca vdr: [2746] VNSI: Requesting clients to reload timers Jan 23 11:15:54 seneca vdr: [7892] ERROR: driver buffer overflow on device 2 Jan 23 11:15:58 seneca vdr: message repeated 2 times: [ [7892] ERROR: driver buffer overflow on device 2] Jan 23 11:16:00 seneca vdr: [7889] ERROR: skipped 123 bytes to sync on TS packet on device 2 Jan 23 11:16:03 seneca vdr: [7892] ERROR: driver buffer overflow on device 2 Jan 23 11:16:04 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:04 seneca vdr: [7889] ERROR: skipped 123 bytes to sync on TS packet on device 2 Jan 23 11:16:04 seneca vdr: [7892] i/o throttle released, count = 0 (tid=7892) Jan 23 11:16:05 seneca vdr: [7892] i/o throttle activated, count = 1 (tid=7892) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:06 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:07 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:07 seneca vdr: [7892] buffer usage: 80% (tid=7889) Jan 23 11:16:08 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:08 seneca vdr: [7892] buffer usage: 70% (tid=7889) Jan 23 11:16:08 seneca vdr: [7892] buffer usage: 60% (tid=7889) Jan 23 11:16:09 seneca vdr: [7892] buffer usage: 70% (tid=7889)
and voilà, decoding errors, blocks, resyncs. The fun part is, it is not enough to restart VDR (and hence, vnsiserver) or unload and reload the kernel modules, but I actually need to restart the _machine_ in order to get away with this.
Both device 1 and device 2 are attached to Astra, these are two independent LNBs with no multiswitch or anything inbetween. It makes no difference if the current channel is on 1 or 2, so it should not be the LNBs (how?) or the receiver modules on the DD card.
This does not happen when watching live streams with xineliboutput / vdr-sxfe, and also not if I watch recordings using vnsiserver / kodi. Only when it's live streams and vnsiserver / kodi. Happens with HD or SD channels. Does not go away when switching channels. Recording works just fine without any problems.
I opened a ticket with Digital Devices but for now I haven't got a clue from them, and also no answer in the VNSI / Kodi forum, so I hope that somebody here might have a clue where to look.
And sorry for using an old VDR version but this is where I am. Going to upgrade to 2.2.0 with Ubuntu 16.04 as soon as it's available. This is a "production" (as in "high WAF required") machine. ;-)
TIA!
Hi all,
over the weekend I upgraded to vdr-2.2.0, and I'm still seeing the same problems.
- vdr-2.2.0 from ftp://ftp.tvdr.de/vdr/vdr-2.2.0.tar.bz2 - vnsiserver from git (from yesterday) - dddvb-0.9.22 (loaded as ddbridge msi=0)
Everything else is unchanged.
Result: when the problem starts, 1. switching channels does not help 2. restarting VDR does not help 3. stopping VDR, reloading driver, and restarting VDR does not help 4. only restarting the machine seems to help so far, for some time, until the problem occurs again.
This is after 3.:
Feb 1 07:56:59 seneca vdr: [31887] VNSI: Client with ID 2 connected: 192.168.20.200:37103 Feb 1 07:56:59 seneca vdr: [31939] VNSI: Welcome client 'XBMC Media Center' with protocol version '8' Feb 1 07:56:59 seneca vdr: [31939] VNSI: LiveStreamer::Close - close Feb 1 07:56:59 seneca vdr: [31939] VNSI: close video input ... Feb 1 07:56:59 seneca vdr: [31939] VNSI: Successfully found following device: 0x8aaee00 (2) for receiving Feb 1 07:56:59 seneca vdr: [31940] device 2 receiver thread started (pid=31867, tid=31940, prio=high) Feb 1 07:56:59 seneca vdr: [31939] VNSI: Successfully switched to channel 2 - ZDF HD Feb 1 07:56:59 seneca vdr: [31939] VNSI: Started streaming of channel ZDF HD (timeout 10 seconds) Feb 1 07:56:59 seneca vdr: [31943] device 2 TS buffer thread started (pid=31867, tid=31943, prio=high) Feb 1 07:56:59 seneca vdr: [31942] cLiveStreamer stream processor thread started (pid=31867, tid=31942, prio=high) Feb 1 07:56:59 seneca vdr: [31941] VNSI: VideoInput: no pat/pmt within timeout, falling back to channel pids Feb 1 07:56:59 seneca vdr: [31941] VNSI: Video Input - new pmt, attaching receiver Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6110 and type=8 Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6122 and type=1 Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6120 and type=2 Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6121 and type=2 Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6123 and type=2 Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6131 and type=9 Feb 1 07:57:00 seneca vdr: [31942] VNSI: Created stream for pid=6130 and type=11 Feb 1 07:57:02 seneca vdr: [31943] i/o throttle activated, count = 1 (tid=31943) Feb 1 07:57:03 seneca vdr: [31943] buffer usage: 70% (tid=31940) Feb 1 07:57:03 seneca vdr: [31943] buffer usage: 60% (tid=31940) Feb 1 07:57:03 seneca vdr: [31943] buffer usage: 70% (tid=31940) Feb 1 07:57:04 seneca vdr: [31943] buffer usage: 80% (tid=31940) Feb 1 07:57:04 seneca vdr: [31943] buffer usage: 90% (tid=31940) Feb 1 07:57:05 seneca vdr: [31943] buffer usage: 100% (tid=31940) Feb 1 07:57:06 seneca vdr: [31943] buffer usage: 60% (tid=31940) Feb 1 07:57:06 seneca vdr: [31943] buffer usage: 70% (tid=31940) Feb 1 07:57:06 seneca vdr: [31943] buffer usage: 60% (tid=31940) Feb 1 07:57:06 seneca vdr: [31943] buffer usage: 70% (tid=31940) Feb 1 07:57:06 seneca vdr: [31943] buffer usage: 80% (tid=31940) Feb 1 07:57:07 seneca vdr: [31943] buffer usage: 90% (tid=31940) Feb 1 07:57:08 seneca vdr: [31943] buffer usage: 100% (tid=31940) Feb 1 07:57:09 seneca vdr: [31943] ERROR: driver buffer overflow on device 2 Feb 1 07:57:19 seneca vdr: message repeated 6 times: [ [31943] ERROR: driver buffer overflow on device 2] Feb 1 07:57:20 seneca vdr: [31940] ERROR: skipped 123 bytes to sync on TS packet on device 2 Feb 1 07:57:21 seneca vdr: [31943] ERROR: driver buffer overflow on device 2 Feb 1 07:57:23 seneca vdr: [31943] ERROR: driver buffer overflow on device 2 Feb 1 07:57:23 seneca vdr: [31943] buffer usage: 60% (tid=31940) Feb 1 07:57:23 seneca vdr: [31943] buffer usage: 70% (tid=31940) Feb 1 07:57:24 seneca vdr: [31943] buffer usage: 80% (tid=31940) Feb 1 07:57:25 seneca vdr: [31943] buffer usage: 90% (tid=31940) Feb 1 07:57:26 seneca vdr: [31943] buffer usage: 100% (tid=31940) Feb 1 07:57:26 seneca vdr: [31940] ERROR: skipped 123 bytes to sync on TS packet on device 2 Feb 1 07:57:27 seneca vdr: [31943] ERROR: driver buffer overflow on device 2 Feb 1 07:57:35 seneca vdr: message repeated 5 times: [ [31943] ERROR: driver buffer overflow on device 2] Feb 1 07:57:36 seneca vdr: [31940] ERROR: skipped 51 bytes to sync on TS packet on device 2 Feb 1 07:57:36 seneca vdr: [31940] ERROR: skipped 72 bytes to sync on TS packet on device 2 Feb 1 07:57:37 seneca vdr: [31943] ERROR: driver buffer overflow on device 2 Feb 1 07:57:48 seneca vdr: message repeated 8 times: [ [31943] ERROR: driver buffer overflow on device 2] Feb 1 07:57:49 seneca vdr: [31940] ERROR: skipped 33 bytes to sync on TS packet on device 2 Feb 1 07:57:49 seneca vdr: [31940] ERROR: skipped 90 bytes to sync on TS packet on device 2 Feb 1 07:57:50 seneca vdr: [31943] ERROR: driver buffer overflow on device 2
Again, this happens only when watching live TV with vnsiserver / kodi (on RPi2 with OpenELEC-latest or on Android 5.1.1 using Kodi-latest as from Google Play). Every other combination (recording, watching recordings, watching live TV with xineliboutput / vdr-sxfe (on Ubuntu 14.04-x86)) does not exhibit the problem.
I have no idea what I can do here. Any hint or help is appreciated.
TIA!
On Sat, Jan 30, 2016 at 10:40:19AM +0100, Harald Milz wrote:
OK - I think I have a stable configuration now, albeit weird.
- I upgraded the mobo BIOS to -latest, to no avail (hoping this would change the MSI interrupt behaviour, but it only appears to add some more CPU support. But you never know, BIOS changelogs haven't been well known for being particularly verbose.) - I set pci=nomsi - no change. Will change this back to default for the next reboot - I enlarged PLAYERBUFSIZE (and RECORDERBUFSIZE to be sure) to 50 megs, and voilà, the setup has been stable for the last 4 days or so. I know this only cures the symptom IF the buffer logic has an actual problem
OK, the WAF has been saved for now, but the fix still does not explain why the buffer overrun problem only occurs when watching live TV with vnsiserver and kodi, and can only be cured by rebooting the machine. So ... :-/
On Mon, Feb 01, 2016 at 08:20:06AM +0100, Harald Milz wrote:
Harald,
I'm using a somewhat similar config to yours, though different receivers (PCTV Nanostick 290e for DVB-T2, and very old "WideView USB DVB-T"). I too have had problems with streaming live TV to Kodi for many, many versions. As you have noted, no issues recording, and no issues playing back recordings, it's just live TV streaming that's the problem, and usually only after a few minutes of watching, not immediately (so perhaps testers haven't noticed), and a bit worse in HD unsurprisingly. But I never see buffer or driver errors in the logs - no errors from vnsi in fact, so I think in my case it's purely a Kodi issue, perhaps something to do with PTS time stamps, and/or buffer synchronisation. It works very well, aside from live TV - just waiting for a Kodi version that solves this issue.
One of the things that the vnsi developer said to do set this in the VDR config
vnsiserver.AvoidEPGScan = 1 (http://forum.kodi.tv/showthread.php?tid=203396)
It prevents interruptions during streaming. It certainly helps, but not a 100% fix.
I don't know where PLAYERBUFSIZE is - Kodi config file - which one?
Thanks
On 7/02/2016 07:18, Harald Milz wrote:
Richard,
On Sun, Feb 07, 2016 at 12:34:17PM +0000, Richard F wrote:
Now that you mention it - I also see interruptions sometimes when Kodi appears to update its timers. That is, when it scans through the timer list, displaying the respective message windows bottom left. Sometimes, live streaming just crashes, and needs to be restarted manually.
I'll give AvoidEPGScan = 1 a try - thank you!
I don't know where PLAYERBUFSIZE is - Kodi config file - which one?
No, that's in vdr:
dvbplayer.c:#define PLAYERBUFSIZE MEGABYTE(1)
and
recorder.c:#define RECORDERBUFSIZE (MEGABYTE(10) / TS_SIZE * TS_SIZE) // multiple of TS_SIZE
Please not that it really cures only the symptom. If there is a problem with filling any emptying the buffer, leading to an overrun, then it will eventually happen, no matter what the size is. So far, I haven't seen this yet with 50 megs each.
Hi folks,
I hate to follow up on myself, but as it appears I cheered too soon. It now also happens reproducibly when recording, and independent of vnsiserver or anything else.
The machine has been up for 4 days, and when starting a new recording, this is what happens after some seconds:
Feb 9 11:41:37 seneca vdr: [624] i/o throttle activated, count = 1 (tid=624) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 60% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 60% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 60% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 60% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 60% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 60% (tid=623) Feb 9 11:41:46 seneca vdr: [624] buffer usage: 70% (tid=623) Feb 9 11:41:51 seneca vdr: [624] buffer usage: 80% (tid=623) Feb 9 11:41:55 seneca vdr: [624] buffer usage: 90% (tid=623) Feb 9 11:41:59 seneca vdr: [624] buffer usage: 100% (tid=623) Feb 9 11:41:59 seneca vdr: [624] ERROR: 1 ring buffer overflow (1 bytes dropped) Feb 9 11:42:05 seneca vdr: [624] ERROR: 31446 ring buffer overflows (5911848 bytes dropped) Feb 9 11:42:11 seneca vdr: [624] ERROR: 32635 ring buffer overflows (6135380 bytes dropped)
(needless to say the recording is entirely crippled.)
VDR is 2.2.0, plain but with PLAYERBUFSIZE and RECORDERBUFSIZE enlarged to 50 megs each. As I suspected earlier, enlarging the buffers only cures the symptom. It's only a matter of time. As if memory regions and pointers weren't cleanly free()'d but reused next time instead of malloc()ing new ones. Looking at the cRingBufferLinear class this seems to be the case. But how can this persist across VDR restarts? I'm puzzled.
Restarting VDR, reloading the DVB drivers (dddvb-0.9.22 from Digital Devices) does not remedy the overruns. Only restarting the machine does.
If anyone had an idea where to look, that would be great. e.g. were there any significant changes in the TS buffer code between 2.2.0 and devel-latest? I'm a bit reluctant to try 2.3.x because some plugins may not work with it.
TIA!
On Mon, Feb 08, 2016 at 08:17:08AM +0100, Harald Milz wrote:
Harald,
if - the problem surfaces only with a new DVBs hardware card (and not with the old one) and - it only appears when you have traffic both on the DVB card and on the network interface and - the problem only goes away when you cold boot
then this makes me think that you have a problem with the PCIe bus.
I trust you have updated the mainboard BIOS to the latest level, right ?
Can you please elaborate on the hardware * mainboard make and model * schematic of the mainboard and how network card, disk controller and DVB card are attached
Please run an iperf test (bi-directional) to measure the network performance when newly booted and when "the problem" has surfaced.
And I would guess that you can trigger the problem more easily if you run iperf, create disk activity (run a random access read-only disk test ?) and run the remote video client at the same time.
Btw, there are LEDs on the Digital Devices card, do they change between the "good" and the "bad" state ?
Thomas
Hi all,
I think I found the cause of the buffer overrun problem. My system has now been running for nearly 10 hours without a single problem, with occasional "buffer stats 0..3%" in the syslog.
It appears that the problem relies with the Ubuntu-wily HWE kernel 4.2.0-something. I downgraded to 3.19.0-something today, and since then the problem hasn't occured again. I have been load testing the whole day, with up to 5 concurrent recordings on all 4 receivers plus up to 3 live streams (xine, vnsi, and streamdev). Smooth.
Question: has anyone successfully run vdr-2.0.3 or -2.2.0 with the 4.2.0 kernel using a PCIe card? And while we're at it, a PCIe USB3 card with a harddisk attached? It seems that some kernel buffer starts choking after, like, 150 or more GB have been transferred. If that is a common problem (on any Ubuntu distro running the wily HWE kernel or on 15.10 itself) it should be mentioned somewhere - no idea where. vdr-wiki.de maybe.
I also changed the motherboard inbetween. The new one has the ethernet chip attached via PCIe (RTL8111) but my old one had not (RTL8211 / NVidia MCP97), which might be the reason why the network didn't let me down on the old MoBo. But then, I am not a kernel expert.
Phew.
Thanks to Thomas who kept kicking me. (y)
Does anyone need a K10N78 board with 4x 2 GB RAM? ;-)
(I should start using ITIL-like change management. I might have noticed it earlier. It may well be that the problems with the old USB receivers started some time after upgrading the kernel to wily HWE).
On Tue, Feb 09, 2016 at 03:15:09PM +0100, Thomas Netousek wrote:
17.02.2016, 23:14, Harald Milz kirjoitti:
I am running Ubuntu 15.10,
uname -a Linux xpc 4.2.0-27-generic #32-Ubuntu SMP Fri Jan 22 04:49:08 UTC 2016 x86_64 x86_64 x86_64 GNU/Linux
dpkg -l ii vdr 2.0.6-2 amd64 Video Disk Recorder for DVB cards
PCIe DVBSky T982 and T980C cards (cable), total 5 adapters
I don't have this problem.
yours, Jouni
-
Harald Milz -
Jouni Karvo -
Richard F -
Thomas Netousek