search

catalinii / minisatip

minisatip is an SATIP server for linux using local DVB-S2, DVB-C, DVB-T or ATSC cards
https://minisatip.org
328 stars 81 forks source link

Help with Kabelio CI+ Module required #910

Closed localhosthack0r closed 2 years ago

localhosthack0r commented 2 years ago

Hi all,

I recently bought a DD Flex CI extension and a Kabelio module and wanted to use this with minisatip, now. The module is recognized, but the channels do net get encrypted.

Module Info:

27/12 18:18:28.465 CA6: setting CI+ CAM data rate to 96 Mbps 27/12 18:18:29.020 CA6: RECV ciplus AI msg slot_id 0, session_num 2, resource_id 20043 tag 9f8021

27/12 18:18:29.020 CA6: Application type: 01 27/12 18:18:29.020 CA6: Application manufacturer: 4afc 27/12 18:18:29.020 CA6: Manufacturer code: 4afc 27/12 18:18:29.020 CA6: Menu string: KABELIO 1.0103 (129) [27/12 18:18:29.317 main]: Mutex init OK 0x562e63f164e8

Info from MMI menu, when tuning one of the subscribed channels: [27/12 18:18:39.794 CA6]: MMI menu from CAM in the slot 0: [27/12 18:18:39.794 CA6]: title: CI+ KABELIO CAM [27/12 18:18:39.794 CA6]: subtitle: Smartcard Nummer XXXXXXXXXX-X [27/12 18:18:39.794 CA6]: item 1: Keine Berechtigung f�r diesen Sender [27/12 18:18:39.794 CA6]: bottom: OK dr�cken zum fortzufahren [27/12 18:18:39.800 AD0]: writing 16920 bytes to DDCI device 6, fd 19, sock -1

"Keine Berechtigung f�r diesen Sender" is German, it means "No authorization for this channel."

The module needs to be activated, what I did/requested on the providers website. Not sure if the EMM was sent to the module, how can I check that? Can I ensure somehow that the EMM PID is sent to the module, any configuration data required? Ohter boards with Enigma receivers etc. say that the module might also require a firmware update, so I modified the ca.c in function ciplus_app_upgr_message() with setting const uint8_t answer = 0x01; // 0x00 - mean no upgrade, 0x01 - upgrade, 0x02 - ask user by mmi

Does somebody has experience with Kabelio and can help?

Full log attached: minisatip.log

Thank you!

catalinii commented 2 years ago

Probably the easiest way would be to try to upgrade the firmware in an enigma receiver and try after that. Minisatip does not support MMI interaction with the CAM so you may need to do it separately.

localhosthack0r commented 2 years ago

Thanks @catalinii for your answer. I had the fear that something like this could come. :)

Unfortunately I own no classical set-top-box, because there is no need for it with VDR, minisatip, AndroidTV,... :D

The only other DVB hardware I have is the TV in the livingroom, but no Coax cabel is going there, at the moment. I think about it, if it is possible to bring a Coax there, otherwise I'll sent the Kabelio module back.

Other ideas welcome!

localhosthack0r commented 2 years ago

Hi, I managed my cabel issue and was able to do the firmware update for the module at my TV. It's opening the channels at the TV. So the activation procedure has also worked. :-)

Now I put back the module to the DDCI. With minisatip, I have still black channel and the same message.

[28/12 10:43:24.601 CA6]: MMI menu from CAM in the slot 0: [28/12 10:43:24.602 CA6]: title: CI+ KABELIO CAM [28/12 10:43:24.602 CA6]: subtitle: Smartcard Nummer XXXXXXXXXX-X [28/12 10:43:24.602 CA6]: item 1: Keine Berechtigung f�r diesen Sender [28/12 10:43:24.602 CA6]: bottom: OK dr�cken zum fortzufahren

Full log is attached: minisatip.log

Further ideas?

Yuri666 commented 2 years ago

Your CAM is not initializing correctly. Have you installed ci+ certificates?

localhosthack0r commented 2 years ago

Yes, I downloaded the certificates from this issue: https://github.com/catalinii/minisatip/issues/898#issuecomment-939431428

I unpacked the files and placed them under /etc/ssl/certs

Is this right?

Yuri666 commented 2 years ago

Yes, it's right. Try to tune to channel immediately after start minisatip - some modern ci+ CAMs needs provider stream to initialize

localhosthack0r commented 2 years ago

I have tried to tune as fast as possible to a providers channel after start. That didn't change anything. VDR as client does a couple of other things as well, search for 11096 (frequency) in the log. There are the Kabelio channels.

minisatip.log

Yuri666 commented 2 years ago

yes, no difference with stream or without. CAM stop initialize after lang_country resource opening. in your log i don't see why it happening try to uncomment this line https://github.com/catalinii/minisatip/blob/master/src/ca.c#L318 and comment next one

localhosthack0r commented 2 years ago

Not sure if that changed something, picture still black. Log attached.

minisatip.log

Shall I also try CIPLUS_APP_CC_RESOURCEID_THREE and CIPLUS_APP_CC_RESOURCEID_MULTI?

Thanks for your support, @Yuri666!

Edit: Just tried it quickly, also with CIPLUS_APP_CC_RESOURCEID_THREE, or CIPLUS_APP_CC_RESOURCEID_MULTI no luck.

localhosthack0r commented 2 years ago

While reading the code in ca.c I see some comments mentioning CI+ version 1.3. On my CAM is a sticker with CI+ 1.4. Just in case the version is relevant,....

Yuri666 commented 2 years ago

I never seen 1.4 CAM before :) For 1.4 needs extended list mandatory resources to work, what not consist in this code. I can try to to implement it, but it will be not so easy - needs many testing

localhosthack0r commented 2 years ago

If it's unlikely to work in minisatip, I can sent the CAM back till end of January,... But of course if you implement something, I'd be happy to test!

localhosthack0r commented 2 years ago

I tried to find out a bit about the changes in version 1.4 with the specs at http://www.ci-plus.com/documentation/

Mandatory changes seem to be two things:

On the other hand in some forums the Kabelio CAM is reported to work with VU+, DM920,... so it must be possible somehow.

What do you think, @Yuri666 ?

Yuri666 commented 2 years ago

try this https://github.com/yuri666/minisatip no magic waiting, just to look to log

localhosthack0r commented 2 years ago

Thanks @Yuri666 !

Log, from your fork:

[29/12 09:15:16.814 main]: Setting diseqc adapter 5 fast 0 addr 0x10 committed_no 0 uncommitted_no 1 [29/12 09:15:16.814 main]: Calculating adapter sources: [0-5:0-4:0-4:0-5:5:5:5] [29/12 09:15:16.815 main]: Adapter correct sources format parameter [29/12 09:15:16.815 main]: Setting CA 6 pin to 4004 [29/12 09:15:16.815 main]: minisatip version 1.1.3, compiled in Dec 29 2021 09:14:23, with s2api version: 050A [29/12 09:15:16.815 main]: Built with dvbcsa [29/12 09:15:16.815 main]: Built with CI [29/12 09:15:16.815 main]: Built with dvbapi [29/12 09:15:16.815 main]: Built with AES (OpenSSL) [29/12 09:15:16.815 main]: Built with tables processing [29/12 09:15:16.815 main]: Built with pmt processing [29/12 09:15:16.815 main]: Built with satip client [29/12 09:15:16.815 main]: Built with linux dvb client [29/12 09:15:16.815 main]: Built with backtrace [29/12 09:15:16.815 main]: Built without netceiver [29/12 09:15:16.815 main]: Built with ddci [29/12 09:15:16.815 main]: Built without t2mi [29/12 09:15:16.815 main]: LOG of the module enabled: general [29/12 09:15:16.815 main]: LOG of the module enabled: ca [29/12 09:15:16.815 main]: New TCP listening socket 3 at 0:0:0:0:554, family 2 [29/12 09:15:16.815 main]: New TCP listening socket 4 at 0:0:0:0:8080, family 2 [29/12 09:15:16.815 main]: New UDP socket 5 bound to 0.0.0.0:1900 [29/12 09:15:16.815 main]: setting multicast for 239.255.255.250 [29/12 09:15:16.815 main]: New UDP socket 6 bound to 239.255.255.250:1900 (mcast:239.255.255.250) [29/12 09:15:16.815 main]: Mutex init OK 0x5623ad49ec40 [29/12 09:15:16.815 main]: Mutex init OK 0x5623adceca08 [29/12 09:15:16.815 main]: sockets_add: handle 5 (type 0) returning socket sock 0 [:0] read: 0x5623ad234baf [29/12 09:15:16.815 main]: Mutex init OK 0x5623adcecb68 [29/12 09:15:16.815 main]: sockets_add: handle 6 (type 0) returning socket sock 1 [:0] read: 0x5623ad234baf [29/12 09:15:16.815 main]: Mutex init OK 0x5623adceccc8 [29/12 09:15:16.815 main]: sockets_add: handle 3 (type 2) returning socket sock 2 [:0] read: 0x5623ad23499b [29/12 09:15:16.815 main]: Mutex init OK 0x5623adcece28 [29/12 09:15:16.815 main]: sockets_add: handle 4 (type 2) returning socket sock 3 [:0] read: 0x5623ad23499b [29/12 09:15:16.815 main]: Mutex init OK 0x5623adcecf88 [29/12 09:15:16.815 main]: sockets_add: handle -2 (type 0) returning socket sock 4 [:0] read: 0x5623ad234baf [29/12 09:15:16.815 main]: set_socket_thread: thread 7fbc56331700 for sockets 4 [29/12 09:15:16.815 main]: Mutex init OK 0x5623adcee1b8 [29/12 09:15:16.815 main]: sockets_add: handle -2 (type 0) returning socket sock 5 [:0] read: 0x5623ad234baf [29/12 09:15:16.815 main]: set_socket_thread: thread 7fbc56331700 for sockets 5 [29/12 09:15:16.815 main]: Mutex init OK 0x5623ad4a39e0 [29/12 09:15:16.815 main]: Mutex init OK 0x5623ad4a3a40 [29/12 09:15:16.816 signal]: Starting select_and_execute on thread ID 7fbc56331700, thread_name signal [29/12 09:15:16.816 main]: Mutex init OK 0x5623ad4c2bc0 [29/12 09:15:16.816 main]: Mutex init OK 0x5623adcee318 [29/12 09:15:16.816 main]: sockets_add: handle -2 (type 0) returning socket sock 6 [:0] read: 0x5623ad234baf [29/12 09:15:16.816 main]: Mutex init OK 0x5623ad4a0760 [29/12 09:15:16.816 main]: starting init_all_hw 0 [29/12 09:15:16.816 main]: Mutex init OK 0x5623ad49f100 [29/12 09:15:16.821 main]: /dev/dvb/adapter6/sec0 device found, this is a DDCI device [29/12 09:15:16.843 main]: Starting find_ddci_adapter with index 6 [29/12 09:15:16.844 main]: find_ddci_adapter: adding 6 0 to the list of devices [29/12 09:15:16.845 main]: Mutex init OK 0x5623ad4d7de0 [29/12 09:15:16.845 main]: Adding channel 104: DDCIs: 6 [29/12 09:15:16.845 main]: Adding channel 103: DDCIs: 6 [29/12 09:15:16.845 main]: Adding channel 100: DDCIs: 6 [29/12 09:15:16.845 main]: Loaded 3 channels from ddci.conf [29/12 09:15:16.860 main]: Mutex init OK 0x5623adcee478 [29/12 09:15:16.860 main]: trying to open [0] adapter 0 and frontend 0 [29/12 09:15:16.860 main]: opened DVB adapter 0 fe:7 dvr:8 [29/12 09:15:16.860 main]: DVR buffer set to 5775360 bytes [29/12 09:15:16.860 main]: deleting pids on adapter 0, sid -1, pids=NULL [29/12 09:15:16.878 main]: Detected adapter 0 handle 7 DVB Card Name: STV090x Multistandard [29/12 09:15:16.878 main]: Detected delivery system for adapter 0: dvbs [5] [29/12 09:15:16.878 main]: Detected delivery system for adapter 0: dvbs2 [6] [29/12 09:15:16.878 main]: Detected delivery system for adapter 0: dss [4] [29/12 09:15:16.878 main]: Mutex init OK 0x5623adcfa488 [29/12 09:15:16.878 main]: sockets_add: handle 8 (type 5) returning socket sock 7 [:0] read: 0x5623ad234b17 [29/12 09:15:16.878 main]: set_socket_thread: thread 7fbc55a78700 for sockets 7 [29/12 09:15:16.878 AD0]: Starting select_and_execute on thread ID 7fbc55a78700, thread_name AD0 [29/12 09:15:16.879 main]: No CA device detected on adapter 0: file /dev/dvb/adapter0/ca0 [29/12 09:15:16.879 main]: done opening adapter 0 delivery systems: dvbs dvbs2 dss undefined [29/12 09:15:16.879 main]: FE 1 mapped to Adapter 0, sys dvbs2 [29/12 09:15:16.879 main]: Mutex init OK 0x5623adcf02e8 [29/12 09:15:16.879 main]: trying to open [1] adapter 1 and frontend 0 [29/12 09:15:16.879 main]: opened DVB adapter 1 fe:9 dvr:10 [29/12 09:15:16.879 main]: DVR buffer set to 5775360 bytes [29/12 09:15:16.879 main]: deleting pids on adapter 1, sid -1, pids=NULL [29/12 09:15:16.897 main]: Detected adapter 1 handle 9 DVB Card Name: STV090x Multistandard [29/12 09:15:16.897 main]: Detected delivery system for adapter 1: dvbs [5] [29/12 09:15:16.897 main]: Detected delivery system for adapter 1: dvbs2 [6] [29/12 09:15:16.897 main]: Detected delivery system for adapter 1: dss [4] [29/12 09:15:16.897 main]: Mutex init OK 0x5623adcfa718 [29/12 09:15:16.897 main]: sockets_add: handle 10 (type 5) returning socket sock 8 [:0] read: 0x5623ad234b17 [29/12 09:15:16.897 main]: set_socket_thread: thread 7fbc55277700 for sockets 8 [29/12 09:15:16.897 main]: No CA device detected on adapter 1: file /dev/dvb/adapter1/ca0 [29/12 09:15:16.897 main]: done opening adapter 1 delivery systems: dvbs dvbs2 dss undefined [29/12 09:15:16.897 main]: FE 1 mapped to Adapter 0, sys dvbs2 [29/12 09:15:16.897 main]: FE 2 mapped to Adapter 1, sys dvbs2 [29/12 09:15:16.897 AD1]: Starting select_and_execute on thread ID 7fbc55277700, thread_name AD1 [29/12 09:15:16.897 main]: Mutex init OK 0x5623adcf2158 [29/12 09:15:16.897 main]: trying to open [2] adapter 2 and frontend 0 [29/12 09:15:16.897 main]: opened DVB adapter 2 fe:11 dvr:12 [29/12 09:15:16.897 main]: DVR buffer set to 5775360 bytes [29/12 09:15:16.897 main]: deleting pids on adapter 2, sid -1, pids=NULL [29/12 09:15:16.914 main]: Detected adapter 2 handle 11 DVB Card Name: Sony CXD2843ER DVB-T/T2/C/C2 demodulator [29/12 09:15:16.915 main]: Detected delivery system for adapter 2: dvbt [3] [29/12 09:15:16.915 main]: Detected delivery system for adapter 2: dvbt2 [16] [29/12 09:15:16.915 main]: Detected delivery system for adapter 2: dvbc [1] [29/12 09:15:16.915 main]: Mutex init OK 0x5623adcfa9a8 [29/12 09:15:16.915 main]: sockets_add: handle 12 (type 5) returning socket sock 9 [:0] read: 0x5623ad234b17 [29/12 09:15:16.915 main]: set_socket_thread: thread 7fbc54a76700 for sockets 9 [29/12 09:15:16.915 main]: No CA device detected on adapter 2: file /dev/dvb/adapter2/ca0 [29/12 09:15:16.915 main]: done opening adapter 2 delivery systems: dvbt dvbt2 dvbc undefined [29/12 09:15:16.915 AD2]: Starting select_and_execute on thread ID 7fbc54a76700, thread_name AD2 [29/12 09:15:16.915 main]: FE 1 mapped to Adapter 0, sys dvbs2 [29/12 09:15:16.915 main]: FE 2 mapped to Adapter 1, sys dvbs2 [29/12 09:15:16.915 main]: FE 3 mapped to Adapter 2, sys dvbc [29/12 09:15:16.915 main]: FE 4 mapped to Adapter 2, sys dvbt2 [29/12 09:15:16.915 main]: Mutex init OK 0x5623adcf3fc8 [29/12 09:15:16.915 main]: trying to open [3] adapter 3 and frontend 0 [29/12 09:15:16.915 main]: opened DVB adapter 3 fe:13 dvr:14 [29/12 09:15:16.916 main]: DVR buffer set to 5775360 bytes [29/12 09:15:16.916 main]: deleting pids on adapter 3, sid -1, pids=NULL [29/12 09:15:16.934 main]: Detected adapter 3 handle 13 DVB Card Name: Sony CXD2843ER DVB-T/T2/C/C2 demodulator [29/12 09:15:16.934 main]: Detected delivery system for adapter 3: dvbt [3] [29/12 09:15:16.934 main]: Detected delivery system for adapter 3: dvbt2 [16] [29/12 09:15:16.934 main]: Detected delivery system for adapter 3: dvbc [1] [29/12 09:15:16.934 main]: Mutex init OK 0x5623adcfac38 [29/12 09:15:16.934 main]: sockets_add: handle 14 (type 5) returning socket sock 10 [:0] read: 0x5623ad234b17 [29/12 09:15:16.934 main]: set_socket_thread: thread 7fbc47fff700 for sockets 10 [29/12 09:15:16.934 main]: No CA device detected on adapter 3: file /dev/dvb/adapter3/ca0 [29/12 09:15:16.934 main]: done opening adapter 3 delivery systems: dvbt dvbt2 dvbc undefined [29/12 09:15:16.934 main]: FE 1 mapped to Adapter 0, sys dvbs2 [29/12 09:15:16.934 main]: FE 2 mapped to Adapter 1, sys dvbs2 [29/12 09:15:16.934 main]: FE 3 mapped to Adapter 2, sys dvbc [29/12 09:15:16.934 main]: FE 4 mapped to Adapter 3, sys dvbc [29/12 09:15:16.934 main]: FE 5 mapped to Adapter 2, sys dvbt2 [29/12 09:15:16.934 main]: FE 6 mapped to Adapter 3, sys dvbt2 [29/12 09:15:16.934 AD3]: Starting select_and_execute on thread ID 7fbc47fff700, thread_name AD3 [29/12 09:15:16.935 main]: Mutex init OK 0x5623adcf5e38 [29/12 09:15:16.935 main]: trying to open [4] adapter 4 and frontend 0 [29/12 09:15:16.935 main]: opened DVB adapter 4 fe:15 dvr:16 [29/12 09:15:16.936 main]: DVR buffer set to 5775360 bytes [29/12 09:15:16.936 main]: deleting pids on adapter 4, sid -1, pids=NULL [29/12 09:15:16.955 main]: Detected adapter 4 handle 15 DVB Card Name: STV090x Multistandard [29/12 09:15:16.955 main]: Detected delivery system for adapter 4: dvbs [5] [29/12 09:15:16.955 main]: Detected delivery system for adapter 4: dvbs2 [6] [29/12 09:15:16.955 main]: Detected delivery system for adapter 4: dss [4] [29/12 09:15:16.955 main]: Mutex init OK 0x5623adcfaec8 [29/12 09:15:16.955 main]: sockets_add: handle 16 (type 5) returning socket sock 11 [:0] read: 0x5623ad234b17 [29/12 09:15:16.955 main]: set_socket_thread: thread 7fbc477fe700 for sockets 11 [29/12 09:15:16.956 main]: No CA device detected on adapter 4: file /dev/dvb/adapter4/ca0 [29/12 09:15:16.956 main]: done opening adapter 4 delivery systems: dvbs dvbs2 dss undefined [29/12 09:15:16.956 main]: FE 1 mapped to Adapter 0, sys dvbs2 [29/12 09:15:16.956 main]: FE 2 mapped to Adapter 1, sys dvbs2 [29/12 09:15:16.956 main]: FE 3 mapped to Adapter 4, sys dvbs2 [29/12 09:15:16.956 main]: FE 4 mapped to Adapter 2, sys dvbc [29/12 09:15:16.956 main]: FE 5 mapped to Adapter 3, sys dvbc [29/12 09:15:16.956 main]: FE 6 mapped to Adapter 2, sys dvbt2 [29/12 09:15:16.956 main]: FE 7 mapped to Adapter 3, sys dvbt2 [29/12 09:15:16.956 AD4]: Starting select_and_execute on thread ID 7fbc477fe700, thread_name AD4 [29/12 09:15:16.956 main]: Mutex init OK 0x5623adcea268 [29/12 09:15:16.956 main]: trying to open [5] adapter 5 and frontend 0 [29/12 09:15:16.956 main]: opened DVB adapter 5 fe:17 dvr:18 [29/12 09:15:16.957 main]: DVR buffer set to 5775360 bytes [29/12 09:15:16.957 main]: deleting pids on adapter 5, sid -1, pids=NULL [29/12 09:15:16.977 main]: Detected adapter 5 handle 17 DVB Card Name: STV090x Multistandard [29/12 09:15:16.977 main]: Detected delivery system for adapter 5: dvbs [5] [29/12 09:15:16.977 main]: Detected delivery system for adapter 5: dvbs2 [6] [29/12 09:15:16.977 main]: Detected delivery system for adapter 5: dss [4] [29/12 09:15:16.977 main]: Mutex init OK 0x5623adcfb158 [29/12 09:15:16.977 main]: sockets_add: handle 18 (type 5) returning socket sock 12 [:0] read: 0x5623ad234b17 [29/12 09:15:16.977 main]: set_socket_thread: thread 7fbc46ffd700 for sockets 12 [29/12 09:15:16.977 main]: No CA device detected on adapter 5: file /dev/dvb/adapter5/ca0 [29/12 09:15:16.977 main]: done opening adapter 5 delivery systems: dvbs dvbs2 dss undefined [29/12 09:15:16.977 main]: FE 1 mapped to Adapter 0, sys dvbs2 [29/12 09:15:16.977 main]: FE 2 mapped to Adapter 1, sys dvbs2 [29/12 09:15:16.977 main]: FE 3 mapped to Adapter 4, sys dvbs2 [29/12 09:15:16.977 main]: FE 4 mapped to Adapter 5, sys dvbs2 [29/12 09:15:16.977 main]: FE 5 mapped to Adapter 2, sys dvbc [29/12 09:15:16.977 main]: FE 6 mapped to Adapter 3, sys dvbc [29/12 09:15:16.977 main]: FE 7 mapped to Adapter 2, sys dvbt2 [29/12 09:15:16.977 main]: FE 8 mapped to Adapter 3, sys dvbt2 [29/12 09:15:16.977 AD5]: Starting select_and_execute on thread ID 7fbc46ffd700, thread_name AD5 [29/12 09:15:16.977 main]: Mutex init OK 0x5623adcf7ca8 [29/12 09:15:16.995 main]: Mutex init OK 0x5623adcfc1b0 [29/12 09:15:16.996 main]: Mutex init OK 0x5623adcfc418 [29/12 09:15:16.996 main]: DDCI opening [6] adapter 6 and frontend 0 [29/12 09:15:16.996 main]: opened DDCI adapter 6 fe:19 dvr:20 [29/12 09:15:16.996 main]: deleting pids on adapter 6, sid -1, pids=NULL [29/12 09:15:16.996 main]: Mutex init OK 0x5623adcfcdf8 [29/12 09:15:16.996 main]: sockets_add: handle 20 (type 5) returning socket sock 13 [:0] read: 0x5623ad234b17 [29/12 09:15:16.996 main]: set_socket_thread: thread 7fbc4560e700 for sockets 13 [29/12 09:15:16.996 AD6]: Starting select_and_execute on thread ID 7fbc4560e700, thread_name AD6 [29/12 09:15:18.636 main]: initializing CA, fd 21 type 2 flags 0x3, after 1639 ms [29/12 09:15:18.636 main]: slotid: 0 [29/12 09:15:18.636 main]: tcid: 1 [29/12 09:15:18.636 CA6]: stackthread_func: start [29/12 09:15:18.636 main]: Adding pid 0 to the list of pids as not explicitly added for adapter 6 [29/12 09:15:18.636 main]: Mutex init OK 0x5623ad4a2c20 [29/12 09:15:18.636 main]: Mutex init OK 0x5623add06668 [29/12 09:15:18.636 main]: new filter 0 added for adapter 6, pid 0, flags 20, mask_len 0, master_filter 0 [29/12 09:15:18.636 main]: Mutex init OK 0x5623add076d8 [29/12 09:15:18.636 main]: new filter 1 added for adapter 6, pid 17, flags 20, mask_len 0, master_filter 1 [29/12 09:15:18.636 main]: Registered DDCI CA 1 [29/12 09:15:18.636 main]: done opening adapter 6 delivery systems: undefined undefined undefined undefined [29/12 09:15:18.636 main]: done init_hw 1 [29/12 09:15:18.636 main]: Initializing with 7 devices [29/12 09:15:18.636 main]: Starting select_and_execute on thread ID 7fbc57c74f00, thread_name main [29/12 09:15:18.854 CA6]: ca_session_callback: reason 6 slot_id 0 session_number 1 resource_id 0 [29/12 09:15:18.854 CA6]: 00:Host originated transport connection 0 resource 0x00000001 connected 29/12 09:15:19.082 CA6: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 10041 29/12 09:15:19.082 CA6: ca_session_callback: reason 0 slot_id 0 session_number 1 resource_id 10041 29/12 09:15:19.082 CA6: 00:CAM connecting to resource 00010041, session_number 1 29/12 09:15:19.082 CA6: ca_session_callback: reason 1 slot_id 0 session_number 1 resource_id 10041 29/12 09:15:19.082 CA6: 00:CAM successfully connected to resource 00010041, session_number 1

