[SOLVED] NBC nightly news bad when recording another show

Have a MythTV related problem? Ask for help from other MythTV users here.

Moderator: Forum Moderators

mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

[SOLVED] NBC nightly news bad when recording another show

Post by mathog »

We have a dual tuner HDHomerun (original model, I think). As far as I can tell both tuners are working. However, my wife has noticed lately that when she schedules at 6:30PM the NBC nightly news with Extra (channel 11) OR at 4:30 PM NBC nightly news and ABC local news, then the NBC nightly news is mangled but the other show may be OK, other times it too is mangled. Mangled means it is far shorter than 30 minutes and huge chunks drop out as if full of noise or missing data. However, if she only schedules NBC nightly news OR the other show, then it is fine. At other times she says she can schedule two recordings and they are fine. (I'm not entirely sure this is true, and told her to run some experiments at other times and pairs of channels to verify that.) For today's 4:30 simultaneous recording she was not otherwise using MythTV. She has not reported any other recording problems to me in the last year or so, other than when these were probably weather related.

I looked at the log files and didn't see a problem, but I'm not sure what to look for. The mythtv log files not shown either had no entries for the time period examined, or those records were clearly innocuous. The disks are quite full, but as I understand that it should not be an issue, Mythtv should just delete something to make space. Maybe there is a data bottleneck somewhere?

Code: Select all

part of mythbackend.log

Jul 21 16:18:48 mediahog mythbackend: mythbackend[1378]: N Expire autoexpire.cpp:261 (CalcParams) AutoExpire: CalcParams(): Max 
required Free Space: 1.0 GB w/freq: 15 min
Jul 21 16:19:00 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested 
for PLACE PrepareToRecord
Jul 21 16:19:00 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2472 (HandleReschedule) Scheduled 116 items i
n 0.0 = 0.00 match + 0.00 check + 0.04 place
Jul 21 16:19:30 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:1652 (HandlePendingRecordings) TVRec[1]: ASK_RE
CORDING 1 29 0 0
Jul 21 16:19:30 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:1652 (HandlePendingRecordings) TVRec[2]: ASK_RE
CORDING 2 29 0 0
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:1091 (HandleStateChange) TVRec[1]: Changing fro
m None to RecordingOnly
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:3682 (TuningFrequency) TVRec[1]: TuningFrequenc
y
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent recorders/hdhrstreamhandler.cpp:385 (Connect) HDHRSH[1](19
2.168.0.100): Added 2 devices from 192.168.0.100
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent recorders/hdhrstreamhandler.cpp:403 (Connect) HDHRSH[1](19
2.168.0.100): Connected to device(1011F855-0)
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2934 (HandleRecordingStatusChange) Tuning rec
ording: "Eyewitness News 4PM": channel 10701 on cardid [1], sourceid 1
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: C CoreContext programinfo.cpp:347 (ProgramInfo) ProgramInfo(): Failed t
o find recorded entry for 0.
Jul 21 16:20:00 mediahog mythbackend: mythbackend[1378]: I CoreContext scheduler.cpp:729 (UpdateRecStatus) Updating status for "
Eyewitness News 4PM" on cardid [1] (Tuning => Recording)
Jul 21 16:20:01 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:4231 (TuningNewRecorder) TVRec[1]: rec->GetPath
name(): '/home/mythdbstorage/10701_20220721232000.ts'
Jul 21 16:29:00 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested 
for PLACE PrepareToRecord
Jul 21 16:29:00 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2472 (HandleReschedule) Scheduled 116 items i
n 0.0 = 0.00 match + 0.00 check + 0.04 place
Jul 21 16:29:30 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:1652 (HandlePendingRecordings) TVRec[3]: ASK_RE
CORDING 3 29 0 0
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:1091 (HandleStateChange) TVRec[3]: Changing fro
m None to RecordingOnly
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:3682 (TuningFrequency) TVRec[3]: TuningFrequenc
y
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent recorders/hdhrstreamhandler.cpp:385 (Connect) HDHRSH[3](19
2.168.0.100): Added 2 devices from 192.168.0.100
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent recorders/hdhrstreamhandler.cpp:403 (Connect) HDHRSH[3](19
2.168.0.100): Connected to device(1011F855-1)
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2934 (HandleRecordingStatusChange) Tuning rec
ording: "NBC Nightly News With Lester Holt": channel 10401 on cardid [3], sourceid 1
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: N Scheduler scheduler.cpp:3289 (HandleIdleShutdown) Blocking shutdown b
ecause of an active encoder
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: N Scheduler scheduler.cpp:3292 (HandleIdleShutdown) Blocking shutdown b
ecause of a connected client
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: C CoreContext programinfo.cpp:347 (ProgramInfo) ProgramInfo(): Failed t
o find recorded entry for 0.
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I CoreContext scheduler.cpp:729 (UpdateRecStatus) Updating status for "
NBC Nightly News With Lester Holt" on cardid [3] (Tuning => Recording)
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:4231 (TuningNewRecorder) TVRec[3]: rec->GetPath
name(): '/home/mythdbstorage/10401_20220721233000.ts'
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: I TVRecEvent tv_rec.cpp:4263 (TuningNewRecorder) TVRec[3]: TuningNewRec
order - CreateRecorder()
Jul 21 16:30:00 mediahog mythbackend: mythbackend[1378]: E TVRecEvent recorders/recorderbase.cpp:231 (SetStrOption) RecBase[3](1
92.168.0.100): SetStrOption(...recordingtype): Option not in profile.
Jul 21 16:34:48 mediahog mythbackend: mythbackend[1378]: N Expire autoexpire.cpp:261 (CalcParams) AutoExpire: CalcParams(): Max 
required Free Space: 3.0 GB w/freq: 7 min
Jul 21 16:36:54 mediahog mythbackend: mythbackend[1378]: I HDHRStreamHandler recorders/dtvrecorder.cpp:686 (HandleTimestamps) DT
VRec[3]: HandleTimestamps: too much damage, setting status to Failing
Jul 21 16:36:54 mediahog mythbackend: mythbackend[1378]: I CoreContext scheduler.cpp:729 (UpdateRecStatus) Updating status for "
NBC Nightly News With Lester Holt" on cardid [3] (Recording => Failing)
Jul 21 16:36:54 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested 
for CHECK -14 5961 0 UpdateRecStatus2 | NBC Nightly News With Lester Holt |  | The latest news, going beyond the headlines to se
e how lives are affected by the world around them. | EP023034512428
Jul 21 16:36:54 mediahog mythbackend: mythbackend[1378]: I Scheduler scheduler.cpp:2472 (HandleReschedule) Scheduled 116 items i
n 0.1 = 0.00 match + 0.10 check + 0.04 place


part of syslog

Jul 21 16:09:10 mediahog systemd[1]: Starting Clean php session files...
Jul 21 16:09:10 mediahog systemd[1]: Started Clean php session files.
Jul 21 16:15:01 mediahog CRON[987]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jul 21 16:17:01 mediahog CRON[1074]: (root) CMD (   cd / && run-parts --report /etc/cron.hourly)
Jul 21 16:25:01 mediahog CRON[1465]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jul 21 16:35:01 mediahog CRON[2106]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jul 21 16:39:01 mediahog CRON[2276]: (root) CMD (  [ -x /usr/lib/php/sessionclean ] && if [ ! -d /run/systemd/system ]; then /us
r/lib/php/sessionclean; fi)
Jul 21 16:39:10 mediahog systemd[1]: Starting Clean php session files...
Jul 21 16:39:10 mediahog systemd[1]: Started Clean php session files.
Jul 21 16:45:01 mediahog CRON[2557]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)
Jul 21 16:55:01 mediahog CRON[2925]: (root) CMD (command -v debian-sa1 > /dev/null && debian-sa1 1 1)

