Opened 3 years ago
Closed 3 years ago
Last modified 3 years ago
#13231 closed Bug Report - General (fixed)
external .srt subtitles not recognized at all for some mkv files
Reported by: | Owned by: | Peter Bennett | |
---|---|---|---|
Priority: | minor | Milestone: | 29.2 |
Component: | MythTV - Video/OSD Rendering | Version: | Master Head |
Severity: | medium | Keywords: | srt subtitles |
Cc: | Ticket locked: | no |
Description
I have some mkv files for which external .srt subtitles are not displayed my mythtv. For such mkv, OSD menu is not showing "Subtitles from file" option at all. Those mkv+.srt are perfectly working in i.e. VLC or Movist (macOS) and only mythtv seems to have problem with displaying external .srt.
Interesting is that: -other mkv movies with external .srt plays OK in my mythtv -this specific mkv with .srt file from the movie also not displays subtitles
I think there is something special with mkv file that causes that external .srt aren't displayed by mythtv.
sample (mkv + .srt) is here:
Change History (14)
comment:1 Changed 3 years ago by
comment:2 Changed 3 years ago by
peter, how this?
I have this issue on minimyth2 and also on macOS builds with current master.
How can I debug this issue?
Here is fe log with playback, audio filters and debug level
2018-03-01 18:30:52.830958 I Setup Interrupt handler 2018-03-01 18:30:52.831127 I Setup Terminated handler 2018-03-01 18:30:52.831154 I Setup Segmentation fault handler 2018-03-01 18:30:52.831178 I Setup Aborted handler 2018-03-01 18:30:52.831200 I Setup Bus error handler 2018-03-01 18:30:52.831224 I Setup Floating point exception handler 2018-03-01 18:30:52.831246 I Setup Illegal instruction handler 2018-03-01 18:30:52.831274 I Setup Real-time signal 0 handler 2018-03-01 18:30:52.831308 I Setup User defined signal 1 handler 2018-03-01 18:30:52.831332 I Setup User defined signal 2 handler 2018-03-01 18:30:52.831354 I Setup Hangup handler 2018-03-01 18:30:52.831861 C mythfrontend version: master [v30-Pre-521-gf9c9dd4] www.mythtv.org 2018-03-01 18:30:52.831898 C Qt version: compile: 5.4.1, runtime: 5.4.1 2018-03-01 18:30:52.831910 N Enabled verbose msgs: general 2018-03-01 18:30:52.831989 N Setting Log Level to LOG_INFO 2018-03-01 18:30:52.886490 I Added logging to the console 2018-03-01 18:30:52.904173 N Using runtime prefix = /usr 2018-03-01 18:30:52.904192 N Using configuration directory = /home/minimyth/.mythtv 2018-03-01 18:30:52.904490 I Assumed character encoding: en_US.UTF-8 2018-03-01 18:30:52.990869 E DBHostName is not set in config.xml 2018-03-01 18:30:52.991124 N Empty LocalHostName. 2018-03-01 18:30:52.991163 I Using localhost value of FE-Livingroom 2018-03-01 18:30:52.991564 I Start up testing connections. DB 192.168.1.254, BE , attempt 0, status dbAwake 2018-03-01 18:30:54.177974 N Setting QT default locale to pl_US 2018-03-01 18:30:54.178042 I Current locale pl_US 2018-03-01 18:30:54.182271 E No locale defaults file for pl_US, skipping 2018-03-01 18:30:54.253006 I Starting process signal handler 2018-03-01 18:30:54.253239 I Starting IO manager (write) 2018-03-01 18:30:54.256348 I Starting process manager 2018-03-01 18:30:54.256648 I Starting IO manager (read) 2018-03-01 18:30:54.303734 I ScreenSaverX11Private: XScreenSaver support enabled 2018-03-01 18:30:54.305597 I ScreenSaverX11Private: DPMS is disabled. 2018-03-01 18:30:54.469086 N Desktop video mode: 1920x1080 50.000 Hz 2018-03-01 18:30:54.635798 E SG() Error: Could not create builtinStorage Group directory \'/home/minimyth/.mythtv/tmp/hls\' for \'Streaming\' 2018-03-01 18:30:54.868899 I Listening on TCP 0.0.0.0:6547 2018-03-01 18:30:54.873904 I Listening on TCP [::]:6547 2018-03-01 18:30:55.210330 I Loading pl translation for module mythfrontend 2018-03-01 18:30:55.216558 N Desktop video mode: 1920x1080 50.000 Hz 2018-03-01 18:30:55.264211 I Using 1920x1080 50.000 Hz 2018-03-01 18:30:55.264238 I SwitchToGUI: Switched to 1920x1080 50.000 Hz 2018-03-01 18:30:55.291584 I LIRC: Successfully initialized \'/dev/lircd\' using \'/home/minimyth/.mythtv/lircrc\' config 2018-03-01 18:30:55.291746 I UDPListener: Enabling 2018-03-01 18:30:55.294665 I Binding to UDP 0.0.0.0:6948 2018-03-01 18:30:55.294816 I Binding to UDP [::]:6948 2018-03-01 18:30:55.341151 I Using Frameless Window 2018-03-01 18:30:55.341164 I Using Full Screen Window 2018-03-01 18:30:55.380492 I UI Screen Resolution: 1920 x 1080 2018-03-01 18:30:55.395910 I OpenGL: Sync to VBlank is enabled (good!) 2018-03-01 18:30:56.010720 I Trying the OpenGL 2.0 render 2018-03-01 18:30:56.031212 I OpenGL painter using existing OpenGL context. 2018-03-01 18:30:56.080414 I OpenGL2: GLSL supported 2018-03-01 18:30:56.080580 I OpenGL: OpenGL vendor : NVIDIA Corporation 2018-03-01 18:30:56.080593 I OpenGL: OpenGL renderer: ION/PCIe/SSE2 2018-03-01 18:30:56.080604 I OpenGL: OpenGL version : 3.3.0 NVIDIA 340.106 2018-03-01 18:30:56.080640 I OpenGL: Max texture size: 8192 x 8192 2018-03-01 18:30:56.080652 I OpenGL: Max texture units: 4 2018-03-01 18:30:56.080664 I OpenGL: Direct rendering: Yes 2018-03-01 18:30:56.080702 I OpenGL: Extensions Supported: 1e3b 2018-03-01 18:30:56.080712 I OpenGL: PixelBufferObject support available 2018-03-01 18:30:56.387358 I OpenGL: Initialised MythRenderOpenGL 2018-03-01 18:30:56.397222 I MythUIHelper: Pruning cache directory: /home/minimyth/.mythtv/cache/remotecache is disabled 2018-03-01 18:30:56.397249 I MythUIHelper: Pruning cache directory: /home/minimyth/.mythtv/cache/thumbnails is disabled 2018-03-01 18:31:04.623186 I MythCoreContext::ConnectCommandSocket(): Connecting to backend server: 192.168.1.254:6543 (try 1 of 1) 2018-03-01 18:31:04.641674 I MythCoreContext::CheckProtoVersion(): Using protocol version 91 BuzzOff 2018-03-01 18:31:07.020351 W MythCookieJar::load() failed to open file for reading: /home/minimyth/.mythtv/MythBrowser/cookiejar.txt 2018-03-01 18:31:07.348817 I MythUIWebBrowser: Loading css from - file:///usr/share/mythtv/themes/default/htmls/mythbrowser.css 2018-03-01 18:31:07.397308 I MythUIWebBrowser: enabling plugins 2018-03-01 18:31:07.686116 I RAOP Device: Created RAOP device objects. 2018-03-01 18:31:07.689609 I Listening on TCP 0.0.0.0:5000 2018-03-01 18:31:07.689726 I Listening on TCP [::]:5000 2018-03-01 18:31:07.689783 I RAOP Device: Listening for connections on port 5000 2018-03-01 18:31:07.696286 I Registering service 214e624b6333@MythTV on FE-Livingroom._raop._tcp port 5000 TXT tp=UDPsm=falsesv=falseek=1et=0,1cn=0,1ch=2ss=16sr=44100pw=falsevn=3 txtvers=1md=0,1,2vs=115.2da=true am=MythTV,1 2018-03-01 18:31:07.709180 I Current MythTV Schema Version (DBSchemaVer): 1348 2018-03-01 18:31:08.695371 I Bonjour: Service registration complete: name \'214e624b6333@MythTV on FE-Livingroom\' type \'_raop._tcp.\' domain: \'local.\' 2018-03-01 18:31:09.479763 W Key Alt+V is already bound to a jump point. 2018-03-01 18:31:09.510952 N Registering Internal as a media playback plugin. 2018-03-01 18:31:09.533801 E MythSystemLegacy(udevinfo) command not executable, eno: No such file or directory (2) 2018-03-01 18:31:09.569122 N Registering WebBrowser as a media playback plugin. 2018-03-01 18:31:09.571017 I Loading pl translation for module mythbrowser 2018-03-01 18:31:09.651167 I Loading pl translation for module mythgame 2018-03-01 18:31:09.760517 I Current MythMusic Schema Version (MusicDBSchemaVer): 1024 2018-03-01 18:31:09.823704 I Loading pl translation for module mythmusic 2018-03-01 18:31:09.852760 I Loading pl translation for module mythnetvision 2018-03-01 18:31:09.880359 I Loading pl translation for module mythnews 2018-03-01 18:31:09.927114 I Loading pl translation for module mythweather 2018-03-01 18:31:09.962821 I Connecting to zm server: 192.168.1.254:6548 (try 1 of 2) 2018-03-01 18:31:10.965106 I Using protocol version 11 2018-03-01 18:31:11.010542 N Monitor: Salon (5) is using 3 bytes per pixel 2018-03-01 18:31:11.013292 I Loading pl translation for module mythzoneminder 2018-03-01 18:31:11.024641 I Listening on TCP 0.0.0.0:6546 2018-03-01 18:31:11.029561 I Listening on TCP [::]:6546 2018-03-01 18:31:11.204749 N Found mainmenu.xml for theme \'Default\' 2018-03-01 18:31:11.243538 I Registering HouseKeeperTask \'HardwareProfiler\'. 2018-03-01 18:31:11.261069 I Starting HouseKeeper. 2018-03-01 18:31:11.820151 I Bonjour: Service registration complete: name \'Mythfrontend on FE-Livingroom\' type \'_mythfrontend._tcp.\' domain: \'local.\' 2018-03-01 18:31:16.588993 I NetworkControl: New connection established. 2018-03-01 18:31:40.447239 I NetworkControl: New connection established. 2018-03-01 18:31:40.448433 N Verbose mask changed, new level is: general playback audio 2018-03-01 18:31:40.449413 I NetworkControl: Client Socket disconnected 2018-03-01 18:31:44.890568 I NetworkControl: New connection established. 2018-03-01 18:31:44.891512 N Verbose loglevel changed, new loglevel is: debug 2018-03-01 18:31:44.892367 I NetworkControl: Client Socket disconnected 2018-03-01 18:31:47.697876 N Suspending idle timer 2018-03-01 18:31:47.698415 D MythCoreContext::SendReceiveStringList(): SendReceiveStringList(QUERY_FILE_EXISTS,HD/The Glass Castle (2017).mkv/VIDEO_TS...) called from UI thread 2018-03-01 18:31:47.699371 D MythCoreContext::SendReceiveStringList(): SendReceiveStringList(QUERY_FILE_EXISTS,HD/The Glass Castle (2017).mkv/BDMV...) called from UI thread 2018-03-01 18:31:47.714658 N Resuming idle timer 2018-03-01 18:31:50.626537 I TV::TV(): Creating TV object 2018-03-01 18:31:50.752722 I TV::TV(): Finished creating TV object 2018-03-01 18:31:50.752748 D TV::StartTV(): -- begin 2018-03-01 18:31:50.752818 N Suspending idle timer 2018-03-01 18:31:50.752846 D TV::Init(): -- begin 2018-03-01 18:31:50.756860 I TV::Init(): Created TvPlayWindow. 2018-03-01 18:31:50.807711 D TV::DrawUnusedRects(): -- begin 2018-03-01 18:31:50.807796 D TV::DrawUnusedRects(): -- end 2018-03-01 18:31:50.834414 D TV::Init(): -- end 2018-03-01 18:31:50.834494 D TV::StartTV(): tv->Playback() -- begin 2018-03-01 18:31:50.863558 D TV::HandleStateChange(): (0) -- begin 2018-03-01 18:31:50.863603 I TV::HandleStateChange(): Attempting to change from None to WatchingVideo 2018-03-01 18:31:50.866215 D MythCoreContext::SendReceiveStringList(): SendReceiveStringList(QUERY_FILE_EXISTS,HD/The Glass Castle (2017).mkv...) called from UI thread 2018-03-01 18:31:50.867851 I FileRingBuf(myth://Videos@mythtv/HD/The Glass Castle (2017).mkv): OpenFile(myth://Videos@mythtv/HD/The Glass Castle (2017).mkv, 2000 ms) 2018-03-01 18:31:50.868764 D PortChecker::checkPort(): host 192.168.1.254 port 6543 timeLimit 30000 linkLocalOnly 1 2018-03-01 18:31:50.870973 D PortChecker::checkPort(): host 192.168.1.254 port 6543 timeLimit 30000 linkLocalOnly 1 2018-03-01 18:31:50.880788 D TV::StartPlayer(): (0, WatchingVideo, main) -- begin 2018-03-01 18:31:50.880876 I TV::StartPlayer(): Elapsed time since TV constructor was called: 254 ms 2018-03-01 18:31:50.926594 D FilterManager: filters[adjust] = 0x4a07400 2018-03-01 18:31:50.927577 D FilterManager: filters[bobdeint] = 0x60037f0 2018-03-01 18:31:50.928704 D FilterManager: filters[crop] = 0x1232330 2018-03-01 18:31:50.929830 D FilterManager: filters[denoise3d] = 0x64b8cd0 2018-03-01 18:31:50.930687 D FilterManager: filters[fieldorderdoubleprocessdeint] = 0x627dac0 2018-03-01 18:31:50.931463 D FilterManager: filters[forceyv12] = 0x4a2fd20 2018-03-01 18:31:50.931488 D FilterManager: filters[forceyuv422p] = 0x64d1b70 2018-03-01 18:31:50.931506 D FilterManager: filters[forcergb24] = 0x64d7fb0 2018-03-01 18:31:50.931523 D FilterManager: filters[forceargb32] = 0x62ad3e0 2018-03-01 18:31:50.932838 D FilterManager: filters[greedyhdeint] = 0x6336410 2018-03-01 18:31:50.932864 D FilterManager: filters[greedyhdoubleprocessdeint] = 0x64d3b50 2018-03-01 18:31:50.933769 D FilterManager: filters[invert] = 0x4a72130 2018-03-01 18:31:50.934577 D FilterManager: filters[ivtc] = 0x645d8e0 2018-03-01 18:31:50.936339 D FilterManager: filters[kerneldeint] = 0x645df30 2018-03-01 18:31:50.936366 D FilterManager: filters[kerneldoubleprocessdeint] = 0x4a2e330 2018-03-01 18:31:50.937729 D FilterManager: filters[linearblend] = 0x4a2e390 2018-03-01 18:31:50.938613 D FilterManager: filters[onefield] = 0x6331c10 2018-03-01 18:31:50.939890 D FilterManager: filters[postprocess] = 0x63b7210 2018-03-01 18:31:50.941071 D FilterManager: filters[quickdnr] = 0x645d660 2018-03-01 18:31:50.941874 D FilterManager: filters[vflip] = 0x15a14e0 2018-03-01 18:31:50.943283 D FilterManager: filters[yadifdeint] = 0x1f7d920 2018-03-01 18:31:50.943312 D FilterManager: filters[yadifdoubleprocessdeint] = 0x62acb60 2018-03-01 18:31:51.094398 I ALSA: OpenDevice iec958:CARD=Intel,DEV=0 2018-03-01 18:31:51.105588 I AOS: Sample rate 44100 is supported 2018-03-01 18:31:51.105646 I AOS: Sample rate 48000 is supported 2018-03-01 18:31:51.105674 I AOS: Sample rate 88200 is supported 2018-03-01 18:31:51.105695 I AOS: Sample rate 96000 is supported 2018-03-01 18:31:51.105722 I AOS: Sample rate 192000 is supported 2018-03-01 18:31:51.105791 I AOS: Format signed 16 bit is supported 2018-03-01 18:31:51.105811 I AOS: Format signed 24 bit MSB is supported 2018-03-01 18:31:51.105823 I AOS: Format signed 32 bit is supported 2018-03-01 18:31:51.105876 I AOS: 2 channel(s) are supported 2018-03-01 18:31:51.196833 I AOS: may be AC3 or DTS capable 2018-03-01 18:31:51.196865 I AOS: 6 channel(s) are supported 2018-03-01 18:31:51.207113 N AudioPlayer: Enabling Audio 2018-03-01 18:31:51.852926 I AFD: PlayerFlags: 0xc0, AudioReadAhead: 100 msec 2018-03-01 18:31:51.853013 I Player(0): Stretch Factor 1, allow passthru 2018-03-01 18:31:51.853050 D AFD: OpenFile -- begin 2018-03-01 18:31:51.853866 I AFD: Buffer size: 32768 streamed 0 seekable 1 2018-03-01 18:31:52.436558 I AFD: Stream #0, has id 0x0 codec id H264, type Video, bitrate 0 at 0x6f7cba0 2018-03-01 18:31:52.436588 I AFD: Stream #1, has id 0x0 codec id AC3, type Audio, bitrate 640000 at 0x6f7d9a0 2018-03-01 18:31:52.436610 I AFD: codec AC3 has 6 channels 2018-03-01 18:31:52.436622 I AFD: Looking for decoder for AC3 2018-03-01 18:31:52.438030 I AFD: Opened codec 0x7f89680, id(AC3) type(Audio) 2018-03-01 18:31:52.438180 I AFD: Audio Track #1, of type (Normalny) is A/V stream #1 (id=0x0) and has 6 channels in the English language(6647399). 2018-03-01 18:31:52.438208 I AFD: Stream #2, has id 0x0 codec id Unknown Codec ID, type Subtitle, bitrate 0 at 0x6f7e840 2018-03-01 18:31:52.438221 I AFD: subtitle codec (Subtitle) 2018-03-01 18:31:52.438232 I AFD: Looking for decoder for Unknown Codec ID 2018-03-01 18:31:52.438413 I AFD: Opened codec 0x6fb32c0, id(Unknown Codec ID) type(Subtitle) 2018-03-01 18:31:52.438442 I AFD: Subtitle track #1 is A/V stream #2 and is in the English language(6647399). 2018-03-01 18:31:52.438467 I AFD: Stream #3, has id 0x0 codec id Unknown Codec ID, type Subtitle, bitrate 0 at 0x6f7f6e0 2018-03-01 18:31:52.438479 I AFD: subtitle codec (Subtitle) 2018-03-01 18:31:52.438490 I AFD: Looking for decoder for Unknown Codec ID 2018-03-01 18:31:52.438613 I AFD: Opened codec 0x7d69b20, id(Unknown Codec ID) type(Subtitle) 2018-03-01 18:31:52.438640 I AFD: Subtitle track #2 is A/V stream #3 and is in the English language(6647399). 2018-03-01 18:31:52.438651 I AFD: Trying to select best video track 2018-03-01 18:31:52.438786 I AFD: Selected track #0 (id 0x0 codec id H264, type Video, bitrate 500000 at 0x6f7cba0) 2018-03-01 18:31:52.446134 I VDP: Accepting: cmp() w(>=0) h(>=720) framerate() codecs() dec(vdpau) cpus(4) skiploop(enabled) rend(vdpau) osd(vdpau) osdfade(enabled) deint(vdpaubasicdoublerate,vdpauadvanced) filt(vdpaucolorspace=auto,vdpausharpen=1.0) 2018-03-01 18:31:52.446252 I VDP: Accepting: cmp() w() h() framerate() codecs() dec(vdpau) cpus(4) skiploop(enabled) rend(vdpau) osd(vdpau) osdfade(enabled) deint(vdpauadvanceddoublerate,vdpauadvanced) filt(vdpaucolorspace=auto) 2018-03-01 18:31:52.446307 I VDP: LoadBestPreferences(1920x800, 0.000, h264) 2018-03-01 18:31:52.446503 I VDP: LoadBestPreferences Result prio:1, w:>=0, h:>=720, fps:, codecs:, decoder:vdpau, renderer:vdpau, deint:vdpaubasicdoublerate 2018-03-01 18:31:52.446668 I VDPAU: Checking VDPAU support. 2018-03-01 18:31:52.937966 I VDPAU: Version 1 2018-03-01 18:31:52.937993 I VDPAU: Information NVIDIA VDPAU Driver Shared Library 340.106 Tue Jan 9 14:26:01 PST 2018 2018-03-01 18:31:52.938042 I VDPAU: HQ scaling level 1 of 9 available. 2018-03-01 18:31:52.938056 I VDPAU: MPEG4 hardware acceleration supported. 2018-03-01 18:31:52.938066 I VDPAU: HEVC hardware acceleration not supported. 2018-03-01 18:31:52.948443 I AFD: Using 1 CPUs for decoding 2018-03-01 18:31:52.948471 I AFD: InitVideoCodec() 0x7c34dc0 id(H264) type (Video). 2018-03-01 18:31:52.948523 I AFD: Selected FPS is 23.976 (avg 23.976 codec 0 container 1000 estimated 23.976) 2018-03-01 18:31:52.948580 I Player(0): SetFrameInterval ps:1 scan:3 2018-03-01 18:31:52.948621 I Player(0): detectInterlace(Detect Scan, Interlaced Scan, 23.976, 800) ->Interlaced Scan 2018-03-01 18:31:52.948649 D AFD: ScanATSCCaptionStreams() called with no PMT 2018-03-01 18:31:52.948685 I AFD: Using vdpau for video decoding 2018-03-01 18:31:52.948952 I AFD: Opened codec 0x7c34dc0, id(H264) type(Video) 2018-03-01 18:31:52.962192 I AFD: Selected track 1: English AC3 5.1ch (A/V Stream #1) 2018-03-01 18:31:52.962324 I AFD: Audio data is planar 2018-03-01 18:31:52.962389 I AFD: Initializing audio parms from audio track #1 2018-03-01 18:31:52.962451 I AFD: Audio format changed from id(NONE) -1Hz -1/-1ch -1bps (profile 0) to id( AC3) 48000Hz 6/6ch 32bps pt (profile 0) 2018-03-01 18:31:52.962513 I AOBase: Setting AC3 passthrough 2018-03-01 18:31:52.963155 I SPDIFEncoder: Creating spdif encoder (for AC3) 2018-03-01 18:31:52.963179 I AOBase: Killing AudioOutputDSP 2018-03-01 18:31:52.963204 I AOBase: Original codec was AC3, 32 bit floating point, 48 kHz, 6 channels 2018-03-01 18:31:52.963247 I AOBase: enc(0), passthru(1), features (AC3,DTS) configured_channels(6), 6 channels supported(1) max_channels(6) 2018-03-01 18:31:52.963283 I AOBase: Opening audio device \'iec958:CARD=Intel,DEV=0\' ch 2(6) sr 48000 sf signed 16 bit reenc 0 2018-03-01 18:31:52.963300 I ALSA: OpenDevice iec958:CARD=Intel,DEV=0,AES0=6,AES1=0x82,AES2=0x00,AES3=0x01 for passthrough 2018-03-01 18:31:52.970245 I ALSA: SetParameters(format=2, channels=2, rate=48000, buffer_time=500000, period_time=4) 2018-03-01 18:31:52.970739 I ALSA: Buffer size range from 64 to 16384 2018-03-01 18:31:52.970761 I ALSA: Period size range from 32 to 8192 2018-03-01 18:31:52.970856 W ALSA: Requested 500000us got 341333 buffer time 2018-03-01 18:31:52.971189 I ALSA: Hardware audio buffer cur: 64 need: 128 max allowed: 32768 2018-03-01 18:31:52.971266 W ALSA: Try to manually increase audio buffer with: echo 128 | sudo tee /proc/asound/card0/pcm1p/sub0/prealloc 2018-03-01 18:31:52.971296 I ALSA: Buffer time = 341333 us 2018-03-01 18:31:52.971402 I ALSA: Period time = 4 periods 2018-03-01 18:31:52.983791 I ALSA: Buffer size = 16384 | Period size = 4096 2018-03-01 18:31:52.984052 I AOBase: Audio fragment size: 8192 2018-03-01 18:31:52.984118 I AOBase: Audio Stretch Factor: 1 2018-03-01 18:31:52.984258 I AOBase: Ending Reconfigure() 2018-03-01 18:31:52.984317 I Dec: Selected track #1 (type 2) in the Unknown language(0) 2018-03-01 18:31:52.984338 I Dec: Trying to select track (w/lang & forced) 2018-03-01 18:31:52.984357 I Dec: Selected track #1 (type 3) in the English language(6647399) 2018-03-01 18:31:52.984377 I Dec: Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0) 2018-03-01 18:31:52.984567 I AOBase: kickoffOutputAudioLoop: pid = 8511 2018-03-01 18:31:52.984630 I AOBase: OutputAudioLoop: Play Event 2018-03-01 18:31:52.992392 I Dec: SyncPositionMap prerecorded, from DB: 0 entries 2018-03-01 18:31:52.995534 I AFD: Recording has no position -- using libavformat seeking. 2018-03-01 18:31:52.996280 I AFD: Successfully opened decoder for file: "myth://Videos@mythtv/HD/The Glass Castle (2017).mkv". novideo(0) 2018-03-01 18:31:52.996349 I AFD: Chapter 01 found @ [00:00:00.000]->0 2018-03-01 18:31:52.996385 I AFD: Chapter 02 found @ [00:08:15.453]->11878 2018-03-01 18:31:52.996417 I AFD: Chapter 03 found @ [00:15:33.182]->22373 2018-03-01 18:31:52.996449 I AFD: Chapter 04 found @ [00:21:33.292]->31008 2018-03-01 18:31:52.996479 I AFD: Chapter 05 found @ [00:29:25.931]->42340 2018-03-01 18:31:52.996510 I AFD: Chapter 06 found @ [00:37:11.187]->53494 2018-03-01 18:31:52.996541 I AFD: Chapter 07 found @ [00:43:54.840]->63172 2018-03-01 18:31:52.996572 I AFD: Chapter 08 found @ [00:51:53.485]->74648 2018-03-01 18:31:52.996603 I AFD: Chapter 09 found @ [01:00:29.334]->87017 2018-03-01 18:31:52.996634 I AFD: Chapter 10 found @ [01:07:59.659]->97814 2018-03-01 18:31:52.996665 I AFD: Chapter 11 found @ [01:14:05.816]->106592 2018-03-01 18:31:52.996697 I AFD: Chapter 12 found @ [01:24:52.504]->122098 2018-03-01 18:31:52.996728 I AFD: Chapter 13 found @ [01:29:27.696]->128696 2018-03-01 18:31:52.996759 I AFD: Chapter 14 found @ [01:37:47.236]->140672 2018-03-01 18:31:52.996789 I AFD: Chapter 15 found @ [01:45:53.263]->152325 2018-03-01 18:31:52.996819 I AFD: Chapter 16 found @ [01:55:49.484]->166620 2018-03-01 18:31:52.999427 I Using file start 2018-03-01 18:31:53.001902 I VideoOutput: Allowed renderers: vdpau 2018-03-01 18:31:53.001933 I VideoOutput: Allowed renderers (filt: vdpau): vdpau 2018-03-01 18:31:53.002155 I VDP: Accepting: cmp() w(>=0) h(>=720) framerate() codecs() dec(vdpau) cpus(4) skiploop(enabled) rend(vdpau) osd(vdpau) osdfade(enabled) deint(vdpaubasicdoublerate,vdpauadvanced) filt(vdpaucolorspace=auto,vdpausharpen=1.0) 2018-03-01 18:31:53.002233 I VDP: Accepting: cmp() w() h() framerate() codecs() dec(vdpau) cpus(4) skiploop(enabled) rend(vdpau) osd(vdpau) osdfade(enabled) deint(vdpauadvanceddoublerate,vdpauadvanced) filt(vdpaucolorspace=auto) 2018-03-01 18:31:53.002266 I VDP: LoadBestPreferences(1920x800, 23.976, h264) 2018-03-01 18:31:53.002372 I VDP: LoadBestPreferences Result prio:1, w:>=0, h:>=720, fps:, codecs:, decoder:vdpau, renderer:vdpau, deint:vdpaubasicdoublerate 2018-03-01 18:31:53.002398 I VideoOutput: Preferred renderer: vdpau 2018-03-01 18:31:53.002409 I VideoOutput: Trying video renderer: \'vdpau\' 2018-03-01 18:31:53.040527 D ColourSpace: Brightness: 0.0000 Contrast: 1.0000 Saturation: 1.0000 Hue: 0.0000 StudioLevels: 0 2018-03-01 18:31:53.040560 D ColourSpace: 1.1644 0.0000 1.5972 -0.8748 2018-03-01 18:31:53.040584 D ColourSpace: 1.1644 -0.3916 -0.8128 0.5315 2018-03-01 18:31:53.040609 D ColourSpace: 1.1644 2.0184 0.0000 -1.0862 2018-03-01 18:31:53.040640 D ColourSpace: Brightness: 0.0000 Contrast: 1.0000 Saturation: 1.0000 Hue: 0.0000 StudioLevels: 0 2018-03-01 18:31:53.040667 D ColourSpace: 1.1644 0.0000 1.5972 -0.8748 2018-03-01 18:31:53.040692 D ColourSpace: 1.1644 -0.3916 -0.8128 0.5315 2018-03-01 18:31:53.040715 D ColourSpace: 1.1644 2.0184 0.0000 -1.0862 2018-03-01 18:31:53.040746 D ColourSpace: Brightness: 0.0000 Contrast: 1.0000 Saturation: 0.8400 Hue: 0.0000 StudioLevels: 0 2018-03-01 18:31:53.040772 D ColourSpace: 1.1644 0.0000 1.3416 -0.7465 2018-03-01 18:31:53.040796 D ColourSpace: 1.1644 -0.3289 -0.6828 0.4348 2018-03-01 18:31:53.040819 D ColourSpace: 1.1644 1.6954 0.0000 -0.9241 2018-03-01 18:31:53.040850 D ColourSpace: Brightness: 0.0000 Contrast: 1.0000 Saturation: 0.8400 Hue: 0.0000 StudioLevels: 0 2018-03-01 18:31:53.040874 D ColourSpace: 1.1644 0.0000 1.3416 -0.7465 2018-03-01 18:31:53.040899 D ColourSpace: 1.1644 -0.3289 -0.6828 0.4348 2018-03-01 18:31:53.040922 D ColourSpace: 1.1644 1.6954 0.0000 -0.9241 2018-03-01 18:31:53.040952 D ColourSpace: Brightness: 0.0000 Contrast: 1.0000 Saturation: 0.8400 Hue: 0.0000 StudioLevels: 1 2018-03-01 18:31:53.040977 D ColourSpace: 1.0000 0.0000 1.1785 -0.5916 2018-03-01 18:31:53.041002 D ColourSpace: 1.0000 -0.2890 -0.5998 0.4461 2018-03-01 18:31:53.041025 D ColourSpace: 1.0000 1.4893 0.0000 -0.7476 2018-03-01 18:31:53.086405 I VideoOutWindow::SetPIPState. pip_state: 0] 2018-03-01 18:31:53.086451 I Clearing OpenGL painter cache. 2018-03-01 18:31:53.262724 I Snapping width to avoid scaling: width: 1920, left: 0 2018-03-01 18:31:53.262764 I Display Rect left: 0, top: 240, width: 1920, height: 600, aspect: 1.33333 2018-03-01 18:31:53.262789 I Video Rect left: 0, top: 0, width: 1920, height: 800, aspect: 2.4 2018-03-01 18:31:53.262808 I Snapping width to avoid scaling: width: 1920, left: 0 2018-03-01 18:31:53.262831 I Display Rect left: 0, top: 240, width: 1920, height: 600, aspect: 1.33333 2018-03-01 18:31:53.262855 I Video Rect left: 0, top: 0, width: 1920, height: 800, aspect: 2.4 2018-03-01 18:31:53.262879 I VDP: SetVideoRenderer(vdpau) 2018-03-01 18:31:53.262897 I VDP: SetVideoRender(vdpau) == GetVideoRenderer() 2018-03-01 18:31:53.264032 I Trying to match best refresh rate 23.976Hz 2018-03-01 18:31:53.264078 I Changing to 1920x1080 23.971 Hz 2018-03-01 18:31:53.298116 I Dynamic TwinView rate found, set 23.9709Hz as XRandR 54 2018-03-01 18:31:53.708490 I SwitchToVideo: Video size 1920 x 800: Switched to displaying resolution 1920 x 1080, 650mm x 366mm 2018-03-01 18:31:53.708521 I Snapping height to avoid scaling: height: 800, top: 140 2018-03-01 18:31:53.708536 I Snapping width to avoid scaling: width: 1920, left: 0 2018-03-01 18:31:53.708565 I Display Rect left: 0, top: 140, width: 1920, height: 800, aspect: 1.77778 2018-03-01 18:31:53.708590 I Video Rect left: 0, top: 0, width: 1920, height: 800, aspect: 2.4 2018-03-01 18:31:53.708612 I VideoOutput: Pixel dimensions: Screen 1920x1080, window 1920x1080 2018-03-01 18:31:53.708635 I VideoOutput: Actual display dimensions: 650x366 mm Aspect: 1.77596 2018-03-01 18:31:53.708656 I VideoOutput: Estimated window dimensions: 650x366 mm Aspect: 1.77596 2018-03-01 18:31:53.708773 I VidOutVDPAU: VDPAU Sharpen 1.00 2018-03-01 18:31:53.772524 I VDPAU: Created 2 output surfaces. 2018-03-01 18:31:53.772572 I VDPAU: Set colorkey to 0x20202 2018-03-01 18:31:53.772592 I VDPAU: Created VDPAU render device 1920x1080 2018-03-01 18:31:53.784168 I VidOutVDPAU: Created VDPAU osd (1920x1080) 2018-03-01 18:31:54.028784 I ColourSpace: PictureAttributes: Brightness, Contrast, Colour, Hue, Studio Levels, 2018-03-01 18:31:54.028813 I VidOutVDPAU: Using ITU BT.709 colorspace 2018-03-01 18:31:54.028879 D ColourSpace: Brightness: 0.0000 Contrast: 1.0000 Saturation: 0.8400 Hue: 0.0000 StudioLevels: 1 2018-03-01 18:31:54.028922 D ColourSpace: 1.0000 0.0000 1.3189 -0.6620 2018-03-01 18:31:54.028963 D ColourSpace: 1.0000 -0.1571 -0.3918 0.2755 2018-03-01 18:31:54.029003 D ColourSpace: 1.0000 1.5587 0.0000 -0.7824 2018-03-01 18:31:54.029053 I Snapping height to avoid scaling: height: 800, top: 140 2018-03-01 18:31:54.029075 I Snapping width to avoid scaling: width: 1920, left: 0 2018-03-01 18:31:54.029111 I Display Rect left: 0, top: 140, width: 1920, height: 800, aspect: 1.77778 2018-03-01 18:31:54.029151 I Video Rect left: 0, top: 0, width: 1920, height: 800, aspect: 2.4 2018-03-01 18:31:54.029172 I VidOutVDPAU: Created VDPAU context (GPU decode) 2018-03-01 18:31:54.035677 I Over/underscan. V: 0, H: 0 2018-03-01 18:31:54.035702 I Snapping height to avoid scaling: height: 800, top: 140 2018-03-01 18:31:54.035716 I Snapping width to avoid scaling: width: 1920, left: 0 2018-03-01 18:31:54.035743 I Display Rect left: 0, top: 140, width: 1920, height: 800, aspect: 1.77778 2018-03-01 18:31:54.035767 I Video Rect left: 0, top: 0, width: 1920, height: 800, aspect: 2.4 2018-03-01 18:31:54.035809 D Player(0): InitFilters() vo \'vdpaucolorspace=auto,vdpausharpen=1.0\' prog \'\' over \'\' 2018-03-01 18:31:54.035866 I FilterManager: GetFilterInfo(convert) returning: 0x0 2018-03-01 18:31:54.035909 I Player(0): LoadFilters(\'vdpaucolorspace=auto,vdpausharpen=1.0\'..) -> 0x0 2018-03-01 18:31:54.041679 I Player(0): Decoder thread starting. 2018-03-01 18:31:54.076587 I OSD: Loaded window osd_message 2018-03-01 18:31:54.094747 I OSD: Loaded window osd_input 2018-03-01 18:31:54.207991 I OSD: Loaded window program_info 2018-03-01 18:31:54.254124 I OSD: Loaded window browse_info 2018-03-01 18:31:54.292391 I OSD: Loaded window osd_status 2018-03-01 18:31:54.405206 I OSD: Loaded window osd_program_editor 2018-03-01 18:31:54.471236 I OSD: Loaded window osd_debug 2018-03-01 18:31:54.471326 I OSD: Loaded OSD: size 1920x1080 offset 0+0 2018-03-01 18:31:54.472102 I OSD: Created window aa_OSD_SUBTITLES 2018-03-01 18:31:54.475499 I EnableCaptions(4) msg: Napisy 1: English WĹÄ cz 2018-03-01 18:31:54.475557 I Player(0): ClearAfterSeek(0) 2018-03-01 18:31:54.475953 I AOBase: OutputAudioLoop: Play Event 2018-03-01 18:31:54.477219 I VDP: GetFilteredDeint() : vdpau -> \'vdpaubasicdoublerate\' 2018-03-01 18:31:54.480572 I VidOutVDPAU: Enabled deinterlacing. 2018-03-01 18:31:54.480765 E VSYNC: DRMVideoSync: VBlank ioctl did not work, unimplemented in this driver? 2018-03-01 18:31:54.480896 E VSYNC: RTCVideoSync: Could not open /dev/rtc: eno: No such file or directory (2) 2018-03-01 18:31:54.480931 E Player(0): Video sync method can\'t support double framerate (refresh rate too low for 2x deint) 2018-03-01 18:31:54.491968 I VDP: GetFilteredDeint(vdpauadvanced) : vdpau -> \'vdpauadvanced\' 2018-03-01 18:31:54.495646 I VidOutVDPAU: Enabled deinterlacing. 2018-03-01 18:31:54.502803 I Player(0): Video timing method: USleep with busy wait 2018-03-01 18:31:54.502847 I Player(0): Display Refresh Rate: 23.971 Video Frame Rate: 23.976 2018-03-01 18:31:54.502875 I Player(0): SetFrameInterval ps:1 scan:1 2018-03-01 18:31:54.520450 I playCtx: StartPlaying(): took 0 ms to start player. 2018-03-01 18:31:54.520497 I TV::StartPlayer(): Created player. 2018-03-01 18:31:54.520540 D TV::StartPlayer(): (0, WatchingVideo, main) -- end ok 2018-03-01 18:31:54.520628 I TV::HandleStateChange(): Changing from None to WatchingVideo 2018-03-01 18:31:54.532856 D TV::DrawUnusedRects(): -- begin 2018-03-01 18:31:54.532894 D TV::DrawUnusedRects(): -- end 2018-03-01 18:31:54.532986 I TV::HandleStateChange(): Main UI disabled. 2018-03-01 18:31:54.533011 D TV::HandleStateChange(): (0) -- end 2018-03-01 18:31:54.551543 D TV::StartTV(): tv->Playback() -- end 2018-03-01 18:31:54.554418 I TV::StartTV(): Entering main playback loop. 2018-03-01 18:31:54.626763 D ScreenSaverX11Private: ResetTimer -- begin 2018-03-01 18:31:54.626780 D ScreenSaverX11Private: StopTimer 2018-03-01 18:31:54.630162 D ScreenSaverX11Private: StartTimer 2018-03-01 18:31:54.630240 D ScreenSaverX11Private: ResetTimer -- end 2018-03-01 18:31:54.636838 I Player(0): Waiting for video buffers... 2018-03-01 18:31:54.643172 D TV::DrawUnusedRects(): -- begin 2018-03-01 18:31:54.643211 D TV::DrawUnusedRects(): -- end 2018-03-01 18:31:54.695869 I VidOutVDPAU: Added 3 new buffers. New buffer size 17 (5 decode and 12 process) 2018-03-01 18:31:54.732801 I VidOutVDPAU: Created VDPAU decoder (5 ref frames) 2018-03-01 18:31:54.743130 N Player(0): Waited 106ms for video buffers AAAAAAAAAAAAALLLL 2018-03-01 18:31:54.754124 I Player(0): progressive frame seen after 2 interlaced frames 2018-03-01 18:31:54.754160 I Player(0): A/V predict drop frame, dropping frame to catch up. 2018-03-01 18:31:54.754249 I Player(0): Waiting for video buffers... 2018-03-01 18:31:54.789856 I VDPAU: Added 2 output surfaces (total 4, max 4) 2018-03-01 18:31:54.871786 I Player(0): Disabled deinterlacing 2018-03-01 18:31:54.874543 I Player(0): Video is 3.61741 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.874574 I AOBase: Pause 1 2018-03-01 18:31:54.874654 I Player(0): Video is 4.48729 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.874669 I AOBase: Pause 1 2018-03-01 18:31:54.874735 I Player(0): Video is 4.88796 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.874749 I AOBase: Pause 1 2018-03-01 18:31:54.874813 I Player(0): Video is 4.9427 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.874826 I AOBase: Pause 1 2018-03-01 18:31:54.874890 I Player(0): Video is 4.73199 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.874903 I AOBase: Pause 1 2018-03-01 18:31:54.874966 I Player(0): Video is 4.32222 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.874980 I AOBase: Pause 1 2018-03-01 18:31:54.875044 I Player(0): Video is 3.76913 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.875057 I AOBase: Pause 1 2018-03-01 18:31:54.875106 I Player(0): Waiting for video buffers... 2018-03-01 18:31:54.875180 D Dec: TranslatePosition(key=3): extrapolating to (0,0) 2018-03-01 18:31:54.875206 D Dec: TranslatePosition(key=3, ratio=41.7083): extrapolating to (3,125) 2018-03-01 18:31:54.875221 D Dec: TranslatePosition(key=182601): extrapolating to (0,0) 2018-03-01 18:31:54.875246 D Dec: TranslatePosition(key=182601, ratio=41.7083): extrapolating to (182601,7615983) 2018-03-01 18:31:54.880076 I AOBase: OutputAudioLoop: audio paused 2018-03-01 18:31:54.880625 D Dec: TranslatePosition(key=3): extrapolating to (0,0) 2018-03-01 18:31:54.880657 D Dec: TranslatePosition(key=3, ratio=41.7083): extrapolating to (3,125) 2018-03-01 18:31:54.880672 D Dec: TranslatePosition(key=182601): extrapolating to (0,0) 2018-03-01 18:31:54.880697 D Dec: TranslatePosition(key=182601, ratio=41.7083): extrapolating to (182601,7615983) 2018-03-01 18:31:54.886090 I Player(0): Video is 3.10257 frames behind audio (too slow), dropping frame to catch up. 2018-03-01 18:31:54.886151 I Player(0): Waiting for video buffers... 2018-03-01 18:31:54.886218 D Dec: TranslatePosition(key=3): extrapolating to (0,0) 2018-03-01 18:31:54.886244 D Dec: TranslatePosition(key=3, ratio=41.7083): extrapolating to (3,125) 2018-03-01 18:31:54.886260 D Dec: TranslatePosition(key=182601): extrapolating to (0,0) 2018-03-01 18:31:54.886284 D Dec: TranslatePosition(key=182601, ratio=41.7083): extrapolating to (182601,7615983) 2018-03-01 18:31:54.891636 D Dec: TranslatePosition(key=3): extrapolating to (0,0) 2018-03-01 18:31:54.891664 D Dec: TranslatePosition(key=3, ratio=41.7083): extrapolating to (3,125) 2018-03-01 18:31:54.891679 D Dec: TranslatePosition(key=182601): extrapolating to (0,0) 2018-03-01 18:31:54.891703 D Dec: TranslatePosition(key=182601, ratio=41.7083): extrapolating to (182601,7615983) 2018-03-01 18:31:54.897034 D Dec: TranslatePosition(key=3): extrapolating to (0,0) 2018-03-01 18:31:54.897062 D Dec: TranslatePosition(key=3, ratio=41.7083): extrapolating to (3,125) 2018-03-01 18:31:54.897077 D Dec: TranslatePosition(key=182601): extrapolating to (0,0) 2018-03-01 18:31:54.897100 D Dec: TranslatePosition(key=182601, ratio=41.7083): extrapolating to (182601,7615983) 2018-03-01 18:31:54.902482 I AOBase: Pause 0 2018-03-01 18:31:54.909367 I AOBase: OutputAudioLoop: Play Event 2018-03-01 18:31:58.656710 I Player(0): FPS: 24.35 Mean: 41075 Std.Dev: 16304 CPUs: 34% 39% 35% 37% 2018-03-01 18:32:02.618857 I Player(0): FPS: 23.98 Mean: 41703 Std.Dev: 109 CPUs: 3% 5% 5% 5% 2018-03-01 18:32:03.996574 I AFD: gopset not set, syncing positionMap 2018-03-01 18:32:03.996608 I Dec: Resyncing position map. posmapStarted = 0 livetv(0) watchingRec(0) 2018-03-01 18:32:03.996622 I AFD: Initial key frame distance: 15. 2018-03-01 18:32:06.581140 I Player(0): FPS: 23.98 Mean: 41704 Std.Dev: 51 CPUs: 2% 5% 4% 6% 2018-03-01 18:32:10.543356 I Player(0): FPS: 23.98 Mean: 41703 Std.Dev: 54 CPUs: 3% 2% 3% 3% 2018-03-01 18:32:11.294058 I Player(0): 400 progressive frames seen. 2018-03-01 18:32:11.335804 D Running HouseKeeper. 2018-03-01 18:32:11.335832 D Checking to run HardwareProfiler 2018-03-01 18:32:14.005572 I AFD: Key frame distance changed from 239 to 240. 2018-03-01 18:32:14.505665 I Player(0): FPS: 23.98 Mean: 41704 Std.Dev: 97 CPUs: 3% 4% 4% 4% 2018-03-01 18:32:17.301442 I AFD: Key frame distance changed from 240 to 79. 2018-03-01 18:32:18.467883 I Player(0): FPS: 23.98 Mean: 41703 Std.Dev: 97 CPUs: 3% 2% 2% 3% 2018-03-01 18:32:21.304046 D LastPlayPos frame=639 2018-03-01 18:32:21.304171 D PortChecker::checkPort(): host 192.168.1.254 port 3306 timeLimit 30000 linkLocalOnly 1 2018-03-01 18:32:21.722371 I AFD: Key frame distance changed from 79 to 106. 2018-03-01 18:32:22.430183 I Player(0): FPS: 23.98 Mean: 41704 Std.Dev: 55 CPUs: 3% 3% 3% 5% 2018-03-01 18:32:23.224926 I Subtitles: Initialised libass object. 2018-03-01 18:32:23.242113 I Subtitles: Initialised libass renderer. 2018-03-01 18:32:23.242369 E libASS log output truncated 255 of 555 bytes written 2018-03-01 18:32:23.242414 D libass:Raster: FreeType 2.7.1Shaper: FriBidi 0.19.5 (SIMPLE)InitializedEvent: [Script Info] ; Script generated by FFmpeg/Lavc57.107.100 ScriptType: v4.00+ PlayResX: 384 PlayResY: 288 [V4+ Styles] Format: Name, Fontname, Fontsize, PrimaryColour, SecondaryColour, OutlineColour, BackColour, Bold, Italic, Underline, Str 2018-03-01 18:32:23.244264 D Style format: Name, Fontname, Fontsize, PrimaryColour, SecondaryColour, OutlineColour, BackColour, Bold, Italic, Underline, StrikeOut, ScaleX, ScaleY, Spacing, Angle, BorderStyle, Outline, Shadow, Alignment, MarginL, MarginR, MarginV, Encoding[0x6298a50] Style: Default,Arial,16,&Hffffff,&Hffffff,&H0,&H0,0,0,0,0,100,100,0,0,1,1,0,2,10,10,10,0Name = DefaultFontName = ArialFontSize = 16PrimaryColour = &HffffffSecondaryColour = &HffffffOutlineColour = &H0BackColour = &H0Bold = 0Italic = 0Underline = 0StrikeOut = 0ScaleX = 100ScaleY = 100Spacing = 0Angle = 0BorderStyle = 1Outline = 1Shadow = 0Alignment = 2MarginL = 10MarginR = 10MarginV = 10Encoding = 0Event format: Layer, Start, End, Style, Name, MarginL, MarginR, MarginV, Effect, TextEvent: Dialogue: 0,0:00:28.57,0:00:31.91,Default,,0,0,0,,{\i1}Rich city folks\Nand their fancy apartments.{\i0} 2018-03-01 18:32:26.269652 I AFD: Key frame distance changed from 106 to 109. 2018-03-01 18:32:26.309169 I TV::LoadFileHelper(): Loading menu /home/minimyth/.mythtv/menu_playback.xml 2018-03-01 18:32:26.309291 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/Default/menu_playback.xml 2018-03-01 18:32:26.309397 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/default-wide/menu_playback.xml 2018-03-01 18:32:26.310700 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/default/menu_playback.xml 2018-03-01 18:32:26.315862 I TV::LoadFileHelper(): Loading menu /home/minimyth/.mythtv/menu_playback_compact.xml 2018-03-01 18:32:26.315933 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/Default/menu_playback_compact.xml 2018-03-01 18:32:26.316012 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/default-wide/menu_playback_compact.xml 2018-03-01 18:32:26.316074 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/default/menu_playback_compact.xml 2018-03-01 18:32:26.316519 I TV::LoadFileHelper(): Loading menu /home/minimyth/.mythtv/menu_playback.xml 2018-03-01 18:32:26.316573 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/Default/menu_playback.xml 2018-03-01 18:32:26.316613 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/default-wide/menu_playback.xml 2018-03-01 18:32:26.316649 I TV::LoadFileHelper(): Loading menu /usr/share/mythtv/themes/default/menu_playback.xml 2018-03-01 18:32:26.319919 I AFD: GetCurrentChapter(selected chapter 1 framenum 0) 2018-03-01 18:32:26.394343 I ScreenSaverX11Private: Calling xscreensaver-command -deactivate 2018-03-01 18:32:26.420932 I Player(0): FPS: 23.81 Mean: 42003 Std.Dev: 8713 CPUs: 7% 4% 11% 5% 2018-03-01 18:32:27.977318 I Player(0): 800 progressive frames seen. 2018-03-01 18:32:29.147441 D Layer = 0Start = 0:00:28.57Duration = 0:00:31.91Style = DefaultName = MarginL = 0MarginR = 0MarginV = 0Effect = Text = {\i1}Rich city folks\Nand their fancy apartments.{\i0}fontconfig: Selected font is not the requested one: \'Liberation Sans\' != \'Arial\'Font info: family \'Liberation Sans\', style \'Regular\', fullname \'Liberation Sans\', slant 0, weight 80fontconfig_select: (Arial, 80, 0) -> /usr/share/fonts/X11/TTF/LiberationSans-Regular.ttf, 0fontconfig: Selected font is not the requested one: \'Liberation Sans Italic\' != \'Arial\'Font info: family \'Liberation Sans\', style \'Italic\', fullname \'Liberation Sans Italic\', slant 100, weight 80fontconfig_select: (Arial, 80, 110) -> /usr/share/fonts/X11/TTF/LiberationSans-Italic.ttf, 0forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shifting from 16 to 42 by (-273.453125, 44.406250)forced line break at 15shift 2018-03-01 18:32:29.604108 I AFD: GetCurrentChapter(selected chapter 1 framenum 0) 2018-03-01 18:32:30.354738 I Player(0): FPS: 24.15 Mean: 41404 Std.Dev: 5179 CPUs: 7% 4% 6% 6% 2018-03-01 18:32:31.022921 I AFD: Key frame distance changed from 109 to 114. 2018-03-01 18:32:31.147250 D TV::OSDDialogEvent(): result -1 text action 0 2018-03-01 18:32:33.692232 D LastPlayPos frame=936 2018-03-01 18:32:33.696284 D TV::SetActive(): (0,w/o OSD) 0 -> 0 -- begin 2018-03-01 18:32:33.696371 D TV::SetActive(): (0,w/o OSD) 0 -> 0 -- end 2018-03-01 18:32:33.734348 D TV::HandleStateChange(): (0) -- begin 2018-03-01 18:32:33.734387 I TV::HandleStateChange(): Attempting to change from WatchingVideo to None 2018-03-01 18:32:33.734443 D TV::StopStuff(): For player ctx 0 -- begin 2018-03-01 18:32:33.734469 D TV::SetActive(): (0,w/o OSD) 0 -> 0 -- begin 2018-03-01 18:32:33.734527 D TV::SetActive(): (0,w/o OSD) 0 -> 0 -- end 2018-03-01 18:32:33.734549 I Player(0): StopPlaying - begin 2018-03-01 18:32:33.745339 I Player(0): Decoder thread exiting. 2018-03-01 18:32:33.745504 I Player(0): Exited decoder loop. 2018-03-01 18:32:33.801494 I VidOutVDPAU: DiscardFrames(1) 2018-03-01 18:32:33.801674 I VideoBuffers::DiscardFrames(1): UAUUUAUUUAUUUUUAU 2018-03-01 18:32:33.801854 I VideoBuffers::DiscardFrames(1): AAAAAAAAAAAAAAAAA -- done 2018-03-01 18:32:33.801901 I VidOutVDPAU: DiscardFrames() 3: AAAAAAAAAAAAAAAAA -- done() 2018-03-01 18:32:33.807081 W MythPainter: 44 images not yet de-allocated. 2018-03-01 18:32:33.807147 I VDPAU Painter: Clearing VDPAU painter cache. 2018-03-01 18:32:33.915507 I VDPAU Painter: Clearing VDPAU painter cache. 2018-03-01 18:32:33.915580 I Using 1920x1080 23.971 Hz 2018-03-01 18:32:33.915612 I SwitchToGUI: Switched to 1920x1080 23.971 Hz 2018-03-01 18:32:33.915690 I AOBase: Killing AudioOutputDSP 2018-03-01 18:32:33.936102 I AOBase: OutputAudioLoop: Stop Event 2018-03-01 18:32:33.936117 I AOBase: kickoffOutputAudioLoop exiting 2018-03-01 18:32:34.277778 I Player(0): StopPlaying - end 2018-03-01 18:32:34.277799 I TV::StopStuff(): Stopping ring buffer 2018-03-01 18:32:34.277864 I TV::StopStuff(): Stopping player 2018-03-01 18:32:34.277877 D TV::StopStuff(): -- end 2018-03-01 18:32:34.277903 I TV::HandleStateChange(): Changing from WatchingVideo to None 2018-03-01 18:32:34.277935 D TV::HandleStateChange(): (0) -- end 2018-03-01 18:32:34.277970 I TV::StartTV(): Exiting main playback loop. 2018-03-01 18:32:34.277986 I TV::StartTV(): -- process events 2 begin 2018-03-01 18:32:34.278262 D ScreenSaverX11Private: StopTimer 2018-03-01 18:32:34.279037 I TV::StartTV(): -- process events 2 end 2018-03-01 18:32:34.279062 D TV::~TV(): -- begin 2018-03-01 18:32:34.291657 I TV::~TV(): -- lock 2018-03-01 18:32:34.292450 I Player(0): StopPlaying - begin 2018-03-01 18:32:34.292492 I Player(0): Exited decoder loop. 2018-03-01 18:32:34.292512 I Player(0): StopPlaying - end 2018-03-01 18:32:34.302558 D TV::~TV(): -- end 2018-03-01 18:32:34.304387 N Resuming idle timer 2018-03-01 18:32:34.304433 D TV::StartTV(): -- end
comment:3 Changed 3 years ago by
Perhaps the srt file has wrong permissions or for some other reason the backend cannot read it. Did you try with the same sample file you sent me? Maybe the sample works but the full file does not.
comment:4 Changed 3 years ago by
Peter,
I do following tests:
sample5.mkv + sample5.srt - NOK
other mkv + sample5.srt - OK
sample5.mkv + other .srt - NOK
so definitely there is something strange with sample5.mkv.
access rights are OK - as other players are playing fine via NFS and CIFS from be server. I verify rights. all files have mythtv:mythtv; 644
When I enabled fe logging with playback, audio with debug level, this sample5.mkv gives me following entries in log:
2018-03-01 21:18:29.833823 I Subtitles: Initialised libass object. 2018-03-01 21:18:29.855328 I Subtitles: Initialised libass renderer. 2018-03-01 21:18:29.855388 E libASS log output truncated 255 of 555 bytes written 2018-03-01 21:18:29.855419 D forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break at 29forced line break 2018-03-01 21:18:29.856937 D Style format: Name, Fontname, Fontsize, PrimaryColour, SecondaryColour, OutlineColour, BackColour, Bold, Italic, Underline, StrikeOut, ScaleX, ScaleY, Spacing, Angle, BorderStyle, Outline, Shadow, Alignment, MarginL, MarginR, MarginV, Encoding[0x951edc0] Style: Default,Arial,16,&Hffffff,&Hffffff,&H0,&H0,0,0,0,0,100,100,0,0,1,1,0,2,10,10,10,0Event format: Layer, Start, End, Style, Name, MarginL, MarginR, MarginV, Effect, TextEvent: Dialogue: 0,0:00:28.57,0:00:31.91,Default,,0,0,0,,{\i1}Rich city folks\Nand their fancy apartments.{\i0}
other files don't produce such log.
May You look at Yours log and verify do You have similar entries with sample5.mkv?
NOTE: above entries are from mkv embedded subtitles - not from external .srt file. My hypothesis is that mkv embedded subtitles are somehow causing that loading of external subtitles not works. Interesting is why it works for You but not works form me on 2 different platforms (linux and macOS)
also pls notice:
2018-03-01 21:18:29.855388 E libASS log output truncated 255 of 555 bytes written
comment:5 Changed 3 years ago by
Ok - I found it. Issue is with file name:
The Glass Castle (2017).mkv - NOK
Glass Castle (2017).mkv - OK
Interesting is that I have more movies with this issue...
I'm wonder what software component deals with "the" prefix? It looks like this makes difference testing on original filename between Yours tests (are OK) and mine (NOK).
comment:6 Changed 3 years ago by
I still cannot see the problem. I renamed your files sample5.mkv and sample5.srt to "The Sample5.mkv" and "The Sample5.srt" and still the subtitles are working. I searched my library for other moves with "The" and with srt files. I found one, and I tested it and subtitles are working. The subtitle file name has to exactly match the mkv file name.
If the word "The" is causing problems it may be something to do with translation. Do you use it with English or Polish as the language? You could try setting the language to English and see if that changes the problem. I tried setting the language to Polish and the subtitles seemed to be working but I was struggling to understand the menus so I could not do much.
When you set the language to Polish does it still sort "The Glass Castle" with the "G" titles or does it sort it with "T" ? I assume that "The" is not a valid Polish word and should not be treated specially if you have selected Polish language.
comment:7 Changed 3 years ago by
Peter,
I still cannot see the problem. I renamed your files sample5.mkv and sample5.srt to "The Sample5.mkv" and "The Sample5.srt" and >>still the subtitles are working.
May You pls try with exact "The Glass Castle (2017).mkv[srt]" and "Glass Castle (2017).mkv[srt]"?
If the word "The" is causing problems it may be something to do with translation. Do you use it with English or Polish as the language?
I'm using Polish in UI Language settings.
You could try setting the language to English and see if that changes the problem.
I changed all localization settings to English and this not helps.
When you set the language to Polish does it still sort "The Glass Castle" with the "G" titles or does it sort it with "T" ?
"The" is skipped in sorting. I mean sorting is based on the letter in word after "the". Interesting is that I have multiple movies with titles starting with "The" - and almost all are OK. Just filename "The Glass Castle (2017)" makes problem. Removing only word "The" in filename fixes issue. I have this problem on: MiniMyth2 (qt5.4.1), macOS (Archlinux; qt5.5.1) and RPI2(ArchArm?; qt5.9.2). I still think it is kind of bug in mythtv. Maybe we should add some debug logging in code to see how myth processes filename stuff for movie and subtitles?
comment:8 Changed 3 years ago by
I renamed sample5 to The Glass Castle (2017).mkv and srt. External subtitles are working from a local frontend on the same backend but are not working from a remote backend.
I will investigate and fix this.
comment:9 Changed 3 years ago by
Status: | new → accepted |
---|
comment:10 Changed 3 years ago by
Resolution: | → fixed |
---|---|
Status: | accepted → closed |
comment:12 Changed 3 years ago by
Milestone: | needs_triage → 29.2 |
---|
comment:14 Changed 3 years ago by
Owner: | changed from Peter Bennett to Peter Bennett |
---|
It works fine for me on master. I put both files from your tar in the video directory and scanned. When I play video the menu shows subtitles->text subtitles->External Subtitles option. When I select that option I see subtitles in a strange language.