[29/12 09:15:20.071 CA6]: 00:ca_rm_reply_callback resource_count 0 [29/12 09:15:21.164 CA6]: 00:ca_rm_enq_callback resource_count 13 CI+ MODE [29/12 09:15:22.282 CA6]: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 20045 [29/12 09:15:22.282 CA6]: !!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!!! lookup callback for unknown resource id 20045 on slot 0 [29/12 09:15:22.282 CA6]: ca_session_callback: reason 0 slot_id 0 session_number 2 resource_id 20045 [29/12 09:15:22.282 CA6]: 00:CAM connecting to resource 00020045, session_number 2 [29/12 09:15:22.282 CA6]: ca_session_callback: reason 1 slot_id 0 session_number 2 resource_id 20045 [29/12 09:15:22.282 CA6]: 00:CAM successfully connected to resource 00020045, session_number 2 29/12 09:15:24.700 CA6: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 30041 29/12 09:15:24.700 CA6: ca_session_callback: reason 0 slot_id 0 session_number 3 resource_id 30041 29/12 09:15:24.700 CA6: 00:CAM connecting to resource 00030041, session_number 3 29/12 09:15:24.700 CA6: ca_session_callback: reason 1 slot_id 0 session_number 3 resource_id 30041 29/12 09:15:24.700 CA6: 00:CAM successfully connected to resource 00030041, session_number 3

[29/12 09:15:25.577 CA6]: Supported CA ID: 4afc for CA6 [29/12 09:15:25.577 CA6]: CA 0 can handle CAID 4AFC mask FFFF on adapter 6 at position 0 [29/12 09:15:26.671 CA6]: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 240041 [29/12 09:15:26.671 CA6]: ca_session_callback: reason 0 slot_id 0 session_number 4 resource_id 240041 [29/12 09:15:26.671 CA6]: 00:CAM connecting to resource 00240041, session_number 4 [29/12 09:15:26.671 CA6]: ca_session_callback: reason 1 slot_id 0 session_number 4 resource_id 240041 [29/12 09:15:26.671 CA6]: 00:CAM successfully connected to resource 00240041, session_number 4

[29/12 09:15:28.866 CA6]: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 8d1001 [29/12 09:15:28.866 CA6]: ca_session_callback: reason 0 slot_id 0 session_number 5 resource_id 8d1001 [29/12 09:15:28.866 CA6]: 00:CAM connecting to resource 008d1001, session_number 5 [29/12 09:15:28.866 CA6]: ca_session_callback: reason 1 slot_id 0 session_number 5 resource_id 8d1001 [29/12 09:15:28.866 CA6]: 00:CAM successfully connected to resource 008d1001, session_number 5 29/12 09:15:31.279 CA6: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 961001 29/12 09:15:31.279 CA6: ca_session_callback: reason 0 slot_id 0 session_number 6 resource_id 961001 29/12 09:15:31.279 CA6: 00:CAM connecting to resource 00961001, session_number 6 29/12 09:15:31.279 CA6: ca_session_callback: reason 1 slot_id 0 session_number 6 resource_id 961001 29/12 09:15:31.279 CA6: 00:CAM successfully connected to resource 00961001, session_number 6

29/12 09:15:32.168 CA6: CI+ CA6 0x09 0x69 0x74 0x64 0x74 0x74 0x63 0x61 0x00 0x01 [29/12 09:15:46.938 AD0]: Requested adapter 0 close due to timeout 30 sec, result 1 max_rtime 2123 [29/12 09:15:46.938 AD0]: closing DVR socket 8 pos 7 aid 0 [29/12 09:15:46.938 AD0]: closing adapter 0 -> fe:7 dvr:8, sock:7, fe_sock:-1 [29/12 09:15:46.938 AD0]: deleting pids on adapter 0, sid -1, pids=NULL [29/12 09:15:46.938 AD0]: Destroying mutex 0x5623adcee478 [29/12 09:15:46.938 AD0]: done closing adapter 0 [29/12 09:15:46.938 AD0]: sockets_del: sock 7 -> handle 8, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:15:46.939 AD0]: sockets_del: sock 7 Last open socket is at index 13 current_handle 8 [29/12 09:15:46.939 AD0]: Destroying mutex 0x5623adcfa488 [29/12 09:15:46.959 AD1]: Requested adapter 1 close due to timeout 30 sec, result 1 max_rtime 2143 [29/12 09:15:46.959 AD1]: closing DVR socket 10 pos 8 aid 1 [29/12 09:15:46.959 AD1]: closing adapter 1 -> fe:9 dvr:10, sock:8, fe_sock:-1 [29/12 09:15:46.959 AD1]: deleting pids on adapter 1, sid -1, pids=NULL [29/12 09:15:46.959 AD1]: Destroying mutex 0x5623adcf02e8 [29/12 09:15:46.959 AD1]: done closing adapter 1 [29/12 09:15:46.959 AD1]: sockets_del: sock 8 -> handle 10, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:15:46.959 AD1]: sockets_del: sock 8 Last open socket is at index 13 current_handle 10 [29/12 09:15:46.959 AD1]: Destroying mutex 0x5623adcfa718 [29/12 09:15:46.976 AD2]: Requested adapter 2 close due to timeout 30 sec, result 1 max_rtime 2160 [29/12 09:15:46.976 AD2]: closing DVR socket 12 pos 9 aid 2 [29/12 09:15:46.976 AD2]: closing adapter 2 -> fe:11 dvr:12, sock:9, fe_sock:-1 [29/12 09:15:46.976 AD2]: deleting pids on adapter 2, sid -1, pids=NULL [29/12 09:15:46.976 AD2]: Destroying mutex 0x5623adcf2158 [29/12 09:15:46.976 AD2]: done closing adapter 2 [29/12 09:15:46.976 AD2]: sockets_del: sock 9 -> handle 12, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:15:46.976 AD2]: sockets_del: sock 9 Last open socket is at index 13 current_handle 12 [29/12 09:15:46.976 AD2]: Destroying mutex 0x5623adcfa9a8 [29/12 09:15:46.996 AD3]: Requested adapter 3 close due to timeout 30 sec, result 1 max_rtime 2181 [29/12 09:15:46.996 AD3]: closing DVR socket 14 pos 10 aid 3 [29/12 09:15:46.996 AD3]: closing adapter 3 -> fe:13 dvr:14, sock:10, fe_sock:-1 [29/12 09:15:46.996 AD3]: deleting pids on adapter 3, sid -1, pids=NULL [29/12 09:15:46.996 AD3]: Destroying mutex 0x5623adcf3fc8 [29/12 09:15:46.996 AD3]: done closing adapter 3 [29/12 09:15:46.996 AD3]: sockets_del: sock 10 -> handle 14, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:15:46.996 AD3]: sockets_del: sock 10 Last open socket is at index 13 current_handle 14 [29/12 09:15:46.996 AD3]: Destroying mutex 0x5623adcfac38 [29/12 09:15:47.018 AD4]: Requested adapter 4 close due to timeout 30 sec, result 1 max_rtime 2203 [29/12 09:15:47.018 AD4]: closing DVR socket 16 pos 11 aid 4 [29/12 09:15:47.018 AD4]: closing adapter 4 -> fe:15 dvr:16, sock:11, fe_sock:-1 [29/12 09:15:47.018 AD4]: deleting pids on adapter 4, sid -1, pids=NULL [29/12 09:15:47.018 AD4]: Destroying mutex 0x5623adcf5e38 [29/12 09:15:47.018 AD4]: done closing adapter 4 [29/12 09:15:47.018 AD4]: sockets_del: sock 11 -> handle 16, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:15:47.018 AD4]: sockets_del: sock 11 Last open socket is at index 13 current_handle 16 [29/12 09:15:47.018 AD4]: Destroying mutex 0x5623adcfaec8 [29/12 09:15:47.038 AD5]: Requested adapter 5 close due to timeout 30 sec, result 1 max_rtime 2223 [29/12 09:15:47.038 AD5]: closing DVR socket 18 pos 12 aid 5 [29/12 09:15:47.038 AD5]: closing adapter 5 -> fe:17 dvr:18, sock:12, fe_sock:-1 [29/12 09:15:47.038 AD5]: deleting pids on adapter 5, sid -1, pids=NULL [29/12 09:15:47.039 AD5]: Destroying mutex 0x5623adcea268 [29/12 09:15:47.039 AD5]: done closing adapter 5 [29/12 09:15:47.039 AD5]: sockets_del: sock 12 -> handle 18, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:15:47.039 AD0]: No enabled sockets for Thread ID 7fbc55a78700 name AD0 ... exiting [29/12 09:15:47.039 AD0]: Mutex init OK 0x5623ad49fae0 [29/12 09:15:47.039 AD0]: add_join_thread: pthread 7fbc55a78700 [29/12 09:15:47.039 AD5]: sockets_del: sock 12 Last open socket is at index 13 current_handle 18 [29/12 09:15:47.039 AD5]: Destroying mutex 0x5623adcfb158 [29/12 09:15:47.059 AD1]: No enabled sockets for Thread ID 7fbc55277700 name AD1 ... exiting [29/12 09:15:47.059 AD1]: add_join_thread: pthread 7fbc55277700 [29/12 09:15:47.076 AD2]: No enabled sockets for Thread ID 7fbc54a76700 name AD2 ... exiting [29/12 09:15:47.077 AD2]: add_join_thread: pthread 7fbc54a76700 [29/12 09:15:47.097 AD3]: No enabled sockets for Thread ID 7fbc47fff700 name AD3 ... exiting [29/12 09:15:47.097 AD3]: add_join_thread: pthread 7fbc47fff700 [29/12 09:15:47.118 AD4]: No enabled sockets for Thread ID 7fbc477fe700 name AD4 ... exiting [29/12 09:15:47.119 AD4]: add_join_thread: pthread 7fbc477fe700 [29/12 09:15:47.140 AD5]: No enabled sockets for Thread ID 7fbc46ffd700 name AD5 ... exiting [29/12 09:15:47.140 AD5]: add_join_thread: pthread 7fbc46ffd700 [29/12 09:16:10.126 main]: Mutex init OK 0x5623adcfa488 [29/12 09:16:10.126 main]: sockets_add: handle 7 (type 1) returning socket sock 7 [192.168.178.20:46210] read: 0x5623ad234b17 [29/12 09:16:10.126 main]: Mutex init OK 0x5623adcfa718 [29/12 09:16:10.126 main]: sockets_add: handle 8 (type 1) returning socket sock 8 [192.168.178.20:46212] read: 0x5623ad234b17 [29/12 09:16:10.612 main]: Read HTTP (handle -1) [192.168.178.20:46210] sid -1, sock 7 [29/12 09:16:10.612 main]: opened /home/andre/minisatip/html///status.html fd 9 at 0x7fbc57c7e000 - 14655 bytes [29/12 09:16:10.612 main]: processing_file 0x7fbc57c7e000 len 14655: [29/12 09:16:10.612 main]: Reply (handle 7) [192.168.178.20:46210] content_len:0, sock 7 [29/12 09:16:10.713 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:10.713 main]: Requested sid close -1 timeout -1 type -1, sock 7, handle 7, timeout 1 [29/12 09:16:10.713 main]: closing stream sid -1 [29/12 09:16:10.713 main]: sockets_del: sock 7 -> handle 7, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:10.713 main]: sockets_del: sock 7 Last open socket is at index 13 current_handle 7 [29/12 09:16:10.713 main]: Destroying mutex 0x5623adcfa488 [29/12 09:16:10.761 main]: Read HTTP (handle -1) [192.168.178.20:46212] sid -1, sock 8 [29/12 09:16:10.762 main]: opened /home/andre/minisatip/html///jquery.dataTables.min.css fd 7 at 0x7fbc57c7e000 - 13565 bytes [29/12 09:16:10.762 main]: Reply (handle 8) [192.168.178.20:46212] content_len:13565, sock 8 [29/12 09:16:10.776 main]: select_and_execute[8]: Close on socket 8 (sid:-1) from 192.168.178.20:46212 - type http (3) errno 0 [29/12 09:16:10.776 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:10.776 main]: Requested sid close -1 timeout -1 type -1, sock 8, handle 8, timeout 1 [29/12 09:16:10.776 main]: closing stream sid -1 [29/12 09:16:10.776 main]: sockets_del: sock 8 -> handle 8, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:10.776 main]: sockets_del: sock 8 Last open socket is at index 13 current_handle 8 [29/12 09:16:10.776 main]: Destroying mutex 0x5623adcfa718 [29/12 09:16:10.776 main]: Delete socket 8 done: sid -1 [29/12 09:16:10.778 main]: Mutex init OK 0x5623adcfa488 [29/12 09:16:10.778 main]: sockets_add: handle 7 (type 1) returning socket sock 7 [192.168.178.20:46216] read: 0x5623ad234b17 [29/12 09:16:10.778 main]: Mutex init OK 0x5623adcfa718 [29/12 09:16:10.778 main]: sockets_add: handle 8 (type 1) returning socket sock 8 [192.168.178.20:46214] read: 0x5623ad234b17 [29/12 09:16:10.779 main]: Read HTTP (handle -1) [192.168.178.20:46216] sid -1, sock 7 [29/12 09:16:10.779 main]: opened /home/andre/minisatip/html///jquery-3.2.1.min.js fd 9 at 0x7fbc57a92000 - 86659 bytes [29/12 09:16:10.779 main]: Reply (handle 7) [192.168.178.20:46216] content_len:86659, sock 7 [29/12 09:16:10.779 main]: Mutex init OK 0x5623adcfa9a8 [29/12 09:16:10.779 main]: sockets_add: handle 9 (type 1) returning socket sock 9 [192.168.178.20:46218] read: 0x5623ad234b17 [29/12 09:16:10.780 main]: Read HTTP (handle -1) [192.168.178.20:46214] sid -1, sock 8 [29/12 09:16:10.780 main]: opened /home/andre/minisatip/html///jquery.dataTables.min.js fd 10 at 0x7fbc57a93000 - 82480 bytes [29/12 09:16:10.780 main]: Reply (handle 8) [192.168.178.20:46214] content_len:82480, sock 8 [29/12 09:16:10.784 main]: Read HTTP (handle -1) [192.168.178.20:46218] sid -1, sock 9 [29/12 09:16:10.784 main]: opened /home/andre/minisatip/html///jquery.pBar.min.js fd 10 at 0x7fbc57c81000 - 782 bytes [29/12 09:16:10.784 main]: Reply (handle 9) [192.168.178.20:46218] content_len:782, sock 9 [29/12 09:16:10.791 main]: select_and_execute[9]: Close on socket 9 (sid:-1) from 192.168.178.20:46218 - type http (3) errno 0 [29/12 09:16:10.791 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:10.791 main]: Requested sid close -1 timeout -1 type -1, sock 9, handle 9, timeout 1 [29/12 09:16:10.791 main]: closing stream sid -1 [29/12 09:16:10.791 main]: sockets_del: sock 9 -> handle 9, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:10.791 main]: sockets_del: sock 9 Last open socket is at index 13 current_handle 9 [29/12 09:16:10.792 main]: Destroying mutex 0x5623adcfa9a8 [29/12 09:16:10.792 main]: Delete socket 9 done: sid -1 [29/12 09:16:10.798 main]: select_and_execute[8]: Close on socket 8 (sid:-1) from 192.168.178.20:46214 - type http (3) errno 0 [29/12 09:16:10.799 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:10.799 main]: Requested sid close -1 timeout -1 type -1, sock 8, handle 8, timeout 1 [29/12 09:16:10.799 main]: closing stream sid -1 [29/12 09:16:10.799 main]: sockets_del: sock 8 -> handle 8, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:10.799 main]: sockets_del: sock 8 Last open socket is at index 13 current_handle 8 [29/12 09:16:10.799 main]: Destroying mutex 0x5623adcfa718 [29/12 09:16:10.799 main]: Delete socket 8 done: sid -1 [29/12 09:16:10.799 main]: select_and_execute[7]: Close on socket 7 (sid:-1) from 192.168.178.20:46216 - type http (3) errno 0 [29/12 09:16:10.799 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:10.799 main]: Requested sid close -1 timeout -1 type -1, sock 7, handle 7, timeout 1 [29/12 09:16:10.799 main]: closing stream sid -1 [29/12 09:16:10.799 main]: sockets_del: sock 7 -> handle 7, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:10.799 main]: sockets_del: sock 7 Last open socket is at index 13 current_handle 7 [29/12 09:16:10.799 main]: Destroying mutex 0x5623adcfa488 [29/12 09:16:10.799 main]: Delete socket 7 done: sid -1 [29/12 09:16:10.928 signal]: Mutex init OK 0x5623ad49ecc0 [29/12 09:16:10.928 signal]: BW 194KB/s, Total BW: 0 MB, ns/read 0, r: 1, w: 7 fw: 0, tt: 0 ms [29/12 09:16:10.969 main]: Mutex init OK 0x5623adcfa488 [29/12 09:16:10.969 main]: sockets_add: handle 7 (type 1) returning socket sock 7 [192.168.178.20:46220] read: 0x5623ad234b17 [29/12 09:16:10.969 main]: Read HTTP (handle -1) [192.168.178.20:46220] sid -1, sock 7 [29/12 09:16:10.972 main]: Reply (handle 7) [192.168.178.20:46220] content_len:16566, sock 7 [29/12 09:16:10.978 main]: select_and_execute[7]: Close on socket 7 (sid:-1) from 192.168.178.20:46220 - type http (3) errno 0 [29/12 09:16:10.978 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:10.978 main]: Requested sid close -1 timeout -1 type -1, sock 7, handle 7, timeout 1 [29/12 09:16:10.978 main]: closing stream sid -1 [29/12 09:16:10.978 main]: sockets_del: sock 7 -> handle 7, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:10.978 main]: sockets_del: sock 7 Last open socket is at index 13 current_handle 7 [29/12 09:16:10.978 main]: Destroying mutex 0x5623adcfa488 [29/12 09:16:10.978 main]: Delete socket 7 done: sid -1 [29/12 09:16:11.066 main]: Mutex init OK 0x5623adcfa488 [29/12 09:16:11.066 main]: sockets_add: handle 7 (type 1) returning socket sock 7 [192.168.178.20:46222] read: 0x5623ad234b17 [29/12 09:16:11.067 main]: Read HTTP (handle -1) [192.168.178.20:46222] sid -1, sock 7 [29/12 09:16:11.067 main]: opened /home/andre/minisatip/html///sort_both.png fd 8 at 0x7fbc57c81000 - 201 bytes [29/12 09:16:11.067 main]: Reply (handle 7) [192.168.178.20:46222] content_len:201, sock 7 [29/12 09:16:11.072 main]: select_and_execute[7]: Close on socket 7 (sid:-1) from 192.168.178.20:46222 - type http (3) errno 0 [29/12 09:16:11.072 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:11.072 main]: Requested sid close -1 timeout -1 type -1, sock 7, handle 7, timeout 1 [29/12 09:16:11.072 main]: closing stream sid -1 [29/12 09:16:11.072 main]: sockets_del: sock 7 -> handle 7, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:11.073 main]: sockets_del: sock 7 Last open socket is at index 13 current_handle 7 [29/12 09:16:11.073 main]: Destroying mutex 0x5623adcfa488 [29/12 09:16:11.073 main]: Delete socket 7 done: sid -1 [29/12 09:16:11.084 main]: Mutex init OK 0x5623adcfa488 [29/12 09:16:11.084 main]: sockets_add: handle 7 (type 1) returning socket sock 7 [192.168.178.20:46224] read: 0x5623ad234b17 [29/12 09:16:11.090 main]: Read HTTP (handle -1) [192.168.178.20:46224] sid -1, sock 7 [29/12 09:16:11.090 main]: opened /home/andre/minisatip/html///sort_asc.png fd 8 at 0x7fbc57c81000 - 160 bytes [29/12 09:16:11.090 main]: Reply (handle 7) [192.168.178.20:46224] content_len:160, sock 7 [29/12 09:16:11.103 main]: Mutex init OK 0x5623adcfa718 [29/12 09:16:11.103 main]: sockets_add: handle 8 (type 1) returning socket sock 8 [192.168.178.20:46226] read: 0x5623ad234b17 [29/12 09:16:11.103 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:11.103 main]: Requested sid close -1 timeout -1 type -1, sock 7, handle 7, timeout 1 [29/12 09:16:11.103 main]: closing stream sid -1 [29/12 09:16:11.103 main]: sockets_del: sock 7 -> handle 7, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:11.103 main]: sockets_del: sock 7 Last open socket is at index 13 current_handle 7 [29/12 09:16:11.103 main]: Destroying mutex 0x5623adcfa488 [29/12 09:16:11.106 main]: Read HTTP (handle -1) [192.168.178.20:46226] sid -1, sock 8 [29/12 09:16:11.106 main]: Could not open file /home/andre/minisatip/html///.png [29/12 09:16:11.106 main]: Reply (handle 8) [192.168.178.20:46226] content_len:0, sock 8 [29/12 09:16:11.206 main]: minisatip.c:1564 get_sid returns NULL for s_id = -1 [29/12 09:16:11.206 main]: Requested sid close -1 timeout -1 type -1, sock 8, handle 8, timeout 1 [29/12 09:16:11.206 main]: closing stream sid -1 [29/12 09:16:11.206 main]: sockets_del: sock 8 -> handle 8, sid -1, overflow bytes 0, allocated 0, used 0, unsend packets 0 [29/12 09:16:11.206 main]: sockets_del: sock 8 Last open socket is at index 13 current_handle 8 [29/12 09:16:11.206 main]: Destroying mutex 0x5623adcfa718 [29/12 09:16:11.930 signal]: BW 17KB/s, Total BW: 0 MB, ns/read 0, r: 1, w: 4 fw: 0, tt: 0 ms

