Comskip crashing while processing live recordings

[btracy]

I recently switched to the latest version of comskip to allow scanning on active recordings and have run into what is likely the same crashing occurring here: (viewtopic.php?f=5&t=1243). I get the same access violation but I wanted to distinguish that copy protected channels are never scanned in my setup. I can reproduce this pretty much at will. I did a test where I recorded 3 shows at once and 2 of the 3 crashed:

Crash 1:
Faulting application name: comskip.exe, version: 0.0.0.0, time stamp: 0x4fb8bf71
Faulting module name: comskip.exe, version: 0.0.0.0, time stamp: 0x4fb8bf71
Exception code: 0xc0000005
Fault offset: 0x000dbbf5
Faulting process id: 0x2460
Faulting application start time: 0x01cd4fbe2146b241
Faulting application path: C:\Program Files (x86)\DVRMSToolbox\Applications\comskip.exe
Faulting module path: C:\Program Files (x86)\DVRMSToolbox\Applications\comskip.exe
Report Id: a18e4b25-bbb1-11e1-b479-6cf049726406

Crash 2:
Faulting application name: comskip.exe, version: 0.0.0.0, time stamp: 0x4fb8bf71
Faulting module name: comskip.exe, version: 0.0.0.0, time stamp: 0x4fb8bf71
Exception code: 0xc0000005
Fault offset: 0x000dbbf5
Faulting process id: 0x2938
Faulting application start time: 0x01cd4fbe8cd90b8b
Faulting application path: C:\Program Files (x86)\DVRMSToolbox\Applications\comskip.exe
Faulting module path: C:\Program Files (x86)\DVRMSToolbox\Applications\comskip.exe
Report Id: 0ff68b60-bbb2-11e1-b479-6cf049726406


I have logs from a few tests today (pasting one below) if you are interested and can reproduce this pretty much at will (2 out of 3 scans seem to do it). I don't have a large test group to know for sure but if I re-start the scans after the files have been recording for a while (say 15 minutes), I don't seem to get a crash (and they do catch up to the recording). That could be anecdotal though.

I am familiar with debug tools such as Debug Diag so if you have a PDB file I can grab a crash dump and send you a stack trace if you think it would help.

Here is the log from one of the above crashes just in case I have an incorrect setting:

################################################################
Generated using Comskip 0.81.037
Time at start of run:
Thu Jun 21 09:57:08 2012
################################################################
Mpeg: D:\Recorded TV\Comedy Central Presents_CCHD_2012_06_21_09_56_00.wtv
Exe C:\Program Files (x86)\DVRMSToolbox\Applications\comskip.exe
Logo: D:\Recorded TV\Comedy Central Presents_CCHD_2012_06_21_09_56_00.logo.txt
Ini: C:\Program Files (x86)\DVRMSToolbox\Applications\comskip.ini

Detection Methods to be used:
1) Black Frame
2) Logo - Give up after 2000 seconds
3) Resolution Change
4) Aspect Ratio


ComSkip throttles back from -0001 to -0001.
The time is now 0957 so it's full speed ahead!

Settings
--------
[Main Settings]
;the sum of the values for which kind of frames comskip will consider as possible cutpoints: 1=uniform (black or any other color) frame, 2=logo, 4=scene change, 8=resolution change, 16=closed captions, 32=aspect ration, 64=silence, 255=all.
detect_method=43
;Set to 10 to show a lot of extra info, level 5 is also OK, set to 0 to disable
verbose=10
;Frame not black if any of the pixels of the frame has a brightness greater than this (scale 0 to 255)
max_brightness=60
maxbright=1
;Frame not pure black if a small number of the pixels of the frame has a brightness greater than this. To decide if the frame is truly black, comskip will also check average brightness (scale 0 to 255)
test_brightness=40
;
max_avg_brightness=25
;
max_commercialbreak=600
;
min_commercialbreak=25
;
max_commercial_size=125
;
min_commercial_size=4
;
min_show_segment_length=250
;
max_volume=500
;
max_silence=100
;
non_uniformity=500
[Detailed Settings]
min_silence=12
noise_level=5
brightness_jump=200
fps=25
validate_silence=1
validate_uniform=1
validate_scenechange=1
global_threshold=1.05
disable_heuristics=4
[CPU Load Reduction]
thread_count=2
play_nice_start=-1
play_nice_end=-1
play_nice_sleep=10
[Input Correction]
max_repair_size=200
ms_audio_delay=5
volume_slip=40
variable_bitrate=1
lowres=0
[Aspect Ratio]
ar_delta=0.08
cut_on_ar_change=1
[Global Removes]
padding=0
remove_before=0
remove_after=0
added_recording=14
delete_show_after_last_commercial=0
delete_show_before_first_commercial=0
delete_show_before_or_after_current=0
delete_block_after_commercial=0
min_commercial_break_at_start_or_end=39
always_keep_first_seconds=0
always_keep_last_seconds=0
[USA Specific]
intelligent_brightness=0
black_percentile=0.0076
uniform_percentile=0.003
score_percentile=0.71
[Main Scoring]
length_strict_modifier=3
length_nonstrict_modifier=1.5
combined_length_strict_modifier=2
combined_length_nonstrict_modifier=1.25
ar_wrong_modifier=2
excessive_length_modifier=0.01
dark_block_modifier=0.3
min_schange_modifier=0.5
max_schange_modifier=2
logo_present_modifier=0.01
punish_no_logo=1
[Detailed Scoring]
punish=0
reward=0
punish_threshold=1.3
punish_modifier=2
reward_modifier=0.5
[Logo Finding]
border=10
give_up_logo_search=2000
delay_logo_search=0
logo_max_percentage_of_screen=0.12
ticker_tape=0
ticker_tape_percentage=0
ignore_side=0
subtitles=0
logo_at_bottom=0
logo_threshold=0.75
logo_filter=0
aggressive_logo_rejection=0
edge_level_threshold=5
edge_radius=2
edge_weight=10
edge_step=1
num_logo_buffers=50
use_existing_logo_file=1
two_pass_logo=1
[Logo Interpretation]
connect_blocks_with_logo=1
logo_percentile=0.92
logo_fraction=0.4
shrink_logo=5
shrink_logo_tail=0
before_logo=0
after_logo=0
where_logo=0
min_black_frames_for_break=1
[Closed Captioning]
ccCheck=0
cc_commercial_type_modifier=4
cc_wrong_type_modifier=2
cc_correct_type_modifier=0.75
[Live TV]
live_tv=1
live_tv_retries=4
dvrms_live_tv_retries=300
standoff=0
dvrmsstandoff=120000
require_div5=0
div5_tolerance=-1
incommercial_frames=1000
[Output Control]
output_default=1
output_chapters=0
output_plist_cutlist=0
output_zoomplayer_cutlist=0
output_zoomplayer_chapter=0
output_vcf=0
output_vdr=0
output_projectx=0
output_avisynth=0
output_videoredo=0
output_videoredo3=0
videoredo_offset=2
output_btv=0
output_edl=1
edl_offset=0
output_edlp=0
output_bsplayer=0
output_edlx=0
output_cuttermaran=0
output_mpeg2schnitt=0
output_womble=0
output_mls=0
output_mpgtx=0
output_dvrmstb=1
output_dvrcut=0
output_ipodchap=0
output_framearray=0
output_debugwindow=0
output_tuning=0
output_training=0
output_false=0
output_aspect=0
output_demux=0
output_data=0
output_srt=0
output_smi=0
output_timing=0
delete_logo_file=0
cutscene_frame=0
cutscene_dumpfile=""
cutscene_threshold=10
cutscenefile1=""
cutscenefile2=""
cutscenefile3=""
cutscenefile4=""
cutscenefile5=""
cutscenefile6=""
cutscenefile7=""
cutscenefile8=""
windowtitle="Comskip - %s"
cuttermaran_options="cut=\"true\" unattended=\"true\" muxResult=\"false\" snapToCutPoints=\"true\" closeApp=\"true\""
mpeg2schnitt_options="mpeg2schnitt.exe /S /E /R25 /Z %2 %1"
avisynth_options="LoadPlugin(\"MPEG2Dec3.dll\") \nMPEG2Source(\"%s\")\n"
dvrcut_options="dvrcut \"%s.dvr-ms\" \"%s_clean.dvr-ms\" "
[Sage Workarounds]
sage_framenumber_bug=0
sage_minute_bug=0
enable_mencoder_pts=0

