Both. I am seeing the same behavior across all the platforms I have. AppleTV, iOS, chrome browser.
It's working for me. Not sure why it's not for you.
Are you running the latest dvr pre-release version 2022.09.01.2101?
1 Like
Of course. Seems unlikely that all my platforms would be suffering from the same random error. But like I said, it’s not a big deal to me. I use prerelease software so I feel obligated to report my experience and not crap I haven’t done basic troubleshooting on beforehand.
1 Like
No offense meant. Was just trying to figure out why it worked for me and not you.
I'll let the devs continue your conversation 
1 Like
All good. I was just on Facebook so I was already in a bad mood. Thanks for the help.
Everything seems fine today after latest updates. Thanks (if you did something to fix this; if not, thanks anyway).
1 Like
Great!
It happened again. It appears the scheduler is looking at the placeholder time instead of the recording start time and taking into account the padding.
Two scheduled recordings were deleted by Channels DVR and after pausing/resuming the passes, they wouldn't schedule for today.
First one should be recording at 13:20:00, second at 13:40:00
2022/09/04 13:17:00.042054 [DVR] Deleting job with expired serial: 1662322800-105 fake-MAGNOLIA @ 1PM (placeholder/16108/1662321600)
2022/09/04 13:17:00.067346 [DVR] Deleting job with expired serial: 1662324000-106 fake-REELZ @ 1PM (placeholder/16095/1662321600)
I just now changed the passes from a series pass to channel == and time contains 1pm, but I don't think that will fix the problem.
Here's the scheduled job for the 1:40pm recording tomorrow. Not sure how the Serial works with these, as it is when it was scheduled 15 minutes ago. It seems like the scheduler is looking at Airing.Time 1662408000 instead of the scheduled job start Time 1662410400.
{
"ID": "1662410400-106",
"Name": "fake-REELZ @ 1PM",
"Time": 1662410400,
"Duration": 600,
"Channels": [
"16095"
],
"Channel": "",
"DeviceID": "",
"RuleID": "106",
"Serial": 1662324232,
"FileID": "",
"Skipped": false,
"Failed": false,
"Dead": false,
"Error": "",
"Airing": {
"Source": "placeholder",
"Channel": "16095",
"Time": 1662408000,
"Duration": 3600,
"Title": "fake-REELZ @ 1PM",
"SeriesID": "placeholder/16095/1PM",
"ProgramID": "placeholder/16095/1662408000"
},
"UpdatedAt": 1662324233287
},
What is the timezone on that dvr set to/
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.