Simon Baxter kirjoitti 24.4.2008 kello 10.08:

Hello
 
I have 2x DVB-C cards with Alphacrypt multi-cams.  A TT-1500-C budget card and a TT-2300-C FF card and run vdr-xine.
 
When recording one channel and attempting to watch another in the same transport stream, or trying to switch to another transport stream (and hence card) I get "channel not available" messages.  After switching back and forth to other transport streams, usually I can overcome this problem.  But occasionally I it won't play any channels in one specific transport stream or another.
 
What's the best way to diagnose this?  How do I enable debugging to see more info than is displayed in messages:
 
Apr 24 18:53:56 callin vdr: [7375] switching to channel 8
Apr 24 18:53:56 callin vdr: [30940] transfer thread started (pid=7375, tid=30940)
Apr 24 18:53:57 callin vdr: [30939] femon receiver thread ended (pid=7375, tid=30939)
Apr 24 18:53:57 callin vdr: [30941] femon receiver thread started (pid=7375, tid=30941)
Apr 24 18:53:58 callin vdr: [30940] setting audio track to 1 (0)
Apr 24 18:54:04 callin vdr: [7375] switching to channel 9
Apr 24 18:54:04 callin vdr: [30940] transfer thread ended (pid=7375, tid=30940)
Apr 24 18:54:04 callin vdr: [7375] buffer stats: 47564 (2%) used
Apr 24 18:54:04 callin vdr: [7375] info: Channel not available!
Apr 24 18:54:04 callin vdr: [7375] ERROR: attempt to open OSD while it is already open - using dummy OSD!
Apr 24 18:54:22 callin vdr: [7375] switching to channel 1
Apr 24 18:54:22 callin vdr: [30942] transfer thread started (pid=7375, tid=30942)
Apr 24 18:54:22 callin vdr: [30936] TS buffer on device 2 thread ended (pid=7375, tid=30936)
Apr 24 18:54:22 callin vdr: [30935] buffer stats: 84600 (4%) used
Apr 24 18:54:22 callin vdr: [30935] receiver on device 2 thread ended (pid=7375, tid=30935)
Apr 24 18:54:22 callin vdr: [30943] receiver on device 2 thread started (pid=7375, tid=30943)
Apr 24 18:54:22 callin vdr: [30944] TS buffer on device 2 thread started (pid=7375, tid=30944)
Apr 24 18:54:23 callin vdr: [30945] femon receiver thread started (pid=7375, tid=30945)
Apr 24 18:54:23 callin vdr: [30942] setting audio track to 1 (0)
Apr 24 18:54:26 callin vdr: [7375] switching to channel 9
Apr 24 18:54:26 callin vdr: [30942] transfer thread ended (pid=7375, tid=30942)
Apr 24 18:54:26 callin vdr: [7375] buffer stats: 194204 (9%) used
Apr 24 18:54:26 callin vdr: [7375] info: Channel not available!
Apr 24 18:54:26 callin vdr: [7375] ERROR: attempt to open OSD while it is already open - using dummy OSD!
Apr 24 18:54:42 callin vdr: [7375] switching to channel 21
 

Hi,

I don't know if this is same problem or not but I'm having similar symptoms with one encrypted channel. With plain VDR 1.6.0 I cannot tune to that channel, while 1.4.7 works. As can be seen from the log, the receiving starts from couple of seconds but stops right after giving this channel not available message. My system has DVB-C 2.1 FF card and Satelco Easywatch budget card. All the other encrypted channels works ok, but this one channel has problems with VDR 1.6.0.

Here's the channels.conf entry:

EuroNews;GlobeCast:306000:C0M128:C:6875:2221:2232=eng,2233=deu,2231=fra,2234=ita,2235=esl,2236=por,2237=rus,2238:768:B00:214:0:10:0


and here's the syslog:

Apr 27 13:31:53 localhost vdr: [10238] cTimeMs: using monotonic clock (resolution is 999848 ns)
Apr 27 13:31:53 localhost vdr: [10238] VDR version 1.6.0 started
Apr 27 13:31:53 localhost vdr: [10238] codeset is 'ISO-8859-1' - known
Apr 27 13:31:53 localhost vdr: [10238] found 23 locales in ./locale
Apr 27 13:31:53 localhost vdr: [10238] loading /video/setup.conf
Apr 27 13:31:53 localhost vdr: [10238] loading /video/sources.conf
Apr 27 13:31:53 localhost vdr: [10238] loading /video/channels.conf
Apr 27 13:31:53 localhost vdr: [10238] loading /video/timers.conf
Apr 27 13:31:53 localhost vdr: [10238] loading /video/svdrphosts.conf
Apr 27 13:31:53 localhost vdr: [10238] loading /video/remote.conf
Apr 27 13:31:53 localhost vdr: [10238] loading /video/keymacros.conf
Apr 27 13:31:53 localhost vdr: [10238] reading EPG data from /video/epg.data
Apr 27 13:31:53 localhost vdr: [10248] video directory scanner thread started (pid=10238, tid=10248)
Apr 27 13:31:53 localhost vdr: [10249] video directory scanner thread started (pid=10238, tid=10249)
Apr 27 13:31:53 localhost vdr: [10249] video directory scanner thread ended (pid=10238, tid=10249)
Apr 27 13:31:53 localhost vdr: [10248] video directory scanner thread ended (pid=10238, tid=10248)
Apr 27 13:31:53 localhost vdr: [10238] probing /dev/dvb/adapter0/frontend0
Apr 27 13:31:53 localhost vdr: [10251] CI adapter on device 0 thread started (pid=10238, tid=10251)
Apr 27 13:31:53 localhost vdr: [10238] probing /dev/dvb/adapter1/frontend0
Apr 27 13:31:53 localhost vdr: [10252] tuner on device 1 thread started (pid=10238, tid=10252)
Apr 27 13:31:53 localhost vdr: [10253] section handler thread started (pid=10238, tid=10253)
Apr 27 13:31:53 localhost vdr: [10255] CI adapter on device 1 thread started (pid=10238, tid=10255)
Apr 27 13:31:53 localhost vdr: [10251] CAM 1: module present
Apr 27 13:31:54 localhost vdr: [10238] found 2 video devices
Apr 27 13:31:54 localhost vdr: [10238] setting primary device to 1
Apr 27 13:31:54 localhost vdr: [10256] tuner on device 2 thread started (pid=10238, tid=10256)
Apr 27 13:31:54 localhost vdr: [10257] section handler thread started (pid=10238, tid=10257)
Apr 27 13:31:54 localhost vdr: [10238] assuming manual start of VDR
Apr 27 13:31:54 localhost vdr: [10238] SVDRP listening on port 2001
Apr 27 13:31:54 localhost vdr: [10238] skin "DeepBlue" not available - using "classic" instead
Apr 27 13:31:54 localhost vdr: [10238] loading /video/themes/classic-default.theme
Apr 27 13:31:54 localhost vdr: [10238] skin "DeepBlue" not available - using "classic" instead
Apr 27 13:31:54 localhost vdr: [10238] loading /video/themes/classic-default.theme
Apr 27 13:31:54 localhost vdr: [10238] remote control LIRC - keys known
Apr 27 13:31:54 localhost vdr: [10258] LIRC remote control thread started (pid=10238, tid=10258)
Apr 27 13:31:55 localhost vdr: [10251] CAM 2: no module present
Apr 27 13:31:55 localhost vdr: [10255] CAM 3: no module present
Apr 27 13:31:55 localhost vdr: [10238] switching to channel 1
Apr 27 13:31:55 localhost vdr: [10238] setting watchdog timer to 30 seconds
Apr 27 13:31:55 localhost vdr: [10251] CAM 1: no module present
Apr 27 13:31:55 localhost vdr: [10251] CAM 1: module present
Apr 27 13:31:56 localhost vdr: [10253] channel 2 (YLE TV2) event Su  27.04.2008 12:31-13:55 'Sunnuntaidokkari: Maalaiselämää II' status 4
Apr 27 13:31:56 localhost vdr: [10253] channel 3 (MTV3) event Su  27.04.2008 13:05-14:05 'Äitini - eläintarhan tohtori' status 4
Apr 27 13:31:56 localhost vdr: [10253] channel 4 (Nelonen) event Su  27.04.2008 13:30-14:00 'Perhe on pahin' status 4
Apr 27 13:31:57 localhost vdr: [10253] changing pids of channel 1 from 512+512:650=fin:0:2321 to 512+512:650=fin:1027=fin:2321
Apr 27 13:31:57 localhost vdr: [10238] retuning due to modification of channel 1
Apr 27 13:31:57 localhost vdr: [10238] switching to channel 1
Apr 27 13:31:57 localhost vdr: [10267] live subtitle thread started (pid=10238, tid=10267)
Apr 27 13:31:57 localhost vdr: [10268] receiver on device 1 thread started (pid=10238, tid=10268)
Apr 27 13:31:57 localhost vdr: [10269] TS buffer on device 1 thread started (pid=10238, tid=10269)
Apr 27 13:31:57 localhost vdr: [10253] changing pids of channel 2 from 513+513:660=fra:0:2321 to 513+513:660=fra:2027=fin:2321
Apr 27 13:31:57 localhost vdr: [10253] changing pids of channel 3 from 305+305:561=fin:0:817 to 305+305:561=fin:1073=fin:817
Apr 27 13:31:57 localhost vdr: [10251] CAM 1: no module present
Apr 27 13:31:57 localhost vdr: [10251] CAM 1: module present
Apr 27 13:31:58 localhost vdr: [10253] changing pids of channel 5 from 514+514:670=sve:0:2321 to 514+514:670=sve:3028=sve,3027=fin:2321
Apr 27 13:31:58 localhost vdr: [10253] changing pids of channel 8 from 516+516:690=fin:0:2321 to 516+516:690=fin:4027=fin:2321
Apr 27 13:31:59 localhost vdr: [10238] max. latency time 1 seconds
Apr 27 13:31:59 localhost vdr: [10251] CAM 1: no module present
Apr 27 13:31:59 localhost vdr: [10251] CAM 1: module present
Apr 27 13:32:02 localhost vdr: [10251] CAM 1: module ready
Apr 27 13:32:05 localhost vdr: [10251] CAM 1: Conax 4.00e, 01, 0B00, 04B1
Apr 27 13:32:09 localhost vdr: [10251] CAM 1: doesn't reply to QUERY - only a single channel can be decrypted
Apr 27 13:32:26 localhost vdr: [10238] switching to channel 24
Apr 27 13:32:26 localhost vdr: [10267] live subtitle thread ended (pid=10238, tid=10267)
Apr 27 13:32:26 localhost vdr: [10238] buffer stats: 564 (0%) used
Apr 27 13:32:26 localhost vdr: [10238] CAM 1: assigned to device 1
Apr 27 13:32:26 localhost vdr: [10342] transfer thread started (pid=10238, tid=10342)
Apr 27 13:32:26 localhost vdr: [10269] TS buffer on device 1 thread ended (pid=10238, tid=10269)
Apr 27 13:32:26 localhost vdr: [10268] buffer stats: 188 (0%) used
Apr 27 13:32:26 localhost vdr: [10268] receiver on device 1 thread ended (pid=10238, tid=10268)
Apr 27 13:32:26 localhost vdr: [10343] receiver on device 1 thread started (pid=10238, tid=10343)
Apr 27 13:32:26 localhost vdr: [10344] TS buffer on device 1 thread started (pid=10238, tid=10344)
Apr 27 13:32:30 localhost vdr: [10342] transfer thread ended (pid=10238, tid=10342)
Apr 27 13:32:30 localhost vdr: [10344] TS buffer on device 1 thread ended (pid=10238, tid=10344)
Apr 27 13:32:30 localhost vdr: [10343] buffer stats: 117312 (5%) used
Apr 27 13:32:30 localhost vdr: [10343] receiver on device 1 thread ended (pid=10238, tid=10343)
Apr 27 13:32:31 localhost vdr: [10238] switching to channel 24
Apr 27 13:32:31 localhost vdr: [10238] cTS2PES got 26 TS errors, 10 TS continuity errors
Apr 27 13:32:31 localhost vdr: [10238] cTS2PES got 1 TS errors, 0 TS continuity errors
Apr 27 13:32:31 localhost last message repeated 4 times
Apr 27 13:32:31 localhost vdr: [10238] cTS2PES got 2 TS errors, 1 TS continuity errors
Apr 27 13:32:31 localhost vdr: [10238] cTS2PES got 1 TS errors, 0 TS continuity errors
Apr 27 13:32:31 localhost vdr: [10238] buffer stats: 50760 (2%) used
Apr 27 13:32:31 localhost vdr: [10238] info: Kanava ei ole käytettävissä!
Apr 27 13:32:33 localhost vdr: [10238] max. latency time 3 seconds
Apr 27 13:32:42 localhost vdr: [10238] switching to channel 24
Apr 27 13:32:42 localhost vdr: [10238] info: Kanava ei ole käytettävissä!
Apr 27 13:32:53 localhost vdr: [10238] switching to channel 24
Apr 27 13:32:53 localhost vdr: [10403] transfer thread started (pid=10238, tid=10403)
Apr 27 13:32:53 localhost vdr: [10404] receiver on device 1 thread started (pid=10238, tid=10404)
Apr 27 13:32:53 localhost vdr: [10405] TS buffer on device 1 thread started (pid=10238, tid=10405)
Apr 27 13:32:55 localhost vdr: [10403] setting audio track to 1 (0)
Apr 27 13:32:57 localhost vdr: [10403] transfer thread ended (pid=10238, tid=10403)
Apr 27 13:32:57 localhost vdr: [10405] TS buffer on device 1 thread ended (pid=10238, tid=10405)
Apr 27 13:32:57 localhost vdr: [10404] buffer stats: 137616 (6%) used
Apr 27 13:32:57 localhost vdr: [10404] receiver on device 1 thread ended (pid=10238, tid=10404)
Apr 27 13:33:04 localhost vdr: [10238] switching to channel 24
Apr 27 13:33:04 localhost vdr: [10238] buffer stats: 51700 (2%) used
Apr 27 13:33:04 localhost vdr: [10238] info: Kanava ei ole käytettävissä!
Apr 27 13:33:15 localhost vdr: [10238] switching to channel 24
Apr 27 13:33:15 localhost vdr: [10464] transfer thread started (pid=10238, tid=10464)
Apr 27 13:33:15 localhost vdr: [10465] receiver on device 1 thread started (pid=10238, tid=10465)
Apr 27 13:33:15 localhost vdr: [10466] TS buffer on device 1 thread started (pid=10238, tid=10466)
Apr 27 13:33:16 localhost vdr: [10464] setting audio track to 1 (0)
Apr 27 13:33:19 localhost vdr: [10464] transfer thread ended (pid=10238, tid=10464)
Apr 27 13:33:19 localhost vdr: [10466] TS buffer on device 1 thread ended (pid=10238, tid=10466)
Apr 27 13:33:19 localhost vdr: [10465] buffer stats: 134420 (6%) used
Apr 27 13:33:19 localhost vdr: [10465] receiver on device 1 thread ended (pid=10238, tid=10465)
Apr 27 13:33:26 localhost vdr: [10238] switching to channel 24
Apr 27 13:33:26 localhost vdr: [10238] buffer stats: 51324 (2%) used
Apr 27 13:33:26 localhost vdr: [10238] info: Kanava ei ole käytettävissä!
Apr 27 13:33:30 localhost vdr: [10253] changing pids of channel 124 from 0+0:648=fra;649=eng:0:0 to 0+0:648=fra;649=eng:608=fin,607=dan,606=nor,605=sve:0
Apr 27 13:33:30 localhost vdr: [10257] changing pids of channel 33 from 354+354:610=fin:0:0 to 354+354:610=fin:1122=fin:0
Apr 27 13:33:30 localhost vdr: [10257] changing pids of channel 34 from 312+312:313=fin:0:817 to 312+312:313=fin:315=fin,316=sve:817
Apr 27 13:33:30 localhost vdr: [10257] changing pids of channel 35 from 322+322:323=fin:0:817 to 322+322:323=fin:325=fin,326=sve:817
Apr 27 13:33:31 localhost vdr: [10257] changing pids of channel 36 from 352+352:353=fin:0:817 to 352+352:353=fin:355=fin:817
Apr 27 13:33:31 localhost vdr: [10257] changing pids of channel 37 from 372+372:373=fin:0:817 to 372+372:373=fin:375=fin,376=sve:817
Apr 27 13:33:31 localhost vdr: [10257] changing pids of channel 38 from 362+362:363=fin:0:817 to 362+362:363=fin:365=fin,366=sve:817
Apr 27 13:33:31 localhost vdr: [10257] changing pids of channel 32 from 304+304:560=fin:0:817 to 304+304:560=fin:1072=fin:817
Apr 27 13:33:32 localhost vdr: [10251] CAM 1: module reset
Apr 27 13:33:32 localhost vdr: [10251] CAM 1: module present
Apr 27 13:33:32 localhost vdr: [10238] switching to channel 1
Apr 27 13:33:32 localhost vdr: [10238] CAM 1: unassigned
Apr 27 13:33:32 localhost vdr: [10503] live subtitle thread started (pid=10238, tid=10503)
Apr 27 13:33:32 localhost vdr: [10504] receiver on device 1 thread started (pid=10238, tid=10504)
Apr 27 13:33:32 localhost vdr: [10505] TS buffer on device 1 thread started (pid=10238, tid=10505)
Apr 27 13:33:33 localhost vdr: [10251] CAM 1: module ready
Apr 27 13:33:36 localhost vdr: [10251] CAM 1: Conax 4.00e, 01, 0B00, 04B1
Apr 27 13:33:41 localhost vdr: [10251] CAM 1: doesn't reply to QUERY - only a single channel can be decrypted



-- 
Tero