Merge branch 'feature/logging-error-handling' into develop

* feature/logging-error-handling:
  логи
  логи
  логи
  логи

build.gradle.kts

@@ -41,6 +41,8 @@ dependencies {
     implementation(libs.flyway.database.postgresql)
     implementation(libs.kotlin.reflect)
 
+    implementation("net.logstash.logback:logstash-logback-encoder:8.0")
+
     implementation(libs.micrometer.tracing.bridge.otel)
     implementation(libs.opentelemetry.exporter.otlp)
     implementation(libs.sentry.spring.boot.starter)

src/main/kotlin/com/project/movienight/application/services/FilmLibraryService.kt

@@ -17,6 +17,7 @@ import com.project.movienight.application.ports.output.IdGenerator
 import com.project.movienight.domain.exception.DomainException
 import com.project.movienight.domain.exception.EntityNotFoundException
 import com.project.movienight.domain.model.FilmLibrary
+import org.slf4j.LoggerFactory
 import org.springframework.stereotype.Service
 import java.util.UUID
 
@@ -31,14 +32,28 @@ class FilmLibraryService(
     RemoveFilmFromLibraryUseCase,
     GetFilmLibraryUseCase,
     ListFilmLibraryEntriesUseCase {
+    private val log = LoggerFactory.getLogger(javaClass)
+
     override fun create(command: CreateFilmLibraryCommand): FilmLibrary {
-        findByUserId(command.userId)?.let { return it }
+        log.info("Creating film library for user: {}", command.userId)
+        log.debug("Create library request: userId={}, name={}", command.userId, command.name)
+
+        val existing = findByUserId(command.userId)
+        if (existing != null) {
+            log.debug("Library already exists for user {}: libraryId={}", command.userId, existing.id)
+            return existing
+        }
+
+        log.warn("Library not found for user {}, cannot create", command.userId)
         throw EntityNotFoundException(entity = "Film library", id = command.userId.toString())
     }
 
     override fun addFilm(command: AddFilmToLibraryCommand): FilmLibrary {
+        log.info("Adding film to library: userId={}, filmId={}", command.userId, command.filmId)
+
         val existingEntry = findByUserAndFilmId(command.userId, command.filmId)
         if (existingEntry != null) {
+            log.debug("Film already in library, resetting as not viewed: entryId={}", existingEntry.id)
             val saved =
                 filmLibraryRepository.save(
                     existingEntry.copy(
@@ -47,6 +62,12 @@ class FilmLibraryService(
                     ),
                 )
             businessMetricsService.recordLibraryEvent()
+            log.info(
+                "Film re-added to library: userId={}, filmId={}, entryId={}",
+                command.userId,
+                command.filmId,
+                saved.id,
+            )
             return saved
         }
 
@@ -62,34 +83,56 @@ class FilmLibraryService(
                 ),
             )
         businessMetricsService.recordLibraryEvent()
+        log.info(
+            "Film added to library: userId={}, filmId={}, entryId={}",
+            command.userId,
+            command.filmId,
+            saved.id,
+        )
         return saved
     }
 
     override fun removeFilm(command: RemoveFilmFromLibraryCommand): FilmLibrary {
+        log.info("Removing film from library: userId={}, filmId={}", command.userId, command.filmId)
+
         val existingLibrary =
             if (command.libraryId != null) {
+                log.debug("Looking up by libraryId: {}", command.libraryId)
                 filmLibraryRepository.findById(command.libraryId)
                     ?: throw EntityNotFoundException(entity = "Film library", id = command.libraryId.toString())
             } else {
+                log.debug("Looking up by userId and filmId")
                 findByUserAndFilmId(command.userId, command.filmId)
                     ?: throw EntityNotFoundException(entity = "Film library", id = command.filmId.toString())
             }
 
         if (existingLibrary.userId != command.userId || existingLibrary.filmId != command.filmId) {
+            log.warn("Film not found in user's library: userId={}, filmId={}", command.userId, command.filmId)
             throw DomainException("Film with id ${command.filmId} not found in user's library")
         }
 
         filmLibraryRepository.deleteById(existingLibrary.id)
         businessMetricsService.recordLibraryEvent()
+        log.info(
+            "Film removed from library: userId={}, filmId={}, entryId={}",
+            command.userId,
+            command.filmId,
+            existingLibrary.id,
+        )
         return existingLibrary
     }
 
     override fun markViewed(command: MarkFilmViewedCommand): FilmLibrary {
+        log.info("Marking film as viewed: userId={}, filmId={}", command.userId, command.filmId)
+
         val existingEntry = findByUserAndFilmId(command.userId, command.filmId)
         val watchedAt = command.watchedAt ?: java.time.LocalDateTime.now()
 
+        log.debug("Marking as viewed at: {}", watchedAt)
+
         val saved =
             if (existingEntry == null) {
+                log.debug("Film not in library, creating new entry as viewed")
                 filmLibraryRepository.save(
                     FilmLibrary(
                         id = idGenerator.generateId(),
@@ -101,6 +144,11 @@ class FilmLibraryService(
                     ),
                 )
             } else {
+                log.debug(
+                    "Updating existing entry: entryId={}, was viewed={}",
+                    existingEntry.id,
+                    existingEntry.isViewed,
+                )
                 filmLibraryRepository.save(
                     existingEntry.copy(
                         isViewed = true,
@@ -109,20 +157,41 @@ class FilmLibraryService(
                 )
             }
         businessMetricsService.recordLibraryEvent()
+        log.info(
+            "Film marked as viewed: userId={}, filmId={}, entryId={}",
+            command.userId,
+            command.filmId,
+            saved.id,
+        )
         return saved
     }
 
-    override fun getLibrary(query: GetFilmLibraryQuery): FilmLibrary =
+    override fun getLibrary(query: GetFilmLibraryQuery): FilmLibrary {
+        log.debug("Getting library for user: {}", query.userId)
+        val library =
             findByUserId(query.userId)
                 ?: throw EntityNotFoundException(entity = "Film library", id = query.userId.toString())
+        log.debug("Library found: userId={}, libraryId={}", query.userId, library.id)
+        return library
+    }
 
-    override fun list(userId: UUID): List<FilmLibrary> = filmLibraryRepository.findAll().filter { it.userId == userId }
+    override fun list(userId: UUID): List<FilmLibrary> {
+        log.debug("Listing all library entries for user: {}", userId)
+        val entries = filmLibraryRepository.findAll().filter { it.userId == userId }
+        log.info("User {} has {} films in library", userId, entries.size)
+        return entries
+    }
 
     private fun findByUserId(userId: UUID): FilmLibrary? =
-        filmLibraryRepository.findAll().firstOrNull { it.userId == userId }
+        filmLibraryRepository.findAll().firstOrNull {
+            it.userId == userId
+        }
 
     private fun findByUserAndFilmId(
         userId: UUID,
         filmId: UUID,
-    ): FilmLibrary? = filmLibraryRepository.findAll().firstOrNull { it.userId == userId && it.filmId == filmId }
+    ): FilmLibrary? =
+        filmLibraryRepository.findAll().firstOrNull {
+            it.userId == userId && it.filmId == filmId
+        }
 }

src/main/kotlin/com/project/movienight/application/services/FilmService.kt

@@ -36,22 +36,25 @@ class FilmService(
     private val log = LoggerFactory.getLogger(javaClass)
 
     override fun create(command: CreateFilmCommand): Film {
+        log.info("Creating new film: title='{}', contentType={}", command.title, command.contentType)
+        log.debug(
+            "Create film request details: title='{}', descriptionLength={}, genres={}, releaseYear={}",
+            command.title,
+            command.description.length,
+            command.genres,
+            command.releaseYear,
+        )
+
         val sample = Timer.start(meterRegistry)
 
         try {
-            log.debug(
-                "Create film request received: title='{}', descriptionLength={}",
-                command.title,
-                command.description.length,
-            )
-
             if (filmConfig.isBlocked(command.title)) {
-                log.debug("Create film blocked by title policy: title='{}'", command.title)
+                log.warn("Film creation blocked: title contains blocked pattern '{}'", command.title)
                 filmBlockedCounter.increment()
                 throw BlockedValueException(target = "Film", field = "title")
             }
             if (filmConfig.isBlocked(command.description)) {
-                log.debug("Create film blocked by description policy")
+                log.warn("Film creation blocked: description contains blocked pattern")
                 filmBlockedCounter.increment()
                 throw BlockedValueException(target = "Film", field = "description")
             }
@@ -75,6 +78,7 @@ class FilmService(
 
             val saved = filmRepository.save(film)
             filmCreatedCounter.increment()
+            log.info("Film created successfully: id={}, title='{}'", saved.id, saved.title)
             return saved
         } finally {
             sample.stop(createFilmTimer)
@@ -85,18 +89,25 @@ class FilmService(
         id: UUID,
         command: EditFilmCommand,
     ): Film {
+        log.info("Editing film: id={}", id)
+        log.debug(
+            "Edit film request details: id={}, title='{}', descriptionLength={}, genres={}",
+            id,
+            command.title,
+            command.description.length,
+            command.genres,
+        )
+
         val sample = Timer.start(meterRegistry)
 
         try {
-            log.debug("Edit film with id: {}", id)
-
             if (filmConfig.isBlocked(command.title)) {
-                log.debug("Edit film blocked by title policy: title='{}'", command.title)
+                log.warn("Film edit blocked: title contains blocked pattern '{}'", command.title)
                 filmBlockedCounter.increment()
                 throw BlockedValueException(target = "Film", field = "title")
             }
             if (filmConfig.isBlocked(command.description)) {
-                log.debug("Edit film blocked by description policy")
+                log.warn("Film edit blocked: description contains blocked pattern")
                 filmBlockedCounter.increment()
                 throw BlockedValueException(target = "Film", field = "description")
             }
@@ -104,10 +115,12 @@ class FilmService(
             var film = filmRepository.findById(id)
 
             if (film == null) {
-                log.debug("Film not found for edit: id='{}'", id)
+                log.warn("Film not found for edit: id='{}'", id)
                 throw EntityNotFoundException(entity = "Film", id = id.toString())
             }
 
+            log.debug("Existing film found: id={}, current title='{}'", film.id, film.title)
+
             film =
                 film.copy(
                     title = command.title,
@@ -126,6 +139,7 @@ class FilmService(
 
             val saved = filmRepository.save(film)
             filmEditedCounter.increment()
+            log.info("Film edited successfully: id={}, new title='{}'", saved.id, saved.title)
             return saved
         } finally {
             sample.stop(editFilmTimer)
@@ -133,34 +147,54 @@ class FilmService(
     }
 
     override fun delete(id: UUID) {
+        log.info("Deleting film: id={}", 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)
+                log.warn("Film not found for delete: id='{}'", id)
                 throw EntityNotFoundException(entity = "Film", id = id.toString())
             }
 
+            log.debug("Film found for deletion: id={}, title='{}'", film.id, film.title)
+
             filmRepository.deleteById(id)
-
             filmDeletedCounter.increment()
-
+            log.info("Film deleted successfully: id={}, title='{}'", id, film.title)
-            log.info("Film deleted: id='{}'", id)
         } finally {
             sample.stop(deleteFilmTimer)
         }
     }
 
-    override fun getById(id: UUID): Film =
+    override fun getById(id: UUID): Film {
-        filmRepository.findById(id) ?: throw EntityNotFoundException(entity = "Film", id = id.toString())
+        log.debug("Fetching film by id: {}", id)
+        val film =
+            filmRepository.findById(id)
+                ?: throw EntityNotFoundException(entity = "Film", id = id.toString())
+        log.debug("Film found: id={}, title='{}'", film.id, film.title)
+        return film
+    }
 
-    override fun getAll(): List<Film> = filmRepository.findAll()
+    override fun getAll(): List<Film> {
+        log.debug("Fetching all films")
+        val films = filmRepository.findAll()
+        log.info("Retrieved {} films from database", films.size)
+        return films
+    }
 
-    override fun searchByTitle(title: String): Film? = filmRepository.findByTitle(title)
+    override fun searchByTitle(title: String): Film? {
+        log.debug("Searching film by title: '{}'", title)
+        val film = filmRepository.findByTitle(title)
+        if (film != null) {
+            log.info("Film found by title '{}': id={}", title, film.id)
+        } else {
+            log.debug("No film found with title: '{}'", title)
+        }
+        return film
+    }
 
     private val filmCreatedCounter =
         Counter

src/main/kotlin/com/project/movienight/application/services/UserService.kt

@@ -13,6 +13,7 @@ import com.project.movienight.config.UserServiceProperties
 import com.project.movienight.domain.exception.BlockedValueException
 import com.project.movienight.domain.exception.EntityNotFoundException
 import com.project.movienight.domain.model.User
+import org.slf4j.LoggerFactory
 import org.springframework.stereotype.Service
 import java.util.UUID
 
@@ -26,8 +27,14 @@ class UserService(
     DeleteUserUseCase,
     GetUserByIdUseCase,
     GetAllUsersUseCase {
+    private val log = LoggerFactory.getLogger(javaClass)
+
     override fun create(command: CreateUserCommand): User {
+        log.info("Creating new user with email: {}", command.email)
+        log.debug("Create user request: name='{}', email='{}'", command.name, command.email)
+
         if (userConfig.isBlocked(command.name)) {
+            log.warn("User creation blocked: name contains blocked pattern '{}'", command.name)
             throw BlockedValueException(target = "User", field = "name")
         }
 
@@ -39,18 +46,29 @@ class UserService(
                 library = null,
                 jellyfinUserId = null,
             )
-        return userRepository.save(user)
+        val saved = userRepository.save(user)
+
+        log.info("User created successfully: id={}, email='{}'", saved.id, saved.email)
+        return saved
     }
 
     override fun edit(
         id: UUID,
         command: EditUserCommand,
     ): User {
+        log.info("Editing user: id={}", id)
+        log.debug("Edit user request: id={}, name='{}', jellyfinUserId={}", id, command.name, command.jellyfinUserId)
+
         if (userConfig.isBlocked(command.name)) {
+            log.warn("User edit blocked: name contains blocked pattern '{}'", command.name)
             throw BlockedValueException(target = "User", field = "name")
         }
 
-        var user = userRepository.findById(id) ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+        var user =
+            userRepository.findById(id)
+                ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+
+        log.debug("Existing user found: id={}, current name='{}'", user.id, user.name)
 
         user =
             user.copy(
@@ -58,16 +76,38 @@ class UserService(
                 jellyfinUserId = command.jellyfinUserId ?: user.jellyfinUserId,
             )
 
-        return userRepository.save(user)
+        val saved = userRepository.save(user)
+        log.info("User edited successfully: id={}, new name='{}'", saved.id, saved.name)
+        return saved
     }
 
     override fun delete(id: UUID) {
-        userRepository.findById(id) ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+        log.info("Deleting user: id={}", id)
+        log.debug("Delete user request: id={}", id)
+
+        val user =
+            userRepository.findById(id)
+                ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+
+        log.debug("User found for deletion: id={}, email='{}'", user.id, user.email)
+
         userRepository.deleteById(id)
+        log.info("User deleted successfully: id={}", id)
     }
 
-    override fun getById(id: UUID): User =
+    override fun getById(id: UUID): User {
-        userRepository.findById(id) ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+        log.debug("Fetching user by id: {}", id)
+        val user =
+            userRepository.findById(id)
+                ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+        log.debug("User found: id={}, name='{}', email='{}'", user.id, user.name, user.email)
+        return user
+    }
 
-    override fun getAll(): List<User> = userRepository.findAll()
+    override fun getAll(): List<User> {
+        log.debug("Fetching all users")
+        val users = userRepository.findAll()
+        log.info("Retrieved {} users from database", users.size)
+        return users
+    }
 }

src/main/resources/application.yaml

@@ -115,6 +115,11 @@ services:
       - censored
       - epstein
       - python
+
 logging:
+  level:
+    com.project.movienight: DEBUG
+    org.springframework: WARN
+    org.flywaydb: WARN
   pattern:
-    console: "%d{yyyy-MM-dd HH:mm:ss.SSS} %-5level [%X{traceId}] %logger{36} - %msg%n"
+    console: "%d{yyyy-MM-dd HH:mm:ss.SSS} %highlight(%-5level) [%thread] %cyan(%logger{36}) - %msg%n"

src/main/resources/logback-spring.xml

@@ -0,0 +1,23 @@
+<configuration>
+  <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
+    <encoder>
+      <pattern>%d{HH:mm:ss.SSS} %highlight(%-5level) [%thread] %cyan(%logger{36}) - %msg%n</pattern>
+    </encoder>
+  </appender>
+
+  <appender name="JSON_FILE" class="ch.qos.logback.core.rolling.RollingFileAppender">
+    <file>logs/app.json</file>
+    <rollingPolicy class="ch.qos.logback.core.rolling.TimeBasedRollingPolicy">
+      <fileNamePattern>logs/app-%d{yyyy-MM-dd}.json</fileNamePattern>
+      <maxHistory>30</maxHistory>
+    </rollingPolicy>
+    <encoder class="net.logstash.logback.encoder.LogstashEncoder"/>
+  </appender>
+
+  <root level="INFO">
+    <appender-ref ref="CONSOLE"/>
+    <appender-ref ref="JSON_FILE"/>
+  </root>
+
+  <logger name="com.project.movienight" level="DEBUG"/>
+</configuration>