[Solved] Unexpected Recording Conflicts

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

Moderator: Forum Moderators

pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

[Solved] Unexpected Recording Conflicts

Post by pinnerite »

Having got Mythtv 29.0 to work smoothly, I started to select programs to record.
I was surprised and disappointed when I found that many selections were in conflict.
I should have been able to record at least two programs at the same time as my
TBS-6280 has two DVB-T2 tuners.

# dmesg | grep -iC 3 "Turbo" showed that both tuners were detected and registered.

# lsof /dev/dvb/adapter0/frontend0 and /dev/dvb/adapter1/frontend0 showed:

lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
mythbacke 1180 mythtv 38u CHR 212,3 0t0 577 /dev/dvb/adapter0/frontend0

lsof: WARNING: can't stat() fuse.gvfsd-fuse file system /run/user/1000/gvfs
Output information may be incomplete.
COMMAND PID USER FD TYPE DEVICE SIZE/OFF NODE NAME
mythbacke 1180 mythtv 15u CHR 212,7 0t0 582 /dev/dvb/adapter1/frontend0

I do not know what else to check?
wesnewell
Senior
Posts: 731
Joined: Mon Jun 23, 2014 6:54 pm
Location: Wylie TX, USA
United States of America

Re: Unexpected Recording Conflicts

Post by wesnewell »

Check system status and make sure all your tuners are available for recording.
BE/FE-Asrock AB350 Pro Ryzen 3 3200G, 6 atsc tuners. FE's-GF8200's Athlon II, Ryzen 3 2200G. Mythtv user since 2005.
MikeB2013
Senior
Posts: 519
Joined: Mon Jul 25, 2016 4:16 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by MikeB2013 »

The lsof messages are normal when running the command as root and the device is in use.

If you run "dmesg | grep frontend" you should see :

Code: Select all

mike@1804-test:~$ dmesg |grep front
[   10.981381] SAA716x Budget 0000:02:00.0: DVB: registering adapter 0 frontend 0 (TurboSight TBS 6280 DVB-T/T2/C)...
[   10.988448] SAA716x Budget 0000:02:00.0: DVB: registering adapter 1 frontend 0 (TurboSight TBS 6280 DVB-T/T2/C)...
Can you confirm that you are running the latest TBS Opensource drivers from https://github.com/tbsdtv/linux_media/wiki

For the TBS 6280 you should also have a setting in a /etc/modprobe.d/ .conf file to set saa7164 interrupts to MSI (otherwise recordings can fail after a period) see https://www.linuxtv.org/wiki/index.php/ ... IRQ_Issues

None of the above affects your conflicts issues, the mythtv scheduler seems to think there are insufficient tuners to satisfy recording requests.
You can see some more details on what the scheduler is doing by running in a terminal session:
mythbackend --printsched

See https://www.mythtv.org/wiki/Mythbackend for details on --printsched

Also you can record more that one program on each tuner, providing they are on the the same multiplex, by setting Max recordings (mythtv-setup>Input Connections>Interactions between inputs) to a higher number (default is 1, 5 is probably ok). Note depending on your system configuration motherboard, cpu, disks, ram etc you maybe able to go higher than 5 or you may need to reduce it from 5 if you are getting bad recordings.
pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by pinnerite »

I originally had the Max recordings set to 1 for adapter 0 and 4 for adapter 1 (no idea why).
I changed adapter 0 to a max of 3 and following a modification to a different application, I rebooted.

After restarting:

Schedule Status reported:
1 Conflicting
19 will record on card 1 "Adapter0"
1 Will record on card 3 "Adapter0"

Tuner Status reported
Tuners 1, 3 & 4 "not recording"
Tuners 2, 6 & 7 "has an error"
Tuner 5 is not mentioned at all!

# dmesg | grep frontend
[ 16.227211] SAA716x Budget 0000:01:00.0: DVB: registering adapter 0 frontend 0 (TurboSight TBS 6280 DVB-T/T2/C)...
[ 16.233164] SAA716x Budget 0000:01:00.0: DVB: registering adapter 1 frontend 0 (TurboSight TBS 6280 DVB-T/T2/C)...

The driver package that I am using, suggested by TBS support last year is:
# wget http://www.tbsdtv.com/download/document ... 25.tar.bz2

I had already compensated for IRQ errors. I did have IRQ problems a year ago when my mouse began to crawl.

Following the reboot, I scanned the backend log for clues. These are a few if the truncated lines:

DVBChan[1](/dev/dvb/adapter0/frontend0): Failed to open DVB frontend device due to fatal error or too many attempts.

(setupTVs) Problem with capture cards. Card 3 failed init

DVBChan[1](/dev/dvb/adapter0/frontend0): Opening DVB frontend device failed.

ConnectToMasterServer(): ERROR: Master backend tried to connect back to itself!

DTVChan[4](/dev/dvb/adapter0/frontend0): SetChannelByString(107): Requested channel '107' is on input '4' which is in a busy input group

ChannelBase[4]: IsTunable(107) Requested channel is on input '4' which is in a busy input group

Setting start channel '107' failed, #012#011#011#011and we failed to find any suitible channels on any input.

DTVChan[6](/dev/dvb/adapter1/frontend0): SetChannelByString(62): Requested channel '62' is on input '6' which is in a busy input group

ChannelBase[6]: IsTunable(62) Requested channel is on input '6' which is in a busy input group

DTVChan[7](/dev/dvb/adapter1/frontend0): SetChannelByString(62): Requested channel '62' is on input '7' which is in a busy input group

ChannelBase[7]: IsTunable(62) Requested channel is on input '7' which is in a busy input group

Failed listening on TCP 0.0.0.0:6543 - Error 8: The bound address is already in use

DVBChan[1](/dev/dvb/adapter0/frontend0): Next tuning after less than 1000ms. Delaying by 1000ms

mythtbackend --printsched Only confirmed what the menus displayed.
MikeB2013
Senior
Posts: 519
Joined: Mon Jul 25, 2016 4:16 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by MikeB2013 »

DVBChan[1](/dev/dvb/adapter0/frontend0): Failed to open DVB frontend device due to fatal error or too many attempts.
(setupTVs) Problem with capture cards. Card 3 failed init
DVBChan[1](/dev/dvb/adapter0/frontend0): Opening DVB frontend device failed.
ConnectToMasterServer(): ERROR: Master backend tried to connect back to itself!

These are all major issues and indicate dvb driver problems.

