Opened 18 months ago
Closed 18 months ago
Last modified 16 months 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 18 months ago by
comment:2 Changed 18 months 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 18 months 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 18 months 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 18 months 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 18 months 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 18 months 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 18 months 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 18 months ago by
| Status: | new → accepted |
|---|
comment:10 Changed 18 months ago by
| Resolution: | → fixed |
|---|---|
| Status: | accepted → closed |
comment:12 Changed 18 months ago by
| Milestone: | needs_triage → 29.2 |
|---|
comment:14 Changed 16 months ago by
| Owner: | changed from Peter Bennett to Peter Bennett |
|---|
Note: See
TracTickets for help on using
tickets.
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.