Thread leak or expected behavior with fibers ? #1181

Closed
fatum opened this Issue Oct 29, 2013 · 9 comments

Projects

None yet

5 participants

@fatum

I use simple gem fastimage to fetch image metadata, gem uses Fibers

When i run loop in console and watch for jruby process through jmap i see what count org.jruby.RubyThread objects and other thread related objects increased by time

Sample loop

10_000.times { fastimage = FastImage.new(src); fastimage.size; fastimage.type }

jmap output

 86:          1173          93904  [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
 102:           582          65184  org.jruby.runtime.ThreadContext
 104:           594          61776  java.lang.Thread
 109:          1780          56960  java.lang.ThreadLocal$ThreadLocalMap$Entry
 116:           583          51304  org.jruby.RubyThread
 138:           582          32592  org.jruby.ext.fiber.ThreadFiber
 144:           587          28176  java.util.concurrent.ThreadPoolExecutor$Worker
 145:          1173          28152  java.lang.ThreadLocal$ThreadLocalMap
 195:           583          13992  org.jruby.internal.runtime.NativeThread
 198:           581          13944  org.jruby.ext.fiber.ThreadFiber$1
 287:             2           4160  [Ljava.lang.Thread;
 639:            23            368  java.lang.ThreadLocal
 823:             7            224  org.jruby.ext.thread.Mutex
 825:             4            224  java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask
 834:             3            216  java.util.concurrent.ThreadPoolExecutor
 959:             2            160  org.jruby.ext.thread.SizedQueue$INVOKER$i$1$0$push
1214:             3            144  java.lang.ThreadGroup
1236:             5            120  org.jruby.ext.fiber.ThreadFiberState

Environment:
MacOs,
java version "1.7.0_17"
Java(TM) SE Runtime Environment (build 1.7.0_17-b02)
Java HotSpot(TM) 64-Bit Server VM (build 23.7-b01, mixed mode),
jruby 1.7.2 (1.9.3p327) 2013-01-04 302c706 on Java HotSpot(TM) 64-Bit Server VM 1.7.0_17-b02 [darwin-x86_64]

@headius
JRuby Team member

Please test against a more recent JRuby. Fibers have evolved during the maintenance cycle, and were completely rewritten for JRuby 1.7.5.

If you still have issues with JRuby 1.7.6, then we'll help investigate.

@fatum

Thanks for answer!

Run same test on 1.7.6 – output jmap after ten minutes, seems like threads not collected by GC

 63:          2104         168384  [Ljava.lang.ThreadLocal$ThreadLocalMap$Entry;
  82:          1048         125760  org.jruby.runtime.ThreadContext
  84:          1046         125520  org.jruby.ext.fiber.ThreadFiber$1
  88:          1048         108992  org.jruby.RubyThread
  93:          3177         101664  java.lang.ThreadLocal$ThreadLocalMap$Entry
 103:          2094          83760  org.jruby.ext.fiber.ThreadFiber
 104:          2094          83760  org.jruby.ext.thread.SizedQueue
 114:          2094          67008  org.jruby.ext.fiber.ThreadFiber$FiberData
 130:          2104          50496  java.lang.ThreadLocal$ThreadLocalMap
 147:          1046          33472  org.jruby.RubyThread$SleepTask
 159:          1048          25152  org.jruby.internal.runtime.NativeThread
 232:             2           8256  [Ljava.lang.Thread;
 415:            13           1352  java.lang.Thread
 585:            28            448  java.lang.ThreadLocal
 654:            12            384  org.jruby.ext.thread.Mutex
 770:             6            288  java.util.concurrent.ThreadPoolExecutor$Worker
 855:             4            224  java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask
 861:             3            216  java.util.concurrent.ThreadPoolExecutor
1196:             2            176  org.jruby.ext.thread.SizedQueue$INVOKER$i$1$0$push
1266:             3            144  java.lang.ThreadGroup
1323:             1            104  java.lang.ref.Finalizer$FinalizerThread
1355:             4             96  org.jruby.RubyThread$Status
1388:             1             88  org.jruby.RubyThreadGroup$INVOKER$i$0$0$list
1420:             1             88  org.jruby.ext.fiber.ThreadFiber$INVOKER$i$0$0$__transfer__
1443:             1             88  org.jruby.RubyThreadGroup$INVOKER$i$0$0$enclosed_p
@headius
JRuby Team member

Can you provide your reproduction? I will look into it.

@fatum fatum referenced this issue in sdsykes/fastimage Nov 1, 2013
Closed

Possible memory leak in jruby #22

@griffindy

@fatum I was having this same issue. I managed to get around it by forking the gem and removing the use of fibers if you pass FastImage.size something that responds to #read, which you can achieve using open-uri: griffindy/threadless-fastimage@d2e91e2

I also think this might a be a more fundamental problem with fibers, and more specifically with queues, as I have been having problems with queues waiting forever to pop.

@sdsykes

@griffindy Was this also with jruby?

@griffindy

yep, 1.7.10

@headius headius modified the milestone: JRuby 1.7.11, JRuby 1.7.10 Feb 21, 2014
@headius
JRuby Team member

JRuby 1.7.11 fixes several issues with Fiber lifecycle and reintroduces a thread pool for the native threads that back them. I'm going to optimistically call this one closed, but I'd appreciate confirmation that thread counts are more stable now.

@headius headius closed this Feb 21, 2014
@nowhereman

@headius Sadly, same issue with JRuby 1.7.11 😕

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment