mythtranscode crashes in 0.25

[pinball.rules@…]

I have myth installed under Ubuntu and have been getting regular crashes of mythtranscode. Ubuntu bug has been reporting the crash information to Ubuntu, but I thought it would be useful to open a bug here too. I am attaching the apport crash report that contains a the crash dump, as well as all the other useful information.

[pinball.rules@…]

apport crash report minus crash dump and a bunch of logs to fit in max upload space

[pinball.rules@…]

Crash dump was too big, so I had to edit it out along with a bunch of logs. I left as much information as I could regarding the crash and the mythtranscode log.

I forgot to specify the version on ticket submission. This is for Myth version 0.25+fixes. Here is the Ubuntu package information

jheck@paragon:~$ dpkg -l |grep myth
ii  libmyth-0.25-0                         2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 Common library code for MythTV and add-on modules (runtime)
ii  libmyth-python                         2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A python library to access some MythTV features
ii  libmythes-1.2-0                        2:1.2.2-1                                simple thesaurus library
ii  libmythtv-perl                         2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A PERL library to access some MythTV features
ii  mythes-en-us                           1:3.3.0-2ubuntu3                         English Thesaurus for LibreOffice/OpenOffice.org
ii  mythtv                                 2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A personal video recorder application (client and server)
ii  mythtv-backend                         2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A personal video recorder application (server)
ii  mythtv-common                          2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A personal video recorder application (common data)
ii  mythtv-database                        2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A personal video recorder application (database)
ii  mythtv-frontend                        2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 A personal video recorder application (client)
ii  mythtv-transcode-utils                 2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 Utilities used for transcoding MythTV tasks
ii  mythweb                                2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 Web interface add-on module for MythTV
ii  php-mythtv                             2:0.25.0+fixes.20120410.1f5962a-0ubuntu1 PHP Bindings for MythTV

[pinball.rules@…]

I've been trying some additional tests and looking at the mythtranscode log. I've noticed a few errors that my be relevant. In my test I'm trying to invoke mythtv to transcode a previously recorded show from the 'Watch Recordings' menu. In previous tests this had worked for me, but I couldn't get it to work in this set of tests. Refer to the annotated log snippet below.

May 21 08:06:59 paragon mythtranscode[4147]: E CoreContext recordingprofile.cpp:164 (addSelection) SampleRate: Attempted to add a rate 32000 Hz, which is not in the list of allowed rates.

This error was occurring until I changed the sampling rate of the transcoders to 48000. It's curious to me that 32000 is the default yet this error is in the logs. I'm not sure if it's significant or not.

May 21 08:24:08 paragon mythtranscode[5387]: C thread_unknown mythcommandlineparser.cpp:2534 (ConfigureLogging) mythtranscode version: fixes/0.25 [v0.25] www.mythtv.org
May 21 08:24:08 paragon mythtranscode[5387]: N thread_unknown mythcommandlineparser.cpp:2536 (ConfigureLogging) Enabled verbose msgs:  general
May 21 08:24:08 paragon mythtranscode[5387]: N thread_unknown logging.cpp:1176 (logStart) Setting Log Level to LOG_INFO
May 21 08:24:08 paragon mythtranscode[5387]: I thread_unknown logging.cpp:229 (FileLogger) Added logging to the console
May 21 08:24:08 paragon mythtranscode[5387]: I thread_unknown logging.cpp:369 (SyslogLogger) Added syslogging to facility local7
May 21 08:24:08 paragon mythtranscode[5387]: I thread_unknown logging.cpp:425 (DatabaseLogger) Added database logging to table logging
May 21 08:24:08 paragon mythtranscode[5387]: N thread_unknown logging.cpp:1215 (logStart) Setting up SIGHUP handler
May 21 08:24:08 paragon mythtranscode[5387]: N thread_unknown mythdirs.cpp:51 (InitializeMythDirs) Using runtime prefix = /usr
May 21 08:24:08 paragon mythtranscode[5387]: N thread_unknown mythdirs.cpp:64 (InitializeMythDirs) Using configuration directory = /home/mythtv/.mythtv
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext mythcorecontext.cpp:227 (Init) Assumed character encoding: en_US.UTF-8
May 21 08:24:08 paragon mythtranscode[5387]: E CoreContext configuration.cpp:64 (Load) Error parsing: /home/mythtv/.mythtv/config.xml at line: 1  column: 1
May 21 08:24:08 paragon mythtranscode[5387]: E CoreContext configuration.cpp:66 (Load) Error Msg: unexpected end of file

This first significant error seems to be caused by parsing an empty config.xml file. I looked and the mythtv user's .mythtv/config.xml file is a link that points to /etc/mythtv/config.xml, which is empty. Note that I login and use a different user to control mythtv. My normal user has a .mythtv/config.xml file that is not a link, but rather an actual file and contains a stanza with configuration (but that is not a link). I also noticed that the /etc/mythtv/config.xml file gets updated after running mythtv-setup and some other times too (I have noticed it's timestamp is always sometime in the previous 24 hours). My guess here is that at some point this file got truncated by some action within mythtv. I have repaired the /etc/mythtv/config.xml file by copying back the version from my normal user and the error no longer appears in my mythtranscode log. The file has not been truncated over the last day (though its timestamp did change over night and again when I ran mythtv-setup again this morning).

May 21 08:24:08 paragon mythtranscode[5387]: N CoreContext mythcontext.cpp:477 (LoadDatabaseSettings) Empty LocalHostName.
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext mythcontext.cpp:481 (LoadDatabaseSettings) Using localhost value of paragon
May 21 08:24:08 paragon mythtranscode[5387]: E CoreContext configuration.cpp:64 (Load) Error parsing: /home/mythtv/.mythtv/config.xml at line: 1  column: 1
May 21 08:24:08 paragon mythtranscode[5387]: E CoreContext configuration.cpp:66 (Load) Error Msg: unexpected end of file
May 21 08:24:08 paragon mythtranscode[5387]: N CoreContext mythcorecontext.cpp:1270 (InitLocale) Setting QT default locale to EN_US
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext mythcorecontext.cpp:1303 (SaveLocaleDefaults) Current locale EN_US
May 21 08:24:08 paragon mythtranscode[5387]: N CoreContext mythlocale.cpp:121 (LoadDefaultsFromXML) Reading locale defaults from /usr/share/mythtv//locales/en_us.xml
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext mythtranslation.cpp:66 (load) Loading en_us translation for module mythfrontend
May 21 08:24:08 paragon mythtranscode[5387]: N CoreContext main.cpp:540 (main) Transcoding from /var/lib/mythtv/sg_a/recordings/2622_20120521053000.mpg to /var/lib/mythtv/sg_a/recordings/2622_20120521053000.mpg.tmp
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext avformatdecoder.cpp:2100 (ScanStreams) AFD: Opened codec 0xe57170, id(MPEG2VIDEO) type(Video)
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext avformatdecoder.cpp:1958 (ScanStreams) AFD: codec AC3 has 6 channels
May 21 08:24:08 paragon mythtranscode[5387]: I CoreContext avformatdecoder.cpp:2100 (ScanStreams) AFD: Opened codec 0xe5bb20, id(AC3) type(Audio)
May 21 08:24:08 paragon mythtranscode[5387]: N CoreContext audioplayer.cpp:167 (ReinitAudio) AudioPlayer: Enabling Audio
May 21 08:24:08 paragon mythtranscode[5387]: N CoreContext transcode.cpp:1030 (TranscodeFile) Found video height of 1088.  This is unusual and more than likely the video is actually 1080 so mythtranscode will treat it as such.
May 21 08:24:08 paragon mythtranscode[5387]: E CoreContext NuppelVideoRecorder.cpp:610 (SetupAVCodecVideo) NVR(): Unable to open FFMPEG/mpeg4 codec

This seems to be the end of the line for each failed transcode attempt. I'm not sure why it can't open the FFMPEG/mpeg4 codec. As I said above, it has been able to transcode a few shows successfully, but it fails more than it succeeds as shown in this log.

[sphery]

Replying to pinball.rules@…:

This first significant error seems to be caused by parsing an empty config.xml file. I looked and the mythtv user's .mythtv/config.xml file is a link that points to /etc/mythtv/config.xml, which is empty. Note that I login and use a different user to control mythtv. My normal user has a .mythtv/config.xml file that is not a link, but rather an actual file and contains a stanza with configuration (but that is not a link). I also noticed that the /etc/mythtv/config.xml file gets updated after running mythtv-setup and some other times too (I have noticed it's timestamp is always sometime in the previous 24 hours). My guess here is that at some point this file got truncated by some action within mythtv. I have repaired the /etc/mythtv/config.xml file by copying back the version from my normal user and the error no longer appears in my mythtranscode log. The file has not been truncated over the last day (though its timestamp did change over night and again when I ran mythtv-setup again this morning).

This issue was fixed in 3fb9d6eb77 in master, only (and the changes are too invasive to backport). See #10305 and #10249.

[cpinkham]

The attached log file mentions the "Deadlock detected. One buffer is full when the other is empty! Aborting" issue making this ticket a partial duplicate of #2077. The log in comment #2 regarding FFMPEG/mpeg4 is not lossless which means it would be a different unrelated issue. There was a recent fix related to high-resolution transcoding profiles, so it is possible that this is related to that issue. We will need more logs to try to debug though. If you can reproduce the FFMPEG/mpeg4 issue, please run mythtranscode with "-v libav" to see if that helps us know what's going on inside the FFMPEG code.

[stuartm]

No response to request for further information after 2 months.