MP3 stream not starts playing from time to time

[GoogleCodeExporter]

What steps will reproduce the problem?
1. MultiPlayer player = new MultiPlayer();
2. player.playAsync("http://stream01.media.rambler.ru:80/makfresh128.mp3");

What is the expected output? What do you see instead?
Playing not starts from time to time. 7 of 10 times playing not starts!

What version of the product are you using? On which device ?
0.6.1

What is the URL of the stream ?
http://stream01.media.rambler.ru:80/makfresh128.mp3

Please provide any additional information below.

Log when playing not started:

21:57:44.823: D/dalvikvm(13469): Trying to load lib 
/data/data/ru.makradio.player/lib/libaacdecoder.so
21:57:44.833: D/dalvikvm(13469): Added shared lib 
/data/data/ru.makradio.player/lib/libaacdecoder.so
21:57:44.833: D/dalvikvm(13469): No JNI_OnLoad found in 
/data/data/ru.makradio.player/lib/libaacdecoder.so 0x40514830, skipping init
21:57:45.713: D/AACPlayer(13469): header: key=Cache-Control, val=no-cache
21:57:45.713: D/AACPlayer(13469): header: key=Content-Type, val=audio/mpeg
21:57:45.713: D/AACPlayer(13469): header: key=icy-br, val=128
21:57:45.713: D/AACPlayer(13469): header: key=icy-description, val=Makradio 
station (www.makradio.ru)
21:57:45.713: D/AACPlayer(13469): header: key=icy-genre, val=Discohouse & House
21:57:45.713: D/AACPlayer(13469): header: key=icy-name, val=*** Makradio Fresh 
***
21:57:45.713: D/AACPlayer(13469): header: key=icy-pub, val=1
21:57:45.713: D/AACPlayer(13469): header: key=icy-url, 
val=http://www.makradio.ru
21:57:45.713: D/AACPlayer(13469): header: key=Server, val=Icecast 2.3.2
21:57:45.713: I/MultiPlayer(13469): Setting MP3 decoder for content type 
audio/mpeg
21:57:45.713: I/AACPlayer(13469): Metadata not enabled
21:57:45.723: D/Makradio(13469): Player.playerStarted()
21:57:45.723: D/BufferReader(13469): init(): capacity=8000
21:57:45.733: D/BufferReader(13469): run() started....
21:57:45.733: I/Decoder(13469): start() starting native decoder - OpenCORE-MP3
21:57:45.733: D/BufferReader(13469): next() waiting....
21:57:45.753: D/BufferReader(13469): next() awaken
21:57:45.833: D/BufferReader(13469): run() waiting....

No more messages prints in log!

Log when playing started successfully:

22:05:00.123: D/AACPlayer(13469): header: key=Cache-Control, val=no-cache
22:05:00.123: D/AACPlayer(13469): header: key=Content-Type, val=audio/mpeg
22:05:00.123: D/AACPlayer(13469): header: key=icy-br, val=128
22:05:00.123: D/AACPlayer(13469): header: key=icy-description, val=Makradio 
station (www.makradio.ru)
22:05:00.123: D/AACPlayer(13469): header: key=icy-genre, val=Discohouse & House
22:05:00.123: D/AACPlayer(13469): header: key=icy-name, val=*** Makradio Fresh 
***
22:05:00.123: D/AACPlayer(13469): header: key=icy-pub, val=1
22:05:00.123: D/AACPlayer(13469): header: key=icy-url, 
val=http://www.makradio.ru
22:05:00.123: D/AACPlayer(13469): header: key=Server, val=Icecast 2.3.2
22:05:00.133: I/MultiPlayer(13469): Setting MP3 decoder for content type 
audio/mpeg
22:05:00.133: I/AACPlayer(13469): Metadata not enabled
22:05:00.133: D/BufferReader(13469): init(): capacity=8000
22:05:00.133: I/Decoder(13469): start() starting native decoder - OpenCORE-MP3
22:05:00.133: D/BufferReader(13469): next() waiting....
22:05:00.133: D/BufferReader(13469): run() started....
22:05:00.843: D/BufferReader(13469): next() awaken
22:05:00.893: D/AACPlayer(13469): play(): samplerate=44100, channels=2
22:05:00.943: D/BufferReader(13469): run() waiting....
22:05:01.013: D/dalvikvm(13469): GC_FOR_MALLOC freed 138K, 48% free 
3084K/5831K, external 645K/1043K, paused 43ms
22:05:01.053: D/dalvikvm(13469): GC_FOR_MALLOC freed 12K, 47% free 3243K/6023K, 
external 645K/1043K, paused 37ms
22:05:01.053: D/PCMFeed(13469): run(): sampleRate=44100, channels=2, 
bufferSizeInBytes=264600 (1500 ms)
22:05:01.113: D/BufferReader(13469): run() awaken
22:05:01.113: D/BufferReader(13469): run() waiting....
22:05:01.163: D/AACPlayer(13469): play(): decoded 87552 samples
22:05:01.163: D/BufferReader(13469): run() awaken
22:05:01.163: D/BufferReader(13469): run() waiting....
22:05:01.163: I/AACPlayer(13469): play(): changing kBitSecRate: 64 -> 128
22:05:01.163: D/BufferReader(13469): setCapacity(): 16000
22:05:01.213: D/BufferReader(13469): run() awaken
22:05:01.213: D/BufferReader(13469): run() capacity changed: 8000 -> 16000
22:05:01.213: D/BufferReader(13469): run() waiting....
22:05:01.263: D/BufferReader(13469): run() awaken
22:05:01.263: D/BufferReader(13469): run() capacity changed: 8000 -> 16000
22:05:01.263: D/AACPlayer(13469): play(): decoded 87552 samples
22:05:01.263: D/BufferReader(13469): run() waiting....
22:05:01.263: D/PCMFeed(13469): start buffer not filled enough - AudioTrack not 
started yet
22:05:01.273: D/PCMFeed(13469): start of AudioTrack - buffered 132300 samples
22:05:01.313: D/BufferReader(13469): run() awaken
22:05:01.313: D/BufferReader(13469): run() capacity changed: 8000 -> 16000
22:05:01.333: D/PCMFeed(13469): too fast for playback, sleeping...
22:05:01.383: D/AACPlayer(13469): play(): decoded 87552 samples
22:05:01.473: D/AACPlayer(13469): play(): decoded 87552 samples
22:05:02.053: D/AACPlayer(13469): play(): decoded 87552 samples
22:05:02.963: I/Decoder(13469): stop() stopping native decoder
22:05:02.963: I/AACPlayer(13469): play(): average decoding time: 97 ms
22:05:02.963: I/AACPlayer(13469): play(): average rate (samples/sec): 
audio=88200, decoding=900740, audio/decoding= 921 %  (the higher, the better; 
negative means that decoding is slower than needed by audio)
22:05:03.223: D/BufferReader(13469): run() stopped.
22:05:03.963: D/PCMFeed(13469): run() stopped.

Original issue reported on code.google.com by NKuznet...@gmail.com on 13 Sep 2012 at 4:09

[GoogleCodeExporter]

Not really 7 out of 10, its a bit lower. In my test it was only 3 out of 10. 

Original comment by arvid.ge...@gmail.com on 8 Oct 2012 at 6:16

[GoogleCodeExporter]

I wrote some code to do this and got the same behavior. The freeze occurs on 
the call to

decoder.start()

Original comment by bj...@xowave.com on 1 Nov 2012 at 8:59

[GoogleCodeExporter]

I am looking into core of this problem and find it in "jni 
mp3-opencore-decoder.c" -> static long aacd_opencoremp3_start(...):
...
/* pre-init search adts sync */
    while (pExt->outputFrameSize == 0) {
...
    status = pvmp3_framedecoder(pExt, oc->pMem); // status may never return NO_DECODING_ERROR sometimes

But I'am not C programmer and don't know how to fix it.

Original comment by Maxim.XT@gmail.com on 5 Jan 2013 at 4:13

[GoogleCodeExporter]

I've committed patch #22 (trunk) which fixes the way how the error is handled 
in MP3 decoder wrapper. So since now it does not hang up, but it throws an 
exception to the Java part.

Unfortunately it seems the root cause of the problem is somewhere in the 
underlying MP3 decoder: the error UNSUPPORTED_FREE_BITRATE is returned from it 
time to time.

Original comment by vbarta...@gmail.com on 29 May 2013 at 2:06

• Changed state: Accepted
• Added labels: Component-Native

[GoogleCodeExporter]

Revision 26: retry-loop rewritten in the mp3 wrapper as well in the generic 
decode loop (native)
Now the output looks like the following:

V/Decoder[OpenCORE-MP3](  997): start() buffer=c8a1446a size=5600
D/Decoder[OpenCORE-MP3](  997): start() Status[0]: 2 - consumed 0 bytes
E/Decoder[OpenCORE-MP3](  997): start() frame decode error=2
E/Decoder[OpenCORE-MP3](  997): start() first frame cannot be decoded - trying 
to sync again
E/Decoder[OpenCORE-MP3](  997): start() cannot re-sync the stream after next 
1024 bytes, status=12
D/Decoder[OpenCORE-MP3](  997): start() Status[0]: 0 - consumed 844 bytes
D/Decoder[OpenCORE-MP3](  997): start() bytesconsumed=1868
D/Decoder (  997): start() bytesleft=3732

Tested a little bit, seems working.

Original comment by vbarta...@gmail.com on 30 May 2013 at 9:00

• Changed state: Started

[GoogleCodeExporter]

Included in version 0.7

Original comment by vbarta...@gmail.com on 29 Dec 2013 at 10:37

• Changed state: Fixed