Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Complex synchronization issue. #402

Closed
Tolriq opened this issue Apr 13, 2015 · 11 comments
Closed

Complex synchronization issue. #402

Tolriq opened this issue Apr 13, 2015 · 11 comments
Labels

Comments

@Tolriq
Copy link
Contributor

Tolriq commented Apr 13, 2015

Glide Version/Integration library (if any): 3.6.0-SNAPSHOT
Device/Android Version: Nexus 5 / 5.1.0
Issue details/Repro steps:

In an attempt to handle my dual cache problem while using all the power of Glide I encounter a synchronization problem inside Glide but quite out of my competence on this library to find and understand.

The principle is quite simple :
Register 2 modules : 1 for normal queries that will then call Glide synchronously with the other model loader in it's DataFetcher.onLoad

glide.register(ImageRequest.class, InputStream.class, new ImageRequestCacheLoader.Factory());
glide.register(NetworkImageRequest.class, InputStream.class, new NetworkImageRequestLoader.Factory());

Glide load line in the onLoad:

Glide.with(mContext)
                .load(new NetworkImageRequest(imageRequest))
                .asBitmap()
                .diskCacheStrategy(DiskCacheStrategy.NONE)
                .into(500, 500);

The NetworkImageRequest is a module that is a copy paste of the okhttp integration.

When using glide like this somtimes when scrolling fast or not, (I.E. randomly) there will be locks that will prevent all future image loading to happens and images to not be displayed.

Adding a forced timeout (.get(20, TimeUnit.SECONDS);) will make things recover after the timeout but for multiple images they will not be displayed and sometimes cache is corrupted.
And no image loading during xx seconds is not really wanted for smooth interface.

Remark : There's a timeout set on OKHTTP client that do not trigger so the lock is not on OKHTTP .

If instead of calling Glide I use my code to download the image with okhttp and resize it at the exact same place all works perfectly and there's never locks.

So all points to a non reentrant lock somewhere in Glide but I have no clue where to look at :(

@sjudd
Copy link
Collaborator

sjudd commented Apr 13, 2015

Do you exclusively load images using into(width, height) on background threads?

Can you try running Thread.getAllStackTraces() when you detect (or suspect) deadlock and provide those stack traces? It also looks like sending SIGQUIT will dump stack traces to /data/anr/traces.txt.

See: https://groups.google.com/forum/#!topic/android-developers/N18KV5DyJpE

@Tolriq
Copy link
Contributor Author

Tolriq commented Apr 13, 2015

The only into(w,h) is called from the onLoad of the DataFetcher

The ImageRequest modelloader is only :

@Override
public DataFetcher<InputStream> getResourceFetcher(ImageRequest model, int width, int height) {
    return new ImageRequestCacheStreamFetcher(mContext, mCacheDirectory, model);
}

The DataFetcher

@Override
public InputStream loadData(Priority priority) throws Exception {
    test if image is from cache then return inputstream from it (never locks)
    The glide.into that will lock forever even with timeouts in the okhttpclient unless I force the timeouts in the .get()
    put image in cache (never locks here)
    return inputstream from image in cache.
}

The first Glide call is from a cursorAdapter with a simple :

Glide.with(ctx)
        .load(DisplayHelper.getGlideImageRequest(buffer))
        .centerCrop()
        .placeholder(mDefaultImageResource)
        .error(mDefaultErrorResource)
        .crossFade(250)
        .into((ImageView) view.getTag(imageViewId));

I suspect this is more or less tied to my PR about request not set on the future soon enough.
Maybe there's other things impacted by this that will lead to infinite wait on cancel.

No more time today to roll back my current state with my implementation for the stack trace, will try to gather them tomorrow.

@sjudd
Copy link
Collaborator

sjudd commented Apr 13, 2015

I agree, your PR is probably related. It looks like at least the logic here is broken: https://github.com/bumptech/glide/blob/master/library/src/main/java/com/bumptech/glide/GenericRequestBuilder.java#L673.

The run() method there should first acquire a lock on the Target so that it isn't cancelled between the isCanceled check and the into() method.

@sjudd sjudd added the bug label Apr 13, 2015
@TWiStErRob
Copy link
Collaborator

kill -3 (SIGQUIT) requires root, the only way I was able to take a thread dump is to do it from within your app.

@Tolriq
Copy link
Contributor Author

Tolriq commented Apr 14, 2015

Here's the part relative to glide on the traces.

2 different cases but always blocked queues so clearly a synchronization problem.
But I must also admit that my use case is maybe not common.

"fifo-pool-thread-0" prio=5 tid=42 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12e09460 self=0xa1858800
  | sysTid=32180 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xb4bcb980
  | state=S schedstat=( 75699377 137548016 226 ) utm=7 stm=0 core=1 HZ=100
  | stack=0x98f12000-0x98f14000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x0fda0e43> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x0fda0e43> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-0" prio=5 tid=43 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12e53700 self=0xa1859400
  | sysTid=32181 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9a4b4700
  | state=S schedstat=( 768518082 808396197 3788 ) utm=72 stm=4 core=1 HZ=100
  | stack=0x9e3af000-0x9e3b1000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x076f1037> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:265)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:202)
  - locked <0x076f1037> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:121)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:220)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:39)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-1" prio=5 tid=44 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12e53760 self=0xa1859800
  | sysTid=32182 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9a4b4980
  | state=S schedstat=( 707184514 869056571 3706 ) utm=62 stm=8 core=0 HZ=100
  | stack=0x9e2ab000-0x9e2ad000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x02c4d9a4> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:265)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:202)
  - locked <0x02c4d9a4> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:121)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:220)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:39)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-3" prio=5 tid=45 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12e538e0 self=0xa185a000
  | sysTid=32184 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9a4b4e80
  | state=S schedstat=( 637342934 751956241 3006 ) utm=52 stm=11 core=2 HZ=100
  | stack=0x9e0a3000-0x9e0a5000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x20f8d30d> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:265)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:202)
  - locked <0x20f8d30d> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:121)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:220)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:39)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-2" prio=5 tid=46 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12e53820 self=0xa1859c00
  | sysTid=32183 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0x9a4b4c00
  | state=S schedstat=( 613054053 778342974 3460 ) utm=49 stm=12 core=1 HZ=100
  | stack=0x9e1a7000-0x9e1a9000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x234e02c2> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:265)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:202)
  - locked <0x234e02c2> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:121)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:220)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:39)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)
"fifo-pool-thread-0" prio=5 tid=43 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12f3c220 self=0xa183b800
  | sysTid=24880 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xb491cb80
  | state=S schedstat=( 8879844 8565313 34 ) utm=0 stm=0 core=0 HZ=100
  | stack=0x98e8e000-0x98e90000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x13411aa3> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x13411aa3> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-3" prio=5 tid=44 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12f6ad00 self=0xaec4ac00
  | sysTid=24886 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaec56100
  | state=S schedstat=( 70005678 34776196 122 ) utm=7 stm=0 core=0 HZ=100
  | stack=0x9e08b000-0x9e08d000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x05e831a0> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x05e831a0> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-2" prio=5 tid=45 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12f6ab20 self=0xaec4a800
  | sysTid=24885 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaec55e80
  | state=S schedstat=( 59300679 154612918 341 ) utm=3 stm=2 core=1 HZ=100
  | stack=0x9e18f000-0x9e191000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x04bc1159> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x04bc1159> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-1" prio=5 tid=46 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12f6aa60 self=0xaec4a400
  | sysTid=24884 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaec55c00
  | state=S schedstat=( 68682864 197314114 469 ) utm=6 stm=0 core=2 HZ=100
  | stack=0x9e293000-0x9e295000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x1532b11e> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x1532b11e> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-0" prio=5 tid=47 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12f6aa00 self=0xaec49c00
  | sysTid=24883 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaec55980
  | state=S schedstat=( 56339274 165162494 330 ) utm=3 stm=2 core=1 HZ=100
  | stack=0x9e397000-0x9e399000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x13c0bdff> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x13c0bdff> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

@sjudd sjudd closed this as completed in 59209d8 Apr 16, 2015
@Tolriq
Copy link
Contributor Author

Tolriq commented Apr 16, 2015

