Closed d4rken closed 8 years ago
TWiStErRob
commented
8 years ago Which fragment life cycle method has the Glide line?
It looks like Glide is automatically trying to start the drawable on return because it's still in active resources or it was already loaded by the time it hit on start by hitting memory cache. Either of these should consistently repro.
Are you sure there's no lower/upper bound on versions? Which version of support lib is it?
d4rken
commented
8 years ago API 16 (4.1.1) to API 23 (6.0.1)
The supportlib version is 23.1.1.
It's also not a ROM specific issue as this happens on a variety of devices.
The call chain is a bit complicated, but it originates from Fragment.onActivityCreated.
Repeating the same thing that caused it the last time does currently not trigger it again for me.
I've update the first post as i noticed, I'm also calling Glide.with(getContext()).clear(mWorkingAnimation);
The usecase is that when returning to the previous Activity the UI connects to a service, obtains the current working state and depending on that either makes the ImageView VISIBLE and loads the gif into it, or sets the imageview to GONE and uses the clear method.
TWiStErRob
commented
8 years ago Visibility is set as Glide would expect and also worth noting that clear is a sync operation and you ordered it nicely for Glide.
Another theory: you're using the activity in with so Glide doesn't know about the Fragment's lifecycle. The activity survives another activity coming on top, it is just stopped. When you go back the activity is the same and it is restarted and started. But at the same time the Fragment's view is likely recreated, so the original ImageView is detached, but Glide still believes it has an active resource because it's request manager, which is paired with the activity is still not destroyed.
That code looks like it's in a view so I see how it's inconvenient to pass the fragment there, but at the same time you might pass a RequestManager so it's more general, that way that custom view can be paired with anything.
Another less nice possible workaround is to call setState(GONE) in onViewDestroyed to manually clear the fragment to make Glide forget about it.
This is just a theory and I acknowledge you can't test it. I would say apply one of these options and publish a new version if your local testing doesn't show any backlash from it. A mass user base would give you validation in that the frequency of this exception decreases or even stops with the new version.
TWiStErRob
commented
8 years ago It would still be beneficial to try to reproduce consistently. And I would like to warn you that all the above is without looking at the Glide code, so take it with a grain of salt. There might be much simpler explanation lurking there and even if my theory is right it possibly shouldn't throw an NPE.
d4rken
commented
8 years ago As I can't reproduce it I don't have many options :astonished: . I looked through the related Glide code but didn't see any obvious issue.
I'll try Glide.with(Fragment) and see what the crashtracker says after the next update.
Out of 22k users, 350 experienced the crash.
I'm also seeing a few Canvas: trying to use a recycled bitmap and Cannot draw recycled bitmaps which I think might be related to this, but the stacktrace is unfortunately inconclusive.
TWiStErRob
commented
8 years ago Yikes, I hate those "recycled bitmap" issues. Can you track down any custom targets, custom transformations and custom views and see if any of them steal/hold the Bitmap passed to them or prematurely recycle (transformation shouldn't call recycle for example)? The problem with those is that just one component can poison the whole app and may not even pop up at the location that's causing it (comparable to OOMs in nastiness, but harder to fix), you should find examples for those in this tracker as well.
d4rken
commented
8 years ago All other glide operations I do happen when binding RecyclerView ViewHolders, no custom targets, but a custom listener that starts/stops the drawable that was loaded if it is an instance of Animatable.
The image sources can vary a lot, from image files to apk files and icons for packagenames. As I've not found any relation to the gif loading, I'll make an extra issue ticket for the "recycled bitmap" issues when i tackle those.
yshubin
commented
8 years ago Glide.with(getContext()) -> Glide.with(getApplicationContext()) helped me with this
java.lang.NullPointerException: Attempt to read from field 'int com.bumptech.glide.gifdecoder.GifHeader.frameCount' on a null object reference
crash.
What the cons for this workaround?
P.S. Tried to caught some memory leaks, but all ok with it.
TWiStErRob
commented
8 years ago yshubin
commented
8 years ago Thanks @TWiStErRob!
d4rken
commented
8 years ago Changing to Glide.with(Fragment) for the gif loading has made no noticeable difference.
I'm still seeing the same crash. An NPE because the header variable is null:
https://github.com/bumptech/glide/blob/master/third_party/gif_decoder/src/main/java/com/bumptech/glide/gifdecoder/GifDecoder.java#L261
So either the data is cleared prematurely, not yet set, or not set at all... I still have no idea how to debug this :frowning: . It seems to be some kind of race condition and only becoming visible due to a large sample size.
java.lang.RuntimeException: Unable to resume activity {eu.thedarken.sdm/eu.thedarken.sdm.SDMMainActivity}: java.lang.NullPointerException: Attempt to read from field 'int com.bumptech.glide.b.c.c' on a null object reference
at android.app.ActivityThread.performResumeActivity(ActivityThread.java:2974)
at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:3005)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1328)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:135)
at android.app.ActivityThread.main(ActivityThread.java:5297)
at java.lang.reflect.Method.invoke(Method.java:-2)
at java.lang.reflect.Method.invoke(Method.java:372)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:908)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:703)
Caused by: java.lang.NullPointerException: Attempt to read from field 'int com.bumptech.glide.b.c.c' on a null object reference
at com.bumptech.glide.load.resource.d.g.a(GifFrameLoader.java:4262)
at com.bumptech.glide.load.resource.gif.GifDrawable.startRunning(GifDrawable.java:166)
at com.bumptech.glide.load.resource.gif.GifDrawable.start(GifDrawable.java:154)
at com.bumptech.glide.request.target.ImageViewTarget.onStart(ImageViewTarget.java:102)
at com.bumptech.glide.manager.TargetTracker.onStart(TargetTracker.java:31)
at com.bumptech.glide.RequestManager.onStart(RequestManager.java:244)
at com.bumptech.glide.manager.ActivityFragmentLifecycle.onStart(ActivityFragmentLifecycle.java:51)
at com.bumptech.glide.manager.SupportRequestManagerFragment.onStart(SupportRequestManagerFragment.java:175)
at android.support.v4.app.m.a(FragmentManager.java:8000)
at android.support.v4.app.FragmentManagerImpl.moveToState(FragmentManager.java:1252)
at android.support.v4.app.FragmentManagerImpl.moveToState$2563266(FragmentManager.java:1234)
at android.support.v4.app.FragmentManagerImpl.dispatchStart(FragmentManager.java:2051)
at android.support.v4.app.m.a(FragmentManager.java:8006)
at android.support.v4.app.FragmentManagerImpl.moveToState(FragmentManager.java:1252)
at android.support.v4.app.FragmentManagerImpl.moveToState$2563266(FragmentManager.java:1234)
at android.support.v4.app.FragmentManagerImpl.dispatchStart(FragmentManager.java:2051)
at android.support.v4.app.h.onStart(FragmentActivity.java:21185)
at eu.thedarken.sdm.SDMServiceActivity.onStart(SDMServiceActivity.java:76)
at eu.thedarken.sdm.SDMMainActivity.onStart(SDMMainActivity.java:139)
at android.app.Instrumentation.callActivityOnStart(Instrumentation.java:1220)
at android.app.Activity.performStart(Activity.java:6036)
at android.app.Activity.performRestart(Activity.java:6093)
at android.app.Activity.performResume(Activity.java:6098)
at android.app.ActivityThread.performResumeActivity(ActivityThread.java:2963)
at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:3005)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1328)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:135)
at android.app.ActivityThread.main(ActivityThread.java:5297)
at java.lang.reflect.Method.invoke(Method.java:-2)
at java.lang.reflect.Method.invoke(Method.java:372)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:908)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:703)Repro idea: from stack onStart is called, it's not necessarily the first onStart for that Fragment instance. Maybe you need to trigger that drawable to be visible (from the name it's a long running operation) and then leave the app (multitasking, because user gets bored of animation) and then go back to the app while it's still not finished working. This would explain why with(activity) and with(fragment) behaves the same. [Similar case would be just navigating to somewhere else in the app via tabs or drawer, etc. and back to this drawable]
d4rken
commented
8 years ago That is a plausible use-case, but I'm still not able to reproduce it. During the various updates of the app I've also updated the support libs and it also had no impact on this error. The crash tracker shows no specific Android version, ROM or device to be at fault. Currently there are 21 events for 20 users from ~10k downloads. While being quite rare, it's my most common crash reason :smile: .
In case you are curious or want to help, the latest version is available here: http://sdmaid.darken.eu/download/production/
Each tool that is working executes the same code from the first post. The coffee drinking gif is the one being loaded. Is it possible that this is a race condition between one fragment calling clear on the animation and another fragment still using it or starting to use it?
I'll play a bit around with closing and opening the activity, possibly with Don't keep Activities?
TWiStErRob
commented
8 years ago I don't think you need "don't keep", because that destroys. My suspicion is re-starting after a stop.
d4rken
commented
8 years ago Acting on my previous guess I replaced Glide.with(fragment).clear(mWorkingAnimation);
with
Drawable drawable = mWorkingAnimation.getDrawable();
if (drawable instanceof Animatable) {
Animatable gif = (Animatable) drawable;
if (gif.isRunning()) gif.stop();
}in the last update and it had no effect on this issue.
TWiStErRob
commented
8 years ago That may only confirm that the clear had no effect in this issue, as it was not executed, and/or the target is cleared anyway.
In finding a repro here I think we may need some logs. You look like you are willing to experiment, so I think you could gather some evidence if you replaced the default GlideDrawableImageViewTarget with one that:
super.onStart in a try-catchThe same could be done for the SDMMainActivity as well.
This may or may not help, let me know what you think.
d4rken
commented
8 years ago I'm not sure I understand, doesn't that only give us the same callchain we get from the stacktrace? What extra information can we gain that way.?
TWiStErRob
commented
8 years ago We only know that onStart is called, but we don't know what was called before that.
Also not clear whether the Target/View/Drawable is being reused or not.
I think the below code will reveal these and get us closer to see user behavior.
This for is lack of a better idea.
.into(new GlideDrawableImageViewTarget(mWorkingAnimation) {
private final List<String> calls = new ArrayList<>();
{
recordCall("construction");
}
@Override public void onLoadCleared(Drawable placeholder) {
recordCall("onLoadCleared", placeholder);
super.onLoadCleared(placeholder);
}
@Override public void onResourceReady(GlideDrawable resource, GlideAnimation<? super GlideDrawable> animation) {
recordCall("onResourceReady", resource, animation);
super.onResourceReady(resource, animation);
}
// TODO override ALL methods, omitted for brevity
@Override public void onStart() {
recordCall("onStart");
try {
super.onStart();
} catch (RuntimeException ex) {
String message = calls.toString();
calls.clear();
throw new RuntimeException(message, ex);
}
}
private void recordCall(String method, Object... args) {
StringBuilder sb = new StringBuilder()
.append(System.currentTimeMillies()).append(':');
.append("Target@").append(this.hashCode())
.append('[').append(view).append(']')
.append('.').append(method);
sb.append('(');
boolean first = true;
for (Object arg : args) {
if (first) {
first = false;
} else {
sb.append(',').append(' ');
}
sb.append(arg);
}
sb.append(')');
calls.add(sb.toString());
}
})You may need to apply the transformation from XML's scaleType as RequestBuilder.into(ImageView) is not called for custom targets:
.apply(new RequestOptions()
.format(DecodeFormat.PREFER_RGB_565)
.placeholder(R.drawable.sdmanimation)
.optionalFitCenter(mWorkingAnimation.getContext())
)A much easier way would be if you can grab the application logs when the error is captured, but I think that requires a new permission. I tried to play around with the app (installed from play store!), rotating, exiting, resuming, but nothing triggered an error. Is it visible to the user or you fail gracefully?
d4rken
commented
8 years ago You may need to apply the transformation from XML's scaleType as RequestBuilder.into(ImageView) is not called for custom targets:
What transformation?
Thanks for the snippets. It should NOT fail gracefully, but no user has contacted me regarding this either, I've only got the BugSnag pointing out this issue. The playstore version could still be v3 (staged rollout), Glide is only integrated with SD Maid v4 (see link I posted)... you tried to reproduce it with the wrong version :sob: .
I'm using Timber to attach the last 100 lines of my own logging to the bug reports. Though this is just everything that runs through Timber.(...).
Can I make Glide pump it's own logging through a function of mine?
Otherwise, during a beta test I could possibly deploy a version that tries to get the logcat. SD Maid has root on some devices that experience this issue.
TWiStErRob
commented
8 years ago What transformation?
Glide reads <ImageView android:scaleType="..."> in into(ImageView) and applies the corresponding transformation. Check that method's source. Even if you don't have it XML the default is fitCenter.
you tried to reproduce it with the wrong version
I see that now, updated to latest prod, but still nothing.
Can I make Glide pump it's own logging
I don't think so. Glide v3 didn't do it, it's using the built-in Log.*, I'm not aware of any news re this in v4 either.
deploy a version that tries to get the logcat
This would only help gathering the logs. Glide's logging is not fully helpful, only new loads are logged, not all lifecycle events. A listener is mostly enough, but in this case we would need the whole lifecycle to see where the user navigated. I don't think you can even enable Glide logging without adb access, because it's guarded by isLoggable.
I'm using Timber to attach the last 100 lines
I guess this means that the above list.add(sb.toString) should be logging through Timber instead, so it's automatically collected. No need to wrap the exception either in this case.
d4rken
commented
8 years ago Current code: https://gist.github.com/d4rken/275270533dec8801bf245d96dbcfd657
Log output:
// Cold start
04-10 17:02:49.581 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300569581:Target@220129647[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ......ID 0,0-0,0 #7f0d01c4 app:id/iv_working_animation}].construction()
04-10 17:02:49.681 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300569681:Target@220129647[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}].onStart()
04-10 17:02:49.938 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300569938:Target@220129647[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}].onResourceReady(com.bumptech.glide.load.resource.gif.GifDrawable@f38e75b, com.bumptech.glide.request.transition.NoTransition@d1a6bf8)
// Home screen, reopen.
04-10 17:03:09.966 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300589965:Target@220129647[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}].onStart()
// Warm start following the reopen
04-10 17:03:19.063 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300599063:Target@39614069[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}].construction()
04-10 17:03:19.065 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300599065:Target@220129647[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}].onLoadCleared(android.graphics.drawable.BitmapDrawable@f4460a)
04-10 17:03:19.081 14885-14885/eu.thedarken.sdm D/SDM:GlideGif: 1460300599081:Target@39614069[android.support.v7.widget.AppCompatImageView{c23667c V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}].onResourceReady(com.bumptech.glide.load.resource.gif.GifDrawable@b150e7b, com.bumptech.glide.request.transition.NoTransition@d1a6bf8)I'm actually unsure why it is calling onStart when resuming the app, looking into that.
TWiStErRob
commented
8 years ago onStart is normal at activity restart, because it has been stopped for reason of not being visible:
See also official lifecycle or extended lifecycle.
I think you may have missed my TODO comment... it would be more revealing if we saw why, or rather when, stop is called on the target, or what else is called, because something is putting the drawable in a bad state, from where it cannot start properly; where's the exception thrown in this logging? Also related lifecycle methods (the ones on above picture, plus ones ending in ...View) from Fragment may also help.
You can use https://github.com/TWiStErRob/glide-support/blob/master/src/glide3/java/com/bumptech/glide/supportapp/utils/LoggingTarget.java, it already has all target methods, you just need to change one line to Timber. If we have all the events from the Target and Fragment, we can reproduce it locally by calling those methods in order, even if we don't know why those events happen IRL.
Unrelated tip: you have duplicated .apply() calls.
TWiStErRob
commented
8 years ago From the log we can also see that onDestroyView wasn't called, because the ImageView hash is the same inside the two different targets, but a new load was started and into() clears the old target before delivering to the new one.
Why did you wrap the Glide calls in JBMR2? To reduce the affected devices?
d4rken
commented
8 years ago onStart is normal at activity restart, because it has been stopped for reason of not being visible:
I'm aware of Androids lifecycle but I was confused why glide would get that callback, though on further thought it makes sense as the ImageView in which the glide-based image class is still sitting (even though it's gone) will still receive onStart() and it probably forwards that event to the glide-based image inside the ImageView.
Unrelated tip: you have duplicated .apply() calls.
Ty :)
but a new load was started and into() clears the old target before delivering to the new one.
Why was a new load started if what we want to load is the same, am I missunderstanding the caching mechanism here?
Why did you wrap the Glide calls in JBMR2? To reduce the affected devices?
They had displaying artifacts I didn't want to deal with (yet). e.g. i9100@4.1.2. but before we hijack this issue here, let's do it clean :) https://github.com/bumptech/glide/issues/1123
Right, forgot about the TODO, thanks for the utility classes. Updated my gist:
New log output:
// Coldstart
04-10 18:25:05.982 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: getRequest()
04-10 18:25:05.985 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: setRequest(com.bumptech.glide.request.SingleRequest@8171349)
04-10 18:25:06.061 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: getSize(com.bumptech.glide.request.SingleRequest@8171349)
04-10 18:25:06.061 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onSizeReady(com.bumptech.glide.request.SingleRequest@8171349, 600, 600)
04-10 18:25:06.128 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onLoadStarted(android.graphics.drawable.BitmapDrawable@79ac55)
04-10 18:25:06.129 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onStart()
04-10 18:25:06.562 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onResourceReady(com.bumptech.glide.load.resource.gif.GifDrawable@bab8672, com.bumptech.glide.request.transition.NoTransition@92b2ac3)
// Homescreen & back
04-10 18:25:15.706 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onStop()
04-10 18:25:17.692 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onStart()
// Hotstart
04-10 18:25:19.886 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: getRequest()
04-10 18:25:19.886 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: getRequest()
04-10 18:25:19.886 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onLoadCleared(android.graphics.drawable.BitmapDrawable@79ac55)
04-10 18:25:19.886 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: setRequest(null)
04-10 18:25:19.887 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: setRequest(com.bumptech.glide.request.SingleRequest@8171349)
04-10 18:25:19.887 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: getSize(com.bumptech.glide.request.SingleRequest@8171349)
04-10 18:25:19.887 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onSizeReady(com.bumptech.glide.request.SingleRequest@8171349, 600, 600)
04-10 18:25:19.887 12993-12993/eu.thedarken.sdm D/SDM:GlideGif: onResourceReady(com.bumptech.glide.load.resource.gif.GifDrawable@82d498, com.bumptech.glide.request.transition.NoTransition@92b2ac3)I was confused why glide would get that callback
Oh I see, it's because you said Glide.with(fragment). Glide adds a child fragment which follows the lifecycle of the passed-in fragment. See SupportRequestManagerFragment.
Why was a new load started if what we want to load is the same
Because you started it... Glide doesn't care if the current load is the same as the one actively displayed in the target. You said .into() so it goes through the motions of clearing previous, and loading the new one, even if it's coming from the memory cache, in which case it's all synchronous and fast. At the point of clearing we likely don't know if it needs reloading or not.
You may want to consider:
public void setState(@NonNull Fragment fragment, @NonNull State state) {
+ if (state == mState) return;
mState = state;New log output
So you're able to repro this exception now consistently? Where's the exception thrown in the log?
thanks for the utility classes
Dang, it's missing the identity information, so it's not clear which target is cleared and ready'd, see updated class at the same location. Use it as:
.into(new LoggingTarget<GlideDrawable>(new GlideDrawableImageViewTarget(imageView)).addToString());Hopefully it's not missing anything else. Worth noting that these are for v3, not v4!.
d4rken
commented
8 years ago New log with your logging changes (no exception)
// Coldstart
04-10 19:52:45.267 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: setState(fragment=OverviewFragment{6395d8a #1 id=0x7f0d007a eu.thedarken.sdm.overview.OverviewFragment}, state=INTRO
04-10 19:52:46.904 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: setState(fragment=OverviewFragment{6395d8a #1 id=0x7f0d007a eu.thedarken.sdm.overview.OverviewFragment}, state=WORKING
04-10 19:52:46.939 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.getRequest()
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 0,0-0,0 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:46.940 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.setRequest(com.bumptech.glide.request.SingleRequest@d1ee96f)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 0,0-0,0 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:46.981 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.getSize(com.bumptech.glide.request.SingleRequest@d1ee96f)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:46.981 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.onSizeReady(com.bumptech.glide.request.SingleRequest@d1ee96f, 600, 600)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:47.045 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.onLoadStarted(android.graphics.drawable.BitmapDrawable@d17ab0c)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:47.045 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.onStart()
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:47.232 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.onResourceReady(com.bumptech.glide.load.resource.gif.GifDrawable@50e766a, com.bumptech.glide.request.transition.NoTransition@f38e75b)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:52:51.520 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: setState(fragment=OverviewFragment{6395d8a #1 id=0x7f0d007a eu.thedarken.sdm.overview.OverviewFragment}, state=GONE
// Hotstart
04-10 19:53:17.848 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: setState(fragment=OverviewFragment{6395d8a #1 id=0x7f0d007a eu.thedarken.sdm.overview.OverviewFragment}, state=WORKING
04-10 19:53:17.848 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.getRequest()
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.848 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.getRequest()
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.848 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@8171349.onLoadCleared(android.graphics.drawable.BitmapDrawable@d17ab0c)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ........ 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.849 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.setRequest(null)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.849 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.setRequest(com.bumptech.glide.request.SingleRequest@d1ee96f)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.849 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.getSize(com.bumptech.glide.request.SingleRequest@d1ee96f)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.849 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.onSizeReady(com.bumptech.glide.request.SingleRequest@d1ee96f, 600, 600)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:17.850 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: DrawableImageViewTarget@1a9a7fe.onResourceReady(com.bumptech.glide.load.resource.gif.GifDrawable@c3cc9ac, com.bumptech.glide.request.transition.NoTransition@f38e75b)
Target for: android.support.v7.widget.AppCompatImageView{d29a44e V.ED..C.. ......ID 240,384-840,984 #7f0d01c4 app:id/iv_working_animation}
04-10 19:53:18.931 7684-7684/eu.thedarken.sdm D/SDM:GlideGif: setState(fragment=OverviewFragment{6395d8a #1 id=0x7f0d007a eu.thedarken.sdm.overview.OverviewFragment}, state=GONEno exception
Then what are we investigating? :wink: I guess you're preparing to release this and wait until someone reproduces it and then we can can compare this log to theirs? If so, the above is verbose enough, except I think there should be Activity/Fragment methods logging as well.
d4rken
commented
8 years ago I guess you're preparing to release this and wait until someone reproduces it and then we can can compare this log to theirs?
That's the plan. I'll add some more logging for fragment lifecycle events.
BenHenning
commented
8 years ago I was also able to reproduce this problem, though in my case it occurred when trying to set a very large Gif-view visible. There's a similar stack trace to the one above, except setVisible() leads into the GifDecoder. The same failure happens (unable to read frameCount due to a NPE). I was able to reproduce this by trying to load many of these views at once, then repeatedly changing the orientation of the activity, recreating the views. I haven't tried reproducing this in isolation, but it is reproducible within the app I'm working on.
Since it does seem lifecycle-related, the repeated rotation seemed to help with reproduce the issue. I have yet to find a solution.
TWiStErRob
commented
8 years ago @BenHenning if you can create an isolated consistent repro from your app, and share it in email/drive/github we can take a look. This shouldn't happen at all, so the solution is to fix the bug :)
Can you please clarify "very large"? Also please confirm that you're using v4 as well.
BenHenning
commented
8 years ago Thanks for the reply @TWiStErRob.
Finding a solution to this is time-sensitive for me, so I might not have time in the near term to come up with a reproduction scenario. "Large Gifs" refers to Gifs around the 28-30MB mark. We are using v3 of Glide, not v4. If you would prefer I open a new issue for this targeted at v3, I will be happy to. Are there sufficient changes from v3 to v4 that this scenario may be resolved in v4?
TWiStErRob
commented
8 years ago Don't think so. I was asking to understand where this issue reproes, because the original report was for v4. You just confirmed that if there's a fix well need to back/forward port it. @yshubin gave a workaround above if you really need one, but it may not be working (we have no repro to confirm), try it.
BenHenning
commented
8 years ago FYI: We're actually using v4 of Glide; I mistook the version number.
TWiStErRob
commented
8 years ago Thanks! Then another possible fast workaround is to downgrade to v3 ;)
BenHenning
commented
8 years ago Unfortunately we cannot downgrade to v3.
I think I might have found the problem we're experiencing. We have a custom view which contains a view that displays either a loading indicator or an image thumbnail (which can be a Gif). Many instances of this custom view are being displayed in a fragment. Upon rotation, all of the views are torn down and recreated, as is typical Android lifecycle behavior.
However, we have an implementation of Glide's ImageViewTarget with setResource() overloaded. When setResource() is called, we automatically hide the view containing the animated loading indicator and show the view with the thumbnail, after setting the thumbnail's drawable to the one passed into setResource().
Now it gets a bit complicated. I think we almost certainly had a bug, because we would do the above visibility changes before setting the thumbnail view's drawable to the one provided by Glide. It's actually a bit strange to me that it even showed up. I figured this out yesterday, but I wasn't convinced it was the problem because it doesn't make sense that setting a view to be visible should cause the NPE, even if it contains an old Glide drawable that might have been invalidated after a lifecycle change. However, when investigating it further I noticed something strange. Our custom view was actually being detached from the window and then setResource() was being called. In fact, I noticed the following flow:
onAttachedToWindow()setResource()onDetachedFromWindow()setResource()I verified that all four of these were happening upon the same thumbnail view and within the same custom view parent class. Our custom view class overloads onDetachedFromWindow() and calls ResquestManager.clear() on our custom ImageViewTarget target. My question here: why is Glide calling ImageViewTarget.setResource() after it was cleared? I was thinking maybe Glide is trying to be clever as it discovers a lifecycle change, but I don't completely buy that. Why even call setResource() if the view is just going to be recreated, anyway?
After step (4) above, I experienced another NPE and crash. It was on the exact visibility changes which happened within the second setResource() call, which sort of reaffirms my theory. We had a bug, but Glide might also.
I look forward to hearing what @TWiStErRob or @sjudd think the cause of this behavior from Glide might be. Thanks!
TWiStErRob
commented
8 years ago I think the answer to your setResource lies within Log.d("GLIDE", "setResource", new Exception()). My expectation would be that it is called from onLoadCleared with null, as defined in ImageViewTarget, because you cleared the view, or because the RequestManagerFragment noticed a stop/destroy.
The visibility change may affect this issue, because when GifDrawable is set in an ImageView it has a registered callback, and it's a likely interaction between the two: the view needs some info from the Drawable or it tells the Drawable to bound itself or draw, etc...
In both cases in your custom target you should be forgetting the resource that came from onResourceReady from the moment onLoadCleared is called, after that any interaction with the resource triggers undefined behaviour.
BenHenning
commented
8 years ago Ah I see. Yes, the second setResource() call is coming from onLoadCleared(). Looking at ImageViewTarget, setResource() is only called with a non-null drawable in onResourceReady().
I think your thought is correct. Since we were changing visibility at the wrong time, there was a possible situation where it would try making a drawable visible even though a null resource was passed in, resulting in undefined behavior (or, rather, a well-defined NPE). Thank you for the clarification on the Glide setResource() lifecycle. It seems like this is definitely the issue. I can't repro the NPE after the earlier fix. If it comes up again, I will be sure to update this thread.
@d4rken, I'm not sure whether you're doing the same thing. It might be worth making sure you're only changing any views containing Glide drawables visibility only after ensuring the drawable of that view is exactly the latest drawable provided by Glide, even if it's null.
d4rken
commented
8 years ago Good news and bad news, the bug no longer seems to happen... the updates i pushed that contained more detailed logging also contained changes that moved most of the code that connects to my backend services (and changes UI visibility) from onActivityCreated/onViewDestroyed to onResume/ onPause. This isn't satisfying, but unless my changes are proven to be worse, it's unlikely I'll revert other fixes to further troubleshoot this issue in production...
@TWiStErRob There were no changes to 4.0.0-SNAPSHOT in that regard right?
I've written a test version based on the last of my versions that experiences this issue in the wild. It that repeats the same UI actions that I've seen in logs but even leaving that running for half an hour doesn't produce the crash...
I'll update this issue if I see it again.
@BenHenning I don't think my case is similar. I'm not doing anything with setResource or custom targets (in this instance). I'm loading a gif into an imageview and changing the ImageView's visibility. Why would I need to do any checks on the drawable inside the ImageView?
TWiStErRob
commented
8 years ago There were no changes to 4.0.0-SNAPSHOT in that regard right?
I'm not sure I understand. The last commit was a month ago, unrelated to this, if that's what you're asking.
What is sdmanimation, i.e. the placeholder?
d4rken
commented
8 years ago I'm not sure I understand. The last commit was a month ago, unrelated to this, if that's what you're asking.
Yeah thought maybe there was a change in glide that I pulled into the new build, just wanted to rule that out :).
What is sdmanimation, i.e. the placeholder?
Yes it's a still frame of the gif, in PNG form.
SwayChen
commented
8 years ago I want to know if you solve this problem? I meet it in your GiphySample.
d4rken
commented
8 years ago @SwayChen No, but since other UI changed moved my UI changing calls from onActivityCreated to onResume I no longer see bug reports for this issue.
SwayChen
commented
8 years ago @d4rken Just remove your codes changing UI from onActivityCreated to onResume ?
TWiStErRob
commented
8 years ago @SwayChen which Giphy? (v3,/v4, Releases/manual compile) and what steps?
SwayChen
commented
8 years ago @TWiStErRob I just clone your project and run, https://github.com/bumptech/glide/tree/master/samples/giphy. And I can't reappear, because it works well most time. It happens when back from fullscreenActivity to MainActivity.
SwayChen
commented
8 years ago It happen again! @TWiStErRob
See the following logs.
Process: com.bumptech.glide.samples.giphy, PID: 29120
java.lang.RuntimeException: Unable to resume activity {com.bumptech.glide.samples.giphy/com.bumptech.glide.samples.giphy.MainActivity}: java.lang.NullPointerException: Attempt to read from field 'int com.bumptech.glide.gifdecoder.GifHeader.frameCount' on a null object reference
at android.app.ActivityThread.performResumeActivity(ActivityThread.java:3103)
at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:3134)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1388)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:148)
at android.app.ActivityThread.main(ActivityThread.java:5417)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616)
Caused by: java.lang.NullPointerException: Attempt to read from field 'int com.bumptech.glide.gifdecoder.GifHeader.frameCount' on a null object reference
at com.bumptech.glide.gifdecoder.GifDecoder.getFrameCount(GifDecoder.java:262)
at com.bumptech.glide.load.resource.gif.GifFrameLoader.getFrameCount(GifFrameLoader.java:139)
at com.bumptech.glide.load.resource.gif.GifDrawable.startRunning(GifDrawable.java:166)
at com.bumptech.glide.load.resource.gif.GifDrawable.start(GifDrawable.java:154)
at com.bumptech.glide.request.target.ImageViewTarget.onStart(ImageViewTarget.java:102)
at com.bumptech.glide.manager.TargetTracker.onStart(TargetTracker.java:31)
at com.bumptech.glide.RequestManager.onStart(RequestManager.java:244)
at com.bumptech.glide.manager.ActivityFragmentLifecycle.onStart(ActivityFragmentLifecycle.java:51)
at com.bumptech.glide.manager.RequestManagerFragment.onStart(RequestManagerFragment.java:185)
at android.app.Fragment.performStart(Fragment.java:2244)
at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1002)
at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1148)
at android.app.FragmentManagerImpl.moveToState(FragmentManager.java:1130)
at android.app.FragmentManagerImpl.dispatchStart(FragmentManager.java:1958)
at android.app.FragmentController.dispatchStart(FragmentController.java:163)
at android.app.Activity.performStart(Activity.java:6274)
at android.app.Activity.performRestart(Activity.java:6314)
at android.app.Activity.performResume(Activity.java:6319)
at android.app.ActivityThread.performResumeActivity(ActivityThread.java:3092)
at android.app.ActivityThread.handleResumeActivity(ActivityThread.java:3134)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:1388)
at android.os.Handler.dispatchMessage(Handler.java:102)
at android.os.Looper.loop(Looper.java:148)
at android.app.ActivityThread.main(ActivityThread.java:5417)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:726)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:616) Yes, but what did you do? Since the last install: launching, home/back button presses and any taps within the app.
SwayChen
commented
8 years ago @TWiStErRob just slide on MainActivity, choose one and open fullscreenActivity, then back, sometimes it happens NullPointerException... sorry, I can't reappear.
sjudd
commented
8 years ago At least two cases of this should be resolved.
Extra assertions were added for visibility changes on recycled Drawables here: f1975a3d32d5eab0d68c3bc0a8aceb3b706d5663.
Starting recycled animating Drawables that are removed from the in memory cache prior to starting a Fragment was fixed here: f6ba9c212a1030bf1aaf19f9f64cdd22c52ed83e.
I'm going to call this fixed for now, if you still see this issue after this snapshot, please do re-open.
technotiger
commented
6 years ago I am getting almost same stacktrace as the OP. I am using glide v4.6.1. The NPE occurs when scrolling rapidly through RecyclerViews with data set consisting of several hundred GIFs, JPEGs and video thumbnails among other things. Can be reproduces every time. Occurs when scrolling very fast.
glide:4.0.0-SNAPSHOT It's neither device nor Android version specific. I can't reproduce it, but it doesn't seem rare when looking at crash numbers. In this case it happened when returning from Activity A to Activity B and Activity B contains the animation. It possible that the ImageViews visibility state is changed shortly after returning to Activity B.