Dynamic PMT: Audio lost after transcode

[oli.henning@…]

Since a few weeks i have a problem with mythtranscode: Audio is completly lost after transcoding. Perhaps this is the same or similar to ​http://code.mythtv.org/trac/ticket/7118

Details

• Recording with DVB-C
• Problem occurs just on one specific channel: "ORF 1" (prime channel of austria).
• Recorded in switzerland, cable-provider "UPC Cablecom"
• Problem does not occur on every recording - so the problem is not "stable"
• Just using "lossless MPEG-2" transcoding to cut-off commerials.
• No audio- and no video-recompression (so it's quite fast)
• Before the transcoding all audio-channels are present in mythfrontend
• Changes in audio-streams-combinations within recoding is recognized in mythfrontend (e.g. not from the beginning but from somewhere in the middle of the recoding there is an AC3-stream)

Example-File to reproduce

​https://dl.dropboxusercontent.com/u/517875/2109_20130701213000.mpg I cutted of the first 310'200'000 Bytes. This are exactly 1'650'000 TS-Packets (each 188 Bytes). So this is just the first ~9 minutes of the original recording. Interesting fact: If the file would be just the first 1'600'000 TS-Packets, then mythtranscode will not have the audio-loss-problem. This is the reason why the test-file-to-reproduce has to be so big.

LOG-Output of mythtranscode

(my_av_print) Input #0, mpegts, from '/mnt/mythtvRecordings/2109_20130701213000.mpg':
(my_av_print)   Duration: N/A, bitrate: N/A
(my_av_print)     Stream #0:0[0x90]: Video: mpeg2video, 90k tbn
(my_av_print)     Stream #0:1[0x91](ger): Audio: mp3, 0 channels
(my_av_print)     Stream #0:2[0x9b](ger): Audio: ac3, 0 channels
(my_av_print)     Stream #0:3[0xae](ger): Subtitle: dvb_teletext
(InitAV) Skipping invalid audio stream: 1
(InitAV) Skipping invalid audio stream: 2

You can see, that mythtranscode has some problems in identifying the stream-content:

• mythtranscode could not detect the recording-duration (just logs "N/A")
• mythtranscode could not detect details of the video-stream (pixel-format, frame-size, frame-rate, ...)
• mythtranscode detected the first audio-stream as beeing "mp3". But actually it's a normal "mp2" audio-stream (analyzed with avprobe)

To compare: the log of a 'normal' transcoding:

(my_av_print) Input #0, mpegts, from '/mnt/mythtvRecordings/2102_20130629193300.mpg':
(my_av_print)   Duration: 00:44:56.88, start: 13209.723733, bitrate: 7099 kb/s
(my_av_print)     Stream #0:0[0x50]: Video: mpeg2video (Main), yuv420p, 720x576 [SAR 64:45 DAR 16:9], 15000 kb/s, 25 fps, 25 tbr, 90k tbn, 50 tbc
(my_av_print)     Stream #0:1[0x51](deu): Audio: mp2, 48000 Hz, stereo, s16, 192 kb/s
(my_av_print)     Stream #0:2[0x52](eng): Audio: mp2, 48000 Hz, stereo, s16, 192 kb/s
(my_av_print)     Stream #0:3[0x6e](deu): Data: dvb_vbi
(InitAV) Skipping unsupported codec 2 on stream 3

On request i can do further investigations. Perhaps you have to name me some analyze-tools.

[oli.henning@…]

Just to help, as far as i can:

I did some further analyzes with the tool tsinfo (from the tstools-Package):

Problematic recording (audio lost after transcode):

Packet 1 is PAT
Program list:
    Program 1 -> PID 00a4 (164)

Packet 2 is PMT with PID 00a4 (164)
  Program 1, version 12, PCR PID 0090 (144)
  Program streams:
    PID 0090 ( 144) -> Stream type 02 (  2) H.262/13818-2 video (MPEG-2) or 11172-2 constrained video
        ES info (3 bytes): 52 01 01
        Descriptor tag 52 ( 82) (1 byte): 01
    PID 0091 ( 145) -> Stream type 03 (  3) 11172-3 audio (MPEG-1)
        ES info (9 bytes): 52 01 02 0a 04 67 65 72 01
        Descriptor tag 52 ( 82) (1 byte): 02
        Languages: ger/clean effects
    PID 0092 ( 146) -> Stream type 03 (  3) 11172-3 audio (MPEG-1)
        ES info (9 bytes): 52 01 03 0a 04 65 6e 67 01
        Descriptor tag 52 ( 82) (1 byte): 03
        Languages: eng/clean effects
    PID 009b ( 155) -> Stream type 81 (129) User private
        ES info (12 bytes): 6a 01 00 52 01 05 0a 04 67 65 72 01
        DVB AC-3 (1 byte): 00
        Descriptor tag 52 ( 82) (1 byte): 05
        Languages: ger/clean effects
    PID 00ae ( 174) -> Stream type 06 (  6) H.222.0/13818-1 PES private data (maybe Dolby/AC-3 in DVB)
        ES info (15 bytes): 52 01 04 56 0a 67 65 72 09 00 67 65 72 17 77
        Descriptor tag 52 ( 82) (1 byte): 04
        Teletext: language=ger, type=Initial, magazine 1, page 0
                  language=ger, type=Subtitles, magazine 7, page 77

To compare: A non-problematic recording (of another channel):

Packet 1 is PAT
Program list:
    Program 1 -> PID 02e4 (740)

Packet 2 is PMT with PID 02e4 (740)
  Program 1, version 2, PCR PID 02d0 (720)
  Program streams:
    PID 02d0 ( 720) -> Stream type 02 (  2) H.262/13818-2 video (MPEG-2) or 11172-2 constrained video
        ES info (3 bytes): 52 01 01
        Descriptor tag 52 ( 82) (1 byte): 01
    PID 02d1 ( 721) -> Stream type 03 (  3) 11172-3 audio (MPEG-1)
        ES info (9 bytes): 0a 04 64 65 75 01 52 01 03
        Languages: deu/clean effects
        Descriptor tag 52 ( 82) (1 byte): 03
    PID 02db ( 731) -> Stream type 81 (129) User private
        ES info (16 bytes): 6a 05 ff 42 08 00 00 0a 04 64 65 75 01 52 01 07
        DVB AC-3 (5 bytes): ff 42 08 00 00
        Languages: deu/clean effects
        Descriptor tag 52 ( 82) (1 byte): 07
    PID 02ee ( 750) -> Stream type 06 (  6) H.222.0/13818-1 PES private data (maybe Dolby/AC-3 in DVB)
        ES info (15 bytes): 52 01 0a 56 0a 64 65 75 09 00 64 65 75 11 49
        Descriptor tag 52 ( 82) (1 byte): 0a
        Teletext: language=deu, type=Initial, magazine 1, page 0
                  language=deu, type=Subtitles, magazine 1, page 49

Analyze details

• Each of the first audio-stream has another value "descriptor tag 52"
• The ordering of the Descriptor-Tags in the "ES info" (of the audio-stream) is different: In one problematic case, it's tag "0x52" followed by tag "0x0A". In the non-prblematic-case case it's the other way around.
• The ISO language-codes are different. In one case it's "deu" (for "deutsch"). In the other case it's "ger" (for "german")
• number of audio-channels are different: the 'problematic' recording hat 3 audio-streams (2*MP2 and 1*AC3) and the non-problematic just hast two (1*MP2 and 1*AC3)
• The PID-Values differ

My conclution

These differences in the DVB-meta-data (PAT, PMT, PID-Numbers and number of audio-channels) seems very trivial to me so i think that this is not the cause of the "audio lost problem" So the problem is probably within the audio-elementary-streams themselve. Or it's a specific TS-packet-multiplexing case which could not be handled by mythtranscode/ffmpeg.

[Raymond Wagner]

Resetting defaults.

[Karl Egly]

I don't agree with the conclusion. The root cause appears to be the misidentification of the audio streams as having 0 channels, which leads to them being dropped. From your log:

(InitAV) Skipping invalid audio stream: 1

which is triggered by these audio streams with 0 channels, see e.g. [9a677e81dec5694d7dc858eebb19563a54e2c0fd] (pointed out by git blame as the last change to the test in 2005) I need to research where the information comes from, maybe we can fixup the PMT to properly report stereo MPEG audio layer 2 streams or something similar.

[Karl Egly]

looking at the example provided it appears that our version of ffmpeg does something differently then upstream...

our ffmpeg finds two german audio streams

$ mythffmpeg -i 11639-2109_20130701213000.mpg 
ffmpeg version 1.2.1 Copyright (c) 2000-2013 the FFmpeg developers
  built on Jun  8 2013 15:00:48 with gcc 4.6 (Ubuntu/Linaro 4.6.3-1ubuntu5)
  configuration: --compile-type=profile --prefix=/usr --runprefix=/usr --enable-crystalhd --enable-lirc --enable-audio-alsa --enable-audio-oss --enable-dvb --enable-ivtv --enable-firewire --enable-joystick-menu --with-bindings=perl --enable-ffmpeg-pthreads --enable-pic --enable-vaapi --perl-config-opts='INSTALLDIRS=vendor' --enable-libvpx --enable-sdl --enable-libmp3lame --enable-libx264 --enable-opengl-video --enable-vdpau
  libavutil      52. 18.100 / 52. 18.100
  libavcodec     54. 92.100 / 54. 92.100
  libavformat    54. 63.104 / 54. 63.104
  libavdevice    54.  3.103 / 54.  3.103
  libavfilter     3. 42.103 /  3. 42.103
  libswscale      2.  2.100 /  2.  2.100
  libswresample   0. 17.102 /  0. 17.102
  libpostproc    52.  2.100 / 52.  2.100
[mpegts @ 0x13f2a20] PES packet size mismatch
    Last message repeated 2 times
Input #0, mpegts, from '11639-2109_20130701213000.mpg':
  Duration: N/A, bitrate: N/A
    Stream #0:0[0x90]: Video: mpeg2video, 90k tbn
    Stream #0:1[0x91](ger): Audio: mp3, 0 channels
    Stream #0:2[0x9b](ger): Audio: ac3, 0 channels
    Stream #0:3[0xae](ger): Subtitle: dvb_teletext
At least one output file must be specified
$

vs. plain libav finds two german and one english audio stream

$ avconv -i 11639-2109_20130701213000.mpg 
avconv version 0.8.6-4:0.8.6-0ubuntu0.12.04.1, Copyright (c) 2000-2013 the Libav developers
  built on Apr  2 2013 17:02:36 with gcc 4.6.3
[mpegts @ 0x131e7a0] Continuity check failed for pid 0 expected 1 got 8
[mpegts @ 0x131e7a0] max_analyze_duration reached
[mpegts @ 0x131e7a0] PES packet size mismatch
    Last message repeated 2 times
Input #0, mpegts, from '11639-2109_20130701213000.mpg':
  Duration: 00:09:07.23, start: 2626.483556, bitrate: 4534 kb/s
  Program 1 
    Stream #0.0[0x90]: Video: mpeg2video (Main), yuv420p, 720x576 [PAR 64:45 DAR 16:9], 4719 kb/s, 25 fps, 25 tbr, 90k tbn, 50 tbc
    Stream #0.1[0x91](ger): Audio: mp2, 48000 Hz, stereo, s16, 160 kb/s (clean effects)
    Stream #0.2[0x92](eng): Audio: mp2, 48000 Hz, stereo, s16, 160 kb/s (clean effects)
    Stream #0.3[0x9b](ger): Audio: ac3, 48000 Hz, stereo, s16, 448 kb/s (clean effects)
    Stream #0.4[0xae](ger): Subtitle: [6][0][0][0] / 0x0006
At least one output file must be specified
$

wrt to the fact that the first part of the program appears to be fine, the sample contains a dynamic PMT. Version 12 of the PMT has the additional english audio stream while version 13 doesn't.

$ mythutil --pidprinter  --infile 11639-2109_20130701213000.mpg --pids 0,0xa4
2013-07-10 20:31:41.084258 C  mythutil version: master [v0.27-pre2-1284-gdd5a80d-dirty] www.mythtv.org
2013-07-10 20:31:41.084278 C  Qt version: compile: 4.8.1, runtime: 4.8.1
2013-07-10 20:31:41.084283 N  Enabled verbose msgs:  general
2013-07-10 20:31:41.084292 N  Setting Log Level to LOG_INFO
2013-07-10 20:31:41.084949 I  Setup Interrupt handler
2013-07-10 20:31:41.084959 I  Setup Terminated handler
2013-07-10 20:31:41.084966 I  Setup Segmentation fault handler
2013-07-10 20:31:41.084973 I  Setup Aborted handler
2013-07-10 20:31:41.084984 I  Setup Bus error handler
2013-07-10 20:31:41.084992 I  Setup Floating point exception handler
2013-07-10 20:31:41.084998 I  Setup Illegal instruction handler
2013-07-10 20:31:41.085008 I  Setup Real-time signal 0 handler
2013-07-10 20:31:41.085034 N  Using runtime prefix = /usr
2013-07-10 20:31:41.085043 N  Using configuration directory = /home/user/.mythtv
2013-07-10 20:31:41.085105 I  Assumed character encoding: de_DE.UTF-8
2013-07-10 20:31:41.086407 N  Empty LocalHostName.
2013-07-10 20:31:41.086414 I  Using localhost value of mythmaster
2013-07-10 20:31:41.086462 I  Testing network connectivity to '192.168.66.30'
2013-07-10 20:31:41.089621 I  Starting IO manager (write)
2013-07-10 20:31:41.089687 I  Starting IO manager (read)
2013-07-10 20:31:41.089739 I  Starting process signal handler
2013-07-10 20:31:41.090387 I  Starting process manager
2013-07-10 20:31:41.090443 I  Added logging to the console
2013-07-10 20:31:41.106524 N  Setting QT default locale to de_DE
2013-07-10 20:31:41.106585 I  Current locale de_DE
2013-07-10 20:31:41.106629 N  Reading locale defaults from /usr/share/mythtv//locales/de_de.xml
Program Association Section
 PSIP tableID(0x0) length(13) extension(0x4b)
      version(18) current(1) section(0) last_section(0)
      tsid(75) programCount(1)
  program number     1 has PID 0x00a4

Program Map Section
 PSIP tableID(0x2) length(86) extension(0x1)
      version(12) current(1) section(0) last_section(0)
      pnum(1) pid(0xa4)
  Stream #0 pid(0x90) type(0x02 video-mpeg2)
    Stream Identifier Descriptor (0x52): ComponentTag=0x1
  Stream #1 pid(0x91) type(0x03 audio-mp1-layer[1,2,3])
    Stream Identifier Descriptor (0x52): ComponentTag=0x2
    ISO-639 Language: code(ger) canonical(ger) eng(German)
  Stream #2 pid(0x92) type(0x03 audio-mp1-layer[1,2,3])
    Stream Identifier Descriptor (0x52): ComponentTag=0x3
    ISO-639 Language: code(eng) canonical(eng) eng(English)
  Stream #3 pid(0x9b) type(0x81 audio-ac3)
    AC-3 Descriptor (0x6a) length(1)
    Stream Identifier Descriptor (0x52): ComponentTag=0x5
    ISO-639 Language: code(ger) canonical(ger) eng(German)
  Stream #4 pid(0xae) type(0x06 private-data)
    Stream Identifier Descriptor (0x52): ComponentTag=0x4
    Teletext Descriptor: 2 pages
  type(1) mag(1) page(00) lang(ger)
  type(2) mag(7) page(77) lang(ger)

2013-07-10 20:31:41.329546 I  Added logging to mythlogserver at TCP:35327
Program Map Section
 PSIP tableID(0x2) length(72) extension(0x1)
      version(13) current(1) section(0) last_section(0)
      pnum(1) pid(0xa4)
  Stream #0 pid(0x90) type(0x02 video-mpeg2)
    Stream Identifier Descriptor (0x52): ComponentTag=0x1
  Stream #1 pid(0x91) type(0x03 audio-mp1-layer[1,2,3])
    Stream Identifier Descriptor (0x52): ComponentTag=0x2
    ISO-639 Language: code(ger) canonical(ger) eng(German)
  Stream #2 pid(0x9b) type(0x81 audio-ac3)
    AC-3 Descriptor (0x6a) length(1)
    Stream Identifier Descriptor (0x52): ComponentTag=0x5
    ISO-639 Language: code(ger) canonical(ger) eng(German)
  Stream #3 pid(0xae) type(0x06 private-data)
    Stream Identifier Descriptor (0x52): ComponentTag=0x4
    Teletext Descriptor: 2 pages
  type(1) mag(1) page(00) lang(ger)
  type(2) mag(7) page(77) lang(ger)

Processed 310200000 bytes                   
First PTS 236412194, Last PTS 285634994, elapsed 49222800 00:09:06.920
$

[oli.henning@…]

You are righht, the PMT changes at TS-packet number 1644468 (when start counting with 1).

I truncate the original MPEGTS-file to 1644467 packets (dd if=original.mpg of=2109_20130701213000.mpg bs=188 count=1644467). The resulting file is 309'159'796 bytes long. Then mythtranscode has no problem: it identifies all of the 3 audiochannels and the transcoding-result also has all channels

But if i take just one more TS-packet (this will be the packet "PMT Version 13" with the changed audio-channel-config, see previous comment), then mythtranscode fails as explained (MP2 identified as MP3, all audio-streams get lost, and so on...)

You should be able to reproduce it with the given example-file in my Dropbox. And i think this is a "hot scent".

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

I have a similar problem with mythtranscode since upgrading to 0.26 a few months ago, but haven't time to analyze it.

For me it's only a problem with HDTV transcoding which is loosing all audio streams (e.g. ARD HD/ZDF HD), Transcoding SDTV channels are ok. From my mind, Logs of HDTV and SDTV are looking good and very similar, audio is processed in both, but simply not written in HDTV-transcoding. Maybe this could help to size down the points to look at.

@oli.henning You wrote: "Since a few weeks i have a problem with mythtranscode" - Did you upgrade mythtv to 0.26 in this time?

[oli.henning@…]

@Pöhlmann No, the "transcode-removing-audio-problem" also occured while i was using 0.25. Therefore i reopend an old ticket (​http://code.mythtv.org/trac/ticket/7118). But i was asked first to upgrate to 0.26. So i did.

But with 0.26 - as described - the problem still exists. And - also as desribed - the problem occurs with SDTV and only (as far as i see) one channel: "ORF 1". But as you write "Logs ... are looking good": Please post these logs.

The cause of the problem seems to be that "ORF 1" changes the audio-streams from time-to-time and mythtranscode (or the ffmpeg within) can not handle this.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

Narrowing down my error in my less freetime, I run mythtranscode with "--verbose most --loglevel debug" options and saw the following error:

"NVR(): Audio device 0 buffer size: 0 bytes"

So I lookup up in "mythtranscode/transcode.cpp" and see that the audio buffer framesize ("ab->size()") isn't set to the right value. Instead it's set to 0 which is the same as audio output will be disabled. So maybe this option has changed in ffmpeg 0.13 which is used in mythtv 0.26.

I will get a deeper debug next time, but can't say when.

@oli.henning Maybe you can check your logs if you'll find the same error. I have this error even on SDTV programs at least on channels in the same bouquet.

[kungfujesus06@…]

Did you guys also notice after transcoding your seektables produced some crazy length? It thought my transcoded recordings were several hours long. I'll bet that's related to this problem.

[oli.henning@…]

@kungfujesus06 No, i think these two issues ("lost audio" and "wrong recording length") are not related. I also have the "wrong lengths" in cases where i do NOT lose audio.

For the "wrong length"-issue there is another open ticket: ​http://code.mythtv.org/trac/ticket/11634. Please report your observations there.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

Only for info: This problem is still not fixed in 0.27/fixes.

Getting a bit closer to the real problem the lost audio always happens only while using cutlists. Without a cutlist the audio is correctly trans-/encoded for me.

So there's a problem while detecting/loading the first audio frame(s) when cutting a file.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

I've found a workaround for people who want to transcode to mpeg4+mp3/uncompressed:

1. Encode only pure recording without any cutlist to the desired profile
2. after that you can cut the recording and trancode it with the lossless profile

This should beware of lossing the audio stream.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

After another debugging session I've found the error which caused the missing audio for me.

It was a simple audio timecode error while transcoding to mpeg4+mp3. The last written timecode was set only to the new (encoded) frame timecode instead of setting it to the offset timecode where the audio frame in the file to transcode begins. So mythtranscode could just not simply find any audio frames with a valid timecode because it search for (0+x) instead of (y+x) and just set audio each audio frame output to null.

I've also changed the position of all audio output transcodes to be writen after the video output because it always references the video frames timecode. Maybe this can fix the problem where audio begins to late in a video.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

Fix of timecode problem

[oli.henning@…]

@Nicolas: Very interesting - even though i don't understand much of your explanations.

But on thing: I opened this ticket concerning MPEG2-Video with MP2-Audio in SD resolution and a lossless (MPEG2-to-MPEG2 with MP2Audio-to-MP2Audo and/or AC3-to-AC3) transcoding. I think that you talk about HD-material (you say you have mpeg4+mp3).

I'm not sure if these two things are 100% related.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

Yes, you are right. My problem was transcoding into mpeg4+mp3 (SD/HD) where audio was completely missing. But as I described earlier I had also a similiar problem with the first seconds of a SD lossless transcode, where the audio in the file starts about 7 seconds after the first video frame. The workaround was to reencode it lossless again and the audio appears right.

Therefor I changed the position for audio transcoding in the patch. So maybe this patch could help with your problem too.

[oli.henning@…]

I also update to 0.27/fixes, but the problem remains exactly the same.

Perhaps one the Mythtv-Guys takes a look on the patch from Nicolas Pöhlmann (see 3 posts upwards) ad it's explanations (4 posts upwards).

[stuartm]

Nicolas: It would be better to submit two patches, one with the timecode fix and the other speculative patch which moves the code around. If at some point in the future it's discovered that the code move causes a new bug, then it's probable that the whole lot would be reverted and the timecode fix would get inadvertently thrown out.

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

After some more testing on about 15 transcodes to mpeg4+mp3 on different bouquets the speculative patch is needed to let first frame has the right audio timecode. So the patch have to stay as it is.

[dekarl@…]

Nicolas, I'm having a hard time seeing the timecode fix in the moved code, so splitting the patch would still be appreciated.

[nicolas.poehlmann@…]

The timecode patch for frame 2 until end are just one line at 1374 and 1388 in the patch:

lastWrittenTime = frame.timecode + timecodeOffset;

instead of

lastWrittenTime = frame.timecode;

BUT in my last post I tried to explain that if the first frame should also have an audio frame instead of null, the whole audio code have to be moved as in the patch so that it's processed after the video code which "generates" the timecode. So I could split it up, but this would make no sense for a real fix.

[dekarl@…]

Nicolas, looking at the patch I'm wondering if the timecodeOffset should be applied in the third place where video frames are written, too. ​​https://github.com/MythTV/mythtv/blob/master/mythtv/programs/mythtranscode/transcode.cpp#L1277

[Nicolas Pöhlmann <nicolas.poehlmann@…>]

No, this line can be removed. It has no sense here because it doesn't do anything when no audio is transcoded like in this subroutine.

[Karl Dietz <dekarl@…>]

In ea8c2b91e91e5cada8f8309f9fcb63f831f79aee/mythtv:

Error: Processor CommitTicketReference failed

GIT backend not available

[Karl Dietz <dekarl@…>]

In 11cbec350b520b28e0a2c2ae05805fb817acf9a1/mythtv:

Error: Processor CommitTicketReference failed

GIT backend not available

[tobias.powalowski@…]

Probably related: ​https://code.mythtv.org/trac/ticket/12147 Also Audio is identified as MP3. Reverting your 0.27.x commit and using the transcode.patch is not fixing this, so the position of the code does not solve my issue. My broken for transcode recordings were from German Sky program.

[JYA]

See #12153 for the worarounds