Opened 5 months ago

Closed 4 months ago

#13629 closed Bug Report - General (Fixed)

ffmpeg payback with double rate de-einterlacer

Reported by: jksj461 Owned by: Mark Kendall
Priority: minor Milestone: 31.1
Component: MythTV - Video Playback Version: v31-fixes
Severity: medium Keywords:
Cc: Ticket locked: no

Description

Software playback with double rate de-interlacing worked fine in early versions of v31. Then with some recordings the audio went several seconds out and the picture went into some sort of slow motion. Several people have commentated on this in the forum but it must obviously work for most people. Selecting single rate de-interacer always fixes the issue. It may be relevant that the streams being played are UK DVB which switches randomnly between 1080p25 and 1080i25 at the wim of the encoder. I tried to bisect it today but not being a developer may have got it wrong , the bisect however did land on a likely candidate.

commit 31c68a14e816df1ff256280821aeaf8e5f14610d (refs/bisect/bad) Author: Mark Kendall <mark.kendall@…> Date: Tue Mar 10 20:50:03 2020 +0000

MythDeinterlacer?: Don't cleanup deinterlacer if already deinterlaced

(cherry picked from commit 62a8f70bcb6aa1015f545808e3b9007666b6dbb8)

v31.0-48-gc89a7e3771 without the above change works fine. I can't make any sense of the logs which do not show that audio is way out. A none working log is followed by a good one

bad log

Software current version fixes/31 [v31.0-48-gc89a7e3771] 2020-06-03 11:57:14.230104 I Setup Interrupt handler 2020-06-03 11:57:14.230122 I Setup Terminated handler 2020-06-03 11:57:14.230128 I Setup Segmentation fault handler 2020-06-03 11:57:14.230134 I Setup Aborted handler 2020-06-03 11:57:14.230138 I Setup Bus error handler 2020-06-03 11:57:14.230143 I Setup Floating point exception handler 2020-06-03 11:57:14.230148 I Setup Illegal instruction handler 2020-06-03 11:57:14.230154 I Setup Real-time signal 0 handler 2020-06-03 11:57:14.230159 I Setup User defined signal 1 handler 2020-06-03 11:57:14.230163 I Setup User defined signal 2 handler 2020-06-03 11:57:14.230167 I Setup Hangup handler 2020-06-03 11:57:14.230249 C mythfrontend version: fixes/31 [v31.0-48-gc89a7e3771] www.mythtv.org 2020-06-03 11:57:14.230253 C Qt version: compile: 5.12.8, runtime: 5.12.8 2020-06-03 11:57:14.230280 I Ubuntu 20.04 LTS (x86_64) 2020-06-03 11:57:14.230281 N Enabled verbose msgs: general playback 2020-06-03 11:57:14.230291 N Setting Log Level to LOG_INFO 2020-06-03 11:57:14.240541 N Using runtime prefix = /usr/local 2020-06-03 11:57:14.240544 I Added logging to the console 2020-06-03 11:57:14.240545 N Using configuration directory = /home/rip/.mythtv 2020-06-03 11:57:14.240570 I Assumed character encoding: en_GB.UTF-8 2020-06-03 11:57:14.240909 I Loading en_gb translation for module mythfrontend 2020-06-03 11:57:14.241085 I Empty LocalHostName?. This is typical. 2020-06-03 11:57:14.241090 I Using a profile name of: 'rip' (Usually the same as this host's name.) 2020-06-03 11:57:14.241166 I Start up testing connections. DB 192.168.0.108, BE , attempt 0, status dbAwake, Delay: 2000 2020-06-03 11:57:16.318085 N Setting QT default locale to en_GB 2020-06-03 11:57:16.318108 I Current locale en_GB 2020-06-03 11:57:16.318201 N Reading locale defaults from /usr/local/share/mythtvlocales/en_gb.xml 2020-06-03 11:57:16.440027 I Display: Screen 'HDMI-2' not found, defaulting to primary screen (HDMI2) 2020-06-03 11:57:16.440061 I Display: Using screen 'HDMI2' (Make: HPN Model: HP 22f-) 2020-06-03 11:57:16.440083 I Display: Qt screen pixel ratio: 1.00 2020-06-03 11:57:16.440113 I Display: Geometry: 1920x1080+0+0 Size(Qt): 500mmx300mm 2020-06-03 11:57:16.440136 I Display: Total virtual geometry: 3840x1392+0+0 2020-06-03 11:57:16.443064 I Display: Available modes: 2020-06-03 11:57:16.443160 I 1920x1080 74.97 60.00 59.94 50.00 2020-06-03 11:57:16.443183 I 1680x1050 59.88 2020-06-03 11:57:16.443197 I 1600x900 60.00 2020-06-03 11:57:16.443209 I 1440x900 59.90 2020-06-03 11:57:16.443222 I 1280x1024 60.02 2020-06-03 11:57:16.443233 I 1280x800 59.91 2020-06-03 11:57:16.443250 I 1280x720 60.00 59.94 50.00 2020-06-03 11:57:16.443263 I 1024x768 60.00 2020-06-03 11:57:16.443275 I 800x600 60.32 2020-06-03 11:57:16.443287 I 720x576 50.00 2020-06-03 11:57:16.443301 I 720x480 60.00 59.94 2020-06-03 11:57:16.443312 I 720x400 70.08 2020-06-03 11:57:16.443325 I 640x480 60.00 59.94 2020-06-03 11:57:16.448220 N Display: Desktop video mode: 1920x1080 50.000Hz 2020-06-03 11:57:16.448230 N Display: Display has custom colourspace 2020-06-03 11:57:16.572171 I ScreenSaverDBus: Created for DBus service: org.freedesktop.ScreenSaver? 2020-06-03 11:57:16.575419 I ScreenSaverDBus: Created for DBus service: org.gnome.SessionManager? 2020-06-03 11:57:16.575889 I Starting process manager 2020-06-03 11:57:16.575943 I Starting IO manager (read) 2020-06-03 11:57:16.577617 I Starting IO manager (write) 2020-06-03 11:57:16.577725 I Starting process signal handler 2020-06-03 11:57:16.629216 I ScreenSaverX11Private: DPMS is active. 2020-06-03 11:57:16.854664 I Power: On AC power 2020-06-03 11:57:16.854682 I Power: Supported actions: Suspend,Restart,Shutdown 2020-06-03 11:57:16.888118 I Listening on TCP 0.0.0.0:6547 2020-06-03 11:57:16.897967 I Listening on TCP [::]:6547 2020-06-03 11:57:19.680477 I Loading en_gb translation for module mythfrontend 2020-06-03 11:57:19.736122 E LIRC: Failed to connect to Unix socket '/var/run/lirc/lircd'

eno: No such file or directory (2)

2020-06-03 11:57:19.736195 I No joystick configuration found, not enabling joystick control 2020-06-03 11:57:19.736204 I UDPListener: Enabling 2020-06-03 11:57:19.742047 I Binding to UDP 0.0.0.0:6948 2020-06-03 11:57:19.742176 I Binding to UDP [::]:6948 2020-06-03 11:57:20.220112 I Using Frameless Window 2020-06-03 11:57:20.220116 I Using Full Screen Window 2020-06-03 11:57:20.241961 I Display: Have main widget 2020-06-03 11:57:20.241965 I Display: Have main window 2020-06-03 11:57:20.246383 I Display: Screen 'HDMI-2' not found, defaulting to primary screen (HDMI2) 2020-06-03 11:57:20.256372 I UI Screen Resolution: 1920 x 1080 2020-06-03 11:57:20.299138 I OpenGL: OpenGL vendor : Intel Open Source Technology Center 2020-06-03 11:57:20.299144 I OpenGL: OpenGL renderer : Mesa DRI Intel(R) HD Graphics (HSW GT1) 2020-06-03 11:57:20.299146 I OpenGL: OpenGL version : 3.0 Mesa 20.0.4 2020-06-03 11:57:20.299151 I OpenGL: Qt platform : xcb 2020-06-03 11:57:20.299206 I OpenGL: EGL display : Yes 2020-06-03 11:57:20.299208 I OpenGL: EGL images : Yes 2020-06-03 11:57:20.299214 I OpenGL: Qt OpenGL format : OpenGL 3.0 2020-06-03 11:57:20.299216 I OpenGL: Qt OpenGL surface : RGBA: 8880 Depth: 0 Stencil: 0 2020-06-03 11:57:20.299221 I OpenGL: Max texture size : 16384 2020-06-03 11:57:20.299223 I OpenGL: Max texture units : 192 2020-06-03 11:57:20.299226 I OpenGL: Shaders : Yes 2020-06-03 11:57:20.299228 I OpenGL: NPOT textures : Yes 2020-06-03 11:57:20.299231 I OpenGL: Multitexturing : Yes 2020-06-03 11:57:20.299233 I OpenGL: Rectangular textures : Yes 2020-06-03 11:57:20.299236 I OpenGL: Buffer mapping : Yes 2020-06-03 11:57:20.299237 I OpenGL: Framebuffer objects : Yes 2020-06-03 11:57:20.299240 I OpenGL: 16bit framebuffers : Yes 2020-06-03 11:57:20.299242 I OpenGL: Unpack Subimage : Yes 2020-06-03 11:57:20.299247 I OpenGL: GL_RED/GL_R8 : Yes 2020-06-03 11:57:20.304852 I OpenGL: Initialised MythRenderOpenGL 2020-06-03 11:57:20.304858 I OpenGL: Using full range output 2020-06-03 11:57:20.316086 I MythUIHelper: Pruning cache directory: /home/rip/.mythtv/cache/remotecache 2020-06-03 11:57:20.316516 I MythUIHelper: Kept 24 files, deleted 0 files, stat error on 0 files 2020-06-03 11:57:20.316535 I MythUIHelper: Pruning cache directory: /home/rip/.mythtv/cache/thumbnails 2020-06-03 11:57:20.316992 I MythUIHelper: Kept 99 files, deleted 0 files, stat error on 0 files 2020-06-03 11:57:20.964526 I MythCoreContext::ConnectCommandSocket?(): Connecting to backend server: 192.168.0.108:6543 (try 1 of 1) 2020-06-03 11:57:20.975374 I MythCoreContext::CheckProtoVersion?(): Using protocol version 91 BuzzOff? 2020-06-03 11:57:21.150044 I CECAdapter: Using physical address 1.0.0.0 from EDID 2020-06-03 11:57:21.269895 E CECAdapter: Failed to find any CEC devices. 2020-06-03 11:57:21.770198 I CECAdapter: Closing down CEC. 2020-06-03 11:57:21.776452 E RAOP Conn: Failed to read key from: /home/rip/.mythtv/RAOPKey.rsa 2020-06-03 11:57:21.776475 E RAOP Device: Aborting startup - no key found. 2020-06-03 11:57:21.782396 I AirPlay?: Created airplay objects. 2020-06-03 11:57:21.782777 I Listening on TCP 0.0.0.0:5100 2020-06-03 11:57:21.782882 I Listening on TCP [::]:5100 2020-06-03 11:57:21.843577 I Current MythTV Schema Version (DBSchemaVer): 1361 2020-06-03 11:57:21.852559 E VDPAUHelp: Error at decoders/mythvdpauhelper.cpp:254 (#1, Unknown) 2020-06-03 11:57:21.852569 E VDPAUHelp: Failed to create VDPAU device. 2020-06-03 11:57:21.852681 I VDPAUHelp: VDPAU is NOT available 2020-06-03 11:57:21.869938 I MythCodecContext?: Created hardware device 'vaapi' 2020-06-03 11:57:21.869948 I Creating dummy interop 2020-06-03 11:57:21.869975 I VAAPIDec: Supported/available VAAPI decoders: 2020-06-03 11:57:21.871080 I MythCodecContext?: Created hardware device 'vaapi' 2020-06-03 11:57:21.871088 I Creating dummy interop 2020-06-03 11:57:21.871195 I MythCodecContext?: vaapi device context finished 2020-06-03 11:57:21.871207 I MythCodecContext?: Calling default device context free 2020-06-03 11:57:21.871435 I VAAPIDec: EGL DMABUF available for best VAAPI performance 2020-06-03 11:57:21.871449 I VAAPIDec: MPEG2 Simple (Max size: 4096x4096) 2020-06-03 11:57:21.871454 I VAAPIDec: MPEG2 Main (Max size: 4096x4096) 2020-06-03 11:57:21.871459 I VAAPIDec: H264 Constrained (Max size: 4096x4096) 2020-06-03 11:57:21.871463 I VAAPIDec: H264 Main (Max size: 4096x4096) 2020-06-03 11:57:21.871467 I VAAPIDec: H264 High (Max size: 4096x4096) 2020-06-03 11:57:21.871474 I VAAPIDec: VC1 Simple (Max size: 4096x4096) 2020-06-03 11:57:21.871477 I VAAPIDec: VC1 Main (Max size: 4096x4096) 2020-06-03 11:57:21.871481 I VAAPIDec: VC1 Advanced (Max size: 4096x4096) 2020-06-03 11:57:21.871485 I MythCodecContext?: vaapi device context finished 2020-06-03 11:57:21.871488 I MythCodecContext?: Calling default device context free 2020-06-03 11:57:21.871751 E NVDECInterop: Failed to load functions 2020-06-03 11:57:21.871767 I NVDEC: No NVDEC decoders found 2020-06-03 11:57:21.872128 I V4L2_M2M: No V4L2 decoders found 2020-06-03 11:57:21.872418 I DRMPRIMECtx: DRM PRIME codecs supported: None 2020-06-03 11:57:21.872459 I VDP: decoder<->render support: ffmpeg null opengl opengl-yv12 2020-06-03 11:57:21.872465 I VDP: decoder<->render support: vaapi opengl-hw 2020-06-03 11:57:21.872469 I VDP: decoder<->render support: vaapi-dec null opengl opengl-yv12 2020-06-03 11:57:21.931733 N VDP: Ignoring profile 204 (decoder nvdec is not available) 2020-06-03 11:57:21.989891 N VDP: Ignoring profile 205 (decoder v4l2-dec is not available) 2020-06-03 11:57:21.989929 N VDP: Ignoring profile 206 (decoder v4l2 is not available) 2020-06-03 11:57:22.030158 N VDP: Ignoring profile 48 (decoder vdpau is not available) 2020-06-03 11:57:22.041679 N VDP: Ignoring profile 49 (decoder vdpau is not available) 2020-06-03 11:57:22.041727 N VDP: Ignoring profile 50 (decoder vdpau is not available) 2020-06-03 11:57:22.055165 N VDP: Ignoring profile 51 (decoder vdpau is not available) 2020-06-03 11:57:22.693881 I Bonjour: Service registration complete: name 'MythTV on rip' type '_airplay._tcp.' domain: 'local.' 2020-06-03 11:57:25.305320 N Registering Internal as a media playback plugin. 2020-06-03 11:57:25.318874 A MMUnix:CheckMountable: DBus interface error: The name org.freedesktop.UDisks was not provided by any .service files 2020-06-03 11:57:25.321042 W MMUnix:UDisks2 service found. Media Monitor does not support this yet! 2020-06-03 11:57:25.330191 W No plugins directory /usr/local/lib/mythtv/plugins 2020-06-03 11:57:25.374273 N Found mainmenu.xml for theme 'Steppes' 2020-06-03 11:57:25.413353 I Checking for theme updates every hour 2020-06-03 11:57:25.413679 I Registering HouseKeeperTask? 'HardwareProfiler?'. 2020-06-03 11:57:25.430550 I Queueing HouseKeeperTask? 'HardwareProfiler?'. 2020-06-03 11:57:25.430562 I Starting HouseKeeper?. 2020-06-03 11:57:25.556697 I Bonjour: Service registration complete: name 'Mythfrontend on rip' type '_mythfrontend._tcp.' domain: 'local.' 2020-06-03 11:57:31.095614 I TV::TV(): Creating TV object 2020-06-03 11:57:31.134446 I TV::TV(): Finished creating TV object 2020-06-03 11:57:31.134488 N Suspending idle timer 2020-06-03 11:57:31.162980 I TV::Init(): Created TvPlayWindow?. 2020-06-03 11:57:31.219794 I TV::HandleStateChange?(): Attempting to change from None to WatchingPreRecorded? 2020-06-03 11:57:31.258757 I FileRingBuf?(myth://tv/16940_20200601200000.ts): OpenFile?(myth://tv/16940_20200601200000.ts, 2000 ms) 2020-06-03 11:57:31.280591 I TV::StartPlayer?(): Elapsed time since TV constructor was called: 184 ms 2020-06-03 11:57:31.690932 N AudioPlayer?: Enabling Audio 2020-06-03 11:57:31.690945 I Player(0): Opening 'myth://tv/16940_20200601200000.ts' 2020-06-03 11:57:31.917696 I VDP: Accepting: cmp() w() h() framerate() codecs() dec(ffmpeg) cpus(2) skiploop(enabled) rend(opengl) deint(high,high) 2020-06-03 11:57:31.936567 I AFD: PlayerFlags?: 0xc0, AudioReadAhead?: 510 msec 2020-06-03 11:57:31.936611 I Player(0): Stretch Factor 1, allow passthru 2020-06-03 11:57:31.972125 I AFD: Buffer size: 32768 Streamed 0 Seekable 1 Available 1245184 2020-06-03 11:57:32.708711 I AFD: Stream #0: ID: 0x157c Codec ID: H264 Type: Video(1920x1080) Bitrate: 0 2020-06-03 11:57:32.708732 I AFD: Stream #1: ID: 0x157e Codec ID: MP2 Type: Audio Bitrate: 256000 2020-06-03 11:57:32.708750 I AFD: codec MP2 has 2 channels 2020-06-03 11:57:32.708758 I AFD: Looking for decoder for MP2 2020-06-03 11:57:32.711360 I AFD: Opened codec 0x555ef1a23c40, id(MP2) type(Audio) 2020-06-03 11:57:32.711921 I AFD: Stream #2: ID: 0x1580 Codec ID: DVB_SUBTITLE Type: Subtitle Bitrate: 0 2020-06-03 11:57:32.711932 I AFD: subtitle codec (Subtitle) 2020-06-03 11:57:32.711939 I AFD: Looking for decoder for DVB_SUBTITLE 2020-06-03 11:57:32.712087 I AFD: Opened codec 0x555ef1bb2080, id(DVB_SUBTITLE) type(Subtitle) 2020-06-03 11:57:32.712136 I AFD: Subtitle track #1 is A/V stream #2 and is in the English language(6647399). 2020-06-03 11:57:32.712152 I AFD: Stream #3: ID: 0x157f Codec ID: DVB_TELETEXT Type: Subtitle Bitrate: 0 2020-06-03 11:57:32.712210 I AFD: Teletext stream #0 (Caption) is in the English language on page 8 136. 2020-06-03 11:57:32.712225 I AFD: Teletext stream #1 (Menu) is in the English language on page 8 136. 2020-06-03 11:57:32.712243 I AFD: subtitle codec (Subtitle) 2020-06-03 11:57:32.712256 I AFD: Stream #4: ID: 0x157d Codec ID: AC3 Type: Audio Bitrate: 192000 2020-06-03 11:57:32.712267 I AFD: codec AC3 has 2 channels 2020-06-03 11:57:32.712274 I AFD: Looking for decoder for AC3 2020-06-03 11:57:32.712775 I AFD: Opened codec 0x555ef1bec280, id(AC3) type(Audio) 2020-06-03 11:57:32.712851 I AFD: Stream #5: ID: 0xf09 Codec ID: DSMCC_B Type: Data Bitrate: 0 2020-06-03 11:57:32.712860 I AFD: data codec (Data) 2020-06-03 11:57:32.712870 I AFD: Stream #6: ID: 0xf07 Codec ID: DSMCC_B Type: Data Bitrate: 0 2020-06-03 11:57:32.712875 I AFD: data codec (Data) 2020-06-03 11:57:32.712883 I AFD: Stream #7: ID: 0xf06 Codec ID: DSMCC_B Type: Data Bitrate: 0 2020-06-03 11:57:32.712889 I AFD: data codec (Data) 2020-06-03 11:57:32.712894 I AFD: Trying to select best video track 2020-06-03 11:57:32.712975 I AFD: Selected track #0: ID: 0x157c Codec ID: H264 Profile: High Type: Video(1920x1080) Bitrate: 500000 2020-06-03 11:57:32.713069 I AFD: Selected FPS: 25 (Avg:25 Mult:1 Codec:0 Container:90000 Estimated:25) 2020-06-03 11:57:32.713172 I VDP: LoadBestPreferences?(1920x1080, 25.000, h264) 2020-06-03 11:57:32.713211 I VDP: LoadBestPreferences? result: priority:1 width: height: fps: codecs: 2020-06-03 11:57:32.713227 I VDP: decoder:ffmpeg renderer:opengl deint0:high deint1:high cpus:2 2020-06-03 11:57:32.713250 I AFD: Using 2 CPUs for decoding 2020-06-03 11:57:32.713261 I AFD: InitVideoCodec? ID:H264 Type:Video Size:1920x1080 2020-06-03 11:57:32.713366 I Player(0): SetFrameInterval? Interval:40000 Speed:1 Scan:Progressive Scan (Multiplier: 1) 2020-06-03 11:57:32.713389 I Player(0): detectInterlace(Detect Scan, Interlaced Scan, 25, 1080) ->Interlaced Scan 2020-06-03 11:57:32.713482 I AFD: Using ffmpeg for video decoding 2020-06-03 11:57:32.714012 I AFD: Opened codec 0x555ef1bb4b40, id(H264) type(Video) 2020-06-03 11:57:32.769102 I AOBase: Opening audio device 'sysdefault:CARD=PCH' ch 2(2) sr 48000 sf signed 32 bit reenc 0 2020-06-03 11:57:32.805254 W ALSA: Requested 500000us got 170666 buffer time 2020-06-03 11:57:32.805331 W ALSA: Try to manually increase audio buffer with: echo 192 | sudo tee /proc/asound/card1/pcm0p/sub0/prealloc 2020-06-03 11:57:32.828939 E ALSA: no playback control PCM found on mixer device default 2020-06-03 11:57:32.828949 E ALSA: Unable to open audio mixer. Volume control disabled 2020-06-03 11:57:32.829081 I Dec: Selected track #1 (type 2) in the Unknown language(0) 2020-06-03 11:57:32.829109 I Dec: Selected track #1 (type 3) in the English language(6647399) 2020-06-03 11:57:32.829118 I Dec: Selected track #1 (type 6) in the English language(6647399) 2020-06-03 11:57:32.829146 I Dec: Selected track #1 (type 7) in the English language(6647399) 2020-06-03 11:57:32.829164 I Dec: Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0) 2020-06-03 11:57:32.932835 I Dec: Position map filled from DB to: 97498 2020-06-03 11:57:32.939589 I Dec: Duration map filled from DB to: 97498 2020-06-03 11:57:32.940212 I Dec: SyncPositionMap? prerecorded, from DB: 4114 entries 2020-06-03 11:57:32.940225 I Dec: SyncPositionMap?, new totframes: 97498, new length: 3253, posMap size: 4114 2020-06-03 11:57:32.958623 I AFD: Position map found 2020-06-03 11:57:32.958633 I AFD: Successfully opened decoder for file: "myth://tv/16940_20200601200000.ts". novideo(0) 2020-06-03 11:57:33.036165 I VideoOutput?: Allowed renderers for H.264 ffmpeg (Decoder: ffmpeg): 'opengl,opengl-yv12' 2020-06-03 11:57:33.036181 I VDP: Safe renderers for 'ffmpeg': null,opengl,opengl-yv12 2020-06-03 11:57:33.036190 I VideoOutput?: Allowed renderers (filt: ffmpeg): opengl,opengl-yv12 2020-06-03 11:57:33.075286 I VDP: Accepting: cmp() w() h() framerate() codecs() dec(ffmpeg) cpus(2) skiploop(enabled) rend(opengl) deint(high,high) 2020-06-03 11:57:33.075320 I VDP: LoadBestPreferences?(1920x1080, 25.000, h264) 2020-06-03 11:57:33.075346 I VDP: LoadBestPreferences? result: priority:1 width: height: fps: codecs: 2020-06-03 11:57:33.075364 I VDP: decoder:ffmpeg renderer:opengl deint0:high deint1:high cpus:2 2020-06-03 11:57:33.075383 I VideoOutput?: Preferred renderer: opengl 2020-06-03 11:57:33.075389 I VideoOutput?: Trying video renderer: 'opengl' 2020-06-03 11:57:33.388237 I GLVid: Chroma upsampling filter disabled 2020-06-03 11:57:33.388317 I Clearing OpenGL painter cache. 2020-06-03 11:57:33.432716 I VideoWin?: Window using screen HDMI2 1920x1080 2020-06-03 11:57:33.432733 I VideoWin?: Window Rect: 1920x1080+0+0 2020-06-03 11:57:33.432747 I VideoWin?: Display Rect: 1920x1013+0+33 Aspect: 1.66667 2020-06-03 11:57:33.432757 I VideoWin?: Video Rect: 1920x1080+0+0 Aspect: 1.77778 2020-06-03 11:57:33.432785 I ColourSpace?: PictureAttributes?: Brightness,Contrast,Colour,Hue,Range 2020-06-03 11:57:33.432838 I VideoOutput?: Display aspect ratio: 1.66667 (Detected) 2020-06-03 11:57:33.454486 I Created 18 YUV420P (1920x1080) video buffers 2020-06-03 11:57:33.535476 I Player(0): Decoder thread starting. 2020-06-03 11:57:33.535496 I AFD: DoFastForward?(6035 (0), do discard frames) 2020-06-03 11:57:33.535504 I Dec: DoFastForward?(6035 (0), do discard frames) 2020-06-03 11:57:33.535565 I Dec: FindPosition?(6035, search not adjusted) -->

[256:6031(283901432),257:6055(284664148)]

2020-06-03 11:57:33.643704 I AFD: SeekReset?(6031, 4, do flush, do discard) 2020-06-03 11:57:33.643800 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA 2020-06-03 11:57:33.643861 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA -- done 2020-06-03 11:57:33.643903 I AFD: SeekReset?() flushing 2020-06-03 11:57:33.886016 I Player(0): ClearAfterSeek?(0) 2020-06-03 11:57:33.939365 I OSD: Loaded window osd_message 2020-06-03 11:57:33.942921 I OSD: Loaded window osd_input 2020-06-03 11:57:33.961917 I OSD: Loaded window program_info 2020-06-03 11:57:33.988176 I OSD: Loaded window browse_info 2020-06-03 11:57:33.992281 I OSD: Loaded window osd_status 2020-06-03 11:57:33.996716 I OSD: Loaded window osd_program_editor 2020-06-03 11:57:34.002395 I OSD: Loaded window osd_debug 2020-06-03 11:57:34.002405 I OSD: Loaded OSD: size 1920x1080 offset 0+0 2020-06-03 11:57:34.002462 I OSD: Created window aa_OSD_SUBTITLES 2020-06-03 11:57:34.044784 I Player(0): ClearAfterSeek?(0) 2020-06-03 11:57:34.044832 I VideoOutput?: SetDeinterlacing? (Doublerate 1): Single High|CPU Double High|CPU 2020-06-03 11:57:34.044851 I Player(0): Display Refresh Rate: 50.000 Video Frame Rate: 25.000 2020-06-03 11:57:34.044872 I Player(0): SetFrameInterval? Interval:40000 Speed:1 Scan:Interlaced Scan (Multiplier: 1) 2020-06-03 11:57:34.045008 I playCtx: StartPlaying?(): took 0 ms to start player. 2020-06-03 11:57:34.045028 I TV::StartPlayer?(): Created player. 2020-06-03 11:57:34.045100 I TV::HandleStateChange?(): Changing from None to WatchingPreRecorded? 2020-06-03 11:57:34.079101 I TV::HandleStateChange?(): Main UI disabled. 2020-06-03 11:57:34.079159 I TV::StartTV(): Entering main playback loop. 2020-06-03 11:57:34.088648 I ScreenSaverDBus: Successfully inhibited screensaver via org.freedesktop.ScreenSaver?. cookie 1780795432. nom nom 2020-06-03 11:57:34.089052 W ScreenSaverDBus: Failed to disable screensaver: Type of message, “(ss)”, does not match expected type “(susu)” 2020-06-03 11:57:34.089367 I ScreenSaverX11Private: DPMS Deactivated 1 2020-06-03 11:57:34.089492 I Player(0): Waiting for video buffers... 2020-06-03 11:57:34.130398 I OSD: Created window bb_OSD_INTERACTIVE 2020-06-03 11:57:34.130435 I Player(0): Interlaced frame seen after 2 progressive frames 2020-06-03 11:57:34.130440 I Player(0): Locking scan to Interlaced. 2020-06-03 11:57:34.130452 I VideoOutput?: SetDeinterlacing? (Doublerate 1): Single High|CPU Double High|CPU 2020-06-03 11:57:34.130512 I MythDeint?: Deinterlacer change: 0x0 None dr:0 tff:1 -> 1920x1080 YUV420P dr:1 tff:1 2020-06-03 11:57:34.133041 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.140764 W GLVid: New frame format: None:None 1920x1080 (Tex: 2D) -> YUV420P:YUY2 1920x1080 (Tex: 2D) 2020-06-03 11:57:34.140932 I GLVid: Created 1 input textures for 'opengl' 2020-06-03 11:57:34.141317 I ColourSpace?: Input : bt709(Detected) Depth:8 Range:Limited 2020-06-03 11:57:34.141325 I ColourSpace?: Input : Primaries:bt709 Transfer: bt709 2020-06-03 11:57:34.141328 I ColourSpace?: Output: Range:Full Primaries: bt709 2020-06-03 11:57:34.147496 I GLVid: Resizing from 1920x1080 to 1920x1013 for Sampling 2020-06-03 11:57:34.202231 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:34.202312 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:34.230899 I Player(0): AV Sync: Audio ahead by 986 ms 2020-06-03 11:57:34.270763 I Player(0): AV Sync: Audio ahead by 988 ms 2020-06-03 11:57:34.284956 I Player(0): Dropping frame: Video is behind by 47ms 2020-06-03 11:57:34.285020 I Player(0): AV Sync: Audio ahead by 915 ms 2020-06-03 11:57:34.285041 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.289764 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.308354 I Player(0): Dropping frame: Video is behind by 46ms 2020-06-03 11:57:34.308419 I Player(0): AV Sync: Audio ahead by 835 ms 2020-06-03 11:57:34.308443 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.313756 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.333225 I Player(0): Dropping frame: Video is behind by 45ms 2020-06-03 11:57:34.333334 I Player(0): AV Sync: Audio ahead by 780 ms 2020-06-03 11:57:34.333365 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.348725 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.358071 I Player(0): Dropping frame: Video is behind by 40ms 2020-06-03 11:57:34.358101 I Player(0): AV Sync: Audio ahead by 725 ms 2020-06-03 11:57:34.358112 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.358473 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.386917 I Player(0): Dropping frame: Video is behind by 36ms 2020-06-03 11:57:34.386986 I Player(0): AV Sync: Audio ahead by 670 ms 2020-06-03 11:57:34.387018 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.389057 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.408700 I Player(0): AV Sync: Audio ahead by 654 ms 2020-06-03 11:57:34.435690 I Player(0): Dropping frame: Video is behind by 51ms 2020-06-03 11:57:34.435745 I Player(0): AV Sync: Audio ahead by 582 ms 2020-06-03 11:57:34.435764 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.437383 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.455533 I Player(0): AV Sync: Audio ahead by 550 ms 2020-06-03 11:57:34.484503 I Player(0): Dropping frame: Video is behind by 54ms 2020-06-03 11:57:34.484655 I Player(0): AV Sync: Audio ahead by 468 ms 2020-06-03 11:57:34.484749 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.497023 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.509674 I Player(0): Dropping frame: Video is behind by 30ms 2020-06-03 11:57:34.519411 I Player(0): AV Sync: Audio ahead by 388 ms 2020-06-03 11:57:34.519434 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.528511 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.543275 I Player(0): AV Sync: Audio ahead by 380 ms 2020-06-03 11:57:34.567503 I Player(0): AV Sync: Audio ahead by 353 ms 2020-06-03 11:57:34.597922 I Player(0): Dropping frame: Video is behind by 33ms 2020-06-03 11:57:34.598060 I Player(0): AV Sync: Audio ahead by 261 ms 2020-06-03 11:57:34.598093 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.614244 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.628465 I Player(0): AV Sync: Audio ahead by 259 ms 2020-06-03 11:57:34.656678 I Player(0): AV Sync: Audio ahead by 225 ms 2020-06-03 11:57:34.697199 I Player(0): AV Sync: Audio ahead by 188 ms 2020-06-03 11:57:34.736597 I Player(0): Dropping frame: Video is behind by 36ms 2020-06-03 11:57:34.736634 I Player(0): AV Sync: Audio ahead by 120 ms 2020-06-03 11:57:34.736646 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:34.737044 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:34.758400 I Player(0): AV Sync: Audio ahead by 101 ms 2020-06-03 11:57:34.797195 I Player(0): AV Sync: Audio ahead by 82 ms 2020-06-03 11:57:34.837181 I Player(0): AV Sync: Audio ahead by 80 ms 2020-06-03 11:57:34.876963 I Player(0): AV Sync: Audio ahead by 84 ms 2020-06-03 11:57:34.916802 I Player(0): AV Sync: Audio ahead by 80 ms 2020-06-03 11:57:34.956608 I Player(0): AV Sync: Audio ahead by 92 ms 2020-06-03 11:57:34.997152 I Player(0): AV Sync: Audio ahead by 80 ms 2020-06-03 11:57:35.047586 I Player(0): Dropping frame: Video is behind by 37ms 2020-06-03 11:57:35.047667 I Player(0): AV Sync: Audio ahead by 45 ms 2020-06-03 11:57:35.047699 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:35.052971 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:35.053058 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:35.057488 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:35.070934 I Player(0): AV Sync: Audio ahead by 53 ms 2020-06-03 11:57:35.107376 I Player(0): AV Sync: Audio ahead by 34 ms 2020-06-03 11:57:35.143888 I Player(0): AV Sync: Audio ahead by 26 ms 2020-06-03 11:57:35.182238 I Player(0): AV Sync: Audio ahead by 29 ms 2020-06-03 11:57:35.221944 I Player(0): AV Sync: Audio ahead by 22 ms 2020-06-03 11:57:35.257250 I Player(0): AV Sync: Audio ahead by 32 ms 2020-06-03 11:57:35.337018 I Player(0): AV Sync: Audio ahead by 22 ms 2020-06-03 11:57:35.416922 I Player(0): AV Sync: Audio ahead by 23 ms 2020-06-03 11:57:35.497143 I Player(0): AV Sync: Audio ahead by 21 ms 2020-06-03 11:57:35.705242 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:35.705316 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:36.530809 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:36.530841 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:57:37.397310 I Player(0): FPS: 30.61 Mean: 32664 Std.Dev: 12787 CPUs: 14% 14% 2020-06-03 11:57:38.505782 I Player(0): Dropping frame: Video is behind by 49ms 2020-06-03 11:57:38.506040 I Player(0): AV Sync: Audio behind by 38 ms 2020-06-03 11:57:38.506114 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:57:38.521345 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:57:38.534560 I Player(0): AV Sync: Audio ahead by 37 ms 2020-06-03 11:57:38.570075 I Player(0): AV Sync: Audio ahead by 22 ms 2020-06-03 11:57:41.397190 I Player(0): FPS: 25.00 Mean: 39995 Std.Dev: 8147 CPUs: 48% 49% 2020-06-03 11:57:45.396858 I Player(0): FPS: 25.00 Mean: 39993 Std.Dev: 361 CPUs: 42% 45% 2020-06-03 11:57:48.894376 I TV::LoadFileHelper?(): Loading menu /home/rip/.mythtv/menu_playback.xml 2020-06-03 11:57:48.894402 I TV::LoadFileHelper?(): Loading menu /home/rip/.mythtv/themes/Steppes/menu_playback.xml 2020-06-03 11:57:48.894409 I TV::LoadFileHelper?(): Loading menu /usr/local/share/mythtv/themes/default-wide/menu_playback.xml 2020-06-03 11:57:48.894417 I TV::LoadFileHelper?(): Loading menu /usr/local/share/mythtv/themes/default/menu_playback.xml 2020-06-03 11:57:48.895029 I TV::LoadFileHelper?(): Loading menu /home/rip/.mythtv/menu_playback_compact.xml 2020-06-03 11:57:48.895038 I TV::LoadFileHelper?(): Loading menu /home/rip/.mythtv/themes/Steppes/menu_playback_compact.xml 2020-06-03 11:57:48.895044 I TV::LoadFileHelper?(): Loading menu /usr/local/share/mythtv/themes/default-wide/menu_playback_compact.xml 2020-06-03 11:57:48.895050 I TV::LoadFileHelper?(): Loading menu /usr/local/share/mythtv/themes/default/menu_playback_compact.xml 2020-06-03 11:57:48.895093 I TV::LoadFileHelper?(): Loading menu /home/rip/.mythtv/menu_playback.xml 2020-06-03 11:57:48.895100 I TV::LoadFileHelper?(): Loading menu /home/rip/.mythtv/themes/Steppes/menu_playback.xml 2020-06-03 11:57:48.895105 I TV::LoadFileHelper?(): Loading menu /usr/local/share/mythtv/themes/default-wide/menu_playback.xml 2020-06-03 11:57:48.895111 I TV::LoadFileHelper?(): Loading menu /usr/local/share/mythtv/themes/default/menu_playback.xml 2020-06-03 11:57:48.938320 I Player(0): AV Sync: Audio ahead by 31 ms 2020-06-03 11:57:48.970300 I Player(0): AV Sync: Audio ahead by 22 ms 2020-06-03 11:57:49.399510 I Player(0): FPS: 24.99 Mean: 40023 Std.Dev: 4883 CPUs: 48% 45% 2020-06-03 11:57:53.757602 I Player(0): FPS: 25.03 Mean: 39951 Std.Dev: 1037 CPUs: 47% 46% 2020-06-03 11:57:54.758328 I Player(0): FPS: 24.99 Mean: 40021 Std.Dev: 1237 CPUs: 43% 42% 2020-06-03 11:57:55.757688 I Player(0): FPS: 25.02 Mean: 39967 Std.Dev: 1467 CPUs: 43% 44% 2020-06-03 11:57:56.758492 I Player(0): FPS: 24.99 Mean: 40023 Std.Dev: 1992 CPUs: 45% 42% 2020-06-03 11:57:57.757738 I Player(0): FPS: 25.02 Mean: 39961 Std.Dev: 1157 CPUs: 44% 44% 2020-06-03 11:57:58.758860 I Player(0): FPS: 25.05 Mean: 39927 Std.Dev: 1205 CPUs: 45% 44% 2020-06-03 11:57:59.757714 I Player(0): FPS: 25.03 Mean: 39947 Std.Dev: 2318 CPUs: 39% 46% 2020-06-03 11:58:00.757069 I Player(0): FPS: 25.02 Mean: 39968 Std.Dev: 2332 CPUs: 41% 44% 2020-06-03 11:58:01.757676 I Player(0): FPS: 24.99 Mean: 40016 Std.Dev: 2258 CPUs: 43% 42% 2020-06-03 11:58:02.757947 I Player(0): FPS: 25.00 Mean: 40002 Std.Dev: 1208 CPUs: 45% 40% 2020-06-03 11:58:03.757571 I Player(0): FPS: 25.01 Mean: 39977 Std.Dev: 1032 CPUs: 44% 42% 2020-06-03 11:58:04.913537 I Player(0): Dropping frame: Video is behind by 47ms 2020-06-03 11:58:04.913657 I Player(0): AV Sync: Audio behind by 40 ms 2020-06-03 11:58:04.913687 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:58:04.925719 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:58:04.933641 I TV::HandleStateChange?(): Attempting to change from WatchingPreRecorded? to None 2020-06-03 11:58:04.933687 I Player(0): StopPlaying? - begin 2020-06-03 11:58:04.933736 I VidOutGL: (1): ULUUUUUUuUUUAUUULL 2020-06-03 11:58:04.933751 I VideoBuffers::DiscardFrames?(1): ULUUUUUUuUUUAUUULL 2020-06-03 11:58:04.933789 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA -- done 2020-06-03 11:58:04.934801 I Player(0): Decoder thread exiting. 2020-06-03 11:58:04.934970 I Player(0): Exited decoder loop. 2020-06-03 11:58:04.940757 I VidOutGL: (1): AAAAAAAAAAAAAAAAAA 2020-06-03 11:58:04.940774 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA 2020-06-03 11:58:04.940793 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA -- done 2020-06-03 11:58:04.940977 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:58:05.134036 I Player(0): StopPlaying? - end 2020-06-03 11:58:05.134081 I TV::StopStuff?(): Stopping ring buffer 2020-06-03 11:58:05.134262 I TV::StopStuff?(): Stopping player 2020-06-03 11:58:05.134290 I TV::HandleStateChange?(): Changing from WatchingPreRecorded? to None 2020-06-03 11:58:05.134323 I TV::StartTV(): Exiting main playback loop. 2020-06-03 11:58:05.134332 I TV::StartTV(): -- process events 2 begin 2020-06-03 11:58:05.134549 I ScreenSaverDBus: Screensaver uninhibited via org.freedesktop.ScreenSaver? 2020-06-03 11:58:05.134910 I ScreenSaverX11Private: DPMS Reactivated 1 2020-06-03 11:58:05.148615 I TV::StartTV(): -- process events 2 end 2020-06-03 11:58:05.158011 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.158038 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.161105 I TV::~TV(): -- lock 2020-06-03 11:58:05.161287 I Player(0): StopPlaying? - begin 2020-06-03 11:58:05.161305 I Player(0): Exited decoder loop. 2020-06-03 11:58:05.161313 I Player(0): StopPlaying? - end 2020-06-03 11:58:05.174294 N Resuming idle timer 2020-06-03 11:58:05.182657 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.182696 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.392684 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.392704 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.406129 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:05.406159 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:58:10.307435 I MythUIHelper: Pruning cache directory: /home/rip/.mythtv/cache/remotecache 2020-06-03 11:58:10.307876 I MythUIHelper: Kept 24 files, deleted 0 files, stat error on 0 files 2020-06-03 11:58:10.307925 I MythUIHelper: Pruning cache directory: /home/rip/.mythtv/cache/thumbnails 2020-06-03 11:58:10.309408 I MythUIHelper: Kept 99 files, deleted 0 files, stat error on 0 files 2020-06-03 11:58:10.312345 I Bonjour: De-registering service '_mythfrontend._tcp.' on 'Mythfrontend on rip' 2020-06-03 11:58:10.335048 W MythPainter?: 10 images not yet de-allocated. 2020-06-03 11:58:10.335216 I Clearing OpenGL painter cache. 2020-06-03 11:58:10.342633 I OpenGL: MythRenderOpenGL closing 2020-06-03 11:58:10.349491 I Display: Deleting 2020-06-03 11:58:10.351125 I RAOP Device: Cleaning up. 2020-06-03 11:58:10.351347 I AirPlay?: Cleaning up. 2020-06-03 11:58:10.351456 I Bonjour: De-registering service '_airplay._tcp.' on 'MythTV on rip' 2020-06-03 11:58:10.355607 I Shutting down UPnP client... 2020-06-03 11:58:12.742746 I PowerDBus: Closing interfaces 2020-06-03 11:58:12.744876 I Waiting for threads to exit. 2020-06-03 11:58:16.438749 I Exiting [freemheg] WARN Launch not found a [freemheg] WARN Launch not found startup ============================================================================= ============================================================================= Good log software v31.0-48-gc89a7e3771-dirty with this committ removed commit 31c68a14e816df1ff256280821aeaf8e5f14610d Author: Mark Kendall <mark.kendall@…> Date: Tue Mar 10 20:50:03 2020 +0000

MythDeinterlacer?: Don't cleanup deinterlacer if already deinterlaced

(cherry picked from commit 62a8f70bcb6aa1015f545808e3b9007666b6dbb8)

2020-06-03 11:53:53.549417 I Setup Interrupt handler 2020-06-03 11:53:53.549436 I Setup Terminated handler 2020-06-03 11:53:53.549442 I Setup Segmentation fault handler 2020-06-03 11:53:53.549447 I Setup Aborted handler 2020-06-03 11:53:53.549451 I Setup Bus error handler 2020-06-03 11:53:53.549456 I Setup Floating point exception handler 2020-06-03 11:53:53.549461 I Setup Illegal instruction handler 2020-06-03 11:53:53.549467 I Setup Real-time signal 0 handler 2020-06-03 11:53:53.549472 I Setup User defined signal 1 handler 2020-06-03 11:53:53.549477 I Setup User defined signal 2 handler 2020-06-03 11:53:53.549481 I Setup Hangup handler 2020-06-03 11:53:53.549563 C mythfrontend version: fixes/31 [v31.0-48-gc89a7e3771-dirty] www.mythtv.org 2020-06-03 11:53:53.549568 C Qt version: compile: 5.12.8, runtime: 5.12.8 2020-06-03 11:53:53.549597 I Ubuntu 20.04 LTS (x86_64) 2020-06-03 11:53:53.549598 N Enabled verbose msgs: general playback 2020-06-03 11:53:53.549609 N Setting Log Level to LOG_INFO 2020-06-03 11:53:53.559909 N Using runtime prefix = /usr/local 2020-06-03 11:53:53.559909 I Added logging to the console 2020-06-03 11:53:53.559913 N Using configuration directory = /home/rip/.mythtv 2020-06-03 11:53:53.559938 I Assumed character encoding: en_GB.UTF-8 2020-06-03 11:53:53.560287 I Loading en_gb translation for module mythfrontend 2020-06-03 11:53:53.560469 I Empty LocalHostName?. This is typical. 2020-06-03 11:53:53.560474 I Using a profile name of: 'rip' (Usually the same as this host's name.) 2020-06-03 11:53:53.560536 I Start up testing connections. DB 192.168.0.108, BE , attempt 0, status dbAwake, Delay: 2000 2020-06-03 11:53:55.631730 N Setting QT default locale to en_GB 2020-06-03 11:53:55.631754 I Current locale en_GB 2020-06-03 11:53:55.631847 N Reading locale defaults from /usr/local/share/mythtvlocales/en_gb.xml 2020-06-03 11:53:55.754214 I Display: Screen 'HDMI-2' not found, defaulting to primary screen (HDMI2) 2020-06-03 11:53:55.754248 I Display: Using screen 'HDMI2' (Make: HPN Model: HP 22f-) 2020-06-03 11:53:55.754271 I Display: Qt screen pixel ratio: 1.00 2020-06-03 11:53:55.754301 I Display: Geometry: 1920x1080+0+0 Size(Qt): 500mmx300mm 2020-06-03 11:53:55.754323 I Display: Total virtual geometry: 3840x1392+0+0 2020-06-03 11:53:55.757508 I Display: Available modes: 2020-06-03 11:53:55.757603 I 1920x1080 74.97 60.00 59.94 50.00 2020-06-03 11:53:55.757629 I 1680x1050 59.88 2020-06-03 11:53:55.757643 I 1600x900 60.00 2020-06-03 11:53:55.757655 I 1440x900 59.90 2020-06-03 11:53:55.757668 I 1280x1024 60.02 2020-06-03 11:53:55.757679 I 1280x800 59.91 2020-06-03 11:53:55.757696 I 1280x720 60.00 59.94 50.00 2020-06-03 11:53:55.757710 I 1024x768 60.00 2020-06-03 11:53:55.757722 I 800x600 60.32 2020-06-03 11:53:55.757734 I 720x576 50.00 2020-06-03 11:53:55.757748 I 720x480 60.00 59.94 2020-06-03 11:53:55.757759 I 720x400 70.08 2020-06-03 11:53:55.757773 I 640x480 60.00 59.94 2020-06-03 11:53:55.762555 N Display: Desktop video mode: 1920x1080 50.000Hz 2020-06-03 11:53:55.762563 N Display: Display has custom colourspace 2020-06-03 11:53:55.890133 I ScreenSaverDBus: Created for DBus service: org.freedesktop.ScreenSaver? 2020-06-03 11:53:55.894087 I ScreenSaverDBus: Created for DBus service: org.gnome.SessionManager? 2020-06-03 11:53:55.894792 I Starting process manager 2020-06-03 11:53:55.894966 I Starting IO manager (write) 2020-06-03 11:53:55.897088 I Starting IO manager (read) 2020-06-03 11:53:55.897259 I Starting process signal handler 2020-06-03 11:53:55.948998 I ScreenSaverX11Private: DPMS is active. 2020-06-03 11:53:56.176895 I Power: On AC power 2020-06-03 11:53:56.176920 I Power: Supported actions: Suspend,Restart,Shutdown 2020-06-03 11:53:56.208393 I Listening on TCP 0.0.0.0:6547 2020-06-03 11:53:56.221668 I Listening on TCP [::]:6547 2020-06-03 11:53:58.978481 I Loading en_gb translation for module mythfrontend 2020-06-03 11:53:59.034161 E LIRC: Failed to connect to Unix socket '/var/run/lirc/lircd'

eno: No such file or directory (2)

2020-06-03 11:53:59.034233 I No joystick configuration found, not enabling joystick control 2020-06-03 11:53:59.034241 I UDPListener: Enabling 2020-06-03 11:53:59.039306 I Binding to UDP 0.0.0.0:6948 2020-06-03 11:53:59.039428 I Binding to UDP [::]:6948 2020-06-03 11:53:59.478754 I Using Frameless Window 2020-06-03 11:53:59.478761 I Using Full Screen Window 2020-06-03 11:53:59.503698 I Display: Have main widget 2020-06-03 11:53:59.503703 I Display: Have main window 2020-06-03 11:53:59.508627 I Display: Screen 'HDMI-2' not found, defaulting to primary screen (HDMI2) 2020-06-03 11:53:59.517932 I UI Screen Resolution: 1920 x 1080 2020-06-03 11:53:59.545744 I OpenGL: OpenGL vendor : Intel Open Source Technology Center 2020-06-03 11:53:59.545750 I OpenGL: OpenGL renderer : Mesa DRI Intel(R) HD Graphics (HSW GT1) 2020-06-03 11:53:59.545752 I OpenGL: OpenGL version : 3.0 Mesa 20.0.4 2020-06-03 11:53:59.545756 I OpenGL: Qt platform : xcb 2020-06-03 11:53:59.545816 I OpenGL: EGL display : Yes 2020-06-03 11:53:59.545818 I OpenGL: EGL images : Yes 2020-06-03 11:53:59.545825 I OpenGL: Qt OpenGL format : OpenGL 3.0 2020-06-03 11:53:59.545827 I OpenGL: Qt OpenGL surface : RGBA: 8880 Depth: 0 Stencil: 0 2020-06-03 11:53:59.545831 I OpenGL: Max texture size : 16384 2020-06-03 11:53:59.545833 I OpenGL: Max texture units : 192 2020-06-03 11:53:59.545836 I OpenGL: Shaders : Yes 2020-06-03 11:53:59.545838 I OpenGL: NPOT textures : Yes 2020-06-03 11:53:59.545841 I OpenGL: Multitexturing : Yes 2020-06-03 11:53:59.545843 I OpenGL: Rectangular textures : Yes 2020-06-03 11:53:59.545846 I OpenGL: Buffer mapping : Yes 2020-06-03 11:53:59.545847 I OpenGL: Framebuffer objects : Yes 2020-06-03 11:53:59.545850 I OpenGL: 16bit framebuffers : Yes 2020-06-03 11:53:59.545853 I OpenGL: Unpack Subimage : Yes 2020-06-03 11:53:59.545854 I OpenGL: GL_RED/GL_R8 : Yes 2020-06-03 11:53:59.557521 I OpenGL: Initialised MythRenderOpenGL 2020-06-03 11:53:59.557526 I OpenGL: Using full range output 2020-06-03 11:53:59.567175 I MythUIHelper: Pruning cache directory: /home/rip/.mythtv/cache/remotecache 2020-06-03 11:53:59.567347 I MythUIHelper: Kept 24 files, deleted 0 files, stat error on 0 files 2020-06-03 11:53:59.567359 I MythUIHelper: Pruning cache directory: /home/rip/.mythtv/cache/thumbnails 2020-06-03 11:53:59.567769 I MythUIHelper: Kept 99 files, deleted 0 files, stat error on 0 files 2020-06-03 11:54:00.203910 I MythCoreContext::ConnectCommandSocket?(): Connecting to backend server: 192.168.0.108:6543 (try 1 of 1) 2020-06-03 11:54:00.217704 I MythCoreContext::CheckProtoVersion?(): Using protocol version 91 BuzzOff? 2020-06-03 11:54:00.392314 I CECAdapter: Using physical address 1.0.0.0 from EDID 2020-06-03 11:54:00.512189 E CECAdapter: Failed to find any CEC devices. 2020-06-03 11:54:01.012493 I CECAdapter: Closing down CEC. 2020-06-03 11:54:01.017631 E RAOP Conn: Failed to read key from: /home/rip/.mythtv/RAOPKey.rsa 2020-06-03 11:54:01.017655 E RAOP Device: Aborting startup - no key found. 2020-06-03 11:54:01.022869 I AirPlay?: Created airplay objects. 2020-06-03 11:54:01.023193 I Listening on TCP 0.0.0.0:5100 2020-06-03 11:54:01.023301 I Listening on TCP [::]:5100 2020-06-03 11:54:01.081662 I Current MythTV Schema Version (DBSchemaVer): 1361 2020-06-03 11:54:01.089442 E VDPAUHelp: Error at decoders/mythvdpauhelper.cpp:254 (#1, Unknown) 2020-06-03 11:54:01.089451 E VDPAUHelp: Failed to create VDPAU device. 2020-06-03 11:54:01.089615 I VDPAUHelp: VDPAU is NOT available 2020-06-03 11:54:01.104379 I MythCodecContext?: Created hardware device 'vaapi' 2020-06-03 11:54:01.104391 I Creating dummy interop 2020-06-03 11:54:01.104418 I VAAPIDec: Supported/available VAAPI decoders: 2020-06-03 11:54:01.105312 I MythCodecContext?: Created hardware device 'vaapi' 2020-06-03 11:54:01.105315 I Creating dummy interop 2020-06-03 11:54:01.105366 I MythCodecContext?: vaapi device context finished 2020-06-03 11:54:01.105373 I MythCodecContext?: Calling default device context free 2020-06-03 11:54:01.105545 I VAAPIDec: EGL DMABUF available for best VAAPI performance 2020-06-03 11:54:01.105561 I VAAPIDec: MPEG2 Simple (Max size: 4096x4096) 2020-06-03 11:54:01.105566 I VAAPIDec: MPEG2 Main (Max size: 4096x4096) 2020-06-03 11:54:01.105571 I VAAPIDec: H264 Constrained (Max size: 4096x4096) 2020-06-03 11:54:01.105575 I VAAPIDec: H264 Main (Max size: 4096x4096) 2020-06-03 11:54:01.105579 I VAAPIDec: H264 High (Max size: 4096x4096) 2020-06-03 11:54:01.105585 I VAAPIDec: VC1 Simple (Max size: 4096x4096) 2020-06-03 11:54:01.105589 I VAAPIDec: VC1 Main (Max size: 4096x4096) 2020-06-03 11:54:01.105593 I VAAPIDec: VC1 Advanced (Max size: 4096x4096) 2020-06-03 11:54:01.105597 I MythCodecContext?: vaapi device context finished 2020-06-03 11:54:01.105600 I MythCodecContext?: Calling default device context free 2020-06-03 11:54:01.105879 E NVDECInterop: Failed to load functions 2020-06-03 11:54:01.105896 I NVDEC: No NVDEC decoders found 2020-06-03 11:54:01.106267 I V4L2_M2M: No V4L2 decoders found 2020-06-03 11:54:01.106566 I DRMPRIMECtx: DRM PRIME codecs supported: None 2020-06-03 11:54:01.106606 I VDP: decoder<->render support: ffmpeg null opengl opengl-yv12 2020-06-03 11:54:01.106612 I VDP: decoder<->render support: vaapi opengl-hw 2020-06-03 11:54:01.106616 I VDP: decoder<->render support: vaapi-dec null opengl opengl-yv12 2020-06-03 11:54:01.163101 N VDP: Ignoring profile 204 (decoder nvdec is not available) 2020-06-03 11:54:01.217053 N VDP: Ignoring profile 205 (decoder v4l2-dec is not available) 2020-06-03 11:54:01.217103 N VDP: Ignoring profile 206 (decoder v4l2 is not available) 2020-06-03 11:54:01.248919 N VDP: Ignoring profile 48 (decoder vdpau is not available) 2020-06-03 11:54:01.259595 N VDP: Ignoring profile 49 (decoder vdpau is not available) 2020-06-03 11:54:01.259616 N VDP: Ignoring profile 50 (decoder vdpau is not available) 2020-06-03 11:54:01.270064 N VDP: Ignoring profile 51 (decoder vdpau is not available) 2020-06-03 11:54:02.045963 I Bonjour: Service registration complete: name 'MythTV on rip' type '_airplay._tcp.' domain: 'local.' 2020-06-03 11:54:04.291550 N Registering Internal as a media playback plugin. 2020-06-03 11:54:04.304058 A MMUnix:CheckMountable: DBus interface error: The name org.freedesktop.UDisks was not provided by any .service files 2020-06-03 11:54:04.306757 W MMUnix:UDisks2 service found. Media Monitor does not support this yet! 2020-06-03 11:54:04.314504 W No plugins directory /usr/local/lib/mythtv/plugins 2020-06-03 11:54:04.357326 N Found mainmenu.xml for theme 'Steppes' 2020-06-03 11:54:04.394865 I Checking for theme updates every hour 2020-06-03 11:54:04.395228 I Registering HouseKeeperTask? 'HardwareProfiler?'. 2020-06-03 11:54:04.409741 I Queueing HouseKeeperTask? 'HardwareProfiler?'. 2020-06-03 11:54:04.409754 I Starting HouseKeeper?. 2020-06-03 11:54:04.525278 I Bonjour: Service registration complete: name 'Mythfrontend on rip' type '_mythfrontend._tcp.' domain: 'local.' 2020-06-03 11:54:14.979120 I TV::TV(): Creating TV object 2020-06-03 11:54:15.018702 I TV::TV(): Finished creating TV object 2020-06-03 11:54:15.018735 N Suspending idle timer 2020-06-03 11:54:15.045693 I TV::Init(): Created TvPlayWindow?. 2020-06-03 11:54:15.090422 I TV::HandleStateChange?(): Attempting to change from None to WatchingPreRecorded? 2020-06-03 11:54:15.128680 I FileRingBuf?(myth://tv/16940_20200601200000.ts): OpenFile?(myth://tv/16940_20200601200000.ts, 2000 ms) 2020-06-03 11:54:15.150387 I TV::StartPlayer?(): Elapsed time since TV constructor was called: 171 ms 2020-06-03 11:54:15.539618 N AudioPlayer?: Enabling Audio 2020-06-03 11:54:15.539639 I Player(0): Opening 'myth://tv/16940_20200601200000.ts' 2020-06-03 11:54:15.765657 I VDP: Accepting: cmp() w() h() framerate() codecs() dec(ffmpeg) cpus(2) skiploop(enabled) rend(opengl) deint(high,high) 2020-06-03 11:54:15.770758 I AFD: PlayerFlags?: 0xc0, AudioReadAhead?: 510 msec 2020-06-03 11:54:15.770805 I Player(0): Stretch Factor 1, allow passthru 2020-06-03 11:54:15.824968 I AFD: Buffer size: 32768 Streamed 0 Seekable 1 Available 1245184 2020-06-03 11:54:16.547351 I AFD: Stream #0: ID: 0x157c Codec ID: H264 Type: Video(1920x1080) Bitrate: 0 2020-06-03 11:54:16.547400 I AFD: Stream #1: ID: 0x157e Codec ID: MP2 Type: Audio Bitrate: 256000 2020-06-03 11:54:16.547414 I AFD: codec MP2 has 2 channels 2020-06-03 11:54:16.547421 I AFD: Looking for decoder for MP2 2020-06-03 11:54:16.550216 I AFD: Opened codec 0x55838508de40, id(MP2) type(Audio) 2020-06-03 11:54:16.550798 I AFD: Stream #2: ID: 0x1580 Codec ID: DVB_SUBTITLE Type: Subtitle Bitrate: 0 2020-06-03 11:54:16.550811 I AFD: subtitle codec (Subtitle) 2020-06-03 11:54:16.550819 I AFD: Looking for decoder for DVB_SUBTITLE 2020-06-03 11:54:16.551258 I AFD: Opened codec 0x55838393a840, id(DVB_SUBTITLE) type(Subtitle) 2020-06-03 11:54:16.551310 I AFD: Subtitle track #1 is A/V stream #2 and is in the English language(6647399). 2020-06-03 11:54:16.551326 I AFD: Stream #3: ID: 0x157f Codec ID: DVB_TELETEXT Type: Subtitle Bitrate: 0 2020-06-03 11:54:16.551391 I AFD: Teletext stream #0 (Caption) is in the English language on page 8 136. 2020-06-03 11:54:16.551407 I AFD: Teletext stream #1 (Menu) is in the English language on page 8 136. 2020-06-03 11:54:16.551427 I AFD: subtitle codec (Subtitle) 2020-06-03 11:54:16.551443 I AFD: Stream #4: ID: 0x157d Codec ID: AC3 Type: Audio Bitrate: 192000 2020-06-03 11:54:16.551453 I AFD: codec AC3 has 2 channels 2020-06-03 11:54:16.551460 I AFD: Looking for decoder for AC3 2020-06-03 11:54:16.552023 I AFD: Opened codec 0x558383935fc0, id(AC3) type(Audio) 2020-06-03 11:54:16.552108 I AFD: Stream #5: ID: 0xf09 Codec ID: DSMCC_B Type: Data Bitrate: 0 2020-06-03 11:54:16.552117 I AFD: data codec (Data) 2020-06-03 11:54:16.552128 I AFD: Stream #6: ID: 0xf07 Codec ID: DSMCC_B Type: Data Bitrate: 0 2020-06-03 11:54:16.552134 I AFD: data codec (Data) 2020-06-03 11:54:16.552144 I AFD: Stream #7: ID: 0xf06 Codec ID: DSMCC_B Type: Data Bitrate: 0 2020-06-03 11:54:16.552151 I AFD: data codec (Data) 2020-06-03 11:54:16.552159 I AFD: Trying to select best video track 2020-06-03 11:54:16.552240 I AFD: Selected track #0: ID: 0x157c Codec ID: H264 Profile: High Type: Video(1920x1080) Bitrate: 500000 2020-06-03 11:54:16.552343 I AFD: Selected FPS: 25 (Avg:25 Mult:1 Codec:0 Container:90000 Estimated:25) 2020-06-03 11:54:16.552428 I VDP: LoadBestPreferences?(1920x1080, 25.000, h264) 2020-06-03 11:54:16.552478 I VDP: LoadBestPreferences? result: priority:1 width: height: fps: codecs: 2020-06-03 11:54:16.552499 I VDP: decoder:ffmpeg renderer:opengl deint0:high deint1:high cpus:2 2020-06-03 11:54:16.552543 I AFD: Using 2 CPUs for decoding 2020-06-03 11:54:16.552555 I AFD: InitVideoCodec? ID:H264 Type:Video Size:1920x1080 2020-06-03 11:54:16.552663 I Player(0): SetFrameInterval? Interval:40000 Speed:1 Scan:Progressive Scan (Multiplier: 1) 2020-06-03 11:54:16.552692 I Player(0): detectInterlace(Detect Scan, Interlaced Scan, 25, 1080) ->Interlaced Scan 2020-06-03 11:54:16.552812 I AFD: Using ffmpeg for video decoding 2020-06-03 11:54:16.553320 I AFD: Opened codec 0x558383723e40, id(H264) type(Video) 2020-06-03 11:54:16.605530 I AOBase: Opening audio device 'sysdefault:CARD=PCH' ch 2(2) sr 48000 sf signed 32 bit reenc 0 2020-06-03 11:54:16.632540 W ALSA: Requested 500000us got 170666 buffer time 2020-06-03 11:54:16.632658 W ALSA: Try to manually increase audio buffer with: echo 192 | sudo tee /proc/asound/card1/pcm0p/sub0/prealloc 2020-06-03 11:54:16.660053 E ALSA: no playback control PCM found on mixer device default 2020-06-03 11:54:16.660062 E ALSA: Unable to open audio mixer. Volume control disabled 2020-06-03 11:54:16.660156 I Dec: Selected track #1 (type 2) in the Unknown language(0) 2020-06-03 11:54:16.660170 I Dec: Selected track #1 (type 3) in the English language(6647399) 2020-06-03 11:54:16.660177 I Dec: Selected track #1 (type 6) in the English language(6647399) 2020-06-03 11:54:16.660183 I Dec: Selected track #1 (type 7) in the English language(6647399) 2020-06-03 11:54:16.660197 I Dec: Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0) 2020-06-03 11:54:16.742511 I Dec: Position map filled from DB to: 97498 2020-06-03 11:54:16.749654 I Dec: Duration map filled from DB to: 97498 2020-06-03 11:54:16.749960 I Dec: SyncPositionMap? prerecorded, from DB: 4114 entries 2020-06-03 11:54:16.749968 I Dec: SyncPositionMap?, new totframes: 97498, new length: 3253, posMap size: 4114 2020-06-03 11:54:16.778056 I AFD: Position map found 2020-06-03 11:54:16.778067 I AFD: Successfully opened decoder for file: "myth://tv/16940_20200601200000.ts". novideo(0) 2020-06-03 11:54:16.849202 I VideoOutput?: Allowed renderers for H.264 ffmpeg (Decoder: ffmpeg): 'opengl,opengl-yv12' 2020-06-03 11:54:16.849222 I VDP: Safe renderers for 'ffmpeg': null,opengl,opengl-yv12 2020-06-03 11:54:16.849236 I VideoOutput?: Allowed renderers (filt: ffmpeg): opengl,opengl-yv12 2020-06-03 11:54:16.885917 I VDP: Accepting: cmp() w() h() framerate() codecs() dec(ffmpeg) cpus(2) skiploop(enabled) rend(opengl) deint(high,high) 2020-06-03 11:54:16.885950 I VDP: LoadBestPreferences?(1920x1080, 25.000, h264) 2020-06-03 11:54:16.885977 I VDP: LoadBestPreferences? result: priority:1 width: height: fps: codecs: 2020-06-03 11:54:16.885995 I VDP: decoder:ffmpeg renderer:opengl deint0:high deint1:high cpus:2 2020-06-03 11:54:16.886013 I VideoOutput?: Preferred renderer: opengl 2020-06-03 11:54:16.886019 I VideoOutput?: Trying video renderer: 'opengl' 2020-06-03 11:54:17.171445 I GLVid: Chroma upsampling filter disabled 2020-06-03 11:54:17.171513 I Clearing OpenGL painter cache. 2020-06-03 11:54:17.208328 I VideoWin?: Window using screen HDMI2 1920x1080 2020-06-03 11:54:17.208347 I VideoWin?: Window Rect: 1920x1080+0+0 2020-06-03 11:54:17.208362 I VideoWin?: Display Rect: 1920x1013+0+33 Aspect: 1.66667 2020-06-03 11:54:17.208373 I VideoWin?: Video Rect: 1920x1080+0+0 Aspect: 1.77778 2020-06-03 11:54:17.208415 I ColourSpace?: PictureAttributes?: Brightness,Contrast,Colour,Hue,Range 2020-06-03 11:54:17.208443 I VideoOutput?: Display aspect ratio: 1.66667 (Detected) 2020-06-03 11:54:17.230425 I Created 18 YUV420P (1920x1080) video buffers 2020-06-03 11:54:17.305830 I Player(0): Decoder thread starting. 2020-06-03 11:54:17.305856 I AFD: DoFastForward?(4955 (0), do discard frames) 2020-06-03 11:54:17.305866 I Dec: DoFastForward?(4955 (0), do discard frames) 2020-06-03 11:54:17.305914 I Dec: FindPosition?(4955, search not adjusted) -->

[211:4939(236730352),212:4963(237725060)]

2020-06-03 11:54:17.418957 I AFD: SeekReset?(4939, 16, do flush, do discard) 2020-06-03 11:54:17.419051 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA 2020-06-03 11:54:17.419111 I VideoBuffers::DiscardFrames?(1): AAAAAAAAAAAAAAAAAA -- done 2020-06-03 11:54:17.419136 I AFD: SeekReset?() flushing 2020-06-03 11:54:17.806536 I Player(0): ClearAfterSeek?(0) 2020-06-03 11:54:17.865357 I OSD: Loaded window osd_message 2020-06-03 11:54:17.868788 I OSD: Loaded window osd_input 2020-06-03 11:54:17.886092 I OSD: Loaded window program_info 2020-06-03 11:54:17.912113 I OSD: Loaded window browse_info 2020-06-03 11:54:17.916410 I OSD: Loaded window osd_status 2020-06-03 11:54:17.920272 I OSD: Loaded window osd_program_editor 2020-06-03 11:54:17.925591 I OSD: Loaded window osd_debug 2020-06-03 11:54:17.925600 I OSD: Loaded OSD: size 1920x1080 offset 0+0 2020-06-03 11:54:17.925663 I OSD: Created window aa_OSD_SUBTITLES 2020-06-03 11:54:17.953266 I Player(0): ClearAfterSeek?(0) 2020-06-03 11:54:17.953297 I VideoOutput?: SetDeinterlacing? (Doublerate 1): Single High|CPU Double High|CPU 2020-06-03 11:54:17.953309 I Player(0): Display Refresh Rate: 50.000 Video Frame Rate: 25.000 2020-06-03 11:54:17.953320 I Player(0): SetFrameInterval? Interval:40000 Speed:1 Scan:Interlaced Scan (Multiplier: 1) 2020-06-03 11:54:17.954194 I playCtx: StartPlaying?(): took 0 ms to start player. 2020-06-03 11:54:17.954207 I TV::StartPlayer?(): Created player. 2020-06-03 11:54:17.954253 I TV::HandleStateChange?(): Changing from None to WatchingPreRecorded? 2020-06-03 11:54:18.006562 I TV::HandleStateChange?(): Main UI disabled. 2020-06-03 11:54:18.006628 I TV::StartTV(): Entering main playback loop. 2020-06-03 11:54:18.012518 I ScreenSaverDBus: Successfully inhibited screensaver via org.freedesktop.ScreenSaver?. cookie 2139982080. nom nom 2020-06-03 11:54:18.014924 W ScreenSaverDBus: Failed to disable screensaver: Type of message, “(ss)”, does not match expected type “(susu)” 2020-06-03 11:54:18.015042 I ScreenSaverX11Private: DPMS Deactivated 1 2020-06-03 11:54:18.015326 I OSD: Created window bb_OSD_INTERACTIVE 2020-06-03 11:54:18.015343 I Player(0): Interlaced frame seen after 2 progressive frames 2020-06-03 11:54:18.015347 I Player(0): Locking scan to Interlaced. 2020-06-03 11:54:18.015382 I VideoOutput?: SetDeinterlacing? (Doublerate 1): Single High|CPU Double High|CPU 2020-06-03 11:54:18.015432 I MythDeint?: Deinterlacer change: 0x0 None dr:0 tff:1 -> 1920x1080 YUV420P dr:1 tff:1 2020-06-03 11:54:18.016593 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.026923 W GLVid: New frame format: None:None 1920x1080 (Tex: 2D) -> YUV420P:YUY2 1920x1080 (Tex: 2D) 2020-06-03 11:54:18.027086 I GLVid: Created 1 input textures for 'opengl' 2020-06-03 11:54:18.029180 I ColourSpace?: Input : bt709(Detected) Depth:8 Range:Limited 2020-06-03 11:54:18.029192 I ColourSpace?: Input : Primaries:bt709 Transfer: bt709 2020-06-03 11:54:18.029195 I ColourSpace?: Output: Range:Full Primaries: bt709 2020-06-03 11:54:18.042208 I GLVid: Resizing from 1920x1080 to 1920x1013 for Sampling 2020-06-03 11:54:18.094456 I Player(0): Dropping frame: Video is behind by 39ms 2020-06-03 11:54:18.096685 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.097286 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.126352 I PreviewQueue?: Requesting preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:54:18.126419 I PreviewQueue?: Requested preview for '16940_20200601200000.ts_0x0_-1s' 2020-06-03 11:54:18.135815 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.155755 I Player(0): AV Sync: Audio ahead by 991 ms 2020-06-03 11:54:18.155799 I MythDeint?: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1 2020-06-03 11:54:18.156219 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.178318 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.197682 I Player(0): AV Sync: Audio ahead by 978 ms 2020-06-03 11:54:18.197731 I MythDeint?: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1 2020-06-03 11:54:18.198116 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.213091 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.219282 I Player(0): Dropping frame: Video is behind by 56ms 2020-06-03 11:54:18.219383 I Player(0): AV Sync: Audio ahead by 900 ms 2020-06-03 11:54:18.219428 I MythDeint?: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1 2020-06-03 11:54:18.220198 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.236036 I Player(0): Dropping frame: Video is behind by 48ms 2020-06-03 11:54:18.236130 I Player(0): AV Sync: Audio ahead by 835 ms 2020-06-03 11:54:18.236162 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.237115 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.252406 I Player(0): Dropping frame: Video is behind by 38ms 2020-06-03 11:54:18.252488 I Player(0): AV Sync: Audio ahead by 772 ms 2020-06-03 11:54:18.252515 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.253596 I MythDeint?: Created deinterlacer '2x CPU Yadif' (2 threads) 2020-06-03 11:54:18.266340 I Player(0): AV Sync: Audio ahead by 746 ms 2020-06-03 11:54:18.286274 I MythDeint?: Removing CPU deinterlacer 2020-06-03 11:54:18.300385 I Player(0): Dropping frame: Video is behind by 64ms 2020-06-03 11:54:18.300458 I Player(0): AV Sync: Audio ahead by 670 ms 2020-06-03 11:54:18.300487 I MythDeint?: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1

Attachments (2)

bad_parsed.log (34.9 KB) - added by pletch 5 months ago.
Log captured with drift representative of bad playback submitted in original ticket submission by jksj461. The log information has been processed with sed to add back in line breaks.
good_parsed.log (24.1 KB) - added by pletch 5 months ago.
Log captured after removal of commit mentioned in original ticket submission by jksj461. The log information has been processed with sed to add back in line breaks.

Download all attachments as: .zip

Change History (8)

comment:1 Changed 5 months ago by Mark Kendall

Component: MythTV - GeneralMythTV - Video Playback
Milestone: needs_triage31.1
Owner: set to Mark Kendall
Status: newaccepted

comment:2 Changed 5 months ago by Mark Kendall

Could you re-paste the logs within code blocks or just add them as an attachment? A little tricky to get a sense of what is going on:)

Changed 5 months ago by pletch

Attachment: bad_parsed.log added

Log captured with drift representative of bad playback submitted in original ticket submission by jksj461. The log information has been processed with sed to add back in line breaks.

Changed 5 months ago by pletch

Attachment: good_parsed.log added

Log captured after removal of commit mentioned in original ticket submission by jksj461. The log information has been processed with sed to add back in line breaks.

comment:3 Changed 5 months ago by jksj461

Additional observations Watched about 4 hours of programs last night which played back flawlessly with the committ from 10/03 removed. Subtitles were however unwatchable being presented several seconds (maybe 5 or 6) before audio. Also of note is that the logs show the de-interlacor being regularly reset (15-16 times per sec). Which I presume is the issue that the committ was addressing.

Jun  4 21:47:33 tv mythfrontend: mythfrontend[5354]: I CoreContext mythdeinterlacer.cpp:159 (Filter) MythDeint: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1

Jun  4 21:47:33 tv mythfrontend: mythfrontend[5354]: I CoreContext mythdeinterlacer.cpp:159 (Filter) MythDeint: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1

Jun  4 21:47:33 tv mythfrontend: mythfrontend[5354]: I CoreContext mythdeinterlacer.cpp:159 (Filter) MythDeint: Deinterlacer change: 1920x1080 YUV420P dr:1 tff:1 -> 1920x1080 YUV420P dr:1 tff:1

comment:4 Changed 5 months ago by Mark Kendall

Status: acceptedinfoneeded

I believe this is now fixed in master and fixes/31.

Can you confirm this now works without issue for some of those iffy freeview/freesat channels? I can't test those at the moment.

With respect to the subtitle sync issue - if this is still a problem, could you create a new ticket describing what you are seeing and try to upload a small (60s) clip that demonstrates the problem.

Thanks, Mark

comment:5 Changed 5 months ago by jksj461

Thanks a quick check shows the fix to work well. The subtitle issue is still there when software de-interlacing.

VideoOutput?: SetDeinterlacing? (Doublerate 1): Single High|CPU Double High|CPU

but not when

VideoOutput?: SetDeinterlacing? (Doublerate 1): Single High|CPU|GLSL|DRIVER Double High|CPU|GLSL|DRIVE

All other things being equal. Will raise as new issue - many thanks

comment:6 Changed 4 months ago by Mark Kendall

Resolution: Fixed
Status: infoneededclosed
Note: See TracTickets for help on using tickets.