Yuri666 commented 2 years ago

ok, try now

localhosthack0r commented 2 years ago

Log attached:

minisatip.log

Yuri666 commented 2 years ago

no changes, still at same point ok, last things. try to comment this line https://github.com/Yuri666/minisatip/blob/master/src/ca.c#L332

localhosthack0r commented 2 years ago

Commented CIPLUS_APP_SAS_RESOURCEID,

No change visible to me, here the log: minisatip.log

Yuri666 commented 2 years ago

try now from git

localhosthack0r commented 2 years ago

Ok, reverted the local changes (Commenting CIPLUS_APP_SAS_RESOURCEID) and pulled from your fork.

No luck, log attached. minisatip.log

Yuri666 commented 2 years ago

CAM do not send lang&country message. try to comment line https://github.com/Yuri666/minisatip/blob/master/src/ca.c#L327 CAM should send MMI message about lack ci+ compatibility

localhosthack0r commented 2 years ago

Ok, commented the CIPLUS_APP_LANG_RESOURCEID now.

Log: minisatip.log

Yuri666 commented 2 years ago

do not any reaction. sad. ok, last try today, try from git

localhosthack0r commented 2 years ago

Thanks for your patience!

I think this also didn't change anything: minisatip.log

I try also to understand and digest what is happening. If I get it right, the last thing what is happening in the init procedure is

