[Solved] Recorder Failed & Watch TV fails during the Midnight hour every night

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

Moderator: Forum Moderators

Post Reply
paul73
Newcomer
Posts: 2
Joined: Wed Aug 29, 2018 7:06 pm
United States of America

[Solved] Recorder Failed & Watch TV fails during the Midnight hour every night

Post by paul73 » Wed Aug 29, 2018 8:28 pm

As of January-21-2018 I upgraded from 14.04.5 LTS (Trusty Tahr) to 16.04.3 LTS (Xenial Xerus)
My frontend says it is v29.11-31-g563a4b8. I use two Dual HD Homerun tuners so I can record up to 4 programs together. I only have broadcast antenna input.

It started sporadically at first on July 11 and now it is consistent. All Scheduled Recordings report Recorder Failed and also Watch TV fails simultaneously during the Midnight hour every night all at exactly the same time with some slight variance night to night.

To test the issue I set shows to record between midnight and 2 am. All midnight programming starts normally but often ends 12:08:10 or :11 am (but this varies slightly to as late as 12:48 a). The shows set to start at 1 am never start (Recording Unavailable).

Code: Select all

I checked logs which I copy below to show immediately before & after that point in time:
Aug 28 00:00:06 paul-MS-7846 mythbackend: mythbackend[1313]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Aug 28 00:00:06 paul-MS-7846 mythbackend: mythbackend[1313]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: paul-MS-7846(1347ec0) as a client (events: 1)
Aug 28 00:00:08 paul-MS-7846 mythbackend: mythbackend[1313]: I MythSocketThread(118) mainserver.cpp:7643 (connectionClosed) Monitor sock(1346cb0) 'paul-MS-7846' disconnected
Aug 28 00:00:08 paul-MS-7846 mythbackend: mythbackend[1313]: I MythSocketThread(120) mainserver.cpp:7643 (connectionClosed) Monitor sock(1347ec0) 'paul-MS-7846' disconnected
Aug 28 00:01:22 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 2 2018-08-29T14:00:00Z EITScanner
Aug 28 00:01:22 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 20 items in 0.0 = 0.00 match + 0.01 check + 0.02 place
Aug 28 00:01:23 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 13 2018-08-31T02:00:00Z EITScanner
Aug 28 00:01:23 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 20 items in 0.0 = 0.01 match + 0.00 check + 0.02 place
Aug 28 00:01:41 paul-MS-7846 mythbackend: mythbackend[1313]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 3 min
Aug 28 00:05:41 paul-MS-7846 mythbackend: mythbackend[1313]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 3 min
Aug 28 00:08:16 paul-MS-7846 mythbackend: mythbackend[1313]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:471 (TunerSet) HDHRSH[1](10424E80-0): Set request failed#012#011#011#011eno: Resource temporarily unavailable (11)
Aug 28 00:08:16 paul-MS-7846 mythbackend: mythbackend[1313]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:471 (TunerSet) HDHRSH[4](10437A89-1): Set request failed#012#011#011#011eno: Resource temporarily unavailable (11)
Aug 28 00:08:16 paul-MS-7846 mythbackend: mythbackend[1313]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:471 (TunerSet) HDHRSH[3](10437A89-0): Set request failed#012#011#011#011eno: Resource temporarily unavailable (11)
Aug 28 00:08:16 paul-MS-7846 mythbackend: mythbackend[1313]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:471 (TunerSet) HDHRSH[2](10424E80-1): Set request failed#012#011#011#011eno: Resource temporarily unavailable (11)
The "Set request failed" continues until 5:30 a at which time I see "ERROR: resource locked by 192.168.0.186" :

Code: Select all

