[mythtv] Too much EIT activity causing defective recordings

Wed Aug 1 22:21:00 UTC 2018

On 8/2/2018 3:31 AM, John Pilkington wrote:
> On 01/08/18 17:27, Stephen Worthington wrote:
>> On Wed, 1 Aug 2018 13:52:06 +0100, you wrote:
>>
>>> On 01/08/18 12:49, Michael T. Dean wrote:
>>>> On 07/31/2018 06:51 PM, John Pilkington wrote:
>>>>> Hi;  I'm running Master under SL7, recording UK SD DVB-T material via
>>>>> one PCI single-tuner device and one twin-tuner usb dongle.
>>>>>
>>>>> Bus 001 Device 002: ID 1b80:e409 Afatech IT9137FN Dual DVB-T [KWorld
>>>>> UB499-2T]
>>>>>
>>>>> Around 9 July my Project-X-based mythDVBcut logs started reporting
>>>>> multiple AV sync corrections of up to a second in recordings from the
>>>>> usb tuners.  The change occurred after I rescanned my transports
>>>>> following the Wimbledon special tennis coverage;  I'm fairly sure I
>>>>> made other 'minor' changes in the multirec and EIT configs too.
>>>>>
>>>>> Today I realised that the defects were often around 5 minutes apart,
>>>>> and EIT scanning seemed a possible culprit.  I have now unchecked the
>>>>> boxes for usb open-on-demand and active-EIT-scan, and it looks as if
>>>>> the recording defects have largely gone.
>>>>>
>>>>> In the past I probably haven't taken as much notice of the EIT
>>>>> settings as I should have done, but the recent defects were much 
>>>>> worse
>>>>> than I had seen before and I think some of the recent code changes
>>>>> must have been implicated.
>>>>>
>>>>> John P
>>>>>
>>>>> Below is a Project-X log resync section from an affected recording.
>>>>> This should be just a few lines, with no resync required.
>>>>>
>>>>> {{{
>>>>>
>>>>> Input File 0:  '/mnt/dat2/RSG3/1004_20180723195800.ts.old'
>>>>> (1,149,983,780 bytes)
>>>>> -> Filetype is TS (generic PES Container)
>>>>>
>>>>> <demux log snipped>
>>>>>
>>>>> ++> Mpg Audio: PID 0x044E / PesID 0xC0 / SubID 0x00 :
>>>>> -> check CRC of AC-3 / MPEG-Audio L1,2
>>>>> -> remove CRC in MPEG-Audio L1,2
>>>>> -> add frames
>>>>> -> Audio PTS: first packet 08:48:35.071, last packet 09:48:52.207
>>>>> -> Video PTS: start 1.GOP 08:48:41.439, end last GOP 09:48:41.999
>>>>> -> adjusting audio at video-timeline
>>>>> -> src_audio: MPEG-1, Layer2, 48000Hz, stereo, 192kbps, noCRC @
>>>>> 00:00:00.000
>>>>> !> 5 frame(s) (120ms) inserted @ 00:02:28.608
>>>>> !> missing syncword @  6527233, @ 00:04:08.064
>>>>> !> found syncword @ 6528384
>>>>> !> 22 frame(s) (528ms) inserted @ 00:04:08.064
>>>>> !> missing syncword @  6528961, @ 00:04:08.592
>>>>> !> found syncword @ 6529352
>>>>> !> missing syncword @  14213193, @ 00:09:27.840
>>>>> !> found syncword @ 14213560
>>>>> !> missing syncword @  14214137, @ 00:09:27.864
>>>>> !> found syncword @ 14214344
>>>>> !> 4 frame(s) (96ms) inserted @ 00:09:27.864
>>>>> !> missing syncword @  29606793, @ 00:16:02.448
>>>>> !> found syncword @ 29607000
>>>>> !> 1 frame(s) (24ms) inserted @ 00:16:02.448
>>>>> !> 19 frame(s) (456ms) inserted @ 00:21:21.144
>>>>> !> missing syncword @  45001753, @ 00:26:40.656
>>>>> !> found syncword @ 45001960
>>>>> !> 23 frame(s) (552ms) inserted @ 00:26:40.680
>>>>> !> missing syncword @  52701353, @ 00:27:54.144
>>>>> !> found syncword @ 52701536
>>>>> !> missing syncword @  52702689, @ 00:27:54.192
>>>>> !> found syncword @ 52703080
>>>>> !> 20 frame(s) (480ms) inserted @ 00:27:54.192
>>>>> !> missing syncword @  60403625, @ 00:33:14.592
>>>>> !> found syncword @ 60404248
>>>>> !> 17 frame(s) (408ms) inserted @ 00:33:14.616
>>>>> !> missing syncword @  68103065, @ 00:38:34.344
>>>>> !> found syncword @ 68103712
>>>>> !> 17 frame(s) (408ms) inserted @ 00:38:34.344
>>>>> !> missing syncword @  68120993, @ 00:38:34.752
>>>>> !> found syncword @ 68121960
>>>>> !> 2 frame(s) (48ms) inserted @ 00:38:34.752
>>>>> !> missing syncword @  75797161, @ 00:39:47.760
>>>>> !> found syncword @ 75797944
>>>>> !> missing syncword @  83496185, @ 00:45:07.344
>>>>> !> found syncword @ 83496968
>>>>> !> 21 frame(s) (504ms) inserted @ 00:45:07.416
>>>>> !> missing syncword @  83504457, @ 00:45:07.920
>>>>> !> found syncword @ 83505080
>>>>> !> missing syncword @  83566137, @ 00:45:09.816
>>>>> !> found syncword @ 83566920
>>>>> !> 2 frame(s) (48ms) inserted @ 00:45:09.816
>>>>> !> 2 frame(s) (48ms) inserted @ 00:45:09.960
>>>>> audio frames: wri-pre-skip-ins-add 117813-0-0-155-0 @ 00:47:07.512
>>>>> done...
>>>>> ---> new File: '/home/john/MythTmp/tempcut19417.mp2'
>>>>>
>>>>> summary of created media files:
>>>>> .Video (m2v):    70688 Frames    00:47:07.520
>>>>> '/home/john/MythTmp/tempcut19417.m2v'
>>>>> Audio 00 (mp2):    117813 Frames    00:47:07.512 0-0-155-0
>>>>> '/home/john/MythTmp/tempcut19417.mp2'
>>>>> => 775,195,585 bytes written...
>>>>> -> we have 139 warnings/errors.
>>>>>
>>>>> }}}
>>>>
>>>> Could this be due to I/O activity? Have you done an optimize on your
>>>> database, recently?  If not, it may just be that MySQL is taking too
>>>> much time with I/O when MythTV tries to write your listings data 
>>>> and it
>>>> causes problems with MythTV's writing recording data.  Do you have any
>>>> warnings or errors in your MythTV backend logs?
>>>>
>>>> Mike
>>>
>>> Hi Mike:  I run optimize every few days, so I don't think that's it.
>>> But I usually arranged the schedule to record from the usb tuners only
>>> when the PCI device was already recording, often from several channels,
>>> so usually the system would be fairly busy.  Database sql.gz backups 
>>> are
>>> now 125 MiB and autodelete of old recordings is getting invoked.  40 GB
>>> free, 2% of 2.3 GiB reported: 3 partitions on 2 disks.
>>>
>>> I haven't seen any obvious signs of distress on the terminal window in
>>> which I run the backend, and at present I would prefer to let things
>>> roll for a bit rather than going back to do more investigations.
>>
>> You might try setting the -v record option on the mythbackend command
>> line.  That gives more logging of the recording process, and will give
>> you messages like the following if you are getting any problems
>> detected with a recording:
>>
>> root at mypvr:/etc/mythtv# grep -a "overall_score=\"0"
>> /var/log/mythtv/mythbackend.log.1
>> Jul 22 20:34:01 mypvr mythbackend: mythbackend[3543]: I TVRecEvent
>> tv_rec.cpp:863 (FinishedRecording) TVRec[96]:
>> FinishedRecording(10072_2018-07-22T07:29:00Z) good
>> recq:<RecordingQuality overall_score="0.991667"
>> key="10072_2018-07-22T07:29:00Z" countinuity_error_count="11"
>> packet_count="7494980">#012    <Gap start="2018-07-22T07:46:02Z"
>> end="2018-07-22T07:46:22Z" duration="19" />#012</RecordingQuality>
>> Jul 23 20:39:00 mypvr mythbackend: mythbackend[3543]: I TVRecEvent
>> tv_rec.cpp:863 (FinishedRecording) TVRec[94]:
>> FinishedRecording(10007_2018-07-23T07:59:00Z) damaged
>> recq:<RecordingQuality overall_score="0"
>> key="10007_2018-07-23T07:59:00Z" countinuity_error_count="0"
>> packet_count="108664">#012    <Gap start="2018-07-23T07:59:30Z"
>> end="2018-07-23T08:35:00Z" duration="2129" />#012</RecordingQuality>
>> Jul 25 23:06:01 mypvr mythbackend: mythbackend[3644]: I TVRecEvent
>> tv_rec.cpp:863 (FinishedRecording) TVRec[92]:
>> FinishedRecording(10070_2018-07-25T10:14:00Z) damaged
>> recq:<RecordingQuality overall_score="0"
>> key="10070_2018-07-25T10:14:00Z" countinuity_error_count="0"
>> packet_count="194555">#012    <Gap start="2018-07-25T10:15:27Z"
>> end="2018-07-25T11:05:00Z" duration="2972" />#012</RecordingQuality>
>>
>> What I see if I have my hard drives too busy is that I get short gaps
>> in recordings, and get messages like the first one above, where there
>> is a gap with a short duration, and also continuity errors.  I use a
>> rule of thumb that two recordings at once is all I want to have on one
>> hard drive.  Three at once is OK for a short period (during overlaps
>> between recordings due to pre- and post roll), but if I have three
>> recordings at once to one drive for the full length of a recording,
>> there is a good chance I will get gaps.  Four at once and there will
>> almost always be gaps.  Since you have three tuners with multirec on
>> each of them, and only two hard drives to record to, then it is likely
>> that the drives will be overloaded at some point.  And if one of the
>> recording drives is also the system and database drive, then it is
>> much more likely to be too busy at some point.  I put my system and
>> database onto an SSD a couple of years ago and that made a big
>> difference.  But when I increased my tuners, I also had to add more
>> hard drives.  I now have 5 x DVB-T2 and 4 x DVB-S2 tuners in use, and
>> have 7 recording drives.  And I do at times have 14 recordings at
>> once.  But the gaps I get now are normally caused by rain fade on the
>> satellite dish, not by overworked hard drives.
>
> Hi Stephen:  yes, thanks for that.  I will try more comprehensive 
> logging options, and I'm still wondering just how much of an archive, 
> and in what form, I really have a use for.
>
> Often some of my simultaneous recordings are radio, so the load isn't 
> quite as heavy as the number would suggest.  But I did see a big rise 
> in the number and length of the audio insertions in early July, when 
> the only system change that seemed likely to be relevant (IIRC) was in 
> those usb-tuner settings.  Since I unticked the boxes the 
> post-processing logs have been much better.  I'll see if they stay 
> that way - and if I still get the EIT data.
>
I have an afatech 399U and it is woeful when both channels are running. 
USB2 and not a good implementation I think. I had to stop using it for 
myth or only enable 1 tuner. Good eough for random PC watching though so 
thats what it was relegated to.
Cant say about the 499U.

PCI/PCIE devices work flawlessly with many tuners running 
simultaneously. So I have an old TT PCI and a quad Hauppauge. All 
channels can be recording multiples. Never had any disk IO issues either.
Had a system 10 years ago which recorded 5 multiplexes with 3-4 channels 
per multiplex continuously with 20 min overlap. No problems there 
either. That system though had a bit of raid and 3 dual tuner pcie cards.

Mark