[mythtv-users] trandcoding messes up 6 channel audio slow audio playback

Thu Apr 28 07:38:17 UTC 2011

So, what are people doing while mythtranscode doesn't work on 6 channel recordings? I'm burning through disk space pretty fast here. Are there any user jobs I could use to get essentially the same functionality as mythtranscode? I've already tried mythnuv2mkv, but that ruined my recordings in the same way as mythtrancode.

Hopefully this will get fixed soon and I wont need a user job. I've played around a bit and thought I would report on my findings. (Maybe someone finds them useful, or knows what I could do to get more useful results).

I've got another machine that has basically the same set up as my normal backend minus the tuner cards. I compiled the source from https://github.com/MythTV/mythtv/tree/jyavenard/backports/fixes/0.24 that Jean-Yves posted on this other machine. I transfered over mythconverg and a couple of recordings from my actual backend so I could do some testing on this other machine.

I tried to transcode a recording from my cable box with 6 channel audio. I called mythranscode as:
/usr/local/bin/mythtranscode --infile 10181_20110427200700.mpg --outfile /home/scott/HDtestoutput.mpg --profile 27  --showprogress -v audio

(--profile 27 is the profile I described in an earlier post)

here's what happened

[scott at scottdesk recordings]$ /usr/local/bin/mythtranscode --infile 10181_20110427200700.mpg --outfile /home/scott/HDtestoutput.mpg --profile 27  --showprogress -v audio
2011-04-28 01:26:24.465 Using runtime prefix = /usr/local
2011-04-28 01:26:24.465 Using configuration directory = /home/scott/.mythtv
2011-04-28 01:26:24.466 Empty LocalHostName.
2011-04-28 01:26:24.466 Using localhost value of scottdesk
2011-04-28 01:26:24.471 New DB connection, total: 1
2011-04-28 01:26:24.479 Connected to database 'mythconverg' at host: localhost
2011-04-28 01:26:24.485 Closing DB connection named 'DBManager0'
2011-04-28 01:26:24.486 Connected to database 'mythconverg' at host: localhost
2011-04-28 01:26:24.489 Current locale en_US
2011-04-28 01:26:24.489 Reading locale defaults from /usr/local/share/mythtv//locales/en_us.xml
2011-04-28 01:26:24.505 Loading en_us translation for module mythfrontend
2011-04-28 01:26:24.506 Enabled verbose msgs:  important general audio
2011-04-28 01:26:24.515 Transcoding from 10181_20110427200700.mpg to /home/scott/HDtestoutput.mpg
2011-04-28 01:26:24.605 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.606 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.606 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.606 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.607 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.607 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.607 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.607 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.607 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.607 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.608 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.608 [mpeg2video @ 0x7fed4cbe4320]mpeg_decode_postinit() failure
2011-04-28 01:26:24.629 MythCoreContext: Connecting to backend server: 127.0.0.1:6543 (try 1 of 1)
2011-04-28 01:26:24.630 Using protocol version 65
2011-04-28 01:26:24.637 AFD: Opened codec 0x194e700, id(MPEG2VIDEO) type(Video)
2011-04-28 01:26:24.637 AFD: codec AC3 has 5 channels
2011-04-28 01:26:24.637 AFD: Opened codec 0x195cc40, id(AC3) type(Audio)
2011-04-28 01:26:24.637 AFD: Audio Track #1 is A/V stream #1 and has 5 channels in the English language(6647399).
2011-04-28 01:26:24.637 AFD: codec AC3 has 2 channels
2011-04-28 01:26:24.638 AFD: Opened codec 0x195d4c0, id(AC3) type(Audio)
2011-04-28 01:26:24.638 AFD: Audio Track #2 is A/V stream #2 and has 2 channels in the Spanish; Castilian language(7565409).
2011-04-28 01:26:24.638 AFD: Trying to select default track
2011-04-28 01:26:24.638 AFD: Trying to select audio track (w/lang)
2011-04-28 01:26:24.638 AFD: Selected track 1: English AC3 5ch (A/V Stream #1)
2011-04-28 01:26:24.638 AFD: Initializing audio parms from audio track #1
2011-04-28 01:26:24.638 AFD: Audio format changed 
from id(NONE)     -1Hz -1ch -1bps     (profile 0) to id( AC3)  48000Hz  5ch 16bps     (profile 0)
2011-04-28 01:26:24.638 AudioPlayer: Enabling Audio
2011-04-28 01:26:24.641 Found video height of 1088.  This is unusual and more than likely the video is actually 1080 so mythtranscode will treat it as such.
2011-04-28 01:26:24.654 New DB connection, total: 2
2011-04-28 01:26:24.655 Connected to database 'mythconverg' at host: localhost
2011-04-28 01:26:24.729 NVR(/dev/video): Audio device 0 buffer size: 0 bytes
2011-04-28 01:26:24.866 Copying Audio while transcoding Video
2011-04-28 01:26:24.994 mythtranscode: 0% Completed @ 0 fps.
2011-04-28 01:26:26.516 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:28.075 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:29.548 Processed: 88 of 1708 frames(2 seconds)
2011-04-28 01:26:29.613 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:31.112 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:32.734 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:34.212 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:34.602 Processed: 187 of 1708 frames(6 seconds)
2011-04-28 01:26:35.762 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:37.316 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:39.052 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:39.604 Processed: 278 of 1708 frames(9 seconds)
2011-04-28 01:26:40.986 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:42.968 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:44.623 Processed: 355 of 1708 frames(11 seconds)
2011-04-28 01:26:44.900 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:45.002 mythtranscode: 21% Completed @ 17.9281 fps.
2011-04-28 01:26:46.836 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:48.716 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:49.689 Processed: 435 of 1708 frames(14 seconds)
2011-04-28 01:26:50.587 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:52.424 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:54.227 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:54.695 Processed: 517 of 1708 frames(17 seconds)
2011-04-28 01:26:56.089 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:58.102 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:26:59.758 Processed: 591 of 1708 frames(19 seconds)
2011-04-28 01:27:00.375 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:02.687 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:04.815 Processed: 657 of 1708 frames(21 seconds)
2011-04-28 01:27:04.927 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:05.041 mythtranscode: 38% Completed @ 16.4779 fps.
2011-04-28 01:27:06.334 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:07.612 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:08.990 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:09.857 Processed: 766 of 1708 frames(25 seconds)
2011-04-28 01:27:10.521 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:12.113 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:13.885 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:14.864 Processed: 855 of 1708 frames(28 seconds)
2011-04-28 01:27:15.437 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:16.647 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:18.136 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:19.667 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:19.903 Processed: 964 of 1708 frames(32 seconds)
2011-04-28 01:27:21.180 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:22.605 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:24.140 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:24.927 Processed: 1068 of 1708 frames(35 seconds)
2011-04-28 01:27:25.055 mythtranscode: 62% Completed @ 17.7939 fps.
2011-04-28 01:27:25.459 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:27.356 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:29.094 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:29.942 Processed: 1154 of 1708 frames(38 seconds)
2011-04-28 01:27:30.786 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:32.479 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:34.172 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:35.006 Processed: 1244 of 1708 frames(41 seconds)
2011-04-28 01:27:35.997 GetNextFreeFrame() unable to lock frame 100 times. DiscardiSDng Frames.
2011-04-28 01:27:37.419 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:38.828 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:40.027 Processed: 1340 of 1708 frames(44 seconds)
2011-04-28 01:27:40.556 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:42.243 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:44.032 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:45.060 Processed: 1428 of 1708 frames(47 seconds)
2011-04-28 01:27:45.061 mythtranscode: 83% Completed @ 17.8066 fps.
2011-04-28 01:27:45.668 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:47.257 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:48.843 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:50.075 Processed: 1523 of 1708 frames(50 seconds)
2011-04-28 01:27:50.403 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:51.977 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:53.593 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:55.081 Processed: 1618 of 1708 frames(53 seconds)
2011-04-28 01:27:55.145 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:56.696 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:58.218 [ac3 @ 0x7fed4cbe4320]incomplete frame
2011-04-28 01:27:58.278 GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames.
2011-04-28 01:27:58.311 Transcoding 10181_20110427200700.mpg done
2011-04-28 01:27:58.311 ~MythContext waiting for threads to exit.

I also ran

/usr/local/bin/mythtranscode --infile 8064_20110427220300.mpg --outfile /home/scott/SDtestoutput.mpg --profile 27  --showprogress -v audio

on a recording from my analog tuner card with 2 audio channels. The command line output was basically the same except for the stuff about # of channels etc. However, there was essentially no audio on the digital transcoded recording (except a slight hiccup at the beginning) but the audio from the analog recording was perfect. I'm not really getting the "slow playback" problem anymore. I also issued the same commands on my normal backend and got the same results in terms of audio in the transcoded recordings. However, the part from the command line about "GetNextFreeFrame() unable to lock frame 100 times. Discarding Frames." became something like "Processed: 577 of 1710 frames(19 seconds)"

On that note, I think I've made it pretty easy for me to run tests. If there's anything I can run and report the results somewhere to help this get fixed, please let me know what's needed and where to send the results (There's a lot of different options to put after -v...). 