part of df -k output

/dev/sda3      861334344 800539760  17018228  98% /home
/dev/sdb7      935020576 919854876  15165700  99% /home/mythdbstorage2

Suggestions?

Thanks
Last edited by mathog on Wed Aug 10, 2022 12:57 am, edited 2 times in total.
mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by mathog »

Wife tried to record NBC (Kelly Clarkson) and ABC (General Hospital) at 3:00 today for half an hour. Again, the NBC show "lost". The ABC show is intact but the NBC recording was only 30 seconds long. I don't see any error messages.

Ran smartctl -t long on both disks. No problems detected.

Maybe one of the tuners is going? How would one determine from a recording which tuner was used?

EDIT: used "hdhomerun_config_gui" to look at 8vsb:7 (KABC-DT) and 8vsb:36 (NBC4-LA) at the same time. In both cases it showed 100% for Signal Strength, Signal Quality, and Symbol Quality. Looks like the tuners are working internally. Need to dig in my notes to see how to stream directly from
each tuner to a file - take mythtv out of the picture.
User avatar
kmdewaal
Developer
Posts: 644
Joined: Wed Dec 07, 2016 8:01 pm
Netherlands

Re: NBC nightly news bad when recording another show

Post by kmdewaal »

The log message

Code: Select all

Jul 21 16:36:54 mediahog mythbackend: mythbackend[1378]: I HDHRStreamHandler recorders/dtvrecorder.cpp:686 (HandleTimestamps) DT
VRec[3]: HandleTimestamps: too much damage, setting status to Failing
suggests to me that this can be a network problem.
If you have a network switch between the PC and the HDHomeRun, try replacing that switch or try a direct connection between PC and HDHomeRun.
Can also try another port on the same switch.
Can also try replacing cables.
Last but not least: it can be the power supply of the HDHomeRun. A power supply that begins to fail can create all sorts of problems.
mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by mathog »

