Skip to content

Commit 9d02686

Browse files
aman-goelaman-goel
committed
[PEx] Adds option --replay <.schedule file> to replay a buggy trace
1 parent dbe1887 commit 9d02686

File tree

9 files changed

+147
-65
lines changed

9 files changed

+147
-65
lines changed

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/PExplicit.java

Lines changed: 0 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -8,7 +8,6 @@
88
import pexplicit.runtime.logger.PExplicitLogger;
99
import pexplicit.runtime.logger.StatWriter;
1010
import pexplicit.runtime.machine.PTestDriver;
11-
import pexplicit.runtime.scheduler.explicit.strategy.SearchTask;
1211
import pexplicit.utils.exceptions.BugFoundException;
1312
import pexplicit.utils.monitor.MemoryMonitor;
1413
import pexplicit.utils.monitor.TimeMonitor;
@@ -35,7 +34,6 @@ public static void main(String[] args) {
3534
PExplicitGlobal.setConfig(PExplicitOptions.ParseCommandlineArgs(args));
3635
PExplicitLogger.Initialize(PExplicitGlobal.getConfig().getVerbosity());
3736
ComputeHash.Initialize();
38-
SearchTask.Initialize();
3937

4038
// get reflections corresponding to the model
4139
Reflections reflections = new Reflections("pexplicit.model");

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/RuntimeExecutor.java

Lines changed: 65 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -3,8 +3,12 @@
33
import pexplicit.runtime.PExplicitGlobal;
44
import pexplicit.runtime.STATUS;
55
import pexplicit.runtime.logger.PExplicitLogger;
6+
import pexplicit.runtime.logger.ScratchLogger;
67
import pexplicit.runtime.logger.StatWriter;
8+
import pexplicit.runtime.scheduler.Schedule;
79
import pexplicit.runtime.scheduler.explicit.ExplicitSearchScheduler;
10+
import pexplicit.runtime.scheduler.explicit.SearchStatistics;
11+
import pexplicit.runtime.scheduler.explicit.strategy.SearchStrategyMode;
812
import pexplicit.runtime.scheduler.explicit.strategy.SearchTask;
913
import pexplicit.runtime.scheduler.replay.ReplayScheduler;
1014
import pexplicit.utils.exceptions.BugFoundException;
@@ -55,39 +59,42 @@ private static void runWithTimeout(long timeLimit)
5559
}
5660

