KotlinX Coroutines SLF4J

KotlinコルーチンとSLF4JのMDC(Mapped Diagnostic Context)統合を提供するライブラリ。コルーチンコンテキストにMDCを追加し、非同期処理間でのロギングコンテキスト保持を可能にする。

ロギングライブラリKotlinコルーチンSLF4JMDC非同期トレーサビリティ

ライブラリ

KotlinX Coroutines SLF4J

概要

KotlinX Coroutines SLF4Jは、KotlinコルーチンとSLF4JのMDC(Mapped Diagnostic Context)統合を提供する公式ライブラリです。コルーチンコンテキストにMDCを追加し、非同期処理間でのロギングコンテキスト保持を可能にします。分散システムやマイクロサービス環境でのトレーサビリティ向上と、コルーチンベースのサーバーサイドKotlin開発において重要な役割を果たしています。

詳細

KotlinX Coroutines SLF4Jは、Kotlinコルーチンエコシステムの公式モジュールとして2025年において重要性が増加しています。従来のJavaログ実装では、スレッドローカル変数を利用したMDCコンテキスト管理が主流でしたが、コルーチンの非同期性とスレッド切り替えにより、MDC情報が失われる問題がありました。本ライブラリはMDCContextを通じてコルーチンコンテキスト内でMDC情報を保持し、launchasyncなどのコルーチンビルダーで自動的にMDCコンテキストを継承します。

主な特徴

  • MDCコンテキスト統合: SLF4JのMDCとKotlinコルーチンコンテキストの自動統合
  • 非同期ロギング: コルーチン間でのトレーサビリティ情報の自動伝播
  • スレッド切り替え対応: ディスパッチャー間でのMDC情報保持
  • 簡単な統合: 既存のSLF4J/logbackセットアップとの完全互換性
  • 分散トレーシング: リクエストIDやユーザーIDなどの追跡情報管理
  • パフォーマンス最適化: 軽量なコルーチンコンテキスト実装

メリット・デメリット

メリット

  • コルーチンベースアプリケーションでの確実なMDCコンテキスト管理
  • 分散システムでのリクエストトレーシングとデバッグ性向上
  • 既存のSLF4J/logbackエコシステムとの完全な互換性維持
  • JetBrains公式モジュールとしての信頼性と長期サポート
  • 最小限のAPIとシンプルな統合プロセス
  • Spring BootやKtorなどのWebフレームワークとの良好な統合

デメリット

  • SLF4Jエコシステムへの依存が必要でライブラリサイズ増加
  • Kloggingなどの現代的コルーチンネイティブロガーに比べた機能限定
  • MDC使用時のメモリオーバーヘッドとパフォーマンス影響
  • 複雑なコルーチン階層でのコンテキスト継承の理解困難性
  • Structured loggingサポートの限定性
  • コルーチンキャンセレーション時のMDCクリーンアップの複雑さ

参考ページ

書き方の例

インストールとセットアップ

// build.gradle.kts
dependencies {
    implementation("org.jetbrains.kotlinx:kotlinx-coroutines-slf4j:1.8.0")
    implementation("org.jetbrains.kotlinx:kotlinx-coroutines-core:1.8.0")
    implementation("ch.qos.logback:logback-classic:1.4.14")
}

// Logback設定 (logback.xml)
<configuration>
    <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
        <encoder>
            <pattern>[%X{requestId}] %d{HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
    </appender>
    
    <appender name="FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
        <file>app.log</file>
        <encoder>
            <pattern>[%X{requestId}] [%X{userId}] %d{yyyy-MM-dd HH:mm:ss.SSS} [%thread] %-5level %logger{36} - %msg%n</pattern>
        </encoder>
        <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
            <fileNamePattern>app.%d{yyyy-MM-dd}.log</fileNamePattern>
            <maxHistory>30</maxHistory>
        </rollingPolicy>
    </appender>
    
    <root level="INFO">
        <appender-ref ref="CONSOLE" />
        <appender-ref ref="FILE" />
    </root>
</configuration>

基本的なMDCContext使用

import kotlinx.coroutines.*
import kotlinx.coroutines.slf4j.MDCContext
import org.slf4j.LoggerFactory
import org.slf4j.MDC

private val logger = LoggerFactory.getLogger("Application")

suspend fun main() = runBlocking {
    // MDCコンテキストを設定してコルーチンを起動
    MDC.put("requestId", "req-123456")
    MDC.put("userId", "user-789")
    
    launch(MDCContext()) {
        logger.info("メインタスク開始") // [req-123456] [user-789] メインタスク開始
        processData()
    }.join()
    
    // MDCをクリア
    MDC.clear()
}

suspend fun processData() {
    logger.info("データ処理開始") // MDCコンテキストが自動的に保持される
    
    // 並行処理でもMDCが継承される
    val results = coroutineScope {
        listOf(
            async { processStep("ステップ1") },
            async { processStep("ステップ2") },
            async { processStep("ステップ3") }
        )
    }
    
    logger.info("すべての処理完了: ${results.awaitAll()}")
}

suspend fun processStep(step: String): String {
    delay(100) // 非同期処理のシミュレーション
    logger.info("$step 実行中") // MDCコンテキストが保持される
    return "$step 完了"
}

Webアプリケーションでのリクエストトレーシング

import io.ktor.server.application.*
import io.ktor.server.engine.*
import io.ktor.server.netty.*
import io.ktor.server.response.*
import io.ktor.server.routing.*
import kotlinx.coroutines.async
import kotlinx.coroutines.slf4j.MDCContext
import org.slf4j.LoggerFactory
import org.slf4j.MDC
import java.util.*

private val logger = LoggerFactory.getLogger("WebApp")

fun main() {
    embeddedServer(Netty, port = 8080) {
        routing {
            get("/api/users/{id}") {
                // リクエストごとのユニークID生成
                val requestId = UUID.randomUUID().toString()
                val userId = call.parameters["id"] ?: "unknown"
                
                // MDCにトレーシング情報を設定
                MDC.put("requestId", requestId)
                MDC.put("userId", userId)
                MDC.put("endpoint", "/api/users/$userId")
                
                try {
                    // MDCContext付きでコルーチンを起動
                    val userInfo = async(MDCContext()) {
                        fetchUserInfo(userId)
                    }
                    
                    val preferences = async(MDCContext()) {
                        fetchUserPreferences(userId)
                    }
                    
                    // 結果をまとめて返す
                    val response = mapOf(
                        "user" to userInfo.await(),
                        "preferences" to preferences.await()
                    )
                    
                    logger.info("ユーザー情報取得完了")
                    call.respond(response)
                    
                } catch (e: Exception) {
                    logger.error("ユーザー情報取得エラー", e)
                    call.respond(mapOf("error" to "Internal Server Error"))
                } finally {
                    // MDCをクリア(リクエスト終了時)
                    MDC.clear()
                }
            }
        }
    }.start(wait = true)
}

suspend fun fetchUserInfo(userId: String): Map<String, Any> {
    logger.info("ユーザー基本情報取得開始")
    
    // データベースアクセスのシミュレーション
    delay(200)
    
    val userInfo = mapOf(
        "id" to userId,
        "name" to "ユーザー$userId",
        "email" to "user$userId@example.com"
    )
    
    logger.info("ユーザー基本情報取得完了")
    return userInfo
}

suspend fun fetchUserPreferences(userId: String): Map<String, Any> {
    logger.info("ユーザー設定情報取得開始")
    
    // 外部API呼び出しのシミュレーション
    delay(150)
    
    val preferences = mapOf(
        "theme" to "dark",
        "language" to "ja",
        "notifications" to true
    )
    
    logger.info("ユーザー設定情報取得完了")
    return preferences
}

Spring Boot統合とログフィルター

import kotlinx.coroutines.slf4j.MDCContext
import kotlinx.coroutines.launch
import kotlinx.coroutines.runBlocking
import org.slf4j.LoggerFactory
import org.slf4j.MDC
import org.springframework.boot.autoconfigure.SpringBootApplication
import org.springframework.boot.runApplication
import org.springframework.stereotype.Component
import org.springframework.stereotype.Service
import org.springframework.web.bind.annotation.GetMapping
import org.springframework.web.bind.annotation.PathVariable
import org.springframework.web.bind.annotation.RestController
import org.springframework.web.server.ServerWebExchange
import org.springframework.web.server.WebFilter
import org.springframework.web.server.WebFilterChain
import reactor.core.publisher.Mono
import java.util.*

@SpringBootApplication
class LoggingApplication

fun main(args: Array<String>) {
    runApplication<LoggingApplication>(*args)
}

// MDC設定用WebFilter
@Component
class MDCWebFilter : WebFilter {
    
    override fun filter(exchange: ServerWebExchange, chain: WebFilterChain): Mono<Void> {
        val requestId = UUID.randomUUID().toString()
        val path = exchange.request.path.value()
        
        // リクエスト開始時にMDC設定
        MDC.put("requestId", requestId)
        MDC.put("path", path)
        MDC.put("method", exchange.request.method.name())
        
        return chain.filter(exchange)
            .doFinally {
                // リクエスト終了時にMDCクリア
                MDC.clear()
            }
    }
}

@RestController
class UserController(private val userService: UserService) {
    
    private val logger = LoggerFactory.getLogger(UserController::class.java)
    
    @GetMapping("/users/{id}")
    suspend fun getUser(@PathVariable id: String): Map<String, Any> {
        logger.info("ユーザー取得要求: ID=$id")
        
        return runBlocking {
            // MDCContext付きでサービス呼び出し
            launch(MDCContext()) {
                userService.getUserWithDetails(id)
            }.let { it.join(); userService.lastResult }
        }
    }
}

@Service
class UserService {
    private val logger = LoggerFactory.getLogger(UserService::class.java)
    
    var lastResult: Map<String, Any> = emptyMap()
        private set
    
    suspend fun getUserWithDetails(userId: String): Map<String, Any> {
        logger.info("ユーザー詳細情報サービス開始")
        
        // MDCコンテキストは自動的に継承される
        val basicInfo = fetchBasicInfo(userId)
        val permissions = fetchPermissions(userId)
        val activity = fetchRecentActivity(userId)
        
        lastResult = mapOf(
            "basic" to basicInfo,
            "permissions" to permissions,
            "activity" to activity
        )
        
        logger.info("ユーザー詳細情報サービス完了")
        return lastResult
    }
    
    private suspend fun fetchBasicInfo(userId: String): Map<String, String> {
        logger.info("基本情報取得開始")
        delay(100)
        logger.info("基本情報取得完了")
        return mapOf("id" to userId, "name" to "User$userId")
    }
    
    private suspend fun fetchPermissions(userId: String): List<String> {
        logger.info("権限情報取得開始")
        delay(50)
        logger.info("権限情報取得完了")
        return listOf("read", "write")
    }
    
    private suspend fun fetchRecentActivity(userId: String): List<String> {
        logger.info("アクティビティ取得開始")
        delay(75)
        logger.info("アクティビティ取得完了")
        return listOf("login", "view_profile", "update_settings")
    }
}

エラーハンドリングとログ集約

import kotlinx.coroutines.*
import kotlinx.coroutines.slf4j.MDCContext
import org.slf4j.LoggerFactory
import org.slf4j.MDC

private val logger = LoggerFactory.getLogger("ErrorHandling")

// カスタム例外クラス
class BusinessException(message: String, val errorCode: String) : Exception(message)
class ValidationException(message: String, val field: String) : Exception(message)

suspend fun main() = runBlocking {
    // エラー処理とログ集約のデモ
    val requests = listOf("valid-123", "invalid-", "", "error-456", "valid-789")
    
    requests.forEach { requestId ->
        launch(MDCContext()) {
            try {
                MDC.put("requestId", requestId)
                MDC.put("operation", "processRequest")
                
                processRequest(requestId)
                
            } catch (e: Exception) {
                handleError(e, requestId)
            } finally {
                MDC.clear()
            }
        }
    }
}

suspend fun processRequest(requestId: String) {
    logger.info("リクエスト処理開始")
    
    try {
        // バリデーション
        validateRequest(requestId)
        
        // ビジネスロジック実行
        val result = executeBusinessLogic(requestId)
        
        // 結果保存
        saveResult(requestId, result)
        
        logger.info("リクエスト処理正常完了")
        
    } catch (e: ValidationException) {
        // バリデーションエラーのMDC情報追加
        MDC.put("errorType", "validation")
        MDC.put("field", e.field)
        logger.warn("バリデーションエラー: ${e.message}")
        throw e
        
    } catch (e: BusinessException) {
        // ビジネスエラーのMDC情報追加
        MDC.put("errorType", "business")
        MDC.put("errorCode", e.errorCode)
        logger.error("ビジネスロジックエラー: ${e.message}")
        throw e
        
    } catch (e: Exception) {
        // システムエラーのMDC情報追加
        MDC.put("errorType", "system")
        logger.error("システムエラー", e)
        throw e
    }
}

suspend fun validateRequest(requestId: String) {
    logger.debug("リクエストバリデーション開始")
    
    when {
        requestId.isEmpty() -> {
            throw ValidationException("リクエストIDが空です", "requestId")
        }
        requestId.contains("invalid") -> {
            throw ValidationException("無効なリクエストID形式", "requestId")
        }
        requestId.length < 3 -> {
            throw ValidationException("リクエストIDが短すぎます", "requestId")
        }
    }
    
    logger.debug("リクエストバリデーション完了")
}

suspend fun executeBusinessLogic(requestId: String): String {
    logger.info("ビジネスロジック実行開始")
    
    // エラーケースのシミュレーション
    if (requestId.contains("error")) {
        throw BusinessException("ビジネスルール違反", "BUSINESS_001")
    }
    
    // 処理時間のシミュレーション
    delay(100)
    
    val result = "処理結果-$requestId"
    logger.info("ビジネスロジック実行完了")
    return result
}

suspend fun saveResult(requestId: String, result: String) {
    logger.info("結果保存開始")
    
    // データベース保存のシミュレーション
    delay(50)
    
    logger.info("結果保存完了: $result")
}

fun handleError(exception: Exception, requestId: String) {
    when (exception) {
        is ValidationException -> {
            logger.info("バリデーションエラーを適切に処理しました")
            // クライアントに400エラーを返す処理
        }
        is BusinessException -> {
            logger.info("ビジネスエラーを適切に処理しました")
            // クライアントに422エラーを返す処理
        }
        else -> {
            logger.error("予期しないエラーが発生しました", exception)
            // クライアントに500エラーを返す処理
        }
    }
}

// ログ集約用のユーティリティ関数
object LogUtils {
    fun addTransactionContext(transactionId: String, userId: String? = null) {
        MDC.put("transactionId", transactionId)
        userId?.let { MDC.put("userId", it) }
    }
    
    fun addPerformanceContext(operation: String, startTime: Long) {
        MDC.put("operation", operation)
        MDC.put("startTime", startTime.toString())
    }
    
    fun logPerformance(operation: String, startTime: Long) {
        val duration = System.currentTimeMillis() - startTime
        MDC.put("duration", duration.toString())
        logger.info("パフォーマンス: $operation 実行時間=${duration}ms")
    }
}

高度なマイクロサービス統合

import kotlinx.coroutines.*
import kotlinx.coroutines.slf4j.MDCContext
import org.slf4j.LoggerFactory
import org.slf4j.MDC
import java.util.*

private val logger = LoggerFactory.getLogger("MicroserviceIntegration")

// 分散トレーシング用のコンテキスト
data class TraceContext(
    val traceId: String,
    val spanId: String,
    val parentSpanId: String? = null,
    val userId: String? = null,
    val serviceName: String
)

object DistributedTracing {
    
    fun createRootTrace(userId: String? = null, serviceName: String = "main"): TraceContext {
        return TraceContext(
            traceId = UUID.randomUUID().toString(),
            spanId = UUID.randomUUID().toString(),
            userId = userId,
            serviceName = serviceName
        )
    }
    
    fun createChildSpan(parent: TraceContext, serviceName: String): TraceContext {
        return parent.copy(
            spanId = UUID.randomUUID().toString(),
            parentSpanId = parent.spanId,
            serviceName = serviceName
        )
    }
    
    fun setupMDC(context: TraceContext) {
        MDC.put("traceId", context.traceId)
        MDC.put("spanId", context.spanId)
        context.parentSpanId?.let { MDC.put("parentSpanId", it) }
        context.userId?.let { MDC.put("userId", it) }
        MDC.put("serviceName", context.serviceName)
    }
}

// マイクロサービス間通信のシミュレーション
class OrderService {
    
    suspend fun processOrder(userId: String, orderId: String): String = coroutineScope {
        val traceContext = DistributedTracing.createRootTrace(userId, "order-service")
        DistributedTracing.setupMDC(traceContext)
        
        logger.info("注文処理開始: orderId=$orderId")
        
        try {
            // 並行してマイクロサービスを呼び出し
            val userInfoDeferred = async(MDCContext()) {
                callUserService(traceContext, userId)
            }
            
            val inventoryDeferred = async(MDCContext()) {
                callInventoryService(traceContext, orderId)
            }
            
            val paymentDeferred = async(MDCContext()) {
                callPaymentService(traceContext, userId, orderId)
            }
            
            // すべてのサービス呼び出し完了を待機
            val userInfo = userInfoDeferred.await()
            val inventoryResult = inventoryDeferred.await()
            val paymentResult = paymentDeferred.await()
            
            // 最終的な注文確定処理
            val finalResult = finalizeOrder(traceContext, orderId, userInfo, inventoryResult, paymentResult)
            
            logger.info("注文処理正常完了: result=$finalResult")
            finalResult
            
        } catch (e: Exception) {
            logger.error("注文処理エラー", e)
            throw e
        }
    }
    
    private suspend fun callUserService(parentContext: TraceContext, userId: String): String {
        val childContext = DistributedTracing.createChildSpan(parentContext, "user-service")
        DistributedTracing.setupMDC(childContext)
        
        logger.info("ユーザーサービス呼び出し開始")
        
        // 外部サービス呼び出しのシミュレーション
        delay(150)
        
        if (userId == "error-user") {
            throw RuntimeException("ユーザーサービスエラー")
        }
        
        val result = "ユーザー情報取得完了:$userId"
        logger.info("ユーザーサービス呼び出し完了")
        return result
    }
    
    private suspend fun callInventoryService(parentContext: TraceContext, orderId: String): String {
        val childContext = DistributedTracing.createChildSpan(parentContext, "inventory-service")
        DistributedTracing.setupMDC(childContext)
        
        logger.info("在庫サービス呼び出し開始")
        
        delay(100)
        
        val result = "在庫確認完了:$orderId"
        logger.info("在庫サービス呼び出し完了")
        return result
    }
    
    private suspend fun callPaymentService(parentContext: TraceContext, userId: String, orderId: String): String {
        val childContext = DistributedTracing.createChildSpan(parentContext, "payment-service")
        DistributedTracing.setupMDC(childContext)
        
        logger.info("決済サービス呼び出し開始")
        
        delay(200)
        
        val result = "決済処理完了:$userId-$orderId"
        logger.info("決済サービス呼び出し完了")
        return result
    }
    
    private suspend fun finalizeOrder(
        context: TraceContext,
        orderId: String,
        userInfo: String,
        inventoryResult: String,
        paymentResult: String
    ): String {
        DistributedTracing.setupMDC(context)
        
        logger.info("注文確定処理開始")
        
        // 注文確定処理のシミュレーション
        delay(75)
        
        val finalResult = "注文確定:$orderId"
        logger.info("注文確定処理完了")
        return finalResult
    }
}

// デモ実行
suspend fun main() = runBlocking {
    val orderService = OrderService()
    
    // 複数の注文を並行処理
    val orders = listOf(
        "user1" to "order-001",
        "user2" to "order-002",
        "error-user" to "order-003",
        "user3" to "order-004"
    )
    
    orders.map { (userId, orderId) ->
        async {
            try {
                orderService.processOrder(userId, orderId)
            } catch (e: Exception) {
                logger.error("注文処理失敗: userId=$userId, orderId=$orderId", e)
                "失敗:$orderId"
            } finally {
                MDC.clear()
            }
        }
    }.awaitAll()
    
    logger.info("すべての注文処理完了")
}