add Film observability with trace id and metrics

2026-05-18 00:12:38 +03:00
parent e93d9b2c81
commit 66a4add814
4 changed files with 215 additions and 30 deletions
@@ -3,6 +3,8 @@ package com.project.movienight.adapters.web
 import com.project.movienight.domain.exception.BlockedValueException
 import com.project.movienight.domain.exception.DomainException
 import com.project.movienight.domain.exception.EntityNotFoundException
+import org.slf4j.LoggerFactory
+import org.slf4j.MDC
 import org.springframework.http.HttpStatus
 import org.springframework.web.bind.annotation.ExceptionHandler
 import org.springframework.web.bind.annotation.ResponseStatus
@@ -10,22 +12,60 @@ import org.springframework.web.bind.annotation.RestControllerAdvice

@RestControllerAdvice
 class ApiExceptionHandler {
+    private val log = LoggerFactory.getLogger(javaClass)
+
    @ExceptionHandler(EntityNotFoundException::class)
    @ResponseStatus(HttpStatus.NOT_FOUND)
-    fun handleNotFound(exception: EntityNotFoundException): ErrorResponse =
-        ErrorResponse(message = exception.message ?: "Entity not found")
+    fun handleNotFound(exception: EntityNotFoundException): ErrorResponse {
+        val traceId = currentTraceId()
+        log.warn("Entity not found: traceId='{}', message='{}'", traceId, exception.message)
+
+        return ErrorResponse(
+            message = exception.message ?: "Entity not found",
+            traceId = traceId,
+        )
+    }

    @ExceptionHandler(BlockedValueException::class)
    @ResponseStatus(HttpStatus.BAD_REQUEST)
-    fun handleBlockedValue(exception: BlockedValueException): ErrorResponse =
-        ErrorResponse(message = exception.message ?: "Blocked value")
+    fun handleBlockedValue(exception: BlockedValueException): ErrorResponse {
+        val traceId = currentTraceId()
+        log.warn("Blocked value: traceId='{}', message='{}'", traceId, exception.message)
+
+        return ErrorResponse(
+            message = exception.message ?: "Blocked value",
+            traceId = traceId,
+        )
+    }

    @ExceptionHandler(DomainException::class)
    @ResponseStatus(HttpStatus.BAD_REQUEST)
-    fun handleDomainException(exception: DomainException): ErrorResponse =
-        ErrorResponse(message = exception.message ?: "Domain error")
+    fun handleDomainException(exception: DomainException): ErrorResponse {
+        val traceId = currentTraceId()
+        log.warn("Domain error: traceId='{}', message='{}'", traceId, exception.message)
+
+        return ErrorResponse(
+            message = exception.message ?: "Domain error",
+            traceId = traceId,
+        )
+    }
+
+    @ExceptionHandler(Exception::class)
+    @ResponseStatus(HttpStatus.INTERNAL_SERVER_ERROR)
+    fun handleUnexpectedException(exception: Exception): ErrorResponse {
+        val traceId = currentTraceId()
+        log.error("Unexpected error: traceId='{}'", traceId, exception)
+
+        return ErrorResponse(
+            message = "Internal server error",
+            traceId = traceId,
+        )
+    }
+
+    private fun currentTraceId(): String = MDC.get("traceId") ?: "unknown"
 }

 data class ErrorResponse(
    val message: String,
+    val traceId: String,
 )
@@ -0,0 +1,27 @@
+package com.project.movienight.adapters.web
+
+import jakarta.servlet.FilterChain
+import jakarta.servlet.http.HttpServletRequest
+import jakarta.servlet.http.HttpServletResponse
+import org.slf4j.MDC
+import org.springframework.stereotype.Component
+import org.springframework.web.filter.OncePerRequestFilter
+import java.util.UUID
+
+@Component
+class TraceIdFilter : OncePerRequestFilter() {
+    override fun doFilterInternal(
+        request: HttpServletRequest,
+        response: HttpServletResponse,
+        filterChain: FilterChain,
+    ) {
+        val traceId = UUID.randomUUID().toString()
+        MDC.put("traceId", traceId)
+
+        try {
+            filterChain.doFilter(request, response)
+        } finally {
+            MDC.remove("traceId")
+        }
+    }
+}
@@ -14,6 +14,10 @@ import com.project.movienight.config.FilmServiceProperties
 import com.project.movienight.domain.exception.BlockedValueException
 import com.project.movienight.domain.exception.EntityNotFoundException
 import com.project.movienight.domain.model.Film
+import io.micrometer.core.instrument.Counter
+import io.micrometer.core.instrument.MeterRegistry
+import io.micrometer.core.instrument.Timer
+import org.slf4j.LoggerFactory
 import org.springframework.stereotype.Service
 import java.util.UUID

@@ -22,48 +26,117 @@ class FilmService(
    private val filmRepository: FilmRepositoryPort,
    private val idGenerator: IdGenerator,
    private val filmConfig: FilmServiceProperties,
+    private val meterRegistry: MeterRegistry,
 ) : CreateFilmUseCase,
    EditFilmUseCase,
    DeleteFilmUseCase,
    GetFilmByIdUseCase,
    GetAllFilmsUseCase,
    SearchFilmByTitleUseCase {
-    override fun create(command: CreateFilmCommand): Film {
-        if (filmConfig.isBlocked(command.title)) {
-            throw BlockedValueException(target = "Film", field = "title")
-        }
-        if (filmConfig.isBlocked(command.description)) {
-            throw BlockedValueException(target = "Film", field = "description")
-        }
+    private val log = LoggerFactory.getLogger(javaClass)

-        val film =
-            Film(
-                id = idGenerator.generateId(),
-                title = command.title,
-                description = command.description,
+    override fun create(command: CreateFilmCommand): Film {
+        val sample = Timer.start(meterRegistry)
+
+        try {
+            log.debug(
+                "Create film request received: title='{}', descriptionLength={}",
+                command.title,
+                command.description.length,
            )
-        return filmRepository.save(film)
+
+            if (filmConfig.isBlocked(command.title)) {
+                log.debug("Create film blocked by title policy: title='{}'", command.title)
+                filmBlockedCounter.increment()
+                throw BlockedValueException(target = "Film", field = "title")
+            }
+            if (filmConfig.isBlocked(command.description)) {
+                log.debug("Create film blocked by description policy")
+                filmBlockedCounter.increment()
+                throw BlockedValueException(target = "Film", field = "description")
+            }
+
+            val film =
+                Film(
+                    id = idGenerator.generateId(),
+                    title = command.title,
+                    description = command.description,
+                )
+            val saved = filmRepository.save(film)
+
+            filmCreatedCounter.increment()
+
+            log.info("Film created: id='{}', title='{}'", saved.id, saved.title)
+            return saved
+        } finally {
+            sample.stop(createFilmTimer)
+        }
    }

    override fun edit(
        id: UUID,
        command: EditFilmCommand,
    ): Film {
-        if (filmConfig.isBlocked(command.title)) {
-            throw BlockedValueException(target = "Film", field = "title")
-        }
-        if (filmConfig.isBlocked(command.description)) {
-            throw BlockedValueException(target = "Film", field = "description")
-        }
+        val sample = Timer.start(meterRegistry)

-        var film = filmRepository.findById(id) ?: throw EntityNotFoundException(entity = "Film", id = id.toString())
-        film = film.copy(title = command.title, description = command.description)
-        return filmRepository.save(film)
+        try {
+            log.debug("Edit film with id: {}", id)
+
+            if (filmConfig.isBlocked(command.title)) {
+                log.debug("Edit film blocked by title policy: title='{}'", command.title)
+                filmBlockedCounter.increment()
+                throw BlockedValueException(target = "Film", field = "title")
+            }
+            if (filmConfig.isBlocked(command.description)) {
+                log.debug("Edit film blocked by description policy")
+                filmBlockedCounter.increment()
+                throw BlockedValueException(target = "Film", field = "description")
+            }
+
+            val film = filmRepository.findById(id)
+
+            if (film == null) {
+                log.debug("Film not found for edit: id='{}'", id)
+                throw EntityNotFoundException(entity = "Film", id = id.toString())
+            }
+
+            val updatedFilm =
+                film.copy(
+                    title = command.title,
+                    description = command.description,
+                )
+            val saved = filmRepository.save(updatedFilm)
+
+            filmEditedCounter.increment()
+
+            log.info("Film edited: id='{}'", saved.id)
+            return saved
+        } finally {
+            sample.stop(editFilmTimer)
+        }
    }

    override fun delete(id: UUID) {
-        filmRepository.findById(id) ?: throw EntityNotFoundException(entity = "Film", id = id.toString())
-        filmRepository.deleteById(id)
+        val sample = Timer.start(meterRegistry)
+
+        try {
+            log.debug("Delete film with id: {}", id)
+
+            val film = filmRepository.findById(id)
+
+            if (film == null) {
+                log.debug("Film not found for delete: id='{}'", id)
+                throw EntityNotFoundException(entity = "Film", id = id.toString())
+            }
+
+            filmRepository.deleteById(id)
+
+            filmDeletedCounter.increment()
+
+            log.info("Film deleted: id='{}'", id)
+        } finally {
+            sample.stop(deleteFilmTimer)
+        }
    }

    override fun getById(id: UUID): Film =
@@ -72,4 +145,46 @@ class FilmService(
    override fun getAll(): List<Film> = filmRepository.findAll()

    override fun searchByTitle(title: String): Film? = filmRepository.findByTitle(title)
+
+    private val filmCreatedCounter =
+        Counter
+            .builder("film_created_total")
+            .description("Total number of created films")
+            .register(meterRegistry)
+
+    private val filmEditedCounter =
+        Counter
+            .builder("film_edited_total")
+            .description("Total number of successfully edited films")
+            .register(meterRegistry)
+
+    private val filmDeletedCounter =
+        Counter
+            .builder("film_deleted_total")
+            .description("Total number of successfully deleted films")
+            .register(meterRegistry)
+
+    private val filmBlockedCounter =
+        Counter
+            .builder("films.blocked")
+            .description("Total blocked film operations")
+            .register(meterRegistry)
+
+    private val createFilmTimer =
+        Timer
+            .builder("films.create.duration")
+            .description("Film creation duration")
+            .register(meterRegistry)
+
+    private val editFilmTimer =
+        Timer
+            .builder("films.edit.duration")
+            .description("Film edit duration")
+            .register(meterRegistry)
+
+    private val deleteFilmTimer =
+        Timer
+            .builder("films.delete.duration")
+            .description("Film deletion duration")
+            .register(meterRegistry)
 }
@@ -74,3 +74,6 @@ services:
      - censored
      - epstein
      - python
+logging:
+  pattern:
+    console: "%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%X{traceId}] %logger{36} - %msg%n"