Add logging of main actor messages (#110)

* Change Linearized code subfolder * Add logging of SudokuSolver and SudokuProgressTracker messages * Bump sbt from 1.8.3 to 1.9.3 * Change name of log file to sudoku.log
lunatech-labs · Aug 4, 2023 · bee7632 · bee7632
1 parent cf2e510
commit bee7632
Show file tree

Hide file tree

Showing 99 changed files with 1,087 additions and 590 deletions.
diff --git a/course-management.conf b/course-management.conf
@@ -5,6 +5,9 @@ cmt {
   # Folder in studentified repo holding the current exercise code
   studentified-repo-active-exercise-folder = .
 
+  # Folder in linearized repo holding the current exercise code
+  linearized-repo-active-exercise-folder   = code
+
   # List of folders containing test code
   test-code-folders = [
     "src/test"

diff --git a/exercises/exercise_000_sudoku_solver_initial_state/build.sbt b/exercises/exercise_000_sudoku_solver_initial_state/build.sbt
@@ -1,13 +1,10 @@
-
 Global / onChangedBuildSource := ReloadOnSourceChanges
 
-
 lazy val `moving-from-scala-2-to-scala-3` =
   (project in file(".")).settings(
     scalaVersion := "2.13.10",
     Compile / scalacOptions ++= CompileOptions.compileOptions,
     libraryDependencies ++= Dependencies.dependencies,
-    testFrameworks += new TestFramework("munit.Framework"),
-  )
+    testFrameworks += new TestFramework("munit.Framework"))
 
 sbt.addCommandAlias("runSolver", "runMain org.lunatechlabs.dotty.SudokuSolverMain")
diff --git a/exercises/exercise_000_sudoku_solver_initial_state/project/Build.scala b/exercises/exercise_000_sudoku_solver_initial_state/project/Build.scala
@@ -7,42 +7,31 @@ object CompileOptions {
   lazy val rewriteNoIndent = Seq("-rewrite", "-noindent")
   lazy val rewriteOldSyntax = Seq("-rewrite", "-old-syntax")
 
-  lazy val compileOptions = Seq(
-    "-unchecked",
-    "-deprecation",
-    "-encoding", "UTF-8",
-  )
+  lazy val compileOptions = Seq("-unchecked", "-deprecation", "-encoding", "UTF-8")
 }
 
 object Versions {
-  lazy val akkaVer           = "2.6.20"
-  lazy val logbackVer        = "1.2.3"
-  lazy val mUnitVer          = "0.7.26"
+  lazy val akkaVer = "2.6.20"
+  lazy val logbackVer = "1.2.3"
+  lazy val mUnitVer = "0.7.26"
 }
 
 object Dependencies {
 
   private lazy val akkaDeps = Seq(
-    "com.typesafe.akka"             %% "akka-actor-typed",
-    "com.typesafe.akka"             %% "akka-slf4j",
-    "com.typesafe.akka"             %% "akka-stream",
-  ).map (_ % Versions.akkaVer)
+    "com.typesafe.akka" %% "akka-actor-typed",
+    "com.typesafe.akka" %% "akka-slf4j",
+    "com.typesafe.akka" %% "akka-stream").map(_ % Versions.akkaVer)
 
-  private lazy val akkaTestkitDeps = Seq(
-    "com.typesafe.akka"             %% "akka-actor-testkit-typed" % Versions.akkaVer % Test
-  )
+  private lazy val akkaTestkitDeps = Seq("com.typesafe.akka" %% "akka-actor-testkit-typed" % Versions.akkaVer % Test)
 
-  private lazy val logbackDeps = Seq (
-    "ch.qos.logback"                 %  "logback-classic",
-  ).map (_ % Versions.logbackVer)
+  private lazy val logbackDeps = Seq("ch.qos.logback" % "logback-classic").map(_ % Versions.logbackVer)
 
-  private lazy val munitDeps = Seq(
-    "org.scalameta" %% "munit" % Versions.mUnitVer % Test
-  )
+  private lazy val munitDeps = Seq("org.scalameta" %% "munit" % Versions.mUnitVer % Test)
 
   lazy val dependencies: Seq[ModuleID] =
     logbackDeps ++
-    munitDeps ++
-    akkaDeps ++
-    akkaTestkitDeps
+      munitDeps ++
+      akkaDeps ++
+      akkaTestkitDeps
 }
diff --git a/exercises/exercise_000_sudoku_solver_initial_state/project/build.properties b/exercises/exercise_000_sudoku_solver_initial_state/project/build.properties
@@ -1 +1 @@
-sbt.version=1.8.3
+sbt.version=1.9.3
diff --git a/exercises/exercise_000_sudoku_solver_initial_state/src/main/resources/application.conf b/exercises/exercise_000_sudoku_solver_initial_state/src/main/resources/application.conf
@@ -1,4 +1,8 @@
 akka {
+  loggers = ["akka.event.slf4j.Slf4jLogger"]
+  loglevel = "INFO"
+  logging-filter = "akka.event.slf4j.Slf4jLoggingFilter"
+
   log-dead-letters = on
   logger-startup-timeout = 30s
 

diff --git a/exercises/exercise_000_sudoku_solver_initial_state/src/main/resources/logback.xml b/exercises/exercise_000_sudoku_solver_initial_state/src/main/resources/logback.xml
@@ -1,24 +1,24 @@
+<?xml version="1.0" encoding="UTF-8"?>
 <configuration>
 
-    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
+    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
         <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
-            <level>info</level>
+            <level>INFO</level>
         </filter>
         <encoder>
-            <pattern>%date{HH:mm:ss} %-5level [%X{akkaSource}] - %msg%n</pattern>
+            <pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg %n</pattern>
         </encoder>
     </appender>
 
-    <logger name="org.lunatechlabs.dotty" level="info" additivity="false">
-        <appender-ref ref="console"/>
-    </logger>
-
-    <logger name="akka.actor.RepointableActorRef" level="info" additivity="false">
-        <appender-ref ref="console"/>
-    </logger>
+    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
+        <file>target/sudoku.log</file>
+        <encoder>
+            <pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg %n</pattern>
+        </encoder>
+    </appender>
 
-    <root level="info">
-        <appender-ref ref="console"/>
+    <root level="INFO">
+        <appender-ref ref="STDOUT"/>
+        <appender-ref ref="FILE"/>
     </root>
-
 </configuration>
diff --git a/...er_initial_state/src/main/scala/org/lunatechlabs/dotty/sudoku/SudokuProgressTracker.scala b/...er_initial_state/src/main/scala/org/lunatechlabs/dotty/sudoku/SudokuProgressTracker.scala
@@ -30,11 +30,13 @@ class SudokuProgressTracker private (
   def trackProgress(updatesInFlight: Int): Behavior[Command] =
     Behaviors.receiveMessage {
       case NewUpdatesInFlight(updateCount) if updatesInFlight - 1 == 0 =>
+        context.log.debug("NewUpdatesInFlight({}) - UpdatesInFlight={}", updateCount, updatesInFlight + updateCount)
         rowDetailProcessors.foreach { case (_, processor) =>
           processor ! SudokuDetailProcessor.GetSudokuDetailState(context.self)
         }
         collectEndState()
       case NewUpdatesInFlight(updateCount) =>
+        context.log.debug("NewUpdatesInFlight({}) - UpdatesInFlight={}", updateCount, updatesInFlight + updateCount)
         trackProgress(updatesInFlight + updateCount)
       case msg: SudokuDetailState =>
         context.log.error("Received unexpected message in state 'trackProgress': {}", msg)

diff --git a/...doku_solver_initial_state/src/main/scala/org/lunatechlabs/dotty/sudoku/SudokuSolver.scala b/...doku_solver_initial_state/src/main/scala/org/lunatechlabs/dotty/sudoku/SudokuSolver.scala
@@ -74,6 +74,7 @@ class SudokuSolver private (context: ActorContext[SudokuSolver.Command], buffer:
         rowUpdates.foreach { case SudokuDetailProcessor.RowUpdate(row, cellUpdates) =>
           rowDetailProcessors(row) ! SudokuDetailProcessor.Update(cellUpdates, detailProcessorResponseMapper)
         }
+        context.log.debug("InitialRowUpdates: {}", rowUpdates)
         progressTracker ! SudokuProgressTracker.NewUpdatesInFlight(rowUpdates.size)
         processRequest(Some(sender), System.currentTimeMillis())
       case unexpectedMsg =>
@@ -88,52 +89,95 @@ class SudokuSolver private (context: ActorContext[SudokuSolver.Command], buffer:
         response match {
           case SudokuDetailProcessor.RowUpdate(rowNr, updates) =>
             updates.foreach { case (rowCellNr, newCellContent) =>
+              context.log.debug("Incoming update for Row({},{})={} ", rowNr, rowCellNr, newCellContent)
               val (columnNr, columnCellNr) = rowToColumnCoordinates(rowNr, rowCellNr)
               val columnUpdate = Vector(columnCellNr -> newCellContent)
+              context.log.debug(
+                "Outgoing update from RowProcessor({}) for Column({}, {})={} ",
+                rowNr,
+                columnNr,
+                columnCellNr,
+                columnUpdate)
               columnDetailProcessors(columnNr) ! SudokuDetailProcessor.Update(
                 columnUpdate,
                 detailProcessorResponseMapper)
 
               val (blockNr, blockCellNr) = rowToBlockCoordinates(rowNr, rowCellNr)
               val blockUpdate = Vector(blockCellNr -> newCellContent)
+              context.log.debug(
+                "Outgoing update from RowProcessor({}) for Block({}, {})={} ",
+                rowNr,
+                blockNr,
+                blockCellNr,
+                blockUpdate)
               blockDetailProcessors(blockNr) ! SudokuDetailProcessor.Update(blockUpdate, detailProcessorResponseMapper)
             }
             progressTracker ! SudokuProgressTracker.NewUpdatesInFlight(2 * updates.size - 1)
             Behaviors.same
           case SudokuDetailProcessor.ColumnUpdate(columnNr, updates) =>
             updates.foreach { case (colCellNr, newCellContent) =>
+              context.log.debug("Incoming update for Column({},{})={} ", columnNr, colCellNr, newCellContent)
               val (rowNr, rowCellNr) = columnToRowCoordinates(columnNr, colCellNr)
               val rowUpdate = Vector(rowCellNr -> newCellContent)
+              context.log.debug(
+                "Outgoing update from ColumnProcessor({}) for Row({}, {})={} ",
+                columnNr,
+                rowNr,
+                rowCellNr,
+                rowUpdate)
               rowDetailProcessors(rowNr) ! SudokuDetailProcessor.Update(rowUpdate, detailProcessorResponseMapper)
 
               val (blockNr, blockCellNr) = columnToBlockCoordinates(columnNr, colCellNr)
               val blockUpdate = Vector(blockCellNr -> newCellContent)
+              context.log.debug(
+                "Outgoing update from ColumnProcessor({}) for Block({}, {})={} ",
+                columnNr,
+                blockNr,
+                blockCellNr,
+                blockUpdate)
               blockDetailProcessors(blockNr) ! SudokuDetailProcessor.Update(blockUpdate, detailProcessorResponseMapper)
             }
             progressTracker ! SudokuProgressTracker.NewUpdatesInFlight(2 * updates.size - 1)
             Behaviors.same
           case SudokuDetailProcessor.BlockUpdate(blockNr, updates) =>
             updates.foreach { case (blockCellNr, newCellContent) =>
+              context.log.debug("Incoming update for Block({},{})={} ", blockNr, blockCellNr, newCellContent)
               val (rowNr, rowCellNr) = blockToRowCoordinates(blockNr, blockCellNr)
               val rowUpdate = Vector(rowCellNr -> newCellContent)
+              context.log.debug(
+                "Outgoing update from BlockProcessor({}) for Row({}, {})={} ",
+                blockNr,
+                rowNr,
+                rowCellNr,
+                rowUpdate)
+
               rowDetailProcessors(rowNr) ! SudokuDetailProcessor.Update(rowUpdate, detailProcessorResponseMapper)
 
               val (columnNr, columnCellNr) = blockToColumnCoordinates(blockNr, blockCellNr)
               val columnUpdate = Vector(columnCellNr -> newCellContent)
+              context.log.debug(
+                "Outgoing update from BlockProcessor({}) for Column({}, {})={} ",
+                blockNr,
+                columnNr,
+                columnCellNr,
+                columnUpdate)
+
               columnDetailProcessors(columnNr) ! SudokuDetailProcessor.Update(
                 columnUpdate,
                 detailProcessorResponseMapper)
             }
             progressTracker ! SudokuProgressTracker.NewUpdatesInFlight(2 * updates.size - 1)
             Behaviors.same
           case unchanged @ SudokuDetailProcessor.SudokuDetailUnchanged =>
+            context.log.debug("SudokuDetailUnchanged")
             progressTracker ! SudokuProgressTracker.NewUpdatesInFlight(-1)
             Behaviors.same
         }
       case SudokuProgressTrackerResponseWrapped(result) =>
         result match {
           case SudokuProgressTracker.Result(sudoku) =>
             context.log.info(s"Sudoku processing time: ${System.currentTimeMillis() - startTime} milliseconds")
+            context.log.debug("Result: {}", sudoku)
             requestor.get ! SudokuSolution(sudoku)
             resetAllDetailProcessors()
             buffer.unstashAll(idle())

diff --git a/exercises/exercise_001_dotty_deprecated_syntax_rewriting/build.sbt b/exercises/exercise_001_dotty_deprecated_syntax_rewriting/build.sbt
@@ -1,12 +1,10 @@
 Global / onChangedBuildSource := ReloadOnSourceChanges
 
-
 lazy val `moving-from-scala-2-to-scala-3` =
   (project in file(".")).settings(
     scalaVersion := "3.3.0",
     Compile / scalacOptions ++= CompileOptions.compileOptions,
     libraryDependencies ++= Dependencies.dependencies,
-    testFrameworks += new TestFramework("munit.Framework"),
-  )
+    testFrameworks += new TestFramework("munit.Framework"))
 
 sbt.addCommandAlias("runSolver", "runMain org.lunatechlabs.dotty.SudokuSolverMain")
diff --git a/exercises/exercise_001_dotty_deprecated_syntax_rewriting/project/Build.scala b/exercises/exercise_001_dotty_deprecated_syntax_rewriting/project/Build.scala
@@ -7,43 +7,31 @@ object CompileOptions {
   lazy val rewriteNoIndent = Seq("-rewrite", "-noindent")
   lazy val rewriteOldSyntax = Seq("-rewrite", "-old-syntax")
 
-  lazy val compileOptions = Seq(
-    "-unchecked",
-    "-deprecation",
-    "-encoding", "UTF-8",
-    "-source:future-migration",
-  )
+  lazy val compileOptions = Seq("-unchecked", "-deprecation", "-encoding", "UTF-8", "-source:future-migration")
 }
 
 object Versions {
-  lazy val akkaVer           = "2.6.20"
-  lazy val logbackVer        = "1.2.3"
-  lazy val mUnitVer          = "0.7.26"
+  lazy val akkaVer = "2.6.20"
+  lazy val logbackVer = "1.2.3"
+  lazy val mUnitVer = "0.7.26"
 }
 
 object Dependencies {
 
   private lazy val akkaDeps = Seq(
-    "com.typesafe.akka"             %% "akka-actor-typed",
-    "com.typesafe.akka"             %% "akka-slf4j",
-    "com.typesafe.akka"             %% "akka-stream",
-  ).map (_ % Versions.akkaVer)
+    "com.typesafe.akka" %% "akka-actor-typed",
+    "com.typesafe.akka" %% "akka-slf4j",
+    "com.typesafe.akka" %% "akka-stream").map(_ % Versions.akkaVer)
 
-  private lazy val akkaTestkitDeps = Seq(
-    "com.typesafe.akka"             %% "akka-actor-testkit-typed" % Versions.akkaVer % Test
-  )
+  private lazy val akkaTestkitDeps = Seq("com.typesafe.akka" %% "akka-actor-testkit-typed" % Versions.akkaVer % Test)
 
-  private lazy val logbackDeps = Seq (
-    "ch.qos.logback"                 %  "logback-classic",
-  ).map (_ % Versions.logbackVer)
+  private lazy val logbackDeps = Seq("ch.qos.logback" % "logback-classic").map(_ % Versions.logbackVer)
 
-  private lazy val munitDeps = Seq(
-    "org.scalameta" %% "munit" % Versions.mUnitVer % Test
-  )
+  private lazy val munitDeps = Seq("org.scalameta" %% "munit" % Versions.mUnitVer % Test)
 
   lazy val dependencies: Seq[ModuleID] =
     logbackDeps ++
-    munitDeps ++
-    akkaDeps ++
-    akkaTestkitDeps
+      munitDeps ++
+      akkaDeps ++
+      akkaTestkitDeps
 }
diff --git a/exercises/exercise_001_dotty_deprecated_syntax_rewriting/project/build.properties b/exercises/exercise_001_dotty_deprecated_syntax_rewriting/project/build.properties
@@ -1 +1 @@
-sbt.version=1.8.3
+sbt.version=1.9.3
diff --git a/exercises/exercise_001_dotty_deprecated_syntax_rewriting/src/main/resources/application.conf b/exercises/exercise_001_dotty_deprecated_syntax_rewriting/src/main/resources/application.conf
@@ -1,4 +1,8 @@
 akka {
+  loggers = ["akka.event.slf4j.Slf4jLogger"]
+  loglevel = "INFO"
+  logging-filter = "akka.event.slf4j.Slf4jLoggingFilter"
+
   log-dead-letters = on
   logger-startup-timeout = 30s
 

diff --git a/exercises/exercise_001_dotty_deprecated_syntax_rewriting/src/main/resources/logback.xml b/exercises/exercise_001_dotty_deprecated_syntax_rewriting/src/main/resources/logback.xml
@@ -1,24 +1,24 @@
+<?xml version="1.0" encoding="UTF-8"?>
 <configuration>
 
-    <appender name="console" class="ch.qos.logback.core.ConsoleAppender">
+    <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
         <filter class="ch.qos.logback.classic.filter.ThresholdFilter">
-            <level>info</level>
+            <level>INFO</level>
         </filter>
         <encoder>
-            <pattern>%date{HH:mm:ss} %-5level [%X{akkaSource}] - %msg%n</pattern>
+            <pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg %n</pattern>
         </encoder>
     </appender>
 
-    <logger name="org.lunatechlabs.dotty" level="info" additivity="false">
-        <appender-ref ref="console"/>
-    </logger>
-
-    <logger name="akka.actor.RepointableActorRef" level="info" additivity="false">
-        <appender-ref ref="console"/>
-    </logger>
+    <appender name="FILE" class="ch.qos.logback.core.FileAppender">
+        <file>target/sudoku.log</file>
+        <encoder>
+            <pattern>[%date{ISO8601}] [%level] [%logger] [%marker] [%thread] - %msg %n</pattern>
+        </encoder>
+    </appender>
 
-    <root level="info">
-        <appender-ref ref="console"/>
+    <root level="INFO">
+        <appender-ref ref="STDOUT"/>
+        <appender-ref ref="FILE"/>
     </root>
-
 </configuration>
diff --git a/...syntax_rewriting/src/main/scala/org/lunatechlabs/dotty/sudoku/SudokuProgressTracker.scala b/...syntax_rewriting/src/main/scala/org/lunatechlabs/dotty/sudoku/SudokuProgressTracker.scala
@@ -30,11 +30,13 @@ class SudokuProgressTracker private (
   def trackProgress(updatesInFlight: Int): Behavior[Command] =
     Behaviors.receiveMessage {
       case NewUpdatesInFlight(updateCount) if updatesInFlight - 1 == 0 =>
+        context.log.debug("NewUpdatesInFlight({}) - UpdatesInFlight={}", updateCount, updatesInFlight + updateCount)
         rowDetailProcessors.foreach { case (_, processor) =>
           processor ! SudokuDetailProcessor.GetSudokuDetailState(context.self)
         }
         collectEndState()
       case NewUpdatesInFlight(updateCount) =>
+        context.log.debug("NewUpdatesInFlight({}) - UpdatesInFlight={}", updateCount, updatesInFlight + updateCount)
         trackProgress(updatesInFlight + updateCount)
       case msg: SudokuDetailState =>
         context.log.error("Received unexpected message in state 'trackProgress': {}", msg)