[DetectAds] Announcing DetectAds version 2

Hi again
Ok I have installed the package but am having an issue with it. I have recorded some episodes of Come Dine with Me on CH4 HD which have resulted in 'crop-done' files between 2 to 6 mins when the program was actually 30mins long including advert breaks.
Am I missing something?
My detect ads log shows some failures:


21/09/2015 03:40:12 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
227 21/09/2015 03:40:12 NS(4076)-
226 21/09/2015 03:40:12 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
225 21/09/2015 03:40:12 NS(4076)-
224 21/09/2015 03:40:12 DA(4076)- ad break found 26:00-28:23 (1560 - 1703) Frames: 39002 - 42577
223 21/09/2015 03:36:10 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
222 21/09/2015 03:36:10 NS(4076)-
221 21/09/2015 03:33:46 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
220 21/09/2015 03:33:46 NS(4076)-
219 21/09/2015 03:30:45 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
218 21/09/2015 03:30:45 NS(4076)-
217 21/09/2015 03:28:18 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
216 21/09/2015 03:28:18 NS(4076)-
215 21/09/2015 03:28:18 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
214 21/09/2015 03:28:18 NS(4076)-
213 21/09/2015 03:28:18 DA(4076)- ad break found 12:15-14:27 (735 - 867) Frames: 18370 - 21679
212 21/09/2015 03:22:48 NS(4076)- Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
211 21/09/2015 03:22:48 NS(4076)- -+++++++
210 21/09/2015 03:17:14 DA(4076)- ad break found 0:00-0:08 (0 - 8) Frames: 1 - 212
209 21/09/2015 03:16:33 NS(4076)- progLen = 0s, 0 bookmarks, HD = 1
208 21/09/2015 03:11:46 DA(2960)- done...processed /media/My Video/Come Dine with Me Abroad/Come Dine with Me_20150921_0243.ts in 1421.873s 00:23:42 - 3 ad breaks detected
207 21/09/2015 03:11:46 DA(2960)- /media/My Video/Come Dine with Me Abroad/Come Dine with Me_20150921_0243-dec.ts deleted
206 21/09/2015 03:11:38 NS(2960)- New Program Length = 402s
205 21/09/2015 03:11:38 NS(2960)- Wrote 14124 entries to /media/My Video/Come Dine with Me Abroad/Come Dine with Me_20150921_0243-crop. Stripped 100918 packets (18922k) of EPG data
204 2

Any help welcome.

mesaboogieman
 
You should use the bookmarks option without cropping until you get confident that the result will be what you want. Bookmarking is non-destructive, and you can then skip adverts by skipping to the next bookmark.
 
mesaboogieman,

I am afraid I don't have any quick answers
When pasting examples of log in the future it is best to include them within code tags (from the insert icon on the post toolbar)

The messages
Code: 
Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
are on my todo list to remove but are normally innocuous.
In your sample log you have the end of one program (pid 2960) and part of the log for the next (pid 4076).

Could you try setting the logging level to highest via General Setting and posting the log for an entire program, or if it simpler for you, send me the entire log file in a Private message (Conversation)

As BlackHole suggests if you turn off the "Dustbin/delete original recording after processing?" setting you will at least have the bookmarked original recording to fall back on should you have further cropping problems.

I will try setting up a HD recording of Come Dine to see if I can recreate the issue.

Edit: Thinking about it I think I know what has happened, but not why it has has started happening or why it is causing a message loop, extra logging will not help diagnose the issue.
 
Last edited:
MymsMan said:
mesaboogieman,

I am afraid I don't have any quick answers
When pasting examples of log in the future it is best to include them within code tags (from the insert icon on the post toolbar)

The messages
Code: 
Read failure/EOF within frame 12972, chunk 0, frameSize 1, towrite 103, skipping rest of file
are on my todo list to remove but are normally innocuous.
In your sample log you have the end of one program (pid 2960) and part of the log for the next (pid 4076).

Could you try setting the logging level to highest via General Setting and posting the log for an entire program, or if it simpler for you, send me the entire log file in a Private message (Conversation)

As BlackHole suggests if you turn off the "Dustbin/delete original recording after processing?" setting you will at least have the bookmarked original recording to fall back on should you have further cropping problems.

I will try setting up a HD recording of Come Dine to see if I can recreate the issue.
Click to expand...

I had a similar experience with recording the Rugby yesterday, with only the FIRST match being recorded properly, 1/2 the 2nd, and 2-6 minutes of the rest.
Detectads log had something similar to mesaboogieman above - lots of 'skipping rest of file' messages.

This was the first time I used detectads (I'd just updated to the latest version, set up to: chase-run, crop & delete original (optimist that I am :))), so I have no other input here,
but I was wondering this might be due to these being back-to-back events on the ITV channels, and this causing issues with the tracking of 'what's playing, what's processing and what's recording' as the events followed each other?

Quality of that first recording was rubbish though, lots of pixellation, image 1/2 & 1/2 & jumps, so it may just have been the transmission being bad all day -

O
 
I have found on a couple of my recordings on ITV that there have been two bookmarks inserted very close together at the start of some of the ads and another at the end of the ads. So there's three, instead of two to mark the ads. To overcome this and to prevent the possibility of cropping the wrong stuff, (I don't have autocrop set) how about having a 'time delay' of (say) 1 minute before detectads can insert the next one?

I haven't established 100% which one is the correct one, but my feeling is that it's the first. Also I haven't extensively thought through all the other possible consequences of doing the delay idea. Next time it happens, I'll have a good check out of which one's correct and see if I can see a possible reason for the insertion of the second so close to the first. Oh well, let's set a bunch of ITV stuff to record.
 
OwenMc said:
I had a similar experience with recording the Rugby yesterday, with only the FIRST match being recorded properly, 1/2 the 2nd, and 2-6 minutes of the rest.
Detectads log had something similar to mesaboogieman above - lots of 'skipping rest of file' messages.

This was the first time I used detectads (I'd just updated to the latest version, set up to: chase-run, crop & delete original (optimist that I am :))), so I have no other input here,
but I was wondering this might be due to these being back-to-back events on the ITV channels, and this causing issues with the tracking of 'what's playing, what's processing and what's recording' as the events followed each other?

Quality of that first recording was rubbish though, lots of pixellation, image 1/2 & 1/2 & jumps, so it may just have been the transmission being bad all day -

O
Click to expand...
Do you have the originals in the Dustbin? I would not recommend Deleting original unless you have some back up.
If you do have the originals do they show the pixellation and image jumps at the same points as in the cropped recordings?

The read failure messages could possibly result in image problems.

The underlying issue is that the frame count calculated by ffmpeg/silence can, for reasons unknown, differ up to 50 frames (+ or -) from that recorded by the Humax in the nts meaning that in the pipeline nicesplice sometimes reaches eof unexpectedly.

Back to back or simultaneous recordings shouldn't cause problems.
 
Trev said:
I have found on a couple of my recordings on ITV that there have been two bookmarks inserted very close together at the start of some of the ads and another at the end of the ads. So there's three, instead of two to mark the ads. To overcome this and to prevent the possibility of cropping the wrong stuff, (I don't have autocrop set) how about having a 'time delay' of (say) 1 minute before detectads can insert the next one?

I haven't established 100% which one is the correct one, but my feeling is that it's the first. Also I haven't extensively thought through all the other possible consequences of doing the delay idea. Next time it happens, I'll have a good check out of which one's correct and see if I can see a possible reason for the insertion of the second so close to the first. Oh well, let's set a bunch of ITV stuff to record.
Click to expand...
I am not sure how 3 bookmarks could occur for a single ad break - do you have arbookmarks or anything else that could be inserting BookMarks
DetectAds finds clusters of silences so one close the start of an ad break would be considered as part of the break and not introduce another bookmark
Can you post the logfile for one of the programs with extra bookmarks.
 
I have deleted the last one I had. I have set 4 or 5 progs to record from commercial TV this evening so will report back when this is done and checked.
But in the meantime, I have BBC* set in Excluded but have the following entry in the detectads log
Code: 
20/09/2015 18:35:35 DA(1533)- done...processed /media/My Video/Formula 1_ The Australian Grand Prix___/Formula 1_ Singapore Grand Prix -____20150920_1700.ts in 5431.659s 01:30:32 - 2 ad breaks detected
A. Why did it process it?
And
B. Why did it find ads?