I will check the power adapter voltage. Could be the switch or cable, but hard to see why those would work perfectly for one stream and fail specifically on one stream when both are going. Unfortunately the device doesn't show error counts (or any info really) about its ethernet interface.

Oddly in the setup section MythTV shows three hdhomerun sources, but of course there are only two. Mythtv seems to know that too, because if we schedule three shows it says only two can be recorded. Not sure what's up with that.

Also odd, the Dual's firmware is 20170930 but silicondust's firmware download for it shows only a firmware from 2016. Maybe they sent me a special one at some point, I don't recall, that was quite a while back. Need to dig out my notes to see where it came from.

Thanks.
chicobiker
Junior
Posts: 33
Joined: Thu Jun 26, 2014 8:47 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by chicobiker »

One of your tuners may have gone bad which would only exhibit a problem when both tuners in use at the same time. In mythweb I believe you can specify which tuner to record with. I recently updated firmware on my 4 tuner hdhomerun and the version is 2022 something. Not sure what your current firmware would be but that is worth checking too.
User avatar
paulh
Developer
Posts: 909
Joined: Thu Feb 06, 2014 6:09 pm
Great Britain

Re: NBC nightly news bad when recording another show

Post by paulh »

A common theme with the HDHomeRun is the failing power supplies causing problems so I'm with kmdewall it definitely the first thing I would eliminate. It could just be the extra processing required by 2 recordings is enough to push the power supply over.
mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by mathog »

Working on eliminating the power supply as an issue. Naturally when I tried to run the negative control today (two streams at once on the current PS) it worked without any problems, after failing every time in the last several attempts. I have a modified PC power supply with a 5V jack that fits the HDHomerun. Hopefully at some point I can find a show which fails with the old PS and works with the PC one. Or even a pair which fails with the PC power supply, which would rule out power as the issue.

