MythTV / mythtv

The official MythTV repository
https://www.mythtv.org
GNU General Public License v2.0
705 stars 345 forks source link

Subtitles display a little too early #789

Closed white-haired-uncle closed 10 months ago

white-haired-uncle commented 1 year ago

mythbackend: Linux mythbackend 5.19.0-38-generic #39~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 17 21:16:15 UTC 2 x86_64 x86_64 x86_64 GNU/Linux

mythfrontend: Linux spartan 5.15.0-73-generic #80-Ubuntu SMP Mon May 15 15:18:26 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux

$ mythbackend --version Please attach all output as a file in bug reports. MythTV Version : v33.1+fixes.202303140136.7f288be61b~ubuntu22.04.1 MythTV Branch : fixes/33 Network Protocol : 91 Library API : 33.20220913-1 QT Version : 5.15.3 Options compiled in: linux profile use_hidesyms using_alsa using_oss using_pulse using_pulseoutput using_backend using_bindings_perl using_bindings_python using_bindings_php using_dvb using_firewire using_frontend using_hdhomerun using_satip using_vbox using_ceton using_joystick_menu using_libcec using_libcrypto using_gnutls using_libdns_sd using_libxml2 using_lirc using_mheg using_opengl using_egl using_qtwebkit using_qtscript using_qtdbus using_taglib using_v4l2 using_v4l2prime using_x11 using_system_libbluray using_system_libudfread using_systemd_notify using_systemd_journal using_drm using_bindings_perl using_bindings_python using_bindings_php using_freetype2 using_mythtranscode using_opengl using_egl using_drm using_vaapi using_nvdec using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2 using_libmp3lame

spartan$ mythfrontend --version Please attach all output as a file in bug reports. MythTV Version : v33.1-18-g21d2d9d951 MythTV Branch : fixes/33 Network Protocol : 91 Library API : 33.20220913-1 QT Version : 5.15.3 Options compiled in: linux profile use_hidesyms using_alsa using_oss using_pulse using_pulseoutput using_backend using_bindings_perl using_bindings_python using_bindings_php using_dvb using_firewire using_frontend using_hdhomerun using_satip using_vbox using_ceton using_joystick_menu using_libcec using_libcrypto using_gnutls using_libdns_sd using_libxml2 using_lirc using_mheg using_opengl using_egl using_qtwebkit using_qtscript using_qtdbus using_taglib using_v4l2 using_v4l2prime using_x11 using_system_libbluray using_system_libudfread using_systemd_notify using_systemd_journal using_drm using_bindings_perl using_bindings_python using_bindings_php using_freetype2 using_mythtranscode using_opengl using_egl using_drm using_vaapi using_nvdec using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2

As the episode begins, CC says "No!" three times, each a second or so too early (you have to watch carefully, the first one only lasts for an instant). A few seconds later, the CC seems to sync with the dialog but then it gets out of sync again.

vlc/mpv show the CC as the actors speak, with the exception of "I didn't see this..." which is a bit early (not as much as myth).

Unfortunately, I had to really hack this down to fit in the file size limit. Another minute or so would show CC going in an out of sync, sometimes much worse than this example.

Attached file was from HDHR, run through mythtranscode lossless-only profile (which made it a little less noticable), then ffmpeg -i foo.mpg -to 0:00:30 -o foo2.mpg. Renamed to mp4 for upload.

https://github.com/MythTV/mythtv/assets/135195815/ce8607e7-eb38-441f-9802-9ead70f45c04

Ref: https://forum.mythtv.org/viewtopic.php?f=36&t=5479

white-haired-uncle commented 1 year ago

This is the output from mpv on the original recording. The errors disappear as soon as I run it through ffmpeg/transcode.

spartan$ mpv /export/video2/2623_20230807040000.ts                                                 

[ffmpeg/demuxer] mpegts: PES packet size mismatch
[ffmpeg/demuxer] mpegts: Packet corrupt (stream = 1, dts = 4709425295).
 (+) Video --vid=1 (mpeg2video 720x480 29.970fps)
 (+) Audio --aid=1 --alang=eng (ac3 2ch 48000Hz)
 (+) Video --vid=1 (mpeg2video 720x480 29.970fps)
 (+) Audio --aid=1 --alang=eng (ac3 2ch 48000Hz)
     Subs  --sid=1 (*) (eia_608)
AO: [pulse] 48000Hz stereo 2ch float
VO: [gpu] 720x480 => 853x480 yuv420p
AV: 00:00:01 / 00:59:56 (0%) A-V:  0.000 Dropped: 6 Cache: 172s/47MB
[ffmpeg/demuxer] mpegts: Packet corrupt (stream = 0, dts = 4401631130).
[ffmpeg/demuxer] mpegts: PES packet size mismatch
[ffmpeg/demuxer] mpegts: Packet corrupt (stream = 1, dts = 4401582095).
AV: 00:00:08 / 00:59:56 (0%) A-V:  0.000 Dropped: 28 Cache: 544s/150MB
Track switched:
 (+) Video --vid=1 (mpeg2video 720x480 29.970fps)
 (+) Audio --aid=1 --alang=eng (ac3 2ch 48000Hz)
 (+) Subs  --sid=1 (*) (eia_608)
AV: 00:00:09 / 00:59:56 (0%) A-V:  0.000 Dropped: 36 Cache: 160s/43MB
[ffmpeg/demuxer] mpegts: Packet corrupt (stream = 0, dts = 4401631130).
[ffmpeg/demuxer] mpegts: PES packet size mismatch
[ffmpeg/demuxer] mpegts: Packet corrupt (stream = 1, dts = 4401582095).

And the processed file

spartan$ mpv /export/share/video/2623_20230807040000-30sec.mp4 
 (+) Video --vid=1 (mpeg2video 720x480 29.970fps)
 (+) Audio --aid=1 (ac3 2ch 48000Hz)
AO: [pulse] 48000Hz stereo 2ch float
VO: [gpu] 720x480 => 853x480 yuv420p
 (+) Video --vid=1 (mpeg2video 720x480 29.970fps)
 (+) Audio --aid=1 (ac3 2ch 48000Hz)
     Subs  --sid=1 (*) (eia_608)
AV: 00:00:04 / 00:00:30 (14%) A-V:  0.000 Cache: 25s/7MB
Track switched:
 (+) Video --vid=1 (mpeg2video 720x480 29.970fps)
 (+) Audio --aid=1 (ac3 2ch 48000Hz)
 (+) Subs  --sid=1 (*) (eia_608)
AV: 00:00:29 / 00:00:30 (100%) A-V:  0.000 Dropped: 22 Cache: 0.0s
white-haired-uncle commented 1 year ago

Same file played in myth

2023-08-18 14:30:38.461740 I  Player(0): Opening '/net/hawkeye/export/video2/2623_20230807040000.ts
'
2023-08-18 14:30:38.588137 I  AFD: codec ac3 has 2 channels
2023-08-18 14:30:38.593694 I  AFD: Opened codec 0x55aed9893140, id(ac3) type(Audio)
2023-08-18 14:30:38.594373 I  AFD: Using vaapi for video decoding
2023-08-18 14:30:38.594401 I  AFD: Opened codec 0x55aedb317440, id(mpeg2video) type(Video)
2023-08-18 14:30:38.594488 I  AOBase: Opening audio device 'default' ch 2(2) sr 48000 sf 32 bit flo
ating point reenc 0
2023-08-18 14:30:38.656780 E  ALSA: no playback control PCM found on mixer device default
2023-08-18 14:30:38.656788 E  ALSA: Unable to open audio mixer. Volume control disabled
2023-08-18 14:30:38.716359 W  VDPAUInterop: GL_NV_vdpau_interop is not available
2023-08-18 14:30:38.770819 I  Clearing OpenGL painter cache.
libva info: VA-API version 1.14.0
libva info: Trying to open /usr/lib/x86_64-linux-gnu/dri/iHD_drv_video.so
libva info: Found init function __vaDriverInit_1_14
libva info: va_openDriver() returns 0
2023-08-18 14:30:38.802564 I  PlayerVideo: Queuing callback for VAAPI context creation
2023-08-18 14:30:38.850983 I  PlayerVideo: Executing VAAPI context creation
2023-08-18 14:30:38.857081 I  VAAPIInterop: Created VAAPI 1.14 display for GL-VAAPI-DRM (Intel iHD
driver for Intel(R) Gen Graphics - 22.3.1 ())
2023-08-18 14:30:39.192329 I  Qt: libpng warning: iCCP: known incorrect sRGB profile
2023-08-18 14:30:39.196869 I  Qt: libpng warning: iCCP: known incorrect sRGB profile
2023-08-18 14:30:39.197770 I  Qt: libpng warning: iCCP: known incorrect sRGB profile
2023-08-18 14:30:39.268453 I  VideoOutput: SetDeinterlacing (Doublerate 1): Single High|CPU|GLSL|DR
IVER Double High|CPU|GLSL|DRIVER
2023-08-18 14:30:39.275690 I  TV::StartPlayer(): Created player.
2023-08-18 14:30:39.275777 I  TV::HandleStateChange(): Changing from None to WatchingPreRecorded
2023-08-18 14:30:39.294481 I  ScreenSaverX11: Inhibited X11 screensaver
2023-08-18 14:30:39.326703 I  ScreenSaverX11: DPMS Deactivated 1
2023-08-18 14:30:39.326828 I  TV::HandleStateChange(): Main UI disabled.
2023-08-18 14:30:39.326908 I  TV::StartTV(): Entering main playback loop.
2023-08-18 14:30:39.329464 I  VideoOutput: SetDeinterlacing (Doublerate 1): Single High|CPU|GLSL|DR
IVER Double High|CPU|GLSL|DRIVER
2023-08-18 14:30:39.331453 E  VAAPIInterop: VAAPI deinterlacer config failed - 'motion_compensated'
 unsupported?
2023-08-18 14:30:39.331635 E  VAAPIInterop: Failed to create VAAPI deinterlacer 2x VAAPI Compensate
d - disabling
2023-08-18 14:30:39.331971 I  GLVid: New frame format: None:None 720x480 (Tex: 2D) -> VAAPI:NV12 72
0x480 (Tex: 2D)
2023-08-18 14:32:47.539588 I  ScreenSaverX11: Uninhibited screensaver
2023-08-18 14:32:47.540055 I  ScreenSaverX11: DPMS Reactivated 1
2023-08-18 14:32:48.354958 I  ScreenSaverX11: Inhibited X11 screensaver
2023-08-18 14:32:48.410183 I  ScreenSaverX11: DPMS Deactivated 1
2023-08-18 14:32:48.410331 I  VideoOutput: SetDeinterlacing (Doublerate 1): Single High|CPU|GLSL|DR
IVER Double High|CPU|GLSL|DRIVER
DRM_IOCTL_I915_GEM_CONTEXT_DESTROY failed: Bad file descriptor
2023-08-18 14:33:00.422140 I  TV::HandleStateChange(): Attempting to change from WatchingPreRecorde
d to None
2023-08-18 14:33:00.422165 I  ScreenSaverX11: Uninhibited screensaver
2023-08-18 14:33:00.424203 I  ScreenSaverX11: DPMS Reactivated 1
2023-08-18 14:33:00.463695 I  OpenGLInterop: Deleted 30 textures in 15 groups
2023-08-18 14:33:00.937426 I  TV::HandleStateChange(): Changing from WatchingPreRecorded to None
2023-08-18 14:33:00.937541 I  TV::StartTV(): Exiting main playback loop.
2023-08-18 14:33:00.938862 N  Resuming idle timer
2023-08-18 14:33:06.257645 I  Created ExitPrompter
white-haired-uncle commented 1 year ago

This is another frontend that shows the same issue, view basically the same file (after lossless transcode):

Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythplayer.cpp:430 (OpenFile) Player(g): Opening '/net/hawkeye/export/video2/2623_20230807040000.mpg'
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext avformatdecoder.cpp:2029 (ScanStreams) AFD: codec ac3 has 2 channels
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext avformatdecoder.cpp:2508 (OpenAVCodec) AFD: Opened codec 0x55903a9e9180, id(ac3) type(Audio)
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext avformatdecoder.cpp:2427 (ScanStreams) AFD: Using ffmpeg for video decoding
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext avformatdecoder.cpp:2508 (OpenAVCodec) AFD: Opened codec 0x55903d341e80, id(mpeg2video) type(Video)
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext audiooutputdigitalencoder.cpp:119 (Init) DEnc: Using codec ac3 to encode audio
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext audiooutputbase.cpp:782 (Reconfigure) AOBase: Opening audio device 'iec958:CARD=NVidia,DEV=0' ch 2(2) sr 48000 sf signed 16 bit reenc 1
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: E CoreContext audiooutputalsa.cpp:950 (OpenMixer) ALSA: no playback control PCM found on mixer device default
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: E CoreContext audiooutputalsa.cpp:493 (OpenDevice) ALSA: Unable to open audio mixer. Volume control disabled
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythpainteropengl.cpp:77 (ClearCache) Clearing OpenGL painter cache.
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythvideoout.cpp:175 (SetDeinterlacing) VideoOutput: SetDeinterlacing (Doublerate 1): Single Medium|CPU Double Basic|CPU
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext tv_play.cpp:4658 (StartPlayer) TV::StartPlayer(): Created player.
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext tv_play.cpp:2187 (HandleStateChange) TV::HandleStateChange(): Changing from None to WatchingPreRecorded
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythscreensaverx11.cpp:248 (Disable) ScreenSaverX11: Inhibited X11 screensaver
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythscreensaverx11.cpp:128 (DisableDPMS) ScreenSaverX11: DPMS Deactivated 1
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext tv_play.cpp:2263 (HandleStateChange) TV::HandleStateChange(): Main UI disabled.
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext tv_play.cpp:356 (StartTV) TV::StartTV(): Entering main playback loop.
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythvideoout.cpp:175 (SetDeinterlacing) VideoOutput: SetDeinterlacing (Doublerate 1): Single Medium|CPU Double Basic|CPU
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythdeinterlacer.cpp:161 (Filter) MythDeint: Deinterlacer change: 0x0 None dr:0 tff:1 -> 720x480 YUV420P dr:1 tff:1
Aug 19 14:16:54 wolverine mythfrontend: mythfrontend[1289]: I CoreContext mythopenglvideo.cpp:477 (SetupFrameFormat) GLVid: New frame format: None:None 720x480 (Tex: 2D) -> YUV420P:YUV420P 720x480 (Tex: 2D)
Aug 19 14:17:14 wolverine mythfrontend: mythfrontend[1289]: I CoreContext tv_play.cpp:1955 (HandleStateChange) TV::HandleStateChange(): Attempting to change from WatchingPreRecorded to None

I don't remember why it says "-dirty", but I think it's from when I modified something to do with translation to fix an issue with the icon help files when you hit F1 in the main FE screen.

wolverine# mythfrontend --version
Please attach all output as a file in bug reports.
MythTV Version : v33.1-12-gc4b7e4c433-dirty
MythTV Branch : fixes/33
Network Protocol : 91
Library API : 33.20220913-1
QT Version : 5.15.3
Options compiled in:
 linux profile use_hidesyms using_alsa using_oss using_pulse using_pulseoutput using_backend using_bindings_perl using_bindings_python using_bindings_php using_dvb using_firewire using_frontend using_hdhomerun using_satip using_vbox using_ceton using_joystick_menu using_libcec using_libcrypto using_gnutls using_libdns_sd using_libxml2 using_lirc using_mheg using_opengl using_egl using_qtwebkit using_qtscript using_qtdbus using_sqlite3 using_taglib using_v4l2 using_v4l2prime using_x11 using_system_libbluray using_system_libudfread using_systemd_notify using_systemd_journal using_drm using_bindings_perl using_bindings_python using_bindings_php using_freetype2 using_mythtranscode using_opengl using_egl using_drm using_vaapi using_nvdec using_vdpau using_ffmpeg_threads using_mheg using_libass using_libxml2
billmeek commented 1 year ago

On Saturday 19 August 2023 01:25:08 PM (-05:00), white-haired-uncle wrote:

I don't remember why it says "-dirty", but I think it's from when I modified something to do with translation to fix an issue with the icon help files when you hit F1 in the main FE screen.

git status and git diff will jog your memory ;). -- Bill

white-haired-uncle commented 1 year ago

Cool, thanks for the tip.

Changes not staged for commit:
  (use "git add <file>..." to update what will be committed)
  (use "git restore <file>..." to discard changes in working directory)
        modified:   i18n/mythfrontend_en_us.qm
        modified:   i18n/mythfrontend_en_us.ts
BrettLMiller commented 1 year ago

Suggest that the sample video would be more representative if it was still a transport stream file & cut using "dd". Touching file with any other tool is not lossless.

white-haired-uncle commented 10 months ago

I am unable to reliably reproduce this issue. I thought I was experiencing the same issue as another user, but it looks like it's just similar symptoms.