Recordings Always Starting Late

Channels Apple TV
#1

Where does Channels get its time from? The Apple TV itself? If so, my Apple TV is exactly on the correct time, showing me the same time as my iPhone (satellite).

However, every show I have passed for, I always miss the first minute or so. Some shows I set to start recording 3 minutes early and it still clipped some if the beginning.

I can’t do this for all shows, however, as we record multiple shows as the same time, and starting early for all shows would overlap, causing conflicts and, as a result, not recording some shows.

Anyone else have issues with the beginning of shows being clipped? It doesn’t look like I can manually adjust the time in Channels.

Thanks.

#2

Recordings happen on the DVR Server. Where is your DVR Running and did you check the time on the Server. Also, you may want to move this to the DVR Category. And, you can set the start recording time to be before the actual start time of the show.

1 Like
#3

I usually don't use buffers, they are ugly. Unless recording a football or baseball game, or using TVE. But my recordings all start exactly at the start of the show, almost to the second. Occasionally, there is a 1 to 2-second blip of commercial ad and then show starts.

The only recordings time issues I have are with TVE, which always ends up recording almost 1 full minute early. And I have to add 1 minute padding on the end of TVE too.

1 Like
#4

Check the clock on your DVR PC and make sure time sync is enabled.

1 Like
#5

Sorry, I didn't even see these replies. Just actually checked that before logging onto here. Apparently my PC likes to slow down over time. I thought Channels was grabbing the time from Apple TV. I will sync my time to an NTS.

Thanks!

#6

I’m having the same issue. Many of my recordings have the “Recording was started late” warning. Even games that I watched live and I still have the beginning of the game in my client’s buffer have the first 5-15 min missing in the DVR.
I checked the time on my server, seems correct.

My DVR has 2 sources. TVE and an antenna + HDHomeRun.

Anything else I can do to debug this?

#7

Click the Log tab on your DVR web UI, scroll back to time of a recording affected and copy/paste the messages.

#8

Thanks. Here are the logs for the last time this happened. It's job 1573502400-8 on BTN.

2019/11/11 14:18:22 [NAT] Successfully mapped port 8089 using upnp
2019/11/11 15:03:31 [DVR] Starting job 1573502400-8 BTN Football in 60 on ch=[6199]
2019/11/11 15:03:31 [TNR] Sharing existing connection to TVE-ATTOTT for ch6199 BTN (clients=2, len=0)
2019/11/11 15:03:31 [DVR] Starting job 1573502400-9 South Park on ch=[6010]
2019/11/11 15:03:31 [DVR] Waiting 9h1m28.892012s until next job 1573535100-9 South Park
2019/11/11 15:03:31 [DVR] Recording for job 1573502400-8 from TVE-ATTOTT ch6199 into "TV/BTN Football in 60/BTN Football in 60 2019 Illinois at Michigan State 2019-11-11-1503.mpg" for 56m28.892204s
2019/11/11 15:03:31 [IDX] Generating video index for job 1573502400-8
2019/11/11 15:03:32 [TNR] Opened connection to TVE-ATTOTT for ch6010 CC
2019/11/11 15:03:32 [DVR] Recording for job 1573502400-9 from TVE-ATTOTT ch6010 into "TV/South Park/South Park S05E11 2001-11-21 The Entity 2019-11-11-1503.mpg" for 26m28.891964s
2019/11/11 15:03:32 [IDX] Generating video index for job 1573502400-9
2019/11/11 15:20:36 [NAT] Successfully mapped port 8089 using upnp
2019/11/11 15:30:25 [MTS] Statistics for "TV/South Park/South Park S05E11 2001-11-21 The Entity 2019-11-11-1503.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=27 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=false saw_pmt=true highest_pts=1617.655211
2019/11/11 15:30:32 [TNR] Closed connection to TVE-ATTOTT for ch6010 CC
2019/11/11 15:30:32 [DVR] Finished job 1573502400-9 South Park
2019/11/11 15:30:32 [DVR] Waiting 8h34m27.099874s until next job 1573535100-9 South Park
2019/11/11 15:30:32 [DVR] Processing file-167: TV/South Park/South Park S05E11 2001-11-21 The Entity 2019-11-11-1503.mpg
2019/11/11 15:30:35 [DVR] Running commercial detection on file 167 (TV/South Park/South Park S05E11 2001-11-21 The Entity 2019-11-11-1503.mpg)
2019/11/11 15:34:30 [DVR] Commercial detection finished with 6 markers.
2019/11/11 16:00:44 [MTS] Statistics for "TV/BTN Football in 60/BTN Football in 60 2019 Illinois at Michigan State 2019-11-11-1503.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=55 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=false saw_pmt=true highest_pts=6376.770878
2019/11/11 16:00:44 [DVR] Finished job 1573502400-8 BTN Football in 60
2019/11/11 16:00:44 [DVR] Waiting 8h4m15.871812s until next job 1573535100-9 South Park
2019/11/11 16:00:44 [DVR] Processing file-166: TV/BTN Football in 60/BTN Football in 60 2019 Illinois at Michigan State 2019-11-11-1503.mpg
2019/11/11 16:00:44 [DVR] Running commercial detection on file 166 (TV/BTN Football in 60/BTN Football in 60 2019 Illinois at Michigan State 2019-11-11-1503.mpg)
2019/11/11 16:16:36 [DVR] Waiting 7h48m23.020617s until next job 1573535100-9 South Park
2019/11/11 16:21:00 [NAT] Successfully mapped port 8089 using upnp
2019/11/11 16:23:03 [DVR] Commercial detection finished with 12 markers.
2019/11/11 16:39:03 [TNR] Closed connection to TVE-ATTOTT for ch6199 BTN

38%20PM

#9

Here are other mentions of the same job ID:

2019/11/11 08:47:31 [DVR] queued recording job for EP019790520388 @ Mon Nov 11 3:00:00PM (1573502400-8)

2019/11/11 12:59:20 [DVR] Waiting 2h0m39.099268s until next job 1573502400-8 BTN Football in 60

2019/11/11 13:30:57 [DVR] Waiting 1h29m2.006511s until next job 1573502400-8 BTN Football in 60

#10

The "Delayed" error happens on both TVE and my OTA antenna.
But with my TVE I've also seen the "interrupted" error.
Here's an example with ID 1573488600-9:

2019/11/11 10:29:01 [DVR] Waiting 40m58.826418s until next job 1573488600-9 South Park
2019/11/11 10:57:08 [DVR] Rule 'Michigan Wolverines: Basketball' (1) found 2 new airings
2019/11/11 10:57:08 [DVR]   queued recording job for EP032755530432 @ Tue Nov 12 6:30:00PM (1573601400-1)
2019/11/11 10:57:08 [DVR]   queued recording job for EP032755530539 @ Fri Nov 15 7:00:00PM (1573862400-1)
2019/11/11 10:57:09 [DVR] Skipping job 1573486200-8 BTN Football in 60
2019/11/11 10:57:09 [DVR] Waiting 12m50.69567s until next job 1573488600-9 South Park
2019/11/11 11:09:18 [NAT] Successfully mapped port 8089 using upnp
2019/11/11 11:10:09 [DVR] Skipping job 1573486200-8 BTN Football in 60
2019/11/11 11:10:09 [DVR] Starting job 1573488600-9 South Park on ch=[6010]
2019/11/11 11:10:09 [DVR] Waiting 1h44m50.773929s until next job 1573494900-9 South Park
2019/11/11 11:10:12 [TNR] Opened connection to TVE-ATTOTT for ch6010 CC
2019/11/11 11:10:12 [DVR] Recording for job 1573488600-9 from TVE-ATTOTT ch6010 into "TV/South Park/South Park S04E08 2000-07-12 Something You Can Do With Your Finger 2019-11-11-1110.mpg" for 34m50.773881s
2019/11/11 11:10:12 [IDX] Generating video index for job 1573488600-9
2019/11/11 11:15:12 [DVR] Fetching guide data for 126 stations in X-TVE @ 2019-11-11 11:00AM

2019/11/11 11:32:54 [MTS] Statistics for "TV/South Park/South Park S04E08 2000-07-12 Something You Can Do With Your Finger 2019-11-11-1110.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=28 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=false saw_pmt=true highest_pts=1319.076822
2019/11/11 11:32:55 [TNR] Closed connection to TVE-ATTOTT for ch6010 CC
2019/11/11 11:32:55 [DVR] Job 1573488600-9 South Park ended prematurely: 12m4.354364s
2019/11/11 11:32:55 [DVR] Deleting skipped job 1573486200-8 BTN Football in 60
2019/11/11 11:32:55 [DVR] Starting job 1573488600-9 South Park on ch=[6010]
2019/11/11 11:32:55 [DVR] Waiting 1h22m4.316015s until next job 1573494900-9 South Park
2019/11/11 11:32:57 [TNR] Opened connection to TVE-ATTOTT for ch6010 CC
2019/11/11 11:32:57 [DVR] Recording for job 1573488600-9 from TVE-ATTOTT ch6010 into "TV/South Park/South Park S04E08 2000-07-12 Something You Can Do With Your Finger 2019-11-11-1110.mpg" for 12m4.315979s
2019/11/11 11:45:17 [MTS] Statistics for "TV/South Park/South Park S04E08 2000-07-12 Something You Can Do With Your Finger 2019-11-11-1110.mpg": skipped=0 unhandled_packets=0 discontinuity_detected=15 transport_errors=0 invalid_pts=0 invalid_dts=0 saw_pcr=false saw_pmt=true highest_pts=2113.003111
2019/11/11 11:45:26 [TNR] Closed connection to TVE-ATTOTT for ch6010 CC
2019/11/11 11:45:26 [DVR] Finished job 1573488600-9 South Park

#11

What fixed it is that the PC my server runs on keeps slowing the time down. I never reboot it, so I don’t think I need to replace the CSM battery. Not sure why my PC clock slows down

I reset the time and everything was fine again until it started to slow down. Just an issue with my PC.

#12

It is weird there are no messages at 15:00 when the recording should have started. I think probably your mac is going to sleep. Do you have Energy Saver set to never sleep?

#13

Thanks.
I just checked. sleep is set to never. I also have the "NoSleep" app to prevent my mac from sleeping(for Plex).

But either way, I happened to be watching that game live on my Apple TV. Wouldn't that mean the server was on during that time, or can live TV be watched on the AppleTV directly without the server?

Anything else I should check? Is CPU load a factor?

#14

So here it asks the OS to trigger at 14:59, but the first message shown was at 15:03

This makes me suspect a time/clock issue on the hardware or the OS, similar to the problem @kevin.ague had.

Do you have "set date and time automatically" enabled in system preferences?

1 Like
#15

What version of macOS?

1 Like
#16

Do you have "set date and time automatically" enabled in system preferences?

23%20PM
Screen Shot 2019-11-11 at 8.12.23 PM.jpg1204×950 168 KB

What version of macOS?

10.13.6