From cb44a7b6975d6cce53c50ecf15b78baa08412708 Mon Sep 17 00:00:00 2001 From: vasumv Date: Mon, 9 Sep 2024 15:32:22 -0400 Subject: [PATCH] Tyche logging support (#258) * Initial Tyche logging support * Add args logging * Add observeGuidance --- fuzz/pom.xml | 6 + .../berkeley/cs/jqf/fuzz/afl/AFLGuidance.java | 5 + .../berkeley/cs/jqf/fuzz/ei/ZestGuidance.java | 8 ++ .../cs/jqf/fuzz/guidance/Guidance.java | 8 ++ .../fuzz/junit/quickcheck/FuzzStatement.java | 26 ++++- .../cs/jqf/fuzz/repro/ReproGuidance.java | 5 + .../cs/jqf/fuzz/util/Observability.java | 110 ++++++++++++++++++ 7 files changed, 165 insertions(+), 3 deletions(-) create mode 100644 fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/util/Observability.java diff --git a/fuzz/pom.xml b/fuzz/pom.xml index 29ee1a002..d7cbf3c43 100644 --- a/fuzz/pom.xml +++ b/fuzz/pom.xml @@ -55,6 +55,12 @@ eclipse-collections 10.4.0 + + com.fasterxml.jackson.core + jackson-databind + 2.15.2 + compile + diff --git a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/afl/AFLGuidance.java b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/afl/AFLGuidance.java index 9373689d5..11d540f41 100644 --- a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/afl/AFLGuidance.java +++ b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/afl/AFLGuidance.java @@ -167,6 +167,11 @@ public void finalize() { } } + @Override + public String observeGuidance() { + return "AFL"; + } + /** * Returns an input stream containing the bytes that AFL diff --git a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/ei/ZestGuidance.java b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/ei/ZestGuidance.java index b9df383f5..bd79a454c 100644 --- a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/ei/ZestGuidance.java +++ b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/ei/ZestGuidance.java @@ -437,6 +437,14 @@ protected void appendLineToFile(File file, String line) throws GuidanceException } + @Override + public String observeGuidance() { + if (blind) { + return "Random"; + } + return "Zest"; + } + /* Writes a line of text to the log file. */ protected void infoLog(String str, Object... args) { if (verbose) { diff --git a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/guidance/Guidance.java b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/guidance/Guidance.java index 45bfd2bc8..519bc6546 100644 --- a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/guidance/Guidance.java +++ b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/guidance/Guidance.java @@ -132,6 +132,14 @@ default void observeGeneratedArgs(Object[] args) { // Do nothing } + /** + *

This method is only invoked during optional observability + * logging to provide the type of guidance used for input generation.

+ */ + default String observeGuidance() { + return ""; + } + /** * Handles the end of a fuzzing trial. * diff --git a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/junit/quickcheck/FuzzStatement.java b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/junit/quickcheck/FuzzStatement.java index 4ba89fd53..b01d08d7c 100644 --- a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/junit/quickcheck/FuzzStatement.java +++ b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/junit/quickcheck/FuzzStatement.java @@ -41,13 +41,17 @@ import com.pholser.junit.quickcheck.internal.ParameterTypeContext; import com.pholser.junit.quickcheck.internal.generator.GeneratorRepository; import com.pholser.junit.quickcheck.random.SourceOfRandomness; +import edu.berkeley.cs.jqf.fuzz.ei.ZestGuidance; import edu.berkeley.cs.jqf.fuzz.guidance.Guidance; import edu.berkeley.cs.jqf.fuzz.guidance.GuidanceException; import edu.berkeley.cs.jqf.fuzz.guidance.TimeoutException; import edu.berkeley.cs.jqf.fuzz.guidance.Result; import edu.berkeley.cs.jqf.fuzz.guidance.StreamBackedRandom; import edu.berkeley.cs.jqf.fuzz.junit.TrialRunner; +import edu.berkeley.cs.jqf.fuzz.random.NoGuidance; +import edu.berkeley.cs.jqf.fuzz.repro.ReproGuidance; import edu.berkeley.cs.jqf.instrument.InstrumentationException; +import edu.berkeley.cs.jqf.fuzz.util.Observability; import org.junit.AssumptionViolatedException; import org.junit.runners.model.FrameworkMethod; import org.junit.runners.model.MultipleFailureException; @@ -73,6 +77,7 @@ public class FuzzStatement extends Statement { private final List> expectedExceptions; private final List failures = new ArrayList<>(); private final Guidance guidance; + private final Observability observability; private boolean skipExceptionSwallow; public FuzzStatement(FrameworkMethod method, TestClass testClass, @@ -85,6 +90,7 @@ public FuzzStatement(FrameworkMethod method, TestClass testClass, this.expectedExceptions = Arrays.asList(method.getMethod().getExceptionTypes()); this.guidance = fuzzGuidance; this.skipExceptionSwallow = Boolean.getBoolean("jqf.failOnDeclaredExceptions"); + this.observability = new Observability(testClass.getName(), method.getName(), System.currentTimeMillis()); } /** @@ -101,16 +107,19 @@ public void evaluate() throws Throwable { .collect(Collectors.toList()); // Keep fuzzing until no more input or I/O error with guidance + // Get current time in unix timestamp + long endGenerationTime = 0; try { // Keep fuzzing as long as guidance wants to while (guidance.hasInput()) { Result result = INVALID; Throwable error = null; + long startTrialTime = System.currentTimeMillis(); // Initialize guided fuzzing using a file-backed random number source + Object [] args = {}; try { - Object[] args; try { // Generate input values @@ -142,6 +151,7 @@ public void evaluate() throws Throwable { throw new GuidanceException(e); } + endGenerationTime = System.currentTimeMillis(); // Attempt to run the trial guidance.run(testClass, method, args); @@ -170,6 +180,17 @@ public void evaluate() throws Throwable { failures.add(e); } } + long endTrialTime = System.currentTimeMillis(); + if (System.getProperty("jqfObservability") != null) { + observability.addStatus(result); + if (result == SUCCESS) { + observability.addTiming(startTrialTime, endGenerationTime, endTrialTime); + } + observability.addArgs(args); + observability.add("how_generated", guidance.observeGuidance()); + + observability.writeToFile(); + } // Inform guidance about the outcome of this trial try { @@ -180,8 +201,6 @@ public void evaluate() throws Throwable { // Anything else thrown from handleResult is an internal error, so wrap throw new GuidanceException(e); } - - } } catch (GuidanceException e) { System.err.println("Fuzzing stopped due to guidance exception: " + e.getMessage()); @@ -198,6 +217,7 @@ public void evaluate() throws Throwable { } } + } /** diff --git a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/repro/ReproGuidance.java b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/repro/ReproGuidance.java index e64e04554..64f85df4b 100644 --- a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/repro/ReproGuidance.java +++ b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/repro/ReproGuidance.java @@ -191,6 +191,11 @@ public void observeGeneratedArgs(Object[] args) { } } + @Override + public String observeGuidance() { + return "Repro"; + } + /** * Writes an object to a file * diff --git a/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/util/Observability.java b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/util/Observability.java new file mode 100644 index 000000000..e3055bc47 --- /dev/null +++ b/fuzz/src/main/java/edu/berkeley/cs/jqf/fuzz/util/Observability.java @@ -0,0 +1,110 @@ +package edu.berkeley.cs.jqf.fuzz.util; + +import com.fasterxml.jackson.databind.JsonNode; +import com.fasterxml.jackson.databind.ObjectMapper; +import com.fasterxml.jackson.databind.node.ObjectNode; +import edu.berkeley.cs.jqf.fuzz.guidance.Result; + +import java.io.FileWriter; +import java.nio.file.Path; +import java.nio.file.Paths; +import java.util.Arrays; + +import static edu.berkeley.cs.jqf.fuzz.guidance.Result.FAILURE; +import static edu.berkeley.cs.jqf.fuzz.guidance.Result.INVALID; + +public class Observability { + + private final ObjectMapper objectMapper = new ObjectMapper(); + private final String testClass; + private final String testMethod; + private final Path obsPath; + private static ObjectNode testCaseJsonObject; + private final long startTime; + + public Observability(String testClass, String testMethod, long startTime) { + this.testClass = testClass; + this.testMethod = testMethod; + this.obsPath = Paths.get("target", "fuzz-results", testClass, testMethod, "observations.jsonl"); + if (obsPath.toFile().exists()) { + obsPath.toFile().delete(); + } + this.startTime = startTime; + this.initializeTestCase(); + } + + public void initializeTestCase() { + testCaseJsonObject = objectMapper.createObjectNode(); + testCaseJsonObject.putObject("features"); + testCaseJsonObject.putObject("timing"); + testCaseJsonObject.putObject("coverage"); + testCaseJsonObject.putObject("args"); + testCaseJsonObject.putObject("metadata"); + testCaseJsonObject.put("type", "test_case"); + testCaseJsonObject.put("run_start", startTime); + testCaseJsonObject.put("property", testMethod); + } + + public static void event(String value, Object payload) throws RuntimeException { + // Add the payload to the features object + JsonNode jsonFeaturesNode = testCaseJsonObject.get("features"); + ObjectNode featuresNode = (ObjectNode) jsonFeaturesNode; + + if (payload instanceof Integer) { + featuresNode.put(value, (Integer) payload); + } else if (payload instanceof String) { + featuresNode.put(value, (String) payload); + } else if (payload instanceof Float) { + featuresNode.put(value, (Float) payload); + } else { + throw new RuntimeException("Unsupported payload type for event"); + } + } + + public void addStatus(Result result) { + if (result == INVALID) { + testCaseJsonObject.put("status", "gave_up"); + testCaseJsonObject.put("status_reason", "assumption violated"); + } else if (result == FAILURE) { + testCaseJsonObject.put("status", "failed"); + testCaseJsonObject.put("status_reason", "Encountered exception"); + } else { + testCaseJsonObject.put("status", "passed"); + testCaseJsonObject.put("status_reason", ""); + } + + } + + public void addTiming(long startTime, long endGenerationTime, long endExecutionTime) { + JsonNode timingNode = testCaseJsonObject.get("timing"); + ObjectNode timingObject = (ObjectNode) timingNode; + timingObject.put("generation", endGenerationTime - startTime); + timingObject.put("execution", endExecutionTime - endGenerationTime); + } + + public void addArgs(Object[] args) { + JsonNode argsNode = testCaseJsonObject.get("args"); + ObjectNode argsObject = (ObjectNode) argsNode; + for (int i = 0; i < args.length; i++) { + argsObject.put("arg" + i, args[i].toString()); + } + add("representation", Arrays.toString(args)); + } + + public void add(String key, String value) { + testCaseJsonObject.put(key, value); + } + + public void writeToFile() { + // Append the JSON object to a file followed by a newline + try { + String jsonString = objectMapper.writeValueAsString(testCaseJsonObject); + try (FileWriter writer = new FileWriter(obsPath.toFile(), true)) { + writer.write(jsonString); + writer.write(System.lineSeparator()); // Add a new line after each object + } + } catch (Exception e) { + throw new RuntimeException("Failed to write observations to file", e); + } + } +}