@sjudd this is not fully fixed :(

There's no more infinite locks so situation is a little better but seems you only fixed one of the reported traces.

Now there's sometimes (often) lock of the duration of .get(10, TimeUnit.SECONDS); where all images will not be downloaded and will all return null after, then some other images do download then hang again..

"fifo-pool-thread-0" prio=5 tid=39 Waiting
  | group="main" sCount=1 dsCount=0 obj=0x12c008e0 self=0xa1823c00
  | sysTid=10180 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xa1b56580
  | state=S schedstat=( 477608525 1383970023 1701 ) utm=40 stm=7 core=0 HZ=100
  | stack=0x9868e000-0x98690000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x1a3abde0> (a java.lang.Object)
  at java.lang.Thread.parkFor(Thread.java:1220)
  - locked <0x1a3abde0> (a java.lang.Object)
  at sun.misc.Unsafe.park(Unsafe.java:299)
  at java.util.concurrent.locks.LockSupport.park(LockSupport.java:157)
  at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await(AbstractQueuedSynchronizer.java:2016)
  at java.util.concurrent.PriorityBlockingQueue.take(PriorityBlockingQueue.java:510)
  at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:1035)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1097)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-0" prio=5 tid=40 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12d6cee0 self=0xaec4b800
  | sysTid=10181 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaefde300
  | state=S schedstat=( 2851047633 2558026103 14934 ) utm=243 stm=42 core=1 HZ=100
  | stack=0x9858a000-0x9858c000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x0c1d4899> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:238)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:183)
  - locked <0x0c1d4899> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:108)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:112)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:33)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-2" prio=5 tid=41 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12c7b580 self=0xaec4e800
  | sysTid=10183 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaefe0100
  | state=S schedstat=( 2936326626 3119247120 14390 ) utm=255 stm=38 core=2 HZ=100
  | stack=0x98382000-0x98384000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x13ecb75e> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:238)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:183)
  - locked <0x13ecb75e> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:108)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:112)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:33)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-1" prio=5 tid=42 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12d6cfa0 self=0xaec4bc00
  | sysTid=10182 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaefde580
  | state=S schedstat=( 2977751919 2946508912 14942 ) utm=264 stm=33 core=2 HZ=100
  | stack=0x98486000-0x98488000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x0c5ce73f> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:238)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:183)
  - locked <0x0c5ce73f> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:108)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:112)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:33)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

"fifo-pool-thread-3" prio=5 tid=43 TimedWaiting
  | group="main" sCount=1 dsCount=0 obj=0x12c7b640 self=0xaec4ec00
  | sysTid=10184 nice=10 cgrp=bg_non_interactive sched=0/0 handle=0xaefe0380
  | state=S schedstat=( 3171639629 3212509630 14667 ) utm=258 stm=59 core=3 HZ=100
  | stack=0x9827e000-0x98280000 stackSize=1036KB
  | held mutexes=
  at java.lang.Object.wait!(Native method)
  - waiting on <0x2bbdd80c> (a com.bumptech.glide.request.RequestFutureTarget)
  at java.lang.Object.wait(Object.java:422)
  at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:238)
  at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:183)
  - locked <0x2bbdd80c> (a com.bumptech.glide.request.RequestFutureTarget)
  at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:108)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:112)
  at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:33)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
  at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
  at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
  at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
  at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
  at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
  at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
  at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
  at java.util.concurrent.FutureTask.run(FutureTask.java:237)
  at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
  at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
  at java.lang.Thread.run(Thread.java:818)
  at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

@sjudd sjudd reopened this Apr 17, 2015
@sjudd
Copy link
Collaborator

sjudd commented Apr 17, 2015

@Tolriq Are the downloads timing out? Or are they succeeding but we're still blocking on the future for no good reason? Do you have repro steps?

Thanks for confirming we've at least fixed the deadlock.

@Tolriq
Copy link
Contributor Author

Tolriq commented Apr 17, 2015

It's seems to be still FutureRequests since I do set a 5 second timeout on okhttp and it timeout at 10.

Seems a reuse of something does trigger the problem.

The repro steps are as mentioned earlier.

Register a modelloader for something then in it's dataFetcher onLoad() call

mNetworkLoading = Glide.with(ctx)
        .load(new NetworkImageRequest(imageRequest))
        .asBitmap()
        .diskCacheStrategy(DiskCacheStrategy.NONE)
        .into(500, 500);

