Audio breakup's on 720p channels.

[sirwio]

Since the last post I have tested various buffer settings without any improvements. Since playback is fine with omxplayer and omxplayer is using ffmpeg and not libav I spent some time compiling ffmpeg and compiled a vompclient version using ffmpeg instead of libav. Did not improve anything.

Is there a way to dump the stream, by modifying source code on the client and/or server side, to a file to check if the problem is with the streamed data? Suggestions on where and how this could be done would be appreciated.

[MartenR]

There is something else you can use for diagnosis.
In AudioOMX::AdvanceMpAudioSync you can uncomment the log lines with the FRAME messages.
For one television station, they should not change, if they change, it is possible, that the algorithm detect non audio frames as audio frames.

For dumping the stream, you can use DeliverMediaPacket. You can put write the data at various places to a file here. Before and after decoding.

Marten

[sirwio]

So I uncommented the logs in AudioOMX::AdvanceMpAudioSync and can observe the following:

Whenever there is some libav error the logs look like below (greping only logs with text Audio)

15:00:01.116161 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.118679 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.120568 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.122935 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.248154 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.248326 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.253840 [debug]  5064 Audio - FRAME: 0 1 10 48000 0 320 320
15:00:01.255390 [debug]  5064 Audio - FRAME DIAG: ff fa a5
    Last message repeated 2 times
[mp3 @ 0xd3bea0] incomplete frame
15:00:01.262895 [debug]  5064 Audio - FRAME: 0 1 10 48000 0 320 320
15:00:01.266083 [debug]  5064 Audio - FRAME DIAG: ff fa a5
15:00:01.269644 [debug]  5064 Audio - FRAME: 0 1 10 48000 0 320 320
15:00:01.271737 [debug]  5064 Audio - FRAME DIAG: ff fa a5
15:00:01.427507 [debug]  5064 Audio - FRAME: 0 1 10 48000 0 320 320
15:00:01.427676 [debug]  5064 Audio - FRAME DIAG: ff fa a5
15:00:01.428898 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.429013 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.437340 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.438675 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.444627 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.446386 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.451323 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.454851 [debug]  5064 Audio - FRAME DIAG: ff fc c4
15:00:01.457935 [debug]  5064 Audio - FRAME: 0 2 12 48000 0 256 768
15:00:01.466471 [debug]  5064 Audio - FRAME DIAG: ff fc c4

Is this an indication of something broken in the stream or in the frame detection algorithms?

As for the longer audio drops there were at least a few where the FRAME message did not change - nor where there any libav errors.

[MartenR]

Yes,looks like a frame misdetection.

[sirwio]

I suspect that line 1583 in AudioOMX::AdvanceMpAudioSync (audioomx.cc) is parsing the layer description bits incorrectly.

Code Select Expand

1583                         int layer=4-(data[test+2]&0x03)>>1;

The layer is as far as I can tell it located in position bit 18 and 17 of the mpeg audio frame header e.g in data[test+1]. The layer would then be calculated as:

Code Select Expand

int layer = 4 - ( (data[test+1] & 0x06) >>1 );

Does this make sense or have I totally misunderstood how the parsing is done?

Am i correct in the understanding of the local variable mpeg2 that its actually a variable holding status if the frame is an mpeg version 2.5 audio frame or not.

But what is the lsf variable?

[MartenR]

You are correct, this is wrong. Thanks. (I will commit this soon).
Regarding the mpeg2 variable I think it indicates mpeg version 2.5.
lsf indicates mpeg2 vs. mpeg1, if I remember correctly.

Marten

[sirwio]

Thanks. I have figured out the lsf variable as well especially why it was also set when an mpeg 2.5 frame was detected.

I still get some libav errors. On at least one of them the layer value was a reserved value (00). Checking the libav source code I noticed they perform a santiy check on the header not only checking if the framesync is correct but also checking the values of the layer, bitrate and frequency.

A comment of the method making the header check in libav says: "fast header check for resync".

Will test with such checks in place to see what happens.

Another discrepancy between the documentation I have found, http://mpgedit.org/mpgedit/mpeg_format/mpeghdr.htm#MPEG%20HEADER, and the libav implementation is how the frame size is calculated. According to the doc the frame size should be calculated the same for layer 2 and layer 3 messages but in the libav implementation they differ. The docs does however not claim to be accurate... Do you have a pointer to some other documentation on the the mpeg audio frame header.

[MartenR]

not only checking if the framesync is correct but also checking the values of the layer, bitrate and frequency.

It might be necessary to implement this as well....

I have no additional documentation for mpeg audio than the ones you mentioned. There might be the specification...

Marten

[sirwio]

Attached is a patch that will check the mpeg audio header before attempting to parse it. I have kept the implementation simple since I assume it will be rewritten if added to the sources.

The header check is implemented in a helper function private to the class AudioOMX named checkMpAudioHeader

There is one check that is questionable and that is the check if the bitrate index is of type "free format". Since the current code does not appear to take the "free format" into account when the bitrate is calculated I chose to include it in the helper. Its questionable since a function named checkMpAudioHeader shall only check the header and not perform application logic. (In this case invalidating the header if the bitrate index is of type "free format".

With this change there are no more audio drops during live tv. There are however occasional audio "chirps" during both live and playback of recordings on the 720p channels.

When the "chirps" occur there are, with the patch applied, messages about various mpeg header inconsistencies as well as libav errors:
[mp3 @ 0x7ecb60] big_values too big
[mp3 @ 0x7ecb60] Error while decoding MPEG audio frame.

Since recordings play fine using other methods I must ask. Is the vompserver plugin modifying the stream before its sent in some way compared to e.g. the streamdev plugin? In other words. Is the problems I see perhaps on the server side and not on the client side.

[MartenR]

I will look into the patch and implement sth. similar.

Since recordings play fine using other methods I must ask. Is the vompserver plugin modifying the stream before its sent in some way compared to e.g. the streamdev plugin? In other words. Is the problems I see perhaps on the server side and not on the client side.

Of course vomp modifies it in some way. Everything is done on the client side.
We have a demuxer, then the parsing code in audioomx. Everything there can have an error which drops some data.
Also it is possible that the playerlivetv has droped some data, look for the log message "Dropped chunk", if this occurs the number of max buffers PLAYER_MAX_STREAMING_BUFFERS defined in defines.h is too small.

Anyway the message, "big_values too big" is a sanity check in side the mpeg audio layer 3 decoder. Since audio should be layer 1 or 2 in DVB (check this please for your channel), it is very likely, that  it is still not synced properly.

Marten

[MartenR]

I have implemented sanity checks similar to your checks.
Please test it.

Marten

[sirwio]

The implementation works as good as mine.

I still have annoying high frequency chirps once in a while but the client is now usable. There are no log entries indicating that buffers are full.

The specs of the channels are http://www.svt.se/omsvt/om-sandningarna/hdtv/expertinformation:
Video
H.264/AVC/MPEG-4 Part 10 with variable BitRate (VBR). Practically this means that the bitrate may vary between 4 and 16 Mbit/s.

Audio
Both stereo and 5.1 multichannel. The 5.1 sound is coded as Dolby Digital (AC3) @ 448 kbit/s. The stereo sound is coded as MPEG1-L2@256kbit/s

[MartenR]

annoying high frequency chirps

These are probably still misdetected mpeg audio frames. But I do not know how to identify them.
Anyway, I suggest, that you select the ac3 audio track, since all your problems are related to mpeg audio.

Marten

[sirwio]

I just realized while looking at your implementation that the layer description sanity test is not correct.

Its the value of

Code Select Expand

(data[test+1]&0x06)>>1
that shall be checked if its zero. NOT the calculated layer variable :-)

Choosing the ac3 audio track makes the chirps go away but in that case there are libav ac3 errors in the log as well as occasional disturbances in the audio. Much less annoying than the audio chirps but still audible:

I will continue looking into the demuxer and audio parsing code. It annoys me a lot not finding the root of the problems I see.

Code Select Expand


01:52:36.962970 [debug]  2309 Audio - warning we only support 48 KHz sampling rate
    Last message repeated 1 times
