google / ExoPlayer

This project is deprecated and stale. The latest ExoPlayer code is available in https://github.com/androidx/media
https://developer.android.com/media/media3/exoplayer
Apache License 2.0
21.74k stars 6.03k forks source link

ANR on player release #4352

Closed aarondib closed 4 years ago

aarondib commented 6 years ago

Issue description

According to log reports from users, after upgrade to r2.8.1 (from r2.6.1), on about 1% of app sessions we have ANR on SimpleExoPlayer.release(). Never seen this issue (reports) on versions <=r2.6.1.

Reproduction steps

Play some stream and then call SimpleExoPlayer.release(), called in main thread.

Link to test content

Unknown for a while.

Version of ExoPlayer being used

r2.8.1.

Device(s) and version(s) of Android being used

Different devices and Android versions: Nvidia Shield TV, Xiaomi Mi-Box, etc.

A full bug report captured from the device

"main" tid=1 Waiting

"main" prio=5 tid=1 Waiting | group="main" sCount=1 dsCount=0 obj=0x762777f0 self=0x7527e95a00 | sysTid=32258 nice=-10 cgrp=default sched=0/0 handle=0x752beaea98 | state=S schedstat=( 264497782805 29710697109 1267932 ) utm=22158 stm=4291 core=7 HZ=100 | stack=0x7ff8a69000-0x7ff8a6b000 stackSize=8MB | held mutexes=
at java.lang.Object.wait! (Native method)
- waiting on <0x0225fb39> (a com.google.android.exoplayer2.ExoPlayerImplInternal)
at com.google.android.exoplayer2.ExoPlayerImplInternal.release (unavailable)
- locked <0x0225fb39> (a com.google.android.exoplayer2.ExoPlayerImplInternal)
com.google.android.exoplayer2.ExoPlayerImpl.release (unavailable)
com.google.android.exoplayer2.SimpleExoPlayer.release (unavailable)
...
andrewlewis commented 6 years ago
ojw28 commented 6 years ago

Agreed we need a full bug report (or at least the stack traces of all of the threads) to debug this.

aarondib commented 6 years ago

1) Could this "bug report" be get from Google Play Console's ANR reports? And will it has enough data to analyze playback thread?

2) Looks like, all devices are affected equally. It will be more precise when more users install app update.

3) We did not added any new features when upgraded from 2.6.1 to 2.8.1. No manual message sending. But surface changing during playback had been added a long time ago. For example, when Surface occasionally happens to be recreated during playback.

aarondib commented 6 years ago

@andrewlewis sent you an e-mail with ANR bug reports from different devices.

ojw28 commented 6 years ago

Looking at the stack traces, it looks like release is blocked on the playback thread, which is typical for this kind of ANR. The playback thread is blocked on various different codec related platform calls (e.g. MediaCodec.native_stop), without a clear pattern.

We do see this kind of ANR happen occasionally on devices, when the underlying platform media server gets into a bad state. This is not something we'd expect to occur more frequently with 2.8.0 than earlier releases, however, and I'm not aware of anything that we did that's likely to have exacerbated the issue.

Are you certain these ANRs are increased as of 2.8.0, rather than some other change, such as them being better reported than they were previously? What ANR rate did you see when releasing the player previously? It should have been higher than 0 if ANRs were being reported correctly, since we've been aware of rare/sporadic ANRs when calling release for quite a long time.

aarondib commented 6 years ago

@ojw28 Thanks!

We have not seen any of ExoPlayer related ANR reports before. Even can't find any of them. It appears in the last version which uses upgraded 2.8.1 version. The app is on beta stage currently and not looks like it's too much of them but comparable value with the others. We'll put the app with 2.8.1 as a release and then inform you of the result ANR rate.

Do you have any ideas why could we have not seen ExoPlayer related ANRs before?

ojw28 commented 6 years ago

That's (unfortunately!) strange, unless you were previously not calling release on the player. Is that possible? If not, then I think I would expect at least the odd ANR to be reported. Please do let us know what you discover.

prcaen commented 6 years ago

Hey, We are using the 2.7.3 and we are facing the same issue. So this is not specific to 2.8.X version.

aarondib commented 6 years ago

After the final release we do not see any valuable ANR growth. However, we saw it (ExoPlayer-related ANRs) in reports of Beta-versions. Probably, was caught "problematc" beta testers.

Also, during research we've found some specific devices on which changing Surface on-the-fly causes ANRs. Will open separate issue on this. Thanks!

abubalanandan commented 6 years ago

Hi,

I'm seeing the same ANR issue on both the release() method of the exoplayer and also the blockingSendMessages of the exoplayer. Am on exoplayer 2.2.0. Seeing that this issue has still not been resolved, is there good reason to update to the latest version and try? Also, any workarounds for this issue? I have attached stack traces for both issues. blockingSendMessages.txt release_trace.txt

sixones commented 6 years ago

We are experiencing this issue in 2.7.1 as well, stacktrace from the Google Play Console, as you can see we call SimpleExoPlayer.release.

  at java.lang.Object.wait (Object.java)
- waiting on <0x057d9834> (a com.google.android.exoplayer2.k)
  at com.google.android.exoplayer2.ExoPlayerImplInternal.release (ExoPlayerImplInternal.java:232)
- locked <0x057d9834> (a com.google.android.exoplayer2.k)
  at com.google.android.exoplayer2.ExoPlayerImpl.release (ExoPlayerImpl.java:342)
  at com.google.android.exoplayer2.SimpleExoPlayer.release (SimpleExoPlayer.java:681)
  at com.plexapp.plex.videoplayer.local.v2.Exo2VideoPlayer.disconnect

This looks to be only picked up now because of the changes to ANR's on the Google Play Console, rather than an issue in a new version of ExoPlayer v2 (at least from what we can tell).

Tolriq commented 6 years ago

