And the jobs scheduled for tomorrow appear correct in /dvr/programs
"placeholder/16085/1662408000": "queued-1662408000-104",
"placeholder/16108/1662408000": "queued-1662409200-105",
"placeholder/16095/1662408000": "queued-1662410400-106",
Ever since this was implemented I've noticed loads of placeholders in the guide data where there shouldn't be and never were before (see screenshot). Any idea why this is happening? Server is on the latest pre-release 2022.09.05.0346. Source is an M3U that combines output from my HDHR and SAT>IP tuners. Guide data is manually mapped data directly from Channels (not XML).
Just recreated the problem on another server set to do the same thing, just different times.
I captured log info, scheduled jobs and dvr/programs after this mornings guide update.
3 recordings scheduled daily at 12:00, 12:20 and 12:40.
I waited until the 12:00 ten minute recording finished, then at 12:13:04 I created a new series pass for new episodes of The Andy Griffith Show (cause I knew there would be none) just to get the scheduler to run through my passes.
It cancelled the 12:20 and 12:40 scheduled recordings.
Here are the log entries from the daily guide update finishing until the scheduled jobs were cancelled.
2022/09/05 09:25:22.554531 [DVR] Waiting 2h34m37.445479166s until next job 1662404400-50 fake-SUNDANCE @ 12PM
2022/09/05 09:25:22.563352 [IDX] Pruned 4190 expired airings from X-TVE in 475.646676ms.
2022/09/05 09:25:22.652442 [IDX] Pruned 990 expired airings from X-M3U in 88.960491ms.
2022/09/05 09:25:22.673061 [IDX] Pruned 112 expired airings from XMLTV-frndlyTVNoEpg in 20.445329ms.
2022/09/05 10:21:47.173017 [SYS] Created database snapshot: backup-20220905.102147
2022/09/05 10:21:47.173364 [SYS] Removing old backup backup-20220819.154242
2022/09/05 12:00:00.003032 [DVR] Starting job 1662404400-50 fake-SUNDANCE @ 12PM on ch=[16085]
2022/09/05 12:00:00.003210 [DVR] Waiting 19m59.996800965s until next job 1662405600-51 fake-MAGNOLIA @ 12PM
2022/09/05 12:00:02.710476 [TNR] Opened connection to TVE-Comcast_SSO for ch6085 SUNDANCE
2022/09/05 12:00:02.711988 [HLS] Starting live stream for channel 6085 from 192.168.1.3 (bitrate=2654)
2022/09/05 12:00:04.101867 [HLS] Probed live stream in 1.388877171s: h264 1280x720 progressive 2900405bps
2022/09/05 12:00:04.153364 [HLS] Session ch6085-dTVE-Comcast_SSO-ip192.168.1.3 started in 4.146477837s
2022/09/05 12:00:04.189911 [TNR] Opened connection to M3U-fakeCANARY for ch16085 fake-SUNDANCE
2022/09/05 12:00:04.191044 [DVR] Recording for job 1662404400-50 from M3U-fakeCANARY ch16085 into "TV/fake-SUNDANCE @ 12PM/fake-SUNDANCE @ 12PM 2022-09-05-1200.mpg" for 9m59.996699187s
2022/09/05 12:00:04.718407 [IDX] Generating video index for job 1662404400-50
2022/09/05 12:10:09.004692 [SNR] Buffer statistics for "TV/fake-SUNDANCE @ 12PM/fake-SUNDANCE @ 12PM 2022-09-05-1200.mpg": buf=0% drop=0%
2022/09/05 12:10:09.208425 [MTS] Statistics for "TV/fake-SUNDANCE @ 12PM/fake-SUNDANCE @ 12PM 2022-09-05-1200.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=0 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=true saw_pmt=true highest_pts=612.622000
2022/09/05 12:10:09.222107 [TNR] Closed connection to M3U-fakeCANARY for ch16085 fake-SUNDANCE
2022/09/05 12:10:09.311010 [DVR] Finished job 1662404400-50 fake-SUNDANCE @ 12PM
2022/09/05 12:10:09.510842 [DVR] Waiting 9m50.489539197s until next job 1662405600-51 fake-MAGNOLIA @ 12PM
2022/09/05 12:10:09.511181 [DVR] Processing file-991: TV/fake-SUNDANCE @ 12PM/fake-SUNDANCE @ 12PM 2022-09-05-1200.mpg
2022/09/05 12:10:43.091312 [HLS] Stopping inactive session ch6085-dTVE-Comcast_SSO-ip192.168.1.3
2022/09/05 12:10:43.091381 [HLS] Stopping transcoder session ch6085-dTVE-Comcast_SSO-ip192.168.1.3 (out: 10m48.640011s, finished: false)
2022/09/05 12:10:43.098628 [TNR] Closed connection to TVE-Comcast_SSO for ch6085 SUNDANCE
2022/09/05 12:10:43.133567 [SNR] Buffer statistics for ch6085 SUNDANCE: buf=0% drop=0%
2022/09/05 12:13:04.443195 [DVR] Deleting job with expired serial: 1662405600-51 fake-MAGNOLIA @ 12PM (placeholder/16108/1662404400)
2022/09/05 12:13:04.482509 [DVR] Deleting job with expired serial: 1662406800-52 fake-REELZ @ 12PM (placeholder/16095/1662404400)
2022/09/05 12:13:04.500426 [DVR] Waiting 23h46m55.499589761s until next job 1662490800-50 fake-SUNDANCE @ 12PM
2022/09/05 12:13:04.683958 [DVR] Waiting 23h46m55.31605372s until next job 1662490800-50 fake-SUNDANCE @ 12PM
Here are the scheduled jobs info I gathered after this mornings guide update
Schedule Today
12:00 PM 10 min fake-SUNDANCE @ 12PM fake-SUNDANCE 16085
12:20 PM 10 min fake-MAGNOLIA @ 12PM fake-MAGNOLIA 16108
12:40 PM 10 min fake-REELZ @ 12PM fake-REELZ 16095
Calendar Today
fake-SUNDANCE @ 12PM 12:00pm-12:10pm
fake-MAGNOLIA @ 12PM 12:20pm-12:30pm
fake-REELZ @ 12PM 12:40pm-12:50pm
SUNDANCE
Log entries for queuing job and setting Serial
2022/09/04 14:04:28.128927 [DVR] Rule 'Canary SUNDANCE daily 10 min recording at 12PM' (50) found 1 new airings
2022/09/04 14:04:28.136518 [DVR] queued recording job for placeholder/16085/1662404400 @ Mon Sep 5 12:00:00PM on ch=[16085] (1662404400-50)
(NEXT LINE AT END OF GUIDE UPDATE THIS MORNING REFLECTS TIMESTAMP OF SERIAL SET IN SCHEDULED JOB)
2022/09/05 09:25:22.554531 [DVR] Waiting 2h34m37.445479166s until next job 1662404400-50 fake-SUNDANCE @ 12PM
/dvr/programs
"placeholder/16085/1662404400": "queued-1662404400-50",
/dvr/jobs
{
"ID": "1662404400-50",
"Name": "fake-SUNDANCE @ 12PM",
"Time": 1662404400,
"Duration": 600,
"Channels": [
"16085"
],
"Channel": "",
"DeviceID": "",
"RuleID": "50",
"Serial": 1662395122, (FROM GUIDE UPDATE THIS MORNING Monday, September 5, 2022 9:25:22 AM GMT-07:00 DST)
"FileID": "",
"Skipped": false,
"Failed": false,
"Dead": false,
"Error": "",
"Airing": {
"Source": "placeholder",
"Channel": "16085",
"Time": 1662404400,
"Duration": 3600,
"Title": "fake-SUNDANCE @ 12PM",
"SeriesID": "placeholder/16085/12PM",
"ProgramID": "placeholder/16085/1662404400"
},
"UpdatedAt": 1662395122352 (FROM GUIDE UPDATE THIS MORNING Monday, September 5, 2022 9:25:22 AM GMT-07:00 DST)
}
MAGNOLIA
Log
2022/09/04 14:02:59.406023 [DVR] Rule 'Canary MAGNOLIA daily 10 min recording at 12:20PM' (51) found 1 new airings
2022/09/04 14:02:59.424490 [DVR] queued recording job for placeholder/16108/1662404400 @ Mon Sep 5 12:20:00PM on ch=[16108] (1662405600-51)
(NEXT LINE AT END OF GUIDE UPDATE THIS MORNING REFLECTS TIMESTAMP OF SERIAL SET IN SCHEDULED JOB)
2022/09/05 09:25:22.554531 [DVR] Waiting 2h34m37.445479166s until next job 1662404400-50 fake-SUNDANCE @ 12PM
/dvr/programs
placeholder/16108/1662404400": "queued-1662405600-51",
/dvr/jobs
{
"ID": "1662405600-51",
"Name": "fake-MAGNOLIA @ 12PM",
"Time": 1662405600,
"Duration": 600,
"Channels": [
"16108"
],
"Channel": "",
"DeviceID": "",
"RuleID": "51",
"Serial": 1662395122, (FROM GUIDE UPDATE THIS MORNING Monday, September 5, 2022 9:25:22 AM GMT-07:00 DST)
"FileID": "",
"Skipped": false,
"Failed": false,
"Dead": false,
"Error": "",
"Airing": {
"Source": "placeholder",
"Channel": "16108",
"Time": 1662404400,
"Duration": 3600,
"Title": "fake-MAGNOLIA @ 12PM",
"SeriesID": "placeholder/16108/12PM",
"ProgramID": "placeholder/16108/1662404400"
},
"UpdatedAt": 1662395122483 (FROM GUIDE UPDATE THIS MORNING Monday, September 5, 2022 9:25:22 AM GMT-07:00 DST)
}
REELZ
Log
2022/09/04 14:03:48.108588 [DVR] Rule 'Canary REELZ daily 10 min recording at 12:40PM' (52) found 1 new airings
2022/09/04 14:03:48.112688 [DVR] queued recording job for placeholder/16095/1662404400 @ Mon Sep 5 12:40:00PM on ch=[16095] (1662406800-52)
(NEXT LINE AT END OF GUIDE UPDATE THIS MORNING REFLECTS TIMESTAMP OF SERIAL SET IN SCHEDULED JOB)
2022/09/05 09:25:22.554531 [DVR] Waiting 2h34m37.445479166s until next job 1662404400-50 fake-SUNDANCE @ 12PM
/dvr/programs
"placeholder/16095/1662404400": "queued-1662406800-52",
/dvr/jobs
{
"ID": "1662406800-52",
"Name": "fake-REELZ @ 12PM",
"Time": 1662406800,
"Duration": 600,
"Channels": [
"16095"
],
"Channel": "",
"DeviceID": "",
"RuleID": "52",
"Serial": 1662395122, (FROM GUIDE UPDATE THIS MORNING Monday, September 5, 2022 9:25:22 AM GMT-07:00 DST)
"FileID": "",
"Skipped": false,
"Failed": false,
"Dead": false,
"Error": "",
"Airing": {
"Source": "placeholder",
"Channel": "16095",
"Time": 1662404400,
"Duration": 3600,
"Title": "fake-REELZ @ 12PM",
"SeriesID": "placeholder/16095/12PM",
"ProgramID": "placeholder/16095/1662404400"
},
"UpdatedAt": 1662395122547 (FROM GUIDE UPDATE THIS MORNING Monday, September 5, 2022 9:25:22 AM GMT-07:00 DST)
}
And in case it helps, Logs have been submitted as d7536ab6-a9e9-47e8-b683-62dc3a13d476
WORKAROUND: Don't use start padding on placeholder guide channels until it's fixed
Thanks, I'm still trying to wrap my head around what might be going on.
It's definitely the scheduler not finding the airing as part of the rule, but I'm not sure where its failing. I wonder.. if at 12:13pm, you check the edit advanced pass editor where it shows matches, is 12:20 matching or not?
1 Like
I think I fixed it.
2 Likes
Appears to be fixed.
I did a quick test scheduling a 5 minute recording on TVE ch6700 at 6:15pm using negative start padding.
The pass selected the channel and time contains 6pm.
Then at 6:13pm I created a new series pass for new eps of The Andy Griffith show.
The scheduled recording worked.
I also tested on another server that hasn't been updated yet using an HDHR source.
Scheduled a 5 minute recording on a channel that has real guide data for 6:15pm using negative start padding.
The pass selected the channel and time contains 6pm.
Then at 6:12pm I created a new series pass for new eps of The Andy Griffith show.
The scheduled recording was deleted by Channels DVR at that time.
2022/09/05 17:53:48.008692 [DVR] Rule '000-Testing 1 2 3' (615) found 1 new airings
2022/09/05 17:53:48.022883 [DVR] queued recording job for EP000017710021 @ Mon Sep 5 6:15:00PM on ch=[484] (1662426900-615)
2022/09/05 17:59:00.002400 [DVR] Waiting 15m59.997606235s until next job 1662426900-615 Full House
2022/09/05 18:02:00.243655 [DVR] Waiting 12m59.756380058s until next job 1662426900-615 Full House
2022/09/05 18:12:02.308623 [DVR] Deleting job with expired serial: 1662426900-615 Full House (EP000017710021)
So, this issue didn't just affect the new placeholder guide channels.
1 Like
The placeholders seem to have their times wrong this morning. I am observing this on IOS and Web admin.
1 Like
I'm running the latest prerelease and seeing correct times on my three dvr servers using the placeholder EPG. But, mine haven't done their daily morning guide update yet.
I hadn't updated since yesterday morning so I may have been a release or two behind. However, I am seeing the same behavior on the latest build. Four hours fast.
Must be the placeholder EPG data then if it's appearing bad on older releases.
Or could be the release!
Looks good here after updating and daily morning guide refresh.
1 Like
Confirmed fixed after install of v2022.09.06.1554 and refreshing guide.
1 Like
Do you have duplicated channel numbers across different sources?
I love the idea of the placeholders…
Im wondering why im getting placeholder with these timeshifted hours in the guide. Vs the guide times.
Yes, I have a backup M3U for the channels that are duplicates between my HDHR and SAT>IP, so if one fails or goes offline it will pick up channels from the other. The channel numbers are the same and they’re mapped to the same guide data.
Placeholders only appear for unmapped channels, so one of the sources must not have the same guide mapping.
Yes, my HDHR is completely unmapped since I use it via an M3U instead so I can do my own channel numbering scheme. Some of the channel numbers do conflict. This never caused issues before the placeholder feature was added. Is there a way to get the HDHR to not appear as a tuner source?
1 Like
I think the unmapped HDHR is ignored. I meant sources where guide data is setup, but that particular channel does not have a source for data.