Refactor and Json log formatter tests

Author: trueangle

gradle/libs.versions.toml

@@ -7,6 +7,10 @@ serialization = "1.6.3"
 logback = "1.5.6"
 io = "0.5.1"
 date-time = "0.6.0"
+ksp = "2.0.10-1.0.24"
+mockative = "2.2.2"
+allopen = "2.0.20"
+mokkery = "2.3.0"
 
 [libraries]
 kotlin-test = { module = "org.jetbrains.kotlin:kotlin-test", version.ref = "kotlin" }
@@ -25,9 +29,14 @@ ktor-client-curl = { module = "io.ktor:ktor-client-curl", version.ref = "ktor" }
 ktor-client-logging = { module = "io.ktor:ktor-client-logging", version.ref = "ktor" }
 ktor-content-json = { module = "io.ktor:ktor-serialization-kotlinx-json", version.ref = "ktor" }
 ktor-content-negotiation = { module = "io.ktor:ktor-client-content-negotiation", version.ref = "ktor" }
+mockative = { module = "io.mockative:mockative", version.ref = "mockative" }
+mockative-processor = { module = "io.mockative:mockative-processor", version.ref = "mockative" }
 
 [plugins]
 kotlin-jvm = { id = "org.jetbrains.kotlin.jvm", version.ref = "kotlin" }
 kotlin-multiplatform = { id = "org.jetbrains.kotlin.multiplatform", version.ref = "kotlin" }
 ktor = { id = "io.ktor.plugin", version.ref = "ktor" }
-kotlin-serialization = { id = "org.jetbrains.kotlin.plugin.serialization", version.ref = "kotlin" }
+kotlin-serialization = { id = "org.jetbrains.kotlin.plugin.serialization", version.ref = "kotlin" }
+ksp = { id = "com.google.devtools.ksp", version.ref = "ksp" }
+allopen = { id = "org.jetbrains.kotlin.plugin.allopen", version.ref = "allopen" }
+mokkery = { id = "dev.mokkery", version.ref = "mokkery" }

lambda-events/build.gradle.kts