Aug 28 05:35:35 paul-MS-7846 mythbackend: mythbackend[1313]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:471 (TunerSet) HDHRSH[2](10424E80-1): Set request failed#012#011#011#011eno: Resource temporarily unavailable (11)
Aug 28 05:35:36 paul-MS-7846 mythbackend: mythbackend[1313]: I EIT mythdbcon.cpp:435 (PurgeIdleConnections) New DB connection, total: 17
Aug 28 05:36:08 paul-MS-7846 mythbackend: mythbackend[1313]: I TVRecEvent tv_rec.cpp:3665 (TuningFrequency) TVRec[3]: TuningFrequency
Aug 28 05:36:08 paul-MS-7846 mythbackend: mythbackend[1313]: E TVRecEvent recorders/hdhrstreamhandler.cpp:481 (TunerSet) HDHRSH(10437A89-0): DeviceSet(channel 8vsb:491000000): ERROR: resource locked by 192.168.0.186
Aug 28 05:36:08 paul-MS-7846 mythbackend: mythbackend[1313]: E TVRecEvent recorders/dtvchannel.cpp:311 (SetChannelByString) DTVChan[3](10437A89-0): SetChannelByString(17_1): Tuning to frequency.
Aug 28 05:36:08 paul-MS-7846 mythbackend: mythbackend[1313]: E TVRecEvent tv_rec.cpp:3743 (TuningFrequency) TVRec[3]: Failed to set channel to 17_1. Reverting to kState_None
Aug 28 05:36:38 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler scheduler.cpp:2356 (HandleReschedule) Reschedule requested for MATCH 0 1 10 2018-09-01T23:30:00Z EITScanner
Aug 28 05:36:38 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler mythdbcon.cpp:435 (PurgeIdleConnections) New DB connection, total: 17
Aug 28 05:36:38 paul-MS-7846 mythbackend: mythbackend[1313]: I Scheduler scheduler.cpp:2469 (HandleReschedule) Scheduled 13 items in 0.0 = 0.02 match + 0.00 check + 0.03 place
Aug 28 05:36:50 paul-MS-7846 mythbackend: mythbackend[1313]: I TVRecEvent tv_rec.cpp:3665 (TuningFrequency) TVRec[4]: TuningFrequency
Aug 28 05:36:50 paul-MS-7846 mythbackend: mythbackend[1313]: E TVRecEvent recorders/hdhrstreamhandler.cpp:481 (TunerSet) HDHRSH(10437A89-1): DeviceSet(channel 8vsb:563000000): ERROR: resource locked by 192.168.0.186
When I hard reboot the server in the morning then Watch TV is available again & scheduled recordings resume until Midnight hour and we start over again. Any ideas?

As I write I wonder, if my wireless router went down at night during this time period (where my ethernet first brings my internet into the house) could this have an impact?

(FYI I am a novice as far as Linux server management goes. This is my first time submitting. All the posts until now have helped me solve my issues. I could not find this exact scenario anywhere.)

Thanks in advance for your help!

~ Paul

User avatar
bill6502
Developer
Posts: 1070
Joined: Fri Feb 07, 2014 5:28 pm
United States of America

Re: Recorder Failed & Watch TV fails during the Midnight hour every night

Post by bill6502 » Thu Aug 30, 2018 4:51 pm

I'd go with your router suspicion. With the backend working (post reboot you mentioned)
unplug the HDHR or turn off WiFi. See if the same 'Resource temporarily unavailable'
error fires.

You can remove MythTV from the mix. Just stop the backend, then from the command
line and try things like:

Code: Select all

hdhomerun_config discover
hdhomerun_config 131716E9 help # Only with your ID from the above
hdhomerun_config 131716E9 get help
hdhomerun_config 131716E9 get /tuner0/status

paul73
Newcomer
Posts: 2
Joined: Wed Aug 29, 2018 7:06 pm
United States of America

Re: Recorder Failed & Watch TV fails during the Midnight hour every night

Post by paul73 » Sat Sep 01, 2018 4:20 pm

Bill -

Thanks for your reply.

I was under the impression that most critical recording/viewing functions required the antenna input alone, in my case, which was never interrupted. I didn't think constant internet was required for MythTV to record consistently via the HDHR tuners.

My wife's doctor had asked her to turn off Wi-Fi overnight while we were sleeping. At first we did so manually, by unplugging the router, explaining the intermittent initial failures. Then we added an analog timer with buttons depressed to set it off approximately 6.5 hours nightly. I think the analog physical mechanical nature of the timer contributed to some of the variance. An ethernet cable from the router to a switch brought hardwired internet downstream to my server; I didn't realize powering down the router would cut off the wired internet access via the server to the HDHRs.

While gathering data to submit my post it hit me that the errors stopped at a very consistent time. I was looking at errors repeating 5.5 hours each night then the errors stopped. Each morning when internet returned the damage was done; the resource remained locked now that the wireless radio was on until I hard rebooted the server. The first night after this i left internet on all night and recordings completed properly and Watch TV was immediately available. I researched & learned that my router online offers a toggle to disable the wireless without cutting off the power. The second night, with wireless disabled through the app, the recordings and Watch TV again worked correctly each day with no daily reboot required.

Learning this was a big relief. This mystery puzzled me and I brought it on myself. :)

~ Paul

User avatar
pvr4me
Senior
Posts: 619
Joined: Fri Feb 07, 2014 7:25 pm
Location: near Toronto, Canada
Contact:
Canada

Re: Recorder Failed & Watch TV fails during the Midnight hour every night

Post by pvr4me » Sun Sep 02, 2018 12:47 pm

paul73 wrote:
Sat Sep 01, 2018 4:20 pm
... My wife's doctor had asked her to turn off Wi-Fi overnight while we were sleeping. ...
:shock:
:?
:roll:

Craig
The MacPorts guy.

Post Reply