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,98 +32,133 @@ 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) {
-            val saved =
-                filmLibraryRepository.save(
-                    existingEntry.copy(
-                        isViewed = false,
-                        watchedAt = null,
-                    ),
+            log.debug("Film already in library, resetting as not viewed: entryId={}", existingEntry.id)
+            val saved = filmLibraryRepository.save(
+                existingEntry.copy(
+                    isViewed = false,
+                    watchedAt = null,
                 )
+            )
             businessMetricsService.recordLibraryEvent()
+            log.info("Film re-added to library: userId={}, filmId={}, entryId={}", command.userId, command.filmId, saved.id)
             return saved
         }
 
-        val saved =
+        val saved = filmLibraryRepository.save(
+            FilmLibrary(
+                id = idGenerator.generateId(),
+                userId = command.userId,
+                filmId = command.filmId,
+                comment = null,
+                isViewed = false,
+                watchedAt = null,
+            )
+        )
+        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(),
                     userId = command.userId,
                     filmId = command.filmId,
                     comment = null,
-                    isViewed = false,
-                    watchedAt = null,
-                ),
+                    isViewed = true,
+                    watchedAt = watchedAt,
+                )
+            )
+        } else {
+            log.debug("Updating existing entry: entryId={}, was viewed={}", existingEntry.id, existingEntry.isViewed)
+            filmLibraryRepository.save(
+                existingEntry.copy(
+                    isViewed = true,
+                    watchedAt = watchedAt,
+                )
             )
-        businessMetricsService.recordLibraryEvent()
-        return saved
-    }
-
-    override fun removeFilm(command: RemoveFilmFromLibraryCommand): FilmLibrary {
-        val existingLibrary =
-            if (command.libraryId != null) {
-                filmLibraryRepository.findById(command.libraryId)
-                    ?: throw EntityNotFoundException(entity = "Film library", id = command.libraryId.toString())
-            } else {
-                findByUserAndFilmId(command.userId, command.filmId)
-                    ?: throw EntityNotFoundException(entity = "Film library", id = command.filmId.toString())
-            }
-
-        if (existingLibrary.userId != command.userId || existingLibrary.filmId != command.filmId) {
-            throw DomainException("Film with id ${command.filmId} not found in user's library")
         }
-
-        filmLibraryRepository.deleteById(existingLibrary.id)
-        businessMetricsService.recordLibraryEvent()
-        return existingLibrary
-    }
-
-    override fun markViewed(command: MarkFilmViewedCommand): FilmLibrary {
-        val existingEntry = findByUserAndFilmId(command.userId, command.filmId)
-        val watchedAt = command.watchedAt ?: java.time.LocalDateTime.now()
-
-        val saved =
-            if (existingEntry == null) {
-                filmLibraryRepository.save(
-                    FilmLibrary(
-                        id = idGenerator.generateId(),
-                        userId = command.userId,
-                        filmId = command.filmId,
-                        comment = null,
-                        isViewed = true,
-                        watchedAt = watchedAt,
-                    ),
-                )
-            } else {
-                filmLibraryRepository.save(
-                    existingEntry.copy(
-                        isViewed = true,
-                        watchedAt = watchedAt,
-                    ),
-                )
-            }
         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 =
-        findByUserId(query.userId)
+    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 }
+    private fun findByUserId(userId: UUID): FilmLibrary? {
+        return filmLibraryRepository.findAll().firstOrNull { it.userId == userId }
+    }
 
-    private fun findByUserAndFilmId(
-        userId: UUID,
-        filmId: UUID,
-    ): FilmLibrary? = filmLibraryRepository.findAll().firstOrNull { it.userId == userId && it.filmId == filmId }
+    private fun findByUserAndFilmId(userId: UUID, filmId: UUID): FilmLibrary? {
+        return filmLibraryRepository.findAll().firstOrNull { it.userId == userId && it.filmId == filmId }
+    }
 }

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

@@ -33,70 +33,68 @@ class FilmService(
     GetFilmByIdUseCase,
     GetAllFilmsUseCase,
     SearchFilmByTitleUseCase {
+
     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")
             }
 
-            val film =
-                Film(
-                    id = idGenerator.generateId(),
-                    title = command.title,
-                    description = command.description,
-                    contentType = command.contentType,
-                    releaseYear = command.releaseYear,
-                    genres = command.genres,
-                    cast = command.cast,
-                    directors = command.directors,
-                    imdbRating = command.imdbRating,
-                    platformRating = command.platformRating,
-                    externalUrl = command.externalUrl,
-                    jellyfinItemId = command.jellyfinItemId,
-                    jellyfinLibraryId = command.jellyfinLibraryId,
-                )
+            val film = Film(
+                id = idGenerator.generateId(),
+                title = command.title,
+                description = command.description,
+                contentType = command.contentType,
+                releaseYear = command.releaseYear,
+                genres = command.genres,
+                cast = command.cast,
+                directors = command.directors,
+                imdbRating = command.imdbRating,
+                platformRating = command.platformRating,
+                externalUrl = command.externalUrl,
+                jellyfinItemId = command.jellyfinItemId,
+                jellyfinLibraryId = command.jellyfinLibraryId,
+            )
 
             val saved = filmRepository.save(film)
             filmCreatedCounter.increment()
+            log.info("Film created successfully: id={}, title='{}'", saved.id, saved.title)
             return saved
         } finally {
             sample.stop(createFilmTimer)
         }
     }
 
-    override fun edit(
-        id: UUID,
-        command: EditFilmCommand,
-    ): Film {
+    override fun edit(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,28 +102,30 @@ 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())
             }
 
-            film =
-                film.copy(
-                    title = command.title,
-                    description = command.description,
-                    contentType = command.contentType,
-                    releaseYear = command.releaseYear,
-                    genres = command.genres,
-                    cast = command.cast,
-                    directors = command.directors,
-                    imdbRating = command.imdbRating,
-                    platformRating = command.platformRating,
-                    externalUrl = command.externalUrl,
-                    jellyfinItemId = command.jellyfinItemId,
-                    jellyfinLibraryId = command.jellyfinLibraryId,
-                )
+            log.debug("Existing film found: id={}, current title='{}'", film.id, film.title)
+
+            film = film.copy(
+                title = command.title,
+                description = command.description,
+                contentType = command.contentType,
+                releaseYear = command.releaseYear,
+                genres = command.genres,
+                cast = command.cast,
+                directors = command.directors,
+                imdbRating = command.imdbRating,
+                platformRating = command.platformRating,
+                externalUrl = command.externalUrl,
+                jellyfinItemId = command.jellyfinItemId,
+                jellyfinLibraryId = command.jellyfinLibraryId,
+            )
 
             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,74 +133,86 @@ 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: id='{}'", id)
+            log.info("Film deleted successfully: id={}, title='{}'", id, film.title)
         } finally {
             sample.stop(deleteFilmTimer)
         }
     }
 
-    override fun getById(id: UUID): Film =
-        filmRepository.findById(id) ?: throw EntityNotFoundException(entity = "Film", id = id.toString())
+    override fun getById(id: UUID): Film {
+        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
-            .builder("film_created_total")
-            .description("Total number of created films")
-            .register(meterRegistry)
+    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 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 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 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 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 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)
+    private val deleteFilmTimer = Timer
+        .builder("films.delete.duration")
+        .description("Film deletion duration")
+        .register(meterRegistry)
 }

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,48 +27,80 @@ 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")
         }
 
-        val user =
-            User(
-                id = idGenerator.generateId(),
-                name = command.name,
-                email = command.email,
-                library = null,
-                jellyfinUserId = null,
-            )
-        return userRepository.save(user)
+        val user = User(
+            id = idGenerator.generateId(),
+            name = command.name,
+            email = command.email,
+            library = null,
+            jellyfinUserId = null,
+        )
+        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 {
+    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())
 
-        user =
-            user.copy(
-                name = command.name,
-                jellyfinUserId = command.jellyfinUserId ?: user.jellyfinUserId,
-            )
+        log.debug("Existing user found: id={}, current name='{}'", user.id, user.name)
 
-        return userRepository.save(user)
+        user = user.copy(
+            name = command.name,
+            jellyfinUserId = command.jellyfinUserId ?: user.jellyfinUserId,
+        )
+
+        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 =
-        userRepository.findById(id) ?: throw EntityNotFoundException(entity = "User", id = id.toString())
+    override fun getById(id: UUID): User {
+        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>