I still have this one in my deleted items, but HWMBO has commandeered the TV for the evening (soaps). I'll have a look at it later.
 
Trev said:
I have deleted the last one I had. I have set 4 or 5 progs to record from commercial TV this evening so will report back when this is done and checked.
But in the meantime, I have BBC* set in Excluded but have the following entry in the detectads log
Code: 
20/09/2015 18:35:35 DA(1533)- done...processed /media/My Video/Formula 1_ The Australian Grand Prix___/Formula 1_ Singapore Grand Prix -____20150920_1700.ts in 5431.659s 01:30:32 - 2 ad breaks detected
A. Why did it process it?
And
B. Why did it find ads?

I still have this one in my deleted items, but HWMBO has commandeered the TV for the evening (soaps). I'll have a look at it later.
Click to expand...
A. Have you got any DetectAds Sweeper rules? Are there any references to it being queued for detectads in the Auto log?
B Detectads can find the lead-in and trailer messages on BBC programs but overhead of processing outweighs the minimal benefits which is why they are on the exclusion list
 
I think the point was that, if BBC is excluded from processing, why was this example of a BBC recording processed?
 
Correct BH.
What further info do you want Myms? BBC* is in my exclude list, but the GP was processed by detect ads. Why?
I had the qualifying and the race recorded. Looking at the files in the deleted items (I'd binned them from Media), one of each pair has no bookmarks. but the other processed pair has a bookmark at the start and at the end.

The 4 recordings I made this evening all bookmarked the ads correctly.
Emmerdale, one of the 4, (just as a test you realise) had two recordings in the media list, one was a 'raw' recording and the other has 'Decrypt -Len err' in its title, but is the same size as the 'raw recording (1.02GiB)
Ch4 News, Food Unwrapped and Britain as seen on TV were all bookmarked OK and the originals are in the 'bin' as expected.

I had no 'double bookmarks' as reported earlier.
Here's the relevant part of tonight's log.
Code: 
18 21/09/2015 20:02:25 RM(5296)- DETECTADS: Checking /media/My Video/New_ Britain As Seen on ITV_20150921_2002.ts (ITV HD) for channel exclusion
17 21/09/2015 19:59:34 DA(2729)- done...processed /media/My Video/Channel 4 News_20150921_1859.ts in 3274.334s 00:54:34 - 4 ad breaks detected
16 21/09/2015 19:59:34 DA(2729)- /media/My Video/Channel 4 News_20150921_1859.ts deleted
15 21/09/2015 19:59:32 DA(2729)- ad break found 57:26-58:57 (3446 - 3537) Frames: 86144 - 88426
14 21/09/2015 19:52:34 DA(2729)- ad break found 48:37-50:38 (2917 - 3038) Frames: 72934 - 75947
13 21/09/2015 19:42:55 DA(2729)- ad break found 38:15-40:45 (2295 - 2445) Frames: 57364 - 61128
12 21/09/2015 19:31:21 DA(2710)- done...processed /media/My Video/Emmerdale_20150921_1859.ts in 1626.965s 00:27:07 - 3 ad breaks detected
11 21/09/2015 19:31:21 DA(2710)- Incomplete data retrieval -14 bytes missing
10 21/09/2015 19:31:20 DA(2710)- ad break found 27:37-31:45 (1657 - 1905) Frames: 41421 - 47616
9 21/09/2015 19:18:37 DA(2710)- ad break found 13:26-17:31 (806 - 1051) Frames: 20159 - 26268
8 21/09/2015 19:06:39 DA(2729)- ad break found 0:00-0:06 (0 - 6) Frames: 1 - 162
7 21/09/2015 19:04:50 DA(2710)- ad break found 0:00-0:18 (0 - 18) Frames: 1 - 458
6 21/09/2015 18:59:59 DA(2729)- ==DETECTADS Chase Run: /media/My Video/Channel 4 News_20150921_1859.ts
5 21/09/2015 18:59:59 RM(2727)- DETECTADS: Started /media/My Video/Channel 4 News_20150921_1859.ts for chaserun advert detection
4 21/09/2015 18:59:59 RM(2727)- DETECTADS: Checking /media/My Video/Channel 4 News_20150921_1859.ts (Channel 4 HD) for channel exclusion
3 21/09/2015 18:59:15 DA(2710)- ==DETECTADS Chase Run: /media/My Video/Emmerdale_20150921_1859.ts
2 21/09/2015 18:59:15 RM(2704)- DETECTADS: Started /media/My Video/Emmerdale_20150921_1859.ts for chaserun advert detection
1 21/09/2015 18:59:15 RM(2704)- DETECTADS: Checking /media/My Video/Emmerdale_20150921_1859.ts (ITV HD) for channel exclusion
Just realised, I should have recorded ome BBC stuff for completeness. I'll do that tomorrow AM.
 
The Len Err is because the Emmerdale recording is 14 bytes too long
Code: 
Incomplete data retrieval -14 bytes missing
Hardly significant in 1.2Gib but whilst it is likely to be in the last few seconds I have no way of knowing for certain or how much data is actually different between the two versions of the file - I suspect it is due to the Humax starting DLNA indexing of the recording. I prefer to report errors rather than assume there will be no problems during playback

Are all BBC recordings being ad-detected or was the grand prix unique?

I think I have discovered the BBC problem - the default configuration file has DOS line ends rather than UNIX - I thought I had cleaned all the files up but obviously missed one :)
Have you edited the config files using the settings page or a text editor? I think if you make a dummy change via the settings page and save it it should have the correct line endings and work correctly.

For the extra bookmarks when you say "I have deleted the last one I had." do you mean the recordings or the log files? It is the log files that will hopefully have the interesting information - though it might need a high logging level to reveal what is happening.
 
Thanks for the reply Myms.
MymsMan said:
The Len Err is because the Emmerdale recording is 14 bytes too long
Code: 
Incomplete data retrieval -14 bytes missing
Hardly significant in 1.2Gib but whilst it is likely to be in the last few seconds I have no way of knowing for certain or how much data is actually different between the two versions of the file - I suspect it is due to the Humax starting DLNA indexing of the recording. I prefer to report errors rather than assume there will be no problems during playback
Click to expand...
I did notice the 'insignificant bytes missing, but just wanted to report it as it leaves two copies of the recording in 'Media List'
Are all BBC recordings being ad-detected or was the grand prix unique?
Click to expand...
Don't know, going to try some more BBC this morning, but see below
I think I have discovered the BBC problem - the default configuration file has DOS line ends rather than UNIX - I thought I had cleaned all the files up but obviously missed one :)
Click to expand...
I'll wait for the update then, maybe.
Have you edited the config files using the settings page or a text editor?
Click to expand...
No, or I would have said so
I think if you make a dummy change via the settings page and save it it should have the correct line endings and work correctly.
Click to expand...
I'll try that in a bit and report back.
EDIT 09:25 Set Dustbin to NO, Save, Set Dustbin to YES, Save. I'll see if that works after current recordings have finished.
For the extra bookmarks when you say "I have deleted the last one I had." do you mean the recordings or the log files?
Click to expand...
Both
It is the log files that will hopefully have the interesting information - though it might need a high logging level to reveal what is happening.
Click to expand...
How do you do that?

EDIT 10:20
As I write, it is processing Homes Under the Hammer. There are two recordings in the Media list, one with -dec appended and the log shows this;
Code: 
36 22/09/2015 10:00:17 DA(2234)- ==DETECTADS Chase Run: /media/My Video/Homes Under the Hammer_20150922_1000.ts
35 22/09/2015 10:00:17 RM(2225)- DETECTADS: Started /media/My Video/Homes Under the Hammer_20150922_1000.ts for chaserun advert detection
34 22/09/2015 10:00:17 RM(2225)- DETECTADS: Checking /media/My Video/Homes Under the Hammer_20150922_1000.ts (BBC ONE HD) for channel exclusion
Edit 11:50Homes under the Hammer finished. Only one in CF Media List not marked Decrypt done, non in the bin. Two in SUI, one marked Decrypt done which has two bookmarks right at the end. Why the difference between CF Media list and SUI Media List? Getting more confused by the minute.
Recording BBC news now. Not showing in CF Media list, but there is one in the bin.
Code: 
56 22/09/2015 12:00:41 DA(4760)- done...processed /media/My Video/BBC News_20150922_1100.ts in 3330.312s 00:55:30 - 0 ad breaks detected
55 22/09/2015 12:00:41 DA(4760)- /media/My Video/BBC News_20150922_1100.ts deleted
54 22/09/2015 12:00:04 DA(6238)- done...processed /media/My Video/BBC World News_20150922_1129.ts in 1519.581s 00:25:20 - 2 ad breaks detected
53 22/09/2015 12:00:04 DA(6238)- Incomplete data retrieval -14 bytes missing
52 22/09/2015 12:00:03 DA(6238)- ad break found 27:02-29:56 (1622 - 1796) Frames: 40559 - 44906
51 22/09/2015 11:35:38 DA(6238)- ad break found 0:00-0:20 (0 - 20) Frames: 1 - 491
50 22/09/2015 11:30:03 DA(4721)- done...processed /media/My Video/BBC News_20150922_1059.ts in 1517.903s 00:25:18 - 0 ad breaks detected
49 22/09/2015 11:30:03 DA(4721)- /media/My Video/BBC News_20150922_1059.ts deleted
48 22/09/2015 11:29:48 DA(6238)- ==DETECTADS Chase Run: /media/My Video/BBC World News_20150922_1129.ts
47 22/09/2015 11:29:47 RM(6232)- DETECTADS: Started /media/My Video/BBC World News_20150922_1129.ts for chaserun advert detection
46 22/09/2015 11:29:47 RM(6232)- DETECTADS: Checking /media/My Video/BBC World News_20150922_1129.ts (BBC TWO HD) for channel exclusion
45 22/09/2015 11:00:10 DA(4760)- ==DETECTADS Chase Run: /media/My Video/BBC News_20150922_1100.ts
44 22/09/2015 11:00:10 RM(4757)- DETECTADS: Started /media/My Video/BBC News_20150922_1100.ts for chaserun advert detection
43 22/09/2015 11:00:10 RM(4757)- DETECTADS: Checking /media/My Video/BBC News_20150922_1100.ts (BBC NEWS) for channel exclusion
42 22/09/2015 10:59:50 DA(4721)- ==DETECTADS Chase Run: /media/My Video/BBC News_20150922_1059.ts
41 22/09/2015 10:59:50 RM(4717)- DETECTADS: Started /media/My Video/BBC News_20150922_1059.ts for chaserun advert detection
40 22/09/2015 10:59:50 RM(4717)- DETECTADS: Checking /media/My Video/BBC News_20150922_1059.ts (BBC TWO HD) for channel exclusion
39 22/09/2015 10:59:33 DA(2234)- done...processed /media/My Video/Homes Under the Hammer_20150922_1000.ts in 3257.056s 00:54:17 - 1 ad breaks detected
38 22/09/2015 10:59:33 DA(2234)- Incomplete data retrieval -14 bytes missing
37 22/09/2015 10:59:32 DA(2234)- ad break found 57:28-57:58 (3448 - 3478) Frames: 86206 - 86950
36 22/09/2015 10:00:17 DA(2234)- ==DETECTADS Chase Run: /media/My Video/Homes Under the Hammer_20150922_1000.ts
35 22/09/2015 10:00:17 RM(2225)- DETECTADS: Started /media/My Video/Homes Under the Hammer_20150922_1000.ts for chaserun advert detection
34 22/09/2015 10:00:17 RM(2225)- DETECTADS: Checking /media/My Video/Homes Under the Hammer_20150922_1000.ts (BBC ONE HD) for channel exclusion
Seems like the missing 14 bytes is a fairly common happening leaving two copies in SUI Media list.
I'm beginning to think "Is this worth the hassle with multiple copies of the same thing kicking around but not sure where when all I have to do is press 'Skip' twice on the ads anyway"

Still the same question: Why is it processing the BBC channels anyway?
 
Last edited:
MymsMan said:
Do you have the originals in the Dustbin? I would not recommend Deleting original unless you have some back up.
If you do have the originals do they show the pixellation and image jumps at the same points as in the cropped recordings?

The read failure messages could possibly result in image problems.

The underlying issue is that the frame count calculated by ffmpeg/silence can, for reasons unknown, differ up to 50 frames (+ or -) from that recorded by the Humax in the nts meaning that in the pipeline nicesplice sometimes reaches eof unexpectedly.

Back to back or simultaneous recordings shouldn't cause problems.
Click to expand...

Unfortunately no, I don't have the originals - I wasn't using the 'undelete' package (I am now!)

Manual crops all seem to work OK, and the detectads log didn't have any more of those 'skip' entries.

I'll keep an eye on the recordings for the rest of the week and see how it goes.
 
Test recordings:
This morning I recorded:
BBC World News C2 BBC2HD @11:29 30min
BBC News Ch130 BBC News @11:00 60min
BBC News Ch2 BBC2HD @10:59 30min
Homes Under the Hammer Ch1 BBCHD @ 10:00 60min

My SUI Media list contains: (only the relevent ones)
BBC World News Decrypt Len err 11:29 30min 2 BBCHD HD
BBC World News 11:29 30min 2 BBC HD HD Enc
BBC News Decrypt Done 11:00 60min 130 BBC News (No flags)
BBC News Decrypt Done 10:59 30min 2 BBC2HD HD
Homes Under the Hammer 10:00 59min 1 BBC1HD HD Enc
Homes Under the Hammer Decrypt - Len err 10:00 58min 1 BBC1HD HD

My SUI Deleted Items contains (only the relevent ones):
BBC News 11:00 60min 130 BBC News (no flags)
BBC News 10:59 30min 2 BBC2HD HD Enc
Ch130 BBC News @11:00 60min

My CF Media list contains:
Homes Under the Hammer 22-09-15 1000.ts (1.88 GiB)
No other news programmes
My CF Deleted Item folder contains:
BBC News_20150922_1059.ts (1.23 GiB)
No other relevent programmes

Lists posted to illustrate the problems that seem to be associated with detectads. For the fact that the CF and SUI Media lists are different, I have also posted these lists HERE.
So please post comments about the differences between CF and SUI there, not here.
 
I have just uploaded 0.2.1-2 to package catalogue

  • It should fix the problem with BBC programs being selected for ad- detection
  • I have not been able to recreate the problem with very short programmes after cropping or spot any bugs so I have put some more diagnostics in place in the hope of finding some clues

If anyone experiences significantly too short programs after cropping could they please:
  1. Report the problem here, or via private conversation, with all available log data from detectads.log
  2. Turn on debugging level, using General Settings
  3. Rerun ad-detection on the original, undecrypted, input file using Run Analysis in Background from Browse->Detectads
  4. Is problem reproducible? Post log data from the rerun.
  5. Keep the input file - I may need to ask for help with testing any fixes.

Edit: I have now been able to recreate the problem and it is reproducible so I can start to debug the issue and hopefully find a fix soon.
 
Last edited:
Have you sorted the problem when one is 14 bytes shorter? OK so it's a different length, but leaves a lot of 'debris' hanging around.
I'll have another go at recording BBC and ITV in a bit and see what happens (after update of course)
 
Trev said:
Have you sorted the problem when one is 14 bytes shorter? OK so it's a different length, but leaves a lot of 'debris' hanging around.
I'll have another go at recording BBC and ITV in a bit and see what happens (after update of course)
Click to expand...

Not yet - it will form part of the retaining original file names/titles changes,

My current thinking is that I will just throw away the decrypted output if there is a length error and let Auto-decrypt process the file later, (throwing away output on length error is what auto decrypt does - the Humax eventually gets it right).. The decrypted file is only a by-product from DetectAds.

If the length error is significant (> 1 minute worth of recording) it might have affected ad-detection so I could automatically put the recording on the queue to give DetectAds another chance.
 
You must log in or register to reply here.
Back
Top