Some channels work...others don't

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

Moderator: Forum Moderators

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Some channels work...others don't

Post by MickeyRat » Fri Sep 06, 2019 10:26 pm

I've been fooling with this one all day to no avail. I really hope someone here can help. I'm running MythTV 30.0 on Arch Linux on an I5 with 16GB. I have 2 HDhomerun HDHR4-2US tuners. This set up has been working great for well over 2 years but, now I have a problem.

There was a notice from one of the stations I watch that they were changing things and to run a channel scan today. No big deal, I normally run one at the first of the month anyway. When I ran the scan, I got around 15 conflicting channels. I just took the defaults when it asked for a number. None of them had schedules and I marked them hidden. Now some channels I've been using are coming in and others aren't and I will miss the ones that aren't. I can play the channels directly off the tuners in VLC but, not in Myth. Here's an excerpt from the log showing two simultaneous recordings. WHKY News works. Eyewitness News fails.

Code: Select all

Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.014891 I  TVRec[9]: TuningFrequency
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.031881 I  HDHRSH[9](10491557): Added 2 devices from 10491557
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.050478 I  HDHRSH[9](10491557): Connected to device(10491557-0)
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.171578 I  Tuning recording: "WHKY News":"2019-09-06 17:30:00": channel 1703 on cardid [9], sourceid 1
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.184395 I  TVRec[7]: Changing from None to RecordingOnly
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.184780 I  TVRec[7]: TuningFrequency
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.188199 E  HDHRSH[7](10491557): DeviceSet(channel 8vsb:593000000): ERROR: resource locked by 192.168.1.22
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.188203 E  DTVChan[7](10491557): SetChannelByString(9_1): Tuning to frequency.
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.188254 E  TVRec[7]: Failed to set channel to 9_1. Reverting to kState_None
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.188266 I  TVRec[7]: Changing from RecordingOnly to None
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.190972 I  Updating status for "Eyewitness News at 5:30" on cardid [7] (Pending => Recorder Failed)
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.193605 E  HDHRSH[7](10491557): DeviceSet(channel none): ERROR: resource locked by 192.168.1.22
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.195337 I  Tuning recording: "Eyewitness News at 5:30": channel 1001 on cardid [7], sourceid 1
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.196974 I  Reschedule requested for CHECK -9 2793 0 UpdateRecStatus2 | Eyewitness News at 5:30 |  |  | SH016271170000
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.207953 C  ProgramInfo(): Failed to find recorded entry for 0.
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.259820 E  RecordingInfo::InsertProgram(ProgramInfo(1001_20190906213000.ts): channame(WSOC-TV) startts(Fri Sep 6 21:30:00 2019 GM>
Sep 06 17:30:00 zeppo mythbackend[5829]:              recstartts(Fri Sep 6 21:30:00 2019 GMT) recendts(Fri Sep 6 22:00:00 2019 GMT)
Sep 06 17:30:00 zeppo mythbackend[5829]:              title(Eyewitness News at 5:30)): recording already exists...
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.265307 I  TVRec[7]: Changing from None to RecordingOnly
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.265546 I  TVRec[7]: TuningFrequency
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.282141 I  HDHRSH[7](10491557): Added 2 devices from 10491557
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.320214 I  HDHRSH[7](10491557): Connected to device(10491557-1)
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.433567 E  Failed to change end time on card 7 to 2019-09-06T22:00:00Z
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.496707 I  Scheduled 301 items in 0.3 = 0.00 match + 0.00 check + 0.29 place
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.790838 I  Updating status for "WHKY News":"2019-09-06 17:30:00" on cardid [9] (Tuning => Recording)
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.848544 I  TVRec[9]: rec->GetPathname(): '/mnt/mythstore/recordings/1703_20190906213000.ts'
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.848683 I  TVRec[9]: TuningNewRecorder - CreateRecorder()
Sep 06 17:30:00 zeppo mythbackend[5829]: 2019-09-06 17:30:00.850022 E  RecBase[9](10491557): SetStrOption(...recordingtype): Option not in profile.
Sep 06 17:30:01 zeppo mythbackend[5829]: 2019-09-06 17:30:00.935696 E  DTVSigMon[7](10491557): Could not find channel 9_1 in TVCT

I've tried all kinds of things, restore DB from backup, reinstall, increasing the timeout on the inout cards, etc. Nothing has worked so far.

Any help will be appreciated.

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Re: Some channels work...others don't

Post by MickeyRat » Sat Sep 07, 2019 12:33 pm

A couple additional data points, I restored the database prior to the channel scan and the channels I'm missing still don't come in. So, the channel scan's not the culprit. I'm using Kodi as a frontend so I tried installing the hdhomerun plugin. With that, the channels do come in. That's another indicator that the problem only occurs in MythTV.

I'm out of ideas. If I can't get this working, I'll have to move to something else, probably an Emby subscription. That would be painful but, the wife only has so much patience.

User avatar
paulh
Developer
Posts: 436
Joined: Thu Feb 06, 2014 6:09 pm
Great Britain

Re: Some channels work...others don't

Post by paulh » Sun Sep 08, 2019 11:58 am

I've never used any of the HDHomeRun devices but this error
HDHRSH[7](10491557): DeviceSet(channel 8vsb:593000000): ERROR: resource locked by 192.168.1.22
seems to suggest something else is using the tuner?

Did you make sure the backend was shut down and restarted properly?
Could something else be using the tuner?
If you look at the 'Input Status' (TV->System Status->Input Status) in mythfrontend do the tuners show and are they showing any errors?

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

Re: Some channels work...others don't

Post by bill6502 » Sun Sep 08, 2019 8:02 pm

I'll add to Paul's comment. I have HDHR products and have only seen a locking error once in the
last 17 months. It was during a 4 minute run of a BE while testing something else. The IP in my
case was 169.254.88.128 (the Link Local address of my HDHR.) In addition to the suggestions
above, consider restarting the HDHR itself. Logs for my production host go back 2 years and
I've never seen the message there.

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Re: Some channels work...others don't

Post by MickeyRat » Mon Sep 09, 2019 11:05 am

Thanks for the replies. I've restarted the HDHRs, rebooted the system and restarted the backend several times. I did see the locking message. It's my backend server. I'm having trouble with believing locking is the issue because I don't see how that could affect some channels and not others but, at this point, I'll try anything. I just shutdown the backend and restarted the HDHRs. Here are the logs from an attempt to record two shows on channels that I know haven't been working.

Code: Select all

Sep 09 06:40:15 zeppo mythbackend[5173]: 2019-09-09 06:40:15.858317 I  Running Grabber:  -l en -a US -M Eyewitness News Daybreak 6:00
Sep 09 06:40:16 zeppo mythbackend[5173]: 2019-09-09 06:40:15.958585 I  Running Grabber: /usr/share/mythtv/metadata/Movie/tmdb3.py -l en -a US -M Eyewitness News Daybreak 6:00
Sep 09 06:40:16 zeppo mythbackend[5173]: 2019-09-09 06:40:16.208996 E  MythSystemLegacy() command not executable,
Sep 09 06:40:16 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:16 zeppo mythbackend[5173]: 2019-09-09 06:40:16.209007 I  Running Grabber:  -l en -a US -M Eyewitness News Daybreak 6:00
Sep 09 06:40:16 zeppo mythbackend[5173]: 2019-09-09 06:40:16.209024 I  Metadata Lookup Failed: No Results Eyewitness News Daybreak 6:00 0 0
Sep 09 06:40:16 zeppo mythbackend[5173]: 2019-09-09 06:40:16.659715 E  MythSystemLegacy() command not executable,
Sep 09 06:40:16 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:16 zeppo mythbackend[5173]: 2019-09-09 06:40:16.659727 I  Running Grabber:  -l en -a US -M Eyewitness News Daybreak 6:00
Sep 09 06:40:17 zeppo mythbackend[5173]: 2019-09-09 06:40:17.010266 E  MythSystemLegacy() command not executable,
Sep 09 06:40:17 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:17 zeppo mythbackend[5173]: 2019-09-09 06:40:17.010282 I  Running Grabber:  -l en -a US -M Eyewitness News Daybreak 6:00
Sep 09 06:40:17 zeppo mythbackend[5173]: 2019-09-09 06:40:17.010304 I  Metadata Lookup Failed: No Results Eyewitness News Daybreak 6:00 0 0
Sep 09 06:40:20 zeppo mythbackend[5173]: 2019-09-09 06:40:20.522088 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:20 zeppo mythbackend[5173]: 2019-09-09 06:40:20.522157 I  MainServer: adding: zeppo(557ffed46040) as a client (events: 0)
Sep 09 06:40:20 zeppo mythbackend[5173]: 2019-09-09 06:40:20.896516 I  Monitor sock(557ffed46040) 'zeppo' disconnected
Sep 09 06:40:23 zeppo mythbackend[5173]: 2019-09-09 06:40:23.498925 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:23 zeppo mythbackend[5173]: 2019-09-09 06:40:23.498934 I  MainServer: adding: zeppo(557ffed46040) as a client (events: 0)
Sep 09 06:40:23 zeppo mythbackend[5173]: 2019-09-09 06:40:23.578811 I  Monitor sock(557ffed46040) 'zeppo' disconnected
Sep 09 06:40:26 zeppo mythbackend[5173]: 2019-09-09 06:40:26.640498 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:26 zeppo mythbackend[5173]: 2019-09-09 06:40:26.640507 I  MainServer: adding: zeppo(557ffed46040) as a client (events: 0)
Sep 09 06:40:26 zeppo mythbackend[5173]: 2019-09-09 06:40:26.716913 I  Monitor sock(557ffed46040) 'zeppo' disconnected
Sep 09 06:40:28 zeppo mythbackend[5173]: 2019-09-09 06:40:28.694811 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:28 zeppo mythbackend[5173]: 2019-09-09 06:40:28.694821 I  MainServer: adding: zeppo(557ffed46040) as a client (events: 0)
Sep 09 06:40:28 zeppo mythbackend[5173]: 2019-09-09 06:40:28.761837 I  Monitor sock(557ffed46040) 'zeppo' disconnected
Sep 09 06:40:30 zeppo mythbackend[5173]: 2019-09-09 06:40:30.419134 E  TVRec[7]: TuningSignalCheck: Hit pre-fail timeout
Sep 09 06:40:31 zeppo mythbackend[5173]: 2019-09-09 06:40:31.760182 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:31 zeppo mythbackend[5173]: 2019-09-09 06:40:31.760189 I  MainServer: adding: zeppo(557ffed46040) as a client (events: 0)
Sep 09 06:40:31 zeppo mythbackend[5173]: 2019-09-09 06:40:31.837951 I  Monitor sock(557ffed46040) 'zeppo' disconnected
Sep 09 06:40:32 zeppo mythbackend[5173]: 2019-09-09 06:40:32.624593 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:32 zeppo mythbackend[5173]: 2019-09-09 06:40:32.624601 I  MainServer: adding: zeppo(557ffed46040) as a client (events: 0)
Sep 09 06:40:32 zeppo mythbackend[5173]: 2019-09-09 06:40:32.728180 I  Monitor sock(557ffed46040) 'zeppo' disconnected
Sep 09 06:40:32 zeppo mythbackend[5173]: 2019-09-09 06:40:32.933875 I  Running Grabber: /usr/share/mythtv/metadata/Movie/tmdb3.py -l en -a US -M Wake Up CLT at 6:00
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.235618 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.235629 I  MainServer: adding: zeppo(557ffedcc850) as a client (events: 0)
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.321391 I  Reschedule requested for MATCH 2798 0 0 - PHP
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.321496 I  Monitor sock(557ffedcc850) 'zeppo' disconnected
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.322256 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.322263 I  MainServer: adding: zeppo(557ffedf8da0) as a client (events: 2)
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.429872 I  Scheduled 293 items in 0.1 = 0.01 match + 0.00 check + 0.09 place
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.445406 I  TVRec[9]: Changing from None to RecordingOnly
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.446826 I  TVRec[9]: TuningFrequency
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.463608 I  HDHRSH[9](10491557): Added 2 devices from 10491557
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.501961 I  HDHRSH[9](10491557): Connected to device(10491557-1)
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.636862 C  ProgramInfo(): Failed to find recorded entry for 0.
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.636880 I  Monitor sock(557ffedf8da0) 'zeppo' disconnected
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.676741 I  Tuning recording: "Wake Up CLT at 6:00": channel 1361 on cardid [9], sourceid 1
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.684676 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.684683 I  MainServer: adding: zeppo(557ffedebc70) as a client (events: 0)
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.768359 I  Monitor sock(557ffedebc70) 'zeppo' disconnected
Sep 09 06:40:36 zeppo mythbackend[5173]: 2019-09-09 06:40:36.915597 E  ProgramInfo(1361_20190909104100.ts): GetPlaybackURL: '1361_20190909104100.ts' should be local, but it can not be found.
Sep 09 06:40:37 zeppo mythbackend[5173]: 2019-09-09 06:40:36.989881 I  Running Grabber: /usr/share/mythtv/metadata/Movie/tmdb3.py -l en -a US -M Wake Up CLT at 6:00
Sep 09 06:40:37 zeppo mythbackend[5173]: 2019-09-09 06:40:37.422936 W  TVRec[7]: TuningSignalCheck: taking more than 21500 ms to get a lock. marking this recording as 'Failing'.
Sep 09 06:40:37 zeppo mythbackend[5173]: 2019-09-09 06:40:37.422945 W  TVRec[7]: See 'Tuning timeout' in mythtv-setup for this input
Sep 09 06:40:37 zeppo mythbackend[5173]: 2019-09-09 06:40:37.423996 I  Updating status for "Eyewitness News Daybreak 6:00" on cardid [7] (Tuning => Failing)
Sep 09 06:40:37 zeppo mythbackend[5173]: 2019-09-09 06:40:37.429550 I  Reschedule requested for CHECK -14 2797 0 UpdateRecStatus2 | Eyewitness News Daybreak 6:00 |  |  | SH016271210000
Sep 09 06:40:37 zeppo mythbackend[5173]: 2019-09-09 06:40:37.539913 I  Scheduled 293 items in 0.1 = 0.01 match + 0.00 check + 0.09 place
Sep 09 06:40:38 zeppo mythbackend[5173]: 2019-09-09 06:40:38.892379 E  MythSystemLegacy() command not executable,
Sep 09 06:40:38 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:38 zeppo mythbackend[5173]: 2019-09-09 06:40:38.892398 I  Running Grabber:  -l en -a US -M Wake Up CLT at 6:00
Sep 09 06:40:39 zeppo mythbackend[5173]: 2019-09-09 06:40:39.242986 E  MythSystemLegacy() command not executable,
Sep 09 06:40:39 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:39 zeppo mythbackend[5173]: 2019-09-09 06:40:39.242999 I  Running Grabber:  -l en -a US -M Wake Up CLT at 6:00
Sep 09 06:40:39 zeppo mythbackend[5173]: 2019-09-09 06:40:39.243013 I  Metadata Lookup Failed: No Results Wake Up CLT at 6:00 0 0
Sep 09 06:40:40 zeppo mythbackend[5173]: 2019-09-09 06:40:40.487980 I  MainServer: MainServer::ANN Monitor
Sep 09 06:40:40 zeppo mythbackend[5173]: 2019-09-09 06:40:40.487990 I  MainServer: adding: zeppo(557ffedf45e0) as a client (events: 0)
Sep 09 06:40:40 zeppo mythbackend[5173]: 2019-09-09 06:40:40.863650 I  Monitor sock(557ffedf45e0) 'zeppo' disconnected
Sep 09 06:40:42 zeppo mythbackend[5173]: 2019-09-09 06:40:42.818511 E  ProgramInfo(1001_20190909104000.ts): GetPlaybackURL: '1001_20190909104000.ts' should be local, but it can not be found.
Sep 09 06:40:42 zeppo mythbackend[5173]: 2019-09-09 06:40:42.820253 E  ProgramInfo(1001_20190909104000.ts): GetPlaybackURL: '1001_20190909104000.ts' should be local, but it can not be found.
Sep 09 06:40:42 zeppo mythbackend[5173]: 2019-09-09 06:40:42.822827 I  JobQueue: Metadata Lookup Starting for "Eyewitness News Daybreak 6:00" recorded from channel 1001 at 2019-09-09T10:40:>
Sep 09 06:40:43 zeppo mythbackend[5173]: 2019-09-09 06:40:42.998512 E  MythSystemLegacy() command not executable,
Sep 09 06:40:43 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:43 zeppo mythbackend[5173]: 2019-09-09 06:40:42.998522 I  Running Grabber:  -l en -a US -M Wake Up CLT at 6:00
Sep 09 06:40:43 zeppo mythbackend[5173]: 2019-09-09 06:40:43.399085 E  MythSystemLegacy() command not executable,
Sep 09 06:40:43 zeppo mythbackend[5173]:                         eno: No such file or directory (2)
Sep 09 06:40:43 zeppo mythbackend[5173]: 2019-09-09 06:40:43.399099 I  Running Grabber:  -l en -a US -M Wake Up CLT at 6:00
Sep 09 06:40:43 zeppo mythbackend[5173]: 2019-09-09 06:40:43.399117 I  Metadata Lookup Failed: No Results Wake Up CLT at 6:00 0 0
Sep 09 06:40:43 zeppo mysqld[530]: 2019-09-09  6:40:43 814 [Warning] Aborted connection 814 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally w>
Sep 09 06:40:45 zeppo mythbackend[5173]: 2019-09-09 06:40:45.303706 E  JobQueue: Metadata Lookup Errored: "Eyewitness News Daybreak 6:00" recorded from channel 1001 at 2019-09-09T10:40:00Z >
Sep 09 06:40:47 zeppo mythbackend[5173]: 2019-09-09 06:40:47.832992 E  ProgramInfo(1001_20190909104000.ts): GetPlaybackURL: '1001_20190909104000.ts' should be local, but it can not be found.
Sep 09 06:40:47 zeppo mythbackend[5173]: 2019-09-09 06:40:47.835260 E  ProgramInfo(1001_20190909104000.ts): GetPlaybackURL: '1001_20190909104000.ts' should be local, but it can not be found.
Sep 09 06:40:47 zeppo mythbackend[5173]: 2019-09-09 06:40:47.837085 I  JobQueue: Commercial Detection Starting for "Eyewitness News Daybreak 6:00" recorded from channel 1001 at 2019-09-09T1>
Sep 09 06:40:48 zeppo mysqld[530]: 2019-09-09  6:40:48 819 [Warning] Aborted connection 819 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally w>
Sep 09 06:40:49 zeppo mythbackend[5173]: 2019-09-09 06:40:49.109621 E  ProgramInfo(1001_20190909104000.ts): GetPlaybackURL: '1001_20190909104000.ts' should be local, but it can not be found.
Sep 09 06:40:50 zeppo mythbackend[5173]: 2019-09-09 06:40:50.674548 E  TVRec[9]: TuningSignalCheck: Hit pre-fail timeout
Sep 09 06:40:52 zeppo mythbackend[5173]: 2019-09-09 06:40:52.355078 N  AutoExpire: CalcParams(): Max required Free Space: 3.0 GB w/freq: 7 min
Sep 09 06:40:52 zeppo mythbackend[5173]: 2019-09-09 06:40:52.843304 E  ProgramInfo(1361_20190909104100.ts): GetPlaybackURL: '1361_20190909104100.ts' should be local, but it can not be found.
Sep 09 06:40:52 zeppo mythbackend[5173]: 2019-09-09 06:40:52.844874 E  ProgramInfo(1361_20190909104100.ts): GetPlaybackURL: '1361_20190909104100.ts' should be local, but it can not be found.
Sep 09 06:40:52 zeppo mythbackend[5173]: 2019-09-09 06:40:52.847148 I  JobQueue: Metadata Lookup Starting for "Wake Up CLT at 6:00" recorded from channel 1361 at 2019-09-09T10:41:00Z
Sep 09 06:40:53 zeppo mysqld[530]: 2019-09-09  6:40:53 824 [Warning] Aborted connection 824 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally w>
Sep 09 06:40:55 zeppo mythbackend[5173]: 2019-09-09 06:40:55.219205 E  JobQueue: Metadata Lookup Errored: "Wake Up CLT at 6:00" recorded from channel 1361 at 2019-09-09T10:41:00Z (Failed wi>
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.678576 W  TVRec[9]: TuningSignalCheck: taking more than 21000 ms to get a lock. marking this recording as 'Failing'.
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.678583 W  TVRec[9]: See 'Tuning timeout' in mythtv-setup for this input
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.678782 I  Updating status for "Wake Up CLT at 6:00" on cardid [9] (Tuning => Failing)
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.681581 I  Reschedule requested for CHECK -14 2798 0 UpdateRecStatus2 | Wake Up CLT at 6:00 |  |  | SH030264260000
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.798829 I  Scheduled 293 items in 0.1 = 0.00 match + 0.00 check + 0.09 place
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.851750 E  ProgramInfo(1361_20190909104100.ts): GetPlaybackURL: '1361_20190909104100.ts' should be local, but it can not be found.
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.852748 E  ProgramInfo(1361_20190909104100.ts): GetPlaybackURL: '1361_20190909104100.ts' should be local, but it can not be found.
Sep 09 06:40:57 zeppo mythbackend[5173]: 2019-09-09 06:40:57.854411 I  JobQueue: Commercial Detection Starting for "Wake Up CLT at 6:00" recorded from channel 1361 at 2019-09-09T10:41:00Z
Sep 09 06:40:58 zeppo mysqld[530]: 2019-09-09  6:40:58 829 [Warning] Aborted connection 829 to db: 'unconnected' user: 'unauthenticated' host: 'localhost' (This connection closed normally w>
lines 22035-22085/22092 100%
I did perform a system update before this started happening. Right now, I'm attempting to build another system from scratch to see if it has the same problem but, I'll stop that effort immediately if I can get a resolution. Last resort is trying to move to Emby.

User avatar
paulh
Developer
Posts: 436
Joined: Thu Feb 06, 2014 6:09 pm
Great Britain

Re: Some channels work...others don't

Post by paulh » Tue Sep 10, 2019 10:19 pm

We really don't have any easy tool to debug these kind of problems other than looking at the database to spot any configuration problems (Or do a rescan with fingers crossed and hope for the best).

You could use the Services API might be a little easier than messing with the DB. I'm from DVB land so I know what I would look at but no idea for HDHomeRun devices though. I would start by listing the channels and comparing good channels with bad. Look for the bad channels with ChanID 1361 and 1001 from your log.

Code: Select all

http://192.168.1.22:6544/Channel/GetChannelInfoList?OnlyVisible=true&Details=true
(I'm assuming 192.168.1.22 is the IP of your master backend?)
SourceID probably should be the same. For DVB channels the MplexId and ServiceId are also important.

You can also check the MplexID exists for the SourceID by using

Code: Select all

http://192.168.1.22:6544/Channel/GetVideoMultiplexList?SourceID=1

User avatar
heyted
Senior
Posts: 100
Joined: Sun Jun 08, 2014 2:14 am
Location: South Florida
Contact:
United States of America

Re: Some channels work...others don't

Post by heyted » Wed Sep 11, 2019 1:26 am

Have you tried mythfrontend? Same issue with it?
Ted | My blog

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Re: Some channels work...others don't

Post by MickeyRat » Wed Sep 11, 2019 4:37 pm

paulh wrote:
Sun Sep 08, 2019 11:58 am
I've never used any of the HDHomeRun devices but this error
HDHRSH[7](10491557): DeviceSet(channel 8vsb:593000000): ERROR: resource locked by 192.168.1.22
seems to suggest something else is using the tuner?

Did you make sure the backend was shut down and restarted properly?
Could something else be using the tuner?
If you look at the 'Input Status' (TV->System Status->Input Status) in mythfrontend do the tuners show and are they showing any errors?
Thanks for the reply. Yes, 192.168.1.22 is my backend. I don't know for sure but. it is possible that in the snippet I put up in the original post, I did have something else locking the tuner. I was trying all kinds of things to figure out what was going on. I didn't do anything that would have locked all 4 tuners though. The snippet in my last post shows the failures without the locking error. The input status shows available on all inputs in the frontend. No errors.

That brings me to another question. I mentioned I was going to build another server and see if the channels work there. They do. Well one does and that's enough for me to call it good. However, there is one thing that bothers me. In my old setup those two HDHRs are defined as 4 tuners and 4 inputs. In the current version of myth, there doesn't seem to be a way to do that. Am I right in assuming that in it's current incarnation MythTV is smart enough to figure out there are 2 tuners on each HDHR on it's own?
heyted wrote:
Wed Sep 11, 2019 1:26 am
Have you tried mythfrontend? Same issue with it?
Thanks for the reply. I rarely use the frontend. So, that's about the only thing I didn't try but, I have now. Same result.

Right now, I've gone to the trouble of getting myth and mythweb running in Manjaro on another box. It's a little gigabyte dual core w/4GB RAM. but, I think it will do short term. I plan to migrate over to it then rebuild my main server (an I5 w/16GB RAM) and migrate back. It's not as bad as it sounds my main storage is on external drives in LVM. So I can move everything to external drives online and mount them on the temporary box.

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Re: Some channels work...others don't

Post by MickeyRat » Wed Sep 11, 2019 11:10 pm

I went back and checked that new server again and apparently sometimes it is not getting the channel I saw work. So not time to migrate yet.

This may not have to do with the recent FCC channel rearrangement but. it's hard not to think so. One day I'm getting 40 channels, the next I'm getting 5 and it just happens to occur when they move the channels around. I should probably mention that I live in a small town about an hour from a large city. most of what I get comes from that city. Now I'm only seeing local channels.

I have one other thing to try. All of the failures have occurred on the same HDHR. In theory that could be the problem. I also need to look closer at the alternate methods that I used to watch the missing channels.. I just did very quick samples. It's possible that if I watch a little longer, I'll see them drop as well.

Is there any way to make myth use a lower threshold for a lost signal?

mythcube
Newcomer
Posts: 1
Joined: Sat Sep 07, 2019 5:02 pm
United States of America

Re: Some channels work...others don't

Post by mythcube » Wed Sep 11, 2019 11:49 pm

I encountered the same problem when 2 of our local stations changed their channels. Fox went from 50 to 29 and ABC went from 36 to 20. I did a channel scan, deleted all capture cards and re-added and re-scanned all with no joy. Then I found the channel table.

Code: Select all

mysql>  select chanid,channum as chn,freqid as frq, serviceid as sid,mplexid as mpx,tvformat as tvf,callsign as cs from channel order by chanid;
+--------+------+------+------+------+------+---------+
| chanid | chn  | frq  | sid  | mpx  | tvf  | cs      |
+--------+------+------+------+------+------+---------+
|   1061 | 6_1  | 29   |    3 |   15 | ATSC | WBRC    |
|   1062 | 6_2  | 29   |    2 |   15 | ATSC | Bounce  |
|   1063 | 6_3  | 29   |    4 |   15 | ATSC | Grit    |
|   1064 | 6_4  | 29   |    5 |   15 | ATSC | LAFF TV |
|   1101 | 10_1 | 10   |    3 |    2 | ATSC | WBIQ HD |
|   1102 | 10_2 | 10   |    4 |    2 | ATSC | PBSKIDS |
|   1103 | 10_3 | 10   |    5 |    2 | ATSC | Create  |
|   1104 | 10_4 | 10   |    6 |    2 | ATSC | WORLD   |
|   1131 | 13_1 | 13   |    3 |    3 | ATSC | WVTM-HD |
|   1132 | 13_2 | 13   |    4 |    3 | ATSC | MeTV    |
|   1211 | 21_1 | 28   |    3 |    4 | ATSC | WTTO-CW |
|   1212 | 21_2 | 28   |    4 |    4 | ATSC | getTV   |
|   1213 | 21_3 | 21   |    5 |   13 | ATSC | Comet   |
|   1214 | 21_4 | 21   |    6 |   13 | ATSC | TBD     |
|   1421 | 42_1 | 30   |    1 |    5 | ATSC | WIAT-HD |
|   1422 | 42_2 | 30   |    2 |    5 | ATSC | Escape  |
|   1423 | 42_3 | 30   |    3 |    5 | ATSC | Justice |
|   1424 | 42_4 | 30   |    4 |    5 | ATSC | CourtTV |
|   1581 | 58_1 | 40   |    3 |    8 | ATSC | WBMA-1  |
|   1582 | 58_2 | 40   |    4 |    8 | ATSC | WBMA-2  |
|   1681 | 68_1 | 20   |    3 |   11 | ATSC | WABM-MY |
|   1682 | 68_2 | 20   |    4 |   11 | ATSC | abc3340 |
|   1683 | 68_3 | 20   |    5 |   11 | ATSC | Weather |
+--------+------+------+------+------+------+---------+
23 rows in set (0.00 sec)
I changed the changed the frequency to the proper channel, still no joy.
The problem for me was the dtv_multiplex table. The frequency had not been updated. Fox still had the freq for channel 50 (686000000) instead of the value for channel 29 (560000000), this was using mplexid 15. After changing the frequency values in dtv_multiplex.frequency to the proper values both channels started tuning.

Hope this helps.

User avatar
heyted
Senior
Posts: 100
Joined: Sun Jun 08, 2014 2:14 am
Location: South Florida
Contact:
United States of America

Re: Some channels work...others don't

Post by heyted » Thu Sep 12, 2019 1:41 am

MickeyRat wrote:
Wed Sep 11, 2019 4:37 pm
In my old setup those two HDHRs are defined as 4 tuners and 4 inputs. In the current version of myth, there doesn't seem to be a way to do that. Am I right in assuming that in it's current incarnation MythTV is smart enough to figure out there are 2 tuners on each HDHR on it's own?
I'm not familiar with HDHomeRuns other the the Prime, but with the three-tuner Prime, it is necessary to create three input connections.
Ted | My blog

User avatar
paulh
Developer
Posts: 436
Joined: Thu Feb 06, 2014 6:09 pm
Great Britain

Re: Some channels work...others don't

Post by paulh » Thu Sep 12, 2019 11:45 am

Yes you need to add your HDHomeRun 4 inputs if it has 4 tuners and you want MythTV to use them all.
This commit explains the change in more detail
https://github.com/MythTV/mythtv/commit/57a0ad8

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Re: Some channels work...others don't

Post by MickeyRat » Thu Sep 12, 2019 5:53 pm

Special thanks to mythcube. The dtv_multiplex table was something I didn't think of but, after I figured out how to find the frequency for the channel, the dtv_multiplex table did have the correct frequency for one of the channels I was most interested in. So, that doesn't appear to be the problem.

I did figure that needed to put in 2 capture cards and I tried replacing the capture cards and inputs. I didn't have a lot of hope but, I also put that new build in place of my existng server. The behavior hasn't changed. I've done everything I can think of to get myth to work.. Everything else that can access those HDHRs works fine only myth has a problem. I think it's time to bite the bullet and try switching to emby. I'll miss myth but, I can't see how to get it working and this isn't acceptable.

I know this is a MythTV forum. I won't post about my experience with Emby unless someone asks.

User avatar
paulh
Developer
Posts: 436
Joined: Thu Feb 06, 2014 6:09 pm
Great Britain

Re: Some channels work...others don't

Post by paulh » Fri Sep 13, 2019 5:44 pm

Before you nuke your MythTV system could you please dump the following tables and email them to me? I'd like to figure out what went wrong here.

channel
dtv_multiplex
iptv_channel
videosource
capturecard
cardinput

I think that's all I'd need. Something like this should work to dump them

Code: Select all

mysqldump -u mythtv  -h 192.168.1.22 -p mythconverg channel dtv_multiplex iptv_channel videosource capturecard cardinput > ~/dump.sq

MickeyRat
Junior
Posts: 27
Joined: Tue Feb 27, 2018 3:28 am
United States of America

Re: Some channels work...others don't

Post by MickeyRat » Sun Sep 15, 2019 10:17 am

Well after trying Emby (not impressed), I decided that I really wanted to get Myth working and I was willing to lose my recordings to do it. Emby is decent to serve up movies but, it leaves a lot to be desired as a DVR. So I told my wife to watch everything she cared about and I nuked and paved my myth server. In the long run, it's probably a good thing. I really didn't understand much about myth when I set the server up originally and I did a lot of things that I later wished I'd done differently. Also running MythTV which can be finicky at times on Arch whch also can be finicky at times wasn't the best choice. I moved to Manjaro which is still in the Arch family. It does work now and my wife hasn't called a lawyer yet though she got close. :)
paulh wrote:
Fri Sep 13, 2019 5:44 pm
Before you nuke your MythTV system could you please dump the following tables and email them to me? I'd like to figure out what went wrong here.
I'd like to know too but, I didn't see this before I blew everything away. OTOH I would like to know more about this and I'm a recently retired Oracle DBA (SQL'a not a problem) so, perhaps you could provide some references on the database structure.

Post Reply