2015-10-07 10 views
24

Ich bin über ein ziemlich seltsames Problem gestolpert, das ich bei der Ausführung von Java 8 erstellen kann. Das Problem tritt auf, als ob irgendeine Art von Timing-Fehler in der JVM selbst auftritt. Es ist intermittierend, aber leicht reproduzierbar (zumindest in meinen Testumgebungen). Das Problem besteht darin, dass ein Array-Wert, der explizit festgelegt wird, zerstört und unter bestimmten Umständen durch eine 0.0 ersetzt wird. Insbesondere wird in dem folgenden Code array[0] auf 0.0 nach der Zeile new Double(r.nextDouble()); ausgewertet. Wenn Sie dann den Inhalt von array[0] erneut betrachten, wird der Wert jetzt als der korrekte Wert von 1.0 angezeigt. Beispiel für die Ausgabe dieses Testfalls vom Laufen ist:Java 8 seltsames Timing/Speicherproblem

claims array[0] != 1.0....array[0] = 1.0 
claims array[0] now == 1.0...array[0] = 1.0` 

Ich bin mit 64-Bit-Windows 7 und ist in der Lage, dieses Problem zu reproduzieren, sowohl innerhalb von Eclipse und wenn von der Kommandozeile kompiliert, mit JDKs 1.8_45, 1.8_51 und 1.8_60. Ich kann das Problem mit 1.7_51 nicht lösen. Die gleichen Ergebnisse wurden auf einer anderen 64-Bit-Windows 7-Box demonstriert.

Dieses Problem erschien in einer großen, nicht-trivialen Software, aber ich konnte es auf ein paar Zeilen Code reduzieren. Im Folgenden finden Sie einen kleinen Testfall, der das Problem veranschaulicht. Es ist ein ziemlich seltsam aussehender Testfall, scheint jedoch alle notwendig zu sein, um den Fehler zu verursachen. Die Verwendung von Random ist nicht erforderlich - ich kann alle r.nextDouble() mit jedem doppelten Wert ersetzen und das Problem demonstrieren. Interessanterweise, wenn someArray[0] = .45; durch someArray[0] = r.nextDouble(); ersetzt wird, konnte ich das Problem nicht replizieren (obwohl es nichts besonderes an .45 gibt). Eclipse-Debugging hilft auch nicht - es ändert das Timing so stark, dass es nicht mehr passiert. Selbst eine gut platzierte System.err.println()-Anweisung führt dazu, dass das Problem nicht mehr auftritt.

Wieder ist das Problem intermittierend, um das Problem reproduzieren zu können, muss dieser Testfall möglicherweise mehrmals ausgeführt werden. Ich glaube, ich musste es fast 10 mal laufen lassen, bevor ich die oben gezeigte Ausgabe bekomme. In Eclipse gebe ich eine Sekunde oder zwei nach dem Laufen und töte es dann, wenn es nicht passiert ist. Von der Kommandozeile aus - führen Sie es aus, wenn es nicht passiert CTRL+C zu beenden und erneut versuchen. Es scheint, dass wenn es passieren wird, es ziemlich schnell passiert.

Ich bin in der Vergangenheit auf Probleme wie diese gestoßen, aber sie waren alle Threading-Probleme. Ich kann mir nicht vorstellen, was hier vor sich geht - ich habe mir sogar den Bytecode angesehen (der übrigens zwischen 1.7_51 und 1.8_45 identisch war).

Irgendwelche Ideen, was hier passiert?

import java.util.Random; 

public class Test { 
    Test(){ 
     double array[] = new double[1];  
     Random r = new Random(); 

     while(true){ 
      double someArray[] = new double[1];   
      double someArray2 [] = new double [2]; 

      for(int i = 0; i < someArray2.length; i++) { 
       someArray2[i] = r.nextDouble(); 
      } 

      // for whatever reason, using r.nextDouble() here doesn't seem 
      // to show the problem, but the # you use doesn't seem to matter either... 

      someArray[0] = .45; 

      array[0] = 1.0; 

      // commented out lines also demonstrate problem 
      new Double(r.nextDouble()); 
      // new Float(r.nextDouble(); 
      // double d = new Double(.1) * new Double(.3); 
      // double d = new Double(.1)/new Double(.3); 
      // double d = new Double(.1) + new Double(.3); 
      // double d = new Double(.1) - new Double(.3); 

      if(array[0] != 1.0){ 
       System.err.println("claims array[0] != 1.0....array[0] = " + array[0]); 

       if(array[0] != 1.0){ 
        System.err.println("claims array[0] still != 1.0...array[0] = " + array[0]); 
       }else { 
        System.err.println("claims array[0] now == 1.0...array[0] = " + array[0]); 
       } 

       System.exit(0); 
      }else if(r.nextBoolean()){ 
       array = new double[1]; 
      } 
     } 
    } 

    public static void main(String[] args) { 
     new Test(); 
    } 
} 
+0

Haben Sie nach schlechtem Speicher gesucht? – wero

+3

Ich kann das nicht reproduzieren. Funktioniert wie erwartet hier. – marstran

+2

'double' ist inhärent nicht präzise. Sind Sie sicher, dass dies nicht Ihr Problem ist? –

Antwort

21

aktualisieren: scheint, dass meine ursprüngliche Antwort war falsch und OnStackReplacement ergab nur das Problem in diesem speziellen Fall, aber der ursprüngliche Fehler war in dem Analyse-Code zu entkommen. Die Escape-Analyse ist ein Compiler-Subsystem, das bestimmt, ob ein Objekt aus der gegebenen Methode entweicht oder nicht. Nicht maskierte Objekte können skaliert werden (statt einer Zuweisung auf dem Heap) oder vollständig optimiert werden. In unserem Test spielt die Escape-Analyse eine Rolle, da mehrere erstellte Objekte der Methode sicher nicht entkommen.

Ich heruntergeladen und installiert JDK 9 early access build 83 und bemerkte, dass der Fehler dort verschwindet. In JDK 9 existiert der frühe Zugriffsaufbau 82 jedoch immer noch. Die changelog zwischen b82 und b83 zeigt nur einen relevanten Bugfix (korrigieren Sie mich, wenn ich falsch liege): JDK-8134031 "Falsche JIT Kompilierung von komplexen Code mit Inlining und Escape-Analyse". Die committed testcase ist etwas ähnlich: große Schleife, mehrere Boxen (ähnlich Ein-Element-Arrays in unserem Test), die zu der plötzlichen Änderung des Wertes innerhalb der Box führen, so wird das Ergebnis stillschweigend falsch (kein Absturz, keine Ausnahme, nur falscher Wert).Wie in unserem Fall wird berichtet, dass das Problem nicht vor 8 Uhr 40 auftritt. Die introduced fix ist sehr kurz: nur eine Zeile Änderung in der Fluchtanalyse-Quelle.

Nach OpenJDK Bug-Tracker, ist das Update bereits backported zu JDK 8u72 Zweig, die scheduled ist im Januar veröffentlicht werden soll, 2016. Es scheint, dass es zu spät war dieses Update auf die kommenden 8u66 zurückzuzuportieren.

Die vorgeschlagene Problemumgehung besteht darin, die Escape-Analyse zu deaktivieren (-XX: -DoEscapeAnalysis) oder die Eliminierung der Zuordnungsoptimierung zu deaktivieren (-XX: -EliminateAllocations). Also @apangin was actually closer zur Antwort als ich.

Unten ist die Original Antwort


Zuerst habe ich das Problem mit JDK 8u25 nicht wiedergeben kann, kann aber auf JDK 8u40 und 8u60: manchmal läuft es richtig (in Endlosschleife hängen), manchmal gibt sie und beendet. Wenn JDK Downgrade auf 8u25 für Sie akzeptabel ist, können Sie dies in Erwägung ziehen. Beachten Sie, dass Sie, wenn Sie später Fixes in javac benötigen (viele Dinge, die insbesondere labdas betreffen, in 1.8u40 behoben wurden), können Sie mit neueren Java-Programmen kompilieren, aber mit älteren JVM-Versionen.

Für mich scheint es, dass dieses spezielle Problem wahrscheinlich ein Fehler in OnStackReplacement Mechanismus ist (wenn OSR auf Stufe 4 auftritt). Wenn Sie mit OSR nicht vertraut sind, lesen Sie möglicherweise this answer. Der OSR tritt in Ihrem Fall sicher auf, aber auf eine etwas eigenartige Weise. Hier ist -XX:+UnlockDiagnosticVMOptions -XX:+PrintCompilation -XX:+TraceNMethodInstalls für gescheiterte run (% bedeutet OSR JIT, @ 28 bedeutet OSR Bytecode-Position, (3) und (4) bedeutet Tier-Ebene):

... 
    91 37 %  3  Test::<init> @ 28 (194 bytes) 
Installing osr method (3) Test.<init>()V @ 28 
    93 38  3  Test::<init> (194 bytes) 
Installing method (3) Test.<init>()V 
    94 39 %  4  Test::<init> @ 16 (194 bytes) 
Installing osr method (4) Test.<init>()V @ 16 
    102 40 %  4  Test::<init> @ 28 (194 bytes) 
    103 39 %  4  Test::<init> @ -2 (194 bytes) made not entrant 
... 
Installing osr method (4) Test.<init>()V @ 28 
    113 37 %  3  Test::<init> @ -2 (194 bytes) made not entrant 
claims array[0] != 1.0....array[0] = 1.0 
claims array[0] now == 1.0...array[0] = 1.0 

Somit wird die OSR bei Tier4 auftritt für zwei unterschiedliche Bytecode-Offsets: Offset 16 (die die ist while Loop-Entry-Punkt) und Offset 28 (das ist der verschachtelte for Loop-Entry-Punkt). Es scheint, dass während des Kontexttransfers zwischen den beiden OSR-kompilierten Versionen Ihrer Methode eine Race-Bedingung auftritt, die zu einem fehlerhaften Kontext führt. Wenn die Ausführung an die OSR-Methode übergeben wird, sollte sie den aktuellen Kontext einschließlich der Werte der lokalen Variablen wie array und r in die OSR-Methode übertragen. Etwas Schlimmes passiert hier: wahrscheinlich für eine kurze Zeit <init>@16 OSR-Version funktioniert, dann ist es mit <init>@28 ersetzt, aber der Kontext wird mit einer kleinen Verzögerung aktualisiert. Es ist wahrscheinlich, dass die Übertragung von OSR-Kontexten die Optimierung "Eliminierung von Zuweisungen" beeinträchtigt (wie von @apangin bemerkt, hilft das Ausschalten dieser Optimierung in Ihrem Fall). Meine Expertise reicht nicht aus, um hier weiter zu graben, wahrscheinlich @apangin mag kommentieren.

Im Gegensatz im normalen Laufe nur eine Kopie von Stufe 4 OSR-Methode erstellt und installiert:

... 
Installing method (3) Test.<init>()V 
    88 43 %  4  Test::<init> @ 28 (194 bytes) 
Installing osr method (4) Test.<init>()V @ 28 
    100 40 %  3  Test::<init> @ -2 (194 bytes) made not entrant 
    4592 44  3  java.lang.StringBuilder::append (8 bytes) 
... 

scheint also, dass kein Rennen zwischen zwei OSR-Versionen in diesem Fall auftreten, und alles funktioniert perfekt.

Das Problem verschwindet auch, wenn Sie die äußeree Schleife zu dem separaten Verfahren zu bewegen:

import java.util.Random; 

public class Test2 { 
    private static void doTest(double[] array, Random r) { 
     double someArray[] = new double[1]; 
     double someArray2[] = new double[2]; 

     for (int i = 0; i < someArray2.length; i++) { 
      someArray2[i] = r.nextDouble(); 
     } 

     ... // rest of your code 
    } 

    Test2() { 
     double array[] = new double[1]; 
     Random r = new Random(); 

     while (true) { 
      doTest(array, r); 
     } 
    } 

    public static void main(String[] args) { 
     new Test2(); 
    } 
} 

auch manuell die verschachtelten for Schleifenentrollen entfernt den Fehler:

int i=0; 
someArray2[i++] = r.nextDouble(); 
someArray2[i++] = r.nextDouble(); 

diesen Fehler trifft es scheint, dass Sie mindestens zwei verschachtelte Schleifen in der gleichen Methode haben sollten, so dass OSR an verschiedenen Bytecode-Positionen auftreten kann.Um das Problem in Ihrem Code zu lösen, können Sie einfach dasselbe tun: extrahieren Sie den Schleifenkörper in die separate Methode.

Eine alternative Lösung besteht darin, den OSR vollständig mit -XX:-UseOnStackReplacement zu deaktivieren. Es hilft selten im Produktionscode. Schleifenzähler funktionieren immer noch und wenn Ihre Methode mit many-iterations-loop mindestens zweimal aufgerufen wird, wird der zweite Lauf sowieso JIT-kompiliert. Auch wenn Ihre Methode mit langer Schleife aufgrund deaktiviertem OSR nicht JIT-kompiliert wird, werden alle von ihr aufgerufenen Methoden trotzdem JIT-kompiliert.

+0

Gute Arbeit. Bitte fügen Sie dies in den Fehlerbericht ein, da dies den JDK-Entwicklern helfen könnte, das Problem zu beheben. Ich würde +2 geben, wenn ich könnte ... :-) – Axel

+0

Ja, on-stack replacement hilft, wenn Sie große, lang laufende Methoden haben, deren Code leistungsrelevant ist, ein Muster, das nicht mit typischem Anwendungscode übereinstimmt, aber typisch künstlicher Benchmark-Code. – Holger

+0

Wow, tolle Arbeit! Ich hatte den Fehlerbericht bereits eingereicht und wird noch überprüft. Vorausgesetzt, ich kann Informationen hinzufügen, wenn/falls es akzeptiert wird, werde ich das sicher hinzufügen. Danke noch einmal! – bcothren

0

ich diesen Fehler in Zulu wiedergeben kann (ein geprüftes Build von OpenJDK) mit dem entsandten Code bei http://www.javaspecialists.eu/archive/Issue234.html

Mit dem Oracle VM, kann ich nur diesen Fehler reproduzieren, nachdem ich den Code in Zulu ausgeführt habe. Es scheint, als würde Zulu den Cache für gemeinsame Suche kontaminieren. Die Lösung in diesem Fall besteht darin, den Code mit -XX: -EnableSharedLookupCache auszuführen.

+1

Azul hat 2 JVMs Zulu und Zing. Von dem Link, den Sie angeben (was kaputt ist), scheint es, dass Sie sich auf Zulu beziehen, nicht auf Zing. Zulu ist ein OpenJDK-Build, der vollständig OpenJDK-Code, aber getestet und unterstützt. Es sollte das gleiche Verhalten für die vergleichbare Version aufweisen. Zing ist ein ganz anderes Tier. –