Bug #2075
closed
Subscription with no transmission starting on encrypted channels
Added by Rob vh almost 11 years ago. Updated over 10 years ago.
0%
Description
I use XBMC to subscribe, but after the Subscription message in Syslog, nothing happens:
Apr 22 19:55:33 sat tvheadend10990: htsp: 10.29.1.44: Welcomed client software: XBMC Media Center (HTSPv8)
Apr 22 19:55:33 sat tvheadend10990: htsp: 10.29.1.44 [ XBMC Media Center ]: Disconnected
Apr 22 19:55:53 sat tvheadend10990: mpegts: 10920H - starting for 'epggrab' (weight 1)
Apr 22 19:55:53 sat tvheadend10990: mpegts: 10920H - tuning on STV090x Multistandard : DVB-S #5
Apr 22 19:55:54 sat tvheadend10990: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #5', network: '19.2E', mux: '10920H'
Apr 22 19:55:54 sat tvheadend10990: mpegts: 10832H - starting for 'epggrab' (weight 1)
Apr 22 19:55:54 sat tvheadend10990: mpegts: 10832H - tuning on STV090x Multistandard : DVB-S #4
Apr 22 19:55:56 sat tvheadend10990: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #4', network: '19.2E', mux: '10832H'
Apr 22 19:55:56 sat tvheadend10990: mpegts: 11552H - starting for 'epggrab' (weight 1)
Apr 22 19:55:56 sat tvheadend10990: mpegts: 11552H - tuning on STV090x Multistandard : DVB-S #3
Apr 22 19:55:58 sat tvheadend10990: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #3', network: '19.2E', mux: '11552H'
Apr 22 19:55:58 sat tvheadend10990: mpegts: 11420H - starting for 'epggrab' (weight 1)
Apr 22 19:55:58 sat tvheadend10990: mpegts: 11420H - tuning on STV090x Multistandard : DVB-S #2
Apr 22 19:55:59 sat tvheadend10990: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #2', network: '19.2E', mux: '11420H'
Apr 22 19:55:59 sat tvheadend10990: mpegts: 11836H - starting for 'epggrab' (weight 1)
Apr 22 19:55:59 sat tvheadend10990: mpegts: 11836H - tuning on STV090x Multistandard : DVB-S #1
Apr 22 19:55:59 sat tvheadend10990: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #1', network: '19.2E', mux: '11836H'
Apr 22 19:55:59 sat tvheadend10990: mpegts: 11082H - starting for 'epggrab' (weight 1)
Apr 22 19:55:59 sat tvheadend10990: mpegts: 11082H - tuning on STV090x Multistandard : DVB-S #0
Apr 22 19:56:01 sat tvheadend10990: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #0', network: '19.2E', mux: '11082H'
Apr 22 19:56:08 sat tvheadend10990: eit: invalid checksum
Apr 22 19:56:11 tvheadend10990: last message repeated 21 times
Apr 22 19:56:11 sat tvheadend10990: subscription: "epggrab" unsubscribing
Apr 22 19:57:21 tvheadend10990: last message repeated 5 times
Apr 22 19:59:45 sat tvheadend10990: mpegts: 12187H - tuning on STV090x Multistandard : DVB-S #4
Apr 22 19:59:46 sat tvheadend10990: capmt: Starting capmt server for service "NED1 HD" on tuner 4
Apr 22 19:59:46 sat tvheadend10990: subscription: "10.29.1.44 [ XBMC Media Center ]" subscribing on "NED1 HD", weight: 150, adapter: "STV090x Multistandard : DVB-S #4", network: "23.5E", mux: "12187H", provider: "M7 Group", service: "NED1 HD"
The status display shows
Steam 12187H, Subs # 0, bandwidth 0, BER large number, transport error 0, Continuity error 0, SNR 40000%, Signal strength 41000%.
Subscriptions shows Status bad.
This occurs on encrypted channels. On Sunday (with a git pull on Sunday) it worked.
Files
| tvh.log.gz (102 KB) tvh.log.gz | log file | Mario D, 2014-05-05 12:48 |
Updated by Rob vh almost 11 years ago
Also happens on BBC and Channel 4 (FTA).
Live TV and recordings. On Live TV you see "Buffering 0%" forever.
Updated by Sebastian Porombka almost 11 years ago
I got the same on ProSieben HD - observing the Buffering 0% . After a second attemp the live tv started.
Updated by Adam Sutton almost 11 years ago
If you can confirm this works by going back to previous version then please submit debug logs pre and post with the following debug (command line) options:
--trace mpegts,dvb,linuxdvb -l tvh.log
Adam
Updated by Adam Sutton almost 11 years ago
- Status changed from New to Need feedback
Updated by Rob vh almost 11 years ago
Applying the fixes from this morning (you are an active coder!) fixed the "Buffering 0%" issue for me. On encrypted and FTA. Thank you.
Still, it would have been good if Live streaming gave us a debug message like dvr does:
Apr 23 12:24:39 sat tvheadend15379: subscription: "DVR: This Morning" subscribing on "ITV HD", weight: 300, adapter: "STV090x Multistandard : DVB-S #3", network: "28.2E", mux: "11097V", provider: "BSkyB", service: "ITV HD"
Apr 23 12:24:39 sat tvheadend15379: dvr: /data/3/tv_recordings/This Morning/ITV HD-This Morning.2014-04-23.12-30.ts from adapter: "STV090x Multistandard : DVB-S #3", network: "28.2E", mux: "11097V", provider: "BSkyB", service: "ITV HD"
Apr 23 12:24:39 sat tvheadend15379: dvr: # type lang resolution aspect ratio sample rate channels
Apr 23 12:24:39 sat tvheadend15379: dvr: 1 H264 1920x1080 ?
Apr 23 12:24:39 sat tvheadend15379: dvr: 2 MPEG2AUDIO nar ? ?
Apr 23 12:24:39 sat tvheadend15379: dvr: 3 TELETEXT nar
Apr 23 12:24:39 sat tvheadend15379: dvr: 4 DVBSUB eng
Apr 23 12:24:39 sat tvheadend15379: dvr: 5 AC3 eng ? ?
Apr 23 12:24:39 sat tvheadend15379: dvr: 6 TEXTSUB eng
Updated by Rob vh almost 11 years ago
I may have spoken to soon... This afternoon I tested all 6 adapters, one by one (so disable all but one, test, move to the next, etc).
Left all 6 enabled.
Now I see in Status that 2 adapters are in use (adapter 4 and 5) one with live streaming and one with a recorder). But in syslog I see that epgscan cannot find a free adapter:
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - tuning on STV090x Multistandard : DVB-S #0
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - failed to start, try another
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - starting for 'epggrab' (weight 1)
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - tuning on STV090x Multistandard : DVB-S #3
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - failed to start, try another
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - starting for 'epggrab' (weight 1)
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - tuning on STV090x Multistandard : DVB-S #1
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - failed to start, try another
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - starting for 'epggrab' (weight 1)
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - tuning on STV090x Multistandard : DVB-S #2
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - failed to start, try another
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - starting for 'epggrab' (weight 1)
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - tuning on STV090x Multistandard : DVB-S #0
Apr 23 16:17:29 sat tvheadend11581: mpegts: 12265H - failed to start, try another
Apr 23 16:17:30 sat tvheadend11581: subscription: "epggrab" unsubscribing
Apr 23 16:21:22 sat tvheadend11581: mpegts: 12187H - starting for 'epggrab' (weight 1)
Apr 23 16:21:22 sat tvheadend11581: mpegts: 12187H - tuning on STV090x Multistandard : DVB-S #5
Apr 23 16:21:23 sat tvheadend11581: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #5', network: '23.5E', mux: '12187H'
Apr 23 16:23:03 sat tvheadend11581: subscription: "epggrab" unsubscribing
Apr 23 16:26:59 sat tvheadend11581: mpegts: 11552H - starting for 'epggrab' (weight 1)
Apr 23 16:26:59 sat tvheadend11581: mpegts: 11552H - tuning on STV090x Multistandard : DVB-S #5
Apr 23 16:27:02 sat tvheadend11581: subscription: 'epggrab' subscribing to mux, weight: 1, adapter: 'STV090x Multistandard : DVB-S #5', network: '19.2E', mux: '11552H'
Apr 23 16:27:02 sat tvheadend11581: mpegts: 11420H - starting for 'epggrab' (weight 1)
Apr 23 16:27:02 sat tvheadend11581: mpegts: 11420H - tuning on STV090x Multistandard : DVB-S #3
Apr 23 16:27:02 sat tvheadend11581: mpegts: 11420H - failed to start, try another
Apr 23 16:27:02 sat tvheadend11581: mpegts: 11420H - starting for 'epggrab' (weight 1)
Apr 23 16:27:02 sat tvheadend11581: mpegts: 11420H - tuning on STV090x Multistandard : DVB-S #1
Apr 23 16:27:02 sat tvheadend11581: mpegts: 11420H - failed to start, try another
When I check each adapter, it is enabled and has the networks selected.
When I restart tvheadend, all 6 run (again). It is possible that an adapter "remembers" it has been disabled from the Configuration panel?
Updated by Mario D almost 11 years ago
- File tvh.log.gz tvh.log.gz added
I have the same problems on my encrypted channels. They work with the stable version of TVH.
Many encrypted channels don't scream: I can see the correct encryption key requests, but nothing is streamed. The same happens with xbmc, vlc or from browser. On the Status->Subscriptions I can usually see a very low-bitrate (70kb/s) on input and zero on output.
I'm attaching a log of a run of TVH with the suggested parameters (tvheadend --trace mpegts,dvb,linuxdvb -l tvh.log). At time '2014-05-05 12:30:53.587' I've tuned an encrypted channel that works well. Then, at time '2014-05-05 12:31:10.307', another attempt on a channel that never works with the bad described behavior: nothing streams!
The smart-card server has received and successfully replied to all the requests.
I hope it can help.
Thank you!
Updated by av ware almost 11 years ago
Hi, I confirm the issue on encrypted channel. I'm using tvheadend-trunk and showtime-trunk, but I found the same problem on tvheadend stable release (v3.6).
When I select an encrypted channel, subscription starts with state: Testing, but after 6 seconds the state becomes Bad (No input detected). So if I unsubscrive and subscribe more times on the same channel, the state becomes Running. I think the same thing happens during the streaming too, the video stops and resumes after 10-20 seconds even if the process continues to ask for valid keys for descrable.
I tried (with the same results):
- two DVB-T (DiBcom 7000PC, Afatech AF9033)
- one DVB-S (Technisat SkyStar USB HD)
- oscam-trunk-9705 with CWC and CAPMT
I'm available for further testing
Thanks for all
Updated by Mario D almost 11 years ago
Any news on this bug? I can confirm that the same channels, with the same oscam installation, work well on VDR. I've also switched recently on SAT>IP and the problem is still there...
Updated by Mario D almost 11 years ago
I've just discovered that tvheadend support oscam dvbapi network-mode: now all channels work! My previous configuration (working with VDR) used caid-specific newcamd connections.
Updated by Mario D almost 11 years ago
it looks unreliable: sometimes, on the same channel, I get descrambler: channel-name-here: even stream key is not valid on the log...
Updated by Mario D almost 11 years ago
I've solved my problems: this could help other people so I report the details. I've switched on the network-mode of dvbapi but in this mode some channels were not available ("...stream key is not valid" on logs). I've discovered that on these specific channels there are multiple PIDs with the same CAID of my card. I don't know why, but some of these PIDS can't correctly decoded by my card (oscam say decoded but tvheadend says the they are not valid...). In a OSCAM bug report ([[http://www.streamboard.tv/oscam/ticket/3762]]) I've found a way to force the use of a specific PID under some conditions.
For me, a file oscam.dvbapi with the following lines has solved my problems:P: 09CD 3:3
I: 09CD 2
This trick could also help with dvbapi on local socket.
Updated by Mario D over 10 years ago
I'm noting that tvheadend has a per-service property "Preferred CA pid". It looks that using cwc I can force the correct PID and decode even using cwc. By the way, I should correct by-hand every channel and it looks ugly. What have changed in tvheadend. It looks that the choice in my case is incorrect.
For example, for "Cinema Classics" of sky-it on mux 12034V of Hotbird 13°, the info look like this:
@Index PID Type Language Details
0x00a5 / 165 PCR
0x0461 / 1121 PMT
1 0x00a5 / 165 MPEG2VIDEO
2 0x01a4 / 420 MPEG2AUDIO ita
3 0x01a5 / 421 MPEG2AUDIO und
4 0x01d9 / 473 TELETEXT
5 0x2309 / 8969 TEXTSUB ita
6 0x230a / 8970 TEXTSUB eng
7 0x0647 / 1607 CA CAIDS: 0919:000000
8 0x06ab / 1707 CA CAIDS: 093b:000000
9 0x070f / 1807 CA CAIDS: 09cd:000000
10 0x0672 / 1650 CA CAIDS: 0919:000000
11 0x06d6 / 1750 CA CAIDS: 093b:000000
12 0x073a / 1850 CA CAIDS: 09cd:000000
After filtering and reordering (without PCR and PMT)
Index PID Type Language Details
1 0x00a5 / 165 MPEG2VIDEO
2 0x01a4 / 420 MPEG2AUDIO ita
3 0x01a5 / 421 MPEG2AUDIO und
4 0x01d9 / 473 TELETEXT
5 0x2309 / 8969 TEXTSUB ita
6 0x230a / 8970 TEXTSUB eng
7 0x0647 / 1607 CA CAIDS: 0919:000000
8 0x06ab / 1707 CA CAIDS: 093b:000000
9 0x070f / 1807 CA CAIDS: 09cd:000000
10 0x0672 / 1650 CA CAIDS: 0919:000000
11 0x06d6 / 1750 CA CAIDS: 093b:000000
12 0x073a / 1850 CA CAIDS: 09cd:000000@
In my case, my card is a type 09cd and it looks that my pid is always the third. tvheadend automatically select pid 1850 and the decoding doesn't work. If I correct such value in 1807, it works well.
Updated by Mario D over 10 years ago
The prefcapid selection looks broken with my card. On the above example channel there are 2 possible PIDS with 09cd (1807, 1850), and tvheadend try to request two ECMs. My oscam is, maybe wrongly, reporting answers that are both accepted by tvheadend. It looks that the first reply cancels the other request and it is chosen as prefcapid. A log starting with precapid=0 is below reported: at time 17:45:33.502 the working pid 1807 is selected as prefcapid (just because it arrives first!), but later at time 17:45:36.914 it is overwritten (!?!) by the broken pid 1850.
I hope this is not just noise by me. I would try to help you developers to improve the project.
2014-07-21 17:45:09.000 [ TRACE]:cwc: sending message sid 0 len 26 enq 0
2014-07-21 17:45:09.000 [ TRACE]:cwc: 00 00 39 5F 10 98 DD BE 41 9A E2 58 22 64 50 6C ..9_....A..X"dPl
2014-07-21 17:45:09.000 [ TRACE]:cwc: 0D 03 CD 7C E8 BA 58 1B AB D7 ...|..X...
2014-07-21 17:45:32.643 [ INFO]:mpegts: 12034V in Hotbird 13° - tuning on SAT>IP DVB-S Tuner #1 (192.168.200.10)
2014-07-21 17:45:32.643 [ TRACE]:descrambler: mux 0x7f2a8806ded0 open pid 070F (1807) (flags 0x0040)
2014-07-21 17:45:32.643 [ TRACE]:descrambler: mux 0x7f2a8806ded0 open pid 073A (1850) (flags 0x0040)
2014-07-21 17:45:32.643 [ DEBUG]:cwc: 12034V/Cinema Classics using CWC sam:65327
2014-07-21 17:45:32.643 [ INFO]:subscription: "HTTP" subscribing on "none", weight: 100, adapter: "SAT>IP DVB-S Tuner #1 (192.168.200.10)", network: "Hotbird 13°", mux: "12034V", provider: "SkyItalia", service: "Cinema Classics", hostname: "192.168.200.200", username: "<N/A>", client: "VLC/2.1.5 LibVLC/2.1.5"
2014-07-21 17:45:33.182 [WARNING]:TS: 12034V/Cinema Classics: Transport error indicator
2014-07-21 17:45:33.236 [ DEBUG]:cwc: ECM state 0
2014-07-21 17:45:33.236 [ DEBUG]:cwc: Insert new ECM (PID 1807) for service "Cinema Classics"
2014-07-21 17:45:33.236 [ TRACE]:cwc: sending message sid 11109 len 210 enq 1
2014-07-21 17:45:33.236 [ TRACE]:cwc: 00 00 A1 04 92 B5 5C 6D 8D 39 94 D7 E5 37 DF FA ......\m.9...7..
2014-07-21 17:45:33.236 [ TRACE]:cwc: 93 99 0F B5 6D 60 F0 70 63 6B 4E ED 0E A9 8E AA ....m`.pckN.....
2014-07-21 17:45:33.236 [ TRACE]:cwc: 76 CD 61 6F B7 87 0E DD DE B6 39 7F BE 4A 45 59 v.ao......9..JEY
2014-07-21 17:45:33.236 [ TRACE]:cwc: B2 F6 60 5A 5D 94 80 CB D9 32 E0 8F D3 27 BC 22 ..`Z]....2...'."
2014-07-21 17:45:33.236 [ TRACE]:cwc: 79 45 0E 3C 3D 96 33 9B E2 34 06 DC 55 3F 7E B8 yE.<=.3..4..U?~.
2014-07-21 17:45:33.236 [ TRACE]:cwc: F5 6A E6 05 1E 94 05 48 DA 57 77 28 8E 5B D4 E4 .j.....H.Ww(.[..
2014-07-21 17:45:33.237 [ TRACE]:cwc: 88 79 1B 05 F9 07 DA 07 71 DE C6 54 68 A1 32 A4 .y......q..Th.2.
2014-07-21 17:45:33.237 [ TRACE]:cwc: F6 C0 9F D7 02 F3 0A BE B2 B9 BE 3E 55 31 19 19 ...........>U1..
2014-07-21 17:45:33.237 [ TRACE]:cwc: F5 7C 36 23 DD 10 6B 7C F1 65 39 DD CF 40 61 50 .|6#..k|.e9..@aP
2014-07-21 17:45:33.237 [ TRACE]:cwc: F5 79 91 1B E2 98 81 02 A6 6B 09 69 0F 10 57 4C .y.......k.i..WL
2014-07-21 17:45:33.237 [ TRACE]:cwc: 33 BD B6 51 86 86 29 DB E5 C0 FF 74 C9 FE F7 02 3..Q..)....t....
2014-07-21 17:45:33.237 [ TRACE]:cwc: C8 07 20 3B A0 B0 5D 55 EA 19 42 6A 0D 96 6F A8 .. ;..]U..Bj..o.
2014-07-21 17:45:33.237 [ TRACE]:cwc: 51 23 A2 81 60 A5 01 50 7D 4F E3 A9 E2 46 E1 45 Q#..`..P}O...F.E
2014-07-21 17:45:33.237 [ TRACE]:cwc: 7C 00 |.
2014-07-21 17:45:33.237 [ DEBUG]:cwc: Sending ECM (PID 1807) section=0/0, for service "Cinema Classics" (seqno: 3)
2014-07-21 17:45:33.237 [ TRACE]:descrambler: ECM message (len 183, pid 1807) for service "Cinema Classics"
2014-07-21 17:45:33.237 [ TRACE]:descrambler: initial stream key set to even for service "Cinema Classics"
2014-07-21 17:45:33.288 [ DEBUG]:cwc: ECM state 0
2014-07-21 17:45:33.288 [ DEBUG]:cwc: Insert new ECM (PID 1850) for service "Cinema Classics"
2014-07-21 17:45:33.288 [ TRACE]:cwc: sending message sid 11109 len 210 enq 1
2014-07-21 17:45:33.288 [ TRACE]:cwc: 00 00 19 75 21 82 DE BC D2 1D 52 6B 19 76 E7 AA ...u!.....Rk.v..
2014-07-21 17:45:33.288 [ TRACE]:cwc: E6 2F 0C 8E BD 95 F3 30 9B 53 82 B9 6D 7E 20 93 ./.....0.S..m~ .
2014-07-21 17:45:33.288 [ TRACE]:cwc: F5 56 67 67 DB AB C1 DD E9 B2 61 AE 69 7A 69 B2 .Vgg......a.izi.
2014-07-21 17:45:33.288 [ TRACE]:cwc: 69 6B 0C E3 09 E4 69 F7 19 EC 45 19 67 0E E3 5F ik....i...E.g.._
2014-07-21 17:45:33.288 [ TRACE]:cwc: FD 5C 6C 0E DA FB E2 04 01 C3 DD 42 1B 6A 37 80 .\l........B.j7.
2014-07-21 17:45:33.288 [ TRACE]:cwc: 56 3C 63 55 1B 1A F0 19 4F EF FD 1E 2D B6 1D C7 V<cU....O...-...
2014-07-21 17:45:33.288 [ TRACE]:cwc: 8E AC C6 2B F8 CF 49 0C AF A2 67 2B D0 A0 81 49 ...+..I...g+...I
2014-07-21 17:45:33.288 [ TRACE]:cwc: 3D A8 66 BB 6A 51 C2 8C 9F 49 3C 14 B6 0D AF E5 =.f.jQ...I<.....
2014-07-21 17:45:33.288 [ TRACE]:cwc: 81 01 BC DE CF 21 E6 09 C8 6D D5 84 4D 4B 10 04 .....!...m..MK..
2014-07-21 17:45:33.288 [ TRACE]:cwc: 40 BE 6E CB 02 C1 06 DB 97 EB 2B B2 FE B4 2D DE
2014-07-21 17:45:33.289 [ TRACE]:cwc: C5 FC C8 4C 17 F2 02 91 AD 37 77 17 F9 41 9D 91 ...L.....7w..A..
2014-07-21 17:45:33.289 [ TRACE]:cwc: C8 9C 70 94 DA 6C 50 68 E1 6E 84 11 4C 66 EC B8 ..p..lPh.n..Lf..
2014-07-21 17:45:33.289 [ TRACE]:cwc: FE ED ED 9F B7 56 97 B4 DE 60 F8 27 B1 1B 23 16 .....V...`.'..#.
2014-07-21 17:45:33.289 [ TRACE]:cwc: E8 E9 ..
2014-07-21 17:45:33.289 [ DEBUG]:cwc: Sending ECM (PID 1850) section=0/0, for service "Cinema Classics" (seqno: 4)
2014-07-21 17:45:33.289 [ TRACE]:descrambler: ECM message (len 183, pid 1850) for service "Cinema Classics"
2014-07-21 17:45:33.289 [ TRACE]:descrambler: CAT data (len 18)
2014-07-21 17:45:33.289 [ TRACE]:descrambler: 09 04 09 19 E1 2D 09 04 09 3B E1 2D 09 04 09 CD .....-...;.-....
2014-07-21 17:45:33.289 [ TRACE]:descrambler: E1 2D .-
2014-07-21 17:45:33.289 [ TRACE]:cwc: caid update event - mux 0x7f2a8806ded0 caid 0919 (2329) pid 012d (301) valid 1
2014-07-21 17:45:33.289 [ TRACE]:cwc: caid update event - mux 0x7f2a8806ded0 caid 093b (2363) pid 012d (301) valid 1
2014-07-21 17:45:33.289 [ TRACE]:cwc: caid update event - mux 0x7f2a8806ded0 caid 09cd (2509) pid 012d (301) valid 1
2014-07-21 17:45:33.289 [ TRACE]:descrambler: attach emm caid 09CD (2509) pid 012D (301)
2014-07-21 17:45:33.289 [ TRACE]:descrambler: mux 0x7f2a8806ded0 open pid 012D (301) (flags 0x0000)
2014-07-21 17:45:33.502 [ DEBUG]:cwc: Saving prefered PID 1807 for cwc-sam-65327
2014-07-21 17:45:33.502 [ DEBUG]:cwc: Received ECM reply (PID 1807) for service "Cinema Classics" even: 43.03.dd.23.03.92.6e.03 odd: 00.00.00.00.00.00.00.00 (seqno: 3 Req delay: 168 ms)
2014-07-21 17:45:33.502 [ DEBUG]:cwc: Obtained key for service "Cinema Classics" in 268 ms, from cwc-sam-65327
2014-07-21 17:45:33.502 [ DEBUG]:descrambler: Obtained keys from cwc-sam-65327 for service "Cinema Classics"
2014-07-21 17:45:33.502 [ TRACE]:descrambler: Obtained keys 4303DD2303926E03:0000000000000000 from cwc-sam-65327 for service "Cinema Classics"
2014-07-21 17:45:33.502 [WARNING]:cwc: Delete ECM (PID 1850) for service "Cinema Classics" from cwc-sam-65327
2014-07-21 17:45:33.952 [WARNING]:cwc: Got unexpected ECM reply (seqno: 4)
2014-07-21 17:45:35.660 [ DEBUG]:cwc: ECM state 2
2014-07-21 17:45:35.660 [ DEBUG]:cwc: Reset after unexpected or no reply for service "Cinema Classics"
2014-07-21 17:45:35.660 [ DEBUG]:cwc: Insert new ECM (PID 1850) for service "Cinema Classics"
2014-07-21 17:45:35.660 [ TRACE]:cwc: sending message sid 11109 len 210 enq 1
2014-07-21 17:45:35.660 [ TRACE]:cwc: 00 00 E1 EE CA 74 18 CF F6 FF E0 35 A7 2C 62 A6 .....t.....5.,b.
2014-07-21 17:45:35.660 [ TRACE]:cwc: 69 F6 C4 B6 CA 00 F0 C7 63 F7 C6 CA C3 B2 CC F9 i.......c.......
2014-07-21 17:45:35.660 [ TRACE]:cwc: E6 CB DB 8C 2B 79 A5 CC 3C F3 E1 C7 8F B5 3B 41 ....+y..<.....;A
2014-07-21 17:45:35.660 [ TRACE]:cwc: DC 11 6A 0C 39 9E 49 B5 AF C5 B3 E0 15 FA 84 11 ..j.9.I.........
2014-07-21 17:45:35.660 [ TRACE]:cwc: 13 7C 4A 27 7B 28 09 6F 37 1C AF 94 4B 30 C6 6A .|J'{(.o7...K0.j
2014-07-21 17:45:35.660 [ TRACE]:cwc: 95 85 78 6D B1 80 79 9F B1 1F 52 9A 32 9B F3 0F ..xm..y...R.2...
2014-07-21 17:45:35.660 [ TRACE]:cwc: EB E5 32 7F AC C7 64 F2 87 B9 B6 44 E8 91 47 88 ..2...d....D..G.
2014-07-21 17:45:35.660 [ TRACE]:cwc: 68 E7 37 AF 9D 14 F0 53 57 DE 24 39 B6 02 A3 F4 h.7....SW.$9....
2014-07-21 17:45:35.660 [ TRACE]:cwc: 94 12 13 77 7A DC CF D6 E3 A7 F5 A8 01 6D 0D C2 ...wz........m..
2014-07-21 17:45:35.660 [ TRACE]:cwc: 78 DB CA 13 CB 87 DA 2E A0 10 D3 0D 6D 19 3A 19 x...........m.:.
2014-07-21 17:45:35.660 [ TRACE]:cwc: E6 C7 4E 48 C2 01 5E 6A 8A A4 D1 0B 2F 17 8D 46 ..NH..^j..../..F
2014-07-21 17:45:35.660 [ TRACE]:cwc: F8 11 34 50 31 9A D4 C3 F0 74 BD 29 57 83 78 76 ..4P1....t.)W.xv
2014-07-21 17:45:35.660 [ TRACE]:cwc: 4C B1 28 EE FC C0 66 FF 0D DC 76 0F 0E 5A 25 52 L.(...f...v..Z%R
2014-07-21 17:45:35.660 [ TRACE]:cwc: 2E F9 ..
2014-07-21 17:45:35.660 [ DEBUG]:cwc: Sending ECM (PID 1850) section=0/0, for service "Cinema Classics" (seqno: 5)
2014-07-21 17:45:35.660 [ TRACE]:descrambler: ECM message (len 183, pid 1850) for service "Cinema Classics"
2014-07-21 17:45:36.914 [ DEBUG]:cwc: Saving prefered PID 1850 for cwc-sam-65327
2014-07-21 17:45:36.914 [ DEBUG]:cwc: Received ECM reply (PID 1850) for service "Cinema Classics" even: 00.00.00.00.00.00.00.00 odd: 9d.78.49.5e.39.9b.bd.91 (seqno: 5 Req delay: 152 ms)
2014-07-21 17:45:36.914 [ TRACE]:descrambler: Obtained keys 0000000000000000:9D78495E399BBD91 from cwc-sam-65327 for service "Cinema Classics"
2014-07-21 17:45:36.914 [WARNING]:cwc: Delete ECM (PID 1807) for service "Cinema Classics" from cwc-sam-65327
2014-07-21 17:45:42.655 [ DEBUG]:cwc: ECM state 1
2014-07-21 17:45:42.655 [ TRACE]:descrambler: ECM message (len 183, pid 1807) for service "Cinema Classics"
2014-07-21 17:45:43.215 [ TRACE]:descrambler: stream key changed to odd for service "Cinema Classics"
2014-07-21 17:45:45.640 [ TRACE]:cwc: sending message sid 11109 len 210 enq 1
2014-07-21 17:45:45.640 [ TRACE]:cwc: 00 00 27 22 C4 BA 32 C5 BE 23 B1 53 78 F6 CD 4F ..'"..2..#.Sx..O
2014-07-21 17:45:45.640 [ TRACE]:cwc: A3 99 60 99 65 03 F6 00 03 3B B5 FE 36 19 33 53 ..`.e....;..6.3S
2014-07-21 17:45:45.640 [ TRACE]:cwc: F4 82 99 7B 29 6D 93 8F 83 00 BC A9 35 09 C6 DD ...{)m......5...
2014-07-21 17:45:45.640 [ TRACE]:cwc: DD C5 10 00 95 7B C1 EA A4 FD 3E 2D 5E B1 4A 0F .....{....>-^.J.
2014-07-21 17:45:45.640 [ TRACE]:cwc: FE 55 F4 DA D4 98 CE 4B B6 2E 86 6F 63 AA 74 BB .U.....K...oc.t.
2014-07-21 17:45:45.640 [ TRACE]:cwc: 16 41 CD A4 3E EA E8 98 BF 4A 33 56 CF 9E 6D A1 .A..>....J3V..m.
2014-07-21 17:45:45.640 [ TRACE]:cwc: 1D E6 BE 71 E7 E9 85 E6 A6 ED 59 D2 D9 D1 E4 D7 ...q......Y.....
2014-07-21 17:45:45.640 [ TRACE]:cwc: AE 97 C0 D8 FE 0A 38 F3 1B B6 EF A7 7B 20 25 95 ......8.....{ %.
2014-07-21 17:45:45.640 [ TRACE]:cwc: CE C5 E7 F9 BF B7 7C CC 5A 7B 1B E3 6F EE 09 BD ......|.Z{..o...
2014-07-21 17:45:45.640 [ TRACE]:cwc: 4D 44 9F CC DC AF 53 F7 27 07 D7 66 60 AD 50 1C MD....S.'..f`.P.
2014-07-21 17:45:45.640 [ TRACE]:cwc: 46 2F F6 E6 80 0A 51 45 0F C4 10 AB A8 94 DC C5 F/....QE........
2014-07-21 17:45:45.640 [ TRACE]:cwc: 57 5D 51 24 90 11 B2 AA F6 A2 4D 24 4F E7 4E B1 W]Q$......M$O.N.
2014-07-21 17:45:45.640 [ TRACE]:cwc: 2B 43 0A 53 0F 29 A4 FC 91 68 9F D7 EF C9 C4 A7 +C.S.)...h......
2014-07-21 17:45:45.640 [ TRACE]:cwc: 9A 07 ..
2014-07-21 17:45:45.641 [ DEBUG]:cwc: Sending ECM (PID 1850) section=0/0, for service "Cinema Classics" (seqno: 6)
2014-07-21 17:45:45.641 [ TRACE]:descrambler: ECM message (len 183, pid 1850) for service "Cinema Classics"
2014-07-21 17:45:46.274 [ DEBUG]:cwc: Received ECM reply (PID 1850) for service "Cinema Classics" even: 4f.09.8c.e4.c9.ae.82.f9 odd: 00.00.00.00.00.00.00.00 (seqno: 6 Req delay: 136 ms)
2014-07-21 17:45:46.274 [ TRACE]:descrambler: Obtained keys 4F098CE4C9AE82F9:0000000000000000 from cwc-sam-65327 for service "Cinema Classics"
2014-07-21 17:45:52.639 [ DEBUG]:cwc: ECM state 1
2014-07-21 17:45:52.639 [ TRACE]:descrambler: ECM message (len 183, pid 1807) for service "Cinema Classics"@
Updated by Rob vh over 10 years ago
I have not seen this issue in several months. using both FTA (SD and HD) and Oscam (pc-nodmx).
Updated by Jaroslav Kysela over 10 years ago
- Status changed from Need feedback to Fixed