[29/12 13:47:44.585 CA6]: CI+ CA6 0x09 0x69 0x74 0x64 0x74 0x74 0x63 0x61 0x00 0x01

The last byte here in the log is 0x01, so we are not going to call ci_session_sendADPU. Is this intended?

Yuri666 commented 2 years ago

It not last thing. Sessions between CAM and host opened simuonostly and mentioned by you strings just log about that the host not support SAS (it not mandatory resource) last thing this (create session 5):

[29/12 13:47:41.288 CA6]: ===================> ca_lookup_callback: slot_id 0 requested_resource_id 8d1001 [29/12 13:47:41.288 CA6]: ca_session_callback: reason 0 slot_id 0 session_number 5 resource_id 8d1001 [29/12 13:47:41.288 CA6]: 00:CAM connecting to resource 008d1001, session_number 5 [29/12 13:47:41.288 CA6]: ca_session_callback: reason 1 slot_id 0 session_number 5 resource_id 8d1001 [29/12 13:47:41.288 CA6]: 00:CAM successfully connected to resource 008d1001, session_number 5

after this CAM should send country req, but it silent If host not reported support this resource(CIPLUS_APP_LANG_RESOURCEID) CAM should report error, but it silent too

localhosthack0r commented 2 years ago

Ok, thanks for the explanation.

