logging: kotlin-logging 3.0.5 + logback-classic + AGENTIK_LOG_LEVEL env

Заменил все System.err.println / println на структурное логирование (kotlin-logging, пакет mu) — теперь логи идут с timestamp/level/thread/logger. * gradle/libs.versions.toml: kotlin-logging = "3.0.5" (в прокси доступна только эта версия; новые 7.x пока не подтянуты), logback-classic = "1.5.18". * standalone/build.gradle.kts: implementation(libs.kotlin.logging) + implementation(libs.logback.classic) в jvmMain. * standalone/src/jvmMain/resources/logback.xml: консольный appender, pattern с timestamp/level/thread/logger, level управляется через ${AGENTIK_LOG_LEVEL:-INFO} (env override на старте JVM), уровни io.netty/ai.onnxruntime уведены в WARN чтобы не забивать канал. * Заменены все System.err.println в: ChatConversation (14 callsites), Curator (2), McpRegistry (5), McpConfig (2), Main (2). Startup banner в Main оставлен на println — это user-facing output, не log. * Tests: 288 зелёных (только замена log-вызовов, без изменения семантики). Smoke: `04:53:49.313 INFO [DefaultDispatcher-worker-4] p.b.a.s.agent.memory.Curator - started (interval=1d, maxAge=90d, maxUseCount=0)` подтверждает структурный лог вместо println. AGENTIK_LOG_LEVEL=DEBUG работает.
2026-09-15 04:54:16 +03:00
parent 427ce8a572
commit f5a551b2ae
8 changed files with 75 additions and 25 deletions
@@ -77,6 +77,11 @@ kotlin {
            implementation(libs.ktor.client.cio)
            implementation(libs.ktor.client.content.negotiation)
            implementation(libs.ktor.serialization.kotlinx.json)
+
+            // Логирование: kotlin-logging (тонкая обёртка slf4j-api) + logback-classic
+            // (binding для JVM; без него slf4j-api NOP-логирует и не падает).
+            implementation(libs.kotlin.logging)
+            implementation(libs.logback.classic)
        }

        commonTest.dependencies {
@@ -1,5 +1,8 @@
 package pw.binom.agentik.standalone

+import mu.KotlinLogging
+
+
 import io.ktor.server.cio.CIO
 import io.ktor.server.engine.embeddedServer
 import io.ktor.server.response.respondText
@@ -47,6 +50,7 @@ import java.io.File
 *  - Skills: AGENTIK_SKILLS_DIR=<path> (папка с SKILL.md / *.yaml)
 *  - AGENTIK_SYSTEM_PROMPT (default: встроенный `Ты полезный ассистент...`)
 */
+private val log = KotlinLogging.logger {}
 fun main() {
    val config = AgentikConfig.fromEnv()

@@ -55,7 +59,7 @@ fun main() {
    val mcpRegistry = McpRegistry.fromConfig(config.mcp)
    val skills = config.skillsDir?.let { dir ->
        val result = SkillLoader.loadDirectory(File(dir))
-        result.errors.forEach { System.err.println("[agentik] skill '${it.path}': ${it.message}") }
+        result.errors.forEach { log.warn { "skill '${it.path}': ${it.message}" } }
        result.catalog
    } ?: SkillCatalog.EMPTY

@@ -65,7 +69,7 @@ fun main() {
    val soulBody = config.soulPath?.let { path ->
        val file = File(path)
        if (!file.exists() || !file.isFile) {
-            System.err.println("[agentik] SOUL file not found: $path")
+            log.warn { "SOUL file not found: $path" }
            null
        } else {
            file.readText(Charsets.UTF_8)
@@ -1,5 +1,7 @@
 package pw.binom.agentik.standalone.agent

+import mu.KotlinLogging
+
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Dispatchers
 import kotlinx.coroutines.Job
@@ -223,7 +225,7 @@ class ChatConversation(
            when (c) {
                is Content.Text -> LiteContentPart.Text(c.body)
                is Content.Image -> {
-                    System.err.println("[agentik] dropping image input (v1 text-only): mime=${c.mime}, ${c.data.size} bytes")
+                    log.warn { "dropping image input (v1 text-only): mime=${c.mime}, ${c.data.size} bytes" }
                    null
                }
            }
@@ -288,7 +290,7 @@ class ChatConversation(
        }

        if (loopGuard >= MAX_TOOL_LOOPS) {
-            System.err.println("[agentik] tool loop hit MAX_TOOL_LOOPS=$MAX_TOOL_LOOPS for $id — bailing")
+            log.warn { "tool loop hit MAX_TOOL_LOOPS=$MAX_TOOL_LOOPS for $id — bailing" }
        }

        val assistantId = newId("msg")
@@ -337,7 +339,7 @@ class ChatConversation(
        val notes = try {
            prefetcher.prefetch(userText, topK = 10)
        } catch (e: Throwable) {
-            System.err.println("[agentik] memory prefetch failed: ${e.message}")
+            log.warn(e) { "memory prefetch failed: ${e.message}" }
            return null
        }
        if (notes.isEmpty()) return null
@@ -427,7 +429,7 @@ class ChatConversation(
        }
        if (pendingUser != null) paired.add(pendingUser)
        if (paired.isEmpty()) {
-            System.err.println("[agentik] compactPreTurn: nothing to compact for $id")
+            log.info { "compactPreTurn: nothing to compact for $id" }
            return
        }

@@ -436,7 +438,7 @@ class ChatConversation(
        } catch (e: kotlinx.coroutines.CancellationException) {
            throw e
        } catch (e: Throwable) {
-            System.err.println("[agentik] context summarization failed for $id: ${e.message}")
+            log.warn(e) { "context summarization failed for $id: ${e.message}" }
            return
        }
        if (summaryText.isBlank()) return
@@ -457,16 +459,16 @@ class ChatConversation(
                for (n in decision.toSave) {
                    val note = materializeReviewNote(n, conversationId = null)
                    runCatching { store.upsert(note) }
-                        .onFailure { System.err.println("[agentik] pre-compaction upsert failed: ${it.message}") }
+                        .onFailure { log.warn(it) { "pre-compaction upsert failed: ${it.message}" } }
                }
                for (delId in decision.toDelete) {
                    runCatching { store.delete(delId) }
-                        .onFailure { System.err.println("[agentik] pre-compaction delete failed: ${it.message}") }
+                        .onFailure { log.warn(it) { "pre-compaction delete failed: ${it.message}" } }
                }
            } catch (e: kotlinx.coroutines.CancellationException) {
                throw e
            } catch (e: Throwable) {
-                System.err.println("[agentik] pre-compaction review failed for $id: ${e.message}")
+                log.warn(e) { "pre-compaction review failed for $id: ${e.message}" }
            }
        }

@@ -485,7 +487,7 @@ class ChatConversation(
            toolsChars = toolsChars,
        )
        if (after.toDouble() / window >= compressionThreshold) {
-            System.err.println("[agentik] compactPreTurn: still over threshold for $id (estimated=$after, window=$window, threshold=$compressionThreshold). Consider raising contextWindow or lowering threshold.")
+            log.warn { "compactPreTurn: still over threshold for $id (estimated=$after, window=$window, threshold=$compressionThreshold). Consider raising contextWindow or lowering threshold." }
        }
    }

@@ -543,14 +545,14 @@ class ChatConversation(
                for (n in decision.toSave) {
                    val note = materializeReviewNote(n, conversationId = null)
                    runCatching { store.upsert(note) }
-                        .onFailure { System.err.println("[agentik] review upsert failed: ${it.message}") }
+                        .onFailure { log.warn(it) { "review upsert failed: ${it.message}" } }
                }
                for (id in decision.toDelete) {
                    runCatching { store.delete(id) }
-                        .onFailure { System.err.println("[agentik] review delete failed: ${it.message}") }
+                        .onFailure { log.warn(it) { "review delete failed: ${it.message}" } }
                }
            } catch (e: Throwable) {
-                System.err.println("[agentik] review failed for $convId: ${e.message}")
+                log.warn(e) { "review failed for $convId: ${e.message}" }
            }
        }
    }
@@ -582,13 +584,13 @@ class ChatConversation(

        val tool = toolsByName[call.name]
        val resultText: String = if (tool == null) {
-            System.err.println("[agentik] tool '${call.name}' requested but not registered")
+            log.warn { "tool '${call.name}' requested but not registered" }
            "[tool not found: ${call.name}]"
        } else {
            try {
                tool.tool.invoke(argsJson).ifBlank { "<empty result>" }
            } catch (e: Throwable) {
-                System.err.println("[agentik] tool '${call.name}' threw: ${e.message}")
+                log.warn(e) { "tool '${call.name}' threw: ${e.message}" }
                "[tool error: ${e.message ?: e.javaClass.simpleName}]"
            }
        }
@@ -707,6 +709,8 @@ class ChatConversation(
    }

    companion object {
+        private val log = KotlinLogging.logger {}
+
        private const val MAX_TOOL_LOOPS = 16
        /** Сколько последних ходов оставляем нетронутыми при compaction. */
        private const val KEEP_RECENT_TURNS = 4
@@ -1,5 +1,7 @@
 package pw.binom.agentik.standalone.agent.memory

+import mu.KotlinLogging
+
 import kotlinx.coroutines.CoroutineScope
 import kotlinx.coroutines.Dispatchers
 import kotlinx.coroutines.Job
@@ -32,12 +34,13 @@ class Curator(
    private val clock: Clock = Clock.System,
    private val scope: CoroutineScope = CoroutineScope(Dispatchers.IO),
 ) {
+    private val log = KotlinLogging.logger {}
    private var job: Job? = null

    fun start() {
        if (job != null) return
        job = scope.launch {
-            println("[Curator] started (interval=$interval, maxAge=$maxAge, maxUseCount=$maxUseCount)")
+            log.info { "started (interval=$interval, maxAge=$maxAge, maxUseCount=$maxUseCount)" }
            while (isActive) {
                runPass()
                delay(interval)
@@ -53,7 +56,7 @@ class Curator(
            now = clock.now(),
        )
        if (archived > 0) {
-            println("[Curator] archived $archived stale notes (maxAge=$maxAge, maxUseCount=$maxUseCount)")
+            log.info { "archived $archived stale notes (maxAge=$maxAge, maxUseCount=$maxUseCount)" }
        }
        return archived
    }
@@ -1,5 +1,6 @@
 package pw.binom.agentik.standalone.mcp

+
 import kotlinx.serialization.SerialName
 import kotlinx.serialization.Serializable
 import kotlinx.serialization.json.Json
@@ -57,13 +58,14 @@ data class McpConfig(
    val isEmpty: Boolean get() = servers.isEmpty()

    companion object {
+        private val log = mu.KotlinLogging.logger {}
        private val json = Json { ignoreUnknownKeys = true }

        fun fromEnv(env: (String) -> String? = System::getenv): McpConfig {
            val path = env("AGENTIK_MCP_CONFIG")?.takeIf { it.isNotBlank() } ?: return empty()
            val file = File(path)
            if (!file.exists()) {
-                System.err.println("[agentik] AGENTIK_MCP_CONFIG points to missing file: $path")
+                log.warn { "AGENTIK_MCP_CONFIG points to missing file: $path" }
                return empty()
            }
            return fromJson(file.readText())
@@ -96,7 +98,7 @@ data class McpConfig(
                    ?: emptyMap()
                return McpServerSpec.Stdio(name = name, command = command, args = args, env = env)
            }
-            System.err.println("[agentik] MCP server '$name' has neither 'url' nor 'command' — skipped")
+            log.warn { "MCP server '$name' has neither 'url' nor 'command' — skipped" }
            return null
        }
    }
@@ -1,5 +1,7 @@
 package pw.binom.agentik.standalone.mcp

+import mu.KotlinLogging
+
 import io.ktor.client.HttpClient
 import io.ktor.client.engine.cio.CIO
 import io.ktor.client.plugins.defaultRequest
@@ -42,6 +44,7 @@ import java.util.concurrent.ConcurrentHashMap
 *
 * [close] убивает stdio-процессы и закрывает HTTP-клиент.
 */
+private val log = KotlinLogging.logger {}
 class McpRegistry(
    private val servers: List<McpServerSpec>,
    private val httpClient: HttpClient = defaultHttpClient(),
@@ -72,10 +75,10 @@ class McpRegistry(
                    val server = connectOne(spec)
                    connected[spec.name] = server
                }.onFailure { e ->
-                    System.err.println("[agentik] MCP server '${spec.name}' failed to connect: ${e.message}")
+                    log.warn { "MCP server '${spec.name}' failed to connect: ${e.message}" }
                }
            }
-            System.err.println("[agentik] MCP registry: ${connected.size}/${servers.size} servers connected, ${allTools.size} tools total")
+            log.warn { "MCP registry: ${connected.size}/${servers.size} servers connected, ${allTools.size} tools total" }
        }
    }

@@ -84,7 +87,7 @@ class McpRegistry(
        val transport: Transport = when (spec) {
            is McpServerSpec.Stdio -> {
                val cmd = (listOf(spec.command) + spec.args).joinToString(" ")
-                System.err.println("[agentik] MCP stdio '$spec.name': $cmd")
+                log.warn { "MCP stdio '$spec.name': $cmd" }
                val pb = ProcessBuilder(buildList { add(spec.command); addAll(spec.args) })
                    .redirectErrorStream(false)
                spec.env.forEach { (k, v) -> pb.environment()[k] = v }
@@ -97,7 +100,7 @@ class McpRegistry(
                )
            }
            is McpServerSpec.Http -> {
-                System.err.println("[agentik] MCP http '$spec.name': ${spec.url}")
+                log.warn { "MCP http '$spec.name': ${spec.url}" }
                StreamableHttpClientTransport(
                    client = httpClient.config {
                        if (spec.headers.isNotEmpty()) {
@@ -230,7 +233,7 @@ internal class McpLiteToolAdapter(
                val parsed = json.parseToJsonElement(raw)
                if (parsed !is JsonObject) emptyMap() else parsed.toAnyMap()
            } catch (e: Throwable) {
-                System.err.println("[agentik] MCP tool '$toolName' got invalid args JSON: ${e.message}")
+                log.warn { "MCP tool '$toolName' got invalid args JSON: ${e.message}" }
                emptyMap()
            }
        }
@@ -0,0 +1,23 @@
+<?xml version="1.0" encoding="UTF-8"?>
+<!--
+  Logback-конфиг для standalone.
+  Уровень управляется env var AGENTIK_LOG_LEVEL (default INFO).
+  Формат: timestamp [level] [thread] logger — message
+-->
+<configuration>
+  <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder>
+      <pattern>%d{HH:mm:ss.SSS} %-5level [%thread] %logger{36} - %msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <!-- Default уровень — INFO. Можно перебить через env: AGENTIK_LOG_LEVEL=DEBUG -->
+  <root level="${AGENTIK_LOG_LEVEL:-INFO}">
+    <appender-ref ref="STDOUT"/>
+  </root>
+
+  <!-- Шумные библиотеки уводим в WARN. -->
+  <logger name="io.netty" level="WARN"/>
+  <logger name="io.ktor" level="INFO"/>
+  <logger name="ai.onnxruntime" level="WARN"/>
+</configuration>