Video Conversion Problems

[Taddeusz]

I've recently started having issues with video conversion. Started out with an automatic video conversion I've have set up for our daughter's show. Just says it failed. I've looked in the log and there's no apparent reason why. Attached is the log. It's a Sofia the First episode. The recording started at 8:00AM this morning and finished at 8:30AM. Conversion was initiated shortly thereafter but no error seems to appear in the log. "Ministry" doesn't report anything else. I guess Jesus isn't building any more hot rods?

On a lighter note I'm having flashbacks of Dune when I see "Seeker awoken" in the log.

[Narflex]

I don't see any info on why it failed either...try setting: media_server/transcode_debug=true and then it'll log a lot more about what's happening with the transcoder.

[Narflex]

Also set:

xcode_cmdline_debug=TRUE

so it'll print out the exact command line it's using to execute FFMPEG and then you can also try to replicate the failure.

[Taddeusz]

Ok, here are the results. Here is the output when I run the command manually:

C:\Users\jbean>"C:\Program Files (x86)\SageTV\SageTV\SageTVTranscoder.exe", -v, 3, -y, -threads, 2, -sn, -vsync, 1, -async, 100, -stdinctrl, -i, F:\video3\SofiatheFirst-PrincessAdventureClub-21731469-0.ts, -threads, 5, -f, matroska, -vcodec, libx264, -b, 1500000, -s, 720x480, -r, 29.97, -acodec, AC-3, /, 0X332D6361, -ac, 6, -ar, 48000, -ab, 384000, -aspect, 16:9, -coder, 1, -flags, +loop, -cmp, +chroma, -partitions, +parti8x8+parti4x4-partp8x8-partb8x8, -me_method, dia, -subq, 1, -me_range, 16, -g, 250, -keyint_min, 25, -sc_threshold, 40, -i_qfactor, 0.71, -b_strategy, 1, -qcomp, 0.6, -qmin, 10, -qmax, 51, -qdiff, 4, -bf, 3, -refs, 1, -directpred, 1, -trellis, 0, -flags2, +bpyramid-mixed_refs+wpred+dct8x8+fastpskip-mbtree, -wpredp, 0, -rc_lookahead, 0, -priority, idle, F:\video3\SofiatheFirst-PrincessAdventureClub-21731469-0.tmp
FFmpeg version SVN-r93, Copyright (c) 2000-2010 the FFmpeg developers
  built on Jan 28 2011 10:48:22 with gcc 4.2.4
  configuration: --target-os=mingw32 --prefix=/cygdrive/c/dev/src/buildwin/stage --disable-ffplay --disable-ffserver --enable-gpl --enable-nonfree --disable-encoder=aac --disable-demuxer=ea --disable-devices --enable-libxvid --enable-libx264 --enable-libfaac --enable-libfaad --enable-static --disable-shared --enable-pthreads --disable-debug --enable-memalign-hack --arch=x86 --extra-cflags='-fno-common -march=i686 -mtune=i686 -DWIN32 -I/cygdrive/c/dev/src/buildwin/stage/include' --extra-ldflags=-L/cygdrive/c/dev/src/buildwin/stage/lib --enable-cross-compile --cross-prefix=i686-pc-mingw32-
  libavutil     50.22. 0 / 50.22. 0
  libavcodec    52.83. 0 / 52.83. 0
  libavformat   52.73. 0 / 52.73. 0
  libavdevice   52. 2. 0 / 52. 2. 0
  libavfilter    1.22. 0 /  1.22. 0
  libswscale     0.11. 0 /  0.11. 0
Unable to find a suitable output format for ','

[Taddeusz]

Ok, if I take out all the comas here is the output:

C:\Users\jbean>"C:\Program Files (x86)\SageTV\SageTV\SageTVTranscoder.exe" -v 3 -y -threads 2 -sn -vsync 1 -async 100 -stdinctrl -i F:\video3\SofiatheFirst-PrincessAdventureClub-21731469-0.ts -threads 5 -f matroska -vcodec libx264 -b 1500000 -s 720x480 -r 29.97 -acodec AC-3 / 0X332D6361 -ac 6 -ar 48000 -ab 384000 -aspect 16:9 -coder 1 -flags +loop -cmp +chroma -partitions +parti8x8+parti4x4-partp8x8-partb8x8 -me_method dia -subq 1 -me_range 16 -g 250 -keyint_min 25 -sc_threshold 40 -i_qfactor 0.71 -b_strategy 1 -qcomp 0.6 -qmin 10 -qmax 51 -qdiff 4 -bf 3 -refs 1 -directpred 1 -trellis 0 -flags2 +bpyramid-mixed_refs+wpred+dct8x8+fastpskip-mbtree -wpredp 0 -rc_lookahead 0 -priority idle F:\video3\SofiatheFirst-PrincessAdventureClub-21731469-0.tmp
FFmpeg version SVN-r93, Copyright (c) 2000-2010 the FFmpeg developers
  built on Jan 28 2011 10:48:22 with gcc 4.2.4
  configuration: --target-os=mingw32 --prefix=/cygdrive/c/dev/src/buildwin/stage --disable-ffplay --disable-ffserver --enable-gpl --enable-nonfree --disable-encoder=aac --disable-demuxer=ea --disable-devices --enable-libxvid --enable-libx264 --enable-libfaac --enable-libfaad --enable-static --disable-shared --enable-pthreads --disable-debug --enable-memalign-hack --arch=x86 --extra-cflags='-fno-common -march=i686 -mtune=i686 -DWIN32 -I/cygdrive/c/dev/src/buildwin/stage/include' --extra-ldflags=-L/cygdrive/c/dev/src/buildwin/stage/lib --enable-cross-compile --cross-prefix=i686-pc-mingw32-
  libavutil     50.22. 0 / 50.22. 0
  libavcodec    52.83. 0 / 52.83. 0
  libavformat   52.73. 0 / 52.73. 0
  libavdevice   52. 2. 0 / 52. 2. 0
  libavfilter    1.22. 0 /  1.22. 0
  libswscale     0.11. 0 /  0.11. 0
[NULL @ 0x19f7270] Probed with size=2048 and score=100
[mpegts @ 0x19f7270] stream=0 stream_type=1b pid=1011 prog_reg_desc=HDMV
[mpegts @ 0x19f7270] stream=1 stream_type=81 pid=1100 prog_reg_desc=HDMV
[h264 @ 0x19e8960] no picture
[mpegts @ 0x19f7270] Probe buffer size limit 5000000 reached
Input #0, mpegts, from 'F:\video3\SofiatheFirst-PrincessAdventureClub-21731469-0.ts':
  Duration: 00:29:47.83, start: 5510.798600, bitrate: 12742 kb/s
  Program 1
    Stream #0.0[0x1011], 206, 1/90000: Video: h264, yuv420p, 1280x720, 1001/60000, AR: 16:9, progressive, 59.96 fps, 59.94 tbr, 90k tbn, 119.88 tbc
    Stream #0.1[0x1100], 108, 1/90000: Audio: ac3, 48000 Hz, 5.1, s16, 384 kb/s
Unknown encoder 'AC-3'

[Narflex]

OK, thanks. Fixed and uploaded to GitHub.

We had code in there which would substitute FFMPEG names of codecs for SageTV names of codecs....and then when we invoked the transcoder, it would use that map in the reverse direction...and many of those should never go back in the reverse direction. (this was from a change we made on Fiber that added more formats to this list)

[sacrament055]

Originally Posted by Narflex

OK, thanks. Fixed and uploaded to GitHub.

We had code in there which would substitute FFMPEG names of codecs for SageTV names of codecs....and then when we invoked the transcoder, it would use that map in the reverse direction...and many of those should never go back in the reverse direction. (this was from a change we made on Fiber that added more formats to this list)

Guess that explains my failed conversion the other day as well. So is the solution just to replace the sage.jar with a newer version that includes your fix?

[Taddeusz]

Originally Posted by sacrament055

Guess that explains my failed conversion the other day as well. So is the solution just to replace the sage.jar with a newer version that includes your fix?

Yes, that will fix it. Just updated my copy of the source and rebuilt. Have a conversion going right now.

[Fuzzy]

Funny - I was just trying to do the first conversion since upgrading yesterday, and noticed it was failing instantly. Didn't get a change to look into it.. glad now I don't have to.. :-)

[sacrament055]

Originally Posted by Taddeusz

Yes, that will fix it. Just updated my copy of the source and rebuilt. Have a conversion going right now.

Would you mind posting your updated sagetv.jar? Guess I'm going to have to set up my own build environment at some point so I don't have to keep asking.

[jm9843]

Originally Posted by sacrament055

Would you mind posting your updated sagetv.jar?

Check the link in my sig.

[SageWizdom]

Did this fix make it back into the repo? I'm using the latest .deb from stuckless (http://forums.sagetv.com/forums/showthread.php?t=62422), and I'm seeing the exact same symptoms where the conversion fails instantly. I haven't turned on debugging yet to verify its the same, but that is next.

[Taddeusz]

Originally Posted by SageWizdom

Did this fix make it back into the repo? I'm using the latest .deb from stuckless (http://forums.sagetv.com/forums/showthread.php?t=62422), and I'm seeing the exact same symptoms where the conversion fails instantly. I haven't turned on debugging yet to verify its the same, but that is next.

Yes, this fix was submitted to the repo a long time ago. What version of Sage.jar are you running?

[SageWizdom]

I'm running sage 9.0.4.220 (on Ubuntu Desktop 14.04.3

FFmpeg version git-1d682b5, Copyright (c) 2000-2008 Fabrice Bellard, et al.
configuration: --disable-ffserver --disable-ffplay --enable-gpl --enable-pthreads --enable-nonfree --enable-libfaac --enable-libx264 --enable-libxvid --disable-devices --disable-demuxer=msnwc_tcp --enable-libfaad --extra-cflags=-I. -I/vagrant/sagetv/third_party/codecs/faad2/include -I/vagrant/sagetv/third_party/codecs/faac/include -I/vagrant/sagetv/third_party/codecs/x264 -I/vagrant/sagetv/third_party/codecs/xvidcore/src --extra-ldflags=-L/vagrant/sagetv/third_party/codecs/faac/libfaac/.libs -L/vagrant/sagetv/third_party/codecs/faad2/libfaad/.libs -L/vagrant/sagetv/third_party/codecs/x264 -L/vagrant/sagetv/third_party/codecs/xvidcore/build/generic/=build
libavutil version: 49.6.0
libavcodec version: 51.50.1
libavformat version: 52.7.0
libavdevice version: 52.0.0
built on Jan 30 2016 23:03:52, gcc: 4.8.4
usage: ffmpeg [[infile options] -i infile]... {[outfile options] outfile}...
Hyper fast Audio and Video encoder

It may be a different problem with the same symptoms.

I turned on the two debugging options previously noted and then...

In my original file I saw this

Sat 2/6 13:25:47.839 [Ministry@540000c3] BAD transcode job data:java.lang.IllegalArgumentException: Invalid transcode job source file!

After Stopping and restarting