@ojw28 / @tonihei After all discussions about threading and the adding of your internal stat handler that creates the race conditions https://github.com/google/ExoPlayer/issues/4278.

I finally followed the recommendations and switched to all access on mainthread and I'm now facing this ANR too. (Google Vitals, unable to reproduce yet)

"main" prio=5 tid=1 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x749478d0 self=0x7f92095a00
  | sysTid=9432 nice=0 cgrp=default sched=0/0 handle=0x7f95f53a98
  | state=S schedstat=( 0 0 0 ) utm=1130 stm=86 core=4 HZ=100
  | stack=0x7fd81f0000-0x7fd81f2000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait! (Native method)
- waiting on <0x026f6e6f> (a com.google.android.exoplayer2.l)
  at com.google.android.exoplayer2.l.a (ExoPlayerImplInternal.java:228)
- locked <0x026f6e6f> (a com.google.android.exoplayer2.l)
  at com.google.android.exoplayer2.j.c (ExoPlayerImpl.java:372)
  at com.google.android.exoplayer2.al.c (SimpleExoPlayer.java:788)
  at org.leetzone.android.yatsewidget.f.c.e$b.run (MusicPlayer.kt:200)
  at android.os.Handler.handleCallback (Handler.java:751)
  at android.os.Handler.dispatchMessage (Handler.java:95)
  at android.os.Looper.loop (Looper.java:154)
  at android.app.ActivityThread.main (ActivityThread.java:6186)
  at java.lang.reflect.Method.invoke! (Native method)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run (ZygoteInit.java:889)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:779)

Related code is;

    handler.sendEmptyMessage(MSG_RELEASE);
    boolean wasInterrupted = false;
    while (!released) {
      try {
        wait();
      } catch (InterruptedException e) {
        wasInterrupted = true;
      }
    }

IMO you can't ask people to call that on main thread as there's so many possible reasons for a message sent to a thread to be delayed or not arriving at all.

Hard to choose between very rare race conditions or rare ANR.

And a little disappointed that the issue was known yet pushing toward main thread :( since we've been aware of rare/sporadic ANRs when calling release for quite a long time. I should have rewritten the code to do everything on a background thread instead.

Is there a way to reduce risk of race conditions with your stat handler when moving back the release call to background thread?

ojw28 commented 6 years ago

IMO you can't ask people to call that on main thread as there's so many possible reasons for a message sent to a thread to be delayed or not arriving at all.

The rare/sporadic ANRs occur when MediaCodec gets into a bad state, causing one of ExoPlayer's calls into it to hang indefinitely. I'm not sure that we've ever seen a reported occurrence that's been anything other than this, so I disagree with the statement that there are many possible reasons. In practice we only see one.

Hard to choose between very rare race conditions or rare ANR.

I don't think this is an accurate reflection of the choice. It's more like choosing between:

  1. Rare ANRs, which result in your process being killed. This is bad, but at least make it likely that your app will be in a good state when the user re-opens it.
  2. Releasing the player on a background thread, which is being a bad citizen. By doing this you hold on to limited resources (e.g. hardware codecs, possibly the secure video output path) for an uncontrolled period of time that likely extends beyond the point at which your activity is stopped. Whatever activity is coming into the foreground may try and acquire those resources before you release them, and so may end up failing to do so. On some older devices you can break the camera by holding onto the secure video output path beyond the point at which your activity is stopped, for example. Also, whilst you avoid your process being killed, it's quite likely that subsequent playbacks within your own process will fail due to the bad state of the underlying media components. So whilst you've made the problem less visible from the point of view of your dashboards / automatic feedback, you might have actually made the problem worse for your users because your app may just remain in a broken state until the process is killed via some other means.
Tolriq commented 6 years ago

You send a message to a thread and wait for something that is supposed to be done there for infinite time. Maybe currently only MediaCodec bad state generate that, but message queue could be full or take time to manage all and all those will generate lag on main thread. Wait on main thread is being a bad citizen on Android, and Google says that nearly everywhere ;) Specially when it's done inside a library without users having a way to know that this will happens and with said library urging users to only use main thread. I'm happy to have seen that during beta phase.

About the choice, currently the app only use AudioPlayer part, so being a bad citizen is less an issue, and this is just a small part of the app. Release occurs when the user changes it's player to something not ExoPlayer related so hopefully won't reuse the player until the codec is released. If it's never released then maybe there's something to address in ExoPlayer too if possible, else in all cases, crash or issue user is not happy about the app.

And currently app is rated 4.75 and in top 2% of all Play Store apps about crash and 7% for ANR (Both remaining issues being due to bugs in Support Library that should be fixed in 28 and Android 8 bug with startForeground). I'm lucky to have an active community that report issues and allow building such app, so everything I can do on my side to ensure them a proper experience is important. 0,001% of crashed MediaCodec is better than 0,01% of ANR or Lag as both result in reduced experience but one case impact less users.

ojw28 commented 6 years ago

but message queue could be full or take time to manage all and all those will generate lag on main thread

This is hypothetical and not true in practice. The message queue is completely under our control, and will normally only have one or two messages queued at any given point in time.

Wait on main thread is being a bad citizen on Android, and Google says that nearly everywhere ;)

There are some cases where not waiting is significantly worse, as is the case here. There are other cases where waiting on the main thread is unavoidable. For example if you've passed a Surface reference to a non-main thread and that surface is being destroyed. You're contractually obliged to block the main thread until the non-main thread no longer holds a reference to the Surface in that case. This is the one other case where we block the main thread until a message on the playback thread has been processed.

Tolriq commented 6 years ago

@ojw28 So the question is how to avoid the MediaCodec infinite wait so :)

Is there a way to detect that? Is there a way to kill the ExoPlayer thread without the process? (If that reset the MediaCodec of course) Is there a way to detect blocked mediacodecs on new ExoPlayer creation to warn the user and propose a restart of the process?

