[NOOK-162] 게시물 파싱 임시 추적 로그 추가

docs/tasks/NOOK-162/README.md

@@ -0,0 +1,61 @@
+# NOOK-162 게시물·장소 파싱 구조화 단계 로그 표준화
+
+## 목적
+
+Prometheus metric과 별개로 게시물 저장부터 콘텐츠 수집, 장소 파싱과 후처리까지 원본 게시물 ID로
+검색 가능한 구조화 애플리케이션 로그를 제공한다.
+
+이번 리팩터링 기간에만 사용하는 임시 추적 로그이며 모든 새 메시지는 `[PostParcingTracker]`로 시작한다.
+
+## 범위
+
+- 공통 lifecycle event와 로그 필드를 정의한다.
+- 콘텐츠·장소 비동기 실행에 `source_post.id`와 `processing.flow` MDC를 설정한다.
+- Instagram, OpenAI, Kakao, Naver, 미디어, Google 사진과 태그 처리 결과를 요약해 기록한다.
+- Instagram 캐시 적중 여부와 실제 provider 호출, fallback 및 응답 시간을 기록한다.
+- Google 장소 매칭, 사진 목록, 사진 URI 조회와 스토리지 저장을 분리하고 누락 사유를 기록한다.
+- 사용자 저장 게시물 ID와 원본 게시물 ID의 매핑을 기록한다.
+- 새 구조화 로그에는 API key, 인증 헤더, 본문 원문, 전체 외부 응답과 전체 미디어 URL을 추가하지 않는다.
+- 기존 로그의 메시지와 레벨은 호환성을 위해 변경하지 않는다.
+
+## 제외 범위
+
+- Prometheus metric 변경
+- 장소 검색 및 후보 선택 알고리즘 변경
+- 비동기 Job 및 DB 스키마 변경
+
+## 주요 검색 필드
+
+- `event.action`
+- `event.outcome`
+- `processing.flow`
+- `processing.stage`
+- `processing.attempt`
+- `source_post.id`
+- `saved_post.id`
+- `provider.name`
+- `failure.type`
+- `failure.reason`
+
+## 사진 누락 판별
+
+- `place_not_matched`: Google 검색 결과에서 원본 장소와 일치하는 장소가 없음
+- `no_photos`: 일치 장소는 있지만 제공된 사진이 없음
+- `photo_uri_missing`: 사진 메타데이터 응답에 다운로드 URI가 없음
+- `google.photo.media.failed`: 사진 URI 조회 요청 실패
+- `google.photo.store.failed`: 스토리지 저장 실패
+- `google.photo.pipeline.completed`: 선택·저장·실패한 사진 수의 최종 집계
+
+## 로그 레벨
+
+- 새 추적 로그는 기존 운영 로그와 Grafana 알림에 영향을 주지 않도록 모두 `DEBUG`로 기록한다.
+- `event.outcome`과 `failure.type`으로 성공, 빈 결과, 재시도와 실패를 구분한다.
+- 기존 로그의 레벨과 메시지는 그대로 유지한다.
+
+고카디널리티 값은 Loki label로 추가하지 않고 JSON 검색 필드로만 기록한다.
+
+## 검증
+
+- `./gradlew detekt`
+- `./gradlew test`
+- `./gradlew check`

nook-api-application/src/main/kotlin/org/every/nook/api/application/place/PlaceParsingLog.kt

@@ -0,0 +1,24 @@
+package org.every.nook.api.application.place
+
+import org.every.nook.api.application.processing.ProcessingLogEvent
+
+internal fun ClaimedPlaceParsingJob.event(
+    action: String,
+    stage: String,
+    outcome: String,
+    durationMs: Long? = null,
+    fields: Map<String, Any?> = emptyMap(),
+) = ProcessingLogEvent(action, PLACE_FLOW, stage, outcome, postId, attempt, durationMs, fields)
+
+internal fun failureFields(exception: Throwable, reason: String): Map<String, Any?> = mapOf(
+    "failure.type" to exception::class.simpleName,
+    "failure.reason" to reason,
+)
+
+internal fun placeFailureReason(exception: Throwable): String = exception.message.orEmpty()
+    .ifBlank { DEFAULT_FAILURE_REASON }
+    .take(MAX_FAILURE_REASON_LENGTH)
+
+private const val PLACE_FLOW = "place"
+private const val DEFAULT_FAILURE_REASON = "Place parsing failed"
+private const val MAX_FAILURE_REASON_LENGTH = 500