Audio PTS jumped -23 frames at frame 0
Frame Rate set to 29.970 f/s
Format changed to [1920 : 1080]
Frame: 1 Ratio: 1.80 MinY: 1 MaxY: 1080 MinX: 1 MaxX: 1920
Frame Rate set to 29.970 f/s
Frame Rate set to 29.970 f/s
Frame Rate set to 29.970 f/s
Audio PTS jumped -11 frames at frame 4
Resizing scene change array to accomodate 2000 frames.
Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.


Looking For Logo in frames 29 to 1450.
Not enough edge count - 0

Looking For Logo in frames 58 to 1479.
Not enough edge count - 0

Looking For Logo in frames 87 to 1508.
Edge count - 6281 Percentage of screen - 0.72%, Check: 0
Double checking - 1

Looking For Logo in frames 116 to 1537.
Edge count - 6280 Percentage of screen - 0.72%, Check: 1
Double checking - 2
Doublechecking frames 116 to 1537 for logo.
234567890123456789012345678901234567890123456789012345678901234567890123456789012345678901234567890123456
896:
897:
898:
899:
900: - --------
901: -------------------
902: -----------------------------
903: ------+++-------------------------
904: ---+-+----------------------------+---
905: -----+--------- -------------
906: ----+++---- ----++++---
907: --++++---- ---+++++--
908: ------- ----+-+--
909: --++++- ---+---
910: -+-+-- ----- -++++--
911: -+-- -------- -- - --- -++++--
912: --+-- --- ----- ------- --++--
913: +-+-- -------- -------- -++++-
914: --- --- ------- -- --+-
915: --- ---- -+++
916: -- -- ---
917: - ---
918: - |-|
919: || +-| |-|
920:
921: ---
922: -
923: |-|
924: | |
925: | |
926: | |
927:
928:
929:
930:
931:
932:
933: -------- ||||
934: -------------- ||||
935: ---------------- | ||||
936: ||| ------ -----+-| - |||| |||||
937: ||| +- - --+| |||| ||||
938: ||| ||| -|||---- - |||| ||||
939: ||| --- |||| ||||
940: | ---- |||| |||||
941: -- |||| |||||
942: |||| ||||
943: || ||| ||||
944: | |||| ||||
945: |||| ||||
946: |||| ||||
947: |||| ||||
948: |||| ||||
949: |||| ||||
950: |||| ||||
951: |||| ||||
952: - |||| ||||
953: --- |||| |||||
954: - |||| |||||
955: --- |||| |||||
956: | ||||| ||||
957: -+ | | |||| |||||
958: | | + | |||| |||||
959: --- -- - |||| ||+||
960: ----- -+++| |||| |++|
961: -+-+- -+++ |||| |++|
962: -+++- -+-+- ||||| |++|
963: -- +++++ -++++- ||||| |++|
964: --- -- -+++++- -+-++++ |||| |+++|
965: --++-|||| -+++++- --+++++- ||||| |++||
966: -+++++ +||+| -+++++--- ----+++++- |||+|| |+++|
967: +++++- ||++| --+|++-------------++++++- |++|| |++|
968: ||++-- |+++| ---++++++--------++++--- |++++ |+++
969: ||+++ |++++| -------------------- |++++| +++|
970: ||+++ |++++| -------------- |++++| +++||
971: |+++| |++++| ------ +++++ |+++|
972: ++++| |++++- +++++ |++++|
973: |++++ ++++++ |+++++ |+++|
974: |++++ ++++++ ++++++ |++++
975: ++++| -+++++- -++++++ ++++
976: -++++ -++++++ -++++++- +++++|
977: +++++ ++++++- -++++++- |++++|
978: ||+++- -++++++-- -+++++++ ++++++
979: |++++- +++++++--- ---++++++- -+++++
980: ++++++ --+++++++----- ---++++++-- ++++++
981: ++++++- ----+++++--------------+++++++--- ++++++
982: ++++++ -----+++++++-------++++----- -+++++-
983: -+++++- ------------------------ -+++++-
984: -++++-- ------------- --+++++-
985: -++++++- --++++++
986: ++++++-- --++++++-
987: -++++++--- --++++++--
988: -++++++----- ----++++++--
989: ---++++++-------- ------------++++++--
990: ----+++++-------------------+++++++---
991: -----++++-------------++++++----
992: ---------------------------
993: -------------------
994:
995:
996:
997:
998:
999:
1000:
1001: ------ ------ - - --------- -------- ---- ----
1002: -----+-+-- ---------- -- -- --------- ---------- --- ----
1003: ++++---+++|| -++++--+++++ | ++|| |+++|| ||+++----++||||+++---+++++ ||+++++||+++++||
1004: |++++----+++|| +++++----+++++ ||+++|| |++++|| |++++----++||||+++-----++++||+++++||+++++||
1005: +++++-----+++|||++++------+++|| ||+++++| |+++|+| ||||| ---+++|||||||-----++++||++++++++++++|
1006: |||+++++++++++||+|++++++++++|++|||||||+++||+++|||||||||||+++--- |||||+++++++++||++++++++++++|
1007: ||+||++++----- |||++++++++++|+||||||||++||+++|||||||||||++++--- |||||++++++++++||++++--++++|
1008: ||+||+++ --- |||+|++++- +++||+|||||||+++++++||||||||||||++-+||| ||||||||-+++|++||++++++++++
1009: ||||||++| |||+|++|| |++||+||||||+++++++++||||||||||+--+++|| |||||||| |++||+|||+++||+++|
1010: |||||++| |||+|+++| |++||+||||||+-++++++-|||||||||||---++|| |||||||| +++||||| |++||++|
1011: ||+||+++----- ||++|++++--+++|++|||+||+++++-+-+-||+|||||||+++++|| ||||||++++++|++|| |++||++|
1012: ||++|++++----- |+++|++++++++|++|||+||++++++++++||+|||||||+++--- |||||++++++++++|| ||||||||
1013: ||++++++++-+++||+++++++++++++++|||+||++++++++++||+||||||++++-++| |||||++++++++++| ||||||||
1014: |+++++-+--+++|||++++++++++++++|||+++++++++++|++++||||+++++-+++||||+++++++++++++| |||+++||
1015: |+++++----+++|||+++++----+++++ ||++++|++++++|++++|||++++---+++||||+++----+++++| ||++++||
1016: +++++++++++| ++++++++++++ ||++++|+++++||++++|||++++---+++||||+++--++++++- ||++++||
1017: ---++++++-- --+++++++-- ---- ---- ---- |--+-----++| +++---++--- ----
1018: ----------- ---------- --- -- ---- ----------- ---------- -----
1019: -------- ---- ---- ---- --- ---- ------------ --------- ---------
1020: |++----++||-++-- --|+++-||+++++ |-+-+ ---- ---- +-+-| |+++----+++ ++++++++--
1021: ||+++--+++||++++++-++++++||+++++||++++| ||++++|| ||++++| |++++||||+++----+++|||++++-++++++
1022: ||+++---++||++++++-++++++||+++++||++++|| ||++++|| ||++++++ |++++||||+++----+++|||+++---+++++|
1023: ||+++-- ||||++++------+++||++++++||||||| |||||||| |||++++++||+||||||+++--++||||||+++----+++++|
1024: --+++|||||++++-----++++||++++++++||||| |||||||| ||||++++++|||||| ----+++||||||++++++++++++|
1025: --+++|||||++++|+++||+++| |++|++++||||| |||||||| |||||+++++|||||| ---++++||||| -----+++|+++||
1026: |||||||||+++|+++++++| |+++++-+-||||| |||||||| |||||-+++++||||| ||++++++||||| -- |++||+||
1027: |||||||||+++|-++|+++||+++|+----||||| |||||||| |||||--+++++|||| ||+++---||||| |+|||+||
1028: |||||||| |+++++++++|||+++++++++||||| |||||||| |||||++++-+ |||| ||+++---||||| ++||+|||
1029: |||||||| |++++-++++|||+++|+++++||||| +++|||++- |||||+++++- |||| |++++++||||| -----+++||++||
1030: |||||||| |+++++++||||++|++++++|||||-+++||+++- ||||||++++++|||| ----+++||||| ----++++|++||
1031: |||+|+|| |+++++++| ||++|++++||||||++++|||+++|||||+||++++++||| |++++++||+||||++++++++++++|
1032: ||++++|| |++++++| |++++-----+++||+++----+++|||++++||++++++||||+++----+++|||++-----++++|
1033: |++++|| |+++++| ||++++----+++||+++----+++|||++++| +++++||||+++----+++|||+++---+++++
1034: +-+-| ---- +++-----+++ |+++-----++| |-+-+ ---- |+++----+++ |+++---+++-
1035: --- --- ---------- ---------- --- --- --------- ---------
1036: - ------- -------- - ------- ------
1037:
1038:
1039:
1040:
logoMinX=1742 logoMaxX=1846 logoMinY=896 logoMaxY=1040
******************* End of Logo Processing ***************
Audio PTS jumped -27 frames at frame 0
Frame: 1 Ratio: 1.80 MinY: 1 MaxY: 1080 MinX: 1 MaxX: 1920
Audio PTS jumped -11 frames at frame 4
Start logo cblock 0 frame 87
Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.