image = mNetworkLoading.get(10, TimeUnit.SECONDS);

The NetworkImageRequest model handler is a copy paste of the okhttp integration library with just some specific headers handling.

Then in a normal adapter call a simple Glide.load(newmodel).into(imgview) and scroll.
This will lock.

ImageRequestCacheStreamFetcher.loadData@115: Error : Cancelled :
    java.lang.InterruptedException
            at java.lang.Object.wait(Native Method)
            at java.lang.Object.wait(Object.java:422)
            at com.bumptech.glide.request.RequestFutureTarget$Waiter.waitForTimeout(RequestFutureTarget.java:238)
            at com.bumptech.glide.request.RequestFutureTarget.doGet(RequestFutureTarget.java:183)
            at com.bumptech.glide.request.RequestFutureTarget.get(RequestFutureTarget.java:108)
            at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:112)
            at org.leetzone.android.yatsewidget.glide.ImageRequestCacheStreamFetcher.loadData(ImageRequestCacheStreamFetcher.java:33)
            at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:70)
            at com.bumptech.glide.load.model.ImageVideoModelLoader$ImageVideoFetcher.loadData(ImageVideoModelLoader.java:53)
            at com.bumptech.glide.load.engine.DecodeJob.decodeSource(DecodeJob.java:170)
            at com.bumptech.glide.load.engine.DecodeJob.decodeFromSource(DecodeJob.java:128)
            at com.bumptech.glide.load.engine.EngineRunnable.decodeFromSource(EngineRunnable.java:122)
            at com.bumptech.glide.load.engine.EngineRunnable.decode(EngineRunnable.java:101)
            at com.bumptech.glide.load.engine.EngineRunnable.run(EngineRunnable.java:58)
            at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:422)
            at java.util.concurrent.FutureTask.run(FutureTask.java:237)
            at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1112)
            at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:587)
            at java.lang.Thread.run(Thread.java:818)
            at com.bumptech.glide.load.engine.executor.FifoPriorityThreadPoolExecutor$DefaultThreadFactory$1.run(FifoPriorityThreadPoolExecutor.java:52)

@sjudd
Copy link
Collaborator

sjudd commented Apr 19, 2015

Ok two things here:

  1. It looks like 10 second timeout is because you're waiting for 5 seconds inside of ImageRequestCacheStreamFetcher, and then another 5 seconds in your request
  2. You will absolutely encounter deadlock if you start loads with Glide, within loads started by Glide (if that makes any sense...).

To expand on #2 a bit: Glide uses a variable sized thread pool based on the number of cores a device has. In the worst case, the pool will use a single thread. By nesting Glide calls as you are, it's possible you will ask that single pool thread to block and allow no other work, until that single pool thread does some other work, which is deadlock.

For pools with sizes > 1, deadlock is less likely, but it can still happen. You'll need to try to find a way to avoid calling into Glide in ImageRequestCacheStreamFetcher. If you provide a source snippet I may be able to suggest an alternative.

@Tolriq
Copy link
Contributor Author

Tolriq commented Apr 19, 2015

Well there's 4 thread in the pool as the stack traces shows and if I understand correctly and it happens each time.

My need have not changed since the beginning :(

I need to have a permanent SOURCE cache with images that are stored not at SOURCE size but at a max size depending on device (#383)

From all previous discussions the easiest way was to do it in the loadData from the fetcher.
So calling glide again from there was the most simplest way :) Since it did not work I switched to manual download / resize.

Until there's a way to have a way to intercept cache writes / read with more details about what is cached (needs model + cache strategy) I do not think there's other ways.

If it's now clear that calling glide inside glide is not supported I'll keep my way as it works :)

To me there may just be some missing parts in the doc about those details :(

@sjudd
Copy link
Collaborator

sjudd commented Sep 14, 2017

FWIW we added useUnlimtedSourceGeneratorsPool to handle the second case above. You can now actually start a new load with Glide inside an existing load in Glide, but you have to specify that option.

One better would be to make this happen automatically by checking the thread that Glide's started on, but that's a bit more complicated and there doesn't seem to be a lot of demand for it at the moment.

@sjudd sjudd closed this as completed Sep 14, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

3 participants