localhosthack0r commented 2 years ago

I recognized some messages from dvb_ca_en50221 in dmesg. Should I pay attention to that? Or is this normal, when using it from minisatip?

[ 18.446637] dvb_ca_en50221: dvb_ca adapter 6: DVB CAM detected and initialised successfully [ 112.248726] ftdi_sio ttyUSB1: use of SPD flags is deprecated [ 114.607614] ftdi_sio ttyUSB1: use of SPD flags is deprecated [ 124.724762] i2c i2c-3: slot_shutdown [ 128.233767] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 128.234677] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 128.383609] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 128.384725] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 128.545353] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 128.546367] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 128.697168] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 128.697939] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 128.850201] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 128.851104] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.003736] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.004634] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.158454] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.159494] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.310078] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.310782] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.461973] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.462885] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.612552] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.613570] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.770085] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.771175] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 129.927200] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 129.928286] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 130.087791] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 130.089076] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 130.240400] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 130.241514] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 130.396300] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 130.397331] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 130.554586] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 130.555760] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 130.707899] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 130.708868] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 130.865509] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 130.866446] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 131.018069] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 131.019280] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 131.166083] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 131.167027] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 131.315100] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 131.316205] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 131.472268] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 131.473199] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 131.629916] dvb_ca_en50221: dvb_ca adapter 6: Invalid PC card inserted :( [ 131.630683] dvb_ca adapter 6: Trying to read attribute memory again (some CAMs are slow) [ 131.912015] dvb_ca_en50221: dvb_ca adapter 6: DVB CAM detected and initialised successfully

Yuri666 commented 2 years ago

This is not normal. This mean problem with initialize CAM at low level - drivers or hardware.

localhosthack0r commented 2 years ago

Hmm,.. it comes from the dddvb driver: https://github.com/DigitalDevices/dddvb/blob/master/dvb-core/dvb_ca_en50221.c

But at the end there is always a [ 691.434467] dvb_ca_en50221: dvb_ca adapter 6: DVB CAM detected and initialised successfully

I'm using the latest release from an ppa:

apt show dddvb-dkms Package: dddvb-dkms Version: 0.9.37~20190315-0frodo0~bionic Priority: optional Section: misc Maintainer: Lars Hanisch dvb@flensrocker.de, Wolfgang Mangold vdr@gmx.de, Frodo frodo.vdr@gmx.net Installed-Size: 3,822 kB Depends: dkms (>= 2.2) Conflicts: linux-media, linux-media-comp, linux-media-dkms, linux-media-dvbsky, linux-media-dvbsky-c, linux-media-tbs-dkms, linux-tbs-drivers-dkms, media-build-experimental-dkms, s2-liplianin-dkms, v4l-dvb-dkms Replaces: linux-media, linux-media-comp, linux-media-dkms, linux-media-dvbsky, linux-media-dvbsky-c, linux-media-tbs-dkms, linux-tbs-drivers-dkms, media-build-experimental-dkms, s2-liplianin-dkms, v4l-dvb-dkms Download-Size: 439 kB APT-Manual-Installed: yes APT-Sources: http://ppa.launchpad.net/frodo-vdr/dddvb-0.9.37/ubuntu bionic/main amd64 Packages Description: dddvb driver in DKMS format.

Yuri666 commented 2 years ago

dvb-apps-patch.tar.gz You can try to use patched dvb-apps library. It have some improvements to work with slow CAMs. Patches and explanations exist in root directory.

Yuri666 commented 2 years ago

also may try last git

localhosthack0r commented 2 years ago

Thanks @Yuri666 !

Here log with latest git: minisatip.log

It did something, the CAM speaks English now, instead of German. ;-)

At the dvb-apps, I take a look, later,...

Yuri666 commented 2 years ago

Seems we accidentally resolve #854 :)) But it mean that lang resource works ok. And content_control resource session just not started. Now i don't have any minds why it happens. I guess change dvb apps won't help.

catalinii commented 2 years ago

Hey @localhosthack0r Can you test the latest master with your cam.

Cc @Jalle19

supamicha commented 2 years ago

Kabelio ist not working minisatip.log

Yuri666 commented 2 years ago

[12/02 17:37:54.519 CA10]: 00:ca_rm_enq_callback resource_count 12 CI MODE

minisatip not found ci+ certs, or you disable ci+ in command line

supamicha commented 2 years ago

With Certs Kabelio ist not working too minisatip.log .

supamicha commented 2 years ago

Without certs on enigma2 decrytps some channels (without RTL Group). With certs decrypts all channels.

Yuri666 commented 2 years ago

at first look not work lookup for AI recourse

needs add in ca.c after line case CIPLUS_APP_AI_RESOURCEID: next one line case TS103205_APP_AI_RESOURCE_ID:

supamicha commented 2 years ago

Does not work. ca.c.txt minisatip.log

Jalle19 commented 2 years ago

What happens if you comment out CIPLUS_APP_SAS_RESOURCEID from the list of resources?

Jalle19 commented 2 years ago

Seems the original poster here already tried that, but then he had other issues initializing the CAM. Those issues should be fixed in master now, so it would be interesting to see if disabling SAS support helps now.

Yuri666 commented 2 years ago

what other issue fixed in master now? :)

supamicha commented 2 years ago

Does not work ca.c.txt minisatip.log .

Jalle19 commented 2 years ago

@supamicha can you try this branch: https://github.com/Jalle19/minisatip/tree/ai-test ?

Jalle19 commented 2 years ago

Actually, @supamicha try this one instead: https://github.com/Jalle19/minisatip/tree/tweaks this one has both the AI fix and removed SAS support

supamicha commented 2 years ago

Thanks for your support Does not work. Log for ai-test. I will try the tweaks version now minisatip.log :

supamicha commented 2 years ago

Tweaks version is not workrking too. minisatip.log

Jalle19 commented 2 years ago

Alright, now at least the CAM gets initialized properly and there's no partial SAS support there that could screw things up. Can you put the CAM in a TV or other "official" tuner and see if you can get the card updated there? It seems like the subscription updates don't make it to the smart card, which results in "no access for this service". Then again, the specific message shown in your logs is different than the typical "No access (-6)" I've seen before, so it could be that something else is still amiss.