Job ends prematurely error

Some recordings get this error for some time now and do not process commercial detection. The recorded show plays back in full without commercial detection. I have 30 seconds padded to the end of each recording. Here’s some of the log from tonight showing the errors…

2018/01/10 18:59:59 [DVR] Waiting 742.7067ms until next job 1515632400-8 The Goldbergs
2018/01/10 19:00:00 [DVR] Starting job 1515632400-8 The Goldbergs on ch=[30.1]
2018/01/10 19:00:00 [DVR] Waiting 29m59.9557267s until next job 1515634200-19 Speechless
2018/01/10 19:00:00 [TNR] Opened connection to 1046A019 for ch30.1
2018/01/10 19:00:01 [DVR] Recording for job 1515632400-8 from 1046A019 ch30.1 into “TV\The Goldbergs\The Goldbergs S05E12 2018-01-10 Dinner With the Goldbergs 2018-01-10-1900.mpg” for 30m29.9557267s
2018/01/10 19:29:59 [DVR] Waiting 49.8143ms until next job 1515634200-19 Speechless
2018/01/10 19:30:00 [DVR] Starting job 1515634200-19 Speechless on ch=[30.1]
2018/01/10 19:30:00 [DVR] Waiting 30m59.9808143s until next job 1515636060-13 Modern Family
2018/01/10 19:30:00 [TNR] Sharing existing connection to 1046A019 for ch30.1 (clients=2, len=0)
2018/01/10 19:30:00 [DVR] Recording for job 1515634200-19 from 1046A019 ch30.1 into “TV\Speechless\Speechless S02E12 2018-01-10 THE HUS HUSTLE 2018-01-10-1930.mpg” for 31m29.9808143s
2018/01/10 19:30:30 [DVR] Finished job 1515632400-8 The Goldbergs
2018/01/10 19:30:30 [DVR] Waiting 30m29.7713709s until next job 1515636060-13 Modern Family
2018/01/10 19:30:30 [DVR] Processing file-2419: TV\The Goldbergs\The Goldbergs S05E12 2018-01-10 Dinner With the Goldbergs 2018-01-10-1900.mpg
2018/01/10 19:30:30 [DVR] Running commercial detection on file 2419 (TV\The Goldbergs\The Goldbergs S05E12 2018-01-10 Dinner With the Goldbergs 2018-01-10-1900.mpg)
2018/01/10 19:35:52 [DVR] Commercial detection finished with 6 markers.
2018/01/10 20:00:59 [DVR] Waiting 7.5793ms until next job 1515636060-13 Modern Family
2018/01/10 20:01:00 [DVR] Starting job 1515636060-13 Modern Family on ch=[30.1]
2018/01/10 20:01:00 [TNR] Sharing existing connection to 1046A019 for ch30.1 (clients=2, len=0)
2018/01/10 20:01:00 [DVR] Starting job 1515636060-53 SEAL Team on ch=[4.1]
2018/01/10 20:01:00 [DVR] Waiting 29m59.9845793s until next job 1515637860-2 American Housewife
2018/01/10 20:01:00 [DVR] Recording for job 1515636060-13 from 1046A019 ch30.1 into “TV\Modern Family\Modern Family S09E12 2018-01-10 Dear Beloved Family 2018-01-10-2001.mpg” for 30m29.9845793s
2018/01/10 20:01:00 [TNR] Opened connection to 1046A019 for ch4.1
2018/01/10 20:01:00 [DVR] Recording for job 1515636060-53 from 1046A019 ch4.1 into “TV\SEAL Team\SEAL Team S01E11 2018-01-10 Containment 2018-01-10-2001.mpg” for 59m29.9845793s
2018/01/10 20:01:29 [DVR] Job 1515634200-19 Speechless ended prematurely: 33.1149ms
2018/01/10 20:30:59 [DVR] Deleting expired job 1515634200-19 Speechless
2018/01/10 20:30:59 [DVR] Waiting 13.0365ms until next job 1515637860-2 American Housewife
2018/01/10 20:31:00 [DVR] Starting job 1515637860-2 American Housewife on ch=[30.1]
2018/01/10 20:31:00 [DVR] Waiting 1h28m59.9810365s until next job 1515643200-28 News 4 at 10pm
2018/01/10 20:31:00 [TNR] Sharing existing connection to 1046A019 for ch30.1 (clients=2, len=0)
2018/01/10 20:31:00 [DVR] Recording for job 1515637860-2 from 1046A019 ch30.1 into “TV\American Housewife\American Housewife S02E12 2018-01-10 Selling Out 2018-01-10-2031.mpg” for 29m29.9810365s
2018/01/10 20:31:29 [DVR] Job 1515636060-13 Modern Family ended prematurely: 34.5761ms
2018/01/10 21:00:29 [TNR] Closed connection to 1046A019 for ch30.1
2018/01/10 21:00:29 [DVR] Job 1515637860-2 American Housewife ended prematurely: 35.1457ms
2018/01/10 21:00:30 [TNR] Closed connection to 1046A019 for ch4.1
2018/01/10 21:00:30 [DVR] Finished job 1515636060-53 SEAL Team
2018/01/10 21:00:30 [DVR] Deleting expired job 1515636060-13 Modern Family
2018/01/10 21:00:30 [DVR] Deleting expired job 1515637860-2 American Housewife
2018/01/10 21:00:30 [DVR] Waiting 59m29.777549s until next job 1515643200-28 News 4 at 10pm
2018/01/10 21:00:30 [DVR] Processing file-2423: TV\American Housewife\American Housewife S02E12 2018-01-10 Selling Out 2018-01-10-2031.mpg
2018/01/10 21:00:30 [DVR] Running commercial detection on file 2423 (TV\American Housewife\American Housewife S02E12 2018-01-10 Selling Out 2018-01-10-2031.mpg)
2018/01/10 21:05:43 [DVR] Commercial detection finished with 8 markers.
2018/01/10 21:05:44 [DVR] Processing file-2422: TV\SEAL Team\SEAL Team S01E11 2018-01-10 Containment 2018-01-10-2001.mpg
2018/01/10 21:05:44 [DVR] Running commercial detection on file 2422 (TV\SEAL Team\SEAL Team S01E11 2018-01-10 Containment 2018-01-10-2001.mpg)

Thanks for the log entries. There’s some sort of bug that triggers this on windows. What version of windows are you on?

The DVR should still process commercials but it’s getting delayed. I will work on a fix.

Windows Home Server 2011. I couldn’t tell you exactly when this started except to say it used to not do this. It does seem to eventually process the commercials but the results are awful. Normally com skip works pretty accurate but under this scenario it only puts 2 or 3 very small commercial segments.

Made any headway on this?

Thanks for the reminder.

I’ve uploaded a test build with a fix. Open powershell and run this command to upgrade to it:

iwr -usebasicparsing -Method put http://127.0.0.1:8089/updater/check/2018.03.07.2242

Thanks. Just loaded it. I have 5 shows all back to back and one concurrent tonight so I should be able to tell if it fixes it. How about this one?..

The job ends prematurely bug is still present.

What is the bug?

I know that the log prints “ended prematurely” sometimes, but it should still run commercial detection right after it finishes.

Commercial Detection does not run when the show is finished. It finally run at some point but not right after it finishes. I’m watching three shows in a row that started at 7PM and the first one has commercial detection and the last two do not. Normally takes about 5 minutes to complete and the current show I’m watching (Blackish) was finished recording an hour ago. See below…

2018/03/20 19:00:00 [DVR] Starting job 1521590400-25 The Middle on ch=[30.1]
2018/03/20 19:00:00 [DVR] Waiting 29m59.9711256s until next job 1521592200-7 Fresh Off the Boat
2018/03/20 19:00:00 [ERR] Failed to start stream on channel 30.1 via 1046A019: got HDHR error: 805 All Tuners In Use
2018/03/20 19:00:00 [TNR] Opened connection to 1046EF10 for ch30.1
2018/03/20 19:00:08 [DVR] Recording for job 1521590400-25 from 1046EF10 ch30.1 into “TV\The Middle\The Middle S09E17 2018-03-20 Hecks vs Glossners The Final Battle 2018-03-20-1900.mpg” for 30m29.9711256s
2018/03/20 19:29:59 [DVR] Waiting 37.5796ms until next job 1521592200-7 Fresh Off the Boat
2018/03/20 19:30:00 [DVR] Starting job 1521592200-7 Fresh Off the Boat on ch=[30.1]
2018/03/20 19:30:00 [DVR] Waiting 29m59.9865796s until next job 1521594000-3 blackish
2018/03/20 19:30:00 [TNR] Sharing existing connection to 1046A019 for ch30.1 (clients=2, len=0)
2018/03/20 19:30:00 [DVR] Recording for job 1521592200-7 from 1046A019 ch30.1 into “TV\Fresh Off the Boat\Fresh Off the Boat S04E19 2018-03-20 King in the North 2018-03-20-1930.mpg” for 30m29.9865796s
2018/03/20 19:30:30 [DVR] Finished job 1521590400-25 The Middle
2018/03/20 19:30:30 [DVR] Waiting 29m29.8271091s until next job 1521594000-3 blackish
2018/03/20 19:30:30 [DVR] Processing file-2815: TV\The Middle\The Middle S09E17 2018-03-20 Hecks vs Glossners The Final Battle 2018-03-20-1900.mpg
2018/03/20 19:30:30 [DVR] Running commercial detection on file 2815 (TV\The Middle\The Middle S09E17 2018-03-20 Hecks vs Glossners The Final Battle 2018-03-20-1900.mpg)
2018/03/20 19:33:47 [DVR] Commercial detection finished with 10 markers.
2018/03/20 19:59:59 [DVR] Waiting 23.6995ms until next job 1521594000-3 blackish
2018/03/20 20:00:00 [DVR] Starting job 1521594000-3 blackish on ch=[30.1]
2018/03/20 20:00:00 [DVR] Waiting 1h59m59.9866995s until next job 1521601200-28 News 4 at 10pm
2018/03/20 20:00:00 [TNR] Sharing existing connection to 1046A019 for ch30.1 (clients=2, len=0)
2018/03/20 20:00:00 [DVR] Recording for job 1521594000-3 from 1046A019 ch30.1 into “TV\blackish\blackish S04E16 2018-03-20 Things Were Different Then 2018-03-20-2000.mpg” for 30m29.9866995s
2018/03/20 20:00:29 [DVR] Job 1521592200-7 Fresh Off the Boat ended prematurely: 35.226ms
2018/03/20 20:30:29 [TNR] Closed connection to 1046EF10 for ch30.1
2018/03/20 20:30:29 [DVR] Job 1521594000-3 blackish ended prematurely: 31.9458ms

Gotcha, thanks for the details. I confirmed that my previous fix was not sufficient. I’m building a new pre-release and will let you know when it’s ready.

New build is ready. Use shift + check for updates.

Still happening. A recording from 5:30AM this morning (17.5 hours ago) ended prematurely and commercial detection has still not started. But this error occurred. possibly another issue?

2018/03/23 06:00:29 [DVR] Job 1521801000-61 Diff’rent Strokes ended prematurely: 42.2618ms
2018/03/23 06:00:29 [DVR] Waiting 59m30.0032618s until next job 1521806400-20 Today
2018/03/23 06:00:30 [DVR] Processing file-2838: TV\Diff’rent Strokes\Diff’rent Strokes S04E07 1981-12-10 The Ski Weekend 2018-03-23-0530.mpg
2018/03/23 06:00:30 [DVR] Running commercial detection on file 2838 (TV\Diff’rent Strokes\Diff’rent Strokes S04E07 1981-12-10 The Ski Weekend 2018-03-23-0530.mpg)
2018/03/23 06:01:55 [DVR] Commercial detection failed with exit status 1

Looks like it ran right away but failed for some reasonz

Can you open http://127.0.0.1:8089/dvr/files/2838/comskip.log and file>save to email to [email protected]

Done

1 Like

This appears to be fixed. I have not had the issue this week while watching shows soon after they were recorded.

1 Like

Spoke too soon. Same issue tonight.

Please send recent logs. The DVR definitely runs comskip right after the recording now, so perhaps comskip is failing or there are several shows queued up to run commercial detection.