[mythtv-users] Damaged Recordings

Tue Dec 7 03:35:40 UTC 2021

On Mon, 6 Dec 2021 22:16:40 +0100, you wrote:

>On Mon, 6 Dec 2021 at 20:32, Thor <mythtv at x-defense.de> wrote:
>
>> Hi,
>> I noticed that recently all my HD recordings (from onboard DVB-C card)
>> appear "damaged".
>> The video itself seems fine, but they are tagged "Damaged" on mythweb,
>> and show with yellow font on my kodi frontends.
>> I am not sure where to start the "debugging". any hints appreciated.
>> this is from a test recording today :
>> "
>> 2021-12-06 12:02:00.784906 I  TVRec[1]:
>> FinishedRecording(30001_2021-12-06T10:56:00Z) damaged recq:
>>
>> <RecordingQuality overall_score="0.35"
>> key="30001_2021-12-06T10:56:00Z" continuity_error_count="0"
>> packet_count="2920809">
>>
>>      <Gap start="2021-12-06T10:56:00Z" end="2021-12-06T10:56:26Z"
>> duration="26" />
>>
>> </RecordingQuality>
>>
>> 2021-12-06 12:02:00.792595 I  Updating status for "1 (Das Erste HD)"
>> on cardid [1] (Recording => Recorder Failed)
>>
>>
>> "
>>
>> Your recording does not miss any packet from the transport stream, as
>shown by the continuity_error_count value of 0. This means your recording
>is perfect.
>However, the "Gap start" is the time the recording has started later than
>was planned. This is 26 seconds in your recording and that is what causes
>the recording to be marked as failed.
>This is the time it took for the tuner to get in lock. Usually the tuner
>locks in one or a few seconds so this is not really good.
>
>I do not know why it takes so long for your tuner to get in lock although I
>have seen it before.
>There is a small chance that a channel scan might improve this, so that is
>something you can do.
>
>If your recordings always take this long to get started but are otherwise
>OK you can also adjust the time value that is used to decide if a recording
>has failed.
>This is a configuration item in mythfrontend: Setup / Video / General /
>General (Advanced) /  Maximum Start Gap (secs). The default value is 15
>seconds but this can easily be changed to 30 or 60 seconds.
>
>Klaas.

Actually, I think this may be a mythbackend bug causing this.  I get
this all the time, on my DVB-T recordings, but also on DVB-S2
recordings via minisatip, where mythbackend is not running the tuners.
I believe it happens when two or more recordings are starting at the
same time.  My suspicion is that mythbackend is locking some resource
that it should not be locking and one tuner is having to wait for that
resource to be unlocked.  If I am watching recordings at the time
multiple new recordings are starting, I can also get mythfrontend
unable to do things as it can not get a response from mythbackend.
Playing a recording that is already playing is unaffected, but trying
to select a new recording to play does not work.  This usually last
for up to 60 seconds.  My workaround for this is just to set
recordings to have an extra minute of pre-roll.  Occasionally, the gap
at the start is longer than 60 seconds, which means I can still lose
the front of the programme.

Some examples from last week:

grep -a "overall_score=\"0" /var/log/mythtv/mythbackend.log.1

Nov 27 20:42:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[90]:
FinishedRecording(10007_2021-11-27T06:45:00Z) good
recq:<RecordingQuality overall_score="0.971"
key="10007_2021-11-27T06:45:00Z" continuity_error_count="0"
packet_count="10447103">#012    <Gap start="2021-11-27T06:45:00Z"
end="2021-11-27T06:45:29Z" duration="29" />#012</RecordingQuality>
Nov 29 23:34:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[90]:
FinishedRecording(10073_2021-11-29T09:35:00Z) good
recq:<RecordingQuality overall_score="0.979091"
key="10073_2021-11-29T09:35:00Z" continuity_error_count="0"
packet_count="11282233">#012    <Gap start="2021-11-29T09:35:00Z"
end="2021-11-29T09:35:23Z" duration="23" />#012</RecordingQuality>
Nov 30 21:04:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[16]:
FinishedRecording(1017_2021-11-30T07:30:00Z) damaged
recq:<RecordingQuality overall_score="0.948333"
key="1017_2021-11-30T07:30:00Z" continuity_error_count="0"
packet_count="4656361">#012    <Gap start="2021-11-30T07:30:00Z"
end="2021-11-30T07:30:31Z" duration="31" />#012</RecordingQuality>
Nov 30 21:34:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[2]:
FinishedRecording(1001_2021-11-30T07:30:00Z) good
recq:<RecordingQuality overall_score="0.974167"
key="1001_2021-11-30T07:30:00Z" continuity_error_count="0"
packet_count="16363062">#012    <Gap start="2021-11-30T07:30:00Z"
end="2021-11-30T07:30:31Z" duration="31" />#012</RecordingQuality>
Nov 30 22:34:02 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[6]:
FinishedRecording(1012_2021-11-30T08:30:00Z) good
recq:<RecordingQuality overall_score="0.976667"
key="1012_2021-11-30T08:30:00Z" continuity_error_count="2"
packet_count="5478143">#012    <Gap start="2021-11-30T08:30:00Z"
end="2021-11-30T08:30:28Z" duration="28" />#012</RecordingQuality>
Nov 30 22:36:01 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[92]:
FinishedRecording(10007_2021-11-30T08:30:00Z) good
recq:<RecordingQuality overall_score="0.975"
key="10007_2021-11-30T08:30:00Z" continuity_error_count="0"
packet_count="11574563">#012    <Gap start="2021-11-30T08:30:00Z"
end="2021-11-30T08:30:30Z" duration="30" />#012</RecordingQuality>Nov
27 20:42:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[90]:
FinishedRecording(10007_2021-11-27T06:45:00Z) good
recq:<RecordingQuality overall_score="0.971"
key="10007_2021-11-27T06:45:00Z" continuity_error_count="0"
packet_count="10447103">#012    <Gap start="2021-11-27T06:45:00Z"
end="2021-11-27T06:45:29Z" duration="29" />#012</RecordingQuality>
Nov 29 23:34:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[90]:
FinishedRecording(10073_2021-11-29T09:35:00Z) good
recq:<RecordingQuality overall_score="0.979091"
key="10073_2021-11-29T09:35:00Z" continuity_error_count="0"
packet_count="11282233">#012    <Gap start="2021-11-29T09:35:00Z"
end="2021-11-29T09:35:23Z" duration="23" />#012</RecordingQuality>
Nov 30 21:04:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[16]:
FinishedRecording(1017_2021-11-30T07:30:00Z) damaged
recq:<RecordingQuality overall_score="0.948333"
key="1017_2021-11-30T07:30:00Z" continuity_error_count="0"
packet_count="4656361">#012    <Gap start="2021-11-30T07:30:00Z"
end="2021-11-30T07:30:31Z" duration="31" />#012</RecordingQuality>
Nov 30 21:34:00 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[2]:
FinishedRecording(1001_2021-11-30T07:30:00Z) good
recq:<RecordingQuality overall_score="0.974167"
key="1001_2021-11-30T07:30:00Z" continuity_error_count="0"
packet_count="16363062">#012    <Gap start="2021-11-30T07:30:00Z"
end="2021-11-30T07:30:31Z" duration="31" />#012</RecordingQuality>
Nov 30 22:34:02 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[6]:
FinishedRecording(1012_2021-11-30T08:30:00Z) good
recq:<RecordingQuality overall_score="0.976667"
key="1012_2021-11-30T08:30:00Z" continuity_error_count="2"
packet_count="5478143">#012    <Gap start="2021-11-30T08:30:00Z"
end="2021-11-30T08:30:28Z" duration="28" />#012</RecordingQuality>
Nov 30 22:36:01 mypvr mythbackend: mythbackend[3805]: I TVRecEvent
tv_rec.cpp:826 (FinishedRecording) TVRec[92]:
FinishedRecording(10007_2021-11-30T08:30:00Z) good
recq:<RecordingQuality overall_score="0.975"
key="10007_2021-11-30T08:30:00Z" continuity_error_count="0"
packet_count="11574563">#012    <Gap start="2021-11-30T08:30:00Z"
end="2021-11-30T08:30:30Z" duration="30" />#012</RecordingQuality>

Channels with chanids with 5 digits are DVB-S2 via minisatip, channels
with chanids that are 4 digits are DVB-T.  We are also having a lot of
rain here at the moment, so some recordings are getting rain fade and
occasionally continuity errors.

The other suspect is the Housekeeper task doing DBCleanup.  During
DBCleanup, there is a period where mythfrontend becomes unresponsive
for 2-3 minutes for me.  I have a massive database, so it is likely
the period is much shorter for most databases and this problem does
not get noticed.  I suspect this problem is the one that causes my
recordings to get long gaps at the beginning, and the shorter gaps are
caused by multiple recordings starting at the same time.