I don't mind showing a wait dialog or anything useful to the users but randoms ANR or app killing for P without a message or anything to warn the user for something that is known and I hope can be detected does not sounds OK to provide quality app.

I'm open to any suggestion or workaround. Just don't want ANR / app killing without proper user message.

PS: Not wanting to argue more but

This is hypothetical and not true in practice. The message queue is completely under our control, and will normally only have one or two messages queued at any given point in time.

Just 2 messages and a wait is some ms and dropped frames, of course it's not that awful and very far from the ANRs, but it's still dropped frames so lag to the user. And just saying normally implies that there could be anormal cases. Just adding this as note for others that will read, yes it may be unavoidable, but yes it will implies some impact that users should know, as small as they normally are. With audio players, users are probably doing something else in the app and will feel the lag when scrolling, it's a little different from a video player where there can be some delay when they press stop.

ojw28 commented 6 years ago

Unfortunately the only real fix for the MediaCodec issue is to better prevent devices from shipping with the underlying issues that cause it in the first place. Which we've been working on, but it's a hard problem. The percentages are so low and the failures so sporadic, that it's not possible to write a test that will reliably detect such issues during Android device certification.

I'm not aware of a way to kill the ExoPlayer thread without killing the process. I don't think that's possible.

Just 2 messages and a wait is some ms and dropped frames

Whether there are dropped frames depends entirely on how long those messages take to process, so this in itself does not seem like a strong argument. I'm not saying there are never dropped frames, but I am saying (a) it's not inevitable that the piece of code in question will cause dropped frames, and (b) the benefit of blocking until we've released the limited resources is more important.

The ANR issue affects our own applications (e.g. YouTube) as well. If we thought there were a better solution then we would have implemented it.

Tolriq commented 6 years ago

Well there was no offense I'm not native English speaker so often sound harsh. I totally suppose that you'll have fixed it if it was possible. All I'm saying is that ANR / crash are bad, a message saying there's a problem press ok to restart the app is better. I can understand it does not fit Youtube, but for my user target it's a better option.

About sporadic, I only have 7500 beta testers and the audio player is used by 5% max, beta have run for 3 days and already happened twice on an S6 edge and Moto X.

So for my use case the remaining solution would be to propose to the user to restart the app when there's the lock.

The best solution (for my need) would be that my app only propose that when the next player start and can't access the MediaCodec since it's still locked by previous unreleased one. (That I'll release in background thread). Is there a way to detect that on next exoplayer creation? Or maybe a specific error when the track will try to play? (Don't know when they are initialized)

For more background, my app is not primarily a player, it's more a global controller, that connect and control things. At some point user might be playing audio from multiple source to local device and that's the part where ExoPlayer kicks in. User can then stop playing locally and start playing on Chromecast or anything else. Having the app hang and ANR because of ExoPlayer that is no more used and will probably won't until next app start, and have the user loose it's music and queue running on the other player is not something cool if it can be avoided.

saipsa commented 5 years ago

Facing the same issue exoplayer version 2.9.1 This is the top cause of ANRs in my app

Affected android versions 8.0,8.1,9.0 Affected devices from crash clusters of play console.

One (A0001) 5 29.4%
Nokia 6.1 Plus (DRG_sprout) 3 17.6%
OnePlus3T (OnePlus3T) 2 11.8%
V30 (joan) 2 11.8%
Others 5 29.4%
DROID Turbo 2 (kinzie) 4 13.8%
Moto E4 (perry_f) 3 10.3%
Galaxy S3 (m0) 3 10.3%
Moto G(4) Plus (athene_f) 3 10.3%
Others 16 55.2%
MIX 2S (polaris) 8 20.5%
Nokia 7 plus (B2N_sprout) 6 15.4%
OnePlus5T (OnePlus5T) 3 7.7%
Moto Z (2) Play (albus) 3 7.7%
Others 19 48.7%

stack trace

"main" prio=5 tid=1 Waiting
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x73446330 self=0x7d3a8c2a00
  | sysTid=30940 nice=-10 cgrp=default sched=0/0 handle=0x7dbf7b29a8
  | state=S schedstat=( 13621696685 2308186531 21699 ) utm=1102 stm=260 core=4 HZ=100
  | stack=0x7ff9c6a000-0x7ff9c6c000 stackSize=8MB
  | held mutexes=

  at java.lang.Object.wait (Object.java)
- waiting on <0x0cf8f9d3> (a com.google.android.exoplayer2.ExoPlayerImplInternal)

  at com.google.android.exoplayer2.ExoPlayerImplInternal.release (ExoPlayerImplInternal.java:229)
- locked <0x0cf8f9d3> (a com.google.android.exoplayer2.ExoPlayerImplInternal)

  at com.google.android.exoplayer2.ExoPlayerImpl.release (ExoPlayerImpl.java:393)

  at com.google.android.exoplayer2.SimpleExoPlayer.release (SimpleExoPlayer.java:979)
perracodex commented 5 years ago

I can reproduce it quite regularly with the attached sample after a few "play + exit the player" action on a Nexus 6 - API 7.1.1. The sample recording shows no problems in other devices and Android versions.

About the attached sample, it isn't a regular video. Don't expect any image or audio. The video content is dark and is just for testing purposes. It has been recorded using the Android MediaRecorder with a time-lapse Camcorder profile, setting the recording rate at 30fps and a capture rate at 90fps.

sample.zip

czrml commented 5 years ago

We are facing this same issue on version 2.9.4 of ExoPlayer, unlikely described above, we didn't have any errors on Android versions 7.0 and above, but this is likely because of our user base. We noticed that this happens on certain streams, notably a h264 (High), yuv420p(progressive), 960x1080 [SAR 2:1 DAR 16:9], 30 fps, 30 tbr, 90k tbn, 60 tbc (as indicated by ffprobe -I).

Is there any news about this issue? a workraround or something like it?

thx

perracodex commented 5 years ago

