Hello,
first, I'll describe my issue and then I give as much information as possible about my setup to be able to debug it :)
The connection and communication with OScam, both through newcamd and DVBAPI protocols, seems unstable. It sometimes works, but sometimes doesn't. When it stops working, it usually requires disabling/enabling the connection (multiple times) in Configuration > CAs. When I stay connected to a single channel, it works but when I start flipping through channels, after a few channels the descrambling stops working.
What I think works:
* Connection between SAT>IP server and TVHeadend. Unencrypted channels work without problems all the time.
* OScam and the card in the reader - the card has all the entitlements and shows up correctly in OScam.
So I isolated the issue to be between TVHeadend and OScam. This is also supported by the logs. When the descrambling stops working, there's just no new communication logged in OScam.
This is how the OScam log looks when it works:
2017/04/05 20:31:18 618BE836 c (newcamd) user dummy authenticated successfully (Tvheadend)
2017/04/05 20:31:18 618BE836 c (newcamd) AU enabled for user dummy on reader skylink
2017/04/05 20:31:42 5ACAF422 r (reader) skylink [irdeto] Maybe you don't have the entitlements for this channel
2017/04/05 20:31:42 618BE836 c (ecm) dummy (0624@000000/0000/3357/5C:58E3D6014D1AE14A8BCDE4BF7C6242B5): not found (130 ms) by skylink - Prima +1 HD
2017/04/05 20:31:42 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_global_emm.log
2017/04/05 20:31:44 5ACAF422 r (-) -- Skipped 1 duplicated log lines --
2017/04/05 20:31:44 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=37 (hex: 0x25), cnt=0: written (94 ms)
2017/04/05 20:31:45 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_global_emm.log
2017/04/05 20:31:45 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=54 (hex: 0x36), cnt=0: written (118 ms)
2017/04/05 20:31:45 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_global_emm.log
2017/04/05 20:31:45 5ACAF422 r (-) -- Skipped 5 duplicated log lines --
2017/04/05 20:31:45 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=36 (hex: 0x24), cnt=0: written (88 ms)
2017/04/05 20:31:45 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=36 (hex: 0x24), cnt=0: written (89 ms)
2017/04/05 20:31:45 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_global_emm.log
2017/04/05 20:31:45 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=36 (hex: 0x24), cnt=0: written (89 ms)
2017/04/05 20:31:46 5ACAF422 r (-) -- Skipped 3 duplicated log lines --
2017/04/05 20:31:46 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=30 (hex: 0x1E), cnt=0: written (88 ms)
2017/04/05 20:31:46 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_global_emm.log
2017/04/05 20:31:46 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=37 (hex: 0x25), cnt=0: written (97 ms)
2017/04/05 20:31:48 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_global_emm.log
2017/04/05 20:31:48 618BE836 c (-) -- Skipped 6 duplicated log lines --
2017/04/05 20:31:48 618BE836 c (ecm) dummy (0624@000000/0000/3357/5C:81E7684701DD1E64FF303B3F33AA3931): found (185 ms) by skylink - Prima +1 HD
2017/04/05 20:31:48 618BE836 c (reader) skylink [irdeto] Successfully added EMM to /etc/oscam-svn/skylink_shared_emm.log
2017/04/05 20:31:48 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=13 (hex: 0x0D), cnt=0: written (60 ms)
2017/04/05 20:31:48 5ACAF422 r (reader) skylink [irdeto] dummy emmtype=global, len=12 (hex: 0x0C), cnt=0: written (59 ms)
And in TVHeadend:
2017-04-05 20:32:16.465 mpegts: 12070H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 20:32:16.465 subscription: 0018: "epggrab" subscribing to mux "12070H", weight: 4, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", service: "Raw PID Subscription"
2017-04-05 20:32:17.424 tbl-time: tot: 12070H in Astra 23.5E: invalid checksum (len 8, errors 1)
2017-04-05 20:32:26.145 http: 192.168.0.100: using ticket D175897CE59699BE5F207A5958B434ABE92F9E67 for /stream/channel/965b8466b5d23fbda15f733851341a69
2017-04-05 20:32:26.146 mpegts: 12343.5H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 20:32:26.146 subscription: 0018: "epggrab" unsubscribing
2017-04-05 20:32:26.146 subscription: 001B: "HTTP" subscribing on channel "Skylink Ochutnavka", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", mux: "12343.5H", provider: "M7 Group", service: "Skylink Ochutnavka", profile="pass", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 20:32:28.753 tbl-time: tot: 12343.5H in Astra 23.5E: invalid checksum (len 8, errors 1)
2017-04-05 20:32:39.955 subscription: 001B: "HTTP" unsubscribing from "Skylink Ochutnavka", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 20:32:40.953 mpegts: 12070H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 20:32:40.954 subscription: 001E: "epggrab" subscribing to mux "12070H", weight: 4, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", service: "Raw PID Subscription"
2017-04-05 20:32:42.339 tbl-time: tot: 12070H in Astra 23.5E: invalid checksum (len 8, errors 1)
I noticed those "invalid checksum" messages, but 1) they are not always there, 2) the playback was without any problems. The channel played correctly between 2017-04-05 20:32:26.146 and 2017-04-05 20:32:39.955.
And now for the part where it doesn't work. The logs look like this. The client (TVH) just connects to OScam and no further communication is there.
OScam log:
2017/04/05 21:13:26 519EE3A2 c (newcamd) client connected to 8997 port
2017/04/05 21:13:26 519EE3A2 c (client) encrypted newcamd:8997-client 127.0.0.1 granted (dummy, au=on (1 reader))
2017/04/05 21:13:26 519EE3A2 c (newcamd) user dummy authenticated successfully (Tvheadend)
2017/04/05 21:13:26 519EE3A2 c (newcamd) AU enabled for user dummy on reader skylink
TVHeadend log:
2017-04-05 21:13:26.439 cwc: Connected to 127.0.0.1:8997
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Connected as user dummy to a Irdeto-card [0x0624 : 00.00.00.00.11.3d.50.fd] with 5 providers
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Provider ID #1: 0x0624:0x000000 00.00.00.00.00.05.93.51
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Provider ID #2: 0x0624:0x000001 00.00.00.00.01.ff.ff.ff
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Provider ID #3: 0x0624:0x000002 00.00.00.00.01.ff.ff.ff
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Provider ID #4: 0x0624:0x000003 00.00.00.00.01.ff.ff.ff
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Provider ID #5: 0x0624:0x000004 00.00.00.00.00.00.00.00
2017-04-05 21:13:26.444 cwc: 127.0.0.1:8997: Will forward EMMs
2017-04-05 21:13:38.887 http: 192.168.0.100: using ticket 0CAAE405D86484F931A26F7B864C7C1C8C37F477 for /stream/channel/91443296bb3bb15c4e8b1e19fcd95e45
2017-04-05 21:13:38.887 mpegts: 12343.5H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 21:13:38.887 subscription: 003B: "HTTP" subscribing on channel "CT 24 HD", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", mux: "12343.5H", provider: "CESKA TELEVIZE", service: "CT 24 HD", profile="pass", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:13:48.888 subscription: 003B: service instance is bad, reason: No input detected
2017-04-05 21:13:50.888 subscription: 003B: No input source available for subscription "HTTP" to channel "CT 24 HD"
2017-04-05 21:13:50.888 webui: Couldn't start streaming /stream/channel/91443296bb3bb15c4e8b1e19fcd95e45?ticket=0CAAE405D86484F931A26F7B864C7C1C8C37F477, No input detected
2017-04-05 21:13:50.888 subscription: 003B: "HTTP" unsubscribing from "CT 24 HD", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:13:50.895 http: 192.168.0.100: using ticket 0CAAE405D86484F931A26F7B864C7C1C8C37F477 for /stream/channel/91443296bb3bb15c4e8b1e19fcd95e45
2017-04-05 21:13:50.896 mpegts: 12343.5H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 21:13:50.896 subscription: 003C: "HTTP" subscribing on channel "CT 24 HD", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", mux: "12343.5H", provider: "CESKA TELEVIZE", service: "CT 24 HD", profile="pass", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:13:55.896 subscription: 003C: "HTTP" unsubscribing from "CT 24 HD", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
If I switch to DVBAPI, it looks like this:
TVHeadend:
2017-04-05 21:28:11.880 http: 192.168.0.100: using ticket 686BDAA0E01090B9F234D4A656B00AA869F12A9D for /stream/channel/b43466853ba0eafcada7decaebdf822d
2017-04-05 21:28:11.880 mpegts: 12343.5H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 21:28:11.880 capmt: OScam DVBAPI: Starting CAPMT server for service "CT 1 HD" on adapter 0
2017-04-05 21:28:11.881 subscription: 0040: "HTTP" subscribing on channel "CT 1 HD", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", mux: "12343.5H", provider: "CESKA TELEVIZE", service: "CT 1 HD", profile="pass", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:28:11.881 capmt: OScam DVBAPI: mode 5 connected to 127.0.0.1:8998 (single)
2017-04-05 21:28:11.884 capmt: OScam DVBAPI: Connected to server 'OSCam v1.20-unstable_svn, build r0 (x86_64-linux-gnu)' (protocol version 2)
2017-04-05 21:28:21.881 subscription: 0040: service instance is bad, reason: No input detected
2017-04-05 21:28:23.881 subscription: 0040: No input source available for subscription "HTTP" to channel "CT 1 HD"
2017-04-05 21:28:23.881 webui: Couldn't start streaming /stream/channel/b43466853ba0eafcada7decaebdf822d?ticket=686BDAA0E01090B9F234D4A656B00AA869F12A9D, No input detected
2017-04-05 21:28:23.881 subscription: 0040: "HTTP" unsubscribing from "CT 1 HD", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:28:23.919 http: 192.168.0.100: using ticket 686BDAA0E01090B9F234D4A656B00AA869F12A9D for /stream/channel/b43466853ba0eafcada7decaebdf822d
2017-04-05 21:28:23.919 mpegts: 12343.5H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 21:28:23.920 capmt: OScam DVBAPI: Starting CAPMT server for service "CT 1 HD" on adapter 0
2017-04-05 21:28:23.920 subscription: 0041: "HTTP" subscribing on channel "CT 1 HD", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", mux: "12343.5H", provider: "CESKA TELEVIZE", service: "CT 1 HD", profile="pass", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:28:33.920 subscription: 0041: service instance is bad, reason: No input detected
2017-04-05 21:28:35.920 subscription: 0041: No input source available for subscription "HTTP" to channel "CT 1 HD"
2017-04-05 21:28:35.920 webui: Couldn't start streaming /stream/channel/b43466853ba0eafcada7decaebdf822d?ticket=686BDAA0E01090B9F234D4A656B00AA869F12A9D, No input detected
2017-04-05 21:28:35.920 subscription: 0041: "HTTP" unsubscribing from "CT 1 HD", hostname="192.168.0.100", client="VLC/2.2.4 LibVLC/2.2.4"
2017-04-05 21:28:36.002 http: 192.168.0.100: using ticket 686BDAA0E01090B9F234D4A656B00AA869F12A9D for /stream/channel/b43466853ba0eafcada7decaebdf822d
2017-04-05 21:28:36.002 mpegts: 12343.5H in Astra 23.5E - tuning on SAT>IP DVB-S Tuner #1 (192.168.0.12)
2017-04-05 21:28:36.003 capmt: OScam DVBAPI: Starting CAPMT server for service "CT 1 HD" on adapter 0
2017-04-05 21:28:36.003 subscription: 0042: "HTTP" subscribing on channel "CT 1 HD", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.0.12)", network: "Astra 23.5E", mux: "12343.5H", provider: "CESKA TELEVIZE", service: "CT 1 HD", profile="pass", hostname="192.168.0.100", client="NSPlayer/7.10.0.3059"
2017-04-05 21:28:46.003 subscription: 0042: service instance is bad, reason: No input detected
2017-04-05 21:28:48.003 subscription: 0042: No input source available for subscription "HTTP" to channel "CT 1 HD"
2017-04-05 21:28:48.003 webui: Couldn't start streaming /stream/channel/b43466853ba0eafcada7decaebdf822d?ticket=686BDAA0E01090B9F234D4A656B00AA869F12A9D, No input detected
2017-04-05 21:28:48.003 subscription: 0042: "HTTP" unsubscribing from "CT 1 HD", hostname="192.168.0.100", client="NSPlayer/7.10.0.3059"
OScam:
2017/04/05 21:27:22 4C6674CA c (client) plain dvbapi-client granted (anonymous, au=off)
2017/04/05 21:27:22 4C6674CA c (dvbapi) Parsing rule: ret=2 | p: 0624 000000 0000 10000 0000
2017/04/05 21:27:22 4C6674CA c (dvbapi) prio: ret=-1 | p: 0624 000000 0000 0000 10000 -> map 0000 000000 0000 | prio 0 | delay 0
2017/04/05 21:27:22 4C6674CA c (dvbapi) Parsing rule: ret=1 | i: 0000 000000 0000 10000 0000
2017/04/05 21:27:22 4C6674CA c (dvbapi) prio: ret=-1 | i: 0000 000000 0000 0000 10000 -> map 0000 000000 0000 | prio 0 | delay 0
2017/04/05 21:27:22 4C6674CA c (dvbapi) Read 2 entries from oscam.dvbapi
2017/04/05 21:27:22 4C6674CA c (dvbapi) dvbapi channelcache loaded from /etc/oscam-svn/oscam.ccache
2017/04/05 21:27:22 4C6674CA c (dvbapi) Using TCP listen socket, API forced to DVBAPIv3 (0), userconfig boxtype: 11
2017/04/05 21:28:11 4C6674CA c (dvbapi) new socket connection fd: 12
2017/04/05 21:28:11 4C6674CA c (dvbapi) Got DVBAPI_CLIENT_INFO packet with size 41
2017/04/05 21:28:11 4C6674CA c (dvbapi) Client connected: 'Tvheadend 4.1-2405~geb495a0~xenial' (protocol version = 2)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:11 4C6674CA c (dvbapi) FF FF 00 02 00 02 35 4F 53 43 61 6D 20 76 31 2E
2017/04/05 21:28:11 4C6674CA c (dvbapi) 32 30 2D 75 6E 73 74 61 62 6C 65 5F 73 76 6E 2C
2017/04/05 21:28:11 4C6674CA c (dvbapi) 20 62 75 69 6C 64 20 72 30 20 28 78 38 36 5F 36
2017/04/05 21:28:11 4C6674CA c (dvbapi) 34 2D 6C 69 6E 75 78 2D 67 6E 75 29
2017/04/05 21:28:11 4C6674CA c (dvbapi) Got packet with opcode 9F803282 and size 42
2017/04/05 21:28:11 4C6674CA c (dvbapi) PMT Update on socket 12.
2017/04/05 21:28:11 4C6674CA c (dvbapi) Parsing PMT object:
2017/04/05 21:28:11 4C6674CA c (dvbapi) 9F 80 32 82 00 24 03 1F 41 01 00 19 01 82 02 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 81 08 00 00 00 00 0C A1 00 03 84 02 04 4C 09
2017/04/05 21:28:11 4C6674CA c (dvbapi) 04 06 24 E4 74 01 04 56 00 06
2017/04/05 21:28:11 4C6674CA c (dvbapi) capmt:
2017/04/05 21:28:11 4C6674CA c (dvbapi) 03 1F 41 01 00 19 01 82 02 00 00 81 08 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 0C A1 00 03 84 02 04 4C 09 04 06 24 E4 74 01
2017/04/05 21:28:11 4C6674CA c (dvbapi) 04 56 00 06
2017/04/05 21:28:11 4C6674CA c (dvbapi) Receiver sends PMT command 3 for channel 1F41
2017/04/05 21:28:11 4C6674CA c (dvbapi) Receiver wants to demux srvid 1F41 on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0000
2017/04/05 21:28:11 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:11 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 04
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 Filter 1 started successfully (caid 0001 provid 000001 pid 0000)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 found pmt type: 81 length: 8 (assuming enigma private descriptor: namespace 0000 tsid ca1 onid 03)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0624 ECM_PID: 0474 PROVID: 000000
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 stream Videostream (MPEG-1)(type: 01 pid: 0456 length: 6)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 found 1 ECMpids and 1 STREAMpids in caPMT
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 serving srvid 1F41 (CT 1 HD) on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0/16 lets start descrambling (srvid = 1F41 fd = 12 ecmpids = 1)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 prio ecmpid 0 0624@000000:0474:0000 weight: 3 (file)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 prio ecmpid 0 0624@000000:0474:10000 weight: 4 (1 local and 0 cacheex readers)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 sorting the ecmpids took 0 ms
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 trying to descramble PID 0 CAID 0624 PROVID 000000 ECMPID 0474 ANY CHID PMTPID 0000 VPID 0456
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0624, provid: 000000, pid: 0474
2017/04/05 21:28:11 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:11 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 01 04 74 80 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 F0 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 0B B8 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 04
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 Filter 2 started successfully (caid 0624 provid 000000 pid 0474)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Got packet with opcode 9F803282 and size 42
2017/04/05 21:28:11 4C6674CA c (dvbapi) PMT Update on socket 12.
2017/04/05 21:28:11 4C6674CA c (dvbapi) Parsing PMT object:
2017/04/05 21:28:11 4C6674CA c (dvbapi) 9F 80 32 82 00 24 03 1F 41 02 00 19 01 82 02 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 81 08 00 00 00 00 0C A1 00 03 84 02 04 4C 09
2017/04/05 21:28:11 4C6674CA c (dvbapi) 04 06 24 E4 74 01 04 56 00 06
2017/04/05 21:28:11 4C6674CA c (dvbapi) capmt:
2017/04/05 21:28:11 4C6674CA c (dvbapi) 03 1F 41 02 00 19 01 82 02 00 00 81 08 00 00 00
2017/04/05 21:28:11 4C6674CA c (dvbapi) 00 0C A1 00 03 84 02 04 4C 09 04 06 24 E4 74 01
2017/04/05 21:28:11 4C6674CA c (dvbapi) 04 56 00 06
2017/04/05 21:28:11 4C6674CA c (dvbapi) Receiver sends PMT command 3 for channel 1F41
2017/04/05 21:28:11 4C6674CA c (dvbapi) Marked demuxer 0/16 (srvid = 1F41 fd = 12) to stop decoding
2017/04/05 21:28:11 4C6674CA c (dvbapi) Receiver wants to demux srvid 1F41 on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 continue decoding of SRVID 1F41
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 found pmt type: 81 length: 8 (assuming enigma private descriptor: namespace 0000 tsid ca1 onid 03)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 stream Videostream (MPEG-1)(type: 01 pid: 0456 length: 6)
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 found 1 ECMpids and 1 STREAMpids in caPMT
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 serving srvid 1F41 (CT 1 HD) on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:11 4C6674CA c (dvbapi) Demuxer 0 has 1 ecmpids, 1 streampids, 1 ecmfilters and 0 of max 0 emmfilters
2017/04/05 21:28:16 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0011
2017/04/05 21:28:16 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:16 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 02 00 11 42 00 00 00 00 00 00
2017/04/05 21:28:16 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00
2017/04/05 21:28:16 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:16 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:16 4C6674CA c (dvbapi) 04
2017/04/05 21:28:16 4C6674CA c (dvbapi) Demuxer 0 Filter 3 started successfully (caid 0001 provid 000001 pid 0011)
2017/04/05 21:28:21 4C6674CA c (dvbapi) Got packet with opcode 9F803F04 and size 8
2017/04/05 21:28:21 4C6674CA c (dvbapi) Demuxer 0 stop descrambling program number 1F41 (CT 1 HD)
2017/04/05 21:28:21 4C6674CA c (dvbapi) Demuxer 0 stop filter 3 try 1 (fd: 65535 api: 0, caid: 0001, provid: 000001, emmpid: 0011)
2017/04/05 21:28:21 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:21 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 02 00 11
2017/04/05 21:28:21 4C6674CA c (dvbapi) Demuxer 0 stop filter 1 try 1 (fd: 65535 api: 0, caid: 0001, provid: 000001, emmpid: 0000)
2017/04/05 21:28:21 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:21 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 00 00 00
2017/04/05 21:28:21 4C6674CA c (dvbapi) Demuxer 0 stop filter 2 try 1 (fd: 65535 api: 0, caid: 0624, provid: 000000, ecmpid: 0474)
2017/04/05 21:28:21 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:21 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 01 04 74
2017/04/05 21:28:23 4C6674CA c (dvbapi) Got packet with opcode 9F803282 and size 42
2017/04/05 21:28:23 4C6674CA c (dvbapi) PMT Update on socket 12.
2017/04/05 21:28:23 4C6674CA c (dvbapi) Parsing PMT object:
2017/04/05 21:28:23 4C6674CA c (dvbapi) 9F 80 32 82 00 24 03 1F 41 03 00 19 01 82 02 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 81 08 00 00 00 00 0C A1 00 03 84 02 04 4C 09
2017/04/05 21:28:23 4C6674CA c (dvbapi) 04 06 24 E4 74 01 04 56 00 06
2017/04/05 21:28:23 4C6674CA c (dvbapi) capmt:
2017/04/05 21:28:23 4C6674CA c (dvbapi) 03 1F 41 03 00 19 01 82 02 00 00 81 08 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 0C A1 00 03 84 02 04 4C 09 04 06 24 E4 74 01
2017/04/05 21:28:23 4C6674CA c (dvbapi) 04 56 00 06
2017/04/05 21:28:23 4C6674CA c (dvbapi) Receiver sends PMT command 3 for channel 1F41
2017/04/05 21:28:23 4C6674CA c (dvbapi) Receiver wants to demux srvid 1F41 on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0000
2017/04/05 21:28:23 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:23 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 04
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 Filter 1 started successfully (caid 0001 provid 000001 pid 0000)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 found pmt type: 81 length: 8 (assuming enigma private descriptor: namespace 0000 tsid ca1 onid 03)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0624 ECM_PID: 0474 PROVID: 000000
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 stream Videostream (MPEG-1)(type: 01 pid: 0456 length: 6)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 found 1 ECMpids and 1 STREAMpids in caPMT
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 serving srvid 1F41 (CT 1 HD) on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0/16 lets start descrambling (srvid = 1F41 fd = 12 ecmpids = 1)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 prio ecmpid 0 0624@000000:0474:0000 weight: 3 (file)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 prio ecmpid 0 0624@000000:0474:10000 weight: 4 (1 local and 0 cacheex readers)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 sorting the ecmpids took 0 ms
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 trying to descramble PID 0 CAID 0624 PROVID 000000 ECMPID 0474 ANY CHID PMTPID 0000 VPID 0456
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0624, provid: 000000, pid: 0474
2017/04/05 21:28:23 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:23 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 01 04 74 80 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 F0 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 0B B8 00 00 00
2017/04/05 21:28:23 4C6674CA c (dvbapi) 04
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 Filter 2 started successfully (caid 0624 provid 000000 pid 0474)
2017/04/05 21:28:23 4C6674CA c (dvbapi) Demuxer 0 has 1 ecmpids, 1 streampids, 1 ecmfilters and 0 of max 0 emmfilters
2017/04/05 21:28:28 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0011
2017/04/05 21:28:28 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:28 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 02 00 11 42 00 00 00 00 00 00
2017/04/05 21:28:28 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00
2017/04/05 21:28:28 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:28 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:28 4C6674CA c (dvbapi) 04
2017/04/05 21:28:28 4C6674CA c (dvbapi) Demuxer 0 Filter 3 started successfully (caid 0001 provid 000001 pid 0011)
2017/04/05 21:28:33 4C6674CA c (dvbapi) Got packet with opcode 9F803F04 and size 8
2017/04/05 21:28:33 4C6674CA c (dvbapi) Demuxer 0 stop descrambling program number 1F41 (CT 1 HD)
2017/04/05 21:28:33 4C6674CA c (dvbapi) Demuxer 0 stop filter 3 try 1 (fd: 65535 api: 0, caid: 0001, provid: 000001, emmpid: 0011)
2017/04/05 21:28:33 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:33 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 02 00 11
2017/04/05 21:28:33 4C6674CA c (dvbapi) Demuxer 0 stop filter 1 try 1 (fd: 65535 api: 0, caid: 0001, provid: 000001, emmpid: 0000)
2017/04/05 21:28:33 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:33 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 00 00 00
2017/04/05 21:28:33 4C6674CA c (dvbapi) Demuxer 0 stop filter 2 try 1 (fd: 65535 api: 0, caid: 0624, provid: 000000, ecmpid: 0474)
2017/04/05 21:28:33 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:33 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 01 04 74
2017/04/05 21:28:36 4C6674CA c (dvbapi) Got packet with opcode 9F803282 and size 42
2017/04/05 21:28:36 4C6674CA c (dvbapi) PMT Update on socket 12.
2017/04/05 21:28:36 4C6674CA c (dvbapi) Parsing PMT object:
2017/04/05 21:28:36 4C6674CA c (dvbapi) 9F 80 32 82 00 24 03 1F 41 04 00 19 01 82 02 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 81 08 00 00 00 00 0C A1 00 03 84 02 04 4C 09
2017/04/05 21:28:36 4C6674CA c (dvbapi) 04 06 24 E4 74 01 04 56 00 06
2017/04/05 21:28:36 4C6674CA c (dvbapi) capmt:
2017/04/05 21:28:36 4C6674CA c (dvbapi) 03 1F 41 04 00 19 01 82 02 00 00 81 08 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 0C A1 00 03 84 02 04 4C 09 04 06 24 E4 74 01
2017/04/05 21:28:36 4C6674CA c (dvbapi) 04 56 00 06
2017/04/05 21:28:36 4C6674CA c (dvbapi) Receiver sends PMT command 3 for channel 1F41
2017/04/05 21:28:36 4C6674CA c (dvbapi) Receiver wants to demux srvid 1F41 on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0000
2017/04/05 21:28:36 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:36 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 04
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 Filter 1 started successfully (caid 0001 provid 000001 pid 0000)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 found pmt type: 81 length: 8 (assuming enigma private descriptor: namespace 0000 tsid ca1 onid 03)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 ecmpid 0 CAID: 0624 ECM_PID: 0474 PROVID: 000000
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 stream Videostream (MPEG-1)(type: 01 pid: 0456 length: 6)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 found 1 ECMpids and 1 STREAMpids in caPMT
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 serving srvid 1F41 (CT 1 HD) on adapter 0000 camask 0001 index 0000 pmtpid 0000
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0/16 lets start descrambling (srvid = 1F41 fd = 12 ecmpids = 1)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 prio ecmpid 0 0624@000000:0474:0000 weight: 3 (file)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 prio ecmpid 0 0624@000000:0474:10000 weight: 4 (1 local and 0 cacheex readers)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 sorting the ecmpids took 0 ms
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 trying to descramble PID 0 CAID 0624 PROVID 000000 ECMPID 0474 ANY CHID PMTPID 0000 VPID 0456
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0624, provid: 000000, pid: 0474
2017/04/05 21:28:36 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:36 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 01 04 74 80 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 F0 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 0B B8 00 00 00
2017/04/05 21:28:36 4C6674CA c (dvbapi) 04
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 Filter 2 started successfully (caid 0624 provid 000000 pid 0474)
2017/04/05 21:28:36 4C6674CA c (dvbapi) Demuxer 0 has 1 ecmpids, 1 streampids, 1 ecmfilters and 0 of max 0 emmfilters
2017/04/05 21:28:41 4C6674CA c (dvbapi) Demuxer 0 try to start new filter for caid: 0001, provid: 000001, pid: 0011
2017/04/05 21:28:41 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:41 4C6674CA c (dvbapi) 40 3C 6F 2B 00 00 02 00 11 42 00 00 00 00 00 00
2017/04/05 21:28:41 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 FF 00 00 00 00 00 00
2017/04/05 21:28:41 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:41 4C6674CA c (dvbapi) 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00 00
2017/04/05 21:28:41 4C6674CA c (dvbapi) 04
2017/04/05 21:28:41 4C6674CA c (dvbapi) Demuxer 0 Filter 3 started successfully (caid 0001 provid 000001 pid 0011)
2017/04/05 21:28:46 4C6674CA c (dvbapi) Got packet with opcode 9F803F04 and size 8
2017/04/05 21:28:46 4C6674CA c (dvbapi) Demuxer 0 stop descrambling program number 1F41 (CT 1 HD)
2017/04/05 21:28:46 4C6674CA c (dvbapi) Demuxer 0 stop filter 3 try 1 (fd: 65535 api: 0, caid: 0001, provid: 000001, emmpid: 0011)
2017/04/05 21:28:46 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:46 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 02 00 11
2017/04/05 21:28:46 4C6674CA c (dvbapi) Demuxer 0 stop filter 1 try 1 (fd: 65535 api: 0, caid: 0001, provid: 000001, emmpid: 0000)
2017/04/05 21:28:46 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:46 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 00 00 00
2017/04/05 21:28:46 4C6674CA c (dvbapi) Demuxer 0 stop filter 2 try 1 (fd: 65535 api: 0, caid: 0624, provid: 000000, ecmpid: 0474)
2017/04/05 21:28:46 4C6674CA c (dvbapi) Sending packet to dvbapi client (fd=12):
2017/04/05 21:28:46 4C6674CA c (dvbapi) 00 00 6F 2A 00 00 01 04 74
Versions I use:
HTS Tvheadend 4.1-2405~geb495a0~xenial
Oscam 1.20.9978+svn201704010018~ubuntu16.04.1
I also tried different revisions of OScam built from source with the same or worse results.
This is how the connection configurations look like:
[newcamd]
key = 000102030405060708090A0B0C0D
port = 8997@0624:000000
keepalive = 1
[dvbapi]
enabled = 1
pmt_mode = 0
listen_port = 8998 # or whatever port you want if 9001 is taken
ecminfo_type = 4
user = dummy # user should match the user created above
read_sdt = 1
boxtype = pc
au = 1
TVHeadend:
newcamd: dummy/dummy, 127.0.0.1, port 8997, DES key 00:01:02:03:04:05:06:07:08:09:0a:0b:0c:0d, Update card (EMM), keepalive interval 30
DVBAPI: OSCam net protocol (rev >= 10389), 127.0.0.1, 8998
I also tried to disable the system firewall, with no results.
Is there anything else I can provide to figure out this issue?
Thanks a lot!