Bug #5789: PVR Recording stops recording to early - Tvheadend

Bug #5789

PVR Recording stops recording to early

Added by Anonymous about 5 years ago. Updated almost 2 years ago.

Status:

Invalid

Priority:

Normal

Assignee:

Adam Sutton

Category:

PVR / DVR

Target version:

Start date:

2019-12-06

Due date:

% Done:

Estimated time:

Found in version:

4.2.8-27

Affected Versions:

Description

Sometimes when I record a show it stops to early. This seems to happen 2-3 times a week. For example, On 2019-12-01 I tried to record Batwomen which started at 19:59:30 and was suppose to record for an hour but it only recorded for 20 minutes and 30 seconds.

I attach the service.log from TVHeadend and the kodi.log.

Files

kodi.log (1.62 MB) kodi.log		Anonymous, 2019-12-06 00:52
service.log (9.52 MB) service.log		Anonymous, 2019-12-06 00:57

History

Updated by Flole Systems about 5 years ago

Upgrade to latest master and provide only the parts of the log file that show the issue if it still happens. Nobody is going to dig through 9MB of log file to maybe find something that isn't quite right.

Updated by Joe User about 5 years ago

Well, he did say when the program started, so not so difficult to find...

Main relevant entries:

019-12-01 19:59:30.001 [   INFO] dvr: "Batwoman" on "503 WDCWDT" recorder starting
2019-12-01 19:59:30.002 [   INFO] dvr: About to set stop timer for "Batwoman" on "503 WDCWDT" at start 1575248400 and original stop 1575252000 and overall stop at 
2019-12-01 19:59:30.002 [   INFO] mpegts: CW in HDHomerun Dual - tuning on IPTV
2019-12-01 19:59:30.002 [   INFO] subscription: 00A1: "DVR: Batwoman" subscribing on channel "503 WDCWDT", weight: 300, adapter: "IPTV", network: "HDHomerun Dual", mux: "CW", profile="pass" 
2019-12-01 20:00:01.846 [   INFO] dvr: /var/media/PVR/Batwoman/Batwoman-503-WDCWDT2019-12-0120-00-S01E08.ts from adapter: "IPTV", network: "HDHomerun Dual", mux: "CW", provider: "<N/A>", service: "<N/A>" 
2019-12-01 20:00:01.846 [   INFO] dvr:  #  type              lang  resolution  aspect ratio  sample rate  channels
2019-12-01 20:00:01.847 [   INFO] dvr:  1  MPEG2VIDEO              1280x720    ?                                    
2019-12-01 20:00:01.847 [   INFO] dvr:  2  AC3               eng                             ?            ?         
2019-12-01 20:00:01.847 [   INFO] dvr:  3  AC3               spa                             ?            ?         
2019-12-01 20:20:54.001 [   INFO] epgdb: snapshot start
2019-12-01 20:20:54.201 [   INFO] epgdb: queued to save (size 29324899)
2019-12-01 20:20:54.201 [   INFO] epgdb: save start
2019-12-01 20:20:54.201 [   INFO] epgdb:   brands     0
2019-12-01 20:20:54.201 [   INFO] epgdb:   seasons    2296
2019-12-01 20:20:54.201 [   INFO] epgdb:   episodes   25019
2019-12-01 20:20:54.201 [   INFO] epgdb:   broadcasts 31959
2019-12-01 20:20:54.824 [   INFO] epgdb: stored (size 3826132)
2019-12-01 20:29:06.377 [   INFO] subscription: 009D: "192.168.2.128 [ andriodtv1 | Kodi Media Center ]" unsubscribing from "509 WUSADT", hostname="192.168.2.128", username="andriodtv1", client="Kodi Media Center" 
2019-12-01 20:29:30.005 [   INFO] dvr: "60 Minutes" on "509 WUSADT" recorder starting
2019-12-01 20:29:30.005 [   INFO] dvr: About to set stop timer for "60 Minutes" on "509 WUSADT" at start 1575250200 and original stop 1575253800 and overall stop at 1575253860
2019-12-01 20:29:30.006 [   INFO] mpegts: CBS in HDHomerun Dual - tuning on IPTV
2019-12-01 20:29:30.006 [   INFO] subscription: 00A2: "DVR: 60 Minutes" subscribing on channel "509 WUSADT", weight: 300, adapter: "IPTV", network: "HDHomerun Dual", mux: "CBS", profile="pass" 
2019-12-01 20:30:01.882 [   INFO] dvr: /var/media/PVR/60-Minutes/60-Minutes-509-WUSADT2019-12-0120-30-S52E11.ts from adapter: "IPTV", network: "HDHomerun Dual", mux: "CBS", provider: "<N/A>", service: "<N/A>" 
2019-12-01 20:30:01.882 [   INFO] dvr:  #  type              lang  resolution  aspect ratio  sample rate  channels
2019-12-01 20:30:01.882 [   INFO] dvr:  1  MPEG2VIDEO              1920x1080   ?                                    
2019-12-01 20:30:01.882 [   INFO] dvr:  2  AC3               eng                             ?            ?         
2019-12-01 20:30:01.882 [   INFO] dvr:  3  AC3               spa                             ?            ?         
2019-12-01 20:31:05.829 [   INFO] htsp: 192.168.2.128 [ andriodtv1 | Kodi Media Center ]: Disconnected
2019-12-01 20:31:06.052 [   INFO] htsp: Got connection from 192.168.2.128
2019-12-01 20:31:06.053 [   INFO] htsp: 192.168.2.128: Welcomed client software: Kodi Media Center (HTSPv34)
2019-12-01 20:31:06.055 [   INFO] htsp: 192.168.2.128 [ Kodi Media Center ]: Identified as user 'andriodtv1'
2019-12-01 20:31:30.697 [   INFO] htsp: 192.168.2.128 [ andriodtv1 | Kodi Media Center ]: Disconnected
2019-12-01 20:31:39.879 [   INFO] htsp: Got connection from 192.168.2.128
2019-12-01 20:31:39.883 [   INFO] htsp: 192.168.2.128: Welcomed client software: Kodi Media Center (HTSPv34)
2019-12-01 20:31:39.884 [   INFO] htsp: 192.168.2.128 [ Kodi Media Center ]: Identified as user 'andriodtv1'
2019-12-01 21:01:00.043 [   INFO] subscription: 00A1: "DVR: Batwoman" unsubscribing from "503 WDCWDT" 
2019-12-01 21:01:00.044 [   INFO] spawn: Executing "/storage/.kodi/addons/service.tvheadend42/bin/comskip" 
2019-12-01 21:01:00.047 [   INFO] dvr: "Batwoman" on "503 WDCWDT": End of program: Completed OK
2019-12-01 21:01:00.124 [  ERROR] spawn: Comskip 0.82.007, made using ffmpeg
2019-12-01 21:01:00.124 [  ERROR] spawn: Donator build
2019-12-01 21:01:00.126 [   INFO] spawn: The commandline used was:
2019-12-01 21:01:00.126 [   INFO] spawn: /storage/.kodi/addons/service.tvheadend42/bin/comskip --ini=/storage/.kodi/userdata/addon_data/service.tvheadend42/comskip/comskip.ini /var/media/PVR/Batwoman/Batwoman-503-WDCWDT2019-12-0120-00-S01E08.ts
2019-12-01 21:01:00.126 [   INFO] spawn: Setting ini file to /storage/.kodi/userdata/addon_data/service.tvheadend42/comskip/comskip.ini as per commandline
2019-12-01 21:01:00.126 [   INFO] spawn: Using /storage/.kodi/userdata/addon_data/service.tvheadend42/comskip/comskip.ini for initiation values.
2019-12-01 21:01:00.126 [   INFO] spawn: Mpeg:    /var/media/PVR/Batwoman/Batwoman-503-WDCWDT2019-12-0120-00-S01E08.ts
2019-12-01 21:01:00.126 [   INFO] spawn: Exe    comskip.exe
2019-12-01 21:01:00.126 [   INFO] spawn: Logo:    /var/media/PVR/Batwoman/Batwoman-503-WDCWDT2019-12-0120-00-S01E08.logo.txt
2019-12-01 21:01:00.126 [   INFO] spawn: Ini:    /storage/.kodi/userdata/addon_data/service.tvheadend42/comskip/comskip.ini
2019-12-01 21:01:00.126 [   INFO] spawn: Detection Methods to be used:
2019-12-01 21:01:00.126 [   INFO] spawn:     1) Black Frame
2019-12-01 21:01:00.126 [   INFO] spawn:     2) Logo - Give up after 2000 seconds
2019-12-01 21:01:00.126 [   INFO] spawn:     3) Resolution Change
2019-12-01 21:01:00.126 [   INFO] spawn:     4) Aspect Ratio
2019-12-01 21:01:00.126 [   INFO] spawn: ComSkip throttles back from -0001 to -0001.
2019-12-01 21:01:00.126 [   INFO] spawn: The time is now 2101 so it's full speed ahead!
2019-12-01 21:01:00.126 [   INFO] spawn: Settings
2019-12-01 21:01:00.126 [   INFO] spawn: --------
2019-12-01 21:01:00.126 [   INFO] spawn: [Main Settings]
2019-12-01 21:01:00.126 [   INFO] spawn: ;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.
2019-12-01 21:01:00.126 [   INFO] spawn: detect_method=43
2019-12-01 21:01:00.126 [   INFO] spawn: ;Set to 10 to show a lot of extra info, level 5 is also OK, set to 0 to disable
2019-12-01 21:01:00.126 [   INFO] spawn: verbose=10
2019-12-01 21:01:00.126 [   INFO] spawn: ;Frame not black if any of the pixels of the frame has a brightness greater than this (scale 0 to 255)
2019-12-01 21:01:00.126 [   INFO] spawn: max_brightness=60
2019-12-01 21:01:00.126 [   INFO] spawn: maxbright=1
2019-12-01 21:01:00.126 [   INFO] spawn: ;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)
2019-12-01 21:01:00.126 [   INFO] spawn: test_brightness=40
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: max_avg_brightness=25
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: max_commercialbreak=600
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: min_commercialbreak=25
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: max_commercial_size=125
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: min_commercial_size=4
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: min_show_segment_length=250
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: max_volume=500
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: max_silence=100
2019-12-01 21:01:00.126 [   INFO] spawn: ;
2019-12-01 21:01:00.126 [   INFO] spawn: non_uniformity=500
2019-12-01 21:01:00.126 [   INFO] spawn: [Detailed Settings]
2019-12-01 21:01:00.126 [   INFO] spawn: min_silence=12
2019-12-01 21:01:00.126 [   INFO] spawn: remove_silent_segments=0
2019-12-01 21:01:00.126 [   INFO] spawn: noise_level=5
2019-12-01 21:01:00.126 [   INFO] spawn: brightness_jump=200
2019-12-01 21:01:00.126 [   INFO] spawn: fps=1
2019-12-01 21:01:00.126 [   INFO] spawn: validate_silence=1
2019-12-01 21:01:00.126 [   INFO] spawn: validate_uniform=1
2019-12-01 21:01:00.126 [   INFO] spawn: validate_scenechange=1
2019-12-01 21:01:00.126 [   INFO] spawn: global_threshold=1.05
2019-12-01 21:01:00.126 [   INFO] spawn: disable_heuristics=4
2019-12-01 21:01:00.126 [   INFO] spawn: cut_on_ac_change=1
2019-12-01 21:01:00.126 [   INFO] spawn: [CPU Load Reduction]
2019-12-01 21:01:00.126 [   INFO] spawn: thread_count=2
2019-12-01 21:01:00.126 [   INFO] spawn: hardware_decode=0
2019-12-01 21:01:00.126 [   INFO] spawn: play_nice_start=-1
2019-12-01 21:01:00.126 [   INFO] spawn: play_nice_end=-1
2019-12-01 21:01:00.126 [   INFO] spawn: play_nice_sleep=2
2019-12-01 21:01:00.126 [   INFO] spawn: [Input Correction]
2019-12-01 21:01:00.126 [   INFO] spawn: max_repair_size=200
2019-12-01 21:01:00.126 [   INFO] spawn: ms_audio_delay=5
2019-12-01 21:01:00.126 [   INFO] spawn: volume_slip=40
2019-12-01 21:01:00.126 [   INFO] spawn: lowres=0
2019-12-01 21:01:00.126 [   INFO] spawn: skip_b_frames=0
2019-12-01 21:01:00.126 [   INFO] spawn: [Aspect Ratio]
2019-12-01 21:01:00.126 [   INFO] spawn: ar_delta=0.08
2019-12-01 21:01:00.126 [   INFO] spawn: cut_on_ar_change=1
2019-12-01 21:01:00.126 [   INFO] spawn: [Global Removes]
2019-12-01 21:01:00.126 [   INFO] spawn: padding=0
2019-12-01 21:01:00.126 [   INFO] spawn: remove_before=0
2019-12-01 21:01:00.126 [   INFO] spawn: remove_after=0
2019-12-01 21:01:00.126 [   INFO] spawn: added_recording=14
2019-12-01 21:01:00.126 [   INFO] spawn: delete_show_after_last_commercial=0
2019-12-01 21:01:00.126 [   INFO] spawn: delete_show_before_first_commercial=0
2019-12-01 21:01:00.126 [   INFO] spawn: delete_show_before_or_after_current=0
2019-12-01 21:01:00.126 [   INFO] spawn: delete_block_after_commercial=0
2019-12-01 21:01:00.126 [   INFO] spawn: min_commercial_break_at_start_or_end=39
2019-12-01 21:01:00.126 [   INFO] spawn: always_keep_first_seconds=2
2019-12-01 21:01:00.126 [   INFO] spawn: always_keep_last_seconds=0
2019-12-01 21:01:00.126 [   INFO] spawn: [USA Specific]
2019-12-01 21:01:00.126 [   INFO] spawn: intelligent_brightness=0
2019-12-01 21:01:00.126 [   INFO] spawn: black_percentile=0.0076
2019-12-01 21:01:00.126 [   INFO] spawn: uniform_percentile=0.003
2019-12-01 21:01:00.126 [   INFO] spawn: score_percentile=0.71
2019-12-01 21:01:00.126 [   INFO] spawn: [Main Scoring]
2019-12-01 21:01:00.126 [   INFO] spawn: length_strict_modifier=3
2019-12-01 21:01:00.126 [   INFO] spawn: length_nonstrict_modifier=1.5
2019-12-01 21:01:00.126 [   INFO] spawn: combined_length_strict_modifier=2
2019-12-01 21:01:00.126 [   INFO] spawn: combined_length_nonstrict_modifier=1.25
2019-12-01 21:01:00.126 [   INFO] spawn: ar_wrong_modifier=2
2019-12-01 21:01:00.126 [   INFO] spawn: ac_wrong_modifier=1
2019-12-01 21:01:00.126 [   INFO] spawn: excessive_length_modifier=0.01
2019-12-01 21:01:00.126 [   INFO] spawn: dark_block_modifier=0.3
2019-12-01 21:01:00.126 [   INFO] spawn: min_schange_modifier=0.5
2019-12-01 21:01:00.126 [   INFO] spawn: max_schange_modifier=2
2019-12-01 21:01:00.126 [   INFO] spawn: logo_present_modifier=0.01
2019-12-01 21:01:00.126 [   INFO] spawn: punish_no_logo=1
2019-12-01 21:01:00.126 [   INFO] spawn: [Detailed Scoring]
2019-12-01 21:01:00.126 [   INFO] spawn: punish=0
2019-12-01 21:01:00.126 [   INFO] spawn: reward=0
2019-12-01 21:01:00.126 [   INFO] spawn: punish_threshold=1.3
2019-12-01 21:01:00.126 [   INFO] spawn: punish_modifier=2
2019-12-01 21:01:00.126 [   INFO] spawn: reward_modifier=0.5
2019-12-01 21:01:00.126 [   INFO] spawn: [Logo Finding]
2019-12-01 21:01:00.126 [   INFO] spawn: border=10
2019-12-01 21:01:00.126 [   INFO] spawn: give_up_logo_search=2000
2019-12-01 21:01:00.126 [   INFO] spawn: delay_logo_search=0
2019-12-01 21:01:00.126 [   INFO] spawn: logo_max_percentage_of_screen=0.12
2019-12-01 21:01:00.126 [   INFO] spawn: ticker_tape=0
2019-12-01 21:01:00.126 [   INFO] spawn: ticker_tape_percentage=0
2019-12-01 21:01:00.126 [   INFO] spawn: top_ticker_tape=0
2019-12-01 21:01:00.126 [   INFO] spawn: top_ticker_tape_percentage=0
2019-12-01 21:01:00.126 [   INFO] spawn: ignore_side=0
2019-12-01 21:01:00.126 [   INFO] spawn: ignore_left_side=0
2019-12-01 21:01:00.126 [   INFO] spawn: ignore_right_side=0
2019-12-01 21:01:00.126 [   INFO] spawn: subtitles=0
2019-12-01 21:01:00.126 [   INFO] spawn: logo_at_bottom=0
2019-12-01 21:01:00.126 [   INFO] spawn: logo_threshold=0.75
2019-12-01 21:01:00.126 [   INFO] spawn: logo_percentage_threshold=0.25
2019-12-01 21:01:00.126 [   INFO] spawn: logo_filter=0
2019-12-01 21:01:00.126 [   INFO] spawn: aggressive_logo_rejection=0
2019-12-01 21:01:00.126 [   INFO] spawn: edge_level_threshold=5
2019-12-01 21:01:00.126 [   INFO] spawn: edge_radius=2
2019-12-01 21:01:00.126 [   INFO] spawn: edge_weight=10
2019-12-01 21:01:00.126 [   INFO] spawn: edge_step=1
2019-12-01 21:01:00.126 [   INFO] spawn: num_logo_buffers=50
2019-12-01 21:01:00.126 [   INFO] spawn: use_existing_logo_file=1
2019-12-01 21:01:00.126 [   INFO] spawn: two_pass_logo=1
2019-12-01 21:01:00.126 [   INFO] spawn: [Logo Interpretation]
2019-12-01 21:01:00.126 [   INFO] spawn: connect_blocks_with_logo=1
2019-12-01 21:01:00.126 [   INFO] spawn: logo_percentile=0.92
2019-12-01 21:01:00.126 [   INFO] spawn: logo_fraction=0.4
2019-12-01 21:01:00.126 [   INFO] spawn: shrink_logo=5
2019-12-01 21:01:00.126 [   INFO] spawn: shrink_logo_tail=0
2019-12-01 21:01:00.126 [   INFO] spawn: before_logo=0
2019-12-01 21:01:00.126 [   INFO] spawn: after_logo=0
2019-12-01 21:01:00.126 [   INFO] spawn: where_logo=0
2019-12-01 21:01:00.126 [   INFO] spawn: min_black_frames_for_break=1
2019-12-01 21:01:00.126 [   INFO] spawn: [Closed Captioning]
2019-12-01 21:01:00.126 [   INFO] spawn: ccCheck=0
2019-12-01 21:01:00.126 [   INFO] spawn: cc_commercial_type_modifier=4
2019-12-01 21:01:00.126 [   INFO] spawn: cc_wrong_type_modifier=2
2019-12-01 21:01:00.126 [   INFO] spawn: cc_correct_type_modifier=0.75
2019-12-01 21:01:00.126 [   INFO] spawn: [Live TV]
2019-12-01 21:01:00.126 [   INFO] spawn: live_tv=0
2019-12-01 21:01:00.126 [   INFO] spawn: live_tv_retries=4
2019-12-01 21:01:00.126 [   INFO] spawn: require_div5=0
2019-12-01 21:01:00.126 [   INFO] spawn: div5_tolerance=-1
2019-12-01 21:01:00.126 [   INFO] spawn: incommercial_frames=1000
2019-12-01 21:01:00.139 [   INFO] spawn: [Output Control]
2019-12-01 21:01:00.139 [   INFO] spawn: output_default=1
2019-12-01 21:01:00.139 [   INFO] spawn: output_chapters=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_plist_cutlist=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_zoomplayer_cutlist=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_zoomplayer_chapter=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_scf=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_vcf=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_vdr=1
2019-12-01 21:01:00.139 [   INFO] spawn: output_projectx=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_avisynth=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_videoredo=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_videoredo3=0
2019-12-01 21:01:00.139 [   INFO] spawn: videoredo_offset=2
2019-12-01 21:01:00.139 [   INFO] spawn: output_btv=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_edl=1
2019-12-01 21:01:00.139 [   INFO] spawn: output_live=0
2019-12-01 21:01:00.139 [   INFO] spawn: edl_offset=0
2019-12-01 21:01:00.139 [   INFO] spawn: timeline_repair=1
2019-12-01 21:01:00.139 [   INFO] spawn: edl_skip_field=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_edlp=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_bsplayer=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_edlx=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_cuttermaran=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_mpeg2schnitt=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_womble=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_mls=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_mpgtx=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_dvrmstb=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_dvrcut=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_ipodchap=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_framearray=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_debugwindow=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_tuning=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_training=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_false=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_aspect=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_demux=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_data=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_srt=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_smi=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_timing=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_incommercial=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_ffmeta=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_ffsplit=0
2019-12-01 21:01:00.139 [   INFO] spawn: delete_logo_file=0
2019-12-01 21:01:00.139 [   INFO] spawn: output_mkvtoolnix=0
2019-12-01 21:01:00.139 [   INFO] spawn: cutscene_frame=0
2019-12-01 21:01:00.139 [   INFO] spawn: cutscene_threshold=10
2019-12-01 21:01:00.139 [   INFO] spawn: windowtitle="Comskip - %s" 
2019-12-01 21:01:00.139 [   INFO] spawn: cuttermaran_options="cut=\"true\" unattended=\"true\" muxResult=\"false\" snapToCutPoints=\"true\" closeApp=\"true\"" 
2019-12-01 21:01:00.139 [   INFO] spawn: mpeg2schnitt_options="mpeg2schnitt.exe /S /E /R25  /Z %2 %1" 
2019-12-01 21:01:00.139 [   INFO] spawn: avisynth_options="LoadPlugin(\"MPEG2Dec3.dll\") \nMPEG2Source(\"%s\")\n" 
2019-12-01 21:01:00.139 [   INFO] spawn: dvrcut_options="dvrcut \"%s.dvr-ms\" \"%s_clean.dvr-ms\" " 
2019-12-01 21:01:00.139 [   INFO] spawn: [Sage Workarounds]
2019-12-01 21:01:00.139 [   INFO] spawn: sage_framenumber_bug=0
2019-12-01 21:01:00.139 [   INFO] spawn: sage_minute_bug=0
2019-12-01 21:01:00.139 [   INFO] spawn: enable_mencoder_pts=0
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpeg2video @ 0x3fbaa00] Invalid frame dimensions 0x0.
2019-12-01 21:01:00.139 [   INFO] spawn: [mpegts @ 0x3fb5680] PES packet size mismatch
2019-12-01 21:01:00.139 [   INFO] spawn: [mpegts @ 0x3fb5680] PES packet size mismatch
2019-12-01 21:01:00.139 [   INFO] spawn: Input #0, mpegts, from '/var/media/PVR/Batwoman/Batwoman-503-WDCWDT2019-12-0120-00-S01E08.ts':
2019-12-01 21:01:00.139 [   INFO] spawn:   Duration: 00:10:11.56, start: 63049.955522, bitrate: 5088 kb/s
2019-12-01 21:01:00.139 [   INFO] spawn:   Program 1011 
2019-12-01 21:01:00.139 [   INFO] spawn:     Stream #0:0[0x4ed]: Video: mpeg2video (Main) ([2][0][0][0] / 0x0002), yuv420p(tv, progressive), 1280x720 [SAR 1:1 DAR 16:9], Closed Captions, 59.94 fps, 59.94 tbr, 90k tbn, 119.88 tbc
2019-12-01 21:01:01.145 [  ERROR] spawn:  0:00:08 - 501 frames in 1.00 sec(501.00 fps), 1.00 sec(501.00 fps), 1%
2019-12-01 21:01:01.761 [   INFO] spawn:     Stream #0:1[0x4ee](eng): Audio: ac3 ([129][0][0][0] / 0x0081), 48000 Hz, 5.1(side), fltp, 384 kb/s
2019-12-01 21:01:01.761 [   INFO] spawn:     Stream #0:2[0x4ef](spa): Audio: ac3 ([129][0][0][0] / 0x0081), 48000 Hz, mono, fltp, 96 kb/s
2019-12-01 21:01:01.761 [   INFO] spawn: [mpeg2video @ 0x3fba400] gray decoding requested but not enabled at configuration time
2019-12-01 21:01:01.761 [   INFO] spawn: Frame Rate set to 59.940 f/s
2019-12-01 21:01:01.761 [   INFO] spawn: Initial audio pts =      0.000
2019-12-01 21:01:01.761 [   INFO] spawn: Initial video pts =      0.717
2019-12-01 21:01:01.761 [   INFO] spawn: Format changed to [1280 : 720]
2019-12-01 21:01:01.761 [   INFO] spawn: Frame: 1    Ratio: 1.80    MinY: 1 MaxY: 720 MinX: 1 MaxX: 1280
2019-12-01 21:01:01.761 [   INFO] spawn: Frame: 1 Channels:  6
2019-12-01 21:01:01.761 [   INFO] spawn: Resizing scene change array to accomodate 2000 frames.

Tvheadend recorded for an hour, as scheduled, then comskip started, but it says on 10min file, but you say "20 minutes and 30 seconds".

I am no expert on comskip, but I suspect that is your problem, not tvheadend...

In the future, it would be best to post in the forum your "problems" before just assuming it is a bug and filing a bug report. Just because something is not working as you expect, does not necessarily mean it is a bug.

Updated by Flole Systems about 5 years ago

Well, he did say when the program started, so not so difficult to find...

If you want to spend your time digging through 9MB of logs you are welcome to do so, I'm expecting a little more work from a bug reporter

Updated by Joe User about 5 years ago

Flole Systems wrote:

Well, he did say when the program started, so not so difficult to find...

If you want to spend your time digging through 9MB of logs you are welcome to do so, I'm expecting a little more work from a bug reporter

Digging??? Very funny, you spent more time replying to his post than it took me to scroll down the log to the 8:00 time.

Updated by Anonymous about 5 years ago

Sorry, I'll post in the forum first next time and reduce the log if I submit a redmine ticket. Using TVHeadend is new to me so I really wasn't sure about what the correct protocol was when there is an issue.

I've updated to 4.2.8-36 and will see if it resolves the issue.

Thanks

Updated by Joe User about 5 years ago

Try disabling comskip and see if the recordings are okay to narrow down possible problem.

Updated by Anonymous about 5 years ago

Ok, I'm been recording for the past few days to test after upgrading to 4.2.8-36 and it seems like the recording is working fine now even with comskip enabled.

Thanks for your help, you may close my ticket.

I know now for the future when I upgrade libreelec for my server and kodi on andriod tv to also check for any updates on tvheadend server.

Updated by Anonymous almost 5 years ago

Issue appears to have come back where it says it records for 1 hour but it stops recording early. I can confirm it is not a comskip issue as I moved the TS file to my computer and played it which showed only 42 minutes recording on the file.

For some reason it happens more on the WB station but I doubt that has anything to do with it. I've been trying to recreate the issue but so far no luck.

Updated by Anonymous over 4 years ago

Finally figured out the issue is with the HDHomerun firmware. I was able to mitigate the issue by checking the restart on error box on TVHeadend setup. But the stopping of recording and stopping of stream was an issue with the last few HDHomerun firmware which was a lot better in the last release from 5/21/20. Although the stream does still stop once in a while it is a lot better than previously.

You may close this ticket out.
Thanks

#10

Updated by Flole Systems over 4 years ago

Status changed from New to Invalid

#11

Updated by Thomas Heiderer over 2 years ago

Hi!

I also have the same problem that the recording breaks off too early. I have already announced this in the forum, but unfortunately I have not received an answer. https://tvheadend.org/boards/5/topics/46954
My question would be, how can the problem be solved?

Also available in: Atom PDF

Project

General

Profile

Tvheadend

Issues

Custom queries

Bug #5789

PVR Recording stops recording to early

History

Updated by Flole Systems about 5 years ago

Updated by Joe User about 5 years ago

Updated by Flole Systems about 5 years ago

Updated by Joe User about 5 years ago

Updated by Anonymous about 5 years ago

Updated by Joe User about 5 years ago

Updated by Anonymous about 5 years ago

Updated by Anonymous almost 5 years ago

Updated by Anonymous over 4 years ago

Updated by Flole Systems over 4 years ago

Updated by Thomas Heiderer over 2 years ago