It definitely seems to be something wrong with the MediaCodec, probably a bad state.

As I'm able to reproduce the issue easily, when pausing all threads it shows that is stuck when doing the MeciaCodec native stop, as shown next:

image

perracodex commented 5 years ago

In addition when the error happens this is the logcat thrown by the MediaCodec:

2019-03-10 20:28:18.996 6920-6920/com.perracolabs.test I/ExoPlayerImpl: Release 62cdace [ExoPlayerLib/2.9.6] [shamu, Nexus 6, motorola, 25] [goog.exo.core, goog.exo.ui]
2019-03-10 20:28:18.997 407-7144/? E/OMX-VDEC-1080P: OMX_COMPONENT_GENERATE_HARDWARE_ERROR
2019-03-10 20:28:18.997 407-7144/? E/OMX-VDEC-1080P: ERROR: Sending OMX_ErrorHardware to Client
2019-03-10 20:28:18.997 6920-7130/com.perracolabs.test E/ACodec: [OMX.qcom.video.decoder.avc] ERROR(0x80001009)
2019-03-10 20:28:18.997 6920-7130/com.perracolabs.test E/ACodec: signalError(omxError 0x80001009, internalError -2147483648)
2019-03-10 20:28:18.997 6920-7129/com.perracolabs.test E/MediaCodec: Codec reported err 0x80001009, actionCode 0, while in state 9
perracodex commented 5 years ago

I had some success in getting around the ANR, although for the time being looks more like black-yu-yu-magic than a proper solution. And still, it has some side effects but which at least can be managed. It may give some ideas about how to implement a proper fix, or some type of state recovery.

So, by calling seekToDefaultPosition before the stop and release methods the ANR disappears, yet the logs show that there is failure from MediaCodec. It is likely that the MediaCodec stop flow fails altogether, but this is just a guess.

Then the player is not usable for a couple of seconds. If trying to use it again right away then ExoPlayer throws an exception, but since it is thrown via the onPlayerError callback then this one can be gracefully handled. After a couple of seconds, the player recovers, and everything work fine again.

So, to resolve the ANR, I do as next:

player.seekToDefaultPosition();
player.stop(true);
player.release();

Also noticed that if seekToDefaultPosition is called after the stop method then the ANR still happens so must be called before the stop & release.

And these are the 2 new logs, thrown only when the error happens, instead of having the ANR.

This first log is shown when releasing the player, since we started to also call seekToDefaultPosition:

2019-03-11 10:39:47.362 399-654/? D/audio_hw_primary: disable_audio_route: usecase(1) reset and update mixer path: low-latency-playback speaker
2019-03-11 10:39:47.367 399-654/? D/audio_hw_primary: disable_snd_device: snd_device(2: speaker)
2019-03-11 10:39:47.452 12053-13086/com.perracolabs.test I/ACodec: [OMX.qcom.video.decoder.avc] forcing the release of codec
2019-03-11 10:39:47.564 404-5814/? I/OMX-VDEC-1080P: omx_vdec::component_deinit() complete
2019-03-11 10:39:47.569 404-5814/? I/OMX-VDEC-1080P: Exit OMX vdec Destructor: fd=8
2019-03-11 10:39:47.571 12053-13086/com.perracolabs.test E/ACodec: OMX.qcom.video.decoder.avc
2019-03-11 10:39:47.579 12053-13079/com.perracolabs.test E/ExoPlayerImplInternal: Stop failed.
    java.lang.IllegalStateException
        at android.media.MediaCodec.native_stop(Native Method)
        at android.media.MediaCodec.stop(MediaCodec.java:2007)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.releaseCodec(MediaCodecRenderer.java:608)
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.releaseCodec(MediaCodecVideoRenderer.java:508)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onDisabled(MediaCodecRenderer.java:562)
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onDisabled(MediaCodecVideoRenderer.java:377)
        at com.google.android.exoplayer2.BaseRenderer.disable(BaseRenderer.java:153)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.disableRenderer(ExoPlayerImplInternal.java:976)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.resetInternal(ExoPlayerImplInternal.java:764)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.stopInternal(ExoPlayerImplInternal.java:735)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:355)
        at android.os.Handler.dispatchMessage(Handler.java:98)
        at android.os.Looper.loop(Looper.java:154)
        at android.os.HandlerThread.run(HandlerThread.java:61)

This second log, is the exception thrown by ExoPlayer via onPlayerError when trying to use the player again right away, but which no longer happens after a short moment:


2019-03-11 10:39:48.129 407-407/? I/MediaPlayerService: MediaPlayerService::getOMX
2019-03-11 10:39:48.130 12053-13123/com.perracolabs.test I/OMXClient: MuxOMX ctor
2019-03-11 10:39:48.131 404-4010/? I/OMXMaster: makeComponentInstance(OMX.qcom.video.decoder.avc) in mediacodec process
2019-03-11 10:39:48.133 404-4010/? I/OMX-VDEC-1080P: component_init: OMX.qcom.video.decoder.avc : fd=-1
2019-03-11 10:39:48.133 404-4010/? E/OMX-VDEC-1080P: Omx_vdec::Comp Init Returning failure, errno 12
2019-03-11 10:39:48.133 404-4010/? E/OMX-VDEC-1080P: Invalid input: -1
2019-03-11 10:39:48.133 404-4010/? I/OMX-VDEC-1080P: Exit OMX vdec Destructor: fd=-1
2019-03-11 10:39:48.133 404-4010/? E/OMX: FAILED to allocate omx component 'OMX.qcom.video.decoder.avc' err=InsufficientResources(0x80001000)
2019-03-11 10:39:48.133 12053-13123/com.perracolabs.test W/ACodec: Allocating component 'OMX.qcom.video.decoder.avc' failed, try next one.
2019-03-11 10:39:48.133 12053-13123/com.perracolabs.test E/ACodec: Unable to instantiate codec 'OMX.qcom.video.decoder.avc' with err 0xfffffff4.
2019-03-11 10:39:48.133 12053-13123/com.perracolabs.test E/ACodec: signalError(omxError 0xfffffff4, internalError -12)
2019-03-11 10:39:48.134 12053-13122/com.perracolabs.test E/MediaCodec: Codec reported err 0xfffffff4, actionCode 0, while in state 1
2019-03-11 10:39:48.135 10353-10421/? I/Finsky: [595] eku.b(46): com.perracolabs.test: Account from first account - [uqG_yVMXgTWLxCfS_AQbx0RPsDc]
2019-03-11 10:39:48.138 12053-13117/com.perracolabs.test W/MediaCodec-JNI: try to release MediaCodec from JMediaCodec::~JMediaCodec()...
2019-03-11 10:39:48.139 12053-13117/com.perracolabs.test W/MediaCodec-JNI: done releasing MediaCodec from JMediaCodec::~JMediaCodec().
2019-03-11 10:39:48.139 12053-13116/com.perracolabs.test D/BSQ#817.LE.processPurchaseState: Queried purchases.
2019-03-11 10:39:48.139 12053-13116/com.perracolabs.test I/BSQ#817.LE.processPurchaseState: No purchases.
2019-03-11 10:39:48.139 12053-13116/com.perracolabs.test I/BSQ#817.Profiler.mark: BSQ.Worker.query.updateState.mark: 0.016
2019-03-11 10:39:48.139 12053-13117/com.perracolabs.test W/MediaCodecRenderer: Failed to initialize decoder: OMX.qcom.video.decoder.avc
    android.media.MediaCodec$CodecException: Failed to initialize OMX.qcom.video.decoder.avc, error 0xfffffff4
        at android.media.MediaCodec.native_setup(Native Method)
        at android.media.MediaCodec.<init>(MediaCodec.java:1776)
        at android.media.MediaCodec.createByCodecName(MediaCodec.java:1757)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodec(MediaCodecRenderer.java:802)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodecWithFallback(MediaCodecRenderer.java:745)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:474)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111)
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300)
        at android.os.Handler.dispatchMessage(Handler.java:98)
        at android.os.Looper.loop(Looper.java:154)
        at android.os.HandlerThread.run(HandlerThread.java:61)
2019-03-11 10:39:48.141 12053-13117/com.perracolabs.test E/ExoPlayerImplInternal: Playback error.
    com.google.android.exoplayer2.ExoPlaybackException: com.google.android.exoplayer2.mediacodec.MediaCodecRenderer$DecoderInitializationException: Decoder init failed: OMX.qcom.video.decoder.avc, Format(1, null, null, video/avc, null, -1, null, [1280, 720, 90.0], [-1, -1])
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:479)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111)
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300)
        at android.os.Handler.dispatchMessage(Handler.java:98)
        at android.os.Looper.loop(Looper.java:154)
        at android.os.HandlerThread.run(HandlerThread.java:61)
     Caused by: com.google.android.exoplayer2.mediacodec.MediaCodecRenderer$DecoderInitializationException: Decoder init failed: OMX.qcom.video.decoder.avc, Format(1, null, null, video/avc, null, -1, null, [1280, 720, 90.0], [-1, -1])
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodecWithFallback(MediaCodecRenderer.java:753)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:474)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111) 
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300) 
        at android.os.Handler.dispatchMessage(Handler.java:98) 
        at android.os.Looper.loop(Looper.java:154) 
        at android.os.HandlerThread.run(HandlerThread.java:61) 
     Caused by: android.media.MediaCodec$CodecException: Failed to initialize OMX.qcom.video.decoder.avc, error 0xfffffff4
        at android.media.MediaCodec.native_setup(Native Method)
        at android.media.MediaCodec.<init>(MediaCodec.java:1776)
        at android.media.MediaCodec.createByCodecName(MediaCodec.java:1757)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodec(MediaCodecRenderer.java:802)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodecWithFallback(MediaCodecRenderer.java:745)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:474) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111) 
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300) 
        at android.os.Handler.dispatchMessage(Handler.java:98) 
        at android.os.Looper.loop(Looper.java:154) 
        at android.os.HandlerThread.run(HandlerThread.java:61) 
2019-03-11 10:39:48.147 12053-13116/com.perracolabs.test I/BSQ#817.Profiler.end: BSQ.Worker.query.end: 0.133
2019-03-11 10:39:48.162 864-884/? I/ActivityManager: Displayed com.perracolabs.test/app.application.activities.PlayerVideoActivity$Internal: +230ms
2019-03-11 10:39:48.178 12053-12053/com.perracolabs.test E/main#1.VideoPlayerModule.onPlayerError: Unexpected video player error.
    com.google.android.exoplayer2.ExoPlaybackException: com.google.android.exoplayer2.mediacodec.MediaCodecRenderer$DecoderInitializationException: Decoder init failed: OMX.qcom.video.decoder.avc, Format(1, null, null, video/avc, null, -1, null, [1280, 720, 90.0], [-1, -1])
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:479)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111)
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529)
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300)
        at android.os.Handler.dispatchMessage(Handler.java:98)
        at android.os.Looper.loop(Looper.java:154)
        at android.os.HandlerThread.run(HandlerThread.java:61)
     Caused by: com.google.android.exoplayer2.mediacodec.MediaCodecRenderer$DecoderInitializationException: Decoder init failed: OMX.qcom.video.decoder.avc, Format(1, null, null, video/avc, null, -1, null, [1280, 720, 90.0], [-1, -1])
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodecWithFallback(MediaCodecRenderer.java:753)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:474)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111) 
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300) 
        at android.os.Handler.dispatchMessage(Handler.java:98) 
        at android.os.Looper.loop(Looper.java:154) 
        at android.os.HandlerThread.run(HandlerThread.java:61) 
     Caused by: android.media.MediaCodec$CodecException: Failed to initialize OMX.qcom.video.decoder.avc, error 0xfffffff4
        at android.media.MediaCodec.native_setup(Native Method)
        at android.media.MediaCodec.<init>(MediaCodec.java:1776)
        at android.media.MediaCodec.createByCodecName(MediaCodec.java:1757)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodec(MediaCodecRenderer.java:802)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.initCodecWithFallback(MediaCodecRenderer.java:745)
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.maybeInitCodec(MediaCodecRenderer.java:474) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.reinitializeCodec(MediaCodecRenderer.java:1261) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.onInputFormatChanged(MediaCodecRenderer.java:1111) 
        at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onInputFormatChanged(MediaCodecVideoRenderer.java:552) 
        at com.google.android.exoplayer2.mediacodec.MediaCodecRenderer.render(MediaCodecRenderer.java:647) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.doSomeWork(ExoPlayerImplInternal.java:529) 
        at com.google.android.exoplayer2.ExoPlayerImplInternal.handleMessage(ExoPlayerImplInternal.java:300) 
        at android.os.Handler.dispatchMessage(Handler.java:98) 
        at android.os.Looper.loop(Looper.java:154) 
        at android.os.HandlerThread.run(HandlerThread.java:61)
``` 
andrewlewis commented 5 years ago

As you say, it's likely that the calls to stop/release the codec are still failing (throwing instead of just blocking). When you create a player shortly afterwards, E/OMX: FAILED to allocate omx component 'OMX.qcom.video.decoder.avc' err=InsufficientResources(0x80001000) suggests that the previously allocated codec may still be holding resources (i.e., it wasn't released properly), but that after a while the system reclaims those resources and it's possible to create a codec again.

Tolriq commented 5 years ago

@andrewlewis Yep :) That's why as proposed a few times it would be better to allow applications to recover gracefully and show errors to users than triggering ANRs that gives a pretty bad user experience.

richardyang92 commented 5 years ago

I have same issue on exoplayer release-v2 branch on a mstar 638 board. Is there anyway to workraround or fix it?

anr trace:

"main" prio=5 tid=1 WAIT
  | group="main" sCount=1 dsCount=0 obj=0x41f81ca8 self=0x41f70940
  | sysTid=4409 nice=0 sched=0/0 cgrp=apps handle=1073828180
  | state=S schedstat=( 0 0 0 ) utm=230 stm=73 core=1
  at java.lang.Object.wait(Native Method)
  - waiting on <0x43fa1b60> (a com.google.android.exoplayer2.ExoPlayerImplInternal)
  at java.lang.Object.wait(Object.java:364)
  at com.google.android.exoplayer2.ExoPlayerImplInternal.release((null):-1)
  at com.google.android.exoplayer2.ExoPlayerImpl.release((null):-1)
  at com.google.android.exoplayer2.SimpleExoPlayer.release((null):-1)
  at com.funshion.mediarender.player.c.b.f((null):-1)
  at com.funshion.mediarender.player.b.b.f((null):-1)
  at com.funshion.mediarender.player.a.a.f((null):-1)
  at com.funshion.mediarender.player.proxy.VideoPlayerProxy.a((null):-1)
  at com.funshion.mediarender.player.a.b.handleMessage((null):-1)
  at android.os.Handler.dispatchMessage(Handler.java:98)
  at android.os.Looper.loop(Looper.java:136)
  at android.app.ActivityThread.main(ActivityThread.java:5001)
  at java.lang.reflect.Method.invokeNative(Native Method)
  at java.lang.reflect.Method.invoke(Method.java:515)
  at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:788)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:604)
  at dalvik.system.NativeStart.main(Native Method)
bjitivo commented 5 years ago

We experience this too, and I have nothing to add except to say that ojw28's comment on Aug 28, 2018 is a GREAT explanation of why you do not paper over bugs with false workarounds like running actions in background threads -- you fix them, or you don't. There is no try :)

google-oss-bot commented 5 years ago

Hey @aarondib. We need more information to resolve this issue but there hasn't been an update in 14 days. I'm marking the issue as stale and if there are no new updates in the next 7 days I will close it automatically.

If you have more information that will help us get to the bottom of this, just add a comment!

ojw28 commented 5 years ago

Please ignore the comment from @google-oss-bot

teddyla commented 5 years ago

Hey guys. we also facing mediacodec release or stop ANR. logcat only this hints: E/ACodec (21715): signalError(omxError 0x80001009, internalError -2147483648) 69 E/MediaCodec(21715): Codec reported err 0x80001009, actionCode 0, while in state 9

@perracolabs did u mean call flush before stop & release could workaround?

iBotasky commented 5 years ago

Facing ANR in release(); In my case the player handler receive MSG_RELEASE too late to notify to release the lock. And i think is that MessageQueue is block. so I remove the message but not work. How to solve this issue? Here is my code:

    public synchronized void release() {
        if (released) {
            return;
        }
        handler.removeCallbacksAndMessages(null); // I try to remove all message before send MSG_RELEASE
        handler.sendEmptyMessage(MSG_RELEASE);
        boolean wasInterrupted = false;
        while (!released) {
            Log.e("EditorActivity", " PlayRelease on while");
            try {
                wait();
            } catch (InterruptedException e) {
                wasInterrupted = true;
            }
        }
        if (wasInterrupted) {
            // Restore the interrupted status.
            Thread.currentThread().interrupt();
        }
    }
Tolriq commented 5 years ago

Either leave the ANR as Google want expecting this to be a proper user experience .... Specially on P+ where ANR just close the app. (Hint: This is not proper user experience at all)

Or workaround yourself on the app side, release on the background, properly manage initialisation errors with users messages and if after a time you evaluate long enough init still does not work, propose to the user to restart the app to fix the issue and restart the process.

liungkejin commented 5 years ago

Device: Samsung SM-N9109W Android 6.0.1, API 23

Bug reproduces steps: Create a singleton exoplayer

  1. Prepare exoplayer in Activity_1
  2. Play exoplayer in Activity_2
  3. Release exoplayer in Activity_2 // Normally speaking, release is success at first time
  4. Prepare exoplayer in Activity_1
  5. Play exoplayer in Activity_2
  6. Release exoplayer in Activity_2 // release will be blocked 100%

But if i put the prepare, play, release player action in single activity, everything is fine! Maybe this problem is the bug of system MediaCodec

  protected boolean flushOrReleaseCodec() {
    if (codec == null) {
      return false;
    }
    if (codecDrainAction == DRAIN_ACTION_REINITIALIZE
        || codecNeedsFlushWorkaround
        || (codecNeedsEosFlushWorkaround && codecReceivedEos)) {
      releaseCodec();
      return true;
    }

    codec.flush(); // here is blocked
    .... 
  }

the stracktrace is

releaseInternal() : ExoPlayerImplInternal.java
->  resetInternal(
      boolean resetRenderers,
      boolean releaseMediaSource,
      boolean resetPosition,
      boolean resetState)
-> disableRenderer(Renderer renderer)
-> renderer.disable();
-> onDisabled() :  MediaCodecRenderer.java
-> flushOrReleaseCodec() : MediaCodecRenderer.java
-> codec.flush()
tonihei commented 5 years ago

@liungkejin Can you provide an example app for this? If it's 100% reproducible it should be possible to figure out what's wrong.

bjitivo commented 5 years ago

This is caused by the fact that ExoPlayer calls into MediaCodec.setVideoScalingMode() directly from its OnFrameRenderedListener() callback. The Android stagefright library has a bug where it holds a lock while calling back onFrameRenderedListener callbacks. I believe it is a bug for any component to hold a lock while calling an arbitrarily registered listener because you cannot know whether that listener will then need to acquire the same lock, which would then lead to a deadlock - which is what is happening here.

The setVideoScalingMode() call itself goes into native stagefright code which then waits for some other event from MediaCodec ... but that event cannot be delivered by the MediaCodec thread that would deliver it because to do so would require acquiring the same MediaCodec lock that is already being held by the thread calling setVideoScalingMode.

A workaround is to have ExoPlayer's MediaCodecVideoRenderer.OnFrameRenderedListenerV23 instance defer the call to 'onProcessedTunneledBuffer' to a runnable posted to the handler, which will allow the onFrameRenderedListenerCallback to release its lock and return before the call to setVideoScalingMode that onProcessedTunneledBuffer will be made.

We are currently accomplishing this by deferring a Runnable to call onProcessedTunneledBuffer() from within OnFrameRenderedListenerV23.onFrameRendered() ... but we recognize that this would be accomplished in a manner more coherent with the MediaCodecVideoRenderer implementation by posting an event to be handled by the player thread instead, and we are working on a pull request that will accomplish this.

By the way, the actual bug is in libstagefright. It should NOT hold locks while calling back listeners; that's elementary in any multithreaded code that uses callbacks. I would submit this to the stagefright project but I couldn't figure out how to do that; perhaps the ExoPlayer library maintainers know how to do this ...

stevemayhew commented 5 years ago

@tonihei I can do one better... Here's the threads that are deadlocked (in our case, tunneling causes the issue, but in the general case it is calling back into MediaCodec from any listener. Even though MediaCodec listeners are called with Hanlder that is on same thread that created MediaCodec, MediaCodec is not reentrent from its handlers.)

I'll send a bug report, too big to post... Here's the threads involved:


"ExoPlayerImplInternal:Handler" prio=5 tid=13 Native
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x13b1c580 self=0x7e27d800
  | sysTid=5864 nice=-16 cgrp=default sched=0/0 handle=0x8e281970
  | state=S schedstat=( 0 0 0 ) utm=633 stm=174 core=3 HZ=100
  | stack=0x8e17e000-0x8e180000 stackSize=1042KB
  | held mutexes=
  kernel: (couldn't read /proc/self/task/5864/stack)
  native: #00 pc 00019d74  /system/lib/libc.so (syscall+28)
  native: #01 pc 0001d11d  /system/lib/libc.so (__futex_wait_ex(void volatile*, bool, int, bool, timespec const*)+88)
  native: #02 pc 00063a99  /system/lib/libc.so (pthread_cond_wait+32)
  native: #03 pc 0000e291  /system/lib/libstagefright_foundation.so (android::ALooper::awaitResponse(android::sp<android::AReplyToken> const&, android::sp<android::AMessage>*)+156)
  native: #04 pc 0000fd8f  /system/lib/libstagefright_foundation.so (android::AMessage::postAndAwaitResponse(android::sp<android::AMessage>*)+202)
  native: #05 pc 0008bcdd  /system/lib/libstagefright.so (android::MediaCodec::setParameters(android::sp<android::AMessage> const&)+100)
  native: #06 pc 0001faef  /system/lib/libmedia_jni.so (android::JMediaCodec::setVideoScalingMode(int)+70)
  native: #07 pc 00021dc3  /system/lib/libmedia_jni.so (android_media_MediaCodec_setVideoScalingMode(_JNIEnv*, _jobject*, int)+78)
  at android.media.MediaCodec.setVideoScalingMode(Native method)
  at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.processOutputFormat(MediaCodecVideoRenderer.java:810)
  at com.google.android.exoplayer2.video.MediaCodecVideoRenderer.onProcessedTunneledBuffer(MediaCodecVideoRenderer.java:834)
  at com.google.android.exoplayer2.video.MediaCodecVideoRenderer$OnFrameRenderedListenerV23.onFrameRendered(MediaCodecVideoRenderer.java:1613)
  at android.media.MediaCodec$EventHandler.handleMessage(MediaCodec.java:1664)
  - locked <0x0bfaa167> (a java.lang.Object)
  at android.os.Handler.dispatchMessage(Handler.java:106)
  at android.os.Looper.loop(Looper.java:193)
  at android.os.HandlerThread.run(HandlerThread.java:65)

As per the docs, MediaCodec is calling back and the creator's Looper thread (that would be ExoPlayer player thread) through it's MediaCodec$EventHandler. Notice it locks it's mListenerLock (object 0x0bfaa167)

So the wait down in native here is: a. Blocking the player thread's handler. b. Holding a lock

At the same time, the native side of handling the video format change is trying to post a message that will complete the java side, but it is waiting on the same lock (0x0bfaa167):

"MediaCodec_looper" prio=10 tid=45 Blocked
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x14182c08 self=0x7cac9c00
  | sysTid=5885 nice=-10 cgrp=default sched=0/0 handle=0x7927f970
  | state=S schedstat=( 0 0 0 ) utm=161 stm=32 core=1 HZ=100
  | stack=0x79184000-0x79186000 stackSize=1010KB
  | held mutexes=
  at android.media.MediaCodec.postEventFromNative(MediaCodec.java:3514)
  - waiting to lock <0x0bfaa167> (a java.lang.Object) held by thread 13

Meanwhile our lowly application main thread is waiting forever to for the MSG_RELEASE to process, presumably it's in the queue behind the deadlocked frame rendered callback.


"main" prio=5 tid=1 Waiting
  | group="main" sCount=1 dsCount=0 flags=1 obj=0x74a641f0 self=0xabdd1000
  | sysTid=5235 nice=-10 cgrp=default sched=0/0 handle=0xaff85494
  | state=S schedstat=( 0 0 0 ) utm=353 stm=151 core=2 HZ=100
  | stack=0xbe15f000-0xbe161000 stackSize=8MB
  | held mutexes=
  at java.lang.Object.wait(Native method)
  - waiting on <0x0e377c02> (a com.google.android.exoplayer2.ExoPlayerImplInternal)
  at com.google.android.exoplayer2.ExoPlayerImplInternal.release(ExoPlayerImplInternal.java:252)
  - locked <0x0e377c02> (a com.google.android.exoplayer2.ExoPlayerImplInternal)
  at com.google.android.exoplayer2.ExoPlayerImpl.release(ExoPlayerImpl.java:402)
  at com.google.android.exoplayer2.SimpleExoPlayer.release(SimpleExoPlayer.java:1015)
  at com.tivo.platform.video.android.ExoPlayerPlayer.stop(ExoPlayerPlayer.java:370)
  at com.tivo.platform.video.android.ExoPlayerPlayer.access$500(ExoPlayerPlayer.java:84)
  at com.tivo.platform.video.android.ExoPlayerPlayer$7.run(ExoPlayerPlayer.java:1379)
  at com.tivo.platform.video.android.ExoPlayerPlayer$31.run(ExoPlayerPlayer.java:2123)
  at android.os.Handler.handleCallback(Handler.java:873)
  at android.os.Handler.dispatchMessage(Handler.java:99)
  at android.os.Looper.loop(Looper.java:193)
  at android.app.ActivityThread.main(ActivityThread.java:6718)
  at java.lang.reflect.Method.invoke(Native method)
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:493)
  at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:858)
tonihei commented 5 years ago

That's a great find! I'll try to get this fixed in the platform code if possible [Done - Will be fixed in future Android releases]

To clarify for other readers - this bug only affects tunneled playbacks, so the majority of reported ANRs on player release won't be fixed by this.

stevemayhew commented 4 years ago

Thanks for the heads up, I deleted our branch. You’ll have to check with the Google folks when the will merge dev-v2. You might want to

On Mar 26, 2020, at 2:56 PM, Sergei Dryganets notifications@github.com wrote:

Wonder what is the plan for this particular case: 1ec0519 https://github.com/google/ExoPlayer/commit/1ec05199d4f15424588795ecfc29ef6593582ed3 It seems to be was merged to the dev-2 a while ago. How long it usually takes for the changes to get to the release-v2?

— You are receiving this because you commented. Reply to this email directly, view it on GitHub https://github.com/google/ExoPlayer/issues/4352#issuecomment-604706988, or unsubscribe https://github.com/notifications/unsubscribe-auth/AADBF6ECAWIQNUSRJQHR6QTRJPFPDANCNFSM4FD6CAQA.

jboylee commented 4 years ago

I also suffered from this issue. (No response at MediaCodec.flush)

After some tests, it wasn't clear, but the issue appeared after the setSurface call. (When additionally reproduced, the following message was always output. "E/OMX-VDEC-1080P: Error - could not remove ref, no match with any entry in list")

I was using SurfaceView to hand over the Surface, but as a test I used TextureView and the issue disappeared.

I leave a post in case there is anything that might help.

raymondctc commented 4 years ago

background thread

@Tolriq May I know if releasing player in backgrond thread solves this locking problem?

Btw, I found that for Instagram's they have quite an interesting implementation. It looks like they spin up another process for ExoPlayer and make use of IPC to do playing stuff.

Tolriq commented 4 years ago

Yes it does works perfectly for my use case as when I release the player I know I won't use it instantly later and since there's still no way to properly detect / handle this case. And failure to initialize player is something that can be handled and show to user for better experience.

I also use in R8

-assumenosideeffects class com.google.android.exoplayer2.SimpleExoPlayer {
    private void verifyApplicationThread();
}

To have this check removed from production release for a very insignificant performance gain :p

I still do not understand why there's no better workaround so that this that could be handled by devs and not hidden behind potential ANRs. ANRs outside of dev control are bad.

tonihei commented 4 years ago

We now enabled a change that times out the release call so that it's less likely that the app runs into ANRs. Instead the player will report an error through onPlayerError.

The underlying platform issue for this ANR is solved from Android 11, and this workaround is probably all we can do for the existing Android versions.