Rare comskip hang

Channels DVR Server
#1

This is another rare issue. Vary occasionally, as in possibly 3 or 4 times since the inception of Channels DVR, comskip will get stuck on some recording and run forever. Comskip usually takes around 5 minutes, but in this case of a stuck processing, comskip will keep going for hours and hours, indefinitely. Subsequent recordings will not be processed until the stuck comskip is killed, which is done by remoting into the NAS, doing a “ps - A | grep comskip”, noting the excessive run time and then doing either a “kill -9 pid” or a “killall comskip”.

I am interested in something like a crontab entry that will check the runtime of comskip and, if greater than 1 hour, kill the process.

#2

If you can catch this happening next time, it would be useful to grab a coredump so I can figure out the hang and fix it.

In the mean time I can probably add a time limit in the DVR.

#3

The next DVR build will have a 30 minute timeout around comskip.

1 Like
#4

Thanks, this will work great

#5

Had this for a few recordings today:

2017/10/25 22:39:43 [WRN] Commercial detection took longer than 30 minutes, aborting…
2017/10/25 22:39:43 [DVR] Commercial detection failed with signal: killed

They’re 30 min HD recordings which my QNAP TS-251+ seems to take a long time to process. A 30 min SD recording takes about 5 mins to process. Should it take a long time for comskip to process an HD recording? If so then maybe the 30 minute timeout is a bit too aggressive.

#6

Can you post the log message shown when the commercial detection started, so I can see how long it took?

I don’t think any recording should ever take 30 minutes to comskip… are all HD recordings failing or just that one did?

#7

Here’s the HD one that was killed:

2017/10/25 22:09:41 [DVR] Processing file-553: TV/Army Behind the New Frontlines/Army Behind the New Frontlines S01E02 2017-10-25 The New Cold War 2017-10-25-2059.mpg
2017/10/25 22:09:43 [DVR] Running commercial detection on file 553 (TV/Army Behind the New Frontlines/Army Behind the New Frontlines S01E02 2017-10-25 The New Cold War 2017-10-25-2059.mpg)

And here’s the SD one:

2017/10/25 22:04:31 [DVR] Processing file-555: TV/Taskmaster/Taskmaster S05E07 2017-10-25 Boing Boing 2017-10-25-2105.mpg
2017/10/25 22:04:31 [DVR] Running commercial detection on file 555 (TV/Taskmaster/Taskmaster S05E07 2017-10-25 Boing Boing 2017-10-25-2105.mpg)
2017/10/25 22:09:41 [DVR] Commercial detection finished with 12 markers.

#8

And all the HD ones are failing now

#9

Hmm that’s surprising. Can you check older logs by visiting http://x.x.x.x:8089/log?n=10000 and see how long they were taking before on HD channels.

I just tested on my TS-251+ here and a 1-hour show took 6 minutes:

2017/10/25 14:50:26 [DVR] Running commercial detection on file 23 (TV/The Voice/The Voice S13E10 2017-10-24 The Battles Part 4 2017-10-24-2000.mpg)
2017/10/25 14:56:10 [DVR] Commercial detection finished with 16 markers.
```
#10

Ah… my recording was in mpeg2, but I think your UK HD channels are all H264. That might be related. I’m definitely very curious to see how long comskip was taking for recordings before according to your logs.

#11

Is n=10000 the furthest back the logs are kept? I’ve been messing about with tuners and updating guides and it’s filled up the logs so I can’t see any of my previous days’ history

#12

You can increase n to a larger number. The entire history of logs is available on disk.

#13

That’s strange, I’m increasing the number but it’s not going back any further

#14

Forget that, I was doing it wrong! Will find some examples now…

#15

Hmm that is strange. The file is located here if you can access it directly:

/share/CACHEDEV1_DATA/.qpkg/ChannelsDVR/channels-dvr/data/channels-dvr.log

#16

Here’s some examples:

2017/10/21 16:54:30 [DVR] Recording for job 1508601270-1 from 12313578 ch104 into “TV/Live Formula 1 Motor Racing/Live Formula 1 Motor Racing United States Grand Prix 3rd Practice 2017-10-21-1654.mpg” for 1h40m29.987995507s
2017/10/21 18:35:01 [DVR] Finished job 1508601270-1 Live: Formula 1 Motor Racing
2017/10/21 18:35:01 [DVR] Processing file-536: TV/Live Formula 1 Motor Racing/Live Formula 1 Motor Racing United States Grand Prix 3rd Practice 2017-10-21-1654.mpg
2017/10/21 18:35:03 [DVR] Running commercial detection on file 536 (TV/Live Formula 1 Motor Racing/Live Formula 1 Motor Racing United States Grand Prix 3rd Practice 2017-10-21-1654.mpg)
2017/10/21 20:59:29 [DVR] Commercial detection finished with 16 markers.

2017/10/21 06:14:30 [DVR] Recording for job 1508562870-41 from 12313578 ch104 into “TV/Mobil 1 The Grid/Mobil 1 The Grid 2017-10-21 2017-10-21-0614.mpg” for 30m29.988316821s
2017/10/21 06:24:03 [NAT] Successfully mapped port 8089 using natpmp
2017/10/21 06:45:00 [TNR] Closed connection to 12313578 for ch104
2017/10/21 06:45:01 [DVR] Finished job 1508562870-41 Mobil 1 The Grid
2017/10/21 06:45:01 [DVR] Waiting 10h9m28.883847819s until next job 1508601270-1 Live: Formula 1 Motor Racing
2017/10/21 06:45:01 [DVR] Processing file-535: TV/Mobil 1 The Grid/Mobil 1 The Grid 2017-10-21 2017-10-21-0614.mpg
2017/10/21 06:45:02 [DVR] Running commercial detection on file 535 (TV/Mobil 1 The Grid/Mobil 1 The Grid 2017-10-21 2017-10-21-0614.mpg)
2017/10/21 07:06:22 [DVR] Commercial detection finished with 6 markers.

2017/10/17 21:59:30 [DVR] Recording for job 1508273970-6 from 12313578 ch102 into “TV/Later Live… with Jools Holland/Later Live… with Jools Holland S51E04 2017-10-17 2017-10-17-2159.mpg” for 35m29.988785227s
2017/10/17 22:35:00 [TNR] Closed connection to 12313578 for ch102
2017/10/17 22:35:01 [DVR] Finished job 1508273970-6 Later Live… with Jools Holland
2017/10/17 22:35:01 [DVR] Processing file-525: TV/Later Live… with Jools Holland/Later Live… with Jools Holland S51E04 2017-10-17 2017-10-17-2159.mpg
2017/10/17 22:35:01 [DVR] Waiting 22h24m28.839135856s until next job 1508356770-12 Taskmaster
2017/10/17 22:35:02 [DVR] Running commercial detection on file 525 (TV/Later Live… with Jools Holland/Later Live… with Jools Holland S51E04 2017-10-17 2017-10-17-2159.mpg)
2017/10/17 22:46:42 [NAT] Successfully mapped port 8089 using natpmp
2017/10/17 23:00:29 [DVR] Commercial detection finished with 4 markers.

#17

Looks like… 2h25m :open_mouth:, 21m and 25m

So the last two would still work. The first one is a 1h40m recording, but it still doesn’t make sense that it took longer than the recording itself to detect commercials.

I’ll do some tests locally with H264 recordings.

#18

Yes I thought that would be a good one to show :smiley:

Look forward to hearing how your tests go.

#19

I am getting some quite long times for comskip to process. I have seen up to 7 or 8 in progress recordings at a time. I only have 3 tuners so the rest are in comskip processing. I will go find some times.

#20

Here are some of my longer ones:

2017/10/20 21:35:30 [DVR] Running commercial detection on file 1412 (TV/The Walking Dead/The Walking Dead S05E13 2015-03-08 Forget 2017-10-20-1900.mpg)
2017/10/20 22:05:45 [DVR] Commercial detection finished with 14 markers.
2017/10/20 22:58:47 [DVR] Running commercial detection on file 1416 (TV/Star Trek The Next Generation/Star Trek The Next Generation S02E08 1989-02-06 A Matter of Honor 2017-10-20-2000.mpg)
2017/10/20 23:25:19 [DVR] Commercial detection finished with 12 markers.
2017/10/20 23:25:20 [DVR] Running commercial detection on file 1415 (TV/The Walking Dead/The Walking Dead S05E14 2015-03-15 Spend 2017-10-20-2000.mpg)
2017/10/20 23:55:37 [DVR] Commercial detection finished with 14 markers.
2017/10/21 02:30:03 [DVR] Running commercial detection on file 1429 (TV/Cake Boss/Cake Boss S04E26 2011-10-03 Transport Troubles  Two Brides 2017-10-21-0200.mpg)
2017/10/21 02:46:35 [DVR] Commercial detection finished with 10 markers.
2017/10/21 04:31:02 [DVR] Running commercial detection on file 1431 (TV/The Walking Dead/The Walking Dead S05E16 2015-03-29 Conquer 2017-10-21-0301.mpg)
2017/10/21 05:14:59 [DVR] Commercial detection finished with 22 markers.

With the recent changes I also now appear to be getting failures:

2017/10/25 19:57:56 [DVR] Running commercial detection on file 1703 (TV/American Pickers/American Pickers S13E23 2015-09-02 CoinOp Kings 2017-10-25-1800.mpg)
2017/10/25 20:27:56 [WRN] Commercial detection took longer than 30 minutes, aborting...
2017/10/25 20:27:56 [DVR] Commercial detection failed with signal: killed

I had been assuming this was because of my CPU which is one of the reasons I was asking about hardware recently. Here is how my CPU is identified by channels:

4 cores / Intel(R) Atom(TM) CPU C2538 @ 2.40GHz
load averages:  1.10  1.14  1.26

Here is how channels identifies the recording that failed comskip above:

Track #0: H.264 / AVC / MPEG-4 AVC / MPEG-4 part 10
1280x720   16:9   yuv420p   progressive

Track #1: ATSC A/52A (AC-3)
5.1(side)   eng   384kbps

Track #2: ATSC A/52A (AC-3)
stereo   spa   192kbps
1 Like