Occasional failed recordings

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

Moderator: Forum Moderators

Post Reply
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Occasional failed recordings

Post by AdamJacobs »

My MythTV setup works just fine most of the time, but every now and then (maybe 5-10% of recordings?) a recording fails. When that happens, I get no recording at all.

This is what my backend log looks like at the time:

Code: Select all

Nov 27 21:58:00 mythserver mythbackend: mythbackend[378165]: I TVRecEvent tv_rec.cpp:1057 (HandleStateChange) TVRec[17]: Changing from None to RecordingOnly
Nov 27 21:58:00 mythserver mythbackend: mythbackend[378165]: I TVRecEvent mythdbcon.cpp:419 (PurgeIdleConnections) New DB connection, total: 20
Nov 27 21:58:00 mythserver mythbackend: mythbackend[378165]: C CoreContext programinfo.cpp:257 (ProgramInfo) ProgramInfo(): Failed to find recorded entry for 0.
Nov 27 21:58:00 mythserver mythbackend: mythbackend[378165]: I TVRecEvent tv_rec.cpp:3662 (TuningFrequency) TVRec[17]: TuningFrequency
Nov 27 21:58:00 mythserver mythbackend: mythbackend[378165]: I TVRecEvent cardutil.cpp:1170 (SetDeliverySystem) CardUtil[17]: Set delivery system: DVB-T2
Nov 27 21:58:00 mythserver mythbackend: mythbackend[378165]: I Scheduler scheduler.cpp:2880 (HandleRecordingStatusChange) Tuning recording: Parasite: channel 51420 on cardid [17], sourceid 1
Nov 27 21:58:02 mythserver mythbackend: mythbackend[378165]: E HttpServer101 programinfo.cpp:2524 (GetPlaybackURL) ProgramInfo(51420_20211127215800.ts): GetPlaybackURL: '51420_20211127215800.ts' should be local, but it can not be found.
Nov 27 21:58:14 mythserver mythbackend: mythbackend[378165]: E TVRecEvent tv_rec.cpp:3967 (TuningSignalCheck) TVRec[17]: TuningSignalCheck: Hit pre-fail timeout
Nov 27 21:58:20 mythserver mythbackend: mythbackend[378165]: W TVRecEvent tv_rec.cpp:3995 (TuningSignalCheck) TVRec[17]: TuningSignalCheck: taking more than 20000 ms to get a lock. marking this recording as 'Failing'.
Nov 27 21:58:20 mythserver mythbackend: mythbackend[378165]: W TVRecEvent tv_rec.cpp:4000 (TuningSignalCheck) TVRec[17]: See 'Tuning timeout' in mythtv-setup for this input
Nov 27 21:58:20 mythserver mythbackend: mythbackend[378165]: I CoreContext scheduler.cpp:706 (UpdateRecStatus) Updating status for Parasite on cardid [17] (Tuning => Failing)

When I first saw that I had a tuning timeout, I increased the timeout limit, but as you see above it's already at 20 seconds, which I'm guessing is really as long as it's ever going to take if it's going to not time out at all.

I also get rather frequent errors in my backend log (typically a few per hour) that look like this:

Code: Select all

Nov 27 22:44:01 mythserver mythbackend: mythbackend[378165]: E TVRecEvent tv_rec.cpp:3954 (TuningSignalCheck) TVRec[20]: TuningSignalCheck: SignalMonitor timed out
Nov 27 22:44:01 mythserver mythbackend: mythbackend[378165]: I TVRecEvent tv_rec.cpp:3662 (TuningFrequency) TVRec[20]: TuningFrequency
Nov 27 22:44:01 mythserver mythbackend: mythbackend[378165]: I TVRecEvent cardutil.cpp:1170 (SetDeliverySystem) CardUtil[20]: Set delivery system: DVB-T2
Nov 27 22:44:01 mythserver mythbackend: mythbackend[378165]: E TVRecEvent tv_rec.cpp:3735 (TuningFrequency) TVRec[20]: Failed to set channel to . Reverting to kState_None
No idea whether that's related, but as it seems to be another timeout problem it seems worth mentioning.

I'm using Mythbackend 31.0 on Ubuntu 20.04, with a TBS 6285 tuner card.

Any ideas what the problem might be and how I could go about fixing it?

Thanks

Adam
User avatar
kmdewaal
Developer
Posts: 641
Joined: Wed Dec 07, 2016 8:01 pm
Netherlands

Re: Occasional failed recordings

Post by kmdewaal »

Could it be that you need to do a new channel scan with mythtv-setup.
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Re: Occasional failed recordings

Post by AdamJacobs »

I tried that already, though didn't delete all the existing channels first. Do you think that would be worth a try?
User avatar
kmdewaal
Developer
Posts: 641
Joined: Wed Dec 07, 2016 8:01 pm
Netherlands

Re: Occasional failed recordings

Post by kmdewaal »

It can make a difference. I suggest the following:
- create a new video source
- connect the capture card(s) to the new video source
- do a scan
and see how that works out.
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Re: Occasional failed recordings

Post by AdamJacobs »

Thanks, will give it a try and let you know how I get on
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Re: Occasional failed recordings

Post by AdamJacobs »

OK, I have created a new video source as you suggested. Looks like the first recording is recording OK, but it may be a while before I know if this has improved matters, as it was only occasional recordings that were failing previously.

I'm still getting the backend errors in the log that I mentioned in my second log file extract, but they seem to be less frequent now. Not sure if I should be happy that they're less frequent or worried that they haven't gone away altogether, but I guess time will tell.
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Re: Occasional failed recordings

Post by AdamJacobs »

Sadly this doesn't seem to have fixed the problem. I had another failed recording last night. I've had a dozen or so successful recordings since creating the new video source, but since it was only occasional recordings that were failing anyway, I don't really have any evidence that this has made any difference.

As far as I can tell, the behaviour is identical to when recordings were failing previously: I get the tuning timeout message, and no recording is created at all. Here is what the log looked like at the time the recording failed, which I think is pretty much identical to what it looked like before:

Code: Select all

Dec  7 22:18:00 mythserver mythbackend: mythbackend[1355]: I TVRecEvent tv_rec.cpp:1057 (HandleStateChange) TVRec[17]: Changing from None to RecordingOnly
Dec  7 22:18:00 mythserver mythbackend: mythbackend[1355]: I TVRecEvent mythdbcon.cpp:419 (PurgeIdleConnections) New DB connection, total: 18
Dec  7 22:18:00 mythserver mythbackend: mythbackend[1355]: I TVRecEvent tv_rec.cpp:3662 (TuningFrequency) TVRec[17]: TuningFrequency
Dec  7 22:18:00 mythserver mythbackend: mythbackend[1355]: C CoreContext programinfo.cpp:257 (ProgramInfo) ProgramInfo(): Failed to find recorded entry for 0.
Dec  7 22:18:00 mythserver mythbackend: mythbackend[1355]: I TVRecEvent cardutil.cpp:1170 (SetDeliverySystem) CardUtil[17]: Set delivery system: DVB-T2
Dec  7 22:18:00 mythserver mythbackend: mythbackend[1355]: I Scheduler scheduler.cpp:2880 (HandleRecordingStatusChange) Tuning recording: "Amazing Hotels":"Life Beyond the Lobby": channel 20002 on cardid [17], sourceid 2
Dec  7 22:18:02 mythserver mythbackend: mythbackend[1355]: E HttpServer100 programinfo.cpp:2524 (GetPlaybackURL) ProgramInfo(20002_20211207221800.ts): GetPlaybackURL: '20002_20211207221800.ts' should be local, but it can not be found.
Dec  7 22:18:14 mythserver mythbackend: mythbackend[1355]: E TVRecEvent tv_rec.cpp:3967 (TuningSignalCheck) TVRec[17]: TuningSignalCheck: Hit pre-fail timeout
Dec  7 22:18:20 mythserver mythbackend: mythbackend[1355]: W TVRecEvent tv_rec.cpp:3995 (TuningSignalCheck) TVRec[17]: TuningSignalCheck: taking more than 20000 ms to get a lock. marking this recording as 'Failing'.
Dec  7 22:18:20 mythserver mythbackend: mythbackend[1355]: W TVRecEvent tv_rec.cpp:4000 (TuningSignalCheck) TVRec[17]: See 'Tuning timeout' in mythtv-setup for this input
Dec  7 22:18:20 mythserver mythbackend: mythbackend[1355]: I CoreContext scheduler.cpp:706 (UpdateRecStatus) Updating status for "Amazing Hotels":"Life Beyond the Lobby" on cardid [17] (Tuning => Failing)
Dec  7 22:18:20 mythserver mythbackend: mythbackend[1355]: I Scheduler scheduler.cpp:2308 (HandleReschedule) Reschedule requested for CHECK -14 2412 0 UpdateRecStatus2 | Amazing Hotels | Life Beyond the Lobby | Giles Coren and Monica Galetti head to the Andean Cloud Forest of Ecuador to work at Mashpi Lodge, a $10-million modernist hotel. | fp.bbc.co.uk/b/5428bx
Dec  7 22:18:20 mythserver mythbackend: mythbackend[1355]: I Scheduler scheduler.cpp:2425 (HandleReschedule) Scheduled 197 items in 0.1 = 0.04 match + 0.00 check + 0.02 place
Any ideas what to try next?

Thanks,
Adam
jksj
Senior
Posts: 148
Joined: Thu Feb 13, 2014 7:53 pm
Great Britain

Re: Occasional failed recordings

Post by jksj »

What channel / transmitter was the above failed recording on? There were storm force winds last night which may have affected reception on a channel with marginal signal strength. You can monitor the signal strength with femon or dvb-fe-tool -a 0 --femon.
Check that your recording failures don't correlate with poor signal
https://manpages.debian.org/testing/dvb ... .1.en.html
https://manpages.debian.org/testing/dvb ... .1.en.html
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Re: Occasional failed recordings

Post by AdamJacobs »

Thanks for the suggestion. This is the output from femon: don't really have much of a feeling for whether 46% signal is good or bad?

Code: Select all

FE: TurboSight TBS 6285 DVB-T/T2/C (DVBT)
status SCVYL | signal  46% | snr  68% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  62% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  70% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  68% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  66% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  71% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  70% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  68% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  68% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  70% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  69% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  63% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  67% | ber 0 | unc 0 | FE_HAS_LOCK
status SCVYL | signal  46% | snr  67% | ber 0 | unc 0 | FE_HAS_LOCK

Does this fit with your suggestion of "marginal signal strength"?

The most recent failed recording was on BBC 2 (on freeview in the UK), although previous failed recordings have been on various different channels. I haven't noticed any particular pattern of which channels are more likely to fail than others. I believe my nearest transmitter is Hannington.
User avatar
kmdewaal
Developer
Posts: 641
Joined: Wed Dec 07, 2016 8:01 pm
Netherlands

Re: Occasional failed recordings

Post by kmdewaal »

Your signal looks OK to me.
It could be a hardware issue, such as an USB tuner with a flaky connection.
Do you have different tuners and is the issue related to just one tuner?
If you have an USB tuner, you can try using another USB port on your motherboard.
AdamJacobs
Junior
Posts: 18
Joined: Sat Dec 26, 2020 5:58 pm
Great Britain

Re: Occasional failed recordings

Post by AdamJacobs »

I don't have a USB tuner, it's a PCIe tuner card.
Post Reply