Bug #3516
CAPMT server timeout
0%
Description
A couple of days ago I switched to tvheadend-1392. Unfortunately I encountered some bugs of which this one is really annoying.
Sometimes it happens that after a recording has finished an other running recording gets a timeout from the CAPMT server.
2016-01-21 20:30:00.010 subscription: 002E: "DVR: Great British Railway Journeys" unsubscribing from "BBC Two HD"
2016-01-21 20:30:00.011 capmt: Ziggo: Removing CAPMT Server from service "BBC Two HD" on adapter 1
2016-01-21 20:30:00.013 dvr: "Great British Railway Journeys" on "BBC Two HD": End of program: Completed OK
2016-01-21 20:30:26.101 descrambler: ECM - key late (40 seconds) for service "ARD HD"
2016-01-21 20:30:27.293 TS: Ziggo/562MHz/ARD HD: H264 #3801 Continuity counter error (total 1) #3901 Continuity counter error (total 1)
2016-01-21 20:30:27.293 TS: Ziggo/562MHz/ARD HD: TELETEXT
2016-01-21 20:30:27.293 TS: Ziggo/562MHz/ARD HD: AC3 #3812 Continuity counter error (total 1) #3811 Continuity counter error (total 1)
2016-01-21 20:30:27.293 TS: Ziggo/562MHz/ARD HD: MPEG2AUDIO
2016-01-21 20:30:27.293 descrambler: cannot decode packets for service "ARD HD"
2016-01-21 20:30:38.108 descrambler: cannot decode packets for service "ARD HD"
As this descrambler problem is irrecoverable for tvh its quite annoying. Not only results this in a very long list of error messages there is not much that can be done then to quit the recording and restart it by hand. When I quit the recording then the same happened with another running recording.
2016-01-21 21:00:20.106 descrambler: cannot decode packets for service "ARD HD"
2016-01-21 21:00:26.797 subscription: 002F: "DVR: Hubert und Staller - Unter Wölfen" unsubscribing from "ARD HD"
2016-01-21 21:00:26.797 capmt: Ziggo: Removing CAPMT Server from service "ARD HD" on adapter 2
2016-01-21 21:00:26.801 dvr: "Hubert und Staller - Unter Wölfen" on "ARD HD": End of program: Aborted by user
2016-01-21 21:00:26.801 dvr: delete entry 70b8ee7bf5128711e6611c10b6833872 "Hubert und Staller - Unter Wölfen" on "ARD HD" start time 2016-01-21 20:12:30, scheduled for recording by "192.168.178.12", retention "600 days" removal "Forever"
2016-01-21 21:01:05.420 descrambler: ECM - key late (40 seconds) for service "WDR"
2016-01-21 21:01:07.610 TS: Ziggo/794MHz/WDR: MPEG2VIDEO #2901 Continuity counter error (total 1) #3001 Continuity counter error (total 1)
2016-01-21 21:01:07.610 TS: Ziggo/794MHz/WDR: TELETEXT
2016-01-21 21:01:07.610 TS: Ziggo/794MHz/WDR: MPEG2AUDIO @ #2911 Continuity counter error (total 1)
2016-01-21 21:01:07.610 descrambler: cannot decode packets for service "WDR"
2016-01-21 21:01:18.000 descrambler: cannot decode packets for service "WDR"
2016-01-21 21:01:29.055 descrambler: cannot decode packets for service "WDR"
2016-01-21 21:01:30.930 subscription: 0030: "DVR: Tatort" unsubscribing from "WDR"
2016-01-21 21:01:30.931 capmt: Ziggo: Removing CAPMT Server from service "WDR" on adapter 3
2016-01-21 21:01:30.931 dvr: "Tatort" on "WDR": End of program: Aborted by user
2016-01-21 21:01:30.934 dvr: delete entry cdfb27fa50be6aec59b19773162723a2 "Tatort" on "WDR" start time 2016-01-21 20:12:30, scheduled for recording by "192.168.178.12", retention "600 days" removal "Forever"
This cascading of 'descrambler: ECM - key late (40 seconds)' errors did not continue after aborting the WDR recording and the last running recording finished normally.
Speculating about what goes wrong after a recording has finished: it looks like that the communication between tvh and oscam is broken for the recording in question. Maybe reordering of the communication links on one side is not (fully) done on the other side of the link.
I know that in the previous version of tvh (377) I used, there was a minor non-fatal EMM writing problem after removing the first recording during a multi recoding session which had to do with the fact that the EMM writing was only coupled with the first connection link on the side of oscam.
This bug however, is much more serious and I really hope it will be solved. In the mean time I have to revert back to version 377 as my recording with tvh is normally unattended.
Keep up the great work,
Baderks
Files
History
Updated by Jaroslav Kysela almost 9 years ago
Updated by Attach '--trace campt,descrambler' logs when this occurs, also show the debug log from oscam (level 128).
Updated by B.A. Derks almost 9 years ago
Updated by - File oscam 22-01-2016 22.30.log oscam 22-01-2016 22.30.log added
- File tvheadend 22-01-2016 22.30.log tvheadend 22-01-2016 22.30.log added
Thanks for your reaction. I tried to force with no success the 'descrambler: ECM - key late (40 seconds)' error. Tonight during normal recording it happened again, including the cascading. I have included the oscam (level 128) and tvh logs. Unfortunately I'm not able to compile tvh with traces as I run tvh under OpenElec on a mini PC. I got my recent copy of tvh from http://build.mycvh.de/Tvh/.
I hope these two logfiles give you an idea of what is going wrong.
Baderks
Updated by B.A. Derks almost 9 years ago
It happened for the second time this evening. The common factor at both instances was the fact that 2 automatic recordings did finish at exactly the same time while other recordings were still in progress. Not long after those two recording where finished the 'descrambler: ECM - key late (40 seconds)' error occurred. Maybe this is the clue.
Enjoy the puzzle, Baderks
Updated by Jaroslav Kysela almost 9 years ago
2016/01/22 22:35:00 55C0F7B9 c (dvbapi) Demuxer 0 stop descrambling program number 4BA2 (één HD)
You've not provided traces for tvh nor level 128 logs for oscam, so I cannot dig into this more...
Updated by B.A. Derks almost 9 years ago
I got myself a Linux environment on a USB-stick and I eventually managed to compile tvheadend whitch allowed me to use the debug/trace facility of the capmt module. I also managed to compile oscam with debugging activated. I ended up with tvheadend-4.1-1429 and oscam-11209 to get the tracing logs of capmt. Whatever I tried, I was not able to reproduce the problems I got before. So, after a couple of days of testing, I come to the conclusion that wittingly or unwittingly, somewhere between the version 1392 and 1429, the capmt bug has been solved or circumvented. Anyhow, I'm glad I can use tvheadend for unattended daily usage again.
Thank you for your time and effort and keep up this great work,
Baderks