I also tried removing and re-adding input devices, because it was showing 3 HDHomerun inputs in the recording rule (but would only use 2 of them) but there could not be more than two for the physical device. Now it only shows two, but they are numbered 3 and 4. This was after deleting all capture devices and starting over. Strange. Both 3 and 4 work though.

Edit: The PS reads 5.33V when plugged in and voltmeter probes applied, which is similar to the PC PS under the same conditions. Not a great test for a power supply, but I don't have components on hand to measure the voltage with 2.5A being drawn from the jack. Too bad the information on the HDHomerun device's web page does not include the current input voltage.
User avatar
paulh
Developer
Posts: 909
Joined: Thu Feb 06, 2014 6:09 pm
Great Britain

Re: NBC nightly news bad when recording another show

Post by paulh »

It's a process of elimination, if you are happy it's not the PS you can move on to something else like the router or network cable for example.

You mentioned problems with weather. It was just coincidence that in the UK over the weekend we had just the right weather conditions to produce co-channel interference typically caused by high air pressure which causes the signals from many distant transmitters to interfere with one another. I didn't check to see if we had problems where I am but I know other parts of the country had problems. It would likely cause drop-outs in the signal varying from minor glitches to complete signal loss depending on local conditions. It can effect some channels more than others depending on what frequencies each of the transmitters are using, if they overlap then you would expect a bigger chance of interference. Not sure if you get that in the US?
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: NBC nightly news bad when recording another show

Post by PhilB »

That /home partition is where recordings are made and it looks very full.
How much if it is expirable recordings?
What sort of disk and interface (shingle? Usb?).
Is it heavily fragmented?
How many inodes left?
Phil
mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by mathog »

PhilB wrote:
Mon Jul 25, 2022 2:32 pm
That /home partition is where recordings are made and it looks very full.
How much if it is expirable recordings?
What sort of disk and interface (shingle? Usb?).
Is it heavily fragmented?
How many inodes left?
Phil
It is set to use two partitions, the two shown.
Yes, they are very full.
It is almost entirely expirable recordings.
Hard drives, /home is ext4 and /home/mythdbstorag2 is xfs

Code: Select all


e4defrag -c /home
e4defrag 1.44.1 (24-Mar-2018)
<Fragmented files>                             now/best       size/ext
1. /home/david/.cache/mesa_shader_cache/index
                                                20/1              4 KB
2. /home/david/.config/chromium/ShaderCache/GPUCache/index
                                                16/1              4 KB
3. /home/david/.config/google-chrome/Default/Local Storage/leveldb/000007.log
                                                10/1              4 KB
4. /home/david/.config/google-chrome/Default/File System/Plugins/000/application_x-ppapi-widevine-cdm/Paths/000003.log
                                                 4/1              4 KB
5. /home/david/.config/google-chrome/ShaderCache/GPUCache/index
                                                20/1              5 KB

 Total/best extents                             56718/19210
 Average size per extent                        14057 KB
 Fragmentation score                            0
 [0-30 no problem: 31-55 a little bit fragmented: 56- needs defrag]
 This directory (/home) does not need defragmentation.
 Done.
Not sure what xfs fragmentation might even mean, but here goes anyway...

Code: Select all

xfs_db -r /home/mythdbstorage2
xfs_db: can't determine device size
root@mediahog:~# ls /dev/x*
ls: cannot access '/dev/x*': No such file or directory
root@mediahog:~# xfs_db -r /dev/sdb7
xfs_db> frag -d
actual 25, ideal 3, fragmentation factor 88.00%
Note, this number is largely meaningless.
Files on this filesystem average 8.33 extents per file
xfs_db> frag -f
actual 103275, ideal 1560, fragmentation factor 98.49%
Note, this number is largely meaningless.
Files on this filesystem average 66.20 extents per file
Defragmenting it now with xfs_fsr.

Only 1% of inodes are used on both of those.

