feat: Add support for more sophisticated logging

5 files changed, 77 insertions, 16 deletions

diff --git a/opendc/opendc-experiments-sc20/build.gradle.kts b/opendc/opendc-experiments-sc20/build.gradle.kts
index ccfa3038..76ec7cc4 100644
--- a/opendc/opendc-experiments-sc20/build.gradle.kts
+++ b/opendc/opendc-experiments-sc20/build.gradle.kts
@@ -40,12 +40,14 @@ dependencies {
     implementation(project(":opendc:opendc-format"))
     implementation(kotlin("stdlib"))
     implementation("com.xenomachina:kotlin-argparser:2.0.7")
-    api("com.fasterxml.jackson.module:jackson-module-kotlin:2.9.8")
+    implementation("org.slf4j:slf4j-api:${Library.SLF4J}")
+    implementation("io.github.microutils:kotlin-logging:1.7.9")
     implementation("org.apache.parquet:parquet-avro:1.11.0")
     implementation("org.apache.hadoop:hadoop-client:3.2.1") {
         exclude(group = "org.slf4j", module = "slf4j-log4j12")
+        exclude(group = "log4j")
     }
-    runtimeOnly("org.slf4j:slf4j-simple:${Library.SLF4J}")
+    runtimeOnly("org.apache.logging.log4j:log4j-slf4j-impl:2.13.1")
     runtimeOnly(project(":odcsim:odcsim-engine-omega"))
 
     testImplementation("org.junit.jupiter:junit-jupiter-api:${Library.JUNIT_JUPITER}")
diff --git a/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20Experiment.kt b/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20Experiment.kt
index c74189c2..2029d3e7 100644
--- a/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20Experiment.kt
+++ b/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20Experiment.kt
@@ -65,6 +65,7 @@ import kotlinx.coroutines.flow.onEach
 import kotlinx.coroutines.launch
 import kotlinx.coroutines.runBlocking
 import kotlinx.coroutines.withContext
+import mu.KotlinLogging
 import java.io.File
 import java.io.FileReader
 import java.util.ServiceLoader
@@ -73,6 +74,8 @@ import kotlin.math.ln
 import kotlin.math.max
 import kotlin.random.Random
 
+private val logger = KotlinLogging.logger {}
+
 class ExperimentParameters(parser: ArgParser) {
     val traceDirectory by parser.storing("path to the trace directory")
     val environmentFile by parser.storing("path to the environment file")
@@ -244,12 +247,12 @@ suspend fun processTrace(reader: TraceReader<VmWorkload>, scheduler: SimpleVirtP
                 // Check if VM in topology
                 val clusterName = vmPlacements[vmId]
                 if (clusterName == null) {
-                    println("Could not find placement data in VM placement file for VM $vmId")
+                    logger.warn { "Could not find placement data in VM placement file for VM $vmId" }
                     continue
                 }
                 val machineInCluster = hypervisors.ceiling(clusterName)?.contains(clusterName) ?: false
                 if (machineInCluster) {
-                    println("Ignored VM")
+                    logger.info { "Ignored VM $vmId" }
                     continue
                 }
             }
@@ -290,13 +293,13 @@ suspend fun processTrace(reader: TraceReader<VmWorkload>, scheduler: SimpleVirtP
 @OptIn(ExperimentalCoroutinesApi::class)
 fun main(args: Array<String>) {
     val cli = ArgParser(args).parseInto(::ExperimentParameters)
-    println("trace-directory: ${cli.traceDirectory}")
-    println("environment-file: ${cli.environmentFile}")
-    println("performance-interference-file: ${cli.performanceInterferenceFile}")
-    println("selected-vms-file: ${cli.selectedVmsFile}")
-    println("seed: ${cli.seed}")
-    println("failures: ${cli.failures}")
-    println("allocation-policy: ${cli.allocationPolicy}")
+    logger.info("trace-directory: ${cli.traceDirectory}")
+    logger.info("environment-file: ${cli.environmentFile}")
+    logger.info("performance-interference-file: ${cli.performanceInterferenceFile}")
+    logger.info("selected-vms-file: ${cli.selectedVmsFile}")
+    logger.info("seed: ${cli.seed}")
+    logger.info("failures: ${cli.failures}")
+    logger.info("allocation-policy: ${cli.allocationPolicy}")
 
     val start = System.currentTimeMillis()
     val reporter: Sc20Reporter = Sc20ParquetReporter(cli.outputFile)
@@ -349,7 +352,7 @@ fun main(args: Array<String>) {
         val (bareMetalProvisioner, scheduler) = createProvisioner(root, environmentReader, allocationPolicy)
 
         val failureDomain = if (cli.failures) {
-            println("ENABLING failures")
+            logger.info("ENABLING failures")
             createFailureDomain(cli.seed, cli.failureInterval, bareMetalProvisioner, chan)
         } else {
             null
@@ -358,11 +361,15 @@ fun main(args: Array<String>) {
         attachMonitor(scheduler, reporter)
         processTrace(traceReader, scheduler, chan, reporter, vmPlacements)
 
-        println("Finish SUBMIT=${scheduler.submittedVms} FAIL=${scheduler.unscheduledVms} QUEUE=${scheduler.queuedVms} RUNNING=${scheduler.runningVms} FINISH=${scheduler.finishedVms}")
+        logger.debug("SUBMIT=${scheduler.submittedVms}")
+        logger.debug("FAIL=${scheduler.unscheduledVms}")
+        logger.debug("QUEUED=${scheduler.queuedVms}")
+        logger.debug("RUNNING=${scheduler.runningVms}")
+        logger.debug("FINISHED=${scheduler.finishedVms}")
 
         failureDomain?.cancel()
         scheduler.terminate()
-        println("[${simulationContext.clock.millis()}] DONE ${System.currentTimeMillis() - start} milliseconds")
+        logger.info("Simulation took ${System.currentTimeMillis() - start} milliseconds")
     }
 
     runBlocking {
diff --git a/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetReporter.kt b/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetReporter.kt
index 2b653b69..fc3e98ae 100644
--- a/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetReporter.kt
+++ b/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetReporter.kt
@@ -6,6 +6,7 @@ import com.atlarge.opendc.compute.core.ServerState
 import com.atlarge.opendc.compute.metal.driver.BareMetalDriver
 import com.atlarge.opendc.compute.virt.driver.VirtDriver
 import kotlinx.coroutines.flow.first
+import mu.KotlinLogging
 import org.apache.avro.SchemaBuilder
 import org.apache.avro.generic.GenericData
 import org.apache.hadoop.fs.Path
@@ -14,6 +15,8 @@ import org.apache.parquet.hadoop.metadata.CompressionCodecName
 import java.util.concurrent.ArrayBlockingQueue
 import kotlin.concurrent.thread
 
+private val logger = KotlinLogging.logger {}
+
 class Sc20ParquetReporter(
     destination: String
 ) : Sc20Reporter {
@@ -91,7 +94,7 @@ class Sc20ParquetReporter(
             )
         }
 
-        println("[${simulationContext.clock.millis()}] HOST ${server.uid} ${server.state}")
+        logger.info("Host ${server.uid} changed state ${server.state} [${simulationContext.clock.millis()}]")
 
         lastServerStates[server] = Pair(server.state, simulationContext.clock.millis())
     }
diff --git a/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetTraceReader.kt b/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetTraceReader.kt
index 0a7718e9..8ae1693c 100644
--- a/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetTraceReader.kt
+++ b/opendc/opendc-experiments-sc20/src/main/kotlin/com/atlarge/opendc/experiments/sc20/Sc20ParquetTraceReader.kt
@@ -32,6 +32,7 @@ import com.atlarge.opendc.compute.core.workload.VmWorkload
 import com.atlarge.opendc.core.User
 import com.atlarge.opendc.format.trace.TraceEntry
 import com.atlarge.opendc.format.trace.TraceReader
+import mu.KotlinLogging
 import org.apache.avro.generic.GenericData
 import org.apache.hadoop.fs.Path
 import org.apache.parquet.avro.AvroParquetReader
@@ -49,6 +50,8 @@ import java.util.concurrent.ArrayBlockingQueue
 import kotlin.concurrent.thread
 import kotlin.random.Random
 
+private val logger = KotlinLogging.logger {}
+
 /**
  * A [TraceReader] for the internal VM workload trace format.
  *
@@ -190,7 +193,7 @@ class Sc20ParquetTraceReader(
                 assert(uid !in takenIds)
                 takenIds += uid
 
-                println(id)
+                logger.info("Processing VM $id")
 
                 val internalBuffer = mutableListOf<FlopsHistoryFragment>()
                 val externalBuffer = mutableListOf<FlopsHistoryFragment>()
diff --git a/opendc/opendc-experiments-sc20/src/main/resources/log4j2.xml b/opendc/opendc-experiments-sc20/src/main/resources/log4j2.xml
new file mode 100644
index 00000000..77a15e55
--- /dev/null
+++ b/opendc/opendc-experiments-sc20/src/main/resources/log4j2.xml
@@ -0,0 +1,46 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<!--
+  ~ MIT License
+  ~
+  ~ Copyright (c) 2020 atlarge-research
+  ~
+  ~ Permission is hereby granted, free of charge, to any person obtaining a copy
+  ~ of this software and associated documentation files (the "Software"), to deal
+  ~ in the Software without restriction, including without limitation the rights
+  ~ to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
+  ~ copies of the Software, and to permit persons to whom the Software is
+  ~ furnished to do so, subject to the following conditions:
+  ~
+  ~ The above copyright notice and this permission notice shall be included in all
+  ~ copies or substantial portions of the Software.
+  ~
+  ~ THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
+  ~ IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
+  ~ FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
+  ~ AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
+  ~ LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
+  ~ OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN THE
+  ~ SOFTWARE.
+  -->
+
+<Configuration status="WARN">
+    <Appenders>
+        <Console name="Console" target="SYSTEM_OUT">
+            <PatternLayout pattern="%d{HH:mm:ss.SSS} [%highlight{%-5level}] %logger{36} - %msg%n" disableAnsi="false" />
+        </Console>
+    </Appenders>
+    <Loggers>
+        <Logger name="com.atlarge.odcsim" level="info" additivity="false">
+            <AppenderRef ref="Console"/>
+        </Logger>
+        <Logger name="com.atlarge.opendc" level="info" additivity="false">
+            <AppenderRef ref="Console"/>
+        </Logger>
+        <Logger name="org.apache.hadoop" level="warn" additivity="false">
+            <AppenderRef ref="Console"/>
+        </Logger>
+        <Root level="error">
+            <AppenderRef ref="Console"/>
+        </Root>
+    </Loggers>
+</Configuration>