[Solved] Cannot Schedule Recording - Not Listed

[MoisiePants]

Hi:

I'm running an installation which generally works very well - but I'm having an issue scheduling a recording for tomorrow.

I'm in the UK, running DVB-T on a HDHomeRun; I'm running a build of 29.1 on Mac OS X.

My EPG data all looks believable. But when I attempt to schedule a recording for tomorrow (with Record This Showing), I get 'Single Record - Not Listed' displayed.

Looking at the Recording Status, I can see: 'This showing will not be recorded because this rule does not match any showings in the current program listings.'

The same problem is affecting a number of different programmes on a number of different channels - but not all.

I've tried scheduling for the +1 showing of the same film - and get the same result.
I've tried scheduling for 'Record Any Showing' - but neither of the two upcoming showings get flagged for recording.
I've stopped and restarted the backend - same problem.
I've run mythfilldatabase - same problem.
I've run the DB optimise script - same problem.
I can't see anything untoward in the logs.

Any ideas?!

Thanks!

[blm-ubunet]

Default rule setup has some strange configuration?
I'd go into recording rules & find "default" & make sure there are no special rules active.

[MoisiePants]

Hi Bim:

Thanks for the suggestion. Unfortunately there's nothing odd in my default rule - I suspect I haven't changed it from the, errrr, default...

Here are some screenshots showing the problem with an example programme:

https://ibb.co/wQ0ZKp2

https://ibb.co/whvNGF6

(Sorry - can't work out how to embed the images here at the moment)

Currently, I can't find a programme which is looking like it will record...

[blm-ubunet]

I guess if this only effects some program listings then there must be something wrong with some of the listings.
Do you have multiple defined video sources?
Does the problem correlate to a specific video source (& grabber)?
Do you use SD or MHEG EPG (extracted) or EIT

That recording status is set in mythbackend/scheduler.cpp.
Using Doxygen you might be able to deduce the logical flow.
https://code.mythtv.org/doxygen/schedul ... ource.html
(I've wasted hours in there trying to change the default behaviour of the scheduler)

I would run MBE from terminal as normal BE user.
sudo su -l mythtv
mythbackend -v schedule --loglevel=info > /tmp/MBElog.txt
And run FE from icon/menu/another-terminal & exercise "record" in program listings grid

[MoisiePants]

Hi:

Thanks for the suggestions - I'll do my best to answer...

I guess if this only effects some program listings then there must be something wrong with some of the listings.

At the moment, this does appear to affect all listings now... At least, I haven't yet found one I can schedule.

Do you have multiple defined video sources?

No - just a single video source, using OTA EPG.

Do you use SD or MHEG EPG (extracted) or EIT

Not sure!


Before I tried running again, I blew away all the channels and rescanned - but still having the same issue. Here are the backend log entries for when I attempt to schedule a new test recording (in this case 'Loose Women', using 'Record This Showing'):

Code: Select all

2019-11-15 11:14:41.404562 I [59569/17923] Scheduler scheduler.cpp:2357 (HandleReschedule) - Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
2019-11-15 11:14:41.407989 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 0: /record.recordid = :NR0RECID AND program.manualid = 0 AND program.title LIKE :NR0LIKEPHRASE1
2019-11-15 11:14:41.407997 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 1: /record.recordid = :NR1RECID AND program.manualid = 0 AND program.title LIKE :NR1LIKEPHRASE1
2019-11-15 11:14:41.408003 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 2: /record.recordid = :NR2RECID AND program.manualid = 0 AND program.title LIKE :NR2LIKEPHRASE1
2019-11-15 11:14:41.408008 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 3: /record.recordid = :NR3RECID AND program.manualid = 0 AND program.title LIKE :NR3LIKEPHRASE1
2019-11-15 11:14:41.408014 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 4: /record.recordid = :NR4RECID AND program.manualid = 0 AND program.title LIKE :NR4LIKEPHRASE1
2019-11-15 11:14:41.408020 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 5: /record.recordid = :NR5RECID AND program.manualid = 0 AND program.title LIKE :NR5LIKEPHRASE1
2019-11-15 11:14:41.408025 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 6: /record.recordid = :NR6RECID AND program.manualid = 0 AND program.title LIKE :NR6LIKEPHRASE1
2019-11-15 11:14:41.408030 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 7: /record.recordid = :NR7RECID AND program.manualid = 0 AND program.title LIKE :NR7LIKEPHRASE1
2019-11-15 11:14:41.408037 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 8: /record.recordid = :NR8RECID AND program.manualid = 0 AND (program.title LIKE :NR8LIKEPHRASE1 OR program.subtitle LIKE :NR8LIKEPHRASE2 OR program.description LIKE :NR8LIKEPHRASE3)
2019-11-15 11:14:41.408043 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 9: /record.recordid = :NR9RECID AND program.manualid = 0 AND (program.title LIKE :NR9LIKEPHRASE1 OR program.subtitle LIKE :NR9LIKEPHRASE2 OR program.description LIKE :NR9LIKEPHRASE3)
2019-11-15 11:14:41.408048 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 10: /record.type <> :NRTEMPLATE AND record.search = :NRST AND program.manualid = 0 AND program.title = record.title 
2019-11-15 11:14:41.408054 I [59569/17923] Scheduler scheduler.cpp:4051 (UpdateMatches) - Query 11: /record.type <> :NRTEMPLATE AND record.search = :NRST AND program.manualid = 0 AND program.seriesid <> '' AND program.seriesid = record.seriesid 
2019-11-15 11:14:41.408104 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 0...
2019-11-15 11:14:41.517578 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.109428 sec.
2019-11-15 11:14:41.517685 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 1...
2019-11-15 11:14:41.627501 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.109769 sec.
2019-11-15 11:14:41.627623 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 2...
2019-11-15 11:14:41.734619 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.106952 sec.
2019-11-15 11:14:41.734724 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 3...
2019-11-15 11:14:41.841827 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.107058 sec.
2019-11-15 11:14:41.841932 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 4...
2019-11-15 11:14:41.952548 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.110571 sec.
2019-11-15 11:14:41.952662 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 5...
2019-11-15 11:14:42.061305 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.108598 sec.
2019-11-15 11:14:42.061413 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 6...
2019-11-15 11:14:42.063197 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.001772 sec.
2019-11-15 11:14:42.063258 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 7...
2019-11-15 11:14:42.170464 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.107175 sec.
2019-11-15 11:14:42.170564 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 8...
2019-11-15 11:14:42.397700 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.227094 sec.
2019-11-15 11:14:42.397818 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 9...
2019-11-15 11:14:42.617766 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.219888 sec.
2019-11-15 11:14:42.617941 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 10...
2019-11-15 11:14:42.653968 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.035987 sec.
2019-11-15 11:14:42.654077 I [59569/17923] Scheduler scheduler.cpp:4094 (UpdateMatches) -  |-- Start DB Query 11...
2019-11-15 11:14:42.663144 I [59569/17923] Scheduler scheduler.cpp:4118 (UpdateMatches) -  |-- -1 results in 0.009055 sec.
2019-11-15 11:14:42.663173 I [59569/17923] Scheduler scheduler.cpp:4122 (UpdateMatches) -  +-- Done.
2019-11-15 11:14:42.669812 I [59569/17923] Scheduler scheduler.cpp:2432 (HandleReschedule) - CreateTempTables...
2019-11-15 11:14:42.918358 I [59569/17923] Scheduler scheduler.cpp:2438 (HandleReschedule) - UpdateDuplicates...
2019-11-15 11:14:43.157956 I [59569/17923] Scheduler scheduler.cpp:449 (FillRecordList) - BuildWorkList...
2019-11-15 11:14:43.157981 I [59569/17923] Scheduler scheduler.cpp:454 (FillRecordList) - AddNewRecords...
2019-11-15 11:14:43.159367 I [59569/17923] Scheduler scheduler.cpp:4483 (AddNewRecords) -  |-- Start DB Query...
2019-11-15 11:14:43.206756 I [59569/17923] Scheduler scheduler.cpp:4498 (AddNewRecords) -  |-- 708 results in 0.04736 sec. Processing...
2019-11-15 11:14:43.228223 I [59569/17923] Scheduler scheduler.cpp:4709 (AddNewRecords) -  +-- Cleanup...
2019-11-15 11:14:43.228365 I [59569/17923] Scheduler scheduler.cpp:456 (FillRecordList) - AddNotListed...
2019-11-15 11:14:43.228384 I [59569/17923] Scheduler scheduler.cpp:4746 (AddNotListed) -  |-- Start DB Query...
2019-11-15 11:14:43.230097 I [59569/17923] Scheduler scheduler.cpp:4764 (AddNotListed) -  |-- 37 results in 0.0017 sec. Processing...
2019-11-15 11:14:43.230634 I [59569/17923] Scheduler scheduler.cpp:459 (FillRecordList) - Sort by time...
2019-11-15 11:14:43.230991 I [59569/17923] Scheduler scheduler.cpp:461 (FillRecordList) - PruneOverlaps...
2019-11-15 11:14:43.231021 I [59569/17923] Scheduler scheduler.cpp:464 (FillRecordList) - Sort by priority...
2019-11-15 11:14:43.231474 I [59569/17923] Scheduler scheduler.cpp:466 (FillRecordList) - BuildListMaps...
2019-11-15 11:14:43.231683 I [59569/17923] Scheduler scheduler.cpp:468 (FillRecordList) - SchedNewRecords...
2019-11-15 11:14:43.236146 I [59569/17923] Scheduler scheduler.cpp:470 (FillRecordList) - SchedLiveTV...
2019-11-15 11:14:43.236155 I [59569/17923] Scheduler scheduler.cpp:472 (FillRecordList) - ClearListMaps...
2019-11-15 11:14:43.236339 I [59569/17923] Scheduler scheduler.cpp:477 (FillRecordList) - Sort by time...
2019-11-15 11:14:43.236749 I [59569/17923] Scheduler scheduler.cpp:479 (FillRecordList) - PruneRedundants...
2019-11-15 11:14:43.237616 I [59569/17923] Scheduler scheduler.cpp:482 (FillRecordList) - Sort by time...
2019-11-15 11:14:43.237630 I [59569/17923] Scheduler scheduler.cpp:484 (FillRecordList) - ClearWorkList...
2019-11-15 11:14:43.238045 I [59569/17923] Scheduler scheduler.cpp:2451 (HandleReschedule) - DeleteTempTables...
2019-11-15 11:14:43.251609 I [59569/17923] Scheduler scheduler.cpp:2470 (HandleReschedule) - Scheduled 84 items in 1.6 = 1.27 match + 0.24 check + 0.08 place
2019-11-15 11:14:43.251644 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-15T12:30:00Z/Loose Women
2019-11-15 11:14:43.252726 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-15T13:00:00Z/New Home DIY
2019-11-15 11:14:43.253735 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-15T13:30:00Z/New Home DIY
2019-11-15 11:14:43.254386 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-15T17:00:00Z/The Great British Garden Revival
2019-11-15 11:14:43.255030 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T12:00:00Z/The Yorkshire Dales and The Lakes
2019-11-15 11:14:43.255784 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T15:00:00Z/The Yorkshire Dales and The Lakes
2019-11-15 11:14:43.256475 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T16:00:00Z/The Yorkshire Dales and The Lakes
2019-11-15 11:14:43.257111 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T16:30:00Z/Four Rooms with Sarah Beeny
2019-11-15 11:14:43.257746 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T17:00:00Z/The Yorkshire Dales and The Lakes
2019-11-15 11:14:43.258394 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T19:00:00Z/Great British Car Journeys
2019-11-15 11:14:43.259036 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-16T19:00:00Z/The Yorkshire Dales and The Lakes
2019-11-15 11:14:43.259672 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-17T05:00:00Z/Grand Designs New Zealand
2019-11-15 11:14:43.260471 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-17T14:00:00Z/All Gardens Great and Small
2019-11-15 11:14:43.261420 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-17T17:35:00Z/The Dog House
2019-11-15 11:14:43.262359 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-17T19:00:00Z/Great Canal Journeys
2019-11-15 11:14:43.263022 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-17T20:00:00Z/Escape to the Chateau
2019-11-15 11:14:43.263748 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-18T05:35:00Z/Kirstie's Fill Your House for Free
2019-11-15 11:14:43.264561 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-18T18:15:00Z/Britain's Heritage Heroes
2019-11-15 11:14:43.265217 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-18T20:30:00Z/Save Well, Spend Better
2019-11-15 11:14:43.265891 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-18T21:45:00Z/God's Lone Country
2019-11-15 11:14:43.266668 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-18T22:00:00Z/Home Free
2019-11-15 11:14:43.267483 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T03:45:00Z/Grand Designs
2019-11-15 11:14:43.268199 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T05:35:00Z/Kirstie's Fill Your House for Free
2019-11-15 11:14:43.268915 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T15:00:00Z/Real Gardens
2019-11-15 11:14:43.269651 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T15:30:00Z/Real Gardens
2019-11-15 11:14:43.270311 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T18:15:00Z/Britain's Heritage Heroes
2019-11-15 11:14:43.270954 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T20:00:00Z/Food Unwrapped Goes Vegan
2019-11-15 11:14:43.271726 I [59569/17923] Scheduler recordinginfo.cpp:1244 (AddHistory) - AddHistory: 6/0, 1, 0, 2019-11-19T21:00:00Z/Boom, Bust & Bankers
2019-11-15 11:14:43.272550 I [59569/17923] Scheduler scheduler.cpp:2124 (run) - sleeping for 85001 ms (s2n: 4336 sr: 5 qr: 0 cs: 0)

Any clues in there?!

[MoisiePants]

Is it worth me getting rid of the guide data and letting it repopulate? Would I do this just by deleting the contents of the 'program' table in the DB?

[MoisiePants]

Hi:

Is it worth me getting rid of the guide data and letting it repopulate?

Ok - as this is affecting even newly-loaded guide data, I reasoned this wouldn't help matters.

I turned the logging up to debug, and captured the output whilst scheduling another programme - 'The Hurt Locker' on BBC TWO at 23:00 2019-11-17. The log output is too large to post directly here, so:

https://pastebin.com/4FbfpVXU

Any ideas? Please help!!!

Thanks.

[MoisiePants]

Ok - stand down everyone. I'm an idiot...

It seems I had modified the default record rule to enable Schedule Options > Schedule Filters > High Definition.

Then when I attempted to schedule recordings on SD channels, it couldn't find a match... Now that I've disabled the filter, scheduling is working as expected again.

Sorry for the noise...

[blm-ubunet]

Good you solved it.
I only got around to grabbing schedule logs from a working system last night to compare.
But not sure that would have helped.

[MoisiePants]

Thanks for your help Bim - very much appreciated!