Failed: program already started

[Robinlmp]

Here's the start log and end instance of a repeating log entry. I've left out hundreds of lines of identical entries between the two:

2019/12/30 13:24:00 [DVR] Starting job 1577712240-ch101 Indiana Jones and the Kingdom of the Crystal Skull (2008) on ch=[101]
2019/12/30 13:24:00 [DVR] Waiting 5m29.872425s until next job 1577712570-3 The Big Bang Theory
2019/12/30 13:24:00 [ERR] Failed to start stream on channel 101 via 12523831: HDHomeRun: 805 All Tuners In Use
2019/12/30 13:24:00 [DVR] Error running job 1577712240-ch101 Indiana Jones and the Kingdom of the Crystal Skull (2008): could not start stream on channels=[101]: HDHomeRun: 805 All Tuners In Use

2019/12/30 14:00:29 [DVR] Starting job 1577712240-ch101 Indiana Jones and the Kingdom of the Crystal Skull (2008) on ch=[101]
2019/12/30 14:00:29 [DVR] Waiting 1h18m30.897301s until next job 1577719140-ch101 Shrek 2 (2004)
2019/12/30 14:00:29 [ERR] Failed to start stream on channel 101 via 12523831: HDHomeRun: 805 All Tuners In Use
2019/12/30 14:00:29 [DVR] Error running job 1577712240-ch101 Indiana Jones and the Kingdom of the Crystal Skull (2008): could not start stream on channels=[101]: HDHomeRun: 805 All Tuners In Use

[Robinlmp]

And here where the recording started:

2019/12/30 14:00:30 [DVR] Starting job 1577712240-ch101 Indiana Jones and the Kingdom of the Crystal Skull (2008) on ch=[101]
2019/12/30 14:00:30 [DVR] Waiting 1h18m29.851074s until next job 1577719140-ch101 Shrek 2 (2004)
2019/12/30 14:00:30 [DVR] Processing file-16: TV/The Big Bang Theory/The Big Bang Theory S02E05 2008-10-20 The Euclid Alternative 2019-12-30-1329.mpg
2019/12/30 14:00:30 [DVR] Waiting 1h18m29.746815s until next job 1577719140-ch101 Shrek 2 (2004)
2019/12/30 14:00:30 [DVR] Running commercial detection on file 16 (TV/The Big Bang Theory/The Big Bang Theory S02E05 2008-10-20 The Euclid Alternative 2019-12-30-1329.mpg)
2019/12/30 14:00:31 [TNR] Opened connection to 12523831/3 for ch101 BBC ONE HD
2019/12/30 14:00:31 [DVR] Recording for job 1577712240-ch101 from 12523831 ch101 into "Movies/Indiana Jones and the Kingdom of the Crystal Skull (2008) 2019-12-30-1400.mpg" for 1h22m29.821125s
2019/12/30 14:00:31 [IDX] Generating video index for job 1577712240-ch101

[tmm1]

Thank you for the logs!

Looks like there's a bug where a recording doesn't give up when its scheduled manually (not via a pass), which is the case for all movies. Will look into a fix.

[Brucekaiser]

I've recently started getting this same error message. "Failed Program already Started" I have two HDHR Duo's running and have reviewed the recording schedules. I have no more than three programs recording at any given time. Sometimes during the times when 3 programs are recording we watch a live program. That makes 4 programs and my two duo tuners should handle that right? I have recently increased the padding to three minutes on a couple of the programs as they always seemed to start recording late. (after the show has already started). Could the padding be causing this? I have not seen the error message "all tuners in use" yet as stated above by TMM1 post 16.

[tmm1]

Please click Help > Submit Diagnostics

[Brucekaiser]

done; thank you

[Brucekaiser]

Hi; any input after looking at the diagnostics. I did reduce padding on the shows in question to "none" now everything records ok but the two programs start recording a minute or two late.

[Brucekaiser]

I went ahead and changed the end padding on the shows just before the ones in question to "none". See how it goes this evening.

[MikePHall]

I had a program fail to record starting at 8:59pm on 11/1/2021 for channel 103.1 (which is the 3.1 HEVC NextGen TV channel) which was the only 1 of the 2 HEVC tuner in use. I was watching a standard 1 of 2(4) ATSC 1.0 tuner channel 61.4 on TV which I wasn't recording. (A 9.59pm program on 103.1 did record).

Cut out of log around start time:
WHEN IT SHOULD HAVE STARTED:
2021/11/01 20:59:00.110138 [HTTP] | 200 | 24.887357ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:02.145533 [HTTP] | 200 | 26.712823ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:04.178694 [HTTP] | 200 | 26.086847ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:06.213960 [HTTP] | 200 | 24.745839ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:08.246328 [HTTP] | 200 | 27.027894ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:10.276125 [HTTP] | 200 | 24.753172ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:12.307047 [HTTP] | 200 | 25.345759ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:14.336676 [HTTP] | 200 | 23.229739ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:16.366539 [HTTP] | 200 | 24.243527ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:18.396659 [HTTP] | 200 | 23.425626ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:20.428162 [HTTP] | 200 | 24.418785ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:22.457586 [HTTP] | 200 | 24.201138ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:24.487650 [HTTP] | 200 | 24.51958ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:26.522520 [HTTP] | 200 | 26.109401ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:28.556337 [HTTP] | 200 | 24.782837ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:30.586820 [HTTP] | 200 | 23.412033ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:32.616392 [HTTP] | 200 | 24.805892ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:34.644554 [HTTP] | 200 | 23.173535ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:36.674012 [HTTP] | 200 | 23.628419ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:38.704538 [HTTP] | 200 | 23.297737ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:40.733092 [HTTP] | 200 | 23.378328ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:42.767320 [HTTP] | 200 | 24.453283ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:44.796894 [HTTP] | 200 | 24.562542ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:46.824866 [HTTP] | 200 | 23.341051ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:48.858461 [HTTP] | 200 | 24.818706ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:50.887906 [HTTP] | 200 | 24.276432ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:52.917567 [HTTP] | 200 | 23.953823ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:54.948343 [HTTP] | 200 | 25.353905ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:56.979161 [HTTP] | 200 | 24.400894ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 20:59:59.009480 [HTTP] | 200 | 23.444698ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:00:01.037501 [HTTP] | 200 | 23.726436ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"

WHEN IT TRIED TO START:
2021/11/01 21:11:24.076866 [HTTP] | 200 | 25.157531ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:26.107402 [HTTP] | 200 | 23.237678ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:28.140490 [HTTP] | 200 | 25.296363ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:30.173064 [HTTP] | 200 | 25.325382ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:32.204725 [HTTP] | 200 | 25.791508ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:34.237096 [HTTP] | 200 | 25.393307ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:36.271703 [HTTP] | 200 | 25.042773ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:37.793165 [DVR] Skipping job because program already started 1635814770-9 NCIS
2021/11/01 21:11:37.806178 [DVR] Waiting 47m52.193844654s until next job 1635818370-10 NCIS: Hawai'i
2021/11/01 21:11:37.818219 [HTTP] | 200 | 1.826298ms | 192.168.1.198 | GET "/dvr/jobs/1635814770-9"
2021/11/01 21:11:38.305066 [HTTP] | 200 | 28.474668ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:40.336323 [HTTP] | 200 | 25.85971ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:42.366277 [HTTP] | 200 | 24.682999ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:44.395914 [HTTP] | 200 | 23.777636ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:46.424380 [HTTP] | 200 | 23.378566ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"
2021/11/01 21:11:48.460888 [HTTP] | 200 | 25.826099ms | 192.168.1.198 | GET "/devices/10A12D75/status/2/debug"

OS
Linux Raspbian
10.11 (kernel: 5.10.63-v7l+)

CPU
4 cores / ARMv7 Processor rev 3 (v7l)
load averages: 0.52 0.58 0.59

RAM
3.51 GB
91.6% free

[racameron]

@MikePHall

Logs from yesterday are already gone.

The logs aren't gone; the web view just shows the last 1000 lines or so. To see more, just tell it:

Subscription FAQ

[MikePHall]

Thx

[speedingcheetah]

Just had this problem. Only noticed it after the show aired.
Pass was set to Record on REELZ the On Patrol LIVE new premier, and now i see it failed with error "failed" program already started".
it is via TVE, so it not have had a tuner not available issue.

EDIT: btw, the TVE stream for REELZ is crap quality.

[tmm1]

probably the stream was down and now only the low quality one is online

[speedingcheetah]

I only see this in the log
2022/07/23 00:20:15.068649 [TVE] action=error_response type=Document error=net::ERR_ABORTED url=https://sp.auth.adobe.com/adobe-services/completePassiveAuthentication
2022/07/23 00:20:15.669593 [TVE] action=error_response type=Other error=net::ERR_UNKNOWN_URL_SCHEME url=

And i just opened the channel and it plays fine, but looks crappy, but that is how it looked before anyways.

[Absenm]

@speedingcheetah

Pass was set to Record on REELZ the On Patrol LIVE new premier, and now i see it failed with error "failed" program already started".

Yeah On Patrol: Live had a ton of technical problems with their launch tonight. ‘On Patrol: Live’ Technical Launch Glitch Delays Show Debut On Reelz – Deadline. They eventually started it from the beginning 1.25 hrs late (so technically not live) but commercial free. And even then there were moments the channel cut out.

[mjitkop]

FYI, the last I checked on January 2nd this year, Reelz TVE had a low bit rate of 2.8 Mb/s. That put it in the 11th position of the worst bit rates of TVE channels.

For the full list, see this:

TV Everywhere Stream Specs

[speedingcheetah]

Well I tuned in a little bit after midnight for the rerun and started a manual recording

Also according to the guide episode one reairs at 2 PM tomorrow

[speedingcheetah]

Even checking the Xfininty Stream site, the REELZ stream there, looks like VOD, but seems to just open the live channel feed, is the same terrible quality stream.

Playing back the Channels DVR .ts file, it is not deinterlacing by default, and when i engage deinterlace in MPV, wow does it look bad.

Is this how REELZ is normally even on cable tv or ay other streaming service that offers it?

[chDVRuser]

The TVE feed I get for Reelz is 1280x720p @ 59.94FPS
It's not interlaced.
It is a low bit rate though (about 2Mbps).

[speedingcheetah]

forgot a thread already was a thing for Reelz and On Patrol specifically

On Patrol: Live coming to Reelz July 2022

too bad Reelz stream is SO bad quality. I have never seen such a poor quality "HD" stream ever. I have SD channels that look better. [On Patrol Live S01E01 2022-07-22 2022-07-23-1659_00.07.25] [On Patrol Live S01E01 2022-07-22 2022-07-23-1659_00.33.55] is it any better via cable card or elsewhere? It appears to be the same low quality on the Xfinity Stream app.