@@ -5,7 +5,14 @@ plugins {
 
 kotlin {
     val isArm64 = System.getProperty("os.arch") == "aarch64"
-    val nativeTarget = if (isArm64) linuxArm64() else linuxX64()
+    val hostOs = System.getProperty("os.name")
+    val isMingwX64 = hostOs.startsWith("Windows")
+    val nativeTarget = when {
+        hostOs == "Mac OS X" -> if(isArm64) macosArm64() else macosX64()
+        hostOs == "Linux" -> if (isArm64) linuxArm64() else linuxX64()
+        isMingwX64 -> mingwX64("native")
+        else -> throw GradleException("Host OS is not supported in Kotlin/Native.")
+    }
 
     sourceSets {
         commonMain.dependencies {

lambda-runtime/build.gradle.kts

@@ -1,29 +1,43 @@
 plugins {
     alias(libs.plugins.kotlin.multiplatform)
     alias(libs.plugins.kotlin.serialization)
+    alias(libs.plugins.mokkery)
+    alias(libs.plugins.allopen)
 }
 
 kotlin {
     val isArm64 = System.getProperty("os.arch") == "aarch64"
-    val nativeTarget = if (isArm64) linuxArm64() else linuxX64()
+    val hostOs = System.getProperty("os.name")
+    val isMingwX64 = hostOs.startsWith("Windows")
+    val nativeTarget = when {
+        hostOs == "Mac OS X" -> if (isArm64) macosArm64() else macosX64()
+        hostOs == "Linux" -> if (isArm64) linuxArm64() else linuxX64()
+        isMingwX64 -> mingwX64("native")
+        else -> throw GradleException("Host OS is not supported in Kotlin/Native.")
+    }
 
     sourceSets {
         commonMain.dependencies {
             implementation(libs.ktor.client.core)
             implementation(libs.kotlin.serialization.json)
             implementation(libs.kotlin.io.core)
             implementation(libs.kotlin.date.time)
-            //implementation(libs.ktor.client.cio)
             implementation(libs.ktor.client.curl)
             implementation(libs.ktor.client.logging)
             implementation(libs.ktor.content.negotiation)
             implementation(libs.ktor.content.json)
         }
 
-        nativeMain.dependencies {}
-
-        commonTest.dependencies {
+        nativeTest.dependencies {
             implementation(libs.kotlin.test)
         }
     }
 }
+
+fun isTestingTask(name: String) = name.endsWith("Test")
+val isTesting = gradle.startParameter.taskNames.any(::isTestingTask)
+
+if (isTesting) allOpen {
+    annotation("kotlin.Metadata")
+}
+

lambda-runtime/src/commonMain/kotlin/io/github/trueangle/knative/lambda/runtime/LambdaRuntime.kt

@@ -3,18 +3,15 @@ package io.github.trueangle.knative.lambda.runtime
 import io.github.trueangle.knative.lambda.runtime.LambdaEnvironmentException.NonRecoverableStateException
 import io.github.trueangle.knative.lambda.runtime.api.Context
 import io.github.trueangle.knative.lambda.runtime.api.LambdaClient
-import io.github.trueangle.knative.lambda.runtime.api.dto.LogMessageDto
 import io.github.trueangle.knative.lambda.runtime.handler.LambdaBufferedHandler
 import io.github.trueangle.knative.lambda.runtime.handler.LambdaHandler
 import io.github.trueangle.knative.lambda.runtime.handler.LambdaStreamHandler
 import io.github.trueangle.knative.lambda.runtime.log.KtorLogger
 import io.github.trueangle.knative.lambda.runtime.log.Log
-import io.github.trueangle.knative.lambda.runtime.log.LogLevel
 import io.ktor.client.HttpClient
 import io.ktor.client.engine.curl.Curl
 import io.ktor.client.plugins.HttpTimeout
 import io.ktor.client.plugins.contentnegotiation.ContentNegotiation
-import io.ktor.client.plugins.logging.Logger
 import io.ktor.client.plugins.logging.Logging
 import io.ktor.http.content.OutgoingContent.WriteChannelContent
 import io.ktor.serialization.kotlinx.json.json
@@ -23,20 +20,17 @@ import io.ktor.util.reflect.typeInfo
 import io.ktor.utils.io.ByteWriteChannel
 import io.ktor.utils.io.writeStringUtf8
 import kotlinx.coroutines.runBlocking
+import kotlinx.serialization.ExperimentalSerializationApi
 import kotlinx.serialization.json.Json
-import kotlinx.serialization.modules.SerializersModule
 import kotlin.system.exitProcess
-import kotlin.time.TimeSource
-import io.ktor.client.plugins.logging.LogLevel as KtorLogLevel
 
 object LambdaRuntime {
+    @OptIn(ExperimentalSerializationApi::class)
+    internal val json = Json { explicitNulls = false }
+
     private val httpClient = HttpClient(Curl) {
         install(HttpTimeout)
-        install(ContentNegotiation) {
-            json(Json {
-                explicitNulls = false
-            })
-        }
+        install(ContentNegotiation) { json(json) }
         install(Logging) {
             val kLogger = KtorLogger()
             level = kLogger.getLevel()

lambda-runtime/src/commonMain/kotlin/io/github/trueangle/knative/lambda/runtime/api/dto/LogMessageDto.kt

@@ -13,9 +13,10 @@ internal data class LogMessageDto<T>(
     @SerialName("timestamp")
     val timestamp: String,
     @SerialName("message")
+    @Contextual
     val message: T?,
     @SerialName("level")
     val level: LogLevel,
     @SerialName("AWSRequestId")
-    val awsRequestId: String? = null
+    val awsRequestId: String?
 )

lambda-runtime/src/commonMain/kotlin/io/github/trueangle/knative/lambda/runtime/log/JsonLogFormatter.kt

@@ -2,35 +2,36 @@ package io.github.trueangle.knative.lambda.runtime.log
 
 import io.github.trueangle.knative.lambda.runtime.api.Context
 import io.github.trueangle.knative.lambda.runtime.api.dto.LogMessageDto
+import io.ktor.util.reflect.TypeInfo
 import kotlinx.datetime.Clock
-import kotlinx.serialization.InternalSerializationApi
 import kotlinx.serialization.SerializationException
 import kotlinx.serialization.encodeToString
 import kotlinx.serialization.json.Json
 import kotlinx.serialization.serializer
 
-@OptIn(InternalSerializationApi::class)
-internal class JsonLogFormatter : LogFormatter {
+internal class JsonLogFormatter(
+    private val json: Json,
+    private val clock: Clock = Clock.System,
+) : LogFormatter {
     private var requestContext: Context? = null
 
-    override fun format(logLevel: LogLevel, message: Any?): String {
+    override fun <T> format(logLevel: LogLevel, message: T?, messageType: TypeInfo): String {
         val json = try {
-            Json.encodeToString(
+            val messageSerializer = serializer(messageType.reifiedType)
+            val dtoSerializer = LogMessageDto.serializer(messageSerializer)
+            json.encodeToString(
+                dtoSerializer,
                 LogMessageDto(
-                    timestamp = Clock.System.now().toString(),
-                    message = if (message is Throwable) message.prettyPrint() else message?.let {
-                        it::class.serializer()
-                    },
+                    timestamp = clock.now().toString(),
+                    message = if (message is Throwable) message.prettyPrint() else message,
                     level = logLevel,
                     awsRequestId = requestContext?.awsRequestId
                 )
             )
         } catch (e: SerializationException) {
-            Log.warn("Log serialisation error: ${e.message}")
-
-            Json.encodeToString(
+            json.encodeToString(
                 LogMessageDto(
-                    timestamp = Clock.System.now().toString(),
+                    timestamp = clock.now().toString(),
                     message = message?.toString(),
                     level = logLevel,
                     awsRequestId = requestContext?.awsRequestId

lambda-runtime/src/commonMain/kotlin/io/github/trueangle/knative/lambda/runtime/log/Log.kt

@@ -1,59 +1,64 @@
 package io.github.trueangle.knative.lambda.runtime.log
 
 import io.github.trueangle.knative.lambda.runtime.LambdaEnvironment
+import io.github.trueangle.knative.lambda.runtime.LambdaRuntime
 import io.github.trueangle.knative.lambda.runtime.api.Context
+import io.github.trueangle.knative.lambda.runtime.log.Log.write
+import io.ktor.util.reflect.TypeInfo
+import io.ktor.util.reflect.typeInfo
 
 internal interface LogWriter {
     fun write(level: LogLevel, message: Any?)
 }
 
 internal interface LogFormatter {
-    fun format(logLevel: LogLevel, message: Any?): Any?
-    fun onContextAvailable(context: Context) {}
+    fun <T> format(logLevel: LogLevel, message: T?, messageType: TypeInfo): String?
+    fun onContextAvailable(context: Context) = Unit
 }
 
 object Log {
     @PublishedApi
     internal val currentLogLevel = LogLevel.fromEnv()
     private val writer = StdoutLogWriter()
     private val logFormatter = if (LambdaEnvironment.LAMBDA_LOG_FORMAT == "JSON") {
-        JsonLogFormatter()
+        JsonLogFormatter(LambdaRuntime.json)
     } else {
         TextLogFormatter()
     }
 
-    fun trace(message: Any?) {
-        write(LogLevel.TRACE, message)
+    inline fun <reified T> trace(message: T?) {
+        write(LogLevel.TRACE, message, typeInfo<T>())
     }
 
-    fun debug(message: Any?) {
-        write(LogLevel.DEBUG, message)
+    inline fun <reified T> debug(message: T?) {
+        write(LogLevel.DEBUG, message, typeInfo<T>())
     }
 
-    fun info(message: Any?) {
-        write(LogLevel.INFO, message)
+    inline fun <reified T> info(message: T?) {
+        write(LogLevel.INFO, message, typeInfo<T>())
     }
 
-    fun warn(message: Any?) {
-        write(LogLevel.WARN, message)
+    inline fun <reified T> warn(message: T?) {
+        write(LogLevel.WARN, message, typeInfo<T>())
     }
 
-    fun error(message: Any?) {
-        write(LogLevel.ERROR, message)
+    inline fun <reified T> error(message: T?) {
+        write(LogLevel.ERROR, message, typeInfo<T>())
     }
 
-    fun fatal(message: Any?) {
-        write(LogLevel.FATAL, message)
+    inline fun <reified T> fatal(message: T?) {
+        write(LogLevel.FATAL, message, typeInfo<T>())
     }
 
     @PublishedApi
     internal fun setContext(context: Context) {
         logFormatter.onContextAvailable(context)
     }
 
-    private fun write(level: LogLevel, message: Any?) {
+    @PublishedApi
+    internal fun write(level: LogLevel, message: Any?, typeInfo: TypeInfo) {
         if (level >= currentLogLevel) {
-            writer.write(level, logFormatter.format(level, message))
+            writer.write(level, logFormatter.format(level, message, typeInfo))
         }
     }
 }

lambda-runtime/src/commonMain/kotlin/io/github/trueangle/knative/lambda/runtime/log/TextLogFormatter.kt

@@ -1,7 +1,9 @@
 package io.github.trueangle.knative.lambda.runtime.log
 
+import io.ktor.util.reflect.TypeInfo
+
 internal class TextLogFormatter : LogFormatter {
-    override fun format(logLevel: LogLevel, message: Any?): String? = message?.let {
+    override fun <T> format(logLevel: LogLevel, message: T?, typeInfo: TypeInfo) = message?.let {
         buildString {
             append("[${logLevel.toString().uppercase()}] | ")
             append(if (message is Throwable) message.prettyPrint() else message.toString())

lambda-runtime/src/nativeTest/kotlin/io/github/trueangle/knative/lambda/runtime/JsonLogFormatterTest.kt

@@ -0,0 +1,89 @@
+package io.github.trueangle.knative.lambda.runtime
+
+import dev.mokkery.answering.returns
+import dev.mokkery.every
+import dev.mokkery.mock
+import io.github.trueangle.knative.lambda.runtime.api.dto.LogMessageDto
+import io.github.trueangle.knative.lambda.runtime.log.JsonLogFormatter
+import io.github.trueangle.knative.lambda.runtime.log.LogLevel
+import io.ktor.util.reflect.typeInfo
+import kotlinx.datetime.Clock
+import kotlinx.serialization.ExperimentalSerializationApi
+import kotlinx.serialization.Serializable
+import kotlinx.serialization.encodeToString
+import kotlinx.serialization.json.Json
+import kotlin.test.Test
+import kotlin.test.assertEquals
+
+class JsonLogFormatterTest {
+    private val clock = mock<Clock>()
+    private val requestId = "awsRequestId"
+    private val timestamp = Clock.System.now()
+
+    @OptIn(ExperimentalSerializationApi::class)
+    private val formatter = JsonLogFormatter(clock = clock, json = Json { explicitNulls = true }).apply {
+        onContextAvailable(mockContext(requestId))
+    }
+
+    @Test
+    fun `GIVEN message of object WHEN format THEN json`() {
+        val message = SampleObject("Hello world")
+
+        every { clock.now() } returns (timestamp)
+
+        val expected = Json.encodeToString(
+            LogMessageDto(
+                timestamp = timestamp.toString(),
+                message = message,
+                level = LogLevel.INFO,
+                awsRequestId = requestId
+            )
+        )
+        val actual = formatter.format(LogLevel.INFO, message, typeInfo<SampleObject>())
+
+        assertEquals(expected, actual)
+    }
+
+    @Test
+    fun `GIVEN message of primitive WHEN format THEN json`() {
+        val message = "Hello world"
+
+        every { clock.now() } returns (timestamp)
+
+        val expected = Json.encodeToString(
+            LogMessageDto(
+                timestamp = timestamp.toString(),
+                message = message,
+                level = LogLevel.INFO,
+                awsRequestId = requestId
+            )
+        )
+        val actual = formatter.format(LogLevel.INFO, message, typeInfo<String>())
+
+        assertEquals(expected, actual)
+    }
+
+    @Test
+    fun `GIVEN non-serializable message object WHEN format THEN json`() {
+        val message = NoSerialObject("Hello world")
+
+        every { clock.now() } returns (timestamp)
+
+        val expected = Json.encodeToString(
+            LogMessageDto(
+                timestamp = timestamp.toString(),
+                message = message.toString(),
+                level = LogLevel.INFO,
+                awsRequestId = requestId
+            )
+        )
+        val actual = formatter.format(LogLevel.INFO, message, typeInfo<NoSerialObject>())
+
+        assertEquals(expected, actual)
+    }
+
+    @Serializable
+    private data class SampleObject(val hello: String)
+
+    private data class NoSerialObject(val hello: String)
+}