nook-api-application/src/main/kotlin/org/every/nook/api/application/place/ProcessPlaceParsingJobUseCase.kt

@@ -3,7 +3,11 @@ package org.every.nook.api.application.place
 import mu.KotlinLogging
 import org.every.nook.api.application.processing.NoOpProcessingMetrics
 import org.every.nook.api.application.processing.ProcessingMetrics
+import org.every.nook.api.application.processing.error
+import org.every.nook.api.application.processing.info
 import org.every.nook.api.application.processing.measure
+import org.every.nook.api.application.processing.warn
+import org.slf4j.LoggerFactory
 import java.time.Clock
 import java.time.Duration
 import java.time.Instant
@@ -22,46 +26,59 @@ class ProcessPlaceParsingJobUseCase(
     operator fun invoke(postId: Long): Result {
         val job = jobPort.claim(postId, processingTimeout) ?: return Result.Skipped
         val startedAt = clock.instant()
+        eventLogger.info(job.event("place.job.claimed", JOB_STAGE, SUCCESS_OUTCOME))
         logger.info { "Place parsing started: postId=${job.postId}, attempt=${job.attempt}" }
 
-        return runCatching {
-            val expectedPlaceCount = expectedPlaceCount(job.body)
-            val textClues = (job.textClues ?: extractClues(job)).filter { clue ->
-                clue.isGroundedIn(job).also { grounded ->
-                    if (!grounded) {
-                        logger.warn {
-                            "Ungrounded text place clue skipped: postId=${job.postId}, attempt=${job.attempt}, " +
-                                "placeName=${clue.name}, region=${clue.region}, queries=${clue.queries}"
-                        }
+        return runCatching { process(job, startedAt) }.getOrElse { exception ->
+            handleFailure(job, exception, startedAt)
+        }
+    }
+
+    private fun process(job: ClaimedPlaceParsingJob, startedAt: Instant): Result {
+        val expectedPlaceCount = expectedPlaceCount(job.body)
+        val textClues = (job.textClues ?: extractClues(job)).filter { clue ->
+            clue.isGroundedIn(job).also { grounded ->
+                if (!grounded) {
+                    logger.warn {
+                        "Ungrounded text place clue skipped: postId=${job.postId}, attempt=${job.attempt}, " +
+                            "placeName=${clue.name}, region=${clue.region}, queries=${clue.queries}"
                     }
                 }
             }
-            val textResolution = resolveClues(job, textClues)
-            val imageResolution = resolveImageClues(job, textResolution.places.size, expectedPlaceCount)
-            val places = (textResolution.places + imageResolution?.places.orEmpty())
-                .distinctBy { it.provider to it.externalPlaceId }
-            if (places.isEmpty()) {
-                val failure = imageResolution?.failure ?: textResolution.failure
-                terminalFailure(
-                    failure?.message ?: if (imageResolution == null) {
-                        NO_PLACE_RESOLVED_REASON
-                    } else {
-                        NO_PLACE_RESOLVED_AFTER_IMAGE_REASON
-                    },
-                )
-            }
-            measure(job, COMPLETE_STAGE) {
-                jobPort.complete(job.postId, places)
-            }
-            val duration = Duration.between(startedAt, clock.instant()).toMillis()
-            logger.info {
-                "Place parsing completed: postId=${job.postId}, attempt=${job.attempt}, " +
-                    "placeCount=${places.size}, durationMs=$duration"
-            }
-            Result.Completed
-        }.getOrElse { exception ->
-            handleFailure(job, exception, startedAt)
         }
+        val textResolution = resolveClues(job, textClues)
+        logOcrDecision(eventLogger, job, textResolution.places.size, expectedPlaceCount)
+        val imageResolution = resolveImageClues(job, textResolution.places.size, expectedPlaceCount)
+        val places = (textResolution.places + imageResolution?.places.orEmpty())
+            .distinctBy { it.provider to it.externalPlaceId }
+        if (places.isEmpty()) {
+            val failure = imageResolution?.failure ?: textResolution.failure
+            terminalFailure(
+                failure?.message ?: if (imageResolution == null) {
+                    NO_PLACE_RESOLVED_REASON
+                } else {
+                    NO_PLACE_RESOLVED_AFTER_IMAGE_REASON
+                },
+            )
+        }
+        measure(job, COMPLETE_STAGE) {
+            jobPort.complete(job.postId, places)
+        }
+        val duration = Duration.between(startedAt, clock.instant()).toMillis()
+        logger.info {
+            "Place parsing completed: postId=${job.postId}, attempt=${job.attempt}, " +
+                "placeCount=${places.size}, durationMs=$duration"
+        }
+        eventLogger.info(
+            job.event(
+                "place.job.completed",
+                JOB_STAGE,
+                SUCCESS_OUTCOME,
+                duration,
+                mapOf("place.resolved_count" to places.size),
+            ),
+        )
+        return Result.Completed
     }
 
     private fun resolveImageClues(
@@ -187,6 +204,20 @@ class ProcessPlaceParsingJobUseCase(
         if (!clue.isSupportedBy(resolved)) {
             failResolution("Selected place is not grounded in image evidence: ${clue.name}")
         }
+        eventLogger.info(
+            job.event(
+                "place.candidate.selected",
+                SELECT_STAGE,
+                SUCCESS_OUTCOME,
+                fields = mapOf(
+                    "provider.name" to resolved.provider,
+                    "place.external_id" to resolved.externalPlaceId,
+                    "place.selection_method" to if (matches.size == 1) "strict_match" else "openai",
+                    "place.candidate_count" to candidates.size,
+                    "place.strict_match_count" to matches.size,
+                ),
+            ),
+        )
         logger.info {
             "Place resolved: provider=${resolved.provider}, externalPlaceId=${resolved.externalPlaceId}, " +
                 "name=${resolved.name}, address=${resolved.address}"
@@ -234,10 +265,14 @@ class ProcessPlaceParsingJobUseCase(
     private fun failResolution(message: String): Nothing = throw PlaceResolutionException(message)
 
     private fun handleFailure(job: ClaimedPlaceParsingJob, exception: Throwable, startedAt: Instant): Result {
-        val reason = failureReason(exception)
+        val reason = placeFailureReason(exception)
         val duration = Duration.between(startedAt, clock.instant()).toMillis()
         if (exception is TerminalPlaceParsingException) {
             jobPort.fail(job.postId, reason)
+            eventLogger.warn(
+                job.event("place.job.failed", JOB_STAGE, FAILURE_OUTCOME, duration, failureFields(exception, reason)),
+                exception,
+            )
             logger.warn {
                 "Place parsing failed without retry: postId=${job.postId}, attempt=${job.attempt}, " +
                     "durationMs=$duration, reason=$reason"
@@ -249,6 +284,16 @@ class ProcessPlaceParsingJobUseCase(
         if (backoff != null) {
             val nextAttemptAt = clock.instant().plus(backoff)
             jobPort.retry(job.postId, nextAttemptAt, reason)
+            eventLogger.warn(
+                job.event(
+                    "place.job.retry_scheduled",
+                    JOB_STAGE,
+                    FAILURE_OUTCOME,
+                    duration,
+                    failureFields(exception, reason) + ("retry.next_attempt_at" to nextAttemptAt),
+                ),
+                exception,
+            )
             logger.warn(exception) {
                 "Place parsing retry scheduled: postId=${job.postId}, attempt=${job.attempt}, " +
                     "nextAttemptAt=$nextAttemptAt, durationMs=$duration, reason=$reason"
@@ -257,17 +302,17 @@ class ProcessPlaceParsingJobUseCase(
         }
 
         jobPort.fail(job.postId, reason)
+        eventLogger.error(
+            job.event("place.job.failed", JOB_STAGE, FAILURE_OUTCOME, duration, failureFields(exception, reason)),
+            exception,
+        )
         logger.error(exception) {
             "Place parsing failed permanently: postId=${job.postId}, attempt=${job.attempt}, " +
                 "durationMs=$duration, reason=$reason"
         }
         return Result.Failed
     }
 
-    private fun failureReason(exception: Throwable): String = exception.message.orEmpty()
-        .ifBlank { DEFAULT_FAILURE_REASON }
-        .take(MAX_FAILURE_REASON_LENGTH)
-
     private fun terminalFailure(message: String): Nothing = throw TerminalPlaceParsingException(message)
 
     sealed interface Result {
@@ -282,13 +327,12 @@ class ProcessPlaceParsingJobUseCase(
 
     private companion object {
         val logger = KotlinLogging.logger {}
+        val eventLogger = LoggerFactory.getLogger(ProcessPlaceParsingJobUseCase::class.java)
 
         const val MAX_PLACE_COUNT = 20
         const val MAX_QUERY_COUNT = 4
         const val MAX_IMAGE_COUNT = 20
         const val CANDIDATE_LOG_LIMIT = 5
-        const val MAX_FAILURE_REASON_LENGTH = 500
-        const val DEFAULT_FAILURE_REASON = "Place parsing failed"
         const val NO_PLACE_RESOLVED_REASON = "No place could be resolved from text"
         const val NO_PLACE_RESOLVED_AFTER_IMAGE_REASON = "No place could be resolved after image analysis"
         const val PLACE_FLOW = "place"
@@ -298,6 +342,10 @@ class ProcessPlaceParsingJobUseCase(
         const val SEARCH_STAGE = "search"
         const val SELECT_STAGE = "select"
         const val COMPLETE_STAGE = "complete"
+        const val JOB_STAGE = "job"
+        const val OCR_STAGE = "ocr"
+        const val SUCCESS_OUTCOME = "success"
+        const val FAILURE_OUTCOME = "failure"
     }
 
     private class PlaceResolutionException(message: String) : IllegalStateException(message)
@@ -307,6 +355,28 @@ class ProcessPlaceParsingJobUseCase(
     private data class ClueResolution(val places: List<PlaceCandidate>, val failure: PlaceResolutionException?)
 }
 
+private fun logOcrDecision(
+    logger: org.slf4j.Logger,
+    job: ClaimedPlaceParsingJob,
+    textPlaceCount: Int,
+    expectedPlaceCount: Int?,
+) {
+    logger.info(
+        job.event(
+            "place.ocr.decision",
+            "ocr",
+            "success",
+            fields = mapOf(
+                "ocr.required" to requiresImageAnalysis(textPlaceCount, expectedPlaceCount),
+                "ocr.reason" to ocrReason(textPlaceCount, expectedPlaceCount, job.imageUrls.isEmpty()),
+                "place.text_resolved_count" to textPlaceCount,
+                "place.expected_count" to expectedPlaceCount,
+                "content.image_count" to job.imageUrls.size,
+            ),
+        ),
+    )
+}
+
 private fun PlaceClue.isGroundedIn(job: ClaimedPlaceParsingJob): Boolean {
     val sources = buildList {
         job.body?.let(::add)
@@ -323,6 +393,13 @@ private fun PlaceClue.isGroundedIn(job: ClaimedPlaceParsingJob): Boolean {
 private fun requiresImageAnalysis(textPlaceCount: Int, expectedPlaceCount: Int?): Boolean =
     textPlaceCount == 0 || expectedPlaceCount?.let { textPlaceCount < it } == true
 
+private fun ocrReason(textPlaceCount: Int, expectedPlaceCount: Int?, imagesEmpty: Boolean): String = when {
+    imagesEmpty -> "no_images"
+    textPlaceCount == 0 -> "no_text_place_resolved"
+    expectedPlaceCount != null && textPlaceCount < expectedPlaceCount -> "expected_place_count_shortfall"
+    else -> "text_places_sufficient"
+}
+
 private fun expectedPlaceCount(body: String?): Int? = body?.let { content ->
     EXPECTED_PLACE_COUNT_PATTERN.findAll(content)
         .mapNotNull { match -> match.groupValues[1].toIntOrNull() }