United StatesChange Country, Oracle Worldwide Web Sites Communities I am a... I want to...
Bug ID: JDK-7176993 The synchronize keyword is not honored in this very specific case
JDK-7176993 : The synchronize keyword is not honored in this very specific case

Details
Type:
Bug
Submit Date:
2012-06-14
Status:
Closed
Updated Date:
2014-04-14
Project Name:
JDK
Resolved Date:
2014-02-03
Component:
hotspot
OS:
windows_7
Sub-Component:
compiler
CPU:
x86
Priority:
P2
Resolution:
Fixed
Affected Versions:
6u31
Fixed Versions:
6u81 (b01)

Related Reports

Sub Tasks

Description
FULL PRODUCT VERSION :
java version "1.6.0_24"
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Java HotSpot(TM) 64-Bit Server VM (build 19.1-b02, mixed mode)

Others have said it fails on other versions of 6, but not on 7.  Appears to be 64-bit only.

ADDITIONAL OS VERSION INFORMATION :
Microsoft Windows [Version 6.1.7601]

EXTRA RELEVANT SYSTEM CONFIGURATION :
Intel Core i7 X980 CPU

A DESCRIPTION OF THE PROBLEM :
In the example, which I provide below, the `synchronized` keyword is used to protect concurrent access to a class.  One function sets a boolean to true upon entry and false upon exit.  The other function checks that boolean upon entry.  Given that both of these functions are `synchronized`, the boolean should never be true when checked in the other function.  However that does not appear to be the case.

STEPS TO FOLLOW TO REPRODUCE THE PROBLEM :
The bug is detailed in the stack overflow question here:
http://stackoverflow.com/questions/10982941/java-synchronization-not-working-as-expected

Another user has created a simplified version contained in a single class file that is here:
http://pastebin.com/AF85FRT7

The complete source is also included below.



EXPECTED VERSUS ACTUAL BEHAVIOR :
EXPECTED -
Given the expected behavior of the `synchronized` keyword, I would expect `errorC` to be 0 (in the example from the pastebin link) when the application is done running.
ACTUAL -
On my machine, when I run the `main` from the pastebin link I get the following:
Exception in thread "main" java.lang.AssertionError: expected:<0> but was:<412601>
	at org.junit.Assert.fail(Assert.java:91)
	at org.junit.Assert.failNotEquals(Assert.java:645)
	at org.junit.Assert.assertEquals(Assert.java:126)
	at org.junit.Assert.assertEquals(Assert.java:470)
	at org.junit.Assert.assertEquals(Assert.java:454)
	at testing.StrangeRaceConditionTest.strangeRaceConditionTest(StrangeRaceConditionTest.java:59)
	at testing.StrangeRaceConditionTest.main(StrangeRaceConditionTest.java:33)


REPRODUCIBILITY :
This bug can be reproduced often.

---------- BEGIN SOURCE ----------
    package com.mprew.be.service.x;
     
    import static org.junit.Assert.assertEquals;
     
    import java.util.ArrayList;
    import java.util.HashMap;
    import java.util.List;
    import java.util.Map;
    import java.util.Timer;
    import java.util.TimerTask;
     
    import org.junit.Test;
     
    /**
     * This is an interesting test case that seems to be indicating a JRE issue.
     *
     * This comes from http://stackoverflow.com/q/10982941/179850 and the poster named "Luke".
     *
     * I've boiled the code down to its lowest level and added some comments around the changes that can change the error
     * count. This is pretty repeatable to me with 4/5 runs generating errors. If you can't get it to fail I'd try
     * decreasing the fixed-rate period and increasing the NUMBER_TO_USE constant.
     */
    public class StrangeRaceConditionTest {
     
            // if this is decreased it may remove the errors
            public static final int NUMBER_TO_USE = 1000000;
     
            private Map<Integer, Buffer> bufferMap = new HashMap<Integer, Buffer>();
     
            public static void main(String[] args) {
                    new StrangeRaceConditionTest().strangeRaceConditionTest();
            }
     
            @Test
            public void strangeRaceConditionTest() {
                    final Buffer buffer = getBuffer();
     
                    TimerTask getBufferTask = new TimerTask() {
                            @Override
                            public void run() {
                                    buffer.getBuffer();
                            }
                    };
                    // if the period is increased it seems to reduce the errors
                    new Timer(true).scheduleAtFixedRate(getBufferTask, 0 /* delay ms */, 10 /* period ms */);
     
                    for (long i = 0; i < NUMBER_TO_USE; i++) {
                            // if we inline the remove() method here then no errors
                            // if we change this to buffer.remove() then no errors
                            remove();
                    }
     
                    assertEquals(0, buffer.getErrorC());
            }
     
            private synchronized void remove() {
                    Buffer buffer = getBuffer();
                    buffer.remove();
            }
     
            private synchronized Buffer getBuffer() {
                    // if we remove this whole map nonesense then no errors
                    Buffer buffer = bufferMap.get(1);
                    // if this test/else is flipped so it is buffer == null ... then no errors
                    if (buffer != null) {
                            // if this line is commented out then no errors
                            buffer = bufferMap.get(1);
                    } else {
                            buffer = new Buffer();
                            bufferMap.put(1, buffer);
                    }
                    return buffer;
            }
     
            // moving this out to its own class file doesn't seem to help
            private static class Buffer {
                    private List<Integer> list = new ArrayList<Integer>();
                    private boolean insideGetBuffer = false;
                    private int errorC = 0;
     
                    public Buffer() {
                            // initialize the list
                            for (long i = 0; i < NUMBER_TO_USE; i++) {
                                    list.add(null);
                            }
                    }
     
                    public synchronized void remove() {
                            if (insideGetBuffer) {
                                    // adding a System.out.println here makes the problem more repeatable
                                    // System.out.println("How did we get here?");
                                    errorC++;
                            }
                    }
     
                    public synchronized void getBuffer() {
                            insideGetBuffer = true;
                            try {
                                    // if you comment out this sleep then no errors
                                    Thread.sleep(5);
                            } catch (Exception e) {
                                    e.printStackTrace();
                            } finally {
                                    insideGetBuffer = false;
                            }
                    }
     
                    public synchronized int getErrorC() {
                            return errorC;
                    }
            }
    }

---------- END SOURCE ----------

CUSTOMER SUBMITTED WORKAROUND :
The problem seems to go away if you used synchronized(list){...} instead of synchronizing on `this` or using the function level `synchronized` keyword.

                                    

Comments
EVALUATION

Reproduced with VM upto HS23 b06, the test does not fail after HS23 b08. Failed only with enabled EA and lock elimination. Test passed if run with -XX:-EliminateLocks or -XX-DoEscapeAnalysis. It seems, EA incorrectly eliminated locks:

% /java/re/jdk/8/promoted/all/b15/binaries/solaris-amd64/fastdebug/bin/java -showversion -d64 -XX:+PrintCompilation -XX:+PrintInlining -XX:-TieredCompilation -Xbatch -XX:CICompilerCount=1 -XX:+PrintEliminateLocks -XX:+EliminateLocks StrangeRaceConditionTest

java version "1.8.0-ea-fastdebug"
Java(TM) SE Runtime Environment (build 1.8.0-ea-fastdebug-b15)
Java HotSpot(TM) 64-Bit Server VM (build 23.0-b06-fastdebug, mixed mode)
...
   5187    9  s b        StrangeRaceConditionTest::remove (10 bytes)
              s             @ 1   StrangeRaceConditionTest::getBuffer (66 bytes)   already compiled into a big method
              s             @ 6   StrangeRaceConditionTest$Buffer::remove (18 bytes)   inline (hot)
++++ Eliminating: 105 Unlock
++++ Eliminating: 70 Lock
   5196   10  s b        StrangeRaceConditionTest$Buffer::remove (18 bytes)
   5201    2 %  b        StrangeRaceConditionTest::strangeRaceConditionTest @ 36 (103 bytes)
              s             @ 46   StrangeRaceConditionTest::remove (10 bytes)   inline (hot)
              s               @ 1   StrangeRaceConditionTest::getBuffer (66 bytes)   already compiled into a big method
              s               @ 6   StrangeRaceConditionTest$Buffer::remove (18 bytes)   inline (hot)
               !m           @ 59   java.util.Timer::cancel (40 bytes)   too big
              s             @ 63   StrangeRaceConditionTest$Buffer::getErrorC (5 bytes)   inline (hot)
++++ Eliminating: 263 Unlock
++++ Eliminating: 231 Lock
   5308    2 %           StrangeRaceConditionTest::strangeRaceConditionTest @ -2 (103 bytes)   made not entrant
FAILED 515470 times
                                     
2012-06-28
EVALUATION

The test stoped failing after the fix for next bug which fixed several problems in EA:

7112478: after 7105605 JRuby bench_define_method_methods.rb fails with NPE.

We need to backport the fix into jdk 6.
                                     
2012-06-28
SUGGESTED FIX

Next part of 7112478 changes  was enough for the test to pass. But I would suggest to backport full 7112478 fix.

diff -r 6078bcb7f798 src/share/vm/ci/bcEscapeAnalyzer.cpp
--- a/src/share/vm/ci/bcEscapeAnalyzer.cpp	Mon Jun 25 21:25:09 2012 +0200
+++ b/src/share/vm/ci/bcEscapeAnalyzer.cpp	Wed Jun 27 18:16:49 2012 -0700
@@ -150,11 +150,23 @@
   clear_bits(vars, _arg_local);
 }
 
-void BCEscapeAnalyzer::set_global_escape(ArgumentMap vars) {
+void BCEscapeAnalyzer::set_global_escape(ArgumentMap vars, bool merge) {
   clear_bits(vars, _arg_local);
   clear_bits(vars, _arg_stack);
   if (vars.contains_allocated())
     _allocated_escapes = true;
+
+  if (merge && !vars.is_empty()) {
+    // Merge new state into already processed block.
+    // New state is not taken into account and
+    // it may invalidate set_returned() result.
+    if (vars.contains_unknown() || vars.contains_allocated()) {
+      _return_local = false;
+    }
+    if (vars.contains_unknown() || vars.contains_vars()) {
+      _return_allocated = false;
+    }
+  }
 }
 
 void BCEscapeAnalyzer::set_dirty(ArgumentMap vars) {
@@ -998,7 +1010,7 @@
       t.set_difference(d_state->_stack[i]);
       extra_vars.set_union(t);
     }
-    set_global_escape(extra_vars);
+    set_global_escape(extra_vars, true);
   }
 }
 
diff -r 6078bcb7f798 src/share/vm/ci/bcEscapeAnalyzer.hpp
--- a/src/share/vm/ci/bcEscapeAnalyzer.hpp	Mon Jun 25 21:25:09 2012 +0200
+++ b/src/share/vm/ci/bcEscapeAnalyzer.hpp	Wed Jun 27 18:16:49 2012 -0700
@@ -81,7 +81,7 @@
   bool is_arg_stack(ArgumentMap vars);
   void clear_bits(ArgumentMap vars, VectorSet &bs);
   void set_method_escape(ArgumentMap vars);
-  void set_global_escape(ArgumentMap vars);
+  void set_global_escape(ArgumentMap vars, bool merge = false);
   void set_dirty(ArgumentMap vars);
   void set_modified(ArgumentMap vars, int offs, int size);
                                     
2012-06-28
EVALUATION

Note that 7112478 was fixed in jdk7u4 and jdk8. So latest version of VM does not have this problem.
                                     
2012-06-28
I'd say ILW: HLH => P2. Fix exists, probably only need to backport
                                     
2013-11-18
does this bug need a 7-na label ?
                                     
2014-04-10



Hardware and Software, Engineered to Work Together