Building list of all frames with a brightness less than 32.


I am familiar with a number of

[LastButNotLeast]

You should read the "How to ask for help" post:
viewtopic.php?f=5&t=34

[btracy]

Thanks for the reply but I already read that post and it details steps for getting tuning advice. The first line reads:

If you want to ask me for advice on how to tune comskip for your environment you need to follow this procedure to get the most out of your question.

I am not interested in tuning advice at this time but rather reporting a crash.

[erik]

Can you set
live_tv=0
and test if the crash is still there?
If yes, can you upload the smallest possible recording that causes Comskip to crash to my ftp server?

[joesc1]

Can you set
live_tv=0
and test if the crash is still there?
If yes, can you upload the smallest possible recording that causes Comskip to crash to my ftp server?

So the suggestion is to not run comskip on live tv recordings any more?

[bmblank]

The live_TV line does not enable and disable live processing, it just tells comskip when to create the commercials file. With live_TV=0 it will wait until its done processing (shortly after its finished recording) to finalize and create the file. Live_TV=1 will create the file immediately and it is constantly changing until comskip finishes processing and finalizes the file.

[btracy]

Sounds good. I will turn off the live_tv setting and then see if it still happens.

I am actually interested in the file being written while the show is recording so I can wait 15 or 20 minutes in an hour long show and still get commercial skipping to happen while the show is still recording (tested this the other night and it works for those that don't crash). Scanning for a full hour of HD doesn't take more than 8 to 10 minutes after the show finishes recording so if live_tv is my crash problem then being able to scan a recording live doesn't gain me much of anything if I have to wait for the file to write until the very end.

Hopefully I can test this all out tonight.

[ghostlobster]

just an fyi here... I've had flakey results with using live_tv=1. For some reason it would only process the beginning of each show and then it would just bail out. Erik posted something in another thread saying that this flag is still buggy or something like that, so i just disabled it. It's not exactly the perfect solution, as I agree with the OP here, in that I want to wait 15-20 minutes then start watching a show with automatic commercial skipping, but given the fact that the commercial analysis is extremely good, I'm ok with this shortcoming.

[erik]

I found that setting
thread_count=1
also can reduce crashing.

[btracy]

Sorry for the delay. I had to go out of town for work this weekend at the last minute.

I modified my settings to have live_tv set to 0 and set off a number of recordings while I was away. The crash still happens with live_tv set to 0.

I can say however that the crash always happens within the first 5 minutes of the recording starting. By this I mean, if comskip is started within the first 5 minutes of a recording starting there is a chance (not a guarantee) that a crash will occur. When this same recording is re-enqueued automatically (usually around 7 to 10 minutes after the recording has started), a crash never occurs.

I will leave live_tv at 0 and set thread_count=1 and see if that makes any difference. I should be able to test this out in the next few days. If the crashes only occur during live recording, it is likely going to be impossible to get a small file that reproduces the issue since we know every re-scan works perfectly.

[htpcthor]

I am also having this problem.

How do I tell DVRMSToolBox to try and process the file again?

[btracy]

I didn't have a lot of recordings tonight but with live_tv set to 0 and thread_count set to 1 the crash still occurs.

@htpcthor, that would depend on a number of your settings in dvrmstoolbox. For starters, if you have live_tv set to 1 a partial xml file will have been written (by default to C:\Users\Public\DvrmsToolbox\CommercialsXml but check the Commercial Skip tab for your Commercial Path) so you will need to delete it (also the .vih and .txt files for good measure) for the show/s you want to reprocess.

For me, all it takes to re-process is to have the Process Files Missing Artifacts checkbox selected (File Watcher Tab), make sure there is no .xml file present for this show and it starts again when the next poll time occurs (within 5 minutes). What happens has varied by version I run though. Currently I am using 1.2.2.4 but in past versions I have had to re-start the DTB Service to force a re-process.

I will try to work out a time to see if I can set a recording and stop it when a crash happens. I am guessing this won't create a reproducible scenario but it is worth a shot. For now, I am going to hook DebugDiag to comskip to see what it gets me with a full user dump on first chance exceptions.

[erik]

Its possible comskip crashes when started on a recording that does not yet contain some relevant data.
Could you monitor what recording files size comskip is crashing on?

[btracy]

Thanks Erik.

I am going to workout a test to see the file size on crash. I want to do a test first to see if the crash continues to happen if just one version of comskip is going at a time. All of my tests up to this point contain multiple recordings and multiple comskips going at the same time. I know I can run comskip multiple times with no crashes on already recorded shows (did a full wipe and re-scan of 70+ recordings) so I don't see why it shouldn't continue to crash on just one live recording.

I did hook debugdiag to comskip last night and captured details on the crashes. Without debug symbols I can't really see much but I wanted to know if there was any pattern to how long comskip stayed up before crashing. It appears to be just beyond the two minute mark each time. This are the times for some of the crashes:

Process Up-Time 00:02:01
Process Up-Time 00:02:01
Process Up-Time 00:02:02
Process Up-Time 00:02:01
Process Up-Time 00:02:04

I will kick off single recordings today to see if I get a crash and then see if I can workout how big the recording is at that point.

[htpcthor]

Is there a way to tell DVRMSToolBox to wait 5 minutes after a show has started recording before starting ComSkip. I believe the Max Wait in the 'Commercial Processing' tab will cause ComSkip to be run after the show stops recording, which is not what I want.

I think this would be a temporary solution until the real problem is found.

EDIT: Actually, I have been reading more and it looks like the 'Wait Time' parameter in the 'File Watcher' will do what I want. According to the author of DVRMSToolBox, this will delay the starting of ComSkip for x amount of minutes. I am going to set it to 5 and see if it fixes the problem.