Project

General

Profile

Bug #5256

DVR: major issue: recordings from Sky.DE often fail with no file written [master git]

Added by da h4xX0rz1sT about 6 years ago. Updated about 6 years ago.

Status:
Fixed
Priority:
Normal
Assignee:
Adam Sutton
Category:
PVR / DVR
Target version:
-
Start date:
2018-10-14
Due date:
% Done:

0%

Estimated time:
Found in version:
4.3-1468~g3f74523d2
Affected Versions:

Description

This is reopen of rejected bug #5211. This issue seems to apply for master as well. Old description (with updates) following.

  • transport errors at the beginning of the recording can cause this
  • descramble or "Unexpected ECM reply" errors can cause this on encrypted channels
  • on start of recording, log does not show the typical "lang resolution aspect ratio sample rate channels" lines (seems it does not detect the streams)
  • on start of recording, trace dvr log does not show (seems to be new trace message on master)
  • during recording, a file size "---" is shown constantly
  • during recording, status shows a output bandwidth of "0"
  • at the end of recording, log shows "time missed"
  • after recording, it shows up in "deleted recordings" with status "file missing"
  • this never happens if the affected channel is already streamed before recording starts (seems not to apply with master, was in 4.2x)
  • most probably retries are missing when recording

Steps to reproduce:
Record from sky.de, at least one of ten recordings fails with that issue, probably more

Environment:
CWs are working, 100% success in oscam

Log from latest master with "--trace dvr" when it worked:

Oct 14 16:18:30 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - assign broadcast 67145163
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) - set timer - schedule
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f "Planet der Affen: Survival" on "Sky Cinema" starting at 2018-10-14 15:54:30, with broadcast id "<noid>", scheduled for recording by "admin" 
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) - set timer - schedule
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) - set timer - schedule
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - set state - state RECORDING rec_state PENDING error 'OK'
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: "Planet der Affen: Survival" on "Sky Cinema" recorder starting
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f original stop 2018-10-14;18:15:00(+0200) stop 2018-10-14;18:15:00(+0200) - stop timer set
Oct 14 16:18:37 TVHserver tvheadend[18803]: mpegts: 11914.5H in DVB-S Astra1x - tuning on SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)
Oct 14 16:18:37 TVHserver tvheadend[18803]: subscription: 048F: "DVR: Planet der Affen: Survival" subscribing on channel "Sky Cinema", weight: 500, adapter: "SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)", network: "DVB-S Astra1x", mux: "11914.5H", provider: "SKY", service: "Sky Cinema HD", profile="matroska" 
Oct 14 16:18:37 TVHserver tvheadend[18803]: dvr: c33bb2d51bce423d41de20cf9da7197f - recoding thread started for "Planet der Affen: Survival" 
Oct 14 16:18:38 TVHserver tvheadend[18803]: TS: DVB-S Astra1x/11914.5H/Sky Cinema HD: H264 @ #1279 Continuity counter error (total 1)
Oct 14 16:18:39 TVHserver tvheadend[18803]: cwc: localhost:XXXXX: Got unexpected ECM reply (seqno: 170)
Oct 14 16:18:39 TVHserver tvheadend[18803]: descrambler: Sky Cinema HD odd stream key[1279] is not valid
Oct 14 16:18:39 TVHserver tvheadend[18803]: cwc: localhost:XXXXX: Got unexpected ECM reply (seqno: 1738)
Oct 14 16:18:40 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - set state - state RECORDING rec_state EPGWAIT error 'OK'
Oct 14 16:18:45 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:18:53 TVHserver tvheadend[18803]: dvr: dvr_autorec_async_reschedule_cb - begin
Oct 14 16:18:53 TVHserver tvheadend[18803]: dvr: dvr_autorec_async_reschedule_cb - end
Oct 14 16:19:00 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: dvr event running check for Die geheimen Akten der NASA on Discovery running 1
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: dvr event running check for Die geheimen Akten der NASA on Discovery running 3
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: dvr event running check for Pfad der Rache on Sky Cinema running 1
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: dvr event running check for Planet der Affen: Survival on Sky Cinema running 3
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: dvr entry c33bb2d51bce423d41de20cf9da7197f event Planet der Affen: Survival on Sky Cinema - EPG marking start
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: c33bb2d51bce423d41de20cf9da7197f - running flag changed from 0 to 1
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - set state - state RECORDING rec_state RUNNING error 'OK'
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - set state - state RECORDING rec_state WAIT error 'OK'
Oct 14 16:19:12 TVHserver tvheadend[18803]: dvr: File "/storage/recordings/Planet-der-Affen_-Survival/Planet-der-Affen_-Survival.Sky-Cinema.2018-10-14.15-55.mkv" -- No such file or directory -- Using for recording
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: /storage/recordings/Planet-der-Affen_-Survival/Planet-der-Affen_-Survival.Sky-Cinema.2018-10-14.15-55.mkv from adapter: "SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)", network: "DVB-S Astra1x", mux: "11914.5H", provider: "SKY", service: "Sky Cinema HD" 
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr:  #  type              lang  resolution  aspect ratio  sample rate  channels
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr:  1  H264                    1920x1080   16:9
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr:  2  AC3               ger                             48000        5.1
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr:  3  AC3               eng                             48000        2
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f stop 2018-10-14;18:15:00(+0200) - set timer - arm
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: c33bb2d51bce423d41de20cf9da7197f - muxing activated
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - set state - state RECORDING rec_state RUNNING error 'OK'
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: dvr event running check for Modern Family on Sky 1 running 1
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: dvr event running check for Modern Family on Sky 1 running 3
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: entry c791958d07260b99f32b621e555b7702 start 2018-10-14;18:24:30(+0200) stop 2018-10-14;20:15:00(+0200) - set timer
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: entry c791958d07260b99f32b621e555b7702 start 2018-10-14;18:24:30(+0200) - set timer - schedule
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: "Dunkirk" on "Sky Cinema Action": Updated (i)
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: dvr event running check for Live DKB HBL: Füchse Berlin - TBV Lemgo Lippe, Topspiel am Sonntag, 9. Spieltag on Sky Sport 1 running 1
Oct 14 16:19:14 TVHserver tvheadend[18803]: dvr: dvr event running check for Live DKB HBL: Sonntags-Konferenz, 9. Spieltag on Sky Sport 1 running 3
Oct 14 16:19:15 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:19:15 TVHserver tvheadend[18803]: dvr: dvr event running check for Die geheimen Akten der NASA on Discovery running 1
Oct 14 16:19:15 TVHserver tvheadend[18803]: dvr: dvr event running check for Space Shuttle - Das Ende einer Ära on Discovery running 3
Oct 14 16:19:20 TVHserver tvheadend[18803]: dvr: entry c397549fc2e1885ac4e6ab91831924ad start 2018-10-14;20:14:30(+0200) stop 2018-10-14;22:05:00(+0200) - set timer
Oct 14 16:19:20 TVHserver tvheadend[18803]: dvr: entry c397549fc2e1885ac4e6ab91831924ad start 2018-10-14;20:14:30(+0200) - set timer - schedule
Oct 14 16:19:20 TVHserver tvheadend[18803]: dvr: "Geostorm" on "Sky Cinema": Updated (i)
Oct 14 16:19:30 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:19:45 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:19:49 TVHserver tvheadend[18803]: subscription: 048F: "DVR: Planet der Affen: Survival" unsubscribing from "Sky Cinema" 
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - set state - state COMPLETED rec_state FINISHED error 'Aborted by user'
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: adding inotify watch to /storage/recordings/Planet-der-Affen_-Survival (fd=112)
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f when 1970-01-01;01:00:00(+0100) - retention arm
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: "Planet der Affen: Survival" on "Sky Cinema": End of program: Aborted by user
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f when 1970-01-01;01:00:00(+0100) - retention arm
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f when 1970-01-01;01:00:00(+0100) - retention arm
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: delete entry c33bb2d51bce423d41de20cf9da7197f "Planet der Affen: Survival" on "Sky Cinema" start time 2018-10-14 15:54:30, scheduled for recording by "admin", retention "On file removal" removal "Forever" 
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: dvr_autorec_async_reschedule
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: entry c33bb2d51bce423d41de20cf9da7197f - unassign broadcast 67145163
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: inotify: moved from_fd: 112 path: "/storage/recordings/Planet-der-Affen_-Survival/Planet-der-Affen_-Survival.Sky-Cinema.2018-10-14.15-55.mkv" to: ".lanet-der-Affen_-Survival.Sky-Cinema.2018-10-14.15-55.mkv.removing" to_fd: 112
Oct 14 16:19:49 TVHserver tvheadend[18803]: dvr: inotify: moved from_fd: 112 path: "/storage/recordings/Planet-der-Affen_-Survival/.lanet-der-Affen_-Survival.Sky-Cinema.2018-10-14.15-55.mkv.removing" to: "<none>" to_fd: -1

(I cancelled recording manually as it worked)

Log from latest master with "--trace dvr" right after it, recording failed:

Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f - assign broadcast 67145163
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f start 2018-10-14;15:54:30(+0200) - set timer - schedule
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f "Planet der Affen: Survival" on "Sky Cinema" starting at 2018-10-14 15:54:30, with broadcast id "<noid>", scheduled for recording by "admin" 
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f start 2018-10-14;15:54:30(+0200) - set timer - schedule
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f start 2018-10-14;15:54:30(+0200) stop 2018-10-14;18:15:00(+0200) - set timer
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f start 2018-10-14;15:54:30(+0200) - set timer - schedule
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f - set state - state RECORDING rec_state PENDING error 'OK'
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: "Planet der Affen: Survival" on "Sky Cinema" recorder starting
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f original stop 2018-10-14;18:15:00(+0200) stop 2018-10-14;18:15:00(+0200) - stop timer set
Oct 14 16:19:56 TVHserver tvheadend[18803]: mpegts: 11914.5H in DVB-S Astra1x - tuning on SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)
Oct 14 16:19:56 TVHserver tvheadend[18803]: subscription: 0490: "DVR: Planet der Affen: Survival" subscribing on channel "Sky Cinema", weight: 500, adapter: "SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)", network: "DVB-S Astra1x", mux: "11914.5H", provider: "SKY", service: "Sky Cinema HD", profile="matroska" 
Oct 14 16:19:56 TVHserver tvheadend[18803]: dvr: 50c95e71ff7e576be6a358b31b4c118f - recoding thread started for "Planet der Affen: Survival" 
Oct 14 16:19:57 TVHserver tvheadend[18803]: TS: DVB-S Astra1x/11914.5H/Sky Cinema HD Transport error indicator (total 1)
Oct 14 16:19:58 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f - set state - state RECORDING rec_state EPGWAIT error 'OK'
Oct 14 16:20:00 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:20:15 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:20:30 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:20:33 TVHserver tvheadend[18803]: dvr: entry c791958d07260b99f32b621e555b7702 start 2018-10-14;18:24:30(+0200) stop 2018-10-14;20:15:00(+0200) - set timer
Oct 14 16:20:33 TVHserver tvheadend[18803]: dvr: entry c791958d07260b99f32b621e555b7702 start 2018-10-14;18:24:30(+0200) - set timer - schedule
Oct 14 16:20:33 TVHserver tvheadend[18803]: dvr: "Dunkirk" on "Sky Cinema Action": Updated (i)
Oct 14 16:20:33 TVHserver tvheadend[18803]: dvr: entry c791958d07260b99f32b621e555b7702 start 2018-10-14;18:24:30(+0200) stop 2018-10-14;20:15:00(+0200) - set timer
Oct 14 16:20:33 TVHserver tvheadend[18803]: dvr: entry c791958d07260b99f32b621e555b7702 start 2018-10-14;18:24:30(+0200) - set timer - schedule
Oct 14 16:20:33 TVHserver tvheadend[18803]: dvr: "Dunkirk" on "Sky Cinema Action": Updated (i)
Oct 14 16:20:45 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK
Oct 14 16:20:49 TVHserver tvheadend[18803]: dvr: dvr_autorec_async_reschedule_cb - begin
Oct 14 16:20:49 TVHserver tvheadend[18803]: dvr: dvr_autorec_async_reschedule_cb - end
Oct 14 16:21:00 TVHserver tvheadend[18803]: dvr: checking free and used disk space for config "Default profile" : OK

Please add more robustness for recordings. No output file written, output stream size of 0, no streams detected are all signs of a failed start of recording, TVh should retry then - which I think it does not.

HTH,
/HXZ

History

#1

Updated by Jaroslav Kysela about 6 years ago

EITp/f problem:

Oct 14 16:19:58 TVHserver tvheadend[18803]: dvr: entry 50c95e71ff7e576be6a358b31b4c118f - set state - state RECORDING rec_state EPGWAIT error 'OK'
... but no EPG event start signalled ...
#2

Updated by da h4xX0rz1sT about 6 years ago

Pls advice what can I do about it/what to diagnose further?

How does it happen once everything is alright and a few seconds later the same recording from the same channel fails with no file written?

/HXZ

#3

Updated by Jaroslav Kysela about 6 years ago

You may disable EITp/f for this channel. Also you may try to do '--trace dvr' to see if EITp/f is correctly send to the DVR layer in tvh.

#4

Updated by da h4xX0rz1sT about 6 years ago

da h4xX0rz1sT wrote:

  • on start of recording, trace dvr log does not show (seems to be new trace message on master)
should have been
  • on start of recording, trace log does not show "dvr: File "<file>" -- No such file or directory -- Using for recording"

OK, when I disable EITp/f, it works. I just don't understand why it works once, and a few seconds later (on the same channel, the same broadcast) it does not.

/HXZ

#5

Updated by Jaroslav Kysela about 6 years ago

Retest with v4.3-1469-g5c14193ed .

#6

Updated by da h4xX0rz1sT about 6 years ago

  • when I record a broadcast currently running, it seems to always write a file now
  • when I schedule a recording of a future broadcast, it seems to always write a file now

Great! Jaroslav, you made it again :)
Thanks!

/HXZ

#7

Updated by Jaroslav Kysela about 6 years ago

  • Status changed from New to Fixed
#8

Updated by da h4xX0rz1sT about 6 years ago

Unfortunately, after some more testing, I saw it seems only halfway fixed. This is what I got yesterday with a scheduled recording:

Oct 16 11:54:30 TVHserver tvheadend[22021]: dvr: "Liebe zu Besuch" on "Sky Cinema +1" recorder starting
Oct 16 11:54:30 TVHserver tvheadend[22021]: mpegts: 12070.5H in DVB-S Astra1x - tuning on SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)
Oct 16 11:54:30 TVHserver tvheadend[22021]: subscription: 0223: "DVR: Liebe zu Besuch" subscribing on channel "Sky Cinema +1", weight: 500, adapter: "SAT>IP OctopusNet S2/4 DVB-S #1 (192.168.XXX.XXX@UDP)", network: "DVB-S Astra1x", mux: "12070.5H", provider: "SKY", service: "Sky Cinema +1 HD", profile="matroska" 
Oct 16 11:54:31 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: H264 @ #255 Continuity counter error (total 1)
Oct 16 11:54:34 TVHserver tvheadend[22021]: descrambler: Sky Cinema +1 HD odd stream key[255] is not valid
Oct 16 11:54:34 TVHserver tvheadend[22021]: cwc: localhost:XXXXX: Got unexpected ECM reply (seqno: 31)
Oct 16 11:54:34 TVHserver tvheadend[22021]: cwc: localhost:XXXXX: Got unexpected ECM reply (seqno: 3299)
Oct 16 12:41:23 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: H264 @ #255 Continuity counter error (total 7)
Oct 16 12:41:23 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: AC3 @ #259 Continuity counter error (total 1)
Oct 16 12:41:23 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: AC3 @ #260 Continuity counter error (total 1)
Oct 16 12:41:24 TVHserver tvheadend[22021]: cwc: localhost:XXXXX: Got unexpected ECM reply (seqno: 3782)
Oct 16 12:41:25 TVHserver tvheadend[22021]: descrambler: cannot decode packets for service "Sky Cinema +1 HD" 
Oct 16 12:41:25 TVHserver tvheadend[22021]: tsfix: transport stream H264, DTS discontinuity. DTS = 252922728, last = 252814728
Oct 16 12:41:26 TVHserver tvheadend[22021]: tsfix: transport stream AC3, DTS discontinuity. DTS = 252884568, last = 252740568
Oct 16 12:41:26 TVHserver tvheadend[22021]: tsfix: transport stream AC3, DTS discontinuity. DTS = 252883253, last = 252739253
Oct 16 12:43:22 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: AC3 @ #259 Continuity counter error (total 32)
Oct 16 12:43:22 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: H264 @ #255 Continuity counter error (total 86)
Oct 16 12:43:22 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: AC3 @ #260 Continuity counter error (total 20)
Oct 16 12:43:22 TVHserver tvheadend[22021]: cwc: localhost:XXXXX: Got unexpected ECM reply (seqno: 3803)
Oct 16 12:43:24 TVHserver tvheadend[22021]: descrambler: cannot decode packets for service "Sky Cinema +1 HD" 
Oct 16 13:28:42 TVHserver tvheadend[22021]: TS: DVB-S Astra1x/12070.5H/Sky Cinema +1 HD: AC3 @ #259 Continuity counter error (total 64)
Oct 16 13:28:43 TVHserver tvheadend[22021]: tsfix: transport stream AC3, DTS discontinuity. DTS = 508332648, last = 508172933
Oct 16 13:35:00 TVHserver tvheadend[22021]: subscription: 0223: "DVR: Liebe zu Besuch" unsubscribing from "Sky Cinema +1" 
Oct 16 13:35:00 TVHserver tvheadend[22021]: dvr: "Liebe zu Besuch" on "Sky Cinema +1": End of program: Time missed

Again, no file written. For instant recordings of currently running broadcasts, there is no issue reproducible anymore.

HTH,
/HXZ

#9

Updated by Jaroslav Kysela about 6 years ago

It's descrambling issue. Create another bug with '--trace cwc'.

#10

Updated by da h4xX0rz1sT about 6 years ago

Yeah, seems so - I try to catch it next time it happens.

HTH,
/HXZ

Also available in: Atom PDF