This is the mail archive of the kawa@sourceware.org mailing list for the Kawa project.

Index Nav:	[Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav:	[Date Prev] [Date Next]	[Thread Prev] [Thread Next]
Other format:	[Raw text]

Re: Kawa fails if used in multithreading

From: Daniele Benegiamo <danielebenegiamo at fastwebnet dot it>
To: "kawa at sourceware dot org" <kawa at sourceware dot org>
Date: Tue, 03 Aug 2010 13:16:25 +0200
Subject: Re: Kawa fails if used in multithreading
References: <4C51C8CD.1080306@fastwebnet.it> <4C51CD28.9050903@bothner.com> <4C52B747.2080604@fastwebnet.it> <4C53099E.20703@bothner.com> <4C5655D8.7050603@bothner.com>

Per Bothner wrote:

The primary problem appears to have been the thread-local variable
Compilation.current.  This was not used in a safe manner.  I've changed
it to use InheritableThreadLocal - and I also changed the places
where it was set.  (Either change should be enough, but I think both
are reasonable.)

I also made various methods synchronized.  The issue is that the
is a shared pool of ClassType objects for "existing classes", and
initializing those ClassTypes might have been unsafe.

These changes are checked into the SVN repository.

Thanks for your quick fixing.

I've checked revision 6642 and I've found two race conditions. Using the sample program previously sent, setting LOOPS to an high value (1000, 10000, it's machine and weather dependent...) is more likely to get the problem.

In the first type of deadlock all threads waits at the same point (ModuleContext.findInstance(), row 81); this is a sample thread dump:

"Thread-0"
java.lang.Class.getDeclaredFields0(Class.java)
java.lang.Class.privateGetDeclaredFields(Class.java:2291)
java.lang.Class.getDeclaredField(Class.java:1880)
gnu.expr.ModuleContext.findInstance(ModuleContext.java:81)
gnu.expr.ModuleExp.evalModule2(ModuleExp.java:284)
gnu.expr.ModuleExp.evalModule(ModuleExp.java:185)
gnu.expr.Language.eval(Language.java:939)
gnu.expr.Language.eval(Language.java:879)
gnu.expr.Language.eval(Language.java:861)
Main.run(Main.java:61)
java.lang.Thread.run(Thread.java:619)

The second type of deadlock is that some threads ends, but the others loops forever at ModuleContext.findInstance(), row 74 (after the dump, a brutal solution...and another problem...):

2010-08-03 12:44:45
Full thread dump Java HotSpot(TM) 64-Bit Server VM (16.3-b01 mixed mode):

"RMI TCP Connection(2)-127.0.1.1" daemon prio=10 tid=0x00007f6fe05ff000 nid=0x1cd9 runnable [0x0000000041a42000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at java.io.BufferedInputStream.fill(BufferedInputStream.java:218) at java.io.BufferedInputStream.read(BufferedInputStream.java:237) - locked <0x00007f703b6ebcd0> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(FilterInputStream.java:66) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619)

Locked ownable synchronizers: - <0x00007f703adb2138> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"JMX server connection timeout 18" daemon prio=10 tid=0x00007f6fe0717800 nid=0x1cd2 in Object.wait() [0x0000000041941000] java.lang.Thread.State: TIMED_WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00007f703afe0148> (a [I) at com.sun.jmx.remote.internal.ServerCommunicatorAdmin$Timeout.run(ServerCommunicatorAdmin.java:150) - locked <0x00007f703afe0148> (a [I) at java.lang.Thread.run(Thread.java:619)

   Locked ownable synchronizers:
	- None

"RMI Scheduler(0)" daemon prio=10 tid=0x00007f6fe06f3800 nid=0x1cd1 waiting on condition [0x0000000041840000] java.lang.Thread.State: TIMED_WAITING (parking) at sun.misc.Unsafe.park(Native Method) - parking to wait for <0x00007f703ac7fed8> (a java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject) at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:198) at java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:1963) at java.util.concurrent.DelayQueue.take(DelayQueue.java:164) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:583) at java.util.concurrent.ScheduledThreadPoolExecutor$DelayedWorkQueue.take(ScheduledThreadPoolExecutor.java:576) at java.util.concurrent.ThreadPoolExecutor.getTask(ThreadPoolExecutor.java:947) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:907) at java.lang.Thread.run(Thread.java:619)

   Locked ownable synchronizers:
	- None

"RMI TCP Connection(1)-127.0.1.1" daemon prio=10 tid=0x00007f6fe08ef800 nid=0x1cd0 runnable [0x000000004173f000] java.lang.Thread.State: RUNNABLE at java.net.SocketInputStream.socketRead0(Native Method) at java.net.SocketInputStream.read(SocketInputStream.java:129) at java.io.BufferedInputStream.fill(BufferedInputStream.java:218) at java.io.BufferedInputStream.read(BufferedInputStream.java:237) - locked <0x00007f703af86978> (a java.io.BufferedInputStream) at java.io.FilterInputStream.read(FilterInputStream.java:66) at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:517) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790) at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649) at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908) at java.lang.Thread.run(Thread.java:619)

Locked ownable synchronizers: - <0x00007f703adb19f0> (a java.util.concurrent.locks.ReentrantLock$NonfairSync)

"RMI TCP Accept-0" daemon prio=10 tid=0x00007f6fe0842800 nid=0x1cce runnable [0x000000004163e000] java.lang.Thread.State: RUNNABLE at java.net.PlainSocketImpl.socketAccept(Native Method) at java.net.PlainSocketImpl.accept(PlainSocketImpl.java:390) - locked <0x00007f703ac8f0e0> (a java.net.SocksSocketImpl) at java.net.ServerSocket.implAccept(ServerSocket.java:453) at java.net.ServerSocket.accept(ServerSocket.java:421) at sun.management.jmxremote.LocalRMIServerSocketFactory$1.accept(LocalRMIServerSocketFactory.java:34) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.executeAcceptLoop(TCPTransport.java:369) at sun.rmi.transport.tcp.TCPTransport$AcceptLoop.run(TCPTransport.java:341) at java.lang.Thread.run(Thread.java:619)

   Locked ownable synchronizers:
	- None

"Attach Listener" daemon prio=10 tid=0x00007f6fe17e1800 nid=0x1a00 waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Thread-2" prio=10 tid=0x00007f6fdc027800 nid=0x1993 runnable [0x000000004153d000] java.lang.Thread.State: RUNNABLE at java.util.WeakHashMap.get(WeakHashMap.java:355) at gnu.expr.ModuleContext.findInstance(ModuleContext.java:74) at gnu.expr.ModuleExp.evalModule2(ModuleExp.java:284) at gnu.expr.ModuleExp.evalModule(ModuleExp.java:185) at gnu.expr.Language.eval(Language.java:939) at gnu.expr.Language.eval(Language.java:879) at gnu.expr.Language.eval(Language.java:861) at Main.run(Main.java:61) at java.lang.Thread.run(Thread.java:619)

   Locked ownable synchronizers:
	- None

"Thread-1" prio=10 tid=0x00007f6fdc025000 nid=0x1992 runnable [0x000000004143c000] java.lang.Thread.State: RUNNABLE at java.util.WeakHashMap.get(WeakHashMap.java:355) at gnu.expr.ModuleContext.findInstance(ModuleContext.java:74) at gnu.expr.ModuleExp.evalModule2(ModuleExp.java:284) at gnu.expr.ModuleExp.evalModule(ModuleExp.java:185) at gnu.expr.Language.eval(Language.java:939) at gnu.expr.Language.eval(Language.java:879) at gnu.expr.Language.eval(Language.java:861) at Main.run(Main.java:61) at java.lang.Thread.run(Thread.java:619)

   Locked ownable synchronizers:
	- None

"Low Memory Detector" daemon prio=10 tid=0x00007f6fdc002000 nid=0x198f runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"CompilerThread1" daemon prio=10 tid=0x00007f6fe17c8800 nid=0x198e waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"CompilerThread0" daemon prio=10 tid=0x00007f6fe17c5000 nid=0x198d waiting on condition [0x0000000000000000] java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Signal Dispatcher" daemon prio=10 tid=0x00007f6fe17c3000 nid=0x198c runnable [0x0000000000000000] java.lang.Thread.State: RUNNABLE

   Locked ownable synchronizers:
	- None

"Finalizer" daemon prio=10 tid=0x00007f6fe17a3800 nid=0x198b in Object.wait() [0x0000000040d35000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00007f6fe7518ef8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118) - locked <0x00007f6fe7518ef8> (a java.lang.ref.ReferenceQueue$Lock) at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:134) at java.lang.ref.Finalizer$FinalizerThread.run(Finalizer.java:159)

   Locked ownable synchronizers:
	- None

"Reference Handler" daemon prio=10 tid=0x00007f6fe179c000 nid=0x198a in Object.wait() [0x0000000040c34000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00007f6fe750af40> (a java.lang.ref.Reference$Lock) at java.lang.Object.wait(Object.java:485) at java.lang.ref.Reference$ReferenceHandler.run(Reference.java:116) - locked <0x00007f6fe750af40> (a java.lang.ref.Reference$Lock)

   Locked ownable synchronizers:
	- None

"main" prio=10 tid=0x0000000040111000 nid=0x197d in Object.wait() [0x000000004022a000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(Native Method) - waiting on <0x00007f6fe74f76a8> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1143) - locked <0x00007f6fe74f76a8> (a java.lang.Thread) at java.lang.Thread.join(Thread.java:1196) at Main.main(Main.java:46)

   Locked ownable synchronizers:
	- None

"VM Thread" prio=10 tid=0x00007f6fe1797800 nid=0x1989 runnable

"GC task thread#0 (ParallelGC)" prio=10 tid=0x0000000040124000 nid=0x1981 runnable

"GC task thread#1 (ParallelGC)" prio=10 tid=0x0000000040126000 nid=0x1982 runnable

"GC task thread#2 (ParallelGC)" prio=10 tid=0x0000000040127800 nid=0x1983 runnable

"GC task thread#3 (ParallelGC)" prio=10 tid=0x0000000040129800 nid=0x1984 runnable

"GC task thread#4 (ParallelGC)" prio=10 tid=0x00007f6fe16f4800 nid=0x1985 runnable

"GC task thread#5 (ParallelGC)" prio=10 tid=0x00007f6fe16f6000 nid=0x1986 runnable

"GC task thread#6 (ParallelGC)" prio=10 tid=0x00007f6fe16f8000 nid=0x1987 runnable

"GC task thread#7 (ParallelGC)" prio=10 tid=0x00007f6fe16fa000 nid=0x1988 runnable

"VM Periodic Task Thread" prio=10 tid=0x00007f6fdc005000 nid=0x1990 waiting on condition

JNI global references: 1385

Placing a "synchronized" in front of ModuleContext.findInstance() (seems to) solve the problem, but maybe it's too coarse-grained.

This showed up another problem: analyzing the PermGen space, it continuously increase in time; with (very) high LOOPS values threads dead due missing available PermGen space. It seems to depend on reflection or leaking when compiling scheme programs: the number of total loaded classes continuously increase in time as PermGen space. You can monitor all this with the standard Java VisualVM (jvisualvm).

Daniele

Follow-Ups:
- Re: Kawa fails if used in multithreading
  - From: Per Bothner

References:
- Kawa fails if used in multithreading
  - From: Daniele Benegiamo
- Re: Kawa fails if used in multithreading
  - From: Per Bothner
- Re: Kawa fails if used in multithreading
  - From: Daniele Benegiamo
- Re: Kawa fails if used in multithreading
  - From: Per Bothner
- Re: Kawa fails if used in multithreading
  - From: Per Bothner

Index Nav:	[Date Index] [Subject Index] [Author Index] [Thread Index]
Message Nav:	[Date Prev] [Date Next]	[Thread Prev] [Thread Next]