Project

General

Profile

Actions

Bug #5459

closed

Something is slow in 4.3

Added by Robin Mitra over 6 years ago. Updated almost 5 years ago.

Status:
Fixed
Priority:
Normal
Assignee:
-
Category:
Descrambling
Target version:
-
Start date:
2019-06-16
Due date:
% Done:

100%

Estimated time:
(Total: 0:00 h)
Found in version:
last few commits since october 2018 -- December 2018, current:4.3-1690~gb3899e3fd
Affected Versions:

Description

I am seeing quite a number of descrambling errors.
It seems there is an issue with mesage sequencing/reordering when talking to oscam.
Here is an excerpt of a debug log when such errors happen:

2018-12-26 13:43:33.102 [ INFO]:subscription: 0055: "epggrab" unsubscribing
2018-12-26 13:43:34.103 [ INFO]:mpegts: 11347V in ASTRA 192 - tuning on DD4
2018-12-26 13:43:36.538 [ DEBUG]:descrambler: no key for service='Fox HD'
2018-12-26 13:43:36.538 [WARNING]:TS: ASTRA 192/12304H/Fox HD: H264 #2559 Continuity counter error (total 458)
2018-12-26 13:43:36.538 [WARNING]:TS: ASTRA 192/12304H/Fox HD: AC3
#2564 Continuity counter error (total 175)
2018-12-26 13:43:36.538 [WARNING]:TS: ASTRA 192/12304H/Fox HD: AC3 @ #2563 Continuity counter error (total 168)
2018-12-26 13:43:37.074 [ INFO]:subscription: 006F: "epggrab" subscribing to mux "11347V", weight: 4, adapter: "DD4", network: "ASTRA 192", service: "Raw PID Subscription"
2018-12-26 13:43:37.580 [ DEBUG]:cwc: 192.168.1.10:33002: Reset after unexpected or no reply for service "Fox HD"
2018-12-26 13:43:37.580 [ DEBUG]:cwc: 192.168.1.10:33002: ECM state INIT
2018-12-26 13:43:37.580 [ DEBUG]:cwc: 192.168.1.10:33002: Insert new ECM (PID 6937) for service "Fox HD"
2018-12-26 13:43:37.580 [ DEBUG]:cwc: 192.168.1.10:33002: Sending ECM (PID 6937) section=0/0 for service "Fox HD" (seqno: 471)
2018-12-26 13:43:37.581 [ DEBUG]:cwc: 192.168.1.10:33002: Sending ECM (PID 6937) section=0/0 for service "Fox HD" (seqno: 472)
2018-12-26 13:43:37.589 [WARNING]:cwc: 192.168.1.10:33002: Got unexpected ECM reply (seqno: 471)
2018-12-26 13:43:37.739 [ DEBUG]:cwc: 192.168.1.10:33002: Saving prefered PID 6937 for newcamd-192.168.1.10:33002-09C4
2018-12-26 13:43:37.739 [ DEBUG]:cwc: 192.168.1.10:33002: Received ECM reply (PID 6937) for service "Fox HD" [0] (seqno: 472 Req delay: 156 ms)
2018-12-26 13:43:37.739 [ DEBUG]:cwc: 192.168.1.10:33002: Obtained DES keys for service "Fox HD" in 156 ms, from newcamd-192.168.1.10:33002-09C4
2018-12-26 13:43:37.739 [ DEBUG]:descrambler: Obtained CSA keys from newcamd-192.168.1.10:33002-09C4 for service "Fox HD"
2018-12-26 13:43:37.739 [ DEBUG]:descrambler: info - service='Fox HD' caid=09C4(NDS) provid=000000 ecmtime=156 hops=1 reader='' from='192.168.1.10:33002' protocol='newcamd'
2018-12-26 13:43:39.065 [ ERROR]:descrambler: cannot decode packets for service "Fox HD"
2018-12-26 13:43:39.069 [ ERROR]:tsfix: transport stream H264, DTS discontinuity. DTS = 88357454, last = 88235054
2018-12-26 13:43:39.086 [ ERROR]:tsfix: transport stream AC3, DTS discontinuity. DTS = 88292880, last = 88148880
2018-12-26 13:43:39.087 [ ERROR]:tsfix: transport stream AC3, DTS discontinuity. DTS = 88294814, last = 88150814
2018-12-26 13:43:42.929 [ DEBUG]:cwc: 192.168.1.10:33002: Sending ECM (PID 6937) section=0/0 for service "Fox HD" (seqno: 473)
2018-12-26 13:43:43.078 [ DEBUG]:cwc: 192.168.1.10:33002: Received ECM reply (PID 6937) for service "Fox HD" [0] (seqno: 473 Req delay: 148 ms)
2018-12-26 13:43:43.078 [ DEBUG]:descrambler: info - service='Fox HD' caid=09C4(NDS) provid=000000 ecmtime=148 hops=1 reader='' from='192.168.1.10:33002' protocol='newcamd'

Please let me know what specific other logs(or traces) I should enable to help with this.
Thx.


Files

tvheadend.zip (1.28 MB) tvheadend.zip Robin Mitra, 2019-01-13 16:17
tvheadend.2019-01-20.log.zip (46.9 KB) tvheadend.2019-01-20.log.zip Robin Mitra, 2019-01-20 13:06

Subtasks 1 (0 open1 closed)

Bug #5659: Descrambler issues in 4.3Fixed2019-06-16

Actions
Actions

Also available in: Atom PDF