llmhyy / microbat

A feedback-based debugger for interactively recommending suspicious step in buggy program execution.
55 stars 16 forks source link

[Agent] Lang-13: store trace fail with java.io.ObjectStreamClass being instrumented. #170

Closed lylytran closed 6 years ago

lylytran commented 6 years ago

lang-13-bug.txt E:\lyly\Projects\microbat\jdk\jdk1.7.0_80\bin\java -XX:+UseG1GC -Xmx30g -ea -noverify -javaagent:E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\instrumentator.jar=precheck=false,java_home=E:\lyly\Projects\microbat\jdk\jdk1.7.0_80,stepLimit=100000,log=printProgress;info;debug;error,require_method_split=false,working_dir=E:\linyun\bug_repo\Lang\13\bug,varLayer=2,includes=java.io.ObjectInputStream;java.io.InputStream;org.apache.commons.lang3.SerializationUtils$ClassLoaderAwareObjectInputStream;java.io.Serializable;java.lang.RuntimeException;java.lang.Exception;java.lang.Throwable;org.apache.commons.lang3.SerializationException;java.lang.Thread;java.lang.ClassLoader;java.lang.System;sun.reflect.Reflection;java.lang.Class;java.security.BasicPermission;java.security.Permission;java.lang.RuntimePermission;java.lang.SecurityManager;java.lang.ReflectiveOperationException;java.lang.ClassNotFoundException;java.io.ObjectStreamClass;java.io.ByteArrayInputStream;java.util.Map;java.util.Properties;java.util.WeakHashMap;java.util.HashMap;java.util.jar.Attributes;java.util.Collections$EmptyMap;java.util.Hashtable;java.util.AbstractMap;java.lang.ClassValue$ClassValueMap;java.util.LinkedHashMap;java.util.Collections$SingletonMap;java.io.ObjectInputStream$BlockDataInputStream;java.io.ObjectInputStream$HandleTable;java.io.ObjectInputStream$ValidationList,launch_class=org.apache.commons.lang3.SerializationUtilsTest,class_path=E:\linyun\bug_repo\Lang\13\bug\target\tests;E:\linyun\bug_repo\Lang\13\bug\target\classes;E:\linyun\bug_repo\Lang\lib\cglib-nodep-2.2.2.jar;E:\linyun\bug_repo\Lang\lib\commons-io-2.4.jar;E:\linyun\bug_repo\Lang\lib\easymock-3.1.jar;E:\linyun\bug_repo\Lang\lib\objenesis-1.2.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\junit.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\org.hamcrest.core.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\testrunner.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\bcel-6.0.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\javassist.jar,dump_file_path=E:\lyly\bug.exec,expectedSteps=46 -cp E:\linyun\bug_repo\Lang\13\bug\target\tests;E:\linyun\bug_repo\Lang\13\bug\target\classes;E:\linyun\bug_repo\Lang\lib\cglib-nodep-2.2.2.jar;E:\linyun\bug_repo\Lang\lib\commons-io-2.4.jar;E:\linyun\bug_repo\Lang\lib\easymock-3.1.jar;E:\linyun\bug_repo\Lang\lib\objenesis-1.2.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\junit.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\org.hamcrest.core.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\testrunner.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\bcel-6.0.jar;E:\lyly\eclipse-java-mars-clean\eclipse-for-unmodified-code\dropins\junit_lib\javassist.jar microbat.evaluation.junit.MicroBatTestRunner org.apache.commons.lang3.SerializationUtilsTest testPrimitiveTypeClassSerialization

NOTE: The problem might because of instrumenting java.io.ObjectStreamClass, but the behavior is hard to diagnose, it does not always happen, and seems like it won't happen if there's some time delays.

java.lang.NullPointerException at java.io.ObjectStreamClass$FieldReflector.getObjFieldValues(ObjectStreamClass.java:2046) at java.io.ObjectStreamClass.getObjFieldValues(ObjectStreamClass.java:1252) at java.io.ObjectOutputStream.defaultWriteFields(ObjectOutputStream.java:1538) at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1508) at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431) at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177) at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347) at java.util.ArrayList.writeObject(ArrayList.java:742) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:988) at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1495) at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431) at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177) at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347) at java.util.ArrayList.writeObject(ArrayList.java:742) at sun.reflect.GeneratedMethodAccessor1.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:606) at java.io.ObjectStreamClass.invokeWriteObject(ObjectStreamClass.java:988) at java.io.ObjectOutputStream.writeSerialData(ObjectOutputStream.java:1495) at java.io.ObjectOutputStream.writeOrdinaryObject(ObjectOutputStream.java:1431) at java.io.ObjectOutputStream.writeObject0(ObjectOutputStream.java:1177) at java.io.ObjectOutputStream.writeObject(ObjectOutputStream.java:347) at microbat.instrumentation.output.ByteConverter.convertToBytes(ByteConverter.java:20) at microbat.instrumentation.output.TraceOutputWriter.writeVarValues(TraceOutputWriter.java:189) at microbat.instrumentation.output.TraceOutputWriter.writeSteps(TraceOutputWriter.java:172) at microbat.instrumentation.output.TraceOutputWriter.writeTrace(TraceOutputWriter.java:90) at microbat.instrumentation.output.TraceOutputWriter.writeTrace(TraceOutputWriter.java:46) at microbat.instrumentation.output.RunningInfo.saveToFile(RunningInfo.java:75) at microbat.instrumentation.TraceAgent.writeOutput(TraceAgent.java:84) at microbat.instrumentation.TraceAgent.shutdown(TraceAgent.java:65) at microbat.instrumentation.Agent.stop(Agent.java:46) at microbat.instrumentation.Agent._exitProgram(Agent.java:35) at microbat.evaluation.junit.MicroBatTestRunner.$exitProgram(MicroBatTestRunner.java:77) at microbat.evaluation.junit.MicroBatTestRunner.runTest(MicroBatTestRunner.java:64) at microbat.evaluation.junit.MicroBatTestRunner.main(MicroBatTestRunner.java:28)

llmhyy commented 6 years ago

Shall we finish this by Jun 8?

lylytran commented 6 years ago

fixed.