[ac3 @ 0xc03340] invalid sample rate
01:52:41.043573 [debug]  2309 VDR - Sending KA packet
01:52:41.047933 [debug]  2309 VDR - Rxd correct KA reply
01:52:44.727333 [debug]  2309 Audio - warning we only support 48 KHz sampling rate
[ac3 @ 0xc03340] invalid bitstream id
01:52:47.037351 [debug]  2309 VDR - Sending KA packet
01:52:47.045016 [debug]  2309 VDR - Rxd correct KA reply
01:52:53.021903 [debug]  2309 VDR - Sending KA packet
01:52:53.024487 [debug]  2309 VDR - Rxd correct KA reply
01:52:59.047240 [debug]  2309 VDR - Sending KA packet
01:52:59.052316 [debug]  2309 VDR - Rxd correct KA reply
01:53:00.000099 [debug]  2309 Timers - Timer firing for client 0xc2407c ref 1
01:53:00.001678 [debug]  2309 Timers - Timer firing for client 0xc1ab94 ref 2
01:53:00.003375 [debug]  2309 Timers - sending timer to 0xc2407c with parameter 1
01:53:00.010658 [debug]  2309 Timers - sending timer to 0xc1ab94 with parameter 2
01:53:00.013072 [debug]  2309 VVideoLiveTV - Timer Call 2  start.
01:53:00.015855 [debug]  2309 Timers - Starting set timer 1
01:53:00.016964 [debug]  2309 VVideoLiveTV - Timer Call 2 end.
01:53:00.017663 [debug]  2309 Timers - timerEventFinished for 0xc1ab94
01:53:00.019067 [debug]  2309 Timers - timerEventFinished RESTART for 0xc1ab94
01:53:00.014019 [debug]  2309 Timers - Starting set timer 1
01:53:00.020865 [debug]  2309 BoxStack - Update called
01:53:00.021624 [debug]  2309 BoxStack - Locked for update
01:53:00.022474 [debug]  2309 BoxStack - Unlocked for update
01:53:00.023312 [debug]  2309 Timers - timerEventFinished for 0xc2407c
01:53:00.024435 [debug]  2309 Timers - timerEventFinished RESTART for 0xc2407c
01:53:05.006448 [debug]  2309 VDR - Sending KA packet
01:53:05.017063 [debug]  2309 VDR - Rxd correct KA reply
01:53:11.036978 [debug]  2309 VDR - Sending KA packet
01:53:11.042163 [debug]  2309 VDR - Rxd correct KA reply
[ac3 @ 0xc03340] frame CRC mismatch
01:53:15.819078 [debug]  2309 Audio - warning we only support 48 KHz sampling rate
[ac3 @ 0xc03340] Additional substreams not implemented. Update your Libav version to the newest one from Git. If the problem still occurs, it means that your file has a feature which has not been implemented.
[ac3 @ 0xc03340] If you want to help, upload a sample of this file to ftp://upload.libav.org/incoming/ and contact the libav-devel mailing list.
[ac3 @ 0xc03340] unsupported frame type : skipping frame
01:53:17.034369 [debug]  2309 VDR - Sending KA packet
01:53:17.039655 [debug]  2309 VDR - Rxd correct KA reply
01:53:23.030194 [debug]  2309 VDR - Sending KA packet
01:53:23.033451 [debug]  2309 VDR - Rxd correct KA reply
01:53:29.026229 [debug]  2309 VDR - Sending KA packet
01:53:29.031699 [debug]  2309 VDR - Rxd correct KA reply
01:53:35.024122 [debug]  2309 VDR - Sending KA packet
01:53:35.027782 [debug]  2309 VDR - Rxd correct KA reply
01:53:41.026716 [debug]  2309 VDR - Sending KA packet
01:53:41.031866 [debug]  2309 VDR - Rxd correct KA reply
01:53:47.034125 [debug]  2309 VDR - Sending KA packet
01:53:47.038614 [debug]  2309 VDR - Rxd correct KA reply
01:53:53.032517 [debug]  2309 VDR - Sending KA packet
01:53:53.036165 [debug]  2309 VDR - Rxd correct KA reply
01:53:54.520081 [debug]  2309 Audio - warning we only support 48 KHz sampling rate
[ac3 @ 0xc03340] invalid bitstream id
[ac3 @ 0xc03340] frame CRC mismatch
01:53:59.009119 [debug]  2309 VDR - Sending KA packet
01:53:59.014178 [debug]  2309 VDR - Rxd correct KA reply
01:53:59.402754 [debug]  2309 Audio - warning we only support 48 KHz sampling rate
[ac3 @ 0xc03340] incomplete frame
01:54:00.000155 [debug]  2309 Timers - Timer firing for client 0xc2407c ref 1


[MartenR]

I have fix the sanity check.

I will continue looking into the demuxer and audio parsing code. It annoys me a lot not finding the root of the problems I see.

I think it is very likely, that all problems originate from "DeliverMediaPacket". It is very likely, since you mentioned, that there is no problem on the mvp.

For the ac3 data you can compare passthrough mode and non passthrough mode. In the case of passthrough mode, you would not see any libav messages, since everything is done in the tv, but if the data delivered to "DeliverMediaPacket" is corrupt, you will hear it.
If everything is working fine, that error must be after the "else" related to "if (passthrough) {".

Good luck!

Marten