The driver package suggested by TBS support is now well out of date, particularly for later kernels e.g. 4.15 and later.
My system with a TBS 6280 and a TBS 6981 is running Xubuntu 18.04.2 with a 4.18 (HWE) series kernel with latest TBS Open source drivers ( git commit f539dd63c).

I suggest you build and install the latest TBS drivers at https://github.com/tbsdtv/linux_media/wiki
Tip:
Immediately before the "sudo make install" step you should run:

Code: Select all

sudo rm -rf /lib/modules/``uname -r``/kernel/drivers/media/*
and then do the "sudo make install" followed by a reboot.

Mike
pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by pinnerite »

The replacement driver process went smoothly.

I changed the 'Max' values for both tuners to '5' and set the recording process to record five programmes currently being broadcast.

The result was much the same with similar conflicts as earlier.

This is the complete backend log for this morning. Sadly I cannot interpret it:
Mar 7 11:49:44 origen mythbackend: mythbackend[13160]: I CoreContext recorders/dvbchannel.cpp:714 (Tune) DVBChan[2](/dev/dvb/adapter1/frontend0): Next tuning after less than 1000ms. Delaying by 1000ms
Mar 7 11:49:45 origen mythbackend: mythbackend[13160]: I CoreContext recorders/dvbchannel.cpp:714 (Tune) DVBChan[1](/dev/dvb/adapter0/frontend0): Next tuning after less than 1000ms. Delaying by 1000ms


Mar 7 11:49:56 origen mythbackend: mythbackend[13160]: I CoreContext bonjourregister.cpp:118 (BonjourCallback) Bonjour: Service registration complete: name 'Mythbackend on origen.asandco' type '_mythbackend._tcp.' domain: 'local.'
Mar 7 11:50:51 origen mythbackend: mythbackend[13160]: I MythSocketThread(9) mainserver.cpp:7693 (connectionClosed) Control sock(5640b5c5e9b0) disconnected

0b5ae6e90) as a client (events: 0)
Mar 7 11:50:56 origen mythbackend: mythbackend[13160]: I ProcessRequest backendcontext.cpp:68 (SetFrontendConnected) BackendContext: Frontend 'origen.asandco' connected.
M
Mar 7 11:51:06 origen mythbackend: mythbackend[13160]: I HouseKeeping housekeeper.cpp:153 (Run) HouseKeeperTask 'HardwareProfiler' Finished Successfully.

Mar 7 11:51:06 origen mythbackend: mythbackend[13160]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'ThemeUpdateNotifications'.
Mar 7 11:51:06 origen mythbackend: mythbackend[13160]: I HouseKeeping backendhousekeeper.cpp:397 (DoRun) Loading themes for 29
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124000.ts): GetPlaybackURL: '1081_20190305124000.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120001.ts): GetPlaybackURL: '1057_20190305120001.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124001.ts): GetPlaybackURL: '1081_20190305124001.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120000.ts): GetPlaybackURL: '1057_20190305120000.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225500.ts): GetPlaybackURL: '1048_20190306225500.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225500.ts): GetPlaybackURL: '1048_20190306225500.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124001.ts): GetPlaybackURL: '1081_20190305124001.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124000.ts): GetPlaybackURL: '1081_20190305124000.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120001.ts): GetPlaybackURL: '1057_20190305120001.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120000.ts): GetPlaybackURL: '1057_20190305120000.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225500.ts): GetPlaybackURL: '1048_20190306225500.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124001.ts): GetPlaybackURL: '1081_20190305124001.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124000.ts): GetPlaybackURL: '1081_20190305124000.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120001.ts): GetPlaybackURL: '1057_20190305120001.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120000.ts): GetPlaybackURL: '1057_20190305120000.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:09 origen mythbackend: mythbackend[13160]: E ProcessRequest mainserver.cpp:7280 (HandleGenPreviewPixmap) MainServer: HandleGenPreviewPixmap: Unable to find file locally, unable to make preview image.
Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: E DownloadManager mythdownloadmanager.cpp:1547 (saveFile) Failed to open: '/home/mythtv/.mythtv/tmp/remotethemes/themes.zip'
Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: E HouseKeeping mythcoreutil.cpp:81 (extractZIP) extractZIP(): Unable to open ZIP file /home/mythtv/.mythtv/tmp/remotethemes/themes.zip
Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: E HouseKeeping backendhousekeeper.cpp:458 (LoadVersion) HouseKeeper: Error extracting /home/mythtv/.mythtv/tmp/remotethemes/themes.zip remote themes info package.

Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: I HouseKeeping backendhousekeeper.cpp:411 (DoRun) Loading themes for 29.1
Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: E DownloadManager mythdownloadmanager.cpp:1547 (saveFile) Failed to open: '/home/mythtv/.mythtv/tmp/remotethemes/themes.zip'
Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: I HouseKeeping backendhousekeeper.cpp:450 (LoadVersion) HouseKeeper: Failed to download http://themes.mythtv.org/themes/reposit ... themes.zip remote themes info package.
Mar 7 11:51:10 origen mythbackend: mythbackend[13160]: I HouseKeeping housekeeper.cpp:149 (Run) HouseKeeperTask 'ThemeUpdateNotifications' Failed.


Mar 7 11:51:17 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:27 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225501.ts): GetPlaybackURL: '1048_20190306225501.ts' should be local, but it can not be found.
Mar 7 11:51:27 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK 0 209 0 DoHandleDelete3 | Cross The Line | | A call centre operator (Mischa Barton) and her estranged husband (Luke Goss), a Senior Police Officer, are kidnapped and held hostage in this action thriller. | movies4men.co.uk/e4029772
Mar 7 11:51:27 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225500.ts): GetPlaybackURL: '1048_20190306225500.ts' should be local, but it can not be found.
Mar 7 11:51:27 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
Mar 7 11:51:30 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:129 (delete_file_immediately) MainServer: Error deleting 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1048_20190306225501.ts': No such file or directory
Mar 7 11:51:32 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 493 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1048_20190306225501.ts
Mar 7 11:51:32 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 493 (chanid 1048 at 2019-03-06T22:55:01Z)
Mar 7 11:51:34 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1048_20190306225500.ts): GetPlaybackURL: '1048_20190306225500.ts' should be local, but it can not be found.
Mar 7 11:51:34 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK 0 209 0 DoHandleDelete3 | Cross The Line | | A call centre operator (Mischa Barton) and her estranged husband (Luke Goss), a Senior Police Officer, are kidnapped and held hostage in this action thriller. | movies4men.co.uk/e4029772
Mar 7 11:51:34 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124001.ts): GetPlaybackURL: '1081_20190305124001.ts' should be local, but it can not be found.
Mar 7 11:51:34 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
Mar 7 11:51:37 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:129 (delete_file_immediately) MainServer: Error deleting 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1048_20190306225500.ts': No such file or directory
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 492 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1048_20190306225500.ts
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: E DeleteThread mythdb.cpp:183 (DBError) DB Error (RecordedFiles deletion):#012Query was:#012SELECT basename, hostname, storagegroup FROM recordedfile WHERE recordedid = ?;#012Bindings were:#012:RECORDEDID=492#012No error type from QSqlError? Strange...
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:2468 (DeleteRecordedFiles) MainServer: Error querying recordedfiles for recording id 492 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1048_20190306225500.ts.
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 492 (chanid 1048 at 2019-03-06T22:55:00Z)
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124001.ts): GetPlaybackURL: '1081_20190305124001.ts' should be local, but it can not be found.
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK 0 199 0 DoHandleDelete3 | Dilemma | | 1962. Crime. In this critically acclaimed British film, Harry returns home from work to be told by a neighbour that screams came from his house moments earlier. Starring Patricia Burke & Robert Dean. |
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124000.ts): GetPlaybackURL: '1081_20190305124000.ts' should be local, but it can not be found.
Mar 7 11:51:39 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
Mar 7 11:51:43 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 11:51:43 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:129 (delete_file_immediately) MainServer: Error deleting 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1081_20190305124001.ts': No such file or directory
Mar 7 11:51:43 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1081_20190305124000.ts): GetPlaybackURL: '1081_20190305124000.ts' should be local, but it can not be found.
Mar 7 11:51:43 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK 0 199 0 DoHandleDelete3 | Dilemma | | 1962. Crime. In this critically acclaimed British film, Harry returns home from work to be told by a neighbour that screams came from his house moments earlier. Starring Patricia Burke & Robert Dean. |
Mar 7 11:51:43 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120001.ts): GetPlaybackURL: '1057_20190305120001.ts' should be local, but it can not be found.
Mar 7 11:51:43 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
Mar 7 11:51:45 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 491 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1081_20190305124001.ts
Mar 7 11:51:45 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 491 (chanid 1081 at 2019-03-05T12:40:01Z)
Mar 7 11:51:47 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120001.ts): GetPlaybackURL: '1057_20190305120001.ts' should be local, but it can not be found.
Mar 7 11:51:47 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK 0 198 0 DoHandleDelete3 | Trust No One | | Thriller starring Nicole de Boer and Scott Gibson. A district attorney brings in a forensics professor to help investigate a murder. | www.five.tv/v3pwtdt
Mar 7 11:51:47 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120000.ts): GetPlaybackURL: '1057_20190305120000.ts' should be local, but it can not be found.
Mar 7 11:51:47 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
Mar 7 11:51:49 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:129 (delete_file_immediately) MainServer: Error deleting 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1081_20190305124000.ts': No such file or directory
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 490 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1081_20190305124000.ts
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: E DeleteThread mythdb.cpp:183 (DBError) DB Error (RecordedFiles deletion):#012Query was:#012SELECT basename, hostname, storagegroup FROM recordedfile WHERE recordedid = ?;#012Bindings were:#012:RECORDEDID=490#012No error type from QSqlError? Strange...
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:2468 (DeleteRecordedFiles) MainServer: Error querying recordedfiles for recording id 490 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1081_20190305124000.ts.
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 490 (chanid 1081 at 2019-03-05T12:40:00Z)
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: E ProcessRequest programinfo.cpp:2608 (GetPlaybackURL) ProgramInfo(1057_20190305120000.ts): GetPlaybackURL: '1057_20190305120000.ts' should be local, but it can not be found.
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK 0 198 0 DoHandleDelete3 | Trust No One | | Thriller starring Nicole de Boer and Scott Gibson. A district attorney brings in a forensics professor to help investigate a murder. | www.five.tv/v3pwtdt
Mar 7 11:51:51 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.00 match + 0.00 check + 0.02 place
Mar 7 11:51:55 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:129 (delete_file_immediately) MainServer: Error deleting 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1057_20190305120001.ts': No such file or directory
Mar 7 11:51:57 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 489 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1057_20190305120001.ts
Mar 7 11:51:57 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 489 (chanid 1057 at 2019-03-05T12:00:01Z)
Mar 7 11:51:57 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar 7 11:51:57 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: origen.asandco(5640b5c69510) as a client (events: 0)
Mar 7 11:52:01 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:129 (delete_file_immediately) MainServer: Error deleting 'GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1057_20190305120000.ts': No such file or directory
Mar 7 11:52:03 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 488 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1057_20190305120000.ts
Mar 7 11:52:03 origen mythbackend: mythbackend[13160]: E DeleteThread mythdb.cpp:183 (DBError) DB Error (RecordedFiles deletion):#012Query was:#012SELECT basename, hostname, storagegroup FROM recordedfile WHERE recordedid = ?;#012Bindings were:#012:RECORDEDID=488#012No error type from QSqlError? Strange...
Mar 7 11:52:03 origen mythbackend: mythbackend[13160]: E DeleteThread mainserver.cpp:2468 (DeleteRecordedFiles) MainServer: Error querying recordedfiles for recording id 488 filename GetPlaybackURL/UNABLE/TO/FIND/LOCAL/FILE/ON/origen.asandco/1057_20190305120000.ts.
Mar 7 11:52:03 origen mythbackend: mythbackend[13160]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 488 (chanid 1057 at 2019-03-05T12:00:00Z)
Mar 7 11:52:05 origen mythbackend: mythbackend[13160]: I MythSocketThread(115) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c69510) 'origen.asandco' disconnected
Mar 7 11:52:33 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 11:54:44 origen mythbackend: mythbackend[13160]: I ProcessRequest mythdbcon.cpp:462 (getStaticCon) New static DB connectionDataDirectCon
Mar 7 11:54:45 origen mythbackend: mythbackend[13160]: I ProcessRequest scheduler.cpp:578 (FillRecordListFromDB) Speculative scheduled 13 items in 0.1 = 0.06 match + 0.00 check + 0.01 place
Mar 7 11:54:53 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 11:54:53 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 11:57:00 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-14T23:55:00Z EITScanner
Mar 7 11:57:00 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 11:57:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 11:57:53 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-14T23:35:00Z EITScanner
Mar 7 11:57:53 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 11:57:53 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 14 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[2]: ASK_RECORDING 2 0 0 0
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[1]: Changing from None to RecordingOnly
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[9]: ASK_RECORDING 9 0 0 0
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[10]: ASK_RECORDING 10 0 0 0
Mar 7 12:00:57 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[11]: ASK_RECORDING 11 0 0 0
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: C CoreContext programinfo.cpp:340 (ProgramInfo) ProgramInfo(): Failed to find recorded entry for 0.
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[3]: ASK_RECORDING 3 0 0 0
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2923 (HandleRecordingStatusChange) Tuning recording: A1:"Britain's Longest Road": channel 1001 on cardid [1], sourceid 1
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[4]: ASK_RECORDING 4 0 0 0
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[6]: ASK_RECORDING 6 0 0 0
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[7]: ASK_RECORDING 7 0 0 0
Mar 7 12:00:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[8]: ASK_RECORDING 8 0 0 0
Mar 7 12:00:59 origen mythbackend: mythbackend[13160]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for A1:"Britain's Longest Road" on cardid [1] (Tuning => Recording)
Mar 7 12:00:59 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:4192 (TuningNewRecorder) TVRec[1]: rec->GetPathname(): '/home/mythtv/default/1001_20190307120100.ts'
Mar 7 12:00:59 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:4224 (TuningNewRecorder) TVRec[1]: TuningNewRecorder - CreateRecorder()
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 15 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[1]: ASK_RECORDING 1 0 0 0
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[2]: Changing from None to RecordingOnly
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[4]: ASK_RECORDING 4 0 0 0
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[6]: ASK_RECORDING 6 0 0 0
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[7]: ASK_RECORDING 7 0 0 0
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: C CoreContext programinfo.cpp:340 (ProgramInfo) ProgramInfo(): Failed to find recorded entry for 0.
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[8]: ASK_RECORDING 8 0 0 0
Mar 7 12:01:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2923 (HandleRecordingStatusChange) Tuning recording: "BBC Newsroom Live": channel 1002 on cardid [2], sourceid 1
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[9]: ASK_RECORDING 9 0 0 0
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[10]: ASK_RECORDING 10 0 0 0
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[11]: ASK_RECORDING 11 0 0 0
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[3]: ASK_RECORDING 3 0 0 0
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for "BBC Newsroom Live" on cardid [2] (Tuning => Recording)
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:4192 (TuningNewRecorder) TVRec[2]: rec->GetPathname(): '/home/mythtv/default/1002_20190307120100.ts'
Mar 7 12:01:03 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:4224 (TuningNewRecorder) TVRec[2]: TuningNewRecorder - CreateRecorder()
Mar 7 12:01:06 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 12:01:06 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 16 items in 0.0 = 0.01 match + 0.00 check + 0.03 place
Mar 7 12:01:11 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 12:01:11 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 17 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:01:17 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 12:01:17 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 18 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:01:21 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 7 12:01:21 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 19 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:02:28 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-14T23:45:00Z EITScanner
Mar 7 12:02:28 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 19 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:03:54 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T13:00:00Z EITScanner
Mar 7 12:03:54 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 19 items in 0.0 = 0.01 match + 0.00 check + 0.03 place
Mar 7 12:06:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min
Mar 7 12:07:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T13:05:00Z EITScanner
Mar 7 12:07:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 18 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:07:09 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-14T23:55:00Z EITScanner
Mar 7 12:07:09 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 18 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:09:07 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T12:05:00Z EITScanner
Mar 7 12:09:07 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 18 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:09:09 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T12:30:00Z EITScanner
Mar 7 12:09:09 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 18 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:11:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T12:10:00Z EITScanner
Mar 7 12:11:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 17 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:11:06 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T13:05:00Z EITScanner
Mar 7 12:11:06 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 17 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:13:26 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T12:15:00Z EITScanner
Mar 7 12:13:26 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 17 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:14:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min

Mar 7 12:15:06 origen mythbackend: mythbackend[13160]: I MythSocketThread(74) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c08780) 'origen.asandco' disconnected
Mar 7 12:15:06 origen mythbackend: mythbackend[13160]: I MythSocketThread(121) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c60060) 'origen.asandco' disconnected
Mar 7 12:15:06 origen mythbackend: mythbackend[13160]: I Metadata_278 jobqueue.cpp:2157 (DoMetadataLookupThread) JobQueue: Metadata Lookup Starting for "BBC Newsroom Live" recorded from channel 1002 at 2019-03-07T12:01:00Z
Mar 7 12:15:08 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar 7 12:15:08 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: origen.asandco(5640b5c60060) as a client (events: 0)
Mar 7 12:15:08 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor

Mar 7 12:15:10 origen mythbackend: mythbackend[13160]: I MythSocketThread(74) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c60060) 'origen.asandco' disconnected
Mar 7 12:15:10 origen mythbackend: mythbackend[13160]: I MythSocketThread(121) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c08780) 'origen.asandco' disconnected
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[1]: Changing from RecordingOnly to None
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[2]: Changing from RecordingOnly to None
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: N RecThread recorders/recorderbase.cpp:501 (FinishRecording) Finished Recording: Container: MPEG2-TS Video Codec: mpeg2video (704x576 A/R: 3 25fps) Audio Codec: mp2
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I TVRecEvent recordinginfo.cpp:1186 (FinishedRecording) Finished recording A1 "Britain's Longest Road": channel 1001
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for A1:"Britain's Longest Road" on cardid [1] (Recording => Recorded)
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK -3 252 0 UpdateRecStatus2 | A1 | Britain's Longest Road | A drunk and dangerous driver is caught on camera, and Northumbria police respond to a distressing call-out with heartbreaking news. | fp.bbc.co.uk/241nrr
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 15 items in 0.0 = 0.00 match + 0.00 check + 0.03 place
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: N RecThread recorders/recorderbase.cpp:501 (FinishRecording) Finished Recording: Container: MPEG2-TS Video Codec: mpeg2video (704x576 A/R: 3 25fps) Audio Codec: mp2
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I TVRecEvent recordinginfo.cpp:1186 (FinishedRecording) Finished recording BBC Newsroom Live: channel 1002
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for "BBC Newsroom Live" on cardid [2] (Recording => Recorded)
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for CHECK -3 253 0 UpdateRecStatus2 | BBC Newsroom Live | | Stay up to date on the day's top stories, with the latest breaking news as it happens. | fp.bbc.co.uk/m/1xyo
Mar 7 12:15:30 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 14 items in 0.0 = 0.00 match + 0.00 check + 0.02 place

Mar 7 12:15:42 origen mythbackend: mythbackend[13160]: I MythSocketThread(87) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5b9b170) 'origen.asandco' disconnected
Mar 7 12:15:42 origen mythbackend: mythbackend[13160]: I MythSocketThread(91) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c67d90) 'origen.asandco' disconnected
Mar 7 12:15:45 origen mythbackend: mythbackend[13160]: I MythSocketThread(63) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c99590) 'origen.asandco' disconnected
Mar 7 12:15:45 origen mythbackend: mythbackend[13160]: I MythSocketThread(85) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c08780) 'origen.asandco' disconnected
Mar 7 12:16:05 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 2019-03-07T13:15:00Z EITScanner
Mar 7 12:16:05 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 14 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:16:11 origen mythbackend: mythbackend[13160]: I Commflag_279 jobqueue.cpp:2282 (DoFlagCommercialsThread) JobQueue: Commercial Detection Starting for A1:"Britain's Longest Road" recorded from channel 1001 at 2019-03-07T12:01:00Z
M
Mar 7 12:17:53 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 12:18:25 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 12:18:51 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[2](0x7fd95419f4c0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 12:19:51 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[2](0x7fd95419f4c0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried

Mar 7 12:22:40 origen mythbackend: mythbackend[13160]: I MythSocketThread(62) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c9dfd0) 'origen.asandco' disconnected
Mar 7 12:22:40 origen mythbackend: mythbackend[13160]: I MythSocketThread(65) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c041b0) 'origen.asandco' disconnected

Mar 7 12:22:42 origen mythbackend: mythbackend[13160]: I MythSocketThread(65) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5b9b170) 'origen.asandco' disconnected
Mar 7 12:22:42 origen mythbackend: mythbackend[13160]: I MythSocketThread(125) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b59ec5d0) 'origen.asandco' disconnected

Mar 7 12:29:32 origen mythbackend: mythbackend[13160]: I MythSocketThread(62) mainserver.cpp:7643 (connectionClosed) Monitor sock(7fd88c01bcc0) 'origen.asandco' disconnected
Mar 7 12:29:32 origen mythbackend: mythbackend[13160]: I MythSocketThread(74) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c60060) 'origen.asandco' disconnected
Mar 7 12:29:33 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar 7 12:29:33 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: origen.asandco(5640b5c60060) as a client (events: 0)
Mar 7 12:29:33 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar 7 12:29:33 origen mythbackend: mythbackend[13160]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: origen.asandco(7fd88c01bcc0) as a client (events: 1)
Mar 7 12:29:35 origen mythbackend: mythbackend[13160]: I MythSocketThread(74) mainserver.cpp:7643 (connectionClosed) Monitor sock(5640b5c60060) 'origen.asandco' disconnected
Mar 7 12:29:35 origen mythbackend: mythbackend[13160]: I MythSocketThread(121) mainserver.cpp:7643 (connectionClosed) Monitor sock(7fd88c01bcc0) 'origen.asandco' disconnected
Mar 7 12:33:59 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T17:30:00Z EITScanner
Mar 7 12:33:59 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 12:33:59 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 12:34:18 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-14T23:30:00Z EITScanner
Mar 7 12:34:18 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place

Mar 7 12:50:57 origen mythbackend: mythbackend[13160]: I MythSocketThread(127) mainserver.cpp:7681 (connectionClosed) FileTransfer sock(7fd88c01bcc0) disconnected
Mar 7 12:50:57 origen mythbackend: mythbackend[13160]: I MythSocketThread(125) mainserver.cpp:7643 (connectionClosed) Playback sock(5640b59ab3c0) 'origen.asandco' disconnected
Mar 7 12:52:18 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd95819d4b0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 12:53:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
Mar 7 12:53:24 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd95819d4b0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 12:54:43 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 12:56:11 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-10T23:35:00Z EITScanner

Mar 7 13:08:54 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[2](0x7fd95419f4c0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 13:09:48 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[2](0x7fd95419f4c0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 13:10:17 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-10T23:55:00Z EITScanner

Mar 7 13:39:57 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.03 place
Mar 7 13:39:58 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 13:40:05 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd958201140): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 13:41:24 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T16:05:00Z EITScanner

Mar 7 13:51:47 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 13:53:33 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[2](0x7fd95419f4c0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 13:54:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
Mar 7 13:55:06 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[2](0x7fd95419f4c0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 13:56:22 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T14:45:00Z EITScanner
Mar 7 13:56:22 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place

Mar 7 14:07:20 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 14:07:20 origen mythbackend: mythbackend[13160]: I TVRecEvent recorders/dvbchannel.cpp:714 (Tune) DVBChan[2](/dev/dvb/adapter1/frontend0): Next tuning after less than 1000ms. Delaying by 1000ms
Mar 7 14:09:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
Mar 7 14:12:31 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T15:10:00Z EITScanner

Mar 7 14:18:16 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I Scheduler mythdbcon.cpp:435 (PurgeIdleConnections) New DB connection, total: 20
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[1]: ASK_RECORDING 1 58 0 0
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[2]: ASK_RECORDING 2 58 0 0
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[8]: ASK_RECORDING 8 58 0 0
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[9]: ASK_RECORDING 9 58 0 0
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[10]: ASK_RECORDING 10 58 0 0
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[11]: ASK_RECORDING 11 58 0 0
Mar 7 14:19:00 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[3]: ASK_RECORDING 3 58 0 0
Mar 7 14:19:01 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[4]: ASK_RECORDING 4 58 0 0
Mar 7 14:19:01 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[6]: ASK_RECORDING 6 58 0 0
Mar 7 14:19:01 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[7]: ASK_RECORDING 7 58 0 0
Mar 7 14:19:30 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[1]: Changing from None to RecordingOnly
Mar 7 14:19:30 origen mythbackend: mythbackend[13160]: C CoreContext programinfo.cpp:340 (ProgramInfo) ProgramInfo(): Failed to find recorded entry for 0.
Mar 7 14:19:30 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[1]: TuningFrequency
Mar 7 14:19:31 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2923 (HandleRecordingStatusChange) Tuning recording: "Kidnapped: Desperate Hours": channel 1105 on cardid [1], sourceid 1
Mar 7 14:19:32 origen mythbackend: mythbackend[13160]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for "Kidnapped: Desperate Hours" on cardid [1] (Tuning => Recording)
Mar 7 14:19:32 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:4192 (TuningNewRecorder) TVRec[1]: rec->GetPathname(): '/home/mythtv/default/1105_20190307142000.ts'
Mar 7 14:19:32 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:4224 (TuningNewRecorder) TVRec[1]: TuningNewRecorder - CreateRecorder()
Mar 7 14:21:24 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-10T23:35:00Z EITScanner
Mar 7 14:21:24 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 14:22:19 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:22:53 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T16:00:00Z EITScanner
Mar 7 14:22:53 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 14:22:54 origen mythbackend: mythbackend[13160]: I TVRecEvent tv_rec.cpp:3649 (TuningFrequency) TVRec[2]: TuningFrequency
Mar 7 14:22:54 origen mythbackend: mythbackend[13160]: E TVRecEvent recorders/dtvchannel.cpp:231 (SetChannelByString) DTVChan[2](/dev/dvb/adapter1/frontend0): SetChannelByString(107): Requested channel '107' is not available because the tuner is currently in use on another transport.
Mar 7 14:22:54 origen mythbackend: mythbackend[13160]: E TVRecEvent tv_rec.cpp:3727 (TuningFrequency) TVRec[2]: Failed to set channel to 107. Reverting to kState_None
Mar 7 14:23:09 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:23:09 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:23:23 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:24:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
Mar 7 14:25:43 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T14:40:00Z EITScanner

Mar 7 14:36:32 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried

Mar 7 14:37:29 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:37:55 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:38:07 origen mythbackend: mythbackend[13160]: W DeviceReadBuffer recorders/DeviceReadBuffer.cpp:557 (Poll) DevRdB(/dev/dvb/adapter0/frontend0): Poll took an unusually long time 10591 ms
Mar 7 14:38:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
Mar 7 14:38:54 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:40:50 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:41:15 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T15:05:00Z EITScanner
Mar 7 14:41:15 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 14:41:30 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:41:51 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:44:11 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T15:35:00Z EITScanner

Mar 7 14:48:38 origen mythbackend: mythbackend[13160]: W DeviceReadBuffer recorders/DeviceReadBuffer.cpp:557 (Poll) DevRdB(/dev/dvb/adapter0/frontend0): Poll took an unusually long time 3600 ms
Mar 7 14:49:23 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 14:50:43 origen mythbackend: mythbackend[13160]: W DeviceReadBuffer recorders/DeviceReadBuffer.cpp:557 (Poll) DevRdB(/dev/dvb/adapter0/frontend0): Poll took an unusually long time 4202 ms
Mar 7 14:50:48 origen mythbackend: mythbackend[13160]: W DeviceReadBuffer recorders/DeviceReadBuffer.cpp:557 (Poll) DevRdB(/dev/dvb/adapter0/frontend0): Poll took an unusually long time 4283 ms

Mar 7 14:50:57 origen mythbackend: mythbackend[13160]: I MythSocketThread(105) mainserver.cpp:7681 (connectionClosed) FileTransfer sock(5640b5c0b030) disconnected
Mar 7 14:50:57 origen mythbackend: mythbackend[13160]: I MythSocketThread(103) mainserver.cpp:7643 (connectionClosed) Playback sock(5640b5c9eb30) 'origen.asandco' disconnected
Mar 7 14:52:04 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:52:10 origen mythbackend: mythbackend[13160]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 14 min
Mar 7 14:52:47 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0
Mar 7 14:54:08 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:55:04 origen mythbackend: mythbackend[13160]: W DeviceReadBuffer recorders/DeviceReadBuffer.cpp:557 (Poll) DevRdB(/dev/dvb/adapter0/frontend0): Poll took an unusually long time 3485 ms
Mar 7 14:55:04 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:55:12 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
Mar 7 14:56:13 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T15:00:00Z EITScanner
Mar 7 14:56:13 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 14:58:03 origen mythbackend: mythbackend[13160]: W DeviceReadBuffer recorders/DeviceReadBuffer.cpp:557 (Poll) DevRdB(/dev/dvb/adapter0/frontend0): Poll took an unusually long time 3488 ms
Mar 7 14:58:04 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(182)>184, pes length & current cannot be queried
Mar 7 15:03:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 0 2019-03-07T19:05:00Z EITScanner
Mar 7 15:03:02 origen mythbackend: mythbackend[13160]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Mar 7 15:03:16 origen mythbackend: mythbackend[13160]: E DVBRead mpeg/mpegstreamdata.cpp:340 (AssemblePSIP) MPEGStream[1](0x7fd9581cc5d0): Error: AFCOffset(4)+StartOfFieldPointer(181)>184, pes length & current cannot be queried
MikeB2013
Senior
Posts: 519
Joined: Mon Jul 25, 2016 4:16 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by MikeB2013 »

Unfortunately that is not a complete log. The items relating to mythbackend startup are missing i.e. before Mar 7 11:49:44.
These missing items give details of the environment, including mythtv version, directories etc.
I note that the recording directory is /home/mythtv/default/ which whilst not wrong, is unusual, are the permissions correct ?
What does "ls -lha /home/mythtv" show ?
pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by pinnerite »

I apologise.
I felt guilty about expecting you to scan the whole shooting match so cut what I thought were the least informative lines. :(

$ ls -lha /home/mythtv
total 64K
drwxrwxr-x 14 sshd mythtv 4.0K Mar 1 14:50 .
drwxr-xr-x 9 root root 4.0K Apr 24 2018 ..
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 banners
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 coverart
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 db_backup
drwxrwxr-x 2 sshd mythtv 12K Mar 8 10:00 default
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 fan_art
drwx------ 3 mythtv mythtv 4.0K Feb 15 14:04 .gnupg
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 live_tv
drwxrwxr-x 8 mythtv mythtv 4.0K Mar 1 14:50 .mythtv
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 screenshots
drwx------ 2 mythtv mythtv 4.0K Mar 7 17:43 .smolt
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 trailers
drwxrwxr-x 2 sshd mythtv 4.0K Mar 8 10:00 videos
MikeB2013
Senior
Posts: 519
Joined: Mon Jul 25, 2016 4:16 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by MikeB2013 »

No problem with the log, it is just that sometimes the earlier lines in the log give more clues.

The permissions are strange, the group mythtv part is fine but I don't know about owner being sshd, normally the owner is also mythtv.
The following is what I use:
sudo chown -R mythtv:mythtv <storagegroup_path>
sudo chmod -R 2775 <storagegroup_path>

So in your case replace <storagegroup_path> so you should run
sudo chown -R mythtv:mythtv /home/mythtv/
sudo chmod -R 2775 /home/mythtv/

Best to reboot after the commands, alternatively run sudo systemctl restart mythtv-backend followed by quitting and restarting mythfrontend
pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by pinnerite »

I did as instructed.
I then set five different programs to record at the same time.
None of them did.

I deleted the non-recorded items and shut the system down.

This morning after rebooting, I took a copy of the (complete) backend log excluding only entries from before today:
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: C thread_unknown mythcommandlineparser.cpp:2619 (ConfigureLogging) mythbackend version: fixes/29 [v29.1-13-g329c235] www.mythtv.org
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: C thread_unknown mythcommandlineparser.cpp:2621 (ConfigureLogging) Qt version: compile: 5.9.4, runtime: 5.9.5
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: N thread_unknown mythcommandlineparser.cpp:2623 (ConfigureLogging) Enabled verbose msgs: general
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: N thread_unknown logging.cpp:927 (logStart) Setting Log Level to LOG_INFO
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I Logger logging.cpp:313 (run) Added logging to the console
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Interrupt handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Terminated handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Segmentation fault handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Aborted handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Bus error handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Floating point exception handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Illegal instruction handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Real-time signal 0 handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I thread_unknown signalhandling.cpp:194 (SetHandlerPrivate) Setup Hangup handler
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: N thread_unknown mythdirs.cpp:195 (InitializeMythDirs) Using runtime prefix = /usr
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: N thread_unknown mythdirs.cpp:197 (InitializeMythDirs) Using configuration directory = /home/mythtv/.mythtv
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I CoreContext mythcorecontext.cpp:271 (Init) Assumed character encoding: en_GB.UTF-8
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I LogForward loggingserver.cpp:302 (SyslogLogger) Added syslogging
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I CoreContext mythcontext.cpp:607 (LoadDatabaseSettings) Using localhost value of origen.asandco
Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: I CoreContext mythcontext.cpp:852 (TestDBconnection) Start up testing connections. DB localhost, BE , attempt 0, status dbAwake
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: N CoreContext mythcorecontext.cpp:1768 (InitLocale) Setting QT default locale to en_GB
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: I CoreContext mythcorecontext.cpp:1801 (SaveLocaleDefaults) Current locale en_GB
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: N CoreContext mythlocale.cpp:123 (LoadDefaultsFromXML) Reading locale defaults from /usr/share/mythtv//locales/en_gb.xml
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: I CoreContext mythtranslation.cpp:73 (load) Loading en_gb translation for module mythfrontend
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: I CoreContext schemawizard.cpp:120 (Compare) Current MythTV Schema Version (DBSchemaVer): 1348
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: I CoreContext mythtranslation.cpp:73 (load) Loading en_gb translation for module mythfrontend
Mar 9 13:01:02 origen mythbackend: mythbackend[1216]: N CoreContext main_helpers.cpp:597 (run_backend) MythBackend: Starting up as the master server.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext programinfo.cpp:2382 (CheckProgramIDAuthorities) Found 42 distinct programid authorities
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I Scheduler mythdbcon.cpp:462 (getStaticCon) New static DB connectionSchedCon
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'LogClean'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'DBCleanup'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'ThemeUpdateNotifications'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'RecordedArtworkUpdate'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'MythFillDB'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'UpdateRadioStreams'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'JobQueueRecover'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:633 (RegisterTask) Registering HouseKeeperTask 'HardwareProfiler'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:699 (Start) Queueing HouseKeeperTask 'HardwareProfiler'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:699 (Start) Queueing HouseKeeperTask 'ThemeUpdateNotifications'.
Mar 9 13:01:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:706 (Start) Starting HouseKeeper.
Mar 9 13:01:07 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP 0.0.0.0:6544
Mar 9 13:01:07 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP [::]:6544
Mar 9 13:01:07 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP 0.0.0.0:6554
Mar 9 13:01:07 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP [::]:6554
Mar 9 13:01:07 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP 0.0.0.0:6549
Mar 9 13:01:07 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP [::]:6549
Mar 9 13:01:10 origen mythbackend: mythbackend[1216]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - SchedulerInit
Mar 9 13:01:11 origen mythbackend: mythbackend[1216]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 4 items in 0.5 = 0.41 match + 0.01 check + 0.08 place
Mar 9 13:01:11 origen mythbackend: mythbackend[1216]: I Scheduler scheduler.cpp:2538 (HandleRunSchedulerStartup) Scheduler: Seem to be woken up by USER
Mar 9 13:01:11 origen mythbackend: mythbackend[1216]: I CoreContext main_helpers.cpp:687 (run_backend) Main::Registering HttpStatus Extension
Mar 9 13:01:11 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP 0.0.0.0:6543
Mar 9 13:01:11 origen mythbackend: mythbackend[1216]: I CoreContext serverpool.cpp:422 (listen) Listening on TCP [::]:6543
Mar 9 13:01:11 origen mythbackend: mythbackend[1216]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
Mar 9 13:01:12 origen mythbackend: mythbackend[1216]: I CoreContext bonjourregister.cpp:118 (BonjourCallback) Bonjour: Service registration complete: name 'Mythbackend on origen.asandco' type '_mythbackend._tcp.' domain: 'local.'
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:725 (Run) Queueing HouseKeeperTask 'DBCleanup'.
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:725 (Run) Queueing HouseKeeperTask 'JobQueueRecover'.
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:725 (Run) Queueing HouseKeeperTask 'LogClean'.
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I CoreContext housekeeper.cpp:725 (Run) Queueing HouseKeeperTask 'MythFillDB'.
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'HardwareProfiler'.
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I SystemManager mythsystemunix.cpp:276 (run) Starting process manager
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I SystemSignalManager mythsystemunix.cpp:509 (run) Starting process signal handler
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I SystemIOHandlerR mythsystemunix.cpp:92 (run) Starting IO manager (read)
Mar 9 13:02:06 origen mythbackend: mythbackend[1216]: I SystemIOHandlerW mythsystemunix.cpp:92 (run) Starting IO manager (write)
Mar 9 13:02:08 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:149 (Run) HouseKeeperTask 'HardwareProfiler' Failed.
Mar 9 13:02:08 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'ThemeUpdateNotifications'.
Mar 9 13:02:08 origen mythbackend: mythbackend[1216]: I HouseKeeping backendhousekeeper.cpp:397 (DoRun) Loading themes for 29
Mar 9 13:02:10 origen mythbackend: mythbackend[1216]: E DownloadManager mythdownloadmanager.cpp:1547 (saveFile) Failed to open: '/home/mythtv/.mythtv/tmp/remotethemes/themes.zip'
Mar 9 13:02:10 origen mythbackend: mythbackend[1216]: E HouseKeeping mythcoreutil.cpp:81 (extractZIP) extractZIP(): Unable to open ZIP file /home/mythtv/.mythtv/tmp/remotethemes/themes.zip
Mar 9 13:02:10 origen mythbackend: mythbackend[1216]: E HouseKeeping backendhousekeeper.cpp:458 (LoadVersion) HouseKeeper: Error extracting /home/mythtv/.mythtv/tmp/remotethemes/themes.zip remote themes info package.
Mar 9 13:02:10 origen mythbackend: mythbackend[1216]: I HouseKeeping backendhousekeeper.cpp:411 (DoRun) Loading themes for 29.1
Mar 9 13:02:11 origen mythbackend: mythbackend[1216]: E DownloadManager mythdownloadmanager.cpp:1547 (saveFile) Failed to open: '/home/mythtv/.mythtv/tmp/remotethemes/themes.zip'
Mar 9 13:02:11 origen mythbackend: mythbackend[1216]: I HouseKeeping backendhousekeeper.cpp:450 (LoadVersion) HouseKeeper: Failed to download http://themes.mythtv.org/themes/reposit ... themes.zip remote themes info package.
Mar 9 13:02:11 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:149 (Run) HouseKeeperTask 'ThemeUpdateNotifications' Failed.
Mar 9 13:02:11 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'DBCleanup'.
Mar 9 13:02:12 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:153 (Run) HouseKeeperTask 'DBCleanup' Finished Successfully.
Mar 9 13:02:12 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'JobQueueRecover'.
Mar 9 13:02:12 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:153 (Run) HouseKeeperTask 'JobQueueRecover' Finished Successfully.
Mar 9 13:02:12 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'LogClean'.
Mar 9 13:02:12 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:153 (Run) HouseKeeperTask 'LogClean' Finished Successfully.
Mar 9 13:02:12 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'MythFillDB'.
Mar 9 13:02:13 origen mythbackend: mythbackend[1216]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar 9 13:02:13 origen mythbackend: mythbackend[1216]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: origen.asandco(7f72d0005810) as a client (events: 0)
Mar 9 13:02:17 origen mythbackend: mythbackend[1216]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 0 0 - HandleRescheduleRecordings
Mar 9 13:02:17 origen mythbackend: mythbackend[1216]: I MythSocketThread(76) mainserver.cpp:7643 (connectionClosed) Playback sock(7f72d0005810) 'origen.asandco' disconnected
Mar 9 13:02:17 origen mythbackend: mythbackend[1216]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 4 items in 0.0 = 0.01 match + 0.00 check + 0.01 place
Mar 9 13:02:17 origen mythbackend: mythbackend[1216]: I HouseKeeping housekeeper.cpp:153 (Run) HouseKeeperTask 'MythFillDB' Finished Successfully.
Mar 9 13:02:26 origen mythbackend: mythbackend[1216]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
Mar 9 13:17:26 origen mythbackend: mythbackend[1216]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
Mar 9 13:32:26 origen mythbackend: mythbackend[1216]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 1.0 GB w/freq: 15 min
MikeB2013
Senior
Posts: 519
Joined: Mon Jul 25, 2016 4:16 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by MikeB2013 »

From the latest log Line Mar 9 13:01:00 origen mythbackend: mythbackend[1216]: C thread_unknown mythcommandlineparser.cpp:2619 (ConfigureLogging) mythbackend version: fixes/29 [v29.1-13-g329c235

The version:fixes/29 [v29.1-13-g329c235 is from April 12 2018 and there have been a number of changes since then.

To rule out any problems with such an old version (it is possible that your problems have already been found and fixed) suggest you upgrade to the latest fixes/29 by doing the following in a terminal session:

Code: Select all

sudo add-apt-repository ppa:mythbuntu/0.29
sudo apt-get update
sudo apt upgrade
You should then reboot - you could run sudo systemctl restart mythtv-backend, and restart the mythfrontend, but I prefer the reboot as it ensures a clean start, especially if other software updates are installed at the same time. Note if a kernel upgrade is installed you will need to rebuild the tbs drivers after the reboot and then reboot again.

Mike
pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by pinnerite »

OK. I ran the updates / upgrade suggested, removed the drivers from the existing kernel, booted into the new kernel, downloaded, compiled and installed the latest drivers (again) and rebooted.

I deleted the old items that failed to record and set a new group of eight to record. Only one did so.

I re-ran the tests as before.

The results together with the backend and frontend logs for today were too large to be posted here, so I have uploaded them as a file via dropbox.

This is the link.

https://www.dropbox.com/s/8l4tubcweljb8 ... m.txt?dl=0
MikeB2013
Senior
Posts: 519
Joined: Mon Jul 25, 2016 4:16 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by MikeB2013 »

From the Dropbox file

Code: Select all

$ ls -lha /home/mythtv
total 64K
drwxrwxr-x 14   2775 mythtv 4.0K Mar  1 14:50 .
drwxr-xr-x  9 root   root   4.0K Apr 24  2018 ..
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 banners
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 coverart
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 db_backup
drwxrwxr-x  2   2775 mythtv  12K Mar  9 20:09 default
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 fan_art
drwx------  3   2775 mythtv 4.0K Feb 15 14:04 .gnupg
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:24 live_tv
drwxrwxr-x  8 mythtv mythtv 4.0K Mar  1 14:50 .mythtv
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 screenshots
drwx------  2   2775 mythtv 4.0K Mar  7 17:43 .smolt
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 trailers
drwxrwxr-x  2   2775 mythtv 4.0K Mar  9 18:13 videos
Ownership of 2775 seems wrong for the storagegroup directories, it should be mythtv.

For the mythbackend nothing could have worked until after the restart at Mar 9 18:13:25 as until then the /dev/dvb/adapters were not opening.
I presume this was due to the TBS drivers not being installed until this point, if not what happened (reboot, cold boot etc.) ?
pinnerite
Senior
Posts: 260
Joined: Mon Apr 07, 2014 2:34 pm
Great Britain

Re: Unexpected Recording Conflicts

Post by pinnerite »

Mm. I changed the ownership of /home/mythtv and everything beneath and shutdown.

I waited about 15 minutes before making a cold boot and again set six broadcasts to record at the same time.

Only one made it. The others are marked as conflicting.
wesnewell
Senior
Posts: 731
Joined: Mon Jun 23, 2014 6:54 pm
Location: Wylie TX, USA
United States of America

Re: Unexpected Recording Conflicts

Post by wesnewell »

Look at status page and see if all your tuners are available for recording. If not, reboot without shutting down power and see if that fixes it.
BE/FE-Asrock AB350 Pro Ryzen 3 3200G, 6 atsc tuners. FE's-GF8200's Athlon II, Ryzen 3 2200G. Mythtv user since 2005.
Post Reply