5761
private static void printStats() {
58-
double searchTime = TimeMonitor.stopInterval();
59-
scheduler.recordStats();
60-
if (PExplicitGlobal.getResult().equals("correct for any depth")) {
61-
PExplicitGlobal.setStatus(STATUS.VERIFIED);
62-
} else if (PExplicitGlobal.getResult().startsWith("correct up to step")) {
63-
PExplicitGlobal.setStatus(STATUS.VERIFIED_UPTO_MAX_STEPS);
62+
double timeUsed = (Duration.between(TimeMonitor.getStart(), Instant.now()).toMillis() / 1000.0);
63+
double memoryUsed = MemoryMonitor.getMemSpent();
64+
65+
StatWriter.log("time-seconds", String.format("%.1f", timeUsed));
66+
StatWriter.log("memory-max-MB", String.format("%.1f", MemoryMonitor.getMaxMemSpent()));
67+
StatWriter.log("memory-current-MB", String.format("%.1f", memoryUsed));
68+
69+
if (PExplicitGlobal.getConfig().getSearchStrategyMode() != SearchStrategyMode.Replay) {
70+
StatWriter.log("max-depth-explored", String.format("%d", SearchStatistics.maxSteps));
71+
scheduler.recordStats();
72+
if (PExplicitGlobal.getResult().equals("correct for any depth")) {
73+
PExplicitGlobal.setStatus(STATUS.VERIFIED);
74+
} else if (PExplicitGlobal.getResult().startsWith("correct up to step")) {
75+
PExplicitGlobal.setStatus(STATUS.VERIFIED_UPTO_MAX_STEPS);
76+
}
6477
}
65-
StatWriter.log("time-search-seconds", String.format("%.1f", searchTime));
6678
}
6779

6880
private static void preprocess() {
6981
PExplicitLogger.logInfo(String.format(".. Test case :: " + PExplicitGlobal.getConfig().getTestDriver()));
7082
PExplicitLogger.logInfo(String.format("... Checker is using '%s' strategy (seed:%s)",
7183
PExplicitGlobal.getConfig().getSearchStrategyMode(), PExplicitGlobal.getConfig().getRandomSeed()));
7284

73-
executor = Executors.newSingleThreadExecutor();
74-
7585
PExplicitGlobal.setResult("error");
7686

77-
double preSearchTime =
78-
TimeMonitor.findInterval(TimeMonitor.getStart());
7987
StatWriter.log("project-name", String.format("%s", PExplicitGlobal.getConfig().getProjectName()));
8088
StatWriter.log("strategy", String.format("%s", PExplicitGlobal.getConfig().getSearchStrategyMode()));
8189
StatWriter.log("time-limit-seconds", String.format("%.1f", PExplicitGlobal.getConfig().getTimeLimit()));
8290
StatWriter.log("memory-limit-MB", String.format("%.1f", PExplicitGlobal.getConfig().getMemLimit()));
83-
StatWriter.log("time-pre-seconds", String.format("%.1f", preSearchTime));
8491
}
8592

8693
private static void process(boolean resume) throws Exception {
94+
executor = Executors.newSingleThreadExecutor();
8795
try {
8896
TimedCall timedCall = new TimedCall(scheduler, resume);
8997
future = executor.submit(timedCall);
90-
TimeMonitor.startInterval();
9198
runWithTimeout((long) PExplicitGlobal.getConfig().getTimeLimit());
9299
} catch (TimeoutException e) {
93100
PExplicitGlobal.setStatus(STATUS.TIMEOUT);
@@ -135,12 +142,56 @@ private static void process(boolean resume) throws Exception {
135142
}
136143
}
137144

138-
public static void run() throws Exception {
145+
public static void runSearch() throws Exception {
146+
SearchTask.Initialize();
147+
ScratchLogger.Initialize();
148+
139149
scheduler = new ExplicitSearchScheduler();
140150
PExplicitGlobal.setScheduler(scheduler);
141151

142152
preprocess();
143153
process(false);
144154
}
145155

156+
private static void replaySchedule(String fileName) throws Exception {
157+
PExplicitLogger.logInfo(String.format("... Reading buggy trace from %s", fileName));
158+
159+
ReplayScheduler replayer = new ReplayScheduler(Schedule.readFromFile(fileName));
160+
PExplicitGlobal.setScheduler(replayer);
161+
try {
162+
replayer.run();
163+
} catch (NullPointerException | StackOverflowError | ClassCastException replayException) {
164+
PExplicitGlobal.setStatus(STATUS.BUG_FOUND);
165+
PExplicitGlobal.setResult(String.format("found cex of length %d", replayer.getStepNumber()));
166+
PExplicitLogger.logStackTrace((Exception) replayException);
167+
throw new BugFoundException(replayException.getMessage(), replayException);
168+
} catch (BugFoundException replayException) {
169+
PExplicitGlobal.setStatus(STATUS.BUG_FOUND);
170+
PExplicitGlobal.setResult(String.format("found cex of length %d", replayer.getStepNumber()));
171+
PExplicitLogger.logStackTrace(replayException);
172+
throw replayException;
173+
} catch (Exception replayException) {
174+
PExplicitLogger.logStackTrace(replayException);
175+
throw new Exception("Error when replaying the bug", replayException);
176+
} finally {
177+
printStats();
178+
PExplicitLogger.logEndOfRun(null, Duration.between(TimeMonitor.getStart(), Instant.now()).getSeconds());
179+
}
180+
}
181+
182+
public static void replay() throws Exception {
183+
preprocess();
184+
replaySchedule(PExplicitGlobal.getConfig().getReplayFile());
185+
}
186+
187+
public static void run() throws Exception {
188+
// initialize stats writer
189+
StatWriter.Initialize();
190+
191+
if (PExplicitGlobal.getConfig().getSearchStrategyMode() == SearchStrategyMode.Replay) {
192+
replay();
193+
} else {
194+
runSearch();
195+
}
196+
}
146197
}

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/commandline/PExplicitConfig.java

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -44,6 +44,9 @@ public class PExplicitConfig {
4444
// random seed
4545
@Setter
4646
long randomSeed = System.currentTimeMillis();
47+
// name of the replay file
48+
@Setter
49+
String replayFile = "";
4750
// max number of logs (i.e., internal steps) within a single schedule step
4851
@Setter
4952
int maxStepLogBound = 1000;

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/commandline/PExplicitOptions.java

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -149,6 +149,22 @@ public class PExplicitOptions {
149149
.build();
150150
addOption(randomSeed);
151151

152+
/*
153+
* Replay options
154+
*/
155+
156+
// replay file
157+
Option replayFile =
158+
Option.builder("r")
159+
.longOpt("replay")
160+
.desc("Schedule file to replay")
161+
.numberOfArgs(1)
162+
.hasArg()
163+
.argName("File Name (string)")
164+
.build();
165+
addOption(replayFile);
166+
167+
152168

153169
/*
154170
* Invisible/expert options
@@ -339,6 +355,12 @@ public static PExplicitConfig ParseCommandlineArgs(String[] args) {
339355
option, String.format("Expected an integer value, got %s", option.getValue()));
340356
}
341357
break;
358+
// replay options
359+
case "r":
360+
case "replay":
361+
config.setReplayFile(option.getValue());
362+
config.setSearchStrategyMode(SearchStrategyMode.Replay);
363+
break;
342364
// invisible expert options
343365
case "state-caching":
344366
switch (option.getValue()) {
@@ -427,6 +449,15 @@ public static PExplicitConfig ParseCommandlineArgs(String[] args) {
427449
config.setMaxSchedulesPerTask(0);
428450
}
429451

452+
if (config.getSearchStrategyMode() == SearchStrategyMode.Replay) {
453+
if (config.getVerbosity() == 0) {
454+
config.setVerbosity(1);
455+
}
456+
if (config.getReplayFile().startsWith(config.getOutputFolder())) {
457+
config.setOutputFolder(config.getOutputFolder() + "Replay");
458+
}
459+
}
460+
430461
return config;
431462
}
432463

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/runtime/logger/PExplicitLogger.java

Lines changed: 11 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -58,10 +58,6 @@ public static void Initialize(int verb) {
5858
consoleAppender.start();
5959

6060
context.getConfiguration().addLoggerAppender(coreLogger, consoleAppender);
61-
62-
// initialize all loggers and writers
63-
StatWriter.Initialize();
64-
ScratchLogger.Initialize();
6561
}
6662

6763
public static void logInfo(String message) {
@@ -96,15 +92,17 @@ public static void logEndOfRun(ExplicitSearchScheduler scheduler, long timeSpent
9692
} else {
9793
log.info("..... Found 0 bugs.");
9894
}
99-
log.info("... Scheduling statistics:");
100-
if (PExplicitGlobal.getConfig().getStateCachingMode() != StateCachingMode.None) {
101-
log.info(String.format("..... Explored %d distinct states", SearchStatistics.totalDistinctStates));
95+
if (scheduler != null) {
96+
log.info("... Scheduling statistics:");
97+
if (PExplicitGlobal.getConfig().getStateCachingMode() != StateCachingMode.None) {
98+
log.info(String.format("..... Explored %d distinct states", SearchStatistics.totalDistinctStates));
99+
}
100+
log.info(String.format("..... Explored %d distinct schedules", SearchStatistics.iteration));
101+
log.info(String.format("..... Finished %d search tasks (%d pending)",
102+
scheduler.getSearchStrategy().getFinishedTasks().size(), scheduler.getSearchStrategy().getPendingTasks().size()));
103+
log.info(String.format("..... Number of steps explored: %d (min), %d (avg), %d (max).",
104+
SearchStatistics.minSteps, (SearchStatistics.totalSteps / SearchStatistics.iteration), SearchStatistics.maxSteps));
102105
}
103-
log.info(String.format("..... Explored %d distinct schedules", SearchStatistics.iteration));
104-
log.info(String.format("..... Finished %d search tasks (%d pending)",
105-
scheduler.getSearchStrategy().getFinishedTasks().size(), scheduler.getSearchStrategy().getPendingTasks().size()));
106-
log.info(String.format("..... Number of steps explored: %d (min), %d (avg), %d (max).",
107-
SearchStatistics.minSteps, (SearchStatistics.totalSteps / SearchStatistics.iteration), SearchStatistics.maxSteps));
108106
log.info(String.format("... Elapsed %d seconds and used %.1f GB", timeSpent, MemoryMonitor.getMaxMemSpent() / 1000.0));
109107
log.info(String.format(".. Result: " + PExplicitGlobal.getResult()));
110108
log.info(". Done");
@@ -172,7 +170,7 @@ public static void logNewTasks(List<SearchTask> tasks) {
172170
* Log when serializing a schedule
173171
*
174172
* @param schedule Schedule to serialize
175-
* @param szBytes Bytes written
173+
* @param szBytes Bytes written
176174
*/
177175
public static void logSerializeSchedule(Schedule schedule, String fileName, long szBytes) {
178176
if (verbosity > 1) {

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/runtime/scheduler/Schedule.java

Lines changed: 17 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,6 @@
33
import lombok.Getter;
44
import lombok.Setter;
55
import pexplicit.runtime.PExplicitGlobal;
6-
import pexplicit.runtime.logger.PExplicitLogger;
76
import pexplicit.runtime.machine.PMachineId;
87
import pexplicit.runtime.scheduler.choice.Choice;
98
import pexplicit.runtime.scheduler.choice.DataChoice;
@@ -12,12 +11,7 @@
1211
import pexplicit.runtime.scheduler.explicit.StepState;
1312
import pexplicit.values.PValue;
1413

15-
import java.io.FileOutputStream;
16-
import java.io.IOException;
17-
import java.io.ObjectOutputStream;
18-
import java.io.Serializable;
19-
import java.nio.file.Files;
20-
import java.nio.file.Paths;
14+
import java.io.*;
2115
import java.util.ArrayList;
2216
import java.util.List;
2317

@@ -45,6 +39,22 @@ public class Schedule implements Serializable {
4539
public Schedule() {
4640
}
4741

42+
public static Schedule readFromFile(String fileName) {
43+
assert (fileName != null);
44+
Schedule result = null;
45+
46+
try {
47+
FileInputStream fis;
48+
fis = new FileInputStream(fileName);
49+
ObjectInputStream ois = new ObjectInputStream(fis);
50+
result = (Schedule) ois.readObject();
51+
} catch (IOException | ClassNotFoundException e) {
52+
throw new RuntimeException("Failed to read schedule from file " + fileName, e);
53+
}
54+
55+
return result;
56+
}
57+
4858
/**
4959
* Get the choice at a choice depth
5060
*

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/runtime/scheduler/explicit/ExplicitSearchScheduler.java

Lines changed: 0 additions & 8 deletions
Original file line numberDiff line numberDiff line change
@@ -22,7 +22,6 @@
2222
import pexplicit.values.ComputeHash;
2323
import pexplicit.values.PValue;
2424

25-
import java.time.Duration;
2625
import java.time.Instant;
2726
import java.util.*;
2827
import java.util.concurrent.TimeUnit;
@@ -597,22 +596,15 @@ public void updateResult() {
597596
}
598597

599598
public void recordStats() {
600-
double timeUsed = (Duration.between(TimeMonitor.getStart(), Instant.now()).toMillis() / 1000.0);
601-
double memoryUsed = MemoryMonitor.getMemSpent();
602-
603599
printProgress(true);
604600

605601
// print basic statistics
606-
StatWriter.log("time-seconds", String.format("%.1f", timeUsed));
607-
StatWriter.log("memory-max-MB", String.format("%.1f", MemoryMonitor.getMaxMemSpent()));
608-
StatWriter.log("memory-current-MB", String.format("%.1f", memoryUsed));
609602
StatWriter.log("#-executions", String.format("%d", SearchStatistics.iteration));
610603
if (PExplicitGlobal.getConfig().getStateCachingMode() != StateCachingMode.None) {
611604
StatWriter.log("#-states", String.format("%d", SearchStatistics.totalStates));
612605
StatWriter.log("#-distinct-states", String.format("%d", SearchStatistics.totalDistinctStates));
613606
}
614607
StatWriter.log("steps-min", String.format("%d", SearchStatistics.minSteps));
615-
StatWriter.log("max-depth-explored", String.format("%d", SearchStatistics.maxSteps));
616608
StatWriter.log("steps-avg", String.format("%d", SearchStatistics.totalSteps / SearchStatistics.iteration));
617609
StatWriter.log("#-choices-unexplored", String.format("%d", getNumUnexploredChoices()));
618610
StatWriter.log("%-choices-unexplored-data", String.format("%.1f", getUnexploredDataChoicesPercent()));

‎Src/PRuntimes/PExplicitRuntime/src/main/java/pexplicit/runtime/scheduler/explicit/strategy/SearchStrategyMode.java

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -3,7 +3,8 @@
33
public enum SearchStrategyMode {
44
DepthFirst("dfs"),
55
Random("random"),
6-
Astar("astar");
6+
Astar("astar"),
7+
Replay("replay");
78

89
private String name;
910

0 commit comments

Comments
 (0)