[concurrency-interest] Nested synchronized

Howard Lovatt howard.lovatt at gmail.com
Sun Jan 8 06:14:21 EST 2012


Hi All,

Thanks for everyones suggestions.

Here is a brief summary of my latest experiments with this bug.

   1. I cannot get JConsole to connect
   2. Both Heinz's code and my code run fine on a core 2 duo Mac I have
   (same Java version, same OS - see below)
   3. Both Heinz's code and my code run fine on my MacBook
   running Stephen Bannasch's MLVM, i.e. same machine. JVM version is:

gar-ln:dist lov080$ ~/Downloads/MLVM/1.7.0_2011_05_02/Home/bin/java -version
openjdk version "1.7.0-internal"
OpenJDK Runtime Environment (build
1.7.0-internal-stephen_2011_05_02_10_53-b00)
OpenJDK 64-Bit Server VM (build 21.0-b07, mixed mode)

     4. Both Heinz's code and my code run fine on my MacBook, i.e. same
machine, running Windows 7 (via parallels). JVM version is:

Z:\Dropbox\Personal\Java\examples\NestedSynchronizedProblem\dist>java
-version
java version "1.7.0_02"
Java(TM) SE Runtime Environment (build 1.7.0_02-b13)
Java HotSpot(TM) 64-Bit Server VM (build 22.0-b10, mixed mode)


The only combination for which I can test that fails, for both Heinz's code
and my code, is Mac OS 10.7.2 running:

gar-ln:src lov080$ java -version
java version "1.6.0_29"
Java(TM) SE Runtime Environment (build 1.6.0_29-b11-402-11M3527)
Java HotSpot(TM) 64-Bit Server VM (build 20.4-b02-402, mixed mode)



Is there somewhere to log this bug formally, since I think it is over to
Oracle and/or Apple on this one now?

Thanks again,

 -- Howard.

On 7 January 2012 20:44, Dr Heinz M. Kabutz <heinz at javaspecialists.eu>wrote:

> **
> Yes, we also found this problem to be hardware related.  Here is a class
> sent to me by Jim McClure that also causes a JVM deadlock on certain modern
> i7 chips (not the older ones) on Mac OS X:
>
>  public class Foo {
>
>  private int counter;
>
>  public static void main(String[] args) throws Exception {
>  new Foo().run();
>  }
>
>  public void run() throws Exception {
>
>  Thread[] threads = new Thread[2];
>
>  for (int i = 0; i < threads.length; i++) {
>  threads[i] = new Thread() {
>  public void run() {
>
>  System.out.println("Thread started " + Thread.currentThread().getName());
>  System.out.flush();
>
>  for (int i = 0; i < 100000; i++) {
>  increment();
>  }
>
>  System.out.println("Thread done " + Thread.currentThread().getName());
>  System.out.flush();
>  }
>  };
>  }
>
>  for (Thread t : threads) {
>  t.start();
>  }
>
>  System.out.println("Started");
>  System.out.flush();
>
>  System.out.println("Awaiting complete...");
>  System.out.flush();
>
>  for (Thread t : threads) {
>  t.join();
>  }
>
>  System.out.println("Completed...");
>  System.out.flush();
>  }
>
>  private synchronized void increment() {
>
>  counter++;
>
>  if (counter % 10000 == 0) {
>  System.out.printf("%s: %d\n", Thread.currentThread().getName(), counter);
>  System.out.flush();
>  }
>  }
> }
>
>  Output:
>
>  Thread started Thread-1
> Thread started Thread-2
> Started
> Awaiting complete...
> Thread-2: 10000
> Thread-2: 20000
> Thread-1: 30000
> Thread-2: 40000
> Thread-1: 50000
> Thread-2: 60000
> Thread-2: 70000
> Thread-2: 80000
> Thread-1: 90000
> Thread-1: 100000
> Thread-1: 110000
> Thread-1: 120000
> Thread-1: 130000
> Thread-1: 140000
> Thread done Thread-1
>
>
> Regards
>
> Heinz
> --
> Dr Heinz M. Kabutz (PhD CompSci)
> Author of "The Java(tm) Specialists' Newsletter"
> Sun Java Champion
> IEEE Certified Software Development Professional
> http://www.javaspecialists.eu
> Tel: +30 69 72 850 460
> Skype: kabutz
>
>
>
> On 1/7/12 4:49 AM, Howard Lovatt wrote:
>
> Hi Gregg,
>
>  Weird I have the same Java version, but for me it starts working (high
> CPU usage) and then hangs (negligible CPU usage). Whilst it is running I
> can get a stack trace, see below. But once it has hung I can't get a stack
> trace and I have to kill it.
>
>  Could it be a hardware variation; I have a 4-core i7 processor?
>
>    Model Name: MacBook Pro
>
>   Model Identifier: MacBookPro8,2
>
>   Processor Name: Intel Core i7
>
>   Processor Speed: 2.3 GHz
>
>   Number of Processors: 1
>
>   Total Number of Cores: 4
>
>   L2 Cache (per Core): 256 KB
>
>   L3 Cache: 8 MB
>
>  Could it be a software variation; I have Lion?
>
>    System Version: Mac OS X 10.7.2 (11C74)
>
>   Kernel Version: Darwin 11.2.0
>
>   Boot Volume: sunzero-ln
>
>   Boot Mode: Normal
>
>   Computer Name: sunzero-ln
>
>   User Name: Howard Lovatt (lov080)
>
>   Secure Virtual Memory: Enabled
>
>   64-bit Kernel and Extensions: Yes
>
>   Time since boot: 29 days 4:35
>
>
>  Thanks for running the code.
>
>  -- Howard
>
> ===============================================
>
>  gar-ln:src lov080$ java
> nestedsynchronizedproblem.NestedSynchronizedProblem
> ^\2012-01-06 17:17:34
> Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.4-b02-402 mixed
> mode):
>
>  "pool-1-thread-2" prio=5 tid=7fb8fb291800 nid=0x113dfd000 runnable
> [113dfc000]
>    java.lang.Thread.State: RUNNABLE
>  at java.lang.Thread.isInterrupted(Native Method)
>  at java.lang.Thread.interrupted(Thread.java:934)
>  at
> nestedsynchronizedproblem.ParrallelSumMethod.checkForInterrupt(NestedSynchronizedProblem.java:68)
>  at
> nestedsynchronizedproblem.ParrallelSumMethod.setA2(NestedSynchronizedProblem.java:61)
>  at
> nestedsynchronizedproblem.NestedSynchronizedProblem$2.call(NestedSynchronizedProblem.java:31)
>  at
> nestedsynchronizedproblem.NestedSynchronizedProblem$2.call(NestedSynchronizedProblem.java:29)
>  at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>  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:680)
>
>  "pool-1-thread-1" prio=5 tid=7fb8fb290800 nid=0x113cfa000 waiting for
> monitor entry [113cf9000]
>    java.lang.Thread.State: BLOCKED (on object monitor)
>  at
> nestedsynchronizedproblem.ParrallelSumMethod.isSetA1(NestedSynchronizedProblem.java:72)
>  - locked <7f42b20a0> (a nestedsynchronizedproblem.ParrallelSumMethod)
>  at
> nestedsynchronizedproblem.ParrallelSumMethod.setA1(NestedSynchronizedProblem.java:53)
>  at
> nestedsynchronizedproblem.NestedSynchronizedProblem$1.call(NestedSynchronizedProblem.java:25)
>  at
> nestedsynchronizedproblem.NestedSynchronizedProblem$1.call(NestedSynchronizedProblem.java:23)
>  at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>  at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>  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:680)
>
>  "Low Memory Detector" daemon prio=5 tid=7fb8fb15a000 nid=0x11395d000
> runnable [00000000]
>    java.lang.Thread.State: RUNNABLE
>
>  "C2 CompilerThread1" daemon prio=9 tid=7fb8fb159800 nid=0x11385a000
> waiting on condition [00000000]
>    java.lang.Thread.State: RUNNABLE
>
>  "C2 CompilerThread0" daemon prio=9 tid=7fb8fb158800 nid=0x113757000
> waiting on condition [00000000]
>    java.lang.Thread.State: RUNNABLE
>
>  "Signal Dispatcher" daemon prio=9 tid=7fb8fb158000 nid=0x113654000
> waiting on condition [00000000]
>    java.lang.Thread.State: RUNNABLE
>
>  "Surrogate Locker Thread (Concurrent GC)" daemon prio=5 tid=7fb8fb157000
> nid=0x113551000 waiting on condition [00000000]
>    java.lang.Thread.State: RUNNABLE
>
>  "Finalizer" daemon prio=8 tid=7fb8fb13f000 nid=0x11328d000 in
> Object.wait() [11328c000]
>    java.lang.Thread.State: WAITING (on object monitor)
>  at java.lang.Object.wait(Native Method)
>  - waiting on <7f42b42a0> (a java.lang.ref.ReferenceQueue$Lock)
>  at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
>  - locked <7f42b42a0> (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)
>
>  "Reference Handler" daemon prio=10 tid=7fb8fb13e800 nid=0x11318a000 in
> Object.wait() [113189000]
>    java.lang.Thread.State: WAITING (on object monitor)
>  at java.lang.Object.wait(Native Method)
>  - waiting on <7f42b0100> (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 <7f42b0100> (a java.lang.ref.Reference$Lock)
>
>  "main" prio=5 tid=7fb8fb001000 nid=0x10b414000 waiting on condition
> [10b413000]
>    java.lang.Thread.State: TIMED_WAITING (parking)
>  at sun.misc.Unsafe.park(Native Method)
>  - parking to wait for  <7f42bc010> (a
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>  at java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)
>  at
> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2025)
>  at
> java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1253)
>  at
> nestedsynchronizedproblem.NestedSynchronizedProblem.main(NestedSynchronizedProblem.java:39)
>
>  "VM Thread" prio=9 tid=7fb8fb13a000 nid=0x113087000 runnable
>
>  "Gang worker#0 (Parallel GC Threads)" prio=9 tid=7fb8fb002800
> nid=0x10e74d000 runnable
>
>  "Gang worker#1 (Parallel GC Threads)" prio=9 tid=7fb8fb003000
> nid=0x10e850000 runnable
>
>  "Gang worker#2 (Parallel GC Threads)" prio=9 tid=7fb8fb003800
> nid=0x10e953000 runnable
>
>  "Gang worker#3 (Parallel GC Threads)" prio=9 tid=7fb8fb004000
> nid=0x10ea56000 runnable
>
>  "Gang worker#4 (Parallel GC Threads)" prio=9 tid=7fb8fb005000
> nid=0x10eb59000 runnable
>
>  "Gang worker#5 (Parallel GC Threads)" prio=9 tid=7fb8fb005800
> nid=0x10ec5c000 runnable
>
>  "Gang worker#6 (Parallel GC Threads)" prio=9 tid=7fb8fb006000
> nid=0x10ed5f000 runnable
>
>  "Gang worker#7 (Parallel GC Threads)" prio=9 tid=7fb8fb006800
> nid=0x10ee62000 runnable
>
>  "Concurrent Mark-Sweep GC Thread" prio=9 tid=7fb8fb0e4000
> nid=0x112d2d000 runnable
> "Gang worker#0 (Parallel CMS Threads)" prio=9 tid=7fb8fb0e3000
> nid=0x112327000 runnable
>
>  "Gang worker#1 (Parallel CMS Threads)" prio=9 tid=7fb8fb0e3800
> nid=0x11242a000 runnable
>
>  "VM Periodic Task Thread" prio=10 tid=7fb8fb16b800 nid=0x113a60000
> waiting on condition
>
>  "Exception Catcher Thread" prio=10 tid=7fb8fb001800 nid=0x10b576000
> runnable
> JNI global references: 906
>
>  Heap
>  par new generation   total 19136K, used 1211K [7f3000000, 7f44c0000,
> 7f44c0000)
>   eden space 17024K,   4% used [7f3000000, 7f30d16f8, 7f40a0000)
>   from space 2112K,  17% used [7f42b0000, 7f430d720, 7f44c0000)
>   to   space 2112K,   0% used [7f40a0000, 7f40a0000, 7f42b0000)
>  concurrent mark-sweep generation total 63872K, used 0K [7f44c0000,
> 7f8320000, 7fae00000)
>  concurrent-mark-sweep perm gen total 21248K, used 4769K [7fae00000,
> 7fc2c0000, 800000000)
>
>  Killed: 9
>
>
> On 6 January 2012 15:51, Gregg Wonderly <gergg at cox.net> wrote:
>
>> On my mac, it seems to complete successfully.  I've included a stack dump
>> just FYI.
>>
>> Gregg Wonderly
>>
>> gwmac:~ gregg$ javac -d . Prob.java
>> gwmac:~ gregg$ java my.Prob
>> ^\
>> 2012-01-05 22:48:09
>> Full thread dump Java HotSpot(TM) 64-Bit Server VM (20.4-b02-402 mixed
>> mode):
>>
>> "pool-1-thread-2" prio=5 tid=7ffd42969800 nid=0x10c132000 runnable
>> [10c131000]
>>   java.lang.Thread.State: RUNNABLE
>>        at my.ParrallelSumMethod.conditionallySumArguments(Prob.java:87)
>>        - locked <7f44e1400> (a my.ParrallelSumMethod)
>>        at my.ParrallelSumMethod.isSetA2(Prob.java:80)
>>        - locked <7f44e1400> (a my.ParrallelSumMethod)
>>        at my.ParrallelSumMethod.setA2(Prob.java:57)
>>        at my.Prob$2.call(Prob.java:28)
>>        at my.Prob$2.call(Prob.java:26)
>>        at
>> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>>        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>>        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:680)
>>
>> "pool-1-thread-1" prio=5 tid=7ffd4287f000 nid=0x10c02f000 runnable
>> [10c02e000]
>>   java.lang.Thread.State: RUNNABLE
>>        at java.lang.Thread.isInterrupted(Native Method)
>>        at java.lang.Thread.interrupted(Thread.java:934)
>>        at my.ParrallelSumMethod.checkForInterrupt(Prob.java:65)
>>        at my.ParrallelSumMethod.setA1(Prob.java:51)
>>        at my.Prob$1.call(Prob.java:22)
>>        at my.Prob$1.call(Prob.java:20)
>>        at
>> java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:303)
>>        at java.util.concurrent.FutureTask.run(FutureTask.java:138)
>>        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:680)
>>
>> "Low Memory Detector" daemon prio=5 tid=7ffd4409f000 nid=0x10bc3d000
>> runnable [00000000]
>>   java.lang.Thread.State: RUNNABLE
>>
>> "C2 CompilerThread1" daemon prio=9 tid=7ffd4409e800 nid=0x10bb3a000
>> waiting on condition [00000000]
>>   java.lang.Thread.State: RUNNABLE
>>
>> "C2 CompilerThread0" daemon prio=9 tid=7ffd4409d800 nid=0x10ba37000
>> waiting on condition [00000000]
>>   java.lang.Thread.State: RUNNABLE
>>
>> "Signal Dispatcher" daemon prio=9 tid=7ffd4409d000 nid=0x10b934000
>> waiting on condition [00000000]
>>   java.lang.Thread.State: RUNNABLE
>>
>> "Surrogate Locker Thread (Concurrent GC)" daemon prio=5 tid=7ffd4409c000
>> nid=0x10b831000 waiting on condition [00000000]
>>   java.lang.Thread.State: RUNNABLE
>>
>> "Finalizer" daemon prio=8 tid=7ffd44095800 nid=0x10b54f000 in
>> Object.wait() [10b54e000]
>>   java.lang.Thread.State: WAITING (on object monitor)
>>        at java.lang.Object.wait(Native Method)
>>        - waiting on <7f44e10c0> (a java.lang.ref.ReferenceQueue$Lock)
>>        at java.lang.ref.ReferenceQueue.remove(ReferenceQueue.java:118)
>>        - locked <7f44e10c0> (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)
>>
>> "Reference Handler" daemon prio=10 tid=7ffd44094800 nid=0x10b44c000 in
>> Object.wait() [10b44b000]
>>   java.lang.Thread.State: WAITING (on object monitor)
>>        at java.lang.Object.wait(Native Method)
>>        - waiting on <7f44e1ff8> (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 <7f44e1ff8> (a java.lang.ref.Reference$Lock)
>>
>> "main" prio=5 tid=7ffd44000800 nid=0x104aee000 waiting on condition
>> [104aed000]
>>   java.lang.Thread.State: TIMED_WAITING (parking)
>>        at sun.misc.Unsafe.park(Native Method)
>>        - parking to wait for  <7f44e2070> (a
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject)
>>        at
>> java.util.concurrent.locks.LockSupport.parkNanos(LockSupport.java:196)
>>        at
>> java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.awaitNanos(AbstractQueuedSynchronizer.java:2025)
>>        at
>> java.util.concurrent.ThreadPoolExecutor.awaitTermination(ThreadPoolExecutor.java:1253)
>>        at my.Prob.main(Prob.java:36)
>>
>> "VM Thread" prio=9 tid=7ffd42802800 nid=0x10b349000 runnable
>>
>> "Gang worker#0 (Parallel GC Threads)" prio=9 tid=7ffd44002000
>> nid=0x107e27000 runnable
>>
>> "Gang worker#1 (Parallel GC Threads)" prio=9 tid=7ffd44002800
>> nid=0x107f2a000 runnable
>>
>> "Concurrent Mark-Sweep GC Thread" prio=9 tid=7ffd4404d000 nid=0x10afef000
>> runnable
>> "VM Periodic Task Thread" prio=10 tid=7ffd440a1000 nid=0x10bd40000
>> waiting on condition
>>
>> "Exception Catcher Thread" prio=10 tid=7ffd44001800 nid=0x104c50000
>> runnable
>> JNI global references: 914
>>
>> Heap
>>  par new generation   total 19136K, used 5150K [7f3000000, 7f44c0000,
>> 7f44c0000)
>>  eden space 17024K,  30% used [7f3000000, 7f35078b8, 7f40a0000)
>>  from space 2112K,   0% used [7f40a0000, 7f40a0000, 7f42b0000)
>>  to   space 2112K,   0% used [7f42b0000, 7f42b0000, 7f44c0000)
>>  concurrent mark-sweep generation total 63872K, used 379K [7f44c0000,
>> 7f8320000, 7fae00000)
>>  concurrent-mark-sweep perm gen total 21248K, used 4811K [7fae00000,
>> 7fc2c0000, 800000000)
>>
>> 99999990000000, terminated ok
>> gwmac:~ gregg$ java -version
>> java version "1.6.0_29"
>> Java(TM) SE Runtime Environment (build 1.6.0_29-b11-402-11M3527)
>> Java HotSpot(TM) 64-Bit Server VM (build 20.4-b02-402, mixed mode)
>> gwmac:~ gregg$
>
>
>
>
>  --
>   -- Howard.
>
>  ------------------------------
>
> _______________________________________________
> Concurrency-interest mailing listConcurrency-interest at cs.oswego.eduhttp://cs.oswego.edu/mailman/listinfo/concurrency-interest
>
>


-- 
  -- Howard.
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://cs.oswego.edu/pipermail/concurrency-interest/attachments/20120108/d05796f9/attachment-0001.html>


More information about the Concurrency-interest mailing list