[Solved] Recording remnants in Upcoming Recordings

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

Moderator: Forum Moderators

Post Reply
stantonovitch
Newcomer
Posts: 2
Joined: Sat Mar 06, 2021 5:16 pm
United States of America

[Solved] Recording remnants in Upcoming Recordings

Post by stantonovitch »

One of my channels leaves an active recording remnant in Upcoming Recordings. It's not critical, but it's been bugging me, and I can't figure out why it's happening. I'm hoping you can see something I don't:

Upcoming Recordings shows a proper listing for next programs to record. For one of my channels (29_1), when the recording starts, it invokes the tuner properly and starts recording, but then also looks like it starts a recording of the same show, but on a different source of the same broadcast channel (252). While the show is recording, both showings of the program are highlighted green in Upcoming Recordings, and lights activate on both HDHR tuners. One thing I did notice during a recording is that the "correct" recording in Upcoming Recordings has a start time 1 minute earlier than the superfluous one. For example 12:58 vs 12:59. Unfortunately I didn't capture that in the view below. I do set recordings to start 1 minute early and end 2 minutes late.

After the recording is done, only the proper one is listed in Watch Recordings, but the superfluous recording remains green in Upcoming Recordings. Restarting the backend clears the remnants.

Channel 29_1, WTXFDT OTA through HDHR 2 records fine. Watching live TV, the tuner tunes within a few seconds.
Channel 252, WTXFDT Digital Cable through HDHR Prime is the one that improperly gets invoked.
Both of these channels are Fox 29 HD in Philadelphia, though have different XMLTVIDs

This is what remains in Upcoming Recordings after the recording:
Mythfrontend 210305.PNG
Mythfrontend 210305.PNG (217.42 KiB) Viewed 662 times
Here is the backend log during a recording:

Code: Select all

Mar  5 12:49:40 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 12:49:40 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(1adc890) as a client (events: 1)
Mar  5 12:49:42 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(92) mainserver.cpp:7643 (connectionClosed) Monitor sock(15f6e90) 'mythbox' disconnected
Mar  5 12:49:42 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(94) mainserver.cpp:7643 (connectionClosed) Monitor sock(1adc890) 'mythbox' disconnected
Mar  5 12:51:26 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 5.0 GB w/freq: 15 min
Mar  5 12:57:30 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[36]: ASK_RECORDING 36 89 0 0
Mar  5 12:57:30 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[39]: ASK_RECORDING 39 89 0 0
Mar  5 12:57:30 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1625 (HandlePendingRecordings) TVRec[38]: ASK_RECORDING 38 89 0 0
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[36]: Changing from None to RecordingOnly
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I TVRecEvent mythdbcon.cpp:435 (PurgeIdleConnections) New DB connection, total: 15
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:3580 (TuningCheckForHWChange) TVRec[36]: HW Tuner: 36->36
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:3704 (TuningFrequency) TVRec[36]: TuningFrequency
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2922 (HandleRecordingStatusChange) Tuning recording: "25 Words or Less": channel 3291 on cardid [36], sourceid 3
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I Scheduler mythdbcon.cpp:267 (Reconnect) MySQL reconnected successfully
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2355 (HandleReschedule) Reschedule requested for PLACE PrepareToRecord
Mar  5 12:58:00 mythbox mythbackend: mythbackend[1120]: C CoreContext programinfo.cpp:351 (ProgramInfo) ProgramInfo(): Failed to find recorded entry for 0.
Mar  5 12:58:01 mythbox mythbackend: mythbackend[1120]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for "25 Words or Less" on cardid [36] (Tuning => Recording)
Mar  5 12:58:01 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:4247 (TuningNewRecorder) TVRec[36]: rec->GetPathname(): '/storage/recordings/3291_20210305175800.ts'
Mar  5 12:58:01 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:4279 (TuningNewRecorder) TVRec[36]: TuningNewRecorder - CreateRecorder()
Mar  5 12:58:01 mythbox mythbackend: mythbackend[1120]: E TVRecEvent recorders/recorderbase.cpp:232 (SetStrOption) RecBase[36](10151217-0): SetStrOption(...recordingtype): Option not in profile.
Mar  5 12:58:05 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2459 (HandleReschedule) Reschedule interrupted, will retry
Mar  5 12:58:05 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2355 (HandleReschedule) Reschedule requested for PLACE Interrupted
Mar  5 12:58:09 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2468 (HandleReschedule) Scheduled 3044 items in 4.4 = 0.00 match + 0.00 check + 4.41 place
Mar  5 12:58:28 mythbox mythbackend: mythbackend[1120]: I Metadata_57963 jobqueue.cpp:2157 (DoMetadataLookupThread) JobQueue: Metadata Lookup Starting for "25 Words or Less" recorded from channel 3291 at 2021-03-05T17:58:00Z
Mar  5 12:58:30 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 12:58:30 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(186b7e0) as a client (events: 0)
Mar  5 12:58:30 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 12:58:30 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(19686a0) as a client (events: 1)
Mar  5 12:58:36 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar  5 12:58:36 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(167b880) as a client (events: 0)
Mar  5 12:58:36 mythbox mythbackend: mythbackend[1120]: E ProcessRequest mainserver.cpp:1907 (HandleAnnounce) MainServer: Unable to determine directory to write to in FileTransfer write command
Mar  5 12:58:36 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(104) mainserver.cpp:7693 (connectionClosed) Control sock(18400c0) disconnected
Mar  5 12:58:36 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(102) mainserver.cpp:7643 (connectionClosed) Playback sock(167b880) 'mythbox' disconnected
Mar  5 12:58:38 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(97) mainserver.cpp:7643 (connectionClosed) Monitor sock(186b7e0) 'mythbox' disconnected
Mar  5 12:58:38 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(99) mainserver.cpp:7643 (connectionClosed) Monitor sock(19686a0) 'mythbox' disconnected
Mar  5 12:59:33 mythbox mythbackend: mythbackend[1120]: I Commflag_57964 jobqueue.cpp:2282 (DoFlagCommercialsThread) JobQueue: Commercial Detection Starting for "25 Words or Less" recorded from channel 3291 at 2021-03-05T17:58:00Z
Mar  5 12:59:34 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar  5 12:59:34 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(184ad90) as a client (events: 0)
Mar  5 12:59:34 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 12:59:34 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(1adc890) as a client (events: 1)
Mar  5 12:59:34 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar  5 12:59:34 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(1b44300) as a client (events: 0)
Mar  5 13:07:26 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:09:05 mythbox mythbackend: mythbackend[1120]: I CoreContext housekeeper.cpp:725 (Run) Queueing HouseKeeperTask 'ThemeUpdateNotifications'.
Mar  5 13:09:05 mythbox mythbackend: mythbackend[1120]: I HouseKeeping mythdbcon.cpp:435 (PurgeIdleConnections) New DB connection, total: 16
Mar  5 13:09:05 mythbox mythbackend: mythbackend[1120]: I HouseKeeping housekeeper.cpp:135 (Run) Running HouseKeeperTask 'ThemeUpdateNotifications'.
Mar  5 13:09:05 mythbox mythbackend: mythbackend[1120]: I HouseKeeping backendhousekeeper.cpp:397 (DoRun) Loading themes for 29
Mar  5 13:09:05 mythbox mythbackend: mythbackend[1120]: I HouseKeeping housekeeper.cpp:153 (Run) HouseKeeperTask 'ThemeUpdateNotifications' Finished Successfully.
Mar  5 13:21:26 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:28:54 mythbox mythbackend: mythbackend[1120]: N ProcessRequest recordinginfo.cpp:642 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: Default to Deleted (3)
Mar  5 13:28:54 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2355 (HandleReschedule) Reschedule requested for CHECK 0 3723 0 DoHandleDelete1 | Mysteries of the Abandoned | Forgotten Fortresses of Terror | The desolate fortress of history's most infamous drug lord and a battle-scarred ruin in the Middle East contain a violent past; experts investigate the secrets of these mysterious compounds to uncover how they were built and why they were abandoned. | EP026496350202
Mar  5 13:29:00 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2468 (HandleReschedule) Scheduled 3040 items in 5.4 = 0.02 match + 0.01 check + 5.38 place
Mar  5 13:33:30 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[36]: Changing from RecordingOnly to None
Mar  5 13:33:30 mythbox mythbackend: mythbackend[1120]: N RecThread recorders/recorderbase.cpp:501 (FinishRecording) Finished Recording: Container: MPEG2-TS Video Codec: mpeg2video (1280x720 A/R: 3 59.9401fps) Audio Codec: ac3
Mar  5 13:33:30 mythbox mythbackend: mythbackend[1120]: I TVRecEvent recordinginfo.cpp:1185 (FinishedRecording) Finished recording 25 Words or Less: channel 3291
Mar  5 13:33:30 mythbox mythbackend: mythbackend[1120]: I CoreContext scheduler.cpp:734 (UpdateRecStatus) Updating status for "25 Words or Less" on cardid [36] (Recording => Recorded)
Mar  5 13:33:30 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2355 (HandleReschedule) Reschedule requested for CHECK -3 4588 0 UpdateRecStatus2 | 25 Words or Less |  |  | EP030082090318
Mar  5 13:33:31 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 13:33:31 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(183d8e0) as a client (events: 0)
Mar  5 13:33:31 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 13:33:31 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(1833720) as a client (events: 1)
Mar  5 13:33:34 mythbox mythbackend: mythbackend[1120]: I Scheduler scheduler.cpp:2468 (HandleReschedule) Scheduled 3037 items in 4.1 = 0.01 match + 0.02 check + 4.04 place
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(17abad0) as a client (events: 0)
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(95) mainserver.cpp:7643 (connectionClosed) Playback sock(17abad0) 'mythbox' disconnected
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(17abad0) as a client (events: 0)
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[30]: Changing from None to WatchingLiveTV
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I TVRecEvent mythdbcon.cpp:435 (PurgeIdleConnections) New DB connection, total: 15
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:3704 (TuningFrequency) TVRec[30]: TuningFrequency
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:33:40 mythbox mythbackend: mythbackend[1120]: N TVRecEvent recordinginfo.cpp:694 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: LiveTV to LiveTV (2)
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/dtvsignalmonitor.cpp:322 (HandlePAT) DTVSigMon[30](13128450-0): Program #0 not found in PAT!#012Program Association Section#012 PSIP tableID(0x0) length(13) extension(0x1)#012      version(0) current(1) section(0) last_section(0)#012      tsid(1) programCount(1)#012  program number   203 has PID 0x006f
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/dtvsignalmonitor.cpp:328 (HandlePAT) DTVSigMon[30](13128450-0): But there is only one program in the PAT, so we'll just use it
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: N HDHRStreamHandler recorders/dtvsignalmonitor.cpp:367 (HandlePMT) DTVSigMon[30](13128450-0): PMT says program 203 is encrypted
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:258 (UpdateFilters) HDHRSH(13128450-0): UpdateFilters called in wrong tune mode
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: N TVRecEvent recordinginfo.cpp:694 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: LiveTV to LiveTV (2)
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:4279 (TuningNewRecorder) TVRec[30]: TuningNewRecorder - CreateRecorder()
Mar  5 13:33:41 mythbox mythbackend: mythbackend[1120]: E TVRecEvent recorders/recorderbase.cpp:232 (SetStrOption) RecBase[30](13128450-0): SetStrOption(...recordingtype): Option not in profile.
Mar  5 13:33:46 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(90) mainserver.cpp:7643 (connectionClosed) Monitor sock(183d8e0) 'mythbox' disconnected
Mar  5 13:33:46 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(93) mainserver.cpp:7643 (connectionClosed) Monitor sock(1833720) 'mythbox' disconnected
Mar  5 13:33:49 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(102) mainserver.cpp:7643 (connectionClosed) Playback sock(1b44300) 'mythbox' disconnected
Mar  5 13:33:50 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(97) mainserver.cpp:7643 (connectionClosed) Playback sock(184ad90) 'mythbox' disconnected
Mar  5 13:33:50 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(99) mainserver.cpp:7643 (connectionClosed) Monitor sock(1adc890) 'mythbox' disconnected
Mar  5 13:33:51 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 13:33:51 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(1692660) as a client (events: 0)
Mar  5 13:33:51 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Monitor
Mar  5 13:33:51 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(183d8e0) as a client (events: 1)
Mar  5 13:33:54 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:258 (UpdateFilters) HDHRSH[30](13128450-0): UpdateFilters called in wrong tune mode
Mar  5 13:33:54 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:3704 (TuningFrequency) TVRec[30]: TuningFrequency
Mar  5 13:33:54 mythbox mythbackend: mythbackend[1120]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: N TVRecEvent recordinginfo.cpp:694 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: LiveTV to LiveTV (2)
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/dtvsignalmonitor.cpp:322 (HandlePAT) DTVSigMon[30](13128450-0): Program #0 not found in PAT!#012Program Association Section#012 PSIP tableID(0x0) length(13) extension(0x1)#012      version(0) current(1) section(0) last_section(0)#012      tsid(1) programCount(1)#012  program number  2707 has PID 0x0068
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/dtvsignalmonitor.cpp:328 (HandlePAT) DTVSigMon[30](13128450-0): But there is only one program in the PAT, so we'll just use it
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: N HDHRStreamHandler recorders/dtvsignalmonitor.cpp:367 (HandlePMT) DTVSigMon[30](13128450-0): PMT says program 2707 is encrypted
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:258 (UpdateFilters) HDHRSH[30](13128450-0): UpdateFilters called in wrong tune mode
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:33:55 mythbox mythbackend: mythbackend[1120]: N TVRecEvent recordinginfo.cpp:694 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: LiveTV to LiveTV (2)
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[30]: Changing from WatchingLiveTV to None
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: E HDHRStreamHandler recorders/hdhrstreamhandler.cpp:258 (UpdateFilters) HDHRSH[30](13128450-0): UpdateFilters called in wrong tune mode
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: N RecThread recorders/recorderbase.cpp:501 (FinishRecording) Finished Recording: Container: MPEG2-TS Video Codec: mpeg2video (528x480 A/R: 2 29.97fps) Audio Codec: ac3
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:863 (FinishedRecording) TVRec[30]: FinishedRecording(6029_2021-03-05T18:33:55Z) damaged recq:<RecordingQuality overall_score="0" key="6029_2021-03-05T18:33:55Z" countinuity_error_count="0" packet_count="6248">#012    <Gap start="2021-03-05T18:00:00Z" end="2021-03-05T18:33:55Z" duration="2035" />#012    <Gap start="2021-03-05T18:33:59Z" end="2021-03-05T20:00:00Z" duration="5160" />#012</RecordingQuality>
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(95) mainserver.cpp:7643 (connectionClosed) Playback sock(17abad0) 'mythbox' disconnected
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1738 (HandleAnnounce) MainServer: MainServer::ANN Playback
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I ProcessRequest mainserver.cpp:1743 (HandleAnnounce) MainServer: adding: mythbox(17abad0) as a client (events: 0)
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[36]: Changing from None to WatchingLiveTV
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:3704 (TuningFrequency) TVRec[36]: TuningFrequency
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:34:01 mythbox mythbackend: mythbackend[1120]: N TVRecEvent recordinginfo.cpp:694 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: LiveTV to LiveTV (2)
Mar  5 13:34:02 mythbox mythbackend: mythbackend[1120]: N CoreContext autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 7.0 GB w/freq: 14 min
Mar  5 13:34:02 mythbox mythbackend: mythbackend[1120]: N TVRecEvent recordinginfo.cpp:694 (ApplyRecordRecGroupChange) ApplyRecordRecGroupChange: LiveTV to LiveTV (2)
Mar  5 13:34:02 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:4279 (TuningNewRecorder) TVRec[36]: TuningNewRecorder - CreateRecorder()
Mar  5 13:34:02 mythbox mythbackend: mythbackend[1120]: E TVRecEvent recorders/recorderbase.cpp:232 (SetStrOption) RecBase[36](10151217-0): SetStrOption(...recordingtype): Option not in profile.
Mar  5 13:34:05 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(90) mainserver.cpp:7643 (connectionClosed) Monitor sock(1692660) 'mythbox' disconnected
Mar  5 13:34:05 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(93) mainserver.cpp:7643 (connectionClosed) Monitor sock(183d8e0) 'mythbox' disconnected
Mar  5 13:34:21 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:1088 (HandleStateChange) TVRec[36]: Changing from WatchingLiveTV to None
Mar  5 13:34:21 mythbox mythbackend: mythbackend[1120]: N RecThread recorders/recorderbase.cpp:501 (FinishRecording) Finished Recording: Container: MPEG2-TS Video Codec: mpeg2video (1280x720 A/R: 3 59.9401fps) Audio Codec: ac3
Mar  5 13:34:21 mythbox mythbackend: mythbackend[1120]: I TVRecEvent tv_rec.cpp:863 (FinishedRecording) TVRec[36]: FinishedRecording(3291_2021-03-05T18:34:02Z) damaged recq:<RecordingQuality overall_score="0" key="3291_2021-03-05T18:34:02Z" countinuity_error_count="0" packet_count="147093">#012    <Gap start="2021-03-05T18:30:00Z" end="2021-03-05T18:34:02Z" duration="242" />#012    <Gap start="2021-03-05T18:34:19Z" end="2021-03-05T19:00:00Z" duration="1540" />#012</RecordingQuality>
Mar  5 13:34:21 mythbox mythbackend: mythbackend[1120]: I MythSocketThread(95) mainserver.cpp:7643 (connectionClosed) Playback sock(17abad0) 'mythbox' disconnected
Mar  5 13:36:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 5.0 GB w/freq: 15 min
Mar  5 13:40:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:637 (SendDeleteMessages) Expiring 0 MB for 6805 at 2021-03-05T18:33:40Z => "The Dr. Oz Show":"Exclusive: Jon Gosselin and the Dangerous Blood Clot That Put Him Back in the Hospital"
Mar  5 13:40:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:637 (SendDeleteMessages) Expiring 16 MB for 6805 at 2021-03-05T18:33:41Z => "The Dr. Oz Show":"Exclusive: Jon Gosselin and the Dangerous Blood Clot That Put Him Back in the Hospital"
Mar  5 13:40:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:637 (SendDeleteMessages) Expiring 0 MB for 6029 at 2021-03-05T18:33:54Z => "America Reports With John Roberts & Sandra Smith"
Mar  5 13:40:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:637 (SendDeleteMessages) Expiring 1 MB for 6029 at 2021-03-05T18:33:55Z => "America Reports With John Roberts & Sandra Smith"
Mar  5 13:40:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:637 (SendDeleteMessages) Expiring 0 MB for 3291 at 2021-03-05T18:34:01Z => "25 Words or Less"
Mar  5 13:40:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:637 (SendDeleteMessages) Expiring 26 MB for 3291 at 2021-03-05T18:34:02Z => "25 Words or Less"
Mar  5 13:40:30 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 9877 filename /spare-disk/recordings/6805_20210305183340.ts
Mar  5 13:40:30 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 9877 (chanid 6805 at 2021-03-05T18:33:40Z)
Mar  5 13:40:36 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 9878 filename /spare-disk/recordings/6805_20210305183341.ts
Mar  5 13:40:36 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 9878 (chanid 6805 at 2021-03-05T18:33:41Z)
Mar  5 13:40:42 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 9879 filename /spare-disk/recordings/6029_20210305183354.ts
Mar  5 13:40:42 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 9879 (chanid 6029 at 2021-03-05T18:33:54Z)
Mar  5 13:40:48 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 9880 filename /spare-disk/recordings/6029_20210305183355.ts
Mar  5 13:40:48 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 9880 (chanid 6029 at 2021-03-05T18:33:55Z)
Mar  5 13:40:54 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 9881 filename /spare-disk/recordings/3291_20210305183401.ts
Mar  5 13:40:54 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 9881 (chanid 3291 at 2021-03-05T18:34:01Z)
Mar  5 13:41:00 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2456 (DeleteRecordedFiles) DeleteRecordedFiles - recording id 9882 filename /spare-disk/recordings/3291_20210305183402.ts
Mar  5 13:41:00 mythbox mythbackend: mythbackend[1120]: N DeleteThread mainserver.cpp:2534 (DoDeleteInDB) DoDeleteINDB - recording id 9882 (chanid 3291 at 2021-03-05T18:34:02Z)
Mar  5 13:51:25 mythbox mythbackend: mythbackend[1120]: N Expire autoexpire.cpp:251 (CalcParams) AutoExpire: CalcParams(): Max required Free Space: 5.0 GB w/freq: 15 min
Here is some database info for the channels:

Code: Select all

mysql> select  chanid,channum,freqid,sourceid,callsign,name,xmltvid,mplexid,serviceid,atsc_major_chan,atsc_minor_chan from channel where callsign='WTXFDT' order by chanid,xmltvid,sourceid;
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
| chanid | channum | freqid | sourceid | callsign | name             | xmltvid | mplexid | serviceid | atsc_major_chan | atsc_minor_chan |
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
|   1252 | 252     | 252    |        1 | WTXFDT   | WTXFDT (WTXF-DT) | 11930   |   32767 |         0 |             252 |               0 |
|   3291 | 29_1    | 42     |        3 | WTXFDT   | WTXFDT           | 19614   |     146 |         3 |              29 |               1 |
|   6252 | 252     | 252    |        6 | WTXFDT   | WTXFDT (WTXF-DT) | 11930   |   32767 |         0 |             252 |               0 |
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
3 rows in set (0.00 sec)

mysql> select  chanid,channum,freqid,sourceid,callsign,name,xmltvid,mplexid,serviceid,atsc_major_chan,atsc_minor_chan from channel where channum=252 order by chanid,xmltvid,sourceid;
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
| chanid | channum | freqid | sourceid | callsign | name             | xmltvid | mplexid | serviceid | atsc_major_chan | atsc_minor_chan |
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
|   1252 | 252     | 252    |        1 | WTXFDT   | WTXFDT (WTXF-DT) | 11930   |   32767 |         0 |             252 |               0 |
|   6252 | 252     | 252    |        6 | WTXFDT   | WTXFDT (WTXF-DT) | 11930   |   32767 |         0 |             252 |               0 |
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
2 rows in set, 1 warning (0.00 sec)

mysql> select  chanid,channum,freqid,sourceid,callsign,name,xmltvid,mplexid,serviceid,atsc_major_chan,atsc_minor_chan from channel where channum='29_1' order by chanid,xmltvid,sourceid;
+--------+---------+--------+----------+----------+---------+---------+---------+-----------+-----------------+-----------------+
| chanid | channum | freqid | sourceid | callsign | name    | xmltvid | mplexid | serviceid | atsc_major_chan | atsc_minor_chan |
+--------+---------+--------+----------+----------+---------+---------+---------+-----------+-----------------+-----------------+
|   3291 | 29_1    | 42     |        3 | WTXFDT   | WTXFDT  | 19614   |     146 |         3 |              29 |               1 |
+--------+---------+--------+----------+----------+---------+---------+---------+-----------+-----------------+-----------------+
1 row in set (0.01 sec)

mysql> select  chanid,channum,freqid,sourceid,callsign,name,xmltvid,mplexid,serviceid,atsc_major_chan,atsc_minor_chan from channel where xmltvid=11930 order by chanid,xmltvid,sourceid;
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
| chanid | channum | freqid | sourceid | callsign | name             | xmltvid | mplexid | serviceid | atsc_major_chan | atsc_minor_chan |
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
|   1252 | 252     | 252    |        1 | WTXFDT   | WTXFDT (WTXF-DT) | 11930   |   32767 |         0 |             252 |               0 |
|   6252 | 252     | 252    |        6 | WTXFDT   | WTXFDT (WTXF-DT) | 11930   |   32767 |         0 |             252 |               0 |
|   7893 | 1029    | 1029   |        6 | WTXF     | WTXF             | 11930   |   32767 |         0 |            1029 |               0 |
|  14125 | 1029    | 1029   |        1 | WTXF     | WTXF             | 11930   |   32767 |         0 |            1029 |               0 |
+--------+---------+--------+----------+----------+------------------+---------+---------+-----------+-----------------+-----------------+
4 rows in set (0.00 sec)

mysql> select  chanid,channum,freqid,sourceid,callsign,name,xmltvid,mplexid,serviceid,atsc_major_chan,atsc_minor_chan from channel where xmltvid=19614 order by chanid,xmltvid,sourceid;
+--------+---------+--------+----------+----------+---------+---------+---------+-----------+-----------------+-----------------+
| chanid | channum | freqid | sourceid | callsign | name    | xmltvid | mplexid | serviceid | atsc_major_chan | atsc_minor_chan |
+--------+---------+--------+----------+----------+---------+---------+---------+-----------+-----------------+-----------------+
|   3291 | 29_1    | 42     |        3 | WTXFDT   | WTXFDT  | 19614   |     146 |         3 |              29 |               1 |
+--------+---------+--------+----------+----------+---------+---------+---------+-----------+-----------------+-----------------+
1 row in set (0.00 sec)
What am I missing?!
Attachments
WTXFDT mysql search.txt
(5.21 KiB) Downloaded 35 times
Mythbackend_log 210305.txt
(24.82 KiB) Downloaded 36 times
Last edited by stantonovitch on Thu Mar 11, 2021 9:03 pm, edited 1 time in total.
Top
stantonovitch
Newcomer
Posts: 2
Joined: Sat Mar 06, 2021 5:16 pm
United States of America

Re: Recording remnants in Upcoming Recordings

Post by stantonovitch »

Well, I never found the underlying issue. I did fix the symptom by removing the xmltvid for channel 252. My cable provider, Comcast, also uses channel 1029 in the lineup to broadcast the same channel 29_1, in the same xmltvid as channel 252, so 252 is really unneeded. Channel 29_1 OTA has recorded many times since the xmltvid change, and there have been no issues.

In my digging into this, I did remind myself that at one time I even lowered channel 252's priority by 3 points, and it still had this issue. My database is over 15 years old ( ! ), so I'm guessing there's some strange setting stuck in there from the tuner and source migrations over the years.

Changing the title of this thread to [Solved], even though I never found the underlying issue.
Top
Post Reply

Return to “Troubleshooting”