Logging Strategy

This document defines logging conventions for the Bidder backend application.


Quick Reference

RuleDescription
LibraryUse kotlin-logging (not raw SLF4J)
Logger locationPrivate field inside the class
ReadabilityLogging must not pollute business logic
LevelsINFO/DEBUG/WARN/ERROR with specific purposes
StacktracesAlways include for ERROR level
Sensitive dataDEBUG only; never log passwords/tokens
DuplicationEach event logged in one place only
GET operationsDon't log reads; log decisions based on data
Simple opsOne log per operation, not start + end
Library callsDon't wrap library calls that log internally

Logger Setup

Use Kotlin-Logging Library

Always use kotlin-logging wrapper, not raw SLF4J.

import io.github.oshai.kotlinlogging.KotlinLogging

Logger as Private Field

Logger must be created as a private field inside the class (not companion object, not top-level).

class CampaignServiceImpl(
    private val campaignDao: CampaignDao
) : CampaignService {

    private val logger = KotlinLogging.logger {}

    // ...
}

Code Readability

Logging Must Not Pollute Business Logic

Keep logging unobtrusive. Prefer logging at boundaries (entry/exit points, error handlers) rather than scattering verbose log statements through core logic.

// ✗ Bad - cluttered business logic
suspend fun processOrder(order: Order): Result {
    logger.debug { "Starting order processing" }
    val validated = validator.validate(order)
    logger.debug { "Validation complete: $validated" }
    val enriched = enricher.enrich(validated)
    logger.debug { "Enrichment complete: $enriched" }
    val saved = repository.save(enriched)
    logger.debug { "Save complete: $saved" }
    return saved
}

// ✓ Good - clean with boundary logging
suspend fun processOrder(order: Order): Result {
    logger.info { "Processing order=${order.id}" }
    return validator.validate(order)
        .let { enricher.enrich(it) }
        .let { repository.save(it) }
        .also { logger.info { "Order processed successfully id=${it.id}" } }
}

Use .also {} for Chain Logging

When logging is needed within function chains, use .also {} to maintain readability.

campaignRepository.findById(id)
    .also { logger.debug { "Found campaign: ${it.id}, status=${it.status}" } }
    .toDto()

Logging Levels

LevelPurposeExample
INFOGeneral trace of business operations"Creating campaign for project=$projectId"
DEBUGInformation to trace decisions"Using strategy=$strategy based on config"
WARNBusiness failures, events needing attention"Campaign $id has no active slots - skipping"
ERRORSystem faults (infrastructure, unexpected)"Failed to connect to database"

Level Usage Examples

// INFO - business operation trace
logger.info { "Starting campaign sync for organization=$orgId" }
logger.info { "Campaign created id=$campaignId" }

// DEBUG - decision tracing
logger.debug { "Selected placement strategy=$strategy for campaign=$id" }
logger.debug { "Skipping sync: lastSync=$lastSync within threshold" }

// WARN - business issues needing attention
logger.warn { "Campaign $id budget exhausted, pausing" }
logger.warn { "Account $accountId has invalid credentials" }

// ERROR - system faults (always with exception)
logger.error(ex) { "Failed to fetch campaigns from Wildberries API" }
logger.error(ex) { "Database connection lost during transaction" }

Error Logging

Always Include Stacktraces

ERROR level logs must include the exception to preserve stacktrace.

// ✓ Correct - exception passed first
try {
    externalApi.call()
} catch (ex: Exception) {
    logger.error(ex) { "Failed to call external API for campaign=$campaignId" }
    throw ex
}

// ✗ Wrong - stacktrace lost
catch (ex: Exception) {
    logger.error { "Failed to call external API: ${ex.message}" }
}

Sensitive Data

Rules

  1. Sensitive data may only be logged at DEBUG level
  2. Passwords and tokens must NEVER be logged at any level

Examples

// ✓ OK - sensitive details at DEBUG only
logger.debug { "User request: userId=$userId, email=${user.email}" }
logger.info { "User authenticated successfully userId=$userId" }

// ✗ NEVER - regardless of level
logger.debug { "Auth token: $accessToken" }
logger.info { "Password reset with password=$password" }
logger.error { "API key used: $apiKey" }

Avoiding Duplication

Don't Log GET Operations

Don't log read/fetch operations just to log them. If fetched data influences a decision, log the decision - not the fetch.

// ✗ Wrong - redundant GET log
suspend fun getSettings(id: UUID): Settings {
    logger.debug { "Getting settings: id=$id" }  // Useless noise
    return settingsDao.findById(id)
}

// ✓ Correct - no logging for simple reads
suspend fun getSettings(id: UUID): Settings {
    return settingsDao.findById(id)
}

// ✓ Correct - log the decision, not the fetch
suspend fun processSettings(id: UUID) {
    val settings = settingsDao.findById(id)
    if (settings.isExpired) {
        logger.debug { "Settings expired, using defaults: id=$id" }
        return defaults
    }
    return settings
}

Don't Log Start and End for Simple Operations

For simple single-line operations (DAO calls), log once - not both start and end.

// ✗ Wrong - duplicate start/end
suspend fun updateSettings(settings: Settings) {
    logger.info { "Updating settings: id=${settings.id}" }
    settingsDao.update(settings)
    logger.info { "Settings updated: id=${settings.id}" }
}

// ✓ Correct - single completion log
suspend fun updateSettings(settings: Settings) {
    settingsDao.update(settings)
        .also { logger.info { "Settings updated: id=${settings.id}" } }
}

Don't Duplicate Library Logging

If a library (state machine, external client) logs internally, don't add wrapper logs at the call site.

// ✗ Wrong - state machine already logs transitions
suspend fun pauseCampaign(id: UUID) {
    logger.info { "Pausing campaign: id=$id" }
    stateMachine.processEvent(PauseEvent)
    logger.info { "Campaign paused: id=$id" }
}

// ✓ Correct - state machine handles logging
suspend fun pauseCampaign(id: UUID) {
    stateMachine.processEvent(PauseEvent)
}

Log Each Event Once

Choose one appropriate layer to log each event. Don't duplicate across layers.

// ✗ Wrong - duplicated across layers
class CampaignController {
    suspend fun create(req: CreateRequest): Response {
        logger.info { "Creating campaign" }  // Don't log here
        return service.create(req.toModel())
    }
}

class CampaignServiceImpl : CampaignService {
    override suspend fun create(model: Campaign): Campaign {
        logger.info { "Creating campaign for project=${model.projectId}" }  // Log here
        return campaignDao.insert(model)
    }
}

// ✓ Correct - log at service layer only
class CampaignController {
    suspend fun create(req: CreateRequest): Response {
        return service.create(req.toModel())
    }
}

class CampaignServiceImpl : CampaignService {
    override suspend fun create(model: Campaign): Campaign {
        logger.info { "Creating campaign for project=${model.projectId}" }
        return campaignDao.insert(model)
    }
}

Performance

Always Use Lambda Syntax

Use lambda syntax to avoid string concatenation when log level is disabled.

// ✓ Correct - string only built if DEBUG enabled
logger.debug { "Processing items: count=${items.size}, first=${items.first()}" }

// ✗ Wrong - string always built even if DEBUG disabled
logger.debug("Processing items: count=${items.size}, first=${items.first()}")

Summary Checklist

Before committing code with logging, verify: