Refactor logging

badoo · Dec 12, 2024 · e800803 · e800803
1 parent 497d2a3
commit e800803
Show file tree

Hide file tree

Showing 28 changed files with 251 additions and 322 deletions.
diff --git a/core/src/main/kotlin/com/malinskiy/marathon/Marathon.kt b/core/src/main/kotlin/com/malinskiy/marathon/Marathon.kt
@@ -44,7 +44,7 @@ class Marathon(
     private val timer: Timer
 ) : MarathonRunner {
 
-    private val logger = MarathonLogging.logger("Marathon")
+    private val logger = MarathonLogging.getLogger(Marathon::class.java)
 
     private val configurationValidator = LogicalConfigurationValidator()
     private val strictRunProcessor = StrictRunProcessor(configuration.strictRunConfiguration)
@@ -57,11 +57,18 @@ class Marathon(
         MarathonLogging.debug = configuration.debug
         logConfigurator.configure()
 
+        configurationValidator.validate(configuration)
+
+        logger.debug("Initializing device provider")
         deviceProvider.initialize()
-        logger.debug("Finished loading device provider")
 
-        configurationValidator.validate(configuration)
+        if (configuration.outputDir.exists()) {
+            logger.info("Cleaning output directory ${configuration.outputDir}")
+            configuration.outputDir.deleteRecursively()
+        }
+        configuration.outputDir.mkdirs()
 
+        logger.debug("Initializing scheduler")
         val currentCoroutineContext = coroutineContext
         scheduler = Scheduler(
             deviceProvider,
@@ -77,38 +84,29 @@ class Marathon(
             timer,
             currentCoroutineContext
         )
-
-        logger.debug("Created scheduler")
-
-        if (configuration.outputDir.exists()) {
-            logger.info("Output directory ${configuration.outputDir} already exists")
-            configuration.outputDir.deleteRecursively()
-        }
-        configuration.outputDir.mkdirs()
-
         scheduler.initialize()
     }
 
     override suspend fun scheduleTests(componentInfo: ComponentInfo) {
         val parsedTests = testParser.extract(componentInfo)
         val tests = applyTestFilters(parsedTests)
 
-        logger.info("Scheduling ${tests.size} tests for $componentInfo")
+        logger.info("Scheduling {} tests for {}", tests.size, componentInfo)
         logger.debug(tests.joinToString(", ") { it.toTestName() })
 
         val shard = prepareTestShard(tests, analytics)
         scheduler.addTests(shard)
     }
 
     override suspend fun stopAndWaitForCompletion(): Boolean {
-        logger.debug("Waiting for completion")
+        logger.debug("Waiting for test run to complete")
 
         try {
             scheduler.stopAndWaitForCompletion()
             onFinish()
         } catch (@Suppress("TooGenericExceptionCaught") e: Throwable) {
             // We don't want to catch these. If an exception was thrown, we should fail the execution
-            logger.error("Error occurred while finishing tests run", e)
+            logger.error("An error occurred while finishing test run", e)
             throw e
         }
         return progressReporter.aggregateResult()
@@ -125,7 +123,7 @@ class Marathon(
         try {
             tracker.finish()
         } catch (@Suppress("TooGenericExceptionCaught") e: Throwable) {
-            throw ReportGenerationException("Failed to generate test run report with exception", e)
+            throw ReportGenerationException("Failed to generate test run report", e)
         }
     }
 

diff --git a/core/src/main/kotlin/com/malinskiy/marathon/cache/gradle/GradleHttpCacheService.kt b/core/src/main/kotlin/com/malinskiy/marathon/cache/gradle/GradleHttpCacheService.kt
@@ -29,23 +29,23 @@ class GradleHttpCacheService(private val configuration: RemoteCacheConfiguration
 
     private val httpClient = createClient()
 
-    private val logger = MarathonLogging.logger("GradleHttpCacheService")
+    private val logger = MarathonLogging.getLogger(GradleHttpCacheService::class.java)
 
     override suspend fun load(key: CacheKey, reader: CacheEntryReader): Boolean =
         withContext(Dispatchers.IO) {
             try {
                 val response = httpClient.get(key.key)
                 if (response.status != HttpStatusCode.OK) {
                     if (response.status != HttpStatusCode.NotFound) {
-                        logger.warn("Got response status when loading cache entry for ${key.key} : ${response.status}")
+                        logger.warn("Got response status {} when loading cache entry for {}", response.status, key.key)
                     }
                     false
                 } else {
                     reader.readFrom(response.bodyAsChannel())
                     true
                 }
             } catch (exception: IOException) {
-                logger.warn("Error during loading cache entry for ${key.key}", exception)
+                logger.warn("Error loading cache entry for {}", key.key, exception)
                 false
             }
         }
@@ -59,10 +59,10 @@ class GradleHttpCacheService(private val configuration: RemoteCacheConfiguration
                     setBody(ByteArrayContent(stream.toByteArray()))
                 }
                 if (!response.status.isSuccess()) {
-                    logger.warn("Got response status when storing cache entry for ${key.key} : ${response.status}")
+                    logger.warn("Got response status {} when storing cache entry for {}", response.status, key.key)
                 }
             } catch (exception: IOException) {
-                logger.warn("Error during storing cache entry for ${key.key}", exception)
+                logger.warn("Error storing cache entry for {}", key.key, exception)
             } finally {
                 stream.close()
             }

diff --git a/core/src/main/kotlin/com/malinskiy/marathon/cache/test/TestCacheLoader.kt b/core/src/main/kotlin/com/malinskiy/marathon/cache/test/TestCacheLoader.kt
@@ -24,7 +24,7 @@ class TestCacheLoader(
     private val cacheKeyFactory: TestCacheKeyFactory
 ) {
 
-    private val logger = MarathonLogging.logger("TestCacheLoader")
+    private val logger = MarathonLogging.getLogger(TestCacheLoader::class.java)
 
     private val _results: Channel<CacheResult> = unboundedChannel()
     val results: ReceiveChannel<CacheResult>
@@ -49,13 +49,11 @@ class TestCacheLoader(
                     _results.send(result!!)
                 }
 
-                logger.debug {
-                    val hitOrMiss = when (result!!) {
-                        is Hit -> "hit"
-                        is Miss -> "miss"
-                    }
-                    "Cache $hitOrMiss for ${test.test.toSimpleSafeTestName()}, took $timeMillis milliseconds"
+                val hitOrMiss = when (result!!) {
+                    is Hit -> "hit"
+                    is Miss -> "miss"
                 }
+                logger.debug("Cache {} for {} took {} milliseconds", hitOrMiss, test.test.toSimpleSafeTestName(), timeMillis)
             }
         }
     }
@@ -67,12 +65,12 @@ class TestCacheLoader(
                 if (configuration.strictRunConfiguration.filter.matches(test)) {
                     testCacheBlackList.add(test)
                 } else {
-                    testsToCheck.send(TestToCheck(poolId, test, isStrictRun = false))
+                    testsToCheck.send(TestToCheck(poolId, test))
                 }
             }
 
             if (testCacheBlackList.isNotEmpty()) {
-                logger.debug { "Cache miss for test in blacklist: ${testCacheBlackList.map { it.toSimpleSafeTestName() }} " }
+                logger.debug("Cache miss for tests in blacklist: {}", testCacheBlackList.map { it.toSimpleSafeTestName() })
                 _results.send(Miss(poolId, TestShard(testCacheBlackList)))
             }
         } else {
@@ -84,8 +82,8 @@ class TestCacheLoader(
         testsToCheck.close()
         cacheCheckCompleted.await()
         _results.close()
-        logger.debug { "Cache loader is terminated" }
+        logger.debug("Cache loader is terminated")
     }
 
-    private class TestToCheck(val poolId: DevicePoolId, val test: Test, val isStrictRun: Boolean)
+    private class TestToCheck(val poolId: DevicePoolId, val test: Test)
 }
diff --git a/core/src/main/kotlin/com/malinskiy/marathon/cache/test/TestCacheSaver.kt b/core/src/main/kotlin/com/malinskiy/marathon/cache/test/TestCacheSaver.kt
@@ -16,7 +16,7 @@ class TestCacheSaver(
     private val testCacheKeyProvider: TestCacheKeyFactory
 ) {
 
-    private val logger = MarathonLogging.logger("TestCacheSaver")
+    private val logger = MarathonLogging.getLogger(TestCacheSaver::class.java)
 
     private val tasks: Channel<SaveTask> = unboundedChannel()
     private lateinit var completableDeferred: Deferred<Unit>
@@ -38,7 +38,7 @@ class TestCacheSaver(
     suspend fun terminate() {
         tasks.close()
         completableDeferred.await()
-        logger.debug { "Cache saver is terminated" }
+        logger.debug("Terminated test cache saver")
     }
 
     private class SaveTask(val poolId: DevicePoolId, val result: TestResult)

diff --git a/core/src/main/kotlin/com/malinskiy/marathon/cache/test/TestResultsCache.kt b/core/src/main/kotlin/com/malinskiy/marathon/cache/test/TestResultsCache.kt
@@ -18,7 +18,7 @@ class TestResultsCache(
     private val track: Track
 ) {
 
-    private val logger = MarathonLogging.logger("TestResultsCache")
+    private val logger = MarathonLogging.getLogger(TestResultsCache::class.java)
 
     suspend fun load(key: CacheKey, test: Test): TestResult? {
         val start = Instant.now()
@@ -28,8 +28,8 @@ class TestResultsCache(
                 return null
             }
             return reader.testResult
-        } catch (exception: Throwable) {
-            logger.warn("Error during loading cache entry for ${test.toSimpleSafeTestName()}", exception)
+        } catch (e: Throwable) {
+            logger.warn("Error during loading cache entry for {}", test.toSimpleSafeTestName(), e)
             return null
         } finally {
             val finish = Instant.now()
@@ -42,8 +42,8 @@ class TestResultsCache(
         try {
             val writer = TestResultEntryWriter(testResult)
             cacheService.store(key, writer)
-        } catch (exception: Throwable) {
-            logger.warn("Error during storing cache entry for ${testResult.test.toSimpleSafeTestName()}", exception)
+        } catch (e: Throwable) {
+            logger.warn("Error during storing cache entry for {}", testResult.test.toSimpleSafeTestName(), e)
         } finally {
             val finish = Instant.now()
             track.cacheStore(start, finish, testResult.test)

diff --git a/core/src/main/kotlin/com/malinskiy/marathon/exceptions/NoDevicesException.kt b/core/src/main/kotlin/com/malinskiy/marathon/exceptions/NoDevicesException.kt
@@ -1,3 +1,3 @@
 package com.malinskiy.marathon.exceptions
 
-class NoDevicesException(message: String) : RuntimeException(message)
+class NoDevicesException(message: String = "No devices found") : RuntimeException(message)
diff --git a/core/src/main/kotlin/com/malinskiy/marathon/execution/DevicePoolActor.kt b/core/src/main/kotlin/com/malinskiy/marathon/execution/DevicePoolActor.kt
@@ -41,7 +41,7 @@ class DevicePoolActor(
 ) :
     Actor<DevicePoolMessage>(parent = parent, context = context) {
 
-    private val logger = MarathonLogging.logger("DevicePoolActor[${poolId.name}]")
+    private val logger = MarathonLogging.getLogger("DevicePoolActor[${poolId.name}]")
 
     override suspend fun receive(msg: DevicePoolMessage) {
         when (msg) {
@@ -82,7 +82,7 @@ class DevicePoolActor(
     private var noDevicesTimeoutDeferred: Deferred<Unit>? = null
 
     private suspend fun notifyDevices() {
-        logger.debug { "Notify devices" }
+        logger.debug("Notify devices")
         devices.values.forEach {
             it.safeSend(DeviceEvent.WakeUp)
         }
@@ -146,19 +146,19 @@ class DevicePoolActor(
     }
 
     private suspend fun removeDevice(device: Device) {
-        logger.debug { "remove device ${device.serialNumber}" }
+        logger.debug("Removing device {}", device.serialNumber)
         val actor = devices.remove(device.serialNumber)
         actor?.safeSend(DeviceEvent.Terminate)
-        logger.debug { "devices.size = ${devices.size}" }
+        logger.debug("devices.size = {}", devices.size)
         if (noActiveDevices()) {
             if (!queue.stopRequested) return // we may receive new tests in the future
 
             noDevicesTimeoutDeferred?.cancel()
 
-            logger.debug { "scheduling terminating of device pool actor as no devices found" }
+            logger.debug("Scheduling termination of device pool actor as no devices found")
             noDevicesTimeoutDeferred = async(poolJob) {
                 delay(TimeUnit.MINUTES.toMillis(NO_DEVICES_IN_POOL_TIMEOUT_MINUTES))
-                logger.debug { "terminating device pool actor as no devices found after timeout" }
+                logger.debug("Terminating device pool actor as no devices found after timeout")
                 terminate()
             }
         }
@@ -170,11 +170,11 @@ class DevicePoolActor(
 
     private suspend fun addDevice(device: Device) {
         if (devices.containsKey(device.serialNumber)) {
-            logger.warn { "device ${device.serialNumber} already present in pool ${poolId.name}" }
+            logger.warn("Device {} is already present in pool {}", device.serialNumber, poolId.name)
             return
         }
 
-        logger.debug { "add device ${device.serialNumber}" }
+        logger.debug("Adding device {}", device.serialNumber)
 
         noDevicesTimeoutDeferred?.cancel()