search

runtimeverification / rv-predict

Code for improved rv-predict and installer
BSD 3-Clause "New" or "Revised" License
2 stars 3 forks source link

Java instrumentation error in RV-Predict? #782

Closed traiansf closed 7 years ago

traiansf commented 7 years ago

@grosu FYI @yilongli I think you're still the most knowledgable w.r.t. that part of the code. Could you please take a look at it? I'm wondering whether there could be two agents modifying the code concurrently (one being ours, the other being TestNG)

I was trying to use rv-predict to address Darko's quickml question, when I got what it seems like an instrumentation error:

Running quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest
Configuring TestNG with: TestNG652Configurator
...
java.lang.VerifyError: Stack map does not match the one at exception handler 109
Exception Details:
  Location:
    quickml/supervised/ensembles/randomForest/randomDecisionForest/RandomDecisionForestBuilder.<init>()V @109: sipush
  Reason:
    Current frame's flags are not assignable to stack map frame's.
  Current Frame:
    bci: @97
    flags: { flagThisUninit }
    locals: { uninitializedThis }
    stack: { 'java/lang/Throwable' }
  Stackmap Frame:
    bci: @109
    flags: { }
    locals: { }
    stack: { 'java/lang/Throwable' }
  Bytecode:
    0x0000000: 2abb 0002 59b7 0003 bb00 0459 1400 0511
    0x0000010: 48cb b801 1bb7 0007 1148 cbb8 011e a700
    0x0000020: 0a11 48cb b801 1ebf 1148 cbb8 011b b600
    0x0000030: 0811 48cb b801 1ea7 000a 1148 cbb8 011e
    0x0000040: bf08 1148 cbb8 011b b600 0911 48cb b801
    0x0000050: 1ea7 000a 1148 cbb8 011e bf11 48cb b801
    0x0000060: 1bb7 000a 1148 cbb8 011e a700 0a11 48cb
    0x0000070: b801 1ebf b1                           
  Exception Handler Table:
    bci [21, 33] => handler: 33
    bci [46, 58] => handler: 58
    bci [72, 84] => handler: 84
    bci [97, 109] => handler: 109
  Stackmap Table:
    same_locals_1_stack_item_frame(@33,Object[#288])
    full_frame(@40,{UninitializedThis},{UninitializedThis,Object[#2],Object[#4]})
    same_locals_1_stack_item_frame(@58,Object[#288])
    full_frame(@65,{UninitializedThis},{UninitializedThis,Object[#2]})
    same_locals_1_stack_item_frame(@84,Object[#288])
    full_frame(@91,{UninitializedThis},{UninitializedThis,Object[#2]})
    full_frame(@109,{},{Object[#288]})
    append_frame(@116,Object[#62])

    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest.mockTreeTest(DecisionOldOldTreeBuilderTest.java:87)

Reproduction steps:

cd /tmp
git clone https://github.com/sanity/quickml
cd quickml
git checkout 2b348d549c4752dbbd5f6432a454c39f6d40f0ec
mvn install -DskipTests

Followed by modifying pom.xml according to this diff:

diff --git a/pom.xml b/pom.xml
index ee02f5e..ada8d96 100644
--- a/pom.xml
+++ b/pom.xml
@@ -192,7 +192,7 @@
                 <artifactId>maven-surefire-plugin</artifactId>
                 <version>2.16</version>
                 <configuration>
-                    <argLine>-Xmx256M</argLine>
+                    <argLine>-Xmx256M -javaagent:/home/traian/Documents/rv-predict/target/release/rv-predict/rv-predict.jar</argLine>
                 </configuration>
             </plugin>
             <plugin>

Followed by 

mvn surefire:test -Dtest=DecisionOldOldTreeBuilderTest

Resulted in a run exhibiting errors like the one at the top.

traiansf commented 7 years ago

Per @yilongli observation: This is a duplicate of https://runtimeverification.com/support/predict/issues/264

traiansf commented 7 years ago

Taking @yilongli 's suggestion, I disabled some instrumentation on the classes which were causing errors like the above:

diff --git a/rv-predict-source/src/main/java/com/runtimeverification/rvpredict/instrument/transformer/MethodTransformer.java b/rv-predict-source/src/main/java/com/runtimeverification/rvpredict/instrument/transformer/MethodTransformer.java
index cd4b53a..19bef8b 100644
--- a/rv-predict-source/src/main/java/com/runtimeverification/rvpredict/instrument/transformer/MethodTransformer.java
+++ b/rv-predict-source/src/main/java/com/runtimeverification/rvpredict/instrument/transformer/MethodTransformer.java
@@ -281,7 +281,7 @@ public class MethodTransformer extends MethodVisitor implements Opcodes {
                 }
             }
         } else {
-            if (owner.startsWith("[") || isSelfCtorCall || !strategy.logCallStackEvent()) {
+            if (owner.startsWith("[") || isSelfCtorCall || !strategy.logCallStackEvent() || owner.contains("RandomDecisionForestBuilder") || owner.contains("OldTreeBuilder")) {
                 mv.visitMethodInsn(opcode, owner, name, desc, itf);
                 return;
             }

And rv-predict managed to predict some races:

Data race on field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.minSplitFraction: {{{
    Concurrent read in thread T17 (locks held: {Monitor@36b12d79, Monitor@3d34d211})
 ---->  at quickml.supervised.tree.branchingConditions.StandardBranchingConditions.copy(StandardBranchingConditions.java:114)
        - locked Monitor@3d34d211 at quickml.supervised.tree.branchingConditions.StandardBranchingConditions.copy(StandardBranchingConditions.java:n/a) 
        at quickml.supervised.tree.branchFinders.branchFinderBuilders.BranchFinderBuilder.copy(BranchFinderBuilder.java:71)
        at quickml.supervised.tree.decisionTree.treeBuildContexts.DTreeContextBuilder.copyBranchFinderBuilders(DTreeContextBuilder.java:82)
        at quickml.supervised.tree.decisionTree.treeBuildContexts.DTreeContextBuilder.deepCopyConfig(DTreeContextBuilder.java:196)
        at quickml.supervised.tree.decisionTree.treeBuildContexts.DTreeContextBuilder.copy(DTreeContextBuilder.java:72)
        - locked Monitor@36b12d79 at quickml.supervised.tree.decisionTree.treeBuildContexts.DTreeContextBuilder.copy(DTreeContextBuilder.java:n/a) 
        at quickml.supervised.tree.TreeBuilderHelper.<init>(TreeBuilderHelper.java:27)
        at quickml.supervised.tree.decisionTree.DecisionTreeBuilder.buildPredictiveModel(DecisionTreeBuilder.java:52)
        at quickml.supervised.ensembles.randomForest.randomDecisionForest.RandomDecisionForestBuilder.buildModel(RandomDecisionForestBuilder.java:92)
    T17 is created by T1
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:1028)

    Concurrent write in thread T19 (locks held: {})
 ---->  at quickml.supervised.tree.branchingConditions.StandardBranchingConditions.update(StandardBranchingConditions.java:107)
        at quickml.supervised.tree.treeBuildContexts.TreeContextBuilder.updateEachConfigElement(TreeContextBuilder.java:78)
        at quickml.supervised.tree.treeBuildContexts.TreeContextBuilder.initializeConfig(TreeContextBuilder.java:96)
        at quickml.supervised.tree.decisionTree.DecisionTreeBuilder.buildPredictiveModel(DecisionTreeBuilder.java:51)
        at quickml.supervised.ensembles.randomForest.randomDecisionForest.RandomDecisionForestBuilder.buildModel(RandomDecisionForestBuilder.java:92)
    T19 is created by T1
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:1028)
}}}

Same for field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.minScore
Same for field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.minSplitFraction
Same for field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.minLeafInstances
Same for field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.maxDepth

Data race on field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.minScore: {{{
    Concurrent write in thread T17 (locks held: {})
 ---->  at quickml.supervised.tree.branchingConditions.StandardBranchingConditions.update(StandardBranchingConditions.java:103)
        at quickml.supervised.tree.treeBuildContexts.TreeContextBuilder.updateEachConfigElement(TreeContextBuilder.java:78)
        at quickml.supervised.tree.treeBuildContexts.TreeContextBuilder.initializeConfig(TreeContextBuilder.java:96)
        at quickml.supervised.tree.decisionTree.DecisionTreeBuilder.buildPredictiveModel(DecisionTreeBuilder.java:51)
        at quickml.supervised.ensembles.randomForest.randomDecisionForest.RandomDecisionForestBuilder.buildModel(RandomDecisionForestBuilder.java:92)
    T17 is created by T1
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:1028)

    Concurrent write in thread T19 (locks held: {})
 ---->  at quickml.supervised.tree.branchingConditions.StandardBranchingConditions.update(StandardBranchingConditions.java:103)
        at quickml.supervised.tree.treeBuildContexts.TreeContextBuilder.updateEachConfigElement(TreeContextBuilder.java:78)
        at quickml.supervised.tree.treeBuildContexts.TreeContextBuilder.initializeConfig(TreeContextBuilder.java:96)
        at quickml.supervised.tree.decisionTree.DecisionTreeBuilder.buildPredictiveModel(DecisionTreeBuilder.java:51)
        at quickml.supervised.ensembles.randomForest.randomDecisionForest.RandomDecisionForestBuilder.buildModel(RandomDecisionForestBuilder.java:92)
    T19 is created by T1
        at java.util.concurrent.ThreadPoolExecutor.addWorker(ThreadPoolExecutor.java:1028)
}}}

Same for field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.minLeafInstances
Same for field quickml.supervised.tree.branchingConditions.StandardBranchingConditions.maxDepth
traiansf commented 7 years ago

This seems to indicate that the StandardBranchingConditions fields could be updated simultaneously by two threads. The question is whether two threads would attempt to put different information

traiansf commented 7 years ago

W.r.t. the error: @yilongli recalled he has previously encountered it, and it might be an ASM / JDK bug: http://forge.ow2.org/tracker/?group_id=23&atid=100023&func=detail&aid=317583

traiansf commented 7 years ago

Related to this particular example, this is one of the ways the test can fail:

java.lang.AssertionError: attribute: ecp.  branch.getProbabilityOfTrueChild(): 0.9
    at org.junit.Assert.fail(Assert.java:88)
    at org.junit.Assert.assertTrue(Assert.java:41)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest$Conditions.satisfiesBranchConditions(DecisionOldOldTreeBuilderTest.java:159)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest$Conditions.satisfiesConditions(DecisionOldOldTreeBuilderTest.java:152)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest.recurseTree(DecisionOldOldTreeBuilderTest.java:127)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest.recurseTree(DecisionOldOldTreeBuilderTest.java:130)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest.recurseTree(DecisionOldOldTreeBuilderTest.java:130)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest.recurseTree(DecisionOldOldTreeBuilderTest.java:129)
    at quickml.supervised.tree.decisionTree.DecisionOldOldTreeBuilderTest.mockTreeTest(DecisionOldOldTreeBuilderTest.java:91)

which I guess it could fail due to the above mentioned races.