Project

General

Profile

Bug #4876

Got unexpected ECM reply (seqno: xxxx)

Added by saen acro over 3 years ago. Updated over 3 years ago.

Status:
Invalid
Priority:
Normal
Assignee:
-
Category:
Descrambling
Target version:
-
Start date:
2018-02-08
Due date:
% Done:

0%

Estimated time:
(Total: 0.00 h)
Found in version:
4.3.98x+
Affected Versions:

Description

Channel descrambled but log full

2018-01-20 00:27:37.199 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52551)
2018-01-20 00:27:37.499 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52552)
2018-01-20 00:27:47.405 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52618)
2018-01-20 00:27:57.315 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52684)
2018-01-20 00:27:57.326 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52686)
2018-01-20 00:28:07.206 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52752)
2018-01-20 00:28:07.501 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52753)
2018-01-20 00:28:07.524 cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 52755)

OSCam: 1.20-unstable_svn Build: r11392 Compiler: x86_64-linux-gnu-ssl

2018/01/20 00:24:54 14C0EB16 c      (ecm) tvheadend ([email protected]/0009/03F4/34:A4BF4866A1E78CD70519DCDD99BC8043): cache1 (10 ms) by reader - channel (cw count 3)
2018/01/20 00:24:54 14C0EB16 c      (ecm) tvheadend ([email protected]/000F/03F4/34:82C288E33249A60A013C3CDD1E355849): cache1 (10 ms) by reader - channel (cw count 3)
2018/01/20 00:26:47 14C0EB16 c      (ecm) tvheadend ([email protected]/0009/03F4/34:6823FC91010170B85776423AD3E8BFCC): cache1 (11 ms) by reader - channel
2018/01/20 00:26:47 14C0EB16 c      (ecm) tvheadend ([email protected]/0009/03F4/34:6823FC91010170B85776423AD3E8BFCC): cache1 (10 ms) by reader - channel
2018/01/20 00:26:47 14C0EB16 c      (ecm) tvheadend ([email protected]/000F/03F4/34:86E0E007E4295C4E2F2E7E526BA1ADB5): cache1 (10 ms) by reader - channel
2018/01/20 00:26:47 14C0EB16 c      (ecm) tvheadend ([email protected]/000F/03F4/34:86E0E007E4295C4E2F2E7E526BA1ADB5): found (322 ms) by reader - channel


Files

cwc.log.txt.bz2 (92.4 KB) cwc.log.txt.bz2 saen acro, 2018-01-20 21:10
tvh.log (209 KB) tvh.log Philippe Larcher, 2018-01-23 23:17
NewTVHlog.txt (77.4 KB) NewTVHlog.txt New TVH Log Philippe Larcher, 2018-01-25 19:13

Subtasks

Bug #4924: PVu: Add newcamd supportAccepted

Actions

Associated revisions

Revision 3e55aafd (diff)
Added by Jaroslav Kysela over 3 years ago

cclient: try to fix duplicate ECM requests for multiple sections, issue #4876

Revision b16e53cb (diff)
Added by Jaroslav Kysela over 3 years ago

cclient: handle send_ecm return value correctly, issue #4876

History

#1

Updated by Jaroslav Kysela over 3 years ago

'--trace cwc'

#2

Updated by saen acro over 3 years ago

Key come from 127.0.0.1:10005
CAID 0604

#3

Updated by Jaroslav Kysela over 3 years ago

It seems that it's a multi-section ECM issue:

[  DEBUG]:cwc: 127.0.0.1:10005: Sending ECM (PID 3305) section=0/1 for service "KinoNova" (seqno: 4603)
[  DEBUG]:cwc: 127.0.0.1:10005: Sending ECM (PID 3305) section=1/1 for service "KinoNova" (seqno: 4604)
[  DEBUG]:cwc: 127.0.0.1:10005: Sending ECM (PID 3305) section=0/1 for service "KinoNova" (seqno: 4605)
[  DEBUG]:cwc: 127.0.0.1:10005: Sending ECM (PID 3305) section=1/1 for service "KinoNova" (seqno: 4606)
[WARNING]:cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 4604)
[  DEBUG]:cwc: 127.0.0.1:10005: Sending ECM (PID 3305) section=0/1 for service "KinoNova" (seqno: 4607)
[  DEBUG]:cwc: 127.0.0.1:10005: Sending ECM (PID 3305) section=1/1 for service "KinoNova" (seqno: 4608)
[  DEBUG]:cwc: 127.0.0.1:10005: Received ECM reply (PID 3305) for service "KinoNova" [0] (seqno: 4607 Req delay: 12 ms)
[WARNING]:cwc: 127.0.0.1:10005: Got unexpected ECM reply (seqno: 4606)
#4

Updated by Jaroslav Kysela over 3 years ago

Try latest v4.3-995-g9bdd7470d

#5

Updated by Philippe Larcher over 3 years ago

v4.3-995-g9bdd7470d

Having the same bug with the above version.

Waiting for fix.

#7

Updated by Philippe Larcher over 3 years ago

I hope this log file is fine for analysis.

My CCCam Server is working with other clients without problems f.y.i.

Thank you for your help & time, I hope you find a solution.

#8

Updated by Philippe Larcher over 3 years ago

Philippe Larcher wrote:

I hope this log file is fine for analysis.

My CCCam Server is working with other clients without problems f.y.i.

Thank you for your help & time, I hope you find a solution.

2018-01-23 23:13:04.057 mpegts: 12304.5H in Astra scan complete
2018-01-23 23:13:04.057 subscription: 049A: "scan" unsubscribing
2018-01-23 23:13:07.572 cwc: localhost:54545: Disconnected
2018-01-23 23:13:07.572 cwc: localhost:54545: Inactive, thread exit
2018-01-23 23:13:14.024 mpegts: 12304.5H in Astra - tuning on Montage Technology M88RS6000 #0 : master for #0
2018-01-23 23:13:14.074 subscription: 049C: "scan" subscribing to mux "12304.5H", weight: 2, adapter: "Montage Technology M88RS6000 #0 : master for #0", network: "Astra", service: "Raw PID Subscription"
2018-01-23 23:13:26.423 http: 192.168.178.25: using ticket 0198b6521876573bbaa0c9605af70a769241c3fc for /stream/channelid/398327299
2018-01-23 23:13:26.424 subscription: 049F: "HTTP" subscribing on channel "Sky Cinema Hits HD", weight: 100, adapter: "Montage Technology M88RS6000 #0 : master for #0", network: "Astra", mux: "12304.5H", provider: "SKY", service: "Sky Cinema Hits HD", profile="pass", hostname="192.168.178.25", client="VLC/2.2.6 LibVLC/2.2.6"
2018-01-23 23:13:26.612 cccam: >IP<:54345: Ignore ECM request 80 (server is busy)
2018-01-23 23:13:29.837 cccam: >IP<:54345: Ignore ECM request 81 (server is busy)
2018-01-23 23:13:31.215 TS: Astra/12304.5H/Sky Cinema Hits HD: H264
#767 Continuity counter error (total 1)
2018-01-23 23:13:33.814 mpegts: 12304.5H in Astra scan complete
2018-01-23 23:13:33.814 subscription: 049C: "scan" unsubscribing
2018-01-23 23:13:36.851 cccam: >IP<:54345: Ignore ECM request 80 (server is busy)
2018-01-23 23:13:41.735 TS: Astra/12304.5H/Sky Cinema Hits HD: H264 #767 Continuity counter error (total 8)
2018-01-23 23:13:43.864 cccam: >IP<:54345: Ignore ECM request 81 (server is busy)
2018-01-23 23:13:50.847 cccam: >IP<:54345: Ignore ECM request 80 (server is busy)

#9

Updated by Jaroslav Kysela over 3 years ago

Phillipe - it appears like a different issue than in the original report. Upgrade to latest and create a new bug-report with '--trace cccam' (I need to see the log before 'server is busy' occurs).

#10

Updated by Philippe Larcher over 3 years ago

Hey,
here is the new log with log before server is busy. Thanks for helping

#11

Updated by Jaroslav Kysela over 3 years ago

I can only guess:

2018-01-25 19:01:27.346 [WARNING]:subscription: 45DE: service instance is bad, reason: No descrambler

I already pushed a change to the master which clears the busy flag when the service is closed on the tvheadend's side.

#12

Updated by Philippe Larcher over 3 years ago

Still having this problem with version: HTS Tvheadend 4.3-1028~g7de759e83

2018-02-01 21:15:50.658 cccam: >IP<:54345: Got unexpected ECM reply (seqno: 1)
2018-02-01 21:15:51.329 TS: Astra/12304.5H/Sky Cinema Superhelden HD: H264
#767 Continuity counter error (total 1)
2018-02-01 21:15:56.371 mpegts: 12304.5H in Astra scan complete
2018-02-01 21:16:01.380 TS: Astra/12304.5H/Sky Cinema Superhelden HD: H264 #767 Continuity counter error (total 16)
2018-02-01 21:16:02.037 cccam: >IP<:54345: Ignore ECM request 80 (server is busy)

#13

Updated by Jaroslav Kysela over 3 years ago

Show full uncut logs.

#14

Updated by Jaroslav Kysela over 3 years ago

  • Status changed from New to Invalid

No further response.

#15

Updated by navaneeta harsha over 3 years ago

-

Also available in: Atom PDF