search

pipelka / vdr-plugin-xvdr

DISCONTINUED - XVDR Plugin for VDR
GNU General Public License v2.0
43 stars 22 forks source link

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

Open ghost opened 11 years ago

ghost commented 11 years ago

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: --------------------------------------

pipelka commented 11 years ago

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.

ghost commented 11 years ago

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.

pipelka commented 11 years ago

Is this still valid with the latest "master" ?

ghost commented 11 years ago

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

ghost commented 11 years ago

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)

pipelka commented 11 years ago

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

pipelka commented 11 years ago

BTW, which VDR version are you using ?

ghost commented 11 years ago

VDR 1.7.32

ghost commented 11 years ago

Hi again,

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

pipelka commented 11 years ago

Does this happen on starting or switching to that channel ?

ghost commented 11 years ago

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

pipelka commented 11 years ago

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.

ghost commented 11 years ago

Hi,

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

Thanks

pipelka commented 11 years ago

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

pipelka commented 11 years ago

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

ghost commented 11 years ago

Hi,

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

BR, Gilles

pipelka commented 11 years ago

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

pipelka commented 11 years ago

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"

ghost commented 11 years ago

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!

ckarrie commented 10 years ago

channelcache.data is located under Ubuntu at:

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