Last night it messed up on NBC again 28 minutes into a 30 minute recording with ABC also recording. Plugged in the power supply and the next 30 minutes were good on both. Not very convincing though. Oddly it seems to be doing better now that I am trying to make it fail. Maybe the device/PS connectors were a little dirty and plugging and unplugging it a bunch of times is making a better connection? Anyway, at this point I will probably just buy another PS to leave in and see if the problem goes away. (The PC PS's fan is a little noisy, we wouldn't want to use that all the time.)
User avatar
kmdewaal
Developer
Posts: 644
Joined: Wed Dec 07, 2016 8:01 pm
Netherlands

Re: NBC nightly news bad when recording another show

Post by kmdewaal »

About using a PC power supply, it is good for testing but they can deliver far too much power and that gives a fire risk in case the HDHomeRun itself is failing. Replacing the power supply with a new one with the same rating as the original supply is definitely recommended.
Plugging and unplugging connectors can help, also on the network cabling.
PhilB
Senior
Posts: 403
Joined: Sun May 11, 2014 6:23 pm
Great Britain

Re: NBC nightly news bad when recording another show

Post by PhilB »

You don't have lots of zombie recordings do you?
viewtopic.php?f=2&t=4739
Phil
mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by mathog »

No zombie recordings - already checked that.

Stuff accumulates because my wife (who is the primary user by about 99:1) only explicitly deletes half the shows she records.

xfs_fsr didn't make very much difference:

Code: Select all

xfs_db -r /dev/sdb7
xfs_db> frag -d
actual 25, ideal 3, fragmentation factor 88.00%
Note, this number is largely meaningless.
Files on this filesystem average 8.33 extents per file
xfs_db> frag -f
actual 76737, ideal 1562, fragmentation factor 97.96%
Note, this number is largely meaningless.
Files on this filesystem average 49.13 extents per file
User avatar
kmdewaal
Developer
Posts: 644
Joined: Wed Dec 07, 2016 8:01 pm
Netherlands

Re: NBC nightly news bad when recording another show

Post by kmdewaal »

Stuff accumulates because my wife (who is the primary user by about 99:1) only explicitly deletes half the shows she records.
This does not matter if the recordings are allowed to auto-expire, but it could be a good idea to check that.
mathog
Senior
Posts: 124
Joined: Thu Dec 15, 2016 5:22 pm
United States of America

Re: NBC nightly news bad when recording another show

Post by mathog »

kmdewaal wrote:
Tue Jul 26, 2022 6:26 pm
Stuff accumulates because my wife (who is the primary user by about 99:1) only explicitly deletes half the shows she records.
This does not matter if the recordings are allowed to auto-expire, but it could be a good idea to check that.
They are set to auto-expire and there is a page somewhere or other which shows which are the next files to be removed.

Perhaps xfs_fsr is actually doing something. I have now run that three times. The "frag -d" report doesn't change but the frag -f
seems to be improving on each pass (even though it says one of the numbers is meaningless). The values are:

Code: Select all

xfs_db> frag -f
actual 103275, ideal 1560, fragmentation factor 98.49%
Note, this number is largely meaningless.
Files on this filesystem average 66.20 extents per file

xfs_db> frag -f
actual 76737, ideal 1562, fragmentation factor 97.96%
Note, this number is largely meaningless.
Files on this filesystem average 49.13 extents per file

xfs_db> frag -f
actual 22503, ideal 1562, fragmentation factor 93.06%
Note, this number is largely meaningless.
Files on this filesystem average 14.41 extents per file

xfs_db> frag -f
actual 1681, ideal 1562, fragmentation factor 7.08%
Note, this number is largely meaningless.
Files on this filesystem average 1.08 extents per file



Guess I'll run that a few more times and see what happens.

Ordering a new PS now too.

EDIT: one more xfs_fsr pass seems to have eliminated pretty much all of the existing fragmentation. Wee above.
I also changed the fstab mount option from

relatime

to

relatime,allocsize=512m

and rebooted. The large allocsize is supposed to minimize fragmentation going forward.
Post Reply