Hi,
I upgraded my VDR setup from 1.4.7 to 1.5.17. After the upgrade I've begun to see these CAM initialization and TS continuity error messages in the syslog (see the attached file). I'm using Technotrend 1500 DVB- C card with CI and Conax CAM and card from local cable operator. Operating system is Ubuntu gutsy with Ubuntu's default 2.6.22 based kernel. Any idea what might be going on?
Tuomas Jormola wrote:
I upgraded my VDR setup from 1.4.7 to 1.5.17. After the upgrade I've begun to see these CAM initialization and TS continuity error messages in the syslog (see the attached file). I'm using Technotrend 1500 DVB-C card with CI and Conax CAM and card from local cable operator.
No answer so far... Same error here. I have similar configuration. I'm using vdr-1.6.0 with xine plugin, kernel 2.6.24.3, multiproto drivers, Terratec Cinergy 1200 DVB-C with CI and Technisat Conax CAM (TechniCAM CX). It is impossible to watch either FTA or crypted channels with iserted CAM. At the same time, all this works with kaffeine and with gnutv from dvb-apps I can access CAM menu.
AK
Mar 30 15:24:24 vdr vdr: [10975] cTimeMs: using monotonic clock (resolution is 4000250 ns) Mar 30 15:24:24 vdr vdr: [10975] VDR version 1.6.0 started Mar 30 15:24:24 vdr vdr: [10975] codeset is 'UTF-8' - known Mar 30 15:24:25 vdr vdr: [10975] found 23 locales in /usr/local/src/vdr-1.6.0/locale Mar 30 15:24:25 vdr vdr: [10975] loading plugin: /usr/local/src/vdr-1.6.0-vanilla/PLUGINS/lib/libvdr-xine.so.1.6.0 Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/setup.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/sources.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/diseqc.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/channels.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/timers.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/commands.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/reccmds.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/svdrphosts.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/remote.conf Mar 30 15:24:25 vdr vdr: [10975] loading /usr/local/etc/vdr/keymacros.conf Mar 30 15:24:25 vdr vdr: [10976] video directory scanner thread started (pid=10975, tid=10976) Mar 30 15:24:25 vdr vdr: [10977] video directory scanner thread started (pid=10975, tid=10977) Mar 30 15:24:25 vdr vdr: [10975] reading EPG data from /usr/local/etc/vdr/epg.data Mar 30 15:24:25 vdr vdr: [10976] video directory scanner thread ended (pid=10975, tid=10976) Mar 30 15:24:25 vdr vdr: [10977] video directory scanner thread ended (pid=10975, tid=10977) Mar 30 15:24:25 vdr vdr: [10975] probing /dev/dvb/adapter0/frontend0 Mar 30 15:24:25 vdr vdr: [10979] CI adapter on device 0 thread started (pid=10975, tid=10979) Mar 30 15:24:25 vdr kernel: DVB: TDA10021(0): _tda10021_writereg, writereg error (reg == 0x01, val == 0x6a, ret == -121) Mar 30 15:24:25 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:26 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:26 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:27 vdr vdr: [10980] tuner on device 1 thread started (pid=10975, tid=10980) Mar 30 15:24:27 vdr vdr: [10981] section handler thread started (pid=10975, tid=10981) Mar 30 15:24:27 vdr vdr: [10975] found 1 video device Mar 30 15:24:27 vdr vdr: [10975] initializing plugin: xine (0.8.2): Software based playback using xine Mar 30 15:24:27 vdr vdr: [10982] XineRemote control thread started (pid=10975, tid=10982) Mar 30 15:24:27 vdr vdr: [10982] Entering cXineRemote thread Mar 30 15:24:27 vdr vdr: [10975] setting primary device to 2 Mar 30 15:24:27 vdr vdr: [10975] assuming manual start of VDR Mar 30 15:24:27 vdr vdr: [10975] SVDRP listening on port 2001 Mar 30 15:24:27 vdr vdr: [10975] starting plugin: xine Mar 30 15:24:27 vdr vdr: [10985] KBD remote control thread started (pid=10975, tid=10985) Mar 30 15:24:27 vdr vdr: [10975] ERROR: remote control XineRemote not ready! Mar 30 15:24:27 vdr vdr: [10975] remote control KBD - keys known Mar 30 15:24:28 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:30 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:30 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:32 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:33 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:33 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:36 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:37 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:37 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:39 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:41 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:41 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:43 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:44 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:44 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:47 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:48 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:48 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:51 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:52 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:52 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:54 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:56 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:56 vdr vdr: [10979] CAM 1: module ready Mar 30 15:24:57 vdr vdr: [10975] not all devices ready after 30 seconds Mar 30 15:24:57 vdr vdr: [10975] switching to channel 50 Mar 30 15:24:57 vdr vdr: [11006] transfer thread started (pid=10975, tid=11006) Mar 30 15:24:57 vdr vdr: [11007] receiver on device 1 thread started (pid=10975, tid=11007) Mar 30 15:24:57 vdr vdr: [11008] TS buffer on device 1 thread started (pid=10975, tid=11008) Mar 30 15:24:57 vdr vdr: [10975] setting watchdog timer to 60 seconds Mar 30 15:24:58 vdr vdr: [10979] CAM 1: module present Mar 30 15:24:59 vdr vdr: [10975] max. latency time 1 seconds Mar 30 15:24:59 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:24:59 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:02 vdr vdr: [10979] CAM 1: module present Mar 30 15:25:03 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:25:03 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:05 vdr kernel: DVB: TDA10021: tda10021_readreg: readreg error (ret == -121) Mar 30 15:25:05 vdr vdr: [10979] CAM 1: module present Mar 30 15:25:07 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:25:07 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:09 vdr vdr: [10979] CAM 1: module present Mar 30 15:25:10 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:25:10 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:11 vdr vdr: [10975] ERROR: Can't open CAM menu! Mar 30 15:25:13 vdr vdr: [10979] CAM 1: module present Mar 30 15:25:14 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:25:14 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:17 vdr vdr: [10979] CAM 1: module present Mar 30 15:25:18 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:25:18 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:20 vdr vdr: [10979] CAM 1: module present Mar 30 15:25:22 vdr kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Mar 30 15:25:22 vdr vdr: [10979] CAM 1: module ready Mar 30 15:25:23 vdr vdr: [10975] caught signal 2 Mar 30 15:25:23 vdr vdr: [10975] stopping plugin: xine Mar 30 15:25:23 vdr vdr: [11006] transfer thread ended (pid=10975, tid=11006) Mar 30 15:25:23 vdr vdr: [10975] cTS2PES got 3 TS errors, 1 TS continuity errors Mar 30 15:25:23 vdr vdr: [10975] cTS2PES got 2 TS errors, 1 TS continuity errors Mar 30 15:25:23 vdr vdr: [10975] buffer stats: 940 (0%) used Mar 30 15:25:23 vdr vdr: [10982] Leaving cXineRemote thread Mar 30 15:25:23 vdr vdr: [10982] XineRemote control thread ended (pid=10975, tid=10982) Mar 30 15:25:23 vdr vdr: [10985] KBD remote control thread ended (pid=10975, tid=10985) Mar 30 15:25:23 vdr vdr: [10975] saved setup to /usr/local/etc/vdr/setup.conf Mar 30 15:25:23 vdr vdr: [11008] TS buffer on device 1 thread ended (pid=10975, tid=11008) Mar 30 15:25:23 vdr vdr: [11007] buffer stats: 376 (0%) used Mar 30 15:25:23 vdr vdr: [11007] receiver on device 1 thread ended (pid=10975, tid=11007)
On 03/31/08 07:32, Arthur Konovalov wrote:
Tuomas Jormola wrote:
I upgraded my VDR setup from 1.4.7 to 1.5.17. After the upgrade I've begun to see these CAM initialization and TS continuity error messages in the syslog (see the attached file). I'm using Technotrend 1500 DVB-C card with CI and Conax CAM and card from local cable operator.
No answer so far... Same error here. I have similar configuration. I'm using vdr-1.6.0 with xine plugin, kernel 2.6.24.3, multiproto drivers, Terratec Cinergy 1200 DVB-C with CI and Technisat Conax CAM (TechniCAM CX). It is impossible to watch either FTA or crypted channels with iserted CAM. At the same time, all this works with kaffeine and with gnutv from dvb-apps I can access CAM menu.
Looks like the lastModuleStatus for some reason falls back to msReset.
Please dd some debug output to cCamSlot::ModuleStatus() to see what's going on around ciAdapter->ModuleStatus(slotIndex) and resetTime. Maybe resetTime should be handled in milliseconds, using a cTimeMs...
Klaus
Well, I'm not big guru of debugging. I made following changes to mentioned part of code:
eModuleStatus cCamSlot::ModuleStatus(void) { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; isyslog("ms: %d", ms); //AKO isyslog("resetTime1: %d", resetTime); //AK if (resetTime) { isyslog("resetTime2: %d", resetTime); //AK if (ms <= msReset) { isyslog("resetTime3: %d", resetTime); //AK if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) isyslog("resetTime4: %d", resetTime); //AK return msReset; } resetTime = 0; } return ms; }
Log file attached. I suspect that additional instructions are welcome.
AK
Klaus Schmidinger wrote:
Looks like the lastModuleStatus for some reason falls back to msReset.
Please dd some debug output to cCamSlot::ModuleStatus() to see what's going on around ciAdapter->ModuleStatus(slotIndex) and resetTime. Maybe resetTime should be handled in milliseconds, using a cTimeMs...
Apr 7 09:06:37 vdr vdr: [4862] cTimeMs: using monotonic clock (resolution is 4000250 ns) Apr 7 09:06:37 vdr vdr: [4862] VDR version 1.6.0 started Apr 7 09:06:37 vdr vdr: [4862] codeset is 'UTF-8' - known Apr 7 09:06:37 vdr vdr: [4862] found 23 locales in /usr/local/src/vdr-1.6.0/locale Apr 7 09:06:37 vdr vdr: [4862] loading plugin: /usr/local/src/vdr-1.6.0-vanilla/PLUGINS/lib/libvdr-xine.so.1.6.0 Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/setup.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/sources.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/diseqc.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/channels.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/timers.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/commands.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/reccmds.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/svdrphosts.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/remote.conf Apr 7 09:06:37 vdr vdr: [4862] loading /usr/local/etc/vdr/keymacros.conf Apr 7 09:06:37 vdr vdr: [4863] video directory scanner thread started (pid=4862, tid=4863) Apr 7 09:06:37 vdr vdr: [4864] video directory scanner thread started (pid=4862, tid=4864) Apr 7 09:06:37 vdr vdr: [4862] reading EPG data from /usr/local/etc/vdr/epg.data Apr 7 09:06:37 vdr vdr: [4863] video directory scanner thread ended (pid=4862, tid=4863) Apr 7 09:06:37 vdr vdr: [4864] video directory scanner thread ended (pid=4862, tid=4864) Apr 7 09:06:38 vdr vdr: [4862] probing /dev/dvb/adapter0/frontend0 Apr 7 09:06:38 vdr vdr: [4866] tuner on device 1 thread started (pid=4862, tid=4866) Apr 7 09:06:38 vdr vdr: [4867] section handler thread started (pid=4862, tid=4867) Apr 7 09:06:38 vdr vdr: [4862] probing /dev/dvb/adapter1/frontend0 Apr 7 09:06:38 vdr vdr: [4869] CI adapter on device 1 thread started (pid=4862, tid=4869) Apr 7 09:06:38 vdr kernel: DVB: TDA10021(1): _tda10021_writereg, writereg error (reg == 0x01, val == 0x6a, ret == -121) Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 1207548398 Apr 7 09:06:38 vdr vdr: [4869] resetTime2: 1207548398 Apr 7 09:06:38 vdr vdr: [4869] CAM 1: module present Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:38 vdr vdr: [4869] ms: 2 Apr 7 09:06:38 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 2 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 2 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr kernel: dvb_ca adapter 1: DVB CAM detected and initialised successfully Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] CAM 1: module ready Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:39 vdr vdr: [4869] ms: 3 Apr 7 09:06:39 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4870] tuner on device 2 thread started (pid=4862, tid=4870) Apr 7 09:06:40 vdr vdr: [4871] section handler thread started (pid=4862, tid=4871) Apr 7 09:06:40 vdr vdr: [4862] found 2 video devices Apr 7 09:06:40 vdr vdr: [4862] initializing plugin: xine (0.8.2): Software based playback using xine Apr 7 09:06:40 vdr vdr: [4872] XineRemote control thread started (pid=4862, tid=4872) Apr 7 09:06:40 vdr vdr: [4872] Entering cXineRemote thread Apr 7 09:06:40 vdr vdr: [4862] setting primary device to 3 Apr 7 09:06:40 vdr vdr: [4862] assuming manual start of VDR Apr 7 09:06:40 vdr vdr: [4862] SVDRP listening on port 2001 Apr 7 09:06:40 vdr vdr: [4862] starting plugin: xine Apr 7 09:06:40 vdr vdr: [4862] skin "soppalusikka" not available - using "classic" instead Apr 7 09:06:40 vdr vdr: [4875] KBD remote control thread started (pid=4862, tid=4875) Apr 7 09:06:40 vdr vdr: [4862] ERROR: remote control XineRemote not ready! Apr 7 09:06:40 vdr vdr: [4862] remote control KBD - keys known Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4862] ms: 3 Apr 7 09:06:40 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:40 vdr vdr: [4869] ms: 3 Apr 7 09:06:40 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 3 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 3 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 3 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 3 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 3 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 3 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 1207548401 Apr 7 09:06:41 vdr vdr: [4862] resetTime2: 1207548401 Apr 7 09:06:41 vdr vdr: [4869] ms: 2 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] CAM 1: module present Apr 7 09:06:41 vdr vdr: [4862] ms: 2 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 2 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4869] ms: 2 Apr 7 09:06:41 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4862] ms: 2 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:42 vdr vdr: [4869] ms: 2 Apr 7 09:06:42 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:42 vdr kernel: dvb_ca adapter 1: DVB CAM detected and initialised successfully Apr 7 09:06:42 vdr vdr: [4862] ms: 3 Apr 7 09:06:42 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] CAM 1: module ready Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4862] ms: 3 Apr 7 09:06:43 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:43 vdr vdr: [4869] ms: 3 Apr 7 09:06:43 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4869] ms: 3 Apr 7 09:06:44 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:44 vdr vdr: [4862] ms: 3 Apr 7 09:06:44 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 3 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 3 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 3 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 3 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 3 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 3 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 3 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 3 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 2 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 1207548405 Apr 7 09:06:45 vdr vdr: [4869] resetTime2: 1207548405 Apr 7 09:06:45 vdr vdr: [4869] CAM 1: module present Apr 7 09:06:45 vdr vdr: [4862] ms: 2 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 2 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 2 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 2 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 2 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 2 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 2 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 2 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4862] ms: 2 Apr 7 09:06:45 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:45 vdr vdr: [4869] ms: 2 Apr 7 09:06:45 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4869] ms: 2 Apr 7 09:06:46 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4869] ms: 2 Apr 7 09:06:46 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4869] ms: 2 Apr 7 09:06:46 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4869] ms: 2 Apr 7 09:06:46 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4869] ms: 2 Apr 7 09:06:46 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4869] ms: 2 Apr 7 09:06:46 vdr vdr: [4869] resetTime1: 0 Apr 7 09:06:46 vdr vdr: [4862] ms: 2 Apr 7 09:06:46 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:46 vdr kernel: dvb_ca adapter 1: DVB CAM detected and initialised successfully Apr 7 09:06:46 vdr vdr: [4869] ms: 3
On 04/07/08 08:34, Arthur Konovalov wrote:
Well, I'm not big guru of debugging. I made following changes to mentioned part of code:
eModuleStatus cCamSlot::ModuleStatus(void) { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; isyslog("ms: %d", ms); //AKO isyslog("resetTime1: %d", resetTime); //AK if (resetTime) { isyslog("resetTime2: %d", resetTime); //AK if (ms <= msReset) { isyslog("resetTime3: %d", resetTime); //AK if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) isyslog("resetTime4: %d", resetTime); //AK return msReset; } resetTime = 0; } return ms; }
Log file attached. I suspect that additional instructions are welcome.
At this point...
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
...the module status changed from 3 ("ready") to 2 ("present"). The module status is retrieved from the driver in cDvbCiAdapter::ModuleStatus():
eModuleStatus cDvbCiAdapter::ModuleStatus(int Slot) { ca_slot_info_t sinfo; sinfo.num = Slot; if (ioctl(fd, CA_GET_SLOT_INFO, &sinfo) != -1) { if ((sinfo.flags & CA_CI_MODULE_READY) != 0) return msReady; else if ((sinfo.flags & CA_CI_MODULE_PRESENT) != 0) return msPresent; } else esyslog("ERROR: can't get info of CAM slot %d on device %d: %m", Slot, device->DeviceNumber()); return msNone; }
So for some reason the sinfo.flags doesn't seem to have the CA_CI_MODULE_READY flag set any longer.
Klaus
Hi,
I forgot to post this earlier, but in the attachment you'll find logs of this issue on my system. I modified the code like this:
eModuleStatus cCamSlot::ModuleStatus(void) { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; isyslog("CAM DEBUG: ms: %d resetTime: %d", ms, resetTime); if (resetTime) { if (ms <= msReset) { isyslog("CAM DEBUG: ms le msReset"); if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) { isyslog("CAM DEBUG: return msReset"); return msReset; } } isyslog("CAM DEBUG: resetTime zero"); resetTime = 0; } return ms; }
btw. it looks like a bug crept into Arthur's code below. After if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) if this if expression evaluates true, only the debug message is printed, and return msReset is executed always due to missing brackets. Intendation of the closing brackets of the if blocks in the original piece of code seem to be incorrect, which makes it difficult to spot things like this.
Tuomas Jormola
On 7 Apr 2008, at 19:12, Klaus Schmidinger wrote:
On 04/07/08 08:34, Arthur Konovalov wrote:
Well, I'm not big guru of debugging. I made following changes to mentioned part of code:
eModuleStatus cCamSlot::ModuleStatus(void) { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; isyslog("ms: %d", ms); //AKO isyslog("resetTime1: %d", resetTime); //AK if (resetTime) { isyslog("resetTime2: %d", resetTime); //AK if (ms <= msReset) { isyslog("resetTime3: %d", resetTime); //AK if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) isyslog("resetTime4: %d", resetTime); //AK return msReset; } resetTime = 0; } return ms; }
Log file attached. I suspect that additional instructions are welcome.
At this point...
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
...the module status changed from 3 ("ready") to 2 ("present"). The module status is retrieved from the driver in cDvbCiAdapter::ModuleStatus():
eModuleStatus cDvbCiAdapter::ModuleStatus(int Slot) { ca_slot_info_t sinfo; sinfo.num = Slot; if (ioctl(fd, CA_GET_SLOT_INFO, &sinfo) != -1) { if ((sinfo.flags & CA_CI_MODULE_READY) != 0) return msReady; else if ((sinfo.flags & CA_CI_MODULE_PRESENT) != 0) return msPresent; } else esyslog("ERROR: can't get info of CAM slot %d on device %d: %m", Slot, device->DeviceNumber()); return msNone; }
So for some reason the sinfo.flags doesn't seem to have the CA_CI_MODULE_READY flag set any longer.
Klaus
vdr mailing list vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
On 04/08/08 10:25, Tuomas Jormola wrote:
Hi,
I forgot to post this earlier, but in the attachment you'll find logs of this issue on my system. I modified the code like this:
eModuleStatus cCamSlot::ModuleStatus(void) { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; isyslog("CAM DEBUG: ms: %d resetTime: %d", ms, resetTime); if (resetTime) { if (ms <= msReset) { isyslog("CAM DEBUG: ms le msReset"); if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) { isyslog("CAM DEBUG: return msReset"); return msReset; } } isyslog("CAM DEBUG: resetTime zero"); resetTime = 0; } return ms; }
btw. it looks like a bug crept into Arthur's code below. After if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) if this if expression evaluates true, only the debug message is printed, and return msReset is executed always due to missing brackets.
While you are right about this, I don't think that it even got there, because resetTime was actually 0 when the switch from 3 ("ready") to 2 ("present") occurred:
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
Intendation of the closing brackets of the if blocks in the original piece of code seem to be incorrect, which makes it difficult to spot things like this.
Closing brackets are of course indented, since they are part of the block. But I guess this is a philosophical argument, so let's not get into this ;-)
Klaus
Tuomas Jormola
On 7 Apr 2008, at 19:12, Klaus Schmidinger wrote:
On 04/07/08 08:34, Arthur Konovalov wrote:
Well, I'm not big guru of debugging. I made following changes to mentioned part of code:
eModuleStatus cCamSlot::ModuleStatus(void) { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; isyslog("ms: %d", ms); //AKO isyslog("resetTime1: %d", resetTime); //AK if (resetTime) { isyslog("resetTime2: %d", resetTime); //AK if (ms <= msReset) { isyslog("resetTime3: %d", resetTime); //AK if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) isyslog("resetTime4: %d", resetTime); //AK return msReset; } resetTime = 0; } return ms; }
Log file attached. I suspect that additional instructions are welcome.
At this point...
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
...the module status changed from 3 ("ready") to 2 ("present"). The module status is retrieved from the driver in cDvbCiAdapter::ModuleStatus():
eModuleStatus cDvbCiAdapter::ModuleStatus(int Slot) { ca_slot_info_t sinfo; sinfo.num = Slot; if (ioctl(fd, CA_GET_SLOT_INFO, &sinfo) != -1) { if ((sinfo.flags & CA_CI_MODULE_READY) != 0) return msReady; else if ((sinfo.flags & CA_CI_MODULE_PRESENT) != 0) return msPresent; } else esyslog("ERROR: can't get info of CAM slot %d on device %d: %m", Slot, device->DeviceNumber()); return msNone; }
So for some reason the sinfo.flags doesn't seem to have the CA_CI_MODULE_READY flag set any longer.
Klaus
Klaus Schmidinger wrote:
At this point...
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
...the module status changed from 3 ("ready") to 2 ("present"). The module status is retrieved from the driver in cDvbCiAdapter::ModuleStatus():
eModuleStatus cDvbCiAdapter::ModuleStatus(int Slot) { ca_slot_info_t sinfo; sinfo.num = Slot; if (ioctl(fd, CA_GET_SLOT_INFO, &sinfo) != -1) { if ((sinfo.flags & CA_CI_MODULE_READY) != 0) return msReady; else if ((sinfo.flags & CA_CI_MODULE_PRESENT) != 0) return msPresent; } else esyslog("ERROR: can't get info of CAM slot %d on device %d: %m", Slot, device->DeviceNumber()); return msNone; }
So for some reason the sinfo.flags doesn't seem to have the CA_CI_MODULE_READY flag set any longer.
Please take a look to the test code in attachment, provided by Christoph Pfister. With it I got the following output:
root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000161: 0 0.014133: 1 1.694142: 3
And explanation: After a reset CAM is "absent" for a very short time (<14ms == less than a scheduler tick) and then it takes ~1.7s to become ready again. (The intervall between reset and status query seems to be a bit bigger in vdr - so we only see the 3-->1 change == 3-->2 in vdr numbers).
It's an endless loop: cam detection --> cam reset --> cam not present/ready for a short while --> vdr thinks cam has been physically removed --> cam detection --> cam reset etc.
Big thanks to Christoph for assistance.
Is it realistic to hope for a workaround/solution for this kind of CAMs (Technotrend CX at my case)?
Regards, AK
#include <fcntl.h> #include <linux/dvb/ca.h> #include <stdio.h> #include <string.h> #include <sys/ioctl.h> #include <sys/time.h> #include <unistd.h>
int cam_status(int fd) { ca_slot_info_t info; memset(&info, 0, sizeof(info)); info.num = 0;
if (ioctl(fd, CA_GET_SLOT_INFO, &info) != 0) { printf("error: couldn't get slot info\n"); return -1; }
return info.flags; }
struct timeval start_time;
void print_status(int status) { struct timeval time; gettimeofday(&time, NULL);
int dsec = time.tv_sec - start_time.tv_sec; int dusec = time.tv_usec - start_time.tv_usec;
if (dusec < 0) { dusec += 1000000; dsec -= 1; }
printf("%i.%06i: %i\n", dsec, dusec, status); }
int main() { int fd = open("/dev/dvb/adapter0/ca0", O_RDWR);
if (fd < 0) { printf("error: couldn't open ca handle\n"); return 1; }
gettimeofday(&start_time, NULL);
int status = cam_status(fd); print_status(status);
if (ioctl(fd, CA_RESET, (1 << 0)) != 0) { printf("error: couldn't reset cam\n"); return 1; }
int i; for (i = 0; i < 200; ++i) { int new_status = cam_status(fd);
if (status != new_status) { status = new_status; print_status(status); }
usleep(10000); }
return 0; }
On 04/08/08 21:10, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
At this point...
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
...the module status changed from 3 ("ready") to 2 ("present"). The module status is retrieved from the driver in cDvbCiAdapter::ModuleStatus():
eModuleStatus cDvbCiAdapter::ModuleStatus(int Slot) { ca_slot_info_t sinfo; sinfo.num = Slot; if (ioctl(fd, CA_GET_SLOT_INFO, &sinfo) != -1) { if ((sinfo.flags & CA_CI_MODULE_READY) != 0) return msReady; else if ((sinfo.flags & CA_CI_MODULE_PRESENT) != 0) return msPresent; } else esyslog("ERROR: can't get info of CAM slot %d on device %d: %m", Slot, device->DeviceNumber()); return msNone; }
So for some reason the sinfo.flags doesn't seem to have the CA_CI_MODULE_READY flag set any longer.
Please take a look to the test code in attachment, provided by Christoph Pfister. With it I got the following output:
root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000161: 0 0.014133: 1 1.694142: 3
And explanation: After a reset CAM is "absent" for a very short time (<14ms == less than a scheduler tick) and then it takes ~1.7s to become ready again. (The intervall between reset and status query seems to be a bit bigger in vdr
- so we only see the 3-->1 change == 3-->2 in vdr numbers).
It's an endless loop: cam detection --> cam reset --> cam not present/ready for a short while --> vdr thinks cam has been physically removed --> cam detection --> cam reset etc.
Big thanks to Christoph for assistance.
Is it realistic to hope for a workaround/solution for this kind of CAMs (Technotrend CX at my case)?
Since this apparently happens also without VDR, I guess it will have to be fixed in the driver.
Klaus
On 8 Apr 2008, at 23:49, Klaus Schmidinger wrote:
Since this apparently happens also without VDR, I guess it will have to be fixed in the driver.
Well, the funny thing is that VDR 1.4.7 with exactly the same kernel and hardware does not give any symptoms at all. On startup CAM is initialized quickly just fine.
Tuomas
On 04/08/08 23:17, Tuomas Jormola wrote:
On 8 Apr 2008, at 23:49, Klaus Schmidinger wrote:
Since this apparently happens also without VDR, I guess it will have to be fixed in the driver.
Well, the funny thing is that VDR 1.4.7 with exactly the same kernel and hardware does not give any symptoms at all. On startup CAM is initialized quickly just fine.
VDR 1.4 didn't permanently monitor the module status.
Klaus
On 9 Apr 2008, at 00:26, Klaus Schmidinger wrote:
On 04/08/08 23:17, Tuomas Jormola wrote:
On 8 Apr 2008, at 23:49, Klaus Schmidinger wrote:
Since this apparently happens also without VDR, I guess it will have to be fixed in the driver.
Well, the funny thing is that VDR 1.4.7 with exactly the same kernel and hardware does not give any symptoms at all. On startup CAM is initialized quickly just fine.
VDR 1.4 didn't permanently monitor the module status.
Well, as an end user I don't really care what the two versions do differently behind the scenes. Net effect for me is that with VDR 1.4 my CAM is working and with VDR 1.6 it's unusable. So to me VDR 1.6 is broken, what ever the technical reason might be.
Tuomas
Perhaps a plug-in or a setup menu entry to enable the work around code for VDR until the driver has resolved this issue.
Could this be done as a plugin?
On 09/04/2008, Tuomas Jormola tjormola@cc.hut.fi wrote:
On 9 Apr 2008, at 00:26, Klaus Schmidinger wrote:
On 04/08/08 23:17, Tuomas Jormola wrote:
On 8 Apr 2008, at 23:49, Klaus Schmidinger wrote:
Since this apparently happens also without VDR, I guess it will have to be fixed in the driver.
Well, the funny thing is that VDR 1.4.7 with exactly the same kernel and hardware does not give any symptoms at all. On startup CAM is initialized quickly just fine.
VDR 1.4 didn't permanently monitor the module status.
Well, as an end user I don't really care what the two versions do differently behind the scenes. Net effect for me is that with VDR 1.4 my CAM is working and with VDR 1.6 it's unusable. So to me VDR 1.6 is broken, what ever the technical reason might be.
Tuomas
vdr mailing list vdr@linuxtv.org http://www.linuxtv.org/cgi-bin/mailman/listinfo/vdr
On 04/09/08 02:11, Tuomas Jormola wrote:
On 9 Apr 2008, at 00:26, Klaus Schmidinger wrote:
On 04/08/08 23:17, Tuomas Jormola wrote:
On 8 Apr 2008, at 23:49, Klaus Schmidinger wrote:
Since this apparently happens also without VDR, I guess it will have to be fixed in the driver.
Well, the funny thing is that VDR 1.4.7 with exactly the same kernel and hardware does not give any symptoms at all. On startup CAM is initialized quickly just fine.
VDR 1.4 didn't permanently monitor the module status.
Well, as an end user I don't really care what the two versions do differently behind the scenes. Net effect for me is that with VDR 1.4 my CAM is working and with VDR 1.6 it's unusable. So to me VDR 1.6 is broken, what ever the technical reason might be.
The problem is that this malfunction happens on *your* system, not on *mine*. So I'm afraid I can't be of too much help in debugging this.
Klaus
On 04/09/08 22:14, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
The problem is that this malfunction happens on *your* system, not on *mine*. So I'm afraid I can't be of too much help in debugging this.
What about ssh console to my PC?
Maybe as a last resort.
Please see my other posting I just wrote.
Klaus
On 04/08/08 21:10, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
At this point...
Apr 7 09:06:41 vdr vdr: [4862] ms: 3 Apr 7 09:06:41 vdr vdr: [4862] resetTime1: 0 Apr 7 09:06:41 vdr vdr: [4862] ms: 2
...the module status changed from 3 ("ready") to 2 ("present"). The module status is retrieved from the driver in cDvbCiAdapter::ModuleStatus():
eModuleStatus cDvbCiAdapter::ModuleStatus(int Slot) { ca_slot_info_t sinfo; sinfo.num = Slot; if (ioctl(fd, CA_GET_SLOT_INFO, &sinfo) != -1) { if ((sinfo.flags & CA_CI_MODULE_READY) != 0) return msReady; else if ((sinfo.flags & CA_CI_MODULE_PRESENT) != 0) return msPresent; } else esyslog("ERROR: can't get info of CAM slot %d on device %d: %m", Slot, device->DeviceNumber()); return msNone; }
So for some reason the sinfo.flags doesn't seem to have the CA_CI_MODULE_READY flag set any longer.
Please take a look to the test code in attachment, provided by Christoph Pfister. With it I got the following output:
root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000161: 0 0.014133: 1 1.694142: 3
And explanation: After a reset CAM is "absent" for a very short time (<14ms == less than a scheduler tick) and then it takes ~1.7s to become ready again. (The intervall between reset and status query seems to be a bit bigger in vdr
- so we only see the 3-->1 change == 3-->2 in vdr numbers).
It's an endless loop: cam detection --> cam reset --> cam not present/ready for a short while --> vdr thinks cam has been physically removed --> cam detection --> cam reset etc.
So does this mean that with the small test.c program the module status is continuously going on and off, without VDR even being involved?
Can you post more than the above 4 lines from ./test (like 20 or so)?
Since cCamSlot::Reset() is the only place where resetTime is set to a non-zero value, and you had lines like "resetTime1: 1207548401" in your syslog_1 file, apparently the tc[i]->Process() call in cCamSlot::Process() must have failed. If the communication with the CAM fails, how should VDR continue to work with it?
Klaus
Big thanks to Christoph for assistance.
Is it realistic to hope for a workaround/solution for this kind of CAMs (Technotrend CX at my case)?
Regards, AK
Klaus Schmidinger wrote:
So does this mean that with the small test.c program the module status is continuously going on and off, without VDR even being involved?
No. It just exit.
Can you post more than the above 4 lines from ./test (like 20 or so)?
test* test.c root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000161: 0 0.014133: 1 1.694142: 3 root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000193: 0 0.012121: 1 1.692260: 3 root@vdr:/video/vdr/cam# ./test 0.000009: 3 0.000087: 0 0.013873: 1 1.694011: 3
If the communication with the CAM fails, how should VDR continue to work with it?
I don't know, but Kaffeine works. Sorry, nothing personal, just remark for clarity that success is possible with same hardware.
Regards, Arthur
On 04/10/08 18:52, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
So does this mean that with the small test.c program the module status is continuously going on and off, without VDR even being involved?
No. It just exit.
Please change the line
for (i = 0; i < 200; ++i) {
so that it loop 2000 times. That should cover a longer time.
Can you post more than the above 4 lines from ./test (like 20 or so)?
test* test.c root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000161: 0 0.014133: 1 1.694142: 3 root@vdr:/video/vdr/cam# ./test 0.000008: 3 0.000193: 0 0.012121: 1 1.692260: 3 root@vdr:/video/vdr/cam# ./test 0.000009: 3 0.000087: 0 0.013873: 1 1.694011: 3
If the communication with the CAM fails, how should VDR continue to work with it?
I don't know, but Kaffeine works. Sorry, nothing personal, just remark for clarity that success is possible with same hardware.
I'm not taking anything personal ;-)
Klaus
Klaus Schmidinger wrote:
Please change the line
for (i = 0; i < 200; ++i) {so that it loop 2000 times. That should cover a longer time.
I see. Set to 4000.
Additionally added before 'return 0;': printf("end: "); print_status(status);
Now it loops about 50 seconds : root@vdr:/video/vdr/cam# ./test 0.000010: 3 0.000088: 0 0.012613: 1 1.692749: 3 end: 48.004572: 3
Arthur
On 04/11/08 07:18, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
Please change the line
for (i = 0; i < 200; ++i) {so that it loop 2000 times. That should cover a longer time.
I see. Set to 4000.
Additionally added before 'return 0;': printf("end: "); print_status(status);
Now it loops about 50 seconds : root@vdr:/video/vdr/cam# ./test 0.000010: 3 0.000088: 0 0.012613: 1 1.692749: 3 end: 48.004572: 3
Ok, that proves that the module status is stable - which is good.
Further hints in my other posting.
Klaus
Klaus Schmidinger wrote:
Since cCamSlot::Reset() is the only place where resetTime is set to a non-zero value, and you had lines like "resetTime1: 1207548401" in your syslog_1 file, apparently the tc[i]->Process() call in cCamSlot::Process() must have failed.
Yes, reset came from this procedure. I added some printouts (look at attached diff).
How to see reason why this Reset() is called?
Arthur
--- ci.c.orig 2008-04-11 21:20:00.000000000 +0300 +++ ci.c 2008-04-11 23:37:16.000000000 +0300 @@ -1625,6 +1625,7 @@ for (int i = 1; i <= MAX_CONNECTIONS_PER_CAM_SLOT; i++) { if (tc[i]) { if (!tc[i]->Process()) { + isyslog("CAM DEBUG: Reset calling i=%d, tc[i]=%d", i, tc[i]); //AK Reset(); return; } @@ -1681,16 +1682,20 @@
bool cCamSlot::Reset(void) { + isyslog("CAM DEBUG: Reset called"); //AK cMutexLock MutexLock(&mutex); ChannelCamRelations.Reset(slotNumber); DeleteAllConnections(); if (ciAdapter) { dbgprotocol("Slot %d: reset...", slotNumber); + isyslog("CAM DEBUG: Slot %d: reset...", slotNumber); //AK if (ciAdapter->Reset(slotIndex)) { resetTime = time(NULL); dbgprotocol("ok.\n"); + isyslog("CAM DEBUG: ok"); //AK return true; } + isyslog("CAM DEBUG: failed"); //AK dbgprotocol("failed!\n"); } return false; @@ -1700,11 +1705,15 @@ { cMutexLock MutexLock(&mutex); eModuleStatus ms = ciAdapter ? ciAdapter->ModuleStatus(slotIndex) : msNone; + isyslog("CAM DEBUG: ms: %d resetTime: %d", ms, resetTime); //AK if (resetTime) { if (ms <= msReset) { - if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) + isyslog("CAM DEBUG: ms le msReset"); //AK + if (time(NULL) - resetTime < MODULE_RESET_TIMEOUT) { + isyslog("CAM DEBUG: return msReset"); //AK return msReset; } + } resetTime = 0; } return ms;
Apr 11 23:40:31 akovdr2 vdr: [6914] cTimeMs: using monotonic clock (resolution is 4000250 ns) Apr 11 23:40:31 akovdr2 vdr: [6914] VDR version 1.6.0 started Apr 11 23:40:31 akovdr2 vdr: [6914] codeset is 'UTF-8' - known Apr 11 23:40:31 akovdr2 vdr: [6914] found 23 locales in /usr/local/src/vdr-1.6.0/locale Apr 11 23:40:31 akovdr2 vdr: [6914] loading plugin: /usr/local/vdr/PLUGINS/lib/libvdr-xine.so.1.6.0 Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/setup.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/sources.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/diseqc.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/channels.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/timers.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/svdrphosts.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/remote.conf Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/keymacros.conf Apr 11 23:40:31 akovdr2 vdr: [6915] video directory scanner thread started (pid=6914, tid=6915) Apr 11 23:40:31 akovdr2 vdr: [6915] video directory scanner thread ended (pid=6914, tid=6915) Apr 11 23:40:31 akovdr2 vdr: [6916] video directory scanner thread started (pid=6914, tid=6916) Apr 11 23:40:31 akovdr2 vdr: [6916] video directory scanner thread ended (pid=6914, tid=6916) Apr 11 23:40:31 akovdr2 vdr: [6914] reading EPG data from /usr/local/etc/vdr/epg.data Apr 11 23:40:31 akovdr2 vdr: [6914] probing /dev/dvb/adapter0/frontend0 Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: Reset called Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: Slot 1: reset... Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ok Apr 11 23:40:31 akovdr2 vdr: [6918] CI adapter on device 0 thread started (pid=6914, tid=6918) Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 1207946431 Apr 11 23:40:31 akovdr2 vdr: [6918] CAM 1: module present Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6919] tuner on device 1 thread started (pid=6914, tid=6919) Apr 11 23:40:31 akovdr2 vdr: [6920] section handler thread started (pid=6914, tid=6920) Apr 11 23:40:31 akovdr2 vdr: [6914] found 1 video device Apr 11 23:40:31 akovdr2 vdr: [6914] initializing plugin: xine (0.8.2): Software based playback using xine Apr 11 23:40:31 akovdr2 vdr: [6921] XineRemote control thread started (pid=6914, tid=6921) Apr 11 23:40:31 akovdr2 vdr: [6921] Entering cXineRemote thread Apr 11 23:40:31 akovdr2 vdr: [6914] setting primary device to 2 Apr 11 23:40:31 akovdr2 vdr: [6914] assuming manual start of VDR Apr 11 23:40:31 akovdr2 vdr: [6914] SVDRP listening on port 2001 Apr 11 23:40:31 akovdr2 vdr: [6914] setting current skin to "sttng" Apr 11 23:40:31 akovdr2 vdr: [6914] loading /usr/local/etc/vdr/themes/sttng-default.theme Apr 11 23:40:31 akovdr2 vdr: [6914] starting plugin: xine Apr 11 23:40:31 akovdr2 vdr: [6924] KBD remote control thread started (pid=6914, tid=6924) Apr 11 23:40:31 akovdr2 vdr: [6914] ERROR: remote control XineRemote not ready! Apr 11 23:40:31 akovdr2 vdr: [6914] remote control KBD - keys known Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:31 akovdr2 kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6918] CAM 1: module ready Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:31 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:32 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:33 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: Reset calling i=1, tc[i]=136770992 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: Reset called Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: Slot 1: reset... Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ok Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 1207946434 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM 1: module present Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:34 akovdr2 kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM 1: module ready Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:34 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:35 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:36 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: Reset calling i=1, tc[i]=136770992 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: Reset called Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: Slot 1: reset... Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ok Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 1207946437 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM 1: module present Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ms: 2 resetTime: 0 Apr 11 23:40:37 akovdr2 kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM 1: module ready Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6918] CAM DEBUG: ms: 3 resetTime: 0 Apr 11 23:40:37 akovdr2 vdr: [6914] CAM DEBUG: ms: 3 resetTime: 0
On 04/11/08 22:51, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
Since cCamSlot::Reset() is the only place where resetTime is set to a non-zero value, and you had lines like "resetTime1: 1207548401" in your syslog_1 file, apparently the tc[i]->Process() call in cCamSlot::Process() must have failed.
Yes, reset came from this procedure. I added some printouts (look at attached diff).
How to see reason why this Reset() is called?
The tc[i]->Process() call failed.
Further debug info could be gathered by adding output at the "return false" lines in cCiTransportConnection::Process().
Well, actually it's only one place there where false is returned, and that's when the "alive" timer times out, which is apparently after the 2 seconds between the resets you're observing, see
#define TC_ALIVE_TIMEOUT 2000
One possible test would be to increase this time and see whether this increases the distance between resets - or makes them go away at all.
Depending on the result of this test we'll see how to continue.
Klaus
Klaus Schmidinger wrote:
Well, actually it's only one place there where false is returned, and that's when the "alive" timer times out, which is apparently after the 2 seconds between the resets you're observing, see
#define TC_ALIVE_TIMEOUT 2000
One possible test would be to increase this time and see whether this increases the distance between resets - or makes them go away at all.
Depending on the result of this test we'll see how to continue.
Meanwhile I increased constant
MODULE_CHECK_INTERVAL to 300 ms
and now syslog looks much better.
Currently I have not display (ssh session only) and can't verify final result.
Is it possible that is OK now?
Arthur
Apr 12 00:00:03 akovdr2 vdr: [7372] cTimeMs: using monotonic clock (resolution is 4000250 ns) Apr 12 00:00:03 akovdr2 vdr: [7372] VDR version 1.6.0 started Apr 12 00:00:03 akovdr2 vdr: [7372] codeset is 'UTF-8' - known Apr 12 00:00:03 akovdr2 vdr: [7372] found 23 locales in /usr/local/src/vdr-1.6.0/locale Apr 12 00:00:03 akovdr2 vdr: [7372] loading plugin: /usr/local/vdr/PLUGINS/lib/libvdr-xine.so.1.6.0 Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/setup.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/sources.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/diseqc.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/channels.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/timers.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/svdrphosts.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/remote.conf Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/keymacros.conf Apr 12 00:00:03 akovdr2 vdr: [7373] video directory scanner thread started (pid=7372, tid=7373) Apr 12 00:00:03 akovdr2 vdr: [7373] video directory scanner thread ended (pid=7372, tid=7373) Apr 12 00:00:03 akovdr2 vdr: [7374] video directory scanner thread started (pid=7372, tid=7374) Apr 12 00:00:03 akovdr2 vdr: [7374] video directory scanner thread ended (pid=7372, tid=7374) Apr 12 00:00:03 akovdr2 vdr: [7372] reading EPG data from /usr/local/etc/vdr/epg.data Apr 12 00:00:03 akovdr2 vdr: [7372] probing /dev/dvb/adapter0/frontend0 Apr 12 00:00:03 akovdr2 vdr: [7372] CAM DEBUG: Reset called Apr 12 00:00:03 akovdr2 vdr: [7372] CAM DEBUG: Slot 1: reset... Apr 12 00:00:03 akovdr2 vdr: [7372] CAM DEBUG: ok Apr 12 00:00:03 akovdr2 vdr: [7376] CI adapter on device 0 thread started (pid=7372, tid=7376) Apr 12 00:00:03 akovdr2 vdr: [7376] CAM 1: module present Apr 12 00:00:03 akovdr2 vdr: [7377] tuner on device 1 thread started (pid=7372, tid=7377) Apr 12 00:00:03 akovdr2 vdr: [7378] section handler thread started (pid=7372, tid=7378) Apr 12 00:00:03 akovdr2 vdr: [7372] found 1 video device Apr 12 00:00:03 akovdr2 vdr: [7372] initializing plugin: xine (0.8.2): Software based playback using xine Apr 12 00:00:03 akovdr2 vdr: [7379] XineRemote control thread started (pid=7372, tid=7379) Apr 12 00:00:03 akovdr2 vdr: [7379] Entering cXineRemote thread Apr 12 00:00:03 akovdr2 vdr: [7372] setting primary device to 2 Apr 12 00:00:03 akovdr2 vdr: [7372] assuming manual start of VDR Apr 12 00:00:03 akovdr2 vdr: [7372] SVDRP listening on port 2001 Apr 12 00:00:03 akovdr2 vdr: [7372] setting current skin to "sttng" Apr 12 00:00:03 akovdr2 vdr: [7372] loading /usr/local/etc/vdr/themes/sttng-default.theme Apr 12 00:00:03 akovdr2 vdr: [7372] starting plugin: xine Apr 12 00:00:03 akovdr2 vdr: [7382] KBD remote control thread started (pid=7372, tid=7382) Apr 12 00:00:03 akovdr2 vdr: [7372] ERROR: remote control XineRemote not ready! Apr 12 00:00:03 akovdr2 vdr: [7372] remote control KBD - keys known Apr 12 00:00:03 akovdr2 kernel: dvb_ca adapter 0: DVB CAM detected and initialised successfully Apr 12 00:00:03 akovdr2 vdr: [7376] CAM 1: module ready Apr 12 00:00:05 akovdr2 vdr: [7376] CAM 1: TSD Crypt Conax, 01, 0000, 033D Apr 12 00:00:11 akovdr2 vdr: [7376] CAM 1: doesn't reply to QUERY - only a single channel can be decrypted Apr 12 00:00:11 akovdr2 vdr: [7372] setting watchdog timer to 30 seconds Apr 12 00:00:11 akovdr2 vdr: [7372] switching to channel 1 Apr 12 00:00:11 akovdr2 vdr: [7383] transfer thread started (pid=7372, tid=7383) Apr 12 00:00:11 akovdr2 vdr: [7384] receiver on device 1 thread started (pid=7372, tid=7384) Apr 12 00:00:11 akovdr2 vdr: [7385] TS buffer on device 1 thread started (pid=7372, tid=7385) Apr 12 00:00:17 akovdr2 vdr: [7372] max. latency time 1 seconds Apr 12 00:00:20 akovdr2 vdr: [7377] frontend 0 timed out while tuning to channel 1, tp 112187
Now I have next question/problem. From Technisat support I have the following answer:
Our CAM TechniCrypt CW is able to do multiple parallel decryptions since the software version 26.1.5.0.11
I have this firmware: Conax CA About 0. Quit menu 1. Software version: 26.1.5.0.11 2. Interface version: 0x40 3. Smart card number: 014 6900 0921 - 3 4. Number of sessions: 5 5. Language: 44 6. CA_SYS_ID: 0x0B00 SE
But line from syslog says:
CAM 1: doesn't reply to QUERY - only a single channel can be decrypted
Is it possible to verify is it true or is there misunderstanding somewhere?
Arthur
On 04/11/08 23:31, Arthur Konovalov wrote:
Now I have next question/problem.
Please start a new thread for a new topic ( I've at least changed the subject).
From Technisat support I have the following answer:
Our CAM TechniCrypt CW is able to do multiple parallel decryptions since the software version 26.1.5.0.11
I have this firmware: Conax CA About 0. Quit menu
- Software version: 26.1.5.0.11
- Interface version: 0x40
- Smart card number: 014 6900 0921 - 3
- Number of sessions: 5
- Language: 44
- CA_SYS_ID: 0x0B00
SE
But line from syslog says:
CAM 1: doesn't reply to QUERY - only a single channel can be decrypted
Is it possible to verify is it true or is there misunderstanding somewhere?
Please activate the DumpTPDUDataTransfer and DebugProtocol switches in ci.c and check whether VDR receives a reply to its QUERY.
Klaus
On 04/11/08 23:10, Arthur Konovalov wrote:
Klaus Schmidinger wrote:
Well, actually it's only one place there where false is returned, and that's when the "alive" timer times out, which is apparently after the 2 seconds between the resets you're observing, see
#define TC_ALIVE_TIMEOUT 2000
One possible test would be to increase this time and see whether this increases the distance between resets - or makes them go away at all.
Depending on the result of this test we'll see how to continue.
Meanwhile I increased constant
MODULE_CHECK_INTERVAL to 300 ms
and now syslog looks much better.
Currently I have not display (ssh session only) and can't verify final result.
Is it possible that is OK now?
What you're achieving with this longer timeout is that the module status is checked less often. If this leads to an improvement, I guess it means that getting the module status is somehow broken, because it really should be allowed to get te module status at any time (or does anybody know of some specs that say otherwise?).
This might be the reason why you don't have trouble with other apps, because maybe they don't check the module status (or at least not that often).
At any rate, if this really fixes the problem for you (please let us know whether it actually work in the long run) I guess it shouldn't be wrong to generally set this timeout to 300ms - or maybe even more? Like 1000ms or so?
Klaus
Klaus Schmidinger wrote:
Meanwhile I increased constant
MODULE_CHECK_INTERVAL to 300 ms
and now syslog looks much better.
At any rate, if this really fixes the problem for you (please let us know whether it actually work in the long run) I guess it shouldn't be wrong to generally set this timeout to 300ms - or maybe even more?
It seems stable with 300ms with my CAM, but for reliability reason I set it to 500ms.
Arthur
-
Arthur Konovalov -
Klaus Schmidinger -
Theunis Potgieter -
Tuomas Jormola