search

MythTV / mythtv

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

Mytharchive crashes when processing video clip with audio codec Opus #633

Closed bshanteau closed 1 year ago

bshanteau commented 2 years ago

What steps will reproduce the bug?

Utilities->Mytharchive->Create a DVD-> iso file of a video clip (downloaded from YouTube) with audio codec Opus. The problem does not occur when the audio codec is AC3.

This short clip illustrates the issue: Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv.zip

How often does it reproduce? Is there a required condition?

Every time processing video clip >1 minute with audio codec Opus.

What is the expected behaviour?

Create iso.

What do you see instead?

mythburn.log.zip mythburn.log:

...
Extracting thumbnail image from /storage/mytharchive/work/1/stream.mv2 at position 10
Destination file /storage/mytharchive/work/1/title.jpg
Segmentation fault (core dumped)
************************************************************
ERROR: Failed while running mytharchivehelper to get thumbnails.
Result: 139, Command was mytharchivehelper -q -q --createthumbnail --infile "/storage/mytharchive/work/1/stream.mv2" --thumblist '10' --outfile "/storage/mytharchive/work/1/title.jpg"
See mythburn.log for more information.
************************************************************

Terminated

Additional information

rcrdnalor commented 2 years ago

Since you run mythtv master on Ubuntu, please check if the mythtv-dbg package is installed/installable. See https://launchpad.net/~mythbuntu/+archive/ubuntu/33 https://www.mythtv.org/wiki/Debugging for further information.

The ticket how-to suggests that you should post a backtrace of the segfault you got on your system: See https://www.mythtv.org/wiki/Trac:TicketHowTo Please keep the source, the reason of your segfault for later posting on request of the MythTV developer.

In case you need further information, please search the mailingt list https://lists.archive.carbon60.com/mythtv/ or the forum https://forum.mythtv.org/ for getting a proper backtrace.

In this case, please post the backtrace of

mytharchivehelper -q -q --createthumbnail --infile "/storage/mytharchive/work/1/stream.mv2" --thumblist '10' --outfile "/storage/mytharchive/work/1/title.jpg"

when runnning under gdb.

bshanteau commented 2 years ago

@rcrdnalor gdb.txt

rcrdnalor commented 2 years ago

Great, it looks like mytharchivehelper segfaults when it tries to de-interlace a frame at https://github.com/MythTV/mythtv/blob/ecc24f1e154003a629acfbd02b5560b6292160dd/mythplugins/mytharchive/mytharchivehelper/mytharchivehelper.cpp#L1709

The segfault occurs in 

mythdeinterlacer.cpp:550
550                     _mm_avg_epu8(*reinterpret_cast<__m128i*>(&above[col]), mid);

Could you please post the output of

mythffprobe -hide_banner /storage/mytharchive/work/1/stream.mv2

This file should be available after mythburn.py closes on error.

Could you please post the file 'stream.mv2', or at least the first few MBytes (20 to 100) somewhere in the net ?

Possible duplicates to this issue are #626, #615 .

bshanteau commented 2 years ago

@rcrdnalor

$ mythffprobe -hide_banner /storage/mytharchive/work/1/stream.mv2
Input #0, mpegvideo, from '/storage/mytharchive/work/1/stream.mv2':
  Duration: N/A, bitrate: N/A
  Stream #0:0: Video: mpeg2video (Main), yuv420p(tv, bt709, progressive), 352x480 [SAR 80:33 DAR 16:9], 29.97 fps, 29.97 tbr, 1200k tbn, 59.94 tbc
    Side data:
      cpb: bitrate max/min/avg: 9000000/0/0 buffer size: 1835008 vbv_delay: N/A

stream.mv2.tar.gz

KungFuJesus commented 2 years ago

Great, it looks like mytharchivehelper segfaults when it tries to de-interlace a frame at

https://github.com/MythTV/mythtv/blob/ecc24f1e154003a629acfbd02b5560b6292160dd/mythplugins/mytharchive/mytharchivehelper/mytharchivehelper.cpp#L1709

The segfault occurs in

mythdeinterlacer.cpp:550
550                       _mm_avg_epu8(*reinterpret_cast<__m128i*>(&above[col]), mid);

Could you please post the output of

mythffprobe -hide_banner /storage/mytharchive/work/1/stream.mv2

This file should be available after mythburn.py closes on error.

Could you please post the file 'stream.mv2', or at least the first few MBytes (20 to 100) somewhere in the net ?

Possible duplicates to this issue are #626, #615 .

A segfault there seems likely due to an unaligned access.

rcrdnalor commented 2 years ago

Analysis:

The code at https://github.com/MythTV/mythtv/blob/35eccb4fe249a89cbe2c67e9b3ce265868cc5e06/mythplugins/mytharchive/mytharchivehelper/mytharchivehelper.cpp#L1709 tries to de-interlace a FFMpeg 'AVframe' by converting it into a 'MythVideoFrame' by running https://github.com/MythTV/mythtv/blob/35eccb4fe249a89cbe2c67e9b3ce265868cc5e06/mythtv/libs/libmythtv/mythavutil.cpp#L134 and calling the MythTVs own deinterlacer. This conversion from an 'AVFrame' to 'MythVideoFrame' fails, because the 'MythVideoFrame' requires a continuous allocated space for all planes of a frame whilst the 'AVFrame' is more flexible in that way: The pointer substraction at https://github.com/MythTV/mythtv/blob/35eccb4fe249a89cbe2c67e9b3ce265868cc5e06/mythtv/libs/libmythtv/mythavutil.cpp#L148 does only work if all the needed memory is allocated within the same chunk. FFmpeg does no enforce this.

With that explanation in mind, the commit https://github.com/MythTV/mythtv/commit/bb6365f8765c6c4383a9c5bd860cb2d201442dad does not have any motivation.

Reverting the commit manually because of conflicts, the command line

mytharchivehelper --createthumbnail --infile "/path/to/above/mentioned/stream.mv2" --thumblist '1' --outfile "/tmp/title_02.jpg"

produces a valid image.

I do not know the impact on the current and future usage of FFmpeg within MythTV.

kmdewaal commented 2 years ago

Hi Roland, At first sight your analysis looks good to me. I do not fall in the category that has a deep insight but I can have a look at it. Can you please provide the patch to to reverse the offending commit? Thanks, Klaas.

rcrdnalor commented 2 years ago

This was the gdb sequence I did:

$ gdb mytharchivehelper
(gdb) set args --createthumbnail --infile /path/to/stream.mv2 --thumblist '1' --outfile "/tmp/title_02.jpg"

(gdb) break mythavutil.cpp:136

(gdb) run

(gdb) p Frame-> data[0]
$1 = (uint8_t *) 0x7fffe8022040

(gdb) p Frame-> data[1]
$2 = (uint8_t *) 0x5555557e0d80 

(gdb) p Frame-> data[2]
$3 = (uint8_t *) 0x5555557ec200 

(gdb) p Frame-> data[3]
$4 = (uint8_t *) 0x0

(gdb) p Frame->linesize[0]
$5 = 384
(gdb) p Frame->linesize[1]
$6 = 192
(gdb) p Frame->linesize[2]
$7 = 192
(gdb) p Frame->linesize[3]
$8 = 0`

I managed to finish the revert process today by adding the manually changed files to the commit.

Attached the patch, Roland 0001-Revert-MythAVUtil-Replace-MythPictureDeinterlace.zip

kmdewaal commented 2 years ago

The problem can be reproduced here both on mpeg2 and h264 coded videos. The audio codec does not matter. The attached patch that reverses the offending commit does indeed fix the problem.

Looking at the code and the debug data, I am not really convinced that the Frame does have correct pointer values to begin with. Here the pointer values look like this:

(gdb) p Frame->data[0]
$2 = (uint8_t *) 0x7fffdc496040
(gdb) p Frame->data[1]
$3 = (uint8_t *) 0x624100
(gdb) p Frame->data[2]
$4 = (uint8_t *) 0x63f180

I do somehow expect that all pointers should point to the same video buffer area but it looks like data[1] and data[2] are pointing to memory allocated from the heap and data[0] to stack memory.

Given that reverting commit https://github.com/MythTV/mythtv/commit/bb6365f8765c6c4383a9c5bd860cb2d201442dad does indeed fix the problem and that this code is used only in mytharchive I propose that we just put that in master.

kmdewaal commented 1 year ago

I have hacked together a fix in MythAVUtil::DeinterlaceAVFrame that does combine the three parts (Y, U, and V as I understand it) into a single array so that it can be used to create a valid MythVideoFrame. This is not entirely trivial since it needs 16-byte alignment otherwise it does crash in the __m128i instructions. The fix gives better image quality than the original code and that might be the reason why commit https://github.com/MythTV/mythtv/commit/bb6365f8765c6c4383a9c5bd860cb2d201442dad was made in the first place.

@KungFuJesus alignment was a good suggestion but in this case the addresses were aligned but pointing to a faraway place instead of into a video buffer.

It looks like that mytharchivehelper may have never worked at all in its current form.

This is an image from the YLE test file generated with the original code: yle-original

This is the same image but generated with the fixed code: yle-fix

bshanteau commented 1 year ago

@kmdewaal Wow. Impressive.

What testing needs to be done before committing the fixed code?

kmdewaal commented 1 year ago

@bshanteau the fix has been committed to master. It would be great if you can do a bit of additional testing. I think it should also be backported to fixes/32 if it works OK for everybody.

bshanteau commented 1 year ago

@kmdewaal wrote;

It would be great if you can do a bit of additional testing.

mytharchivehelper still segfaults with short video clip from original comment: Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv.zip

$ mytharchivehelper --version
Please attach all output as a file in bug reports.
MythTV Version : v33.0~master.202211182219.092ddc0970~ubuntu22.04.1
MythTV Branch : master
Network Protocol : 91
Library API : 33.20220201-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
$ mytharchivehelper --verbose --createthumbnail --infile "/storage/mytharchive/work/1/stream.mv2" --thumblist '10' --outfile "/storage/mytharchive/work/1/title.jpg"
2022-11-19 00:29:49.189168 C  mytharchivehelper version: master [v33.0~master.202211182219.092ddc0970~ubuntu22.04.1] www.mythtv.org
2022-11-19 00:29:49.189181 C  Qt version: compile: 5.15.3, runtime: 5.15.3
2022-11-19 00:29:49.189232 I  Linux Mint 21 (x86_64)
2022-11-19 00:29:49.189235 N  Enabled verbose msgs:  general
2022-11-19 00:29:49.189244 N  Setting Log Level to LOG_INFO
2022-11-19 00:29:49.199799 N  Using runtime prefix = /usr
2022-11-19 00:29:49.199802 N  Using configuration directory = /home/mythtv/.mythtv
2022-11-19 00:29:49.199858 I  Assumed character encoding: en_US.UTF-8
2022-11-19 00:29:49.199995 I  Added logging to the console
2022-11-19 00:29:49.200149 I  Empty LocalHostName. This is typical.
2022-11-19 00:29:49.200153 I  Using a profile name of: 'dvr' (Usually the same as this host's name.)
2022-11-19 00:29:49.200190 I  Start up testing connections. DB localhost, BE , attempt 0, status dbAwake, Delay: 2000
2022-11-19 00:29:50.249998 N  Setting QT default locale to en_US
2022-11-19 00:29:50.250018 I  Current locale en_US
2022-11-19 00:29:50.250120 N  Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
Segmentation fault (core dumped)

mythburn.log:

Using simple_fix_rtl
mythburn.py (0.2.20200122-1) starting up...
script path:/usr/share/mythtv/mytharchive/scripts
myth share path:/usr/share/mythtv
passed job file: /storage/mytharchive/config/mydata.xml
passed progress log file: /storage/mytharchive/logs/progress.log
mythburn.py (0.2.20200122-1) starting up...
Found 4 CPUs
Obtaining MythTV settings from MySQL database for hostname dvr
temppath: /storage/mytharchive/work
logpath:  /storage/mytharchive/logs
Setting process priority to 10
Setting ionice level to idle
Processing Mythburn job number 1.
Options - mediatype = 3, doburn = 1, createiso = 1, erasedvdrw = 0
          savefilename = '/storage/mytharchive/p-r.iso'
Looking for: /usr/share/mythtv/mytharchive/themes/Simple_-_Autoplay/theme.xml
Loading font 0, /usr/share/mythtv/fonts/FreeSans.ttf size 19
Loading font 1, /usr/share/mythtv/fonts/FreeSans.ttf size 15
Loading font 2, /usr/share/mythtv/fonts/FreeSans.ttf size 13
wantIntro: 0, wantMainMenu: 0, wantChapterMenu: 0, wantDetailsPage: 0
Final DVD Video format will be ntsc
There are 1 file(s) to process
Pre-processing file 1: '/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv'
Input #0, matroska,webm, from '/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv':
  Metadata:
    ENCODER         : Lavf58.76.100
  Duration: 00:01:00.00, start: 0.000000, bitrate: 539 kb/s
  Stream #0:0: Video: vp9 (Profile 0), yuv420p(tv, bt709), 1920x1080, SAR 1:1 DAR 16:9, 29.97 fps, 29.97 tbr, 1k tbn (default)
    Metadata:
      DURATION        : 00:00:59.993000000
  Stream #0:1(eng): Audio: opus, 48000 Hz, stereo, fltp (default)
    Metadata:
      DURATION        : 00:01:00.002000000
/storage/mytharchive/work/1/streaminfo.xml:-
<?xml version="1.0" ?><!DOCTYPE FILEINFO><file filename="/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv" duration="60" type="matroska,webm" cutduration="60">    
        <streams count="2">        
                <video streamindex="0" ffmpegindex="0" codec="vp9 (Profile 0)" start_time="0" aspectratio="N/A" id="0" width="1920" bitrate="0" fps="29.97003" height="1080"/>        
                <audio streamindex="1" ffmpegindex="1" samplerate="48000" codec="opus" channels="2" start_time="0" id="0" language="eng" bitrate="0"/>        
        </streams>    
</file>
Node = chanid, Data = 
Node = type, Data = file
Node = filename, Data = /storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv
Node = title, Data = /storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv
Node = recordingdate, Data = 
Node = recordingtime, Data = 
Node = subtitle, Data = 
Node = description, Data = 
Node = rating, Data = 
Node = coverfile, Data = 
Node = cutlist, Data = 
Video resolution is 1920 by 1080
*************************************************************
Processing file 1: '/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv'
*************************************************************
File type is 'matroska,webm'
Video codec is 'vp9 (Profile 0)'
Input #0, matroska,webm, from '/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv':
  Metadata:
    ENCODER         : Lavf58.76.100
  Duration: 00:01:00.00, start: 0.000000, bitrate: 539 kb/s
  Stream #0:0: Video: vp9 (Profile 0), yuv420p(tv, bt709), 1920x1080, SAR 1:1 DAR 16:9, 29.97 fps, 29.97 tbr, 1k tbn (default)
    Metadata:
      DURATION        : 00:00:59.993000000
  Stream #0:1(eng): Audio: opus, 48000 Hz, stereo, fltp (default)
    Metadata:
      DURATION        : 00:01:00.002000000
/storage/mytharchive/work/1/streaminfo.xml:-
<?xml version="1.0" ?><!DOCTYPE FILEINFO><file duration="60" type="matroska,webm" cutduration="60" filename="/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv">    
        <streams count="2">        
                <video streamindex="0" width="1920" ffmpegindex="0" id="0" start_time="0" codec="vp9 (Profile 0)" aspectratio="N/A" bitrate="0" height="1080" fps="29.97003"/>        
                <audio samplerate="48000" streamindex="1" ffmpegindex="1" id="0" start_time="0" channels="2" codec="opus" language="eng" bitrate="0"/>        
        </streams>    
</file>
Preferred audio languages eng and eng
Video id: 0x0, Audio1: [1] 0x0 (OPUS, eng), Audio2: [-1] - 0x-1 (N/A, N/A)
Re-encoding audio and video
Using encoder profiles from /usr/share/mythtv/mytharchive/encoder_profiles/ffmpeg_dvd_ntsc.xml
Encoding profile (LP) found
mythffmpeg -threads 4 -v 1 -i "/storage/mytharchive/Vuelta a España 2022 Stage 11 0:27:51 Extended Highlights Cycling o_edit.mkv" -r ntsc -target ntsc-dvd -b:v 2344k -s 352x480 -acodec ac3 -b:a 192k -ac 2 -aspect 16:9 "/storage/mytharchive/work/1/newfile2.mpg" -map 0:0 -map 0:1 
[mpeg @ 0x55bc1ab6b800] start time for stream 0 is not set in estimate_timings_from_pts
Input #0, mpeg, from '/storage/mytharchive/work/1/newfile2.mpg':
  Duration: 00:01:00.00, start: 0.533367, bitrate: 646 kb/s
  Stream #0:0[0x1bf]: Data: dvd_nav_packet
  Stream #0:1[0x1e0]: Video: mpeg2video (Main), yuv420p(tv, bt709, progressive), 352x480 [SAR 80:33 DAR 16:9], 29.97 fps, 29.97 tbr, 90k tbn
    Side data:
      cpb: bitrate max/min/avg: 9000000/0/0 buffer size: 1835008 vbv_delay: N/A
  Stream #0:2[0x80]: Audio: ac3, 48000 Hz, stereo, fltp, 192 kb/s
/storage/mytharchive/work/1/streaminfo.xml:-
<?xml version="1.0" ?><!DOCTYPE FILEINFO><file type="mpeg" duration="59" cutduration="59" filename="/storage/mytharchive/work/1/newfile2.mpg">    
        <streams count="3">        
                <data codec="" streamindex="0"/>        
                <video fps="29.97003" start_time="0.48003" id="480" bitrate="0" codec="mpeg2video (Main)" height="480" aspectratio="1.7777779" width="352" streamindex="1" ffmpegindex="0"/>        
                <audio start_time="0.48153" channels="2" id="128" bitrate="192000" codec="ac3" language="N/A" samplerate="48000" streamindex="2" ffmpegindex="1"/>        
        </streams>    
</file>
Preferred audio languages eng and eng
Video id: 0x1e0, Audio1: [1] 0x80 (AC3, N/A), Audio2: [-1] - 0x-1 (N/A, N/A)
Splitting MPEG stream into audio and video parts
Running: mythreplex --demux --fix_sync -o "/storage/mytharchive/work/1/stream" -v 224 -c 128 "/storage/mytharchive/work/1/newfile2.mpg"
Audio is already in ac3 format
Extracting thumbnail image from /storage/mytharchive/work/1/stream.mv2 at position 10
Destination file /storage/mytharchive/work/1/title.jpg
Segmentation fault (core dumped)
************************************************************
ERROR: Failed while running mytharchivehelper to get thumbnails.
Result: 139, Command was mytharchivehelper -q -q --createthumbnail --infile "/storage/mytharchive/work/1/stream.mv2" --thumblist '10' --outfile "/storage/mytharchive/work/1/title.jpg"
See mythburn.log for more information.
************************************************************

Terminated
rcrdnalor commented 1 year ago

Then provide the file : "/storage/mytharchive/work/1/stream.mv2" Please post the version of mytharchivehelper: "mytharchivehelper --version" Thx Roland

kmdewaal commented 1 year ago

Creating a thumbnail from stream.mv2 posted at Sep. 7 works OK for me. Could it be that the fix has not yet been propagated to the ubuntu packages?

bshanteau commented 1 year ago

@kmdewaal @rcrdnalor mytharchivehelper v33 working OK now.

$ mytharchivehelper --version
Please attach all output as a file in bug reports.
MythTV Version : v33.0~master.202211192219.296931bcf0~ubuntu22.04.1
MythTV Branch : master
Network Protocol : 91
Library API : 33.20220201-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
rcrdnalor commented 1 year ago

Your build logs from https://github.com/MythTV/mythtv/issues/633#issuecomment-1320832876 state: 2022-11-19 00:29:50, the installed version is v33.0~master.202211192219.296931bcf0~ubuntu22.04.1 which means, it was published at 2022-11-19 22:19 UTC . What's your time offset to UTC?

bshanteau commented 1 year ago

@rcrdnalor

What's your time offset to UTC?

Pacific Standard Time (PST). Offset UTC -8:00 hours

rcrdnalor commented 1 year ago

I was told that the local mirrors of Ubuntu need some time to synchronize as well. For that reason, it is always recommended to post the version of MythTV actually used in the message.

rcrdnalor commented 1 year ago

Issue closed as implemented on master and fixes/32. Feel free to re-open this issue or create a new one if this is still not solved.