Sat 2/6 13:31:28.550 [1061380594@qtp-1293211520-7@3f4361f2] ::INFO: Groovy servlet initialized on groovy.util.GroovyScriptEngine@60b38ed.
Sat 2/6 13:31:43.560 [1061380594@qtp-1293211520-7@3f4361f2] src=(class sage.MediaFile) - MediaFile[id=514539 A[344690,344116,"Convoy",69070@0204.13:30,120,T] mask=TV host=sagetv-server encodedBy=PrimeNetEncoder 176-0 on sagetv-server:7000 WDCWDT3 format=MPEG2-TS 0:04:58 2067 kbps [#0 Video[MPEG2-Video 29.97003 fps 704x480 4:3 interlaced id=0100]#1 Audio[AC3 48000 Hz 2 channels 192 kbps MAIN idx=1 id=0101 eng]] /var/media/tv/Convoy-344690-0.ts, Seg0[Thu 2/4 13:30:00.014-Thu 2/4 15:30:00.002]]

Sat 2/6 13:32:25.960 [1061380594@qtp-1293211520-7@3f4361f2] src=(class sage.MediaFile) - MediaFile[id=514539 A[344690,344116,"Convoy",69070@0204.13:30,120,T] mask=TV host=sagetv-server encodedBy=PrimeNetEncoder 176-0 on sagetv-server:7000 WDCWDT3 format=MPEG2-TS 0:04:58 2067 kbps [#0 Video[MPEG2-Video 29.97003 fps 704x480 4:3 interlaced id=0100]#1 Audio[AC3 48000 Hz 2 channels 192 kbps MAIN idx=1 id=0101 eng]] /var/media/tv/Convoy-344690-0.ts, Seg0[Thu 2/4 13:30:00.014-Thu 2/4 15:30:00.002]]

[SageWizdom]

Better Log. I'm keep debugging, but in case someone takes a look.

Sat 2/6 13:54:24.095 [168135858@qtp-1075669383-7@a058cb2] Added for transcoding:MediaFile[id=514539 A[344690,344116,"Convoy",69070@0204.13:30,120,T] mask=TV host=sagetv-server encodedBy=PrimeNetEncoder 176-0 on sagetv-server:7000 WDCWDT3 format=MPEG2-TS 0:04:58 2067 kbps [#0 Video[MPEG2-Video 29.97003 fps 704x480 4:3 interlaced id=0100]#1 Audio[AC3 48000 Hz 2 channels 192 kbps MAIN idx=1 id=0101 eng]] /var/media/tv/Convoy-344690-0.ts, Seg0[Thu 2/4 13:30:00.014-Thu 2/4 15:30:00.002]]
Sat 2/6 13:54:24.102 [Ministry@626ac85d] Initiating xcode for /var/media/tv/Convoy-344690-0.ts
Sat 2/6 13:54:24.134 [168135858@qtp-1075669383-7@a058cb2] Error loading Freetype Font; trying to load Java font instead; error=java.lang.UnsatisfiedLinkError: sage.FreetypeFont.loadFreetypeLib0()J
Sat 2/6 13:54:24.160 [Ministry@626ac85d] Set Transcode format source=MPEG2-TS 0:04:58 2067 kbps [#0 Video[MPEG2-Video 29.97003 fps 704x480 4:3 interlaced id=0100]#1 Audio[AC3 48000 Hz 2 channels 192 kbps MAIN idx=1 id=0101 eng]] dest=mp4 0:00:00 0 kbps [#0 Video[h264 29.97 fps 720x480 4:3 2500 kbps progressive]#1 Audio[aac 48000 Hz 2 channels 128 kbps]{CompressionDetails=-coder 0 -flags +loop -cmp +chroma -partitions +parti8x8+parti4x4+partp8x8+partb8x8 -me_method umh -subq 8 -me_range 16 -g 250 -keyint_min 25 -sc_threshold 40 -i_qfactor 0.71 -b_strategy 2 -qcomp 0.6 -qmin 10 -qmax 51 -qdiff 4 -bf 0 -refs 1 -directpred 3 -trellis 1 -flags2 -wpred-dct8x8 -wpredp 0 -rc_lookahead 50 -level 30 -maxrate 10000000 -bufsize 10000000}]
Sat 2/6 13:54:24.187 [Ministry@626ac85d] Using 3 threads for the transcoder
Sat 2/6 13:54:24.187 [Ministry@626ac85d] Automatically adding -deinterlace option to transcoding process
Sat 2/6 13:54:24.188 [Ministry@626ac85d] Executing xcoding process with args: [nice, /opt/sagetv/server/ffmpeg, -v, 3, -y, -threads, 2, -sn, -vsync, 1, -async, 100, -stdinctrl, -i, /var/media/tv/Convoy-344690-0.ts, -threads, 3, -f, mp4, -vcodec, libx264, -b, 2500000, -s, 720x480, -r, 29.97, -aspect, 4:3, -acodec, libfaac, -ab, 128000, -ac, 2, -ar, 48000, -coder, 0, -flags, +loop, -cmp, +chroma, -partitions, +parti8x8+parti4x4+partp8x8+partb8x8, -me_method, umh, -subq, 8, -me_range, 16, -g, 250, -keyint_min, 25, -sc_threshold, 40, -i_qfactor, 0.71, -b_strategy, 2, -qcomp, 0.6, -qmin, 10, -qmax, 51, -qdiff, 4, -bf, 0, -refs, 1, -directpred, 3, -trellis, 1, -flags2, -wpred-dct8x8, -wpredp, 0, -rc_lookahead, 50, -level, 30, -maxrate, 10000000, -bufsize, 10000000, -deinterlace, /var/media/tv/Convoy-344690-0.tmp]
Sat 2/6 13:54:24.256 [XcodeStderrConsumer@6d8ae037] FFmpeg version git-1d682b5, Copyright (c) 2000-2008 Fabrice Bellard, et al.
Sat 2/6 13:54:24.295 [XcodeStderrConsumer@6d8ae037] configuration: --disable-ffserver --disable-ffplay --enable-gpl --enable-pthreads --enable-nonfree --enable-libfaac --enable-libx264 --enable-libxvid --disable-devices --disable-demuxer=msnwc_tcp --enable-libfaad --extra-cflags=-I. -I/vagrant/sagetv/third_party/codecs/faad2/include -I/vagrant/sagetv/third_party/codecs/faac/include -I/vagrant/sagetv/third_party/codecs/x264 -I/vagrant/sagetv/third_party/codecs/xvidcore/src --extra-ldflags=-L/vagrant/sagetv/third_party/codecs/faac/libfaac/.libs -L/vagrant/sagetv/third_party/codecs/faad2/libfaad/.libs -L/vagrant/sagetv/third_party/codecs/x264 -L/vagrant/sagetv/third_party/codecs/xvidcore/build/generic/=build
Sat 2/6 13:54:24.295 [XcodeStderrConsumer@6d8ae037] libavutil version: 49.6.0
Sat 2/6 13:54:24.295 [XcodeStderrConsumer@6d8ae037] libavcodec version: 51.50.1
Sat 2/6 13:54:24.295 [XcodeStderrConsumer@6d8ae037] libavformat version: 52.7.0
Sat 2/6 13:54:24.297 [XcodeStderrConsumer@6d8ae037] libavdevice version: 52.0.0
Sat 2/6 13:54:24.297 [XcodeStderrConsumer@6d8ae037] built on Jan 30 2016 23:03:52, gcc: 4.8.4
Sat 2/6 13:54:24.298 [XcodeStderrConsumer@6d8ae037] Input #0, mpegts, from '/var/media/tv/Convoy-344690-0.ts':
Sat 2/6 13:54:24.298 [XcodeStderrConsumer@6d8ae037] Duration: 01:59:58.5, start: 0.000000, bitrate: 3666 kb/s
Sat 2/6 13:54:24.298 [XcodeStderrConsumer@6d8ae037] Program 1 Service01
Sat 2/6 13:54:24.298 [XcodeStderrConsumer@6d8ae037] Stream #0.0[0x100], 1/90000: Video: mpeg2video, yuv420p, 704x480, 1001/30000, AR: 4:3, interlaced, 15000 kb/s, 29.97 fps(r)
Sat 2/6 13:54:24.298 [XcodeStderrConsumer@6d8ae037] Stream #0.1[0x101](eng), 1/90000: Audio: ac3, 48000 Hz, stereo, 192 kb/s
Sat 2/6 13:54:24.298 [XcodeStderrConsumer@6d8ae037] /opt/sagetv/server/ffmpeg: unrecognized option '-wpredp'
Sat 2/6 13:54:24.298 [Ministry@626ac85d] Ministry is waiting for 180 sec
Sat 2/6 13:54:24.508 [168135858@qtp-1075669383-7@a058cb2] DatePat=EEE, MMM d orgPat=EEEE, MMMM d, yyyy
Sat 2/6 13:54:25.289 [Ministry@626ac85d] Destroying old transcode process...
Sat 2/6 13:54:25.289 [Ministry@626ac85d] Destroyed!
Sat 2/6 13:54:25.290 [Ministry@626ac85d] Stderr consumer thread has terminated for xcoder
Sat 2/6 13:54:25.290 [Ministry@626ac85d] Ministry is waiting for 180 sec
Sat 2/6 13:54:27.203 [168135858@qtp-1075669383-7@a058cb2] src=(class sage.MediaFile) - MediaFile[id=514539 A[344690,344116,"Convoy",69070@0204.13:30,120,T] mask=TV host=sagetv-server encodedBy=PrimeNetEncoder 176-0 on sagetv-server:7000 WDCWDT3 format=MPEG2-TS 0:04:58 2067 kbps [#0 Video[MPEG2-Video 29.97003 fps 704x480 4:3 interlaced id=0100]#1 Audio[AC3 48000 Hz 2 channels 192 kbps MAIN idx=1 id=0101 eng]] /var/media/tv/Convoy-344690-0.ts, Seg0[Thu 2/4 13:30:00.014-Thu 2/4 15:30:00.002]]

[SageWizdom]

It looks like it is having issue with two command line options:

-wpredp
-rc_lookahead

full command line.

nice /opt/sagetv/server/ffmpeg -v 3 -y -threads 2 -sn -vsync 1 -async 100 -stdinctrl -i /var/media/tv/Convoy-344690-0.ts -threads 3 -f mp4 -vcodec libx264 -b 2500000 -s 720x480 -r 29.97 -aspect 4:3 -acodec libfaac -ab 128000 -ac 2 -ar 48000 -coder 0 -flags +loop -cmp +chroma -partitions +parti8x8+parti4x4+partp8x8+partb8x8 -me_method umh -subq 8 -me_range 16 -g 250 -keyint_min 25 -sc_threshold 40 -i_qfactor 0.71 -b_strategy 2 -qcomp 0.6 -qmin 10 -qmax 51 -qdiff 4 -bf 0 -refs 1 -directpred 3 -trellis 1 -flags2 -wpred-dct8x8 -wpredp 0 -rc_lookahead 50 -level 30 -maxrate 10000000 -bufsize 10000000 -deinterlace /var/media/tv/Convoy-344690-0.tmp

This appears to be in the Sage.properties file. I've attempted shutting down sage, removing the text and restarting sage, but even having deleted the autobackup file, the two problem causing command lines options are re-added to the active Sage.properties file.

transcoder/formats/AppleTV-High\ Quality=f\=mp4;MCompressionDetails\=-coder 0 -flags .....

What is very interesting to me is that if I use "-wpredp" as an argument, ffmpeg complains:

./ffmpeg: missing argument for option '-wpredp'

but when I try "-wpredp 0", ffmpeg complains

./ffmpeg: unrecognized option '-wpredp'

[Taddeusz]

Yeah, this looks like a different problem specific to Linux. My main SageTV server is Windows. Conversion works fine on Windows. I attempted to run a conversion on my 32-bit Linux test system and it failed.

[wnjj]

Originally Posted by SageWizdom

What is very interesting to me is that if I use "-wpredp" as an argument, ffmpeg complains:


but when I try "-wpredp 0", ffmpeg complains

I looked at the argument handling in cmdutils.c and it seems there's code in there that always causes unknown arguments to be "renamed" to '-default' and to expect arguments. That's why it complains about no arguments until you add them, and then it complains about being unrecognized. Not sure why it's that way but at any rate, 'wpredp' is not an option in the current ffmpeg code in third_party/ffmpeg. I see where Ministry.java and FFMPEGTranscoder.java use this argument. Is this ffmpeg source code not the correct version?

[SageWizdom]

I was thinking of writing a shim to sit in front of ffmpeg and filter out the two offending commands. I guess its time to also submit a bug. Thanks for helping track down the issue.

[Narflex]

Yeah...this is interesting. Apparently the FFMPEG we have in GitHub isn't the exact same one we had in the final V7 release. What I'm pretty sure happened is that we updated it further and we're using the updated version for the other things that use FFMPEG (like components in the extender, and also the Windows Demux DirectShow filter) but didn't end up recompiling the FFMPEG EXE as well (probably because the changes didn't fix any bugs there).

So this is why its out of sync regarding these options. I know I didn't come up with all those options myself...they were likely from some other examples I found online for x264 encoding options. Feel free to submit a code change that removes their usage...and ideally, also figure out if they need to be replaced by something else or not (but they'll likely be fine at their defaults).