vdr-plugin-xvdr icon indicating copy to clipboard operation
vdr-plugin-xvdr copied to clipboard

Published 20 hours ago • verified publisher icon pipelka

Need to switch twice on a channel the first time with XBMC

Open ghost opened this issue 12 years ago • 20 comments

When switching for the first time on a channel, we get the following log and nothing on screen with XBMC:

Jan 7 18:28:04 dabox vdr: [11920] loading /home/BoB/vdr/conf/plugins/xvdr/allowed_hosts.conf Jan 7 18:28:04 dabox vdr: [11920] XVDR: Client 127.0.0.1:14827 with ID 5 connected. Jan 7 18:28:04 dabox vdr: [14584] ERROR (thread.c,227): Permission denied Jan 7 18:28:04 dabox vdr: [14584] XVDR: Welcome client 'XVDR Client' with protocol version '4' Jan 7 18:28:04 dabox vdr: [14584] XVDR: Preferred language: eng,dos / type: 1 Jan 7 18:28:04 dabox vdr: [14584] ERROR (thread.c,227): Permission denied Jan 7 18:28:04 dabox vdr: [14584] XVDR: -------------------------------------- Jan 7 18:28:04 dabox vdr: [14584] XVDR: Channel streaming request: 25 - Numero 23 HD Jan 7 18:28:04 dabox vdr: [14584] XVDR: Found available device 2 Jan 7 18:28:04 dabox vdr: [14586] XVDR: LiveQueue started Jan 7 18:28:04 dabox vdr: [14584] XVDR: Successfully switched to channel 25 - Numero 23 HD Jan 7 18:28:04 dabox vdr: [14584] XVDR: Started streaming of channel Numero 23 HD (timeout 3 seconds, priority 50) Jan 7 18:28:04 dabox vdr: [14587] cLiveStreamer stream processor thread started (pid=11877, tid=14587, prio=high) Jan 7 18:28:04 dabox vdr: [14588] receiver on device 2 thread started (pid=11877, tid=14588, prio=high) Jan 7 18:28:04 dabox vdr: [14589] TS buffer on device 2 thread started (pid=11877, tid=14589, prio=high) Jan 7 18:28:06 dabox vdr: [14587] XVDR: returning from streamer thread, receiver is no more attached Jan 7 18:28:06 dabox vdr: [14587] cLiveStreamer stream processor thread ended (pid=11877, tid=14587) Jan 7 18:28:06 dabox vdr: [11910] XVDR: Stream: MPEG2AUDIO PID: 34 0 Hz, 0 channels, Lang: qad Jan 7 18:28:06 dabox vdr: [11910] XVDR: Stream: MPEG2AUDIO PID: 71 0 Hz, 0 channels, Lang: qaa Jan 7 18:28:06 dabox vdr: [11910] XVDR: Stream: TELETEXT PID: 97 TXT Jan 7 18:28:06 dabox vdr: [11910] XVDR: Stream: H264 PID: 105 0x0 DAR: 0.00 Jan 7 18:28:06 dabox vdr: [11910] XVDR: Stream: MPEG2AUDIO PID: 107 0 Hz, 0 channels, Lang: fra Jan 7 18:28:06 dabox vdr: [14599] cLiveStreamer stream processor thread started (pid=11877, tid=14599, prio=high) Jan 7 18:28:06 dabox vdr: [14589] TS buffer on device 2 thread ended (pid=11877, tid=14589) Jan 7 18:28:06 dabox vdr: [14588] buffer stats: 101144 (0%) used Jan 7 18:28:06 dabox vdr: [14588] receiver on device 2 thread ended (pid=11877, tid=14588) Jan 7 18:28:06 dabox vdr: [11910] XVDR: Will cache new stream information when all streams are parsed Jan 7 18:28:06 dabox vdr: [14604] receiver on device 2 thread started (pid=11877, tid=14604, prio=high) Jan 7 18:28:06 dabox vdr: [14605] TS buffer on device 2 thread started (pid=11877, tid=14605, prio=high)

the second time, the logs becomes the following and we can see a picture:

Jan 7 18:28:51 dabox vdr: [11920] loading /home/BoB/vdr/conf/plugins/xvdr/allowed_hosts.conf Jan 7 18:28:51 dabox vdr: [11920] XVDR: Client 127.0.0.1:15339 with ID 7 connected. Jan 7 18:28:51 dabox vdr: [15036] ERROR (thread.c,227): Permission denied Jan 7 18:28:51 dabox vdr: [15036] XVDR: Welcome client 'XVDR Client' with protocol version '4' Jan 7 18:28:51 dabox vdr: [15036] XVDR: Preferred language: eng,dos / type: 1 Jan 7 18:28:51 dabox vdr: [15036] ERROR (thread.c,227): Permission denied Jan 7 18:28:51 dabox vdr: [15036] XVDR: -------------------------------------- Jan 7 18:28:51 dabox vdr: [15036] XVDR: Channel streaming request: 25 - Numero 23 HD Jan 7 18:28:51 dabox vdr: [15036] XVDR: Found available device 2 Jan 7 18:28:51 dabox vdr: [15036] XVDR: Channel information found in cache Jan 7 18:28:51 dabox vdr: [15036] XVDR: Stream: MPEG2AUDIO PID: 34 0 Hz, 0 channels, Lang: qad Jan 7 18:28:51 dabox vdr: [15036] XVDR: Stream: MPEG2AUDIO PID: 71 0 Hz, 0 channels, Lang: qaa Jan 7 18:28:51 dabox vdr: [15036] XVDR: Stream: TELETEXT PID: 97 TXT Jan 7 18:28:51 dabox vdr: [15036] XVDR: Stream: H264 PID: 105 0x0 DAR: 0.00 Jan 7 18:28:51 dabox vdr: [15036] XVDR: Stream: MPEG2AUDIO PID: 107 0 Hz, 0 channels, Lang: fra Jan 7 18:28:51 dabox vdr: [15039] cLiveStreamer stream processor thread started (pid=11877, tid=15039, prio=high) Jan 7 18:28:51 dabox vdr: [15038] XVDR: LiveQueue started Jan 7 18:28:51 dabox vdr: [15036] XVDR: Successfully switched to channel 25 - Numero 23 HD Jan 7 18:28:51 dabox vdr: [15040] receiver on device 2 thread started (pid=11877, tid=15040, prio=high) Jan 7 18:28:51 dabox vdr: [15036] XVDR: Started streaming of channel Numero 23 HD (timeout 3 seconds, priority 50) Jan 7 18:28:51 dabox vdr: [15041] TS buffer on device 2 thread started (pid=11877, tid=15041, prio=high) Jan 7 18:28:51 dabox vdr: [11989] [general.debug] logfile '/home/BoB/vdr/sc.log' opened Jan 7 18:28:52 dabox vdr: [15039] XVDR: -------------------------------------- Jan 7 18:28:52 dabox vdr: [15039] XVDR: NEW AUDIO INFORMATION: Jan 7 18:28:52 dabox vdr: [15039] XVDR: Channels: 2 Jan 7 18:28:52 dabox vdr: [15039] XVDR: Samplerate: 48000 Hz Jan 7 18:28:52 dabox vdr: [15039] XVDR: Bitrate: 192000 bps Jan 7 18:28:52 dabox vdr: [15039] XVDR: --------------------------------------

ghost avatar Jan 07 '13 18:01 ghost

Please recheck with the updated "master" branch. If you are using VDR < 1.7.34 please pull the "master-pre-vdr-1.7.34" branch.

pipelka avatar Jan 08 '13 19:01 pipelka

Hi,

still failing sometimes :+1:

Jan 9 00:58:09 dabox vdr: [6058] loading /home/BoB/vdr/conf/plugins/xvdr/allowed_hosts.conf Jan 9 00:58:09 dabox vdr: [6058] XVDR: Client 127.0.0.1:65419 with ID 8 connected. Jan 9 00:58:09 dabox vdr: [7165] ERROR (thread.c,227): Permission denied Jan 9 00:58:09 dabox vdr: [7165] XVDR: Welcome client 'XVDR Client' with protocol version '4' Jan 9 00:58:09 dabox vdr: [7165] XVDR: Preferred language: eng,dos / type: 1 Jan 9 00:58:09 dabox vdr: [7165] ERROR (thread.c,227): Permission denied Jan 9 00:58:10 dabox vdr: [7165] XVDR: -------------------------------------- Jan 9 00:58:10 dabox vdr: [7165] XVDR: Channel streaming request: 24 - 6ter HD Jan 9 00:58:10 dabox vdr: [7165] XVDR: Found available device 2 Jan 9 00:58:10 dabox vdr: [7167] XVDR: LiveQueue started Jan 9 00:58:10 dabox vdr: [7165] XVDR: Successfully switched to channel 24 - 6ter HD Jan 9 00:58:10 dabox vdr: [7165] XVDR: Started streaming of channel 6ter HD (timeout 3 seconds, priority 50) Jan 9 00:58:10 dabox vdr: [7168] cLiveStreamer stream processor thread started (pid=6031, tid=7168, prio=high) Jan 9 00:58:10 dabox vdr: [7169] receiver on device 2 thread started (pid=6031, tid=7169, prio=high) Jan 9 00:58:10 dabox vdr: [7170] TS buffer on device 2 thread started (pid=6031, tid=7170, prio=high) Jan 9 00:58:11 dabox vdr: [7168] XVDR: returning from streamer thread, receiver is no more attached Jan 9 00:58:11 dabox vdr: [7168] cLiveStreamer stream processor thread ended (pid=6031, tid=7168) Jan 9 00:58:11 dabox vdr: [6048] XVDR: Stream: MPEG2AUDIO PID: 38 0 Hz, 0 channels, Lang: qad Jan 9 00:58:11 dabox vdr: [6048] XVDR: Stream: AC3 PID: 44 0 Hz, 0 channels, Lang: fra Jan 9 00:58:11 dabox vdr: [6048] XVDR: Stream: MPEG2AUDIO PID: 45 0 Hz, 0 channels, Lang: qaa Jan 9 00:58:11 dabox vdr: [6048] XVDR: Stream: TELETEXT PID: 46 TXT Jan 9 00:58:11 dabox vdr: [6048] XVDR: Stream: H264 PID: 67 0x0 DAR: 0.00 Jan 9 00:58:11 dabox vdr: [6048] XVDR: Stream: MPEG2AUDIO PID: 70 0 Hz, 0 channels, Lang: fra Jan 9 00:58:11 dabox vdr: [7179] cLiveStreamer stream processor thread started (pid=6031, tid=7179, prio=high) Jan 9 00:58:11 dabox vdr: [7170] TS buffer on device 2 thread ended (pid=6031, tid=7170) Jan 9 00:58:11 dabox vdr: [7169] buffer stats: 37224 (0%) used Jan 9 00:58:11 dabox vdr: [7169] receiver on device 2 thread ended (pid=6031, tid=7169) Jan 9 00:58:11 dabox vdr: [6048] XVDR: Currently unknown new streams found, requesting stream change Jan 9 00:58:11 dabox vdr: [7180] receiver on device 2 thread started (pid=6031, tid=7180, prio=high) Jan 9 00:58:11 dabox vdr: [7181] TS buffer on device 2 thread started (pid=6031, tid=7181, prio=high) Jan 9 00:58:22 dabox vdr: [6058] XVDR: Checking for channel updates ... Jan 9 00:58:22 dabox vdr: [6058] XVDR: Client 0: 433 channels, no change Jan 9 00:58:22 dabox vdr: [6058] XVDR: Done.

ghost avatar Jan 08 '13 23:01 ghost

Is this still valid with the latest "master" ?

pipelka avatar Jan 15 '13 09:01 pipelka

It seems to ok thanks! I ll post here if I reproduce it...

ghost avatar Jan 16 '13 18:01 ghost

Hi it did it again :/ commit 91e04cf6467c782a6aa949f94eabaa98d88df860

First run, no picture:

Jan 25 14:17:49 vdr: [1897] loading /home/BoB/vdr/conf/plugins/xvdr/allowed_hosts.conf Jan 25 14:17:49 vdr: [1897] XVDR: Client 127.0.0.1:21739 with ID 6 connected. Jan 25 14:17:49 vdr: [2312] ERROR (thread.c,227): Permission denied Jan 25 14:17:49 vdr: [2312] XVDR: Welcome client 'XVDR Client' with protocol version '4' Jan 25 14:17:49 vdr: [2312] XVDR: Preferred language: eng,dos / type: 1 Jan 25 14:17:49 vdr: [2312] ERROR (thread.c,227): Permission denied Jan 25 14:17:49 vdr: [2312] XVDR: -------------------------------------- Jan 25 14:17:49 vdr: [2312] XVDR: Channel streaming request: 109 - MEZZO HD Jan 25 14:17:49 vdr: [2312] XVDR: Found available device 1 Jan 25 14:17:49 vdr: [2312] XVDR: Channel information found in cache Jan 25 14:17:49 vdr: [2312] XVDR: Stream: H264 PID: 68 0x0 DAR: 0.00 (parsed: no) Jan 25 14:17:49 vdr: [2312] XVDR: Stream: MPEG2AUDIO PID: 69 0 Hz, 0 channels, Lang: fra (parsed: no) Jan 25 14:17:49 vdr: [2318] XVDR: LiveQueue started Jan 25 14:17:49 vdr: [2312] XVDR: Successfully switched to channel 109 - MEZZO HD Jan 25 14:17:49 vdr: [2312] XVDR: Started streaming of channel MEZZO HD (timeout 3 seconds, priority 50) Jan 25 14:17:49 vdr: [2320] receiver on device 1 thread started (pid=1847, tid=2320, prio=high) Jan 25 14:17:49 vdr: [2321] cLiveStreamer stream processor thread started (pid=1847, tid=2321, prio=high) Jan 25 14:17:49 vdr: [2322] TS buffer on device 1 thread started (pid=1847, tid=2322, prio=high) Jan 25 14:17:57 vdr: [2321] XVDR: returning from streamer thread, receiver is no more attached Jan 25 14:17:57 vdr: [2321] cLiveStreamer stream processor thread ended (pid=1847, tid=2321) Jan 25 14:17:58 vdr: [2318] XVDR: LiveQueue stopped Jan 25 14:17:58 vdr: [2312] buffer stats: 0 (0%) used Jan 25 14:17:58 vdr: [1897] XVDR: Client with ID 6 seems to be disconnected, removing from client list Jan 25 14:17:58 vdr: [2322] TS buffer on device 1 thread ended (pid=1847, tid=2322) Jan 25 14:17:58 vdr: [2320] buffer stats: 470188 (4%) used Jan 25 14:17:58 vdr: [2320] receiver on device 1 thread ended (pid=1847, tid=2320)

Second run, with picturE:

Jan 25 14:18:01 vdr: [1897] loading /home/BoB/vdr/conf/plugins/xvdr/allowed_hosts.conf Jan 25 14:18:01 vdr: [1897] XVDR: Client 127.0.0.1:21995 with ID 7 connected. Jan 25 14:18:01 vdr: [2408] ERROR (thread.c,227): Permission denied Jan 25 14:18:01 vdr: [2408] XVDR: Welcome client 'XVDR Client' with protocol version '4' Jan 25 14:18:01 vdr: [2408] XVDR: Preferred language: eng,dos / type: 1 Jan 25 14:18:01 vdr: [2408] ERROR (thread.c,227): Permission denied Jan 25 14:18:01 vdr: [2408] XVDR: -------------------------------------- Jan 25 14:18:01 vdr: [2408] XVDR: Channel streaming request: 109 - MEZZO HD Jan 25 14:18:01 vdr: [2408] XVDR: Found available device 1 Jan 25 14:18:01 vdr: [2408] XVDR: Channel information found in cache Jan 25 14:18:01 vdr: [2410] XVDR: LiveQueue started Jan 25 14:18:01 vdr: [2408] XVDR: Stream: H264 PID: 68 0x0 DAR: 0.00 (parsed: no) Jan 25 14:18:01 vdr: [2408] XVDR: Stream: MPEG2AUDIO PID: 69 0 Hz, 0 channels, Lang: fra (parsed: no) Jan 25 14:18:01 vdr: [2408] XVDR: Successfully switched to channel 109 - MEZZO HD Jan 25 14:18:01 vdr: [2411] receiver on device 1 thread started (pid=1847, tid=2411, prio=high) Jan 25 14:18:01 vdr: [2408] XVDR: Started streaming of channel MEZZO HD (timeout 3 seconds, priority 50) Jan 25 14:18:01 vdr: [2412] cLiveStreamer stream processor thread started (pid=1847, tid=2412, prio=high) Jan 25 14:18:01 vdr: [2413] TS buffer on device 1 thread started (pid=1847, tid=2413, prio=high) Jan 25 14:18:02 vdr: [1894] suspendoutput: output suspended by inactivity timer Jan 25 14:18:02 vdr: [1938] TS buffer on device 2 thread ended (pid=1847, tid=1938) Jan 25 14:18:02 vdr: [1937] buffer stats: 60536 (0%) used Jan 25 14:18:02 vdr: [1937] receiver on device 2 thread ended (pid=1847, tid=1937) Jan 25 14:18:02 vdr: [2412] XVDR: -------------------------------------- Jan 25 14:18:02 vdr: [2412] XVDR: NEW AUDIO INFORMATION: Jan 25 14:18:02 vdr: [2412] XVDR: Channels: 2 Jan 25 14:18:02 vdr: [2412] XVDR: Samplerate: 48000 Hz Jan 25 14:18:02 vdr: [2412] XVDR: Bitrate: 256000 bps Jan 25 14:18:02 vdr: [2412] XVDR: -------------------------------------- Jan 25 14:18:02 vdr: [2412] XVDR: -------------------------------------- Jan 25 14:18:02 vdr: [2412] XVDR: NEW PICTURE INFORMATION: Jan 25 14:18:02 vdr: [2412] XVDR: Picture Width: 1920 Jan 25 14:18:02 vdr: [2412] XVDR: Picture Height: 1080 Jan 25 14:18:02 vdr: [2412] XVDR: Display Aspect Ratio: 1.78 Jan 25 14:18:02 vdr: [2412] XVDR: -------------------------------------- Jan 25 14:18:02 vdr: [2412] XVDR: streaming of channel started Jan 25 14:18:02 vdr: [2412] XVDR: Stored channel information in cache: Jan 25 14:18:02 vdr: [2412] XVDR: Stream: H264 PID: 68 1920x1080 DAR: 1.78 (parsed: yes) Jan 25 14:18:02 vdr: [2412] XVDR: Stream: MPEG2AUDIO PID: 69 48000 Hz, 2 channels, Lang: fra (parsed: yes)

ghost avatar Jan 25 '13 13:01 ghost

Very strange. It seems there isn't any PAT/PMT information arriving. Is this an encrypted channel ? Which CAM are you using ?

pipelka avatar Jan 27 '13 08:01 pipelka

BTW, which VDR version are you using ?

pipelka avatar Jan 27 '13 13:01 pipelka

VDR 1.7.32

ghost avatar Jan 27 '13 17:01 ghost

Hi again,

sorry I missed the previous question! It is an encrypted channel yes, I am using vdr-sc.

ghost avatar Jan 28 '13 14:01 ghost

Does this happen on starting or switching to that channel ?

pipelka avatar Jan 28 '13 16:01 pipelka

On switching to a channel that was never switched before the start of VDR (or XBMC, not sure about that).

ghost avatar Jan 28 '13 16:01 ghost

Sound's like an old bug that was already fixed. Please try to remove the channelcache:

# rm /var/lib/vdr/plugins/xvdr/channelcache.data
or
# rm /etc/vdr/plugins/xvdr/channelcache.data

The path depends on your installation.

But maybe it's some strange interaction with other plugins. You could try to enable only a minimum of plugins (e.g. xvdr + sc).

I'm unable to reproduce this neither on my development nor on my production system.

pipelka avatar Jan 28 '13 19:01 pipelka

Hi,

so far so good. When should I delete this file ? every time I start vdr ?

Thanks

ghost avatar Jan 29 '13 10:01 ghost

Only once to be sure that the channel cache will be cleanly regenerated.

pipelka avatar Jan 29 '13 10:01 pipelka

BTW, maybe you can check if this only happens for encrypted channels ?

pipelka avatar Jan 29 '13 11:01 pipelka

Hi,

yes I am pretty sure it's only for this kind of channels.

BR, Gilles

ghost avatar Jan 29 '13 13:01 ghost

Maybe you should inspect the sc.log when this happens. An other opportunity would be to try the dvbapi plugin.

pipelka avatar Jan 29 '13 13:01 pipelka

I found another corner case: it's possible that all devices are busy at the moment of a channel switch. until now the streamer just waited and never received any data.

this is fixed in "master" and "master-pre-vdr-1.7.34"

pipelka avatar Jan 29 '13 19:01 pipelka

Hi,

thanks for this fix, but I don't think they are busy (I have 2 of them unused).

I ll try the patch, thanks!

ghost avatar Jan 30 '13 10:01 ghost

channelcache.data is located under Ubuntu at:

/var/cache/vdr/plugins/xvdr/channelcache.data

ckarrie avatar Aug 23 '13 16:08 ckarrie