rjust / defects4j

A Database of Real Faults and an Experimental Infrastructure to Enable Controlled Experiments in Software Engineering Research
MIT License
735 stars 301 forks source link

Unhandled exception in script #489

Open claudeyj opened 2 years ago

claudeyj commented 2 years ago

Hi Professors,

I was trying to run some experiment with defects4j's major mutation testing framework and I have observed some wierd cases. For example, when applying the below mutant as patch, defects4j test should report failing tests but it crashed!

diff --git a/src/main/java/com/fasterxml/jackson/databind/ser/std/ObjectArraySerializer.java b/src/main/java/com/fasterxml/jackson/databind/ser/std/ObjectArraySerializer.java
index 894bfc3b6..d342cd416 100644
--- a/src/main/java/com/fasterxml/jackson/databind/ser/std/ObjectArraySerializer.java
+++ b/src/main/java/com/fasterxml/jackson/databind/ser/std/ObjectArraySerializer.java
@@ -288,7 +288,7 @@ public class ObjectArraySerializer
     {
         final int len = value.length;
         final TypeSerializer typeSer = _valueTypeSerializer;
-        int i = 0;
+        int i = -1;
         Object elem = null;
         try {
             PropertySerializerMap serializers = _dynamicSerializers;

How to reproduce: env: latest defects4j version & Java 8

defects4j checkout -p JacksonDatabind -v 1f -w JacksonDatabind_1f

// apply the mutant patch above

defects4j test

Error message:

run.dev.tests: [junit] Running com.fasterxml.jackson.databind.TestFormatSchema [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.01 sec [junit] Running com.fasterxml.jackson.databind.TestGeneratorUsingMapper [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.018 sec [junit] Running com.fasterxml.jackson.databind.TestHandlerInstantiation [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.041 sec [junit] Running com.fasterxml.jackson.databind.TestJDKSerialization [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.136 sec [junit] Running com.fasterxml.jackson.databind.TestNamingStrategy [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.048 sec [junit] Running com.fasterxml.jackson.databind.TestObjectMapper [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.021 sec [junit] Running com.fasterxml.jackson.databind.TestObjectMapperBeanDeserializer [junit] Tests run: 9, Failures: 0, Errors: 0, Time elapsed: 0.038 sec [junit] Running com.fasterxml.jackson.databind.TestObjectMapperBeanSerializer [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.066 sec [junit] Running com.fasterxml.jackson.databind.TestParserUsingMapper [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.057 sec [junit] Running com.fasterxml.jackson.databind.TestReadValues [junit] Tests run: 10, Failures: 0, Errors: 0, Time elapsed: 0.051 sec [junit] Running com.fasterxml.jackson.databind.TestRootName [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.028 sec [junit] Running com.fasterxml.jackson.databind.TestStdDateFormat [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.001 sec [junit] Running com.fasterxml.jackson.databind.TestStdNamingStrategies [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.027 sec [junit] Running com.fasterxml.jackson.databind.TestVersions [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.036 sec [junit] Running com.fasterxml.jackson.databind.access.TestSerAnyGetter [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.033 sec [junit] Running com.fasterxml.jackson.databind.contextual.TestContextualDeserialization [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.031 sec [junit] Running com.fasterxml.jackson.databind.contextual.TestContextualKeyTypes [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.029 sec [junit] Running com.fasterxml.jackson.databind.contextual.TestContextualSerialization [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.019 sec [junit] Running com.fasterxml.jackson.databind.contextual.TestContextualWithAnnDeserializer [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.014 sec [junit] Running com.fasterxml.jackson.databind.convert.TestArrayConversions [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.024 sec [junit] Running com.fasterxml.jackson.databind.convert.TestBeanConversions [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.03 sec [junit] Running com.fasterxml.jackson.databind.convert.TestConvertingDeserializer [junit] Tests run: 8, Failures: 0, Errors: 0, Time elapsed: 0.025 sec [junit] Running com.fasterxml.jackson.databind.convert.TestConvertingSerializer [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.026 sec [junit] Running com.fasterxml.jackson.databind.convert.TestMapConversions [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.028 sec [junit] Running com.fasterxml.jackson.databind.convert.TestPolymorphicUpdateValue [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.017 sec [junit] Running com.fasterxml.jackson.databind.convert.TestStringConversions [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.019 sec [junit] Running com.fasterxml.jackson.databind.convert.TestUpdateValue [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.022 sec [junit] Running com.fasterxml.jackson.databind.creators.TestBuilderSimple [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.021 sec [junit] Running com.fasterxml.jackson.databind.creators.TestConstructFromMap [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.02 sec [junit] Running com.fasterxml.jackson.databind.creators.TestCreatorNullValue [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.013 sec [junit] Running com.fasterxml.jackson.databind.creators.TestCreators [junit] Tests run: 18, Failures: 0, Errors: 0, Time elapsed: 0.029 sec [junit] Running com.fasterxml.jackson.databind.creators.TestCreators2 [junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.029 sec [junit] Running com.fasterxml.jackson.databind.creators.TestCreatorsDelegating [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.015 sec [junit] Running com.fasterxml.jackson.databind.creators.TestPolymorphicCreators [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.03 sec [junit] Running com.fasterxml.jackson.databind.creators.TestValueInstantiator [junit] Tests run: 15, Failures: 0, Errors: 0, Time elapsed: 0.031 sec [junit] Running com.fasterxml.jackson.databind.deser.TestAbstract [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.009 sec [junit] Running com.fasterxml.jackson.databind.deser.TestAnnotationIgnore [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.015 sec [junit] Running com.fasterxml.jackson.databind.deser.TestAnnotationUsing [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.022 sec [junit] Running com.fasterxml.jackson.databind.deser.TestAnyProperties [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.025 sec [junit] Running com.fasterxml.jackson.databind.deser.TestArrayDeserialization [junit] Tests run: 19, Failures: 0, Errors: 0, Time elapsed: 0.121 sec [junit] Running com.fasterxml.jackson.databind.deser.TestAutoDetect [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.011 sec [junit] Running com.fasterxml.jackson.databind.deser.TestBasicAnnotations [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.018 sec [junit] Running com.fasterxml.jackson.databind.deser.TestBeanDeserializer [junit] Tests run: 9, Failures: 0, Errors: 0, Time elapsed: 0.027 sec [junit] Running com.fasterxml.jackson.databind.deser.TestBlocking [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.009 sec [junit] Running com.fasterxml.jackson.databind.deser.TestCollectionDeserialization [junit] Tests run: 9, Failures: 0, Errors: 0, Time elapsed: 0.033 sec [junit] Running com.fasterxml.jackson.databind.deser.TestConcurrency [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 2.016 sec [junit] Running com.fasterxml.jackson.databind.deser.TestConfig [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.016 sec [junit] Running com.fasterxml.jackson.databind.deser.TestCustomDeserializers [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.036 sec [junit] Running com.fasterxml.jackson.databind.deser.TestCustomFactory [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.016 sec [junit] Running com.fasterxml.jackson.databind.deser.TestCyclicTypes [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.014 sec [junit] Running com.fasterxml.jackson.databind.deser.TestDateDeserialization [junit] Tests run: 17, Failures: 0, Errors: 0, Time elapsed: 0.034 sec [junit] Running com.fasterxml.jackson.databind.deser.TestEnumDeserialization [junit] Tests run: 20, Failures: 0, Errors: 0, Time elapsed: 0.042 sec [junit] Running com.fasterxml.jackson.databind.deser.TestExceptionDeserialization [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.048 sec [junit] Running com.fasterxml.jackson.databind.deser.TestExceptionHandling [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.015 sec [junit] Running com.fasterxml.jackson.databind.deser.TestFieldDeserialization [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.033 sec [junit] Running com.fasterxml.jackson.databind.deser.TestGenericCollectionDeser [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.027 sec [junit] Running com.fasterxml.jackson.databind.deser.TestGenericMapDeser [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.031 sec [junit] Running com.fasterxml.jackson.databind.deser.TestGenericNumber [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.021 sec [junit] Running com.fasterxml.jackson.databind.deser.TestGenerics [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.019 sec [junit] Running com.fasterxml.jackson.databind.deser.TestGenericsBounded [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.032 sec [junit] Running com.fasterxml.jackson.databind.deser.TestIgnoredTypes [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.015 sec [junit] Running com.fasterxml.jackson.databind.deser.TestInjectables [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.019 sec [junit] Running com.fasterxml.jackson.databind.deser.TestInnerClass [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.02 sec [junit] Running com.fasterxml.jackson.databind.deser.TestJacksonTypes [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.047 sec [junit] Running com.fasterxml.jackson.databind.deser.TestJdkTypes [junit] Tests run: 15, Failures: 0, Errors: 0, Time elapsed: 0.064 sec [junit] Running com.fasterxml.jackson.databind.deser.TestMapDeserialization [junit] Tests run: 21, Failures: 0, Errors: 0, Time elapsed: 0.071 sec [junit] Running com.fasterxml.jackson.databind.deser.TestNullHandling [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.005 sec [junit] Running com.fasterxml.jackson.databind.deser.TestNumbers [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.037 sec [junit] Running com.fasterxml.jackson.databind.deser.TestOverloaded [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.022 sec [junit] Running com.fasterxml.jackson.databind.deser.TestParentChildReferences [junit] Tests run: 9, Failures: 0, Errors: 0, Time elapsed: 0.068 sec [junit] Running com.fasterxml.jackson.databind.deser.TestSetterlessProperties [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.036 sec [junit] Running com.fasterxml.jackson.databind.deser.TestSimpleAtomicTypes [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.019 sec [junit] Running com.fasterxml.jackson.databind.deser.TestSimpleTypes [junit] Tests run: 24, Failures: 0, Errors: 0, Time elapsed: 0.053 sec [junit] Running com.fasterxml.jackson.databind.deser.TestStatics [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.015 sec [junit] Running com.fasterxml.jackson.databind.deser.TestTimestampDeserialization [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.01 sec [junit] Running com.fasterxml.jackson.databind.deser.TestUntypedDeserialization [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.061 sec [junit] Running com.fasterxml.jackson.databind.deser.TestValueAnnotations [junit] Tests run: 13, Failures: 0, Errors: 0, Time elapsed: 0.092 sec [junit] Running com.fasterxml.jackson.databind.ext.TestCoreXMLTypes [junit] Tests run: 7, Failures: 0, Errors: 0, Time elapsed: 0.042 sec [junit] Running com.fasterxml.jackson.databind.ext.TestDOM [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.044 sec [junit] Running com.fasterxml.jackson.databind.filter.TestIgnorePropsForSerialization [junit] Tests run: 5, Failures: 0, Errors: 0, Time elapsed: 0.041 sec [junit] Running com.fasterxml.jackson.databind.filter.TestSimpleSerializationIgnore [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.044 sec [junit] Running com.fasterxml.jackson.databind.filter.TestUnknownPropertyDeserialization [junit] Tests run: 11, Failures: 0, Errors: 0, Time elapsed: 0.024 sec [junit] Running com.fasterxml.jackson.databind.interop.TestCglibUsage [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.076 sec [junit] Running com.fasterxml.jackson.databind.interop.TestExternalizable [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.029 sec [junit] Running com.fasterxml.jackson.databind.interop.TestFormatDetection [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.015 sec [junit] Running com.fasterxml.jackson.databind.interop.TestGroovyBeans [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.232 sec [junit] Running com.fasterxml.jackson.databind.interop.TestHibernate [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0 sec [junit] Running com.fasterxml.jackson.databind.interop.TestJDKProxy [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.02 sec [junit] Running com.fasterxml.jackson.databind.introspect.TestAnnotationMerging [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.036 sec [junit] Running com.fasterxml.jackson.databind.introspect.TestAnnotionBundles [junit] Tests run: 3, Failures: 0, Errors: 0, Time elapsed: 0.02 sec [junit] Running com.fasterxml.jackson.databind.introspect.TestBuilderMethods [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.004 sec [junit] Running com.fasterxml.jackson.databind.introspect.TestInferredMutators [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.018 sec [junit] Running com.fasterxml.jackson.databind.introspect.TestJacksonAnnotationIntrospector [junit] Tests run: 4, Failures: 0, Errors: 0, Time elapsed: 0.036 sec [junit] Running com.fasterxml.jackson.databind.introspect.TestPOJOPropertiesCollector [junit] Tests run: 16, Failures: 0, Errors: 0, Time elapsed: 0.02 sec [junit] Running com.fasterxml.jackson.databind.jsonschema.TestGenerateJsonSchema [junit] Tests run: 6, Failures: 0, Errors: 0, Time elapsed: 0.036 sec [junit] Running com.fasterxml.jackson.databind.jsonschema.TestReadJsonSchema [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.032 sec [junit] Running com.fasterxml.jackson.databind.jsontype.TestAbstractTypeNames [junit] Tests run: 2, Failures: 0, Errors: 0, Time elapsed: 0.04 sec [junit] Running com.fasterxml.jackson.databind.jsontype.TestAbstractWithObjectId [junit] deserialised list size = 2 [junit] Tests run: 1, Failures: 0, Errors: 0, Time elapsed: 0.037 sec [junit] Running com.fasterxml.jackson.databind.jsontype.TestCustomTypeIdResolver

BUILD FAILED /home/jun/tools/defects4j/framework/projects/defects4j.build.xml:107: java.lang.NullPointerException at com.fasterxml.jackson.databind.JsonMappingException$Reference.toString(JsonMappingException.java:97) at com.fasterxml.jackson.databind.JsonMappingException._appendPathDesc(JsonMappingException.java:364) at com.fasterxml.jackson.databind.JsonMappingException.getPathReference(JsonMappingException.java:267) at com.fasterxml.jackson.databind.JsonMappingException._buildMessage(JsonMappingException.java:340) at com.fasterxml.jackson.databind.JsonMappingException.getMessage(JsonMappingException.java:321) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.addError(JUnitTestRunner.java:645) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner$3.addError(JUnitTestRunner.java:1123) at junit.framework.TestResult.addError(TestResult.java:39) at junit.framework.TestResult.runProtected(TestResult.java:148) at junit.framework.TestResult.run(TestResult.java:125) at junit.framework.TestCase.run(TestCase.java:129) at junit.framework.TestSuite.runTest(TestSuite.java:255) at junit.framework.TestSuite.run(TestSuite.java:250) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTestRunner.run(JUnitTestRunner.java:520) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.executeInVM(JUnitTask.java:1484) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute(JUnitTask.java:872) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.executeOrQueue(JUnitTask.java:1972) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute1(JUnitTask.java:824) at org.apache.tools.ant.taskdefs.optional.junit.JUnitTask.execute(JUnitTask.java:2277) at org.apache.tools.ant.UnknownElement.execute(UnknownElement.java:291) at sun.reflect.GeneratedMethodAccessor4.invoke(Unknown Source) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.tools.ant.dispatch.DispatchUtils.execute(DispatchUtils.java:106) at org.apache.tools.ant.Task.perform(Task.java:348) at org.apache.tools.ant.Target.execute(Target.java:392) at org.apache.tools.ant.Target.performTasks(Target.java:413) at org.apache.tools.ant.Project.executeSortedTargets(Project.java:1399) at org.apache.tools.ant.Project.executeTarget(Project.java:1368) at org.apache.tools.ant.helper.DefaultExecutor.executeTargets(DefaultExecutor.java:41) at org.apache.tools.ant.Project.executeTargets(Project.java:1251) at org.apache.tools.ant.Main.runBuild(Main.java:811) at org.apache.tools.ant.Main.startAnt(Main.java:217) at org.apache.tools.ant.launch.Launcher.run(Launcher.java:280) at org.apache.tools.ant.launch.Launcher.main(Launcher.java:109)

Total time: 9 seconds Cannot run tests! at /home/jun/tools/defects4j/framework/bin/d4j/d4j-test line 135. Compilation failed in require at /home/jun/tools/defects4j/framework/bin/defects4j line 204.

I think it's very likely that there's something wrong with the exception handling module of defects4j because normaly it will safely exit with reporting some failing tests. But currently I can not figure out where the bug is. Thank you for reading this issue!

rjust commented 1 year ago

@claudeyj, thanks for reporting this!

I agree that test failures should all be logged instead of failing the build. From the output, it looks like the exception is raised in the test runner code itself when creating the exception message. I suspect that the JUnit code is not expecting getMessage to throw and exception itself.

at com.fasterxml.jackson.databind.JsonMappingException$Reference.toString(JsonMappingException.java:97)

Does this line raise an exception because of the generated mutant?

claudeyj commented 1 year ago

Thank you for taking a look! I think so. Because when I run buggy version it will log the failing tests without any complaint. But when I run test for this mutant it just crashed.