refactor.

README.md

@@ -38,53 +38,20 @@ The easiest way to run Fray is to replace `java` with `fray` in your command lin
 fray -cp ./out/ example.FrayExample
 ```
 
-Fray will run the application with a random scheduler. Dependening on the schedule you may either see a `DeadlockException`:
-
-```
-Error found: cmu.pasta.fray.runtime.DeadlockException
-Thread: 0
-Stacktrace:
-        at java.base/java.lang.Thread.getStackTrace(Thread.java:2450)
-        at cmu.pasta.fray.core.GlobalContext.reportError(GlobalContext.kt:84)
-        at cmu.pasta.fray.core.GlobalContext.checkDeadlock(GlobalContext.kt:813)
-        at cmu.pasta.fray.core.GlobalContext.objectWaitImpl(GlobalContext.kt:324)
-        at cmu.pasta.fray.core.GlobalContext.objectWait(GlobalContext.kt:345)
-        at cmu.pasta.fray.core.RuntimeDelegate.onObjectWait(RuntimeDelegate.kt:87)
-        at java.base/cmu.pasta.fray.runtime.Runtime.onObjectWait(Runtime.java:75)
-        at java.base/java.lang.Object.wait(Object.java)
-        at java.base/java.lang.Thread.join(Thread.java:2078)
-        at java.base/java.lang.Thread.join(Thread.java:2154)
-        at example.FrayExample.main(FrayExample.java:24)
-        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
-        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
-        at cmu.pasta.fray.core.command.MethodExecutor.execute(Executor.kt:50)
-        at cmu.pasta.fray.core.TestRunner.run(TestRunner.kt:44)
-        at cmu.pasta.fray.core.MainKt.main(Main.kt:9)
-Thread: 1
-Stacktrace:
-        at java.base/java.lang.Object.wait0(Native Method)
-        at java.base/java.lang.Object.wait(Object.java:366)
-        at java.base/java.lang.Object.wait(Object.java:339)
-        at example.FrayExample.run(FrayExample.java:12)
-```
-
-Or an `AssertionError`:
-
-```
-Error found: java.lang.reflect.InvocationTargetException
-java.lang.reflect.InvocationTargetException
-        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:118)
-        at java.base/java.lang.reflect.Method.invoke(Method.java:580)
-        at cmu.pasta.fray.core.command.MethodExecutor.execute(Executor.kt:50)
-        at cmu.pasta.fray.core.TestRunner.run(TestRunner.kt:44)
-        at cmu.pasta.fray.core.MainKt.main(Main.kt:9)
-Caused by: java.lang.AssertionError
-        at example.FrayExample.main(FrayExample.java:25)
-        at java.base/jdk.internal.reflect.DirectMethodHandleAccessor.invoke(DirectMethodHandleAccessor.java:103)
-        ... 4 more
-```
-
-And you may find the recorded schedule in the `/tmp/report/` directory.
+Fray will run the application with a random scheduler:
+
+```
+Fray Testing:
+Iterations: XXX
+Bugs Found: XXX
+```
+
+If an error is found, fray will also report:
+
+```
+Error found, you may find the error report in XXX
+```
+
 
 To replay a schedule, you may run the following command:
 

build.gradle.kts

@@ -9,7 +9,7 @@ plugins {
 
 allprojects {
   group = "org.pastalab.fray"
-  version = "1.0-SNAPSHOT"
+  version = "0.1-SNAPSHOT"
 }
 
 repositories {
@@ -34,6 +34,9 @@ configure(allprojects - project(":jvmti")) {
 configure(allprojects - project("jvmti") - rootProject) {
   plugins.apply("maven-publish")
   afterEvaluate {
+    java {
+      withSourcesJar()
+    }
     publishing {
       publications {
         create<MavenPublication>("fray") {

core/build.gradle.kts

@@ -1,10 +1,8 @@
-import com.github.jengelman.gradle.plugins.shadow.tasks.ShadowJar
 import java.util.regex.Pattern
 
 plugins {
   kotlin("jvm")
   kotlin("plugin.serialization") version "2.0.0"
-  id("com.github.johnrengelman.shadow") version "8.1.1"
 }
 
 repositories {
@@ -15,33 +13,27 @@ dependencies {
   compileOnly(project(":runtime"))
   compileOnly(project(":instrumentation"))
   implementation("org.jetbrains.kotlinx:kotlinx-serialization-json:1.7.1")
-  testImplementation("org.jetbrains.kotlin:kotlin-test")
   implementation("com.github.ajalt.clikt:clikt:4.2.2")
+  testImplementation("org.jetbrains.kotlin:kotlin-test")
+  implementation("org.apache.logging.log4j:log4j-core:2.23.1")
+  implementation("org.apache.logging.log4j:log4j-slf4j-impl:2.23.1")
 }
 
 tasks.test {
   useJUnitPlatform()
 }
 
-tasks.named<ShadowJar>("shadowJar") {
-  manifest {
-    attributes(mapOf("Main-Class" to "org.pastalab.fray.core.MainKt"))
-  }
-}
-
 tasks.named("build") {
-  dependsOn("shadowJar")
   finalizedBy("genRunner")
 }
 
 tasks.withType<JavaExec> {
-  dependsOn(":jvmti:build")
   dependsOn(":jdk:build")
   val instrumentationTask = evaluationDependsOn(":instrumentation").tasks.named("shadowJar").get()
   val jdk = project(":jdk")
   val jvmti = project(":jvmti")
   val instrumentation = instrumentationTask.outputs.files.first().absolutePath
-  classpath = tasks.named("shadowJar").get().outputs.files
+  classpath += tasks.named("jar").get().outputs.files + files(configurations.runtimeClasspath)
   executable("${jdk.layout.buildDirectory.get().asFile}/java-inst/bin/java")
   mainClass = "org.pastalab.fray.core.MainKt"
   jvmArgs("-agentpath:${jvmti.layout.buildDirectory.get().asFile}/native-libs/libjvmti.so")
@@ -83,7 +75,7 @@ tasks.create("genRunner") {
   doLast {
     val instrumentationTask = evaluationDependsOn(":instrumentation").tasks.named("shadowJar").get()
     val instrumentation = instrumentationTask.outputs.files.first().absolutePath
-    val core = tasks.named("shadowJar").get().outputs.files.first().absolutePath
+    val core = tasks.named("jar").get().outputs.files.first().absolutePath
     val jvmti = project(":jvmti")
     val binDir = "${rootProject.projectDir.absolutePath}/bin"
     var runner = file("${binDir}/fray.template").readText()

core/src/main/kotlin/org/pastalab/fray/core/RunContext.kt

@@ -21,8 +21,6 @@ import org.pastalab.fray.core.concurrency.locks.CountDownLatchManager
 import org.pastalab.fray.core.concurrency.locks.LockManager
 import org.pastalab.fray.core.concurrency.locks.SemaphoreManager
 import org.pastalab.fray.core.concurrency.operations.*
-import org.pastalab.fray.core.logger.LoggerBase
-import org.pastalab.fray.core.scheduler.Choice
 import org.pastalab.fray.instrumentation.memory.VolatileManager
 
 @Suppress("PLATFORM_CLASS_MAPPED_TO_KOTLIN")
@@ -34,13 +32,13 @@ class RunContext(val config: Configuration) {
   var mainExiting = false
   var nanoTime = System.nanoTime()
   val terminatingThread = mutableSetOf<Int>()
+  val logger = config.loggerContext.getLogger(RunContext::class.java)
   private val lockManager = LockManager()
   private val semaphoreManager = SemaphoreManager()
   private val volatileManager = VolatileManager(true)
   private val latchManager = CountDownLatchManager()
   private var step = 0
   val syncManager = SynchronizationManager()
-  val loggers = mutableListOf<LoggerBase>()
   var executor: ExecutorService =
       Executors.newSingleThreadExecutor { r ->
         object : HelperThread() {
@@ -79,14 +77,14 @@ class RunContext(val config: Configuration) {
       } else {
         e.printStackTrace(PrintWriter(sw))
       }
-      for (logger in loggers) {
-        logger.applicationEvent(sw.toString())
-      }
+      logger.error(sw.toString())
       if (config.exploreMode || config.noExitWhenBugFound) {
         return
       }
-      loggers.forEach { it.executionDone(bugFound != null) }
-      exitProcess(-1)
+      logger.error("Error found, the recording is saved to ${config.report}/index_0/")
+      println("Error found, you may find the error report in ${config.report}")
+      config.saveToReportFolder(0)
+      exitProcess(0)
     }
   }
 
@@ -150,13 +148,10 @@ class RunContext(val config: Configuration) {
     mainThreadId = t.id
     registeredThreads[t.id] = ThreadContext(t, registeredThreads.size)
     registeredThreads[t.id]?.state = ThreadState.Enabled
-    loggers.forEach { it.executionStart() }
     scheduleNextOperation(true)
   }
 
   fun done() {
-    loggers.forEach { it.executionDone(bugFound != null && config.exploreMode) }
-    loggers.clear()
     assert(lockManager.waitingThreads.isEmpty())
     assert(syncManager.synchronizationPoints.isEmpty())
     lockManager.done()
@@ -166,14 +161,6 @@ class RunContext(val config: Configuration) {
   fun shutDown() {
     org.pastalab.fray.runtime.Runtime.DELEGATE = org.pastalab.fray.runtime.Delegate()
     executor.shutdown()
-
-    for (logger in loggers) {
-      logger.shutdown()
-    }
-  }
-
-  fun registerLogger(l: LoggerBase) {
-    loggers.add(l)
   }
 
   fun threadStart(t: Thread) {
@@ -561,15 +548,6 @@ class RunContext(val config: Configuration) {
     lockManager.reentrantReadWriteLockInit(readLock, writeLock)
   }
 
-  fun log(format: String, vararg args: Any) {
-    val tid = Thread.currentThread().id
-    val context = registeredThreads[tid]!!
-    val data = "[${context.index}]: ${String.format(format, args)}\n"
-    for (logger in loggers) {
-      logger.applicationEvent(data)
-    }
-  }
-
   fun unlockImpl(
       lock: Any,
       tid: Long,
@@ -856,19 +834,6 @@ class RunContext(val config: Configuration) {
     val nextThread = config.scheduler.scheduleNextOperation(enabledOperations)
     val index = enabledOperations.indexOf(nextThread)
     currentThreadId = nextThread.thread.id
-
-    if (enabledOperations.size > 1 || config.fullSchedule) {
-      loggers.forEach {
-        it.newOperationScheduled(
-            nextThread.pendingOperation,
-            Choice(
-                index,
-                nextThread.index,
-                enabledOperations.size,
-                enabledOperations.map { it.index },
-                nextThread.pendingOperation.toString()))
-      }
-    }
     nextThread.state = ThreadState.Running
     unblockThread(currentThread, nextThread)
     if (currentThread != nextThread && shouldBlockCurrentThread) {

core/src/main/kotlin/org/pastalab/fray/core/RuntimeDelegate.kt

@@ -753,8 +753,4 @@ class RuntimeDelegate(val context: RunContext) : org.pastalab.fray.runtime.Deleg
     }
     return t.hashCode()
   }
-
-  override fun log(format: String, vararg args: Any) {
-    context.log(format, *args)
-  }
 }

core/src/main/kotlin/org/pastalab/fray/core/TestRunner.kt

@@ -1,32 +1,26 @@
 package org.pastalab.fray.core
 
-import java.nio.file.Paths
-import kotlin.io.path.ExperimentalPathApi
-import kotlin.io.path.createDirectories
-import kotlin.io.path.deleteRecursively
 import kotlin.time.TimeSource
+import org.apache.logging.log4j.Logger
 import org.pastalab.fray.core.command.Configuration
-import org.pastalab.fray.core.logger.ConsoleLogger
 import org.pastalab.fray.core.randomness.ControlledRandom
 
 class TestRunner(val config: Configuration) {
 
   val context = RunContext(config)
 
+  val logger: Logger = config.loggerContext.getLogger(TestRunner::class.java)
+
   init {
-    if (!config.isReplay) {
-      prepareReportPath(config.report)
-    }
-    context.registerLogger(ConsoleLogger())
     context.bootstrap()
   }
 
-  @OptIn(ExperimentalPathApi::class)
-  fun prepareReportPath(reportPath: String) {
-    val path = Paths.get(reportPath)
-    path.deleteRecursively()
-    path.createDirectories()
-    println("Report is available at: ${path.toAbsolutePath()}")
+  fun reportProgress(iteration: Int, bugsFound: Int) {
+    print("\u001B[2J")
+    print("\u001B[2H")
+    println("Fray Testing:")
+    println("Iterations: $iteration")
+    println("Bugs Found: $bugsFound")
   }
 
   fun run(): Throwable? {
@@ -37,8 +31,9 @@ class TestRunner(val config: Configuration) {
       val timeSource = TimeSource.Monotonic
       val start = timeSource.markNow()
       var i = 0
+      var bugsFound = 0
       while (i != config.iter) {
-        println("Starting iteration $i")
+        reportProgress(i, bugsFound)
         try {
           if (i != 0) {
             config.scheduler = config.scheduler.nextIteration()
@@ -53,8 +48,10 @@ class TestRunner(val config: Configuration) {
           org.pastalab.fray.runtime.Runtime.onMainExit()
         }
         if (context.bugFound != null) {
+          bugsFound += 1
           println(
-              "Error found at iter: $i, Elapsed time: ${(timeSource.markNow() - start).inWholeMilliseconds}ms")
+              "Error found at iter: $i, Elapsed time: ${(timeSource.markNow() - start).inWholeMilliseconds}ms",
+          )
           if (!config.exploreMode) {
             config.saveToReportFolder(i)
             break

core/src/main/kotlin/org/pastalab/fray/core/command/Configuration.kt

@@ -10,7 +10,9 @@ import com.github.ajalt.clikt.parameters.types.int
 import java.io.File
 import java.nio.file.Paths
 import java.util.*
+import kotlin.io.path.ExperimentalPathApi
 import kotlin.io.path.createDirectories
+import kotlin.io.path.deleteRecursively
 import kotlinx.serialization.Polymorphic
 import kotlinx.serialization.Serializable
 import kotlinx.serialization.encodeToString
@@ -19,6 +21,9 @@ import kotlinx.serialization.json.JsonNamingStrategy
 import kotlinx.serialization.modules.SerializersModule
 import kotlinx.serialization.modules.polymorphic
 import kotlinx.serialization.modules.subclass
+import org.apache.logging.log4j.core.LoggerContext
+import org.apache.logging.log4j.core.config.Configurator
+import org.apache.logging.log4j.core.config.builder.api.ConfigurationBuilderFactory
 import org.pastalab.fray.core.randomness.ControlledRandom
 import org.pastalab.fray.core.scheduler.*
 
@@ -201,4 +206,37 @@ data class Configuration(
     File("$report/index_$index/schedule.json").writeText(Json.encodeToString(scheduler))
     File("$report/index_$index/random.json").writeText(Json.encodeToString(randomnessProvider))
   }
+
+  val loggerContext by lazy {
+    val builder = ConfigurationBuilderFactory.newConfigurationBuilder()
+    builder.setConfigurationName("Fray")
+    builder.setLoggerContext(LoggerContext("Fray"))
+    val appender =
+        builder
+            .newAppender("log", "File")
+            .addAttribute("fileName", "${report}/fray.log")
+            .addAttribute("append", false)
+    val standard = builder.newLayout("PatternLayout")
+    standard.addAttribute("pattern", "%d [%t] %-5level: %msg%n%throwable")
+    appender.add(standard)
+    builder.add(appender)
+    val logger = builder.newLogger("org.pastalab.fray", "INFO")
+    logger.add(builder.newAppenderRef("log"))
+    logger.addAttribute("additivity", false)
+    builder.add(logger)
+    Configurator.initialize(builder.build())
+  }
+
+  init {
+    if (!isReplay) {
+      prepareReportPath(report)
+    }
+  }
+
+  @OptIn(ExperimentalPathApi::class)
+  fun prepareReportPath(reportPath: String) {
+    val path = Paths.get(reportPath)
+    path.deleteRecursively()
+    path.createDirectories()
+  }
 }