HLS Live testing. Failed on Samsung S2 (4.1.2) devices (IllegalStateException)

[taaeng]

Awesome work.

HLS Live working well on: LG G2, Nexus 7, Xperia Tablet Z, Tab 4

The Samsung S2 (4.1.2) gives this stacktrace:

08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): Internal runtime error.
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): java.lang.IllegalStateException
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at android.media.MediaCodec.dequeueOutputBuffer(Native Method)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at com.google.android.exoplayer.MediaCodecTrackRenderer.drainOutputBuffer(MediaCodecTrackRenderer.java:696)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at com.google.android.exoplayer.MediaCodecTrackRenderer.doSomeWork(MediaCodecTrackRenderer.java:387)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at com.google.android.exoplayer.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:407)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:203)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at android.os.Handler.dispatchMessage(Handler.java:95)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at android.os.Looper.loop(Looper.java:137)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at android.os.HandlerThread.run(HandlerThread.java:60)
08-21 15:49:04.345: E/ExoPlayerImplInternal(7284): at com.google.android.exoplayer.ExoPlayerImplInternal$1.run(ExoPlayerImplInternal.java:109)
08-21 15:49:04.350: E/ACodec(7284): [OMX.SEC.avc.dec] ERROR(0x90000004)
08-21 15:49:04.350: E/MediaCodec(7284): Codec reported an error. (omx error 0x90000004, internalError -2147483648)
08-21 15:49:04.355: E/EventLogger(7284): playerFailed [1.30]
08-21 15:49:04.355: E/EventLogger(7284): com.google.android.exoplayer.ExoPlaybackException: java.lang.IllegalStateException
08-21 15:49:04.355: E/EventLogger(7284): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:236)
08-21 15:49:04.355: E/EventLogger(7284): at android.os.Handler.dispatchMessage(Handler.java:95)
08-21 15:49:04.355: E/EventLogger(7284): at android.os.Looper.loop(Looper.java:137)
08-21 15:49:04.355: E/EventLogger(7284): at android.os.HandlerThread.run(HandlerThread.java:60)
08-21 15:49:04.355: E/EventLogger(7284): at com.google.android.exoplayer.ExoPlayerImplInternal$1.run(ExoPlayerImplInternal.java:109)
08-21 15:49:04.355: E/EventLogger(7284): Caused by: java.lang.IllegalStateException
08-21 15:49:04.355: E/EventLogger(7284): at android.media.MediaCodec.dequeueOutputBuffer(Native Method)
08-21 15:49:04.355: E/EventLogger(7284): at com.google.android.exoplayer.MediaCodecTrackRenderer.drainOutputBuffer(MediaCodecTrackRenderer.java:696)
08-21 15:49:04.355: E/EventLogger(7284): at com.google.android.exoplayer.MediaCodecTrackRenderer.doSomeWork(MediaCodecTrackRenderer.java:387)
08-21 15:49:04.355: E/EventLogger(7284): at com.google.android.exoplayer.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:407)
08-21 15:49:04.355: E/EventLogger(7284): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:203)

[fougere-mike]

What versions of android were you running on the S2 / Tab 4? I believe this may be the same issue as #4

[taaeng]

s2: 4.1.2
Tab 4: 4.4.2. I did this test a week ago. This seems to be working on Tab 4 now...
At the moment, only S2 is not working... I´ll test some other devices and update this issue.

[taaeng]

Some quick testing:

_1_
08-21 17:06:49.634: E/AndroidRuntime(3724): java.lang.RuntimeException: An error occured while executing doInBackground()
08-21 17:06:49.634: E/AndroidRuntime(3724): at android.os.AsyncTask$3.done(AsyncTask.java:299)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:352)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.util.concurrent.FutureTask.setException(FutureTask.java:219)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.util.concurrent.FutureTask.run(FutureTask.java:239)
08-21 17:06:49.634: E/AndroidRuntime(3724): at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:230)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.lang.Thread.run(Thread.java:841)
08-21 17:06:49.634: E/AndroidRuntime(3724): Caused by: java.lang.OutOfMemoryError
08-21 17:06:49.634: E/AndroidRuntime(3724): at dalvik.system.VMRuntime.newNonMovableArray(Native Method)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.nio.MemoryBlock.allocate(MemoryBlock.java:125)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:72)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.hls.Packet.resizeSample(Packet.java:47)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.parser.ts.TSExtractor$PESHandler.handlePayload(TSExtractor.java:135)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.parser.ts.TSExtractor.readOnePacket(TSExtractor.java:393)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.parser.ts.TSExtractor.read(TSExtractor.java:403)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.parser.ts.TSExtractorWithParsers.read(TSExtractorWithParsers.java:37)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.hls.HLSSampleSource$ChunkTask.doInBackground(HLSSampleSource.java:602)
08-21 17:06:49.634: E/AndroidRuntime(3724): at com.google.android.exoplayer.hls.HLSSampleSource$ChunkTask.doInBackground(HLSSampleSource.java:1)
08-21 17:06:49.634: E/AndroidRuntime(3724): at android.os.AsyncTask$2.call(AsyncTask.java:287)
08-21 17:06:49.634: E/AndroidRuntime(3724): at java.util.concurrent.FutureTask.run(FutureTask.java:234)
08-21 17:06:49.634: E/AndroidRuntime(3724): ... 4 more

_2_
08-21 17:08:23.864: E/MFC_DEC_APP(1934): SsbSipMfcDecInit] IOCTL_MFC_DEC_INIT failed
08-21 17:08:23.864: E/SEC_H264_DEC(1934): SsbSipMfcDecInit() failed!
08-21 17:08:23.864: E/ACodec(4369): [OMX.SEC.avc.dec] ERROR(0x90000004)
08-21 17:08:23.864: E/MediaCodec(4369): Codec reported an error. (omx error 0x90000004, internalError -2147483648)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): Internal runtime error.
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): java.lang.IllegalStateException
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at android.media.MediaCodec.dequeueOutputBuffer(Native Method)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at com.google.android.exoplayer.MediaCodecTrackRenderer.drainOutputBuffer(MediaCodecTrackRenderer.java:696)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at com.google.android.exoplayer.MediaCodecTrackRenderer.doSomeWork(MediaCodecTrackRenderer.java:387)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at com.google.android.exoplayer.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:407)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:203)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at android.os.Handler.dispatchMessage(Handler.java:95)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at android.os.Looper.loop(Looper.java:176)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at android.os.HandlerThread.run(HandlerThread.java:61)
08-21 17:08:23.869: E/ExoPlayerImplInternal(4369): at com.google.android.exoplayer.ExoPlayerImplInternal$1.run(ExoPlayerImplInternal.java:109)
08-21 17:08:23.869: D/ProgressBar(4369): setProgress = 0
08-21 17:08:23.869: D/ProgressBar(4369): setProgress = 0, fromUser = false
08-21 17:08:23.869: D/ProgressBar(4369): mProgress = 0mIndeterminate = false, mMin = 0, mMax = 1000
08-21 17:08:23.889: V/WindowManager(2339): Window{432faab8 u0 Keyguard}mOrientationRequetedFromKeyguard=false
08-21 17:08:23.894: E/EventLogger(4369): playerFailed [1.93]
08-21 17:08:23.894: E/EventLogger(4369): com.google.android.exoplayer.ExoPlaybackException: java.lang.IllegalStateException
08-21 17:08:23.894: E/EventLogger(4369): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:236)
08-21 17:08:23.894: E/EventLogger(4369): at android.os.Handler.dispatchMessage(Handler.java:95)
08-21 17:08:23.894: E/EventLogger(4369): at android.os.Looper.loop(Looper.java:176)
08-21 17:08:23.894: E/EventLogger(4369): at android.os.HandlerThread.run(HandlerThread.java:61)
08-21 17:08:23.894: E/EventLogger(4369): at com.google.android.exoplayer.ExoPlayerImplInternal$1.run(ExoPlayerImplInternal.java:109)
08-21 17:08:23.894: E/EventLogger(4369): Caused by: java.lang.IllegalStateException
08-21 17:08:23.894: E/EventLogger(4369): at android.media.MediaCodec.dequeueOutputBuffer(Native Method)
08-21 17:08:23.894: E/EventLogger(4369): at com.google.android.exoplayer.MediaCodecTrackRenderer.drainOutputBuffer(MediaCodecTrackRenderer.java:696)
08-21 17:08:23.894: E/EventLogger(4369): at com.google.android.exoplayer.MediaCodecTrackRenderer.doSomeWork(MediaCodecTrackRenderer.java:387)
08-21 17:08:23.894: E/EventLogger(4369): at com.google.android.exoplayer.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:407)
08-21 17:08:23.894: E/EventLogger(4369): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:203)
08-21 17:08:23.894: E/EventLogger(4369): ... 4 more

_3_
08-21 17:21:07.941: E/dalvikvm-heap(4228): Out of memory on a 19032-byte allocation.
08-21 17:21:07.941: I/dalvikvm(4228): "AsyncTask #4" prio=5 tid=17 RUNNABLE
08-21 17:21:07.941: I/dalvikvm(4228): | group="main" sCount=0 dsCount=0 obj=0x42220aa8 self=0x5c41c268
08-21 17:21:07.941: I/dalvikvm(4228): | sysTid=4287 nice=10 sched=0/0 cgrp=apps/bg_non_interactive handle=1547425584
08-21 17:21:07.941: I/dalvikvm(4228): | state=R schedstat=( 11039121000 4383375000 33256 ) utm=951 stm=152 core=1
08-21 17:21:07.941: I/dalvikvm(4228): at dalvik.system.VMRuntime.newNonMovableArray(Native Method)
08-21 17:21:07.941: I/dalvikvm(4228): at java.nio.MemoryBlock.allocate(MemoryBlock.java:126)
08-21 17:21:07.941: I/dalvikvm(4228): at java.nio.ReadWriteDirectByteBuffer.(ReadWriteDirectByteBuffer.java:46)
08-21 17:21:07.941: I/dalvikvm(4228): at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:68)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.hls.Packet.resizeSample(Packet.java:47)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.parser.ts.TSExtractor$PESHandler.handlePayload(TSExtractor.java:135)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.parser.ts.TSExtractor.readOnePacket(TSExtractor.java:393)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.parser.ts.TSExtractor.read(TSExtractor.java:403)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.parser.ts.TSExtractorWithParsers.read(TSExtractorWithParsers.java:37)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.hls.HLSSampleSource$ChunkTask.doInBackground(HLSSampleSource.java:602)
08-21 17:21:07.941: I/dalvikvm(4228): at com.google.android.exoplayer.hls.HLSSampleSource$ChunkTask.doInBackground(HLSSampleSource.java:1)
08-21 17:21:07.941: I/dalvikvm(4228): at android.os.AsyncTask$2.call(AsyncTask.java:287)
08-21 17:21:07.941: I/dalvikvm(4228): at java.util.concurrent.FutureTask.run(FutureTask.java:234)
08-21 17:21:07.941: I/dalvikvm(4228): at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:230)
08-21 17:21:07.941: I/dalvikvm(4228): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
08-21 17:21:07.941: I/dalvikvm(4228): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08-21 17:21:07.941: I/dalvikvm(4228): at java.lang.Thread.run(Thread.java:856)
08-21 17:21:07.941: W/dalvikvm(4228): threadid=17: thread exiting with uncaught exception (group=0x41b4f930)
08-21 17:21:07.951: D/EventLogger(4228): droppedFrames [26.63, 1]
08-21 17:21:07.961: E/AndroidRuntime(4228): FATAL EXCEPTION: AsyncTask #4
08-21 17:21:07.961: E/AndroidRuntime(4228): java.lang.RuntimeException: An error occured while executing doInBackground()
08-21 17:21:07.961: E/AndroidRuntime(4228): at android.os.AsyncTask$3.done(AsyncTask.java:299)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.util.concurrent.FutureTask.finishCompletion(FutureTask.java:352)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.util.concurrent.FutureTask.setException(FutureTask.java:219)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.util.concurrent.FutureTask.run(FutureTask.java:239)
08-21 17:21:07.961: E/AndroidRuntime(4228): at android.os.AsyncTask$SerialExecutor$1.run(AsyncTask.java:230)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1080)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:573)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.lang.Thread.run(Thread.java:856)
08-21 17:21:07.961: E/AndroidRuntime(4228): Caused by: java.lang.OutOfMemoryError
08-21 17:21:07.961: E/AndroidRuntime(4228): at dalvik.system.VMRuntime.newNonMovableArray(Native Method)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.nio.MemoryBlock.allocate(MemoryBlock.java:126)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.nio.ReadWriteDirectByteBuffer.(ReadWriteDirectByteBuffer.java:46)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.nio.ByteBuffer.allocateDirect(ByteBuffer.java:68)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.hls.Packet.resizeSample(Packet.java:47)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.parser.ts.TSExtractor$PESHandler.handlePayload(TSExtractor.java:135)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.parser.ts.TSExtractor.readOnePacket(TSExtractor.java:393)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.parser.ts.TSExtractor.read(TSExtractor.java:403)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.parser.ts.TSExtractorWithParsers.read(TSExtractorWithParsers.java:37)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.hls.HLSSampleSource$ChunkTask.doInBackground(HLSSampleSource.java:602)
08-21 17:21:07.961: E/AndroidRuntime(4228): at com.google.android.exoplayer.hls.HLSSampleSource$ChunkTask.doInBackground(HLSSampleSource.java:1)
08-21 17:21:07.961: E/AndroidRuntime(4228): at android.os.AsyncTask$2.call(AsyncTask.java:287)
08-21 17:21:07.961: E/AndroidRuntime(4228): at java.util.concurrent.FutureTask.run(FutureTask.java:234)
08-21 17:21:07.961: E/AndroidRuntime(4228): ... 4 more

[martinbonnin]

Thanks for the info, that's interesting. I reworked a bit the codec initialization this morning (36a305d). It might or might not help the IllegalState issues.

For the memory issues, I'll try to guess a reasonnable max bufferSize but I'm currently fighting to get my hands on a representative sample of android devices.

[martinbonnin]

@taaeng Also I'm a bit confused. Your initial report stated that S2 was not working but your chart show the opposite. Does that mean it worked in the end ?

[taaeng]

No. That must be an mistake. Let me retest the samsung devices. I´ll update the image.

[martinbonnin]

ok thanks

[fougere-mike]

@taaeng Can you re-test this on ccf17ad ?

[taaeng]

HLS LIVE does not seem to work now.. We have a 3 hour live buffer and it is showing 10 seconds on Sasmung S3 and the video is not showing. On LG3 it is decreasing the duration ones it reach 10 seconds... When I did the test before, the duration was always 3 hours, and I could seek in it.

S3 exception:
09-05 12:29:08.080: E/EventLogger(15488): playerFailed [1.96]
09-05 12:29:08.080: E/EventLogger(15488): com.google.android.exoplayer.ExoPlaybackException: java.lang.IllegalStateException
09-05 12:29:08.080: E/EventLogger(15488): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:236)
09-05 12:29:08.080: E/EventLogger(15488): at android.os.Handler.dispatchMessage(Handler.java:95)
09-05 12:29:08.080: E/EventLogger(15488): at android.os.Looper.loop(Looper.java:176)
09-05 12:29:08.080: E/EventLogger(15488): at android.os.HandlerThread.run(HandlerThread.java:61)
09-05 12:29:08.080: E/EventLogger(15488): at com.google.android.exoplayer.ExoPlayerImplInternal$1.run(ExoPlayerImplInternal.java:109)
09-05 12:29:08.080: E/EventLogger(15488): Caused by: java.lang.IllegalStateException
09-05 12:29:08.080: E/EventLogger(15488): at android.media.MediaCodec.dequeueOutputBuffer(Native Method)
09-05 12:29:08.080: E/EventLogger(15488): at com.google.android.exoplayer.MediaCodecTrackRenderer.drainOutputBuffer(MediaCodecTrackRenderer.java:701)
09-05 12:29:08.080: E/EventLogger(15488): at com.google.android.exoplayer.MediaCodecTrackRenderer.doSomeWork(MediaCodecTrackRenderer.java:390)
09-05 12:29:08.080: E/EventLogger(15488): at com.google.android.exoplayer.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:407)
09-05 12:29:08.080: E/EventLogger(15488): at com.google.android.exoplayer.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:203)
09-05 12:29:08.080: E/EventLogger(15488): ... 4 more

[martinbonnin]

If it's a regression, can you tell the commit that introduced it ?

[taaeng]

-The duration issue seems to happen after Aug 27, 2014 commits...
-I get the exception on S3 on commit "Implement h264 SPS parsing, and use parsed values for codec initiali…" as well...