Tvheadend

I have a Terratec H7 DVB-C USB device with a CI slot.

If I use this receiver with Windows 7 and DVBViewer everything works (live TV on PC, recording, ...), also on the encrypted channels.

If I use this receiver with Linux (Debian Jessie), sometimes it works and sometimes it doesn't.

I have compiled TVHeadend 4.1-955 (from git).
The CA slot is detected in TVH and I have enabled it in the webinterface.

As a test, I scheduled small recording (2-3 minutes) in the DVR-section of the webinterface from 2 different channels (La Une HD and La Deux HD - both are Belgian Frenchspeaking public channels, both on the same mux too)

Recordings from La Une consistently succeed, while does from La Deux consistently fail.
First test was: record La Une first, record La Deux next.
If I schedule it like: La Deux - La Une or even Une - Deux - Une - Une - Deux - Deux the result is the same: recording from La Une are OK, the others fail.

If during a failed recording I check the tab 'status->subscriptions' I notice that

• state = testing (and not running)
• input = 0kb/s
• output = 0kb/s
  Despite that, the tab 'status-> stream' shows a normal bandwidth amount at the same time.

Is there anything I can try to get recording working more consistently?

I made a few logs with this setting: ./build.linux/tvheadend -d --noacl --trace en50221,dvbcam

This is the output from startup:
pi@raspberrypi ~/build/tvheadend/master $ ./build.linux/tvheadend -d --noacl --t race en50221,dvbcam
2015-11-12 12:21:39.089 [ INFO] main: Log started
2015-11-12 12:21:39.140 [ INFO] config: loaded
2015-11-12 12:21:40.052 [ INFO] scanfile: DVB-T - loaded 43 regions with 729 n etworks
2015-11-12 12:21:40.052 [ INFO] scanfile: DVB-S - loaded 1 regions with 92 net works
2015-11-12 12:21:40.052 [ INFO] scanfile: DVB-C - loaded 17 regions with 52 ne tworks
2015-11-12 12:21:40.052 [ INFO] scanfile: ATSC - loaded 2 regions with 14 netw orks
2015-11-12 12:21:40.859 [ INFO] linuxdvb: adapter added /dev/dvb/adapter0
2015-11-12 12:21:40.871 [ INFO] linuxdvb: adapter 0 setting exlusive flag
2015-11-12 12:21:40.876 [ INFO] dvr: Creating new configuration ''
2015-11-12 12:21:40.877 [WARNING] access: Access control checking disabled
2015-11-12 12:21:40.879 [ INFO] CSA: Using 32bit parallel descrambling
2015-11-12 12:21:40.880 [ INFO] descrambler: adding CAID 0963 as quick ECM (Sk y UK)
2015-11-12 12:21:40.880 [ INFO] descrambler: adding CAID 098C as quick ECM (Sk y DE)
2015-11-12 12:21:40.881 [ INFO] descrambler: adding CAID 09C4 as quick ECM (Sk y DE)
2015-11-12 12:21:40.881 [ INFO] descrambler: adding CAID 09CD as quick ECM (Sk y IT)
2015-11-12 12:21:40.882 [ INFO] epggrab: module eit created
2015-11-12 12:21:40.882 [ INFO] epggrab: module uk_freesat created
2015-11-12 12:21:40.883 [ INFO] epggrab: module uk_freeview created
2015-11-12 12:21:40.883 [ INFO] epggrab: module viasat_baltic created
2015-11-12 12:21:40.884 [ INFO] epggrab: module Bulsatcom_39E created
2015-11-12 12:21:40.884 [ INFO] epggrab: module psip created
2015-11-12 12:21:40.910 [ INFO] epggrab: module opentv-skyuk created
2015-11-12 12:21:40.913 [ INFO] epggrab: module opentv-ausat created
2015-11-12 12:21:40.914 [ INFO] epggrab: module opentv-skyit created
2015-11-12 12:21:40.920 [ INFO] epggrab: module opentv-skynz created
2015-11-12 12:21:40.926 [ INFO] epggrab: module pyepg created
2015-11-12 12:21:40.927 [ INFO] epggrab: module xmltv created
2015-11-12 12:21:40.973 [ INFO] epgdb: loaded v2
2015-11-12 12:21:40.973 [ INFO] epgdb: config 1
2015-11-12 12:21:40.974 [ INFO] epgdb: channels 0
2015-11-12 12:21:40.974 [ INFO] epgdb: brands 0
2015-11-12 12:21:40.975 [ INFO] epgdb: seasons 0
2015-11-12 12:21:40.975 [ INFO] epgdb: episodes 315
2015-11-12 12:21:40.976 [ INFO] epgdb: broadcasts 97
2015-11-12 12:21:40.990 [ NOTICE] START: HTS Tvheadend version 4.1-955~ge9a7b3c started, running as PID:12377 UID:1000 GID:1000, CWD:/home/pi/build/tvheadend/ma ster CNF:/home/pi/.hts/tvheadend
2015-11-12 12:21:41.121 [ INFO] linuxdvb: CAM slot 0 status changed to module present
2015-11-12 12:21:41.866 [ INFO] AVAHI: Service 'Tvheadend' successfully established.
2015-11-12 12:21:46.873 [ INFO] linuxdvb: CAM slot 0 status changed to module ready
en50221_tl_handle_sb: Received T_SB for connection not in T_STATE_ACTIVE from module on slot 00

2015-11-12 12:21:46.877 [ ERROR] en50221: poll error on slot 0 [error:-7]
2015-11-12 12:21:46.963 [ TRACE] en50221: 0x00000000 session 1 tc connect
2015-11-12 12:21:47.165 [ TRACE] en50221: 0x00010041 session 1 connecting
2015-11-12 12:21:47.165 [ TRACE] en50221: 0x00010041 session 1 connected
2015-11-12 12:21:47.466 [ TRACE] en50221: rm reply cb received for slot 0, count 0
2015-11-12 12:21:47.766 [ TRACE] en50221: rm enq callback received for slot 0
2015-11-12 12:21:48.105 [ TRACE] en50221: 0x00020041 session 2 connecting
2015-11-12 12:21:48.105 [ TRACE] en50221: 0x00020041 session 2 connected
2015-11-12 12:21:48.412 [ INFO] en50221: CAM slot 0: Application type: 01, manufacturer: 0001, Manufacturer code: 0001
2015-11-12 12:21:48.412 [ INFO] en50221: CAM slot 0: Menu string: Cobra 01.90
2015-11-12 12:21:48.515 [ TRACE] en50221: 0x00030041 session 3 connecting
2015-11-12 12:21:48.515 [ TRACE] en50221: 0x00030041 session 3 connected
2015-11-12 12:21:48.858 [ TRACE] dvbcam: unregister cam lca 0x1f71630 slot 0
2015-11-12 12:21:48.858 [ TRACE] dvbcam: register cam ca 0x1f71630 slot 0 num_caids 56
2015-11-12 12:21:48.858 [ INFO] en50221: CAM slot 0 supported CAIDs: 0100 (Seca) 1801 (NagraVision) 090F (NDS) 093E (NDS) 0500 (Viaccess) 098C (NDS) 09C4 (NDS) 0D95 (CryptoWorks ICE) 0D98 (CryptoWorks ICE) 1702 (BetaCrypt) 1830 (NagraVision) 1843 (NagraVision) 1860 (NagraVision) 186A (NagraVision) 098E (NDS) 09C7 (NDS) 18
2015-11-12 12:21:48.969 [ TRACE] dvbcam: unregister cam lca 0x1f71630 slot 0
2015-11-12 12:21:48.969 [ TRACE] dvbcam: register cam ca 0x1f71630 slot 0 num_caids 4
2015-11-12 12:21:48.969 [ INFO] en50221: CAM slot 0 supported CAIDs: 0100 (Seca) 1801 (NagraVision) 090F (NDS) 093E (NDS)

The output from a succesful recording (La Une HD)
2015-11-12 12:27:00.000 [ INFO] dvr: "test rpi 1201" on "La Une HD" recorder starting
2015-11-12 12:27:00.005 [ INFO] mpegts: 338MHz in My DVB-C - tuning on DRXK DVB-C DVB-T : DVB-C #0
2015-11-12 12:27:00.008 [ TRACE] dvbcam: start service 0x1f69168
2015-11-12 12:27:00.009 [ INFO] subscription: 0001: "DVR: test rpi 1201" subscribing on channel "La Une HD", weight: 500, adapter: "DRXK DVB-C DVB-T : DVB-C #0", network: "My DVB-C", mux: "338MHz", provider: "Telenet", service: "La Une HD", profile="pass"
2015-11-12 12:27:00.536 [ TRACE] dvbcam: start service 0x1f69168
2015-11-12 12:27:00.554 [ INFO] dvr: /home/pi/Videos/test rpi 1201.ts from adapter: "DRXK DVB-C DVB-T : DVB-C #0", network: "My DVB-C", mux: "338MHz", provider: "Telenet", service: "La Une HD"
2015-11-12 12:27:00.555 [ INFO] dvr: # type lang resolution aspect ratio sample rate channels
2015-11-12 12:27:00.555 [ INFO] dvr: 1 H264 ? ?
2015-11-12 12:27:00.555 [ INFO] dvr: 2 MPEG2AUDIO fre ? ?
2015-11-12 12:27:00.555 [ INFO] dvr: 3 TELETEXT
2015-11-12 12:27:00.556 [ INFO] dvr: 4 MPEG2AUDIO und ? ?
2015-11-12 12:27:00.556 [ INFO] dvr: 5 CA
2015-11-12 12:27:00.556 [ INFO] dvr: 6 CA
2015-11-12 12:27:00.556 [ INFO] dvr: 7 CA
2015-11-12 12:27:00.557 [ INFO] dvr: 8 CA
2015-11-12 12:27:00.716 [ TRACE] dvbcam: found active cam entry
2015-11-12 12:27:00.716 [ TRACE] en50221: ok_descrambling CAPMT enqueued (only)
2015-11-12 12:27:00.766 [ TRACE] en50221: ok_descrambling CAPMT sent (only)
2015-11-12 12:27:00.766 [ TRACE] en50221: 03 07 13 2B 00 24 01 09 04 18 01 E7 DB 09 04 18 ...+.$..........
2015-11-12 12:27:00.766 [ TRACE] en50221: 61 E8 3F 09 04 4A C1 E8 A3 09 0F 05 00 E9 07 10 a.?..J..........
2015-11-12 12:27:00.766 [ TRACE] en50221: 01 00 13 01 20 14 03 05 1C 00 0B 00 36 00 00 0B .... .......6...
2015-11-12 12:27:00.766 [ TRACE] en50221: 00 37 00 00 0B 00 38 00 00 0B 00 39 00 00 0B 00 .7....8....9....
2015-11-12 12:27:00.767 [ TRACE] en50221: 3A 00 00 1B 10 05 00 00 04 10 06 00 00 06 10 07 :...............
2015-11-12 12:27:00.767 [ TRACE] en50221: 00 00 04 10 0A 00 00 05 1F 73 00 00 0B 1F 74 00 .........s....t.
2015-11-12 12:27:00.767 [ TRACE] en50221: 00 .
2015-11-12 12:29:30.271 [ INFO] subscription: 0001: "DVR: test rpi 1201" unsubscribing from "La Une HD"
2015-11-12 12:29:30.276 [ TRACE] dvbcam: stop service 0x1f69168
2015-11-12 12:29:30.276 [ TRACE] en50221: not_selected CAPMT enqueued (update)
2015-11-12 12:29:30.276 [ INFO] dvr: "test rpi 1201" on "La Une HD": End of program: Completed OK
2015-11-12 12:29:31.072 [ TRACE] en50221: not_selected CAPMT sent (update)
2015-11-12 12:29:31.072 [ TRACE] en50221: 05 07 13 2B 00 24 04 09 04 18 01 E7 DB 09 04 18 ...+.$..........
2015-11-12 12:29:31.072 [ TRACE] en50221: 61 E8 3F 09 04 4A C1 E8 A3 09 0F 05 00 E9 07 10 a.?..J..........
2015-11-12 12:29:31.072 [ TRACE] en50221: 01 00 13 01 20 14 03 05 1C 00 0B 00 36 00 00 0B .... .......6...
2015-11-12 12:29:31.072 [ TRACE] en50221: 00 37 00 00 0B 00 38 00 00 0B 00 39 00 00 0B 00 .7....8....9....
2015-11-12 12:29:31.073 [ TRACE] en50221: 3A 00 00 1B 10 05 00 00 04 10 06 00 00 06 10 07 :...............
2015-11-12 12:29:31.073 [ TRACE] en50221: 00 00 04 10 0A 00 00 05 1F 73 00 00 0B 1F 74 00 .........s....t.
2015-11-12 12:29:31.073 [ TRACE] en50221: 00

The output from a failed recording (La Deux HD)
2015-11-12 12:30:30.000 [ INFO] dvr: "test rpi 1202" on "La Deux HD" recorder starting
2015-11-12 12:30:30.001 [ INFO] mpegts: 338MHz in My DVB-C - tuning on DRXK DVB-C DVB-T : DVB-C #0
2015-11-12 12:30:30.002 [ TRACE] dvbcam: start service 0x1f68240
2015-11-12 12:30:30.003 [ INFO] subscription: 0002: "DVR: test rpi 1202" subscribing on channel "La Deux HD", weight: 500, adapter: "DRXK DVB-C DVB-T : DVB-C #0", network: "My DVB-C", mux: "338MHz", provider: "Telenet", service: "La Deux HD", profile="pass"
2015-11-12 12:30:30.658 [ TRACE] dvbcam: found active cam entry
2015-11-12 12:30:30.658 [ TRACE] en50221: ok_descrambling CAPMT enqueued (only)
2015-11-12 12:30:30.708 [ TRACE] en50221: ok_descrambling CAPMT sent (only)
2015-11-12 12:30:30.709 [ TRACE] en50221: 03 07 14 0D 00 24 01 09 04 18 01 E7 DC 09 04 18 .....$..........
2015-11-12 12:30:30.709 [ TRACE] en50221: 61 E8 40 09 04 4A C1 E8 A4 09 0F 05 00 E9 08 10 a...J..........
2015-11-12 12:30:30.710 [ TRACE] en50221: 01 00 13 01 20 14 03 05 1C 00 0B 00 36 00 00 0B .... .......6...
2015-11-12 12:30:30.710 [ TRACE] en50221: 00 37 00 00 0B 00 38 00 00 0B 00 39 00 00 0B 00 .7....8....9....
2015-11-12 12:30:30.710 [ TRACE] en50221: 3A 00 00 1B 10 69 00 00 04 10 6A 00 00 06 10 6B :....i....j....k
2015-11-12 12:30:30.711 [ TRACE] en50221: 00 00 04 10 6E 00 00 05 1F 73 00 00 0B 1F 74 00 ....n....s....t.
2015-11-12 12:30:30.711 [ TRACE] en50221: 00 .
2015-11-12 12:30:32.910 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 1)
2015-11-12 12:30:46.870 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 24)
2015-11-12 12:30:57.326 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 45)
2015-11-12 12:31:08.083 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 65)
2015-11-12 12:31:19.063 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 87)
2015-11-12 12:31:30.447 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 112)
2015-11-12 12:31:41.974 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 141)
2015-11-12 12:31:53.040 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 162)
2015-11-12 12:32:04.423 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 185)
2015-11-12 12:32:15.042 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 204)
2015-11-12 12:32:26.445 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 222)
2015-11-12 12:32:37.588 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 240)
2015-11-12 12:32:49.385 [WARNING] TS: My DVB-C/338MHz/La Deux HD: H264 #4201 Continuity counter error (total 259)
2015-11-12 12:33:00.000 [ INFO] subscription: 0002: "DVR: test rpi 1202" unsubscribing from "La Deux HD"
2015-11-12 12:33:00.003 [ TRACE] dvbcam: stop service 0x1f68240
2015-11-12 12:33:00.003 [ TRACE] en50221: not_selected CAPMT enqueued (update)
2015-11-12 12:33:00.004 [ INFO] dvr: "test rpi 1202" on "La Deux HD": End of program: Time missed
2015-11-12 12:33:00.054 [ TRACE] en50221: not_selected CAPMT sent (update)
2015-11-12 12:33:00.054 [ TRACE] en50221: 05 07 14 0D 00 24 04 09 04 18 01 E7 DC 09 04 18 .....$..........
2015-11-12 12:33:00.054 [ TRACE] en50221: 61 E8 40 09 04 4A C1 E8 A4 09 0F 05 00 E9 08 10 [email protected]..........
2015-11-12 12:33:00.054 [ TRACE] en50221: 01 00 13 01 20 14 03 05 1C 00 0B 00 36 00 00 0B .... .......6...
2015-11-12 12:33:00.054 [ TRACE] en50221: 00 37 00 00 0B 00 38 00 00 0B 00 39 00 00 0B 00 .7....8....9....
2015-11-12 12:33:00.054 [ TRACE] en50221: 3A 00 00 1B 10 69 00 00 04 10 6A 00 00 06 10 6B :....i....j....k
2015-11-12 12:33:00.054 [ TRACE] en50221: 00 00 04 10 6E 00 00 05 1F 73 00 00 0B 1F 74 00 ....n....s....t.
2015-11-12 12:33:00.054 [ TRACE] en50221: 00 .

Someone from the Dutch 'tweakers.net' community referred me to your forum and to this issue in particular: https://tvheadend.org/issues/2794