diff --git a/src/main/java/com/beachcheck/global/tracing/SanitizingQueryTracingObservationHandler.java b/src/main/java/com/beachcheck/global/tracing/JdbcQueryErrorSanitizingObservationHandler.java similarity index 81% rename from src/main/java/com/beachcheck/global/tracing/SanitizingQueryTracingObservationHandler.java rename to src/main/java/com/beachcheck/global/tracing/JdbcQueryErrorSanitizingObservationHandler.java index 5b3beb57..e0b593c6 100644 --- a/src/main/java/com/beachcheck/global/tracing/SanitizingQueryTracingObservationHandler.java +++ b/src/main/java/com/beachcheck/global/tracing/JdbcQueryErrorSanitizingObservationHandler.java @@ -16,16 +16,16 @@ * *

Contract(Input): datasource-micrometer가 생성한 QueryContext * - *

Contract(Output): ERROR span에는 원래 예외 클래스명과 민감정보가 제거된 exception event만 기록 + *

Contract(Output): 오류가 발생한 JDBC query span에는 원래 예외 클래스명과 민감정보가 제거된 exception event만 기록 */ @Component @Order(MicrometerTracingAutoConfiguration.DEFAULT_TRACING_OBSERVATION_HANDLER_ORDER - 1000) -public class SanitizingQueryTracingObservationHandler extends QueryTracingObservationHandler { +public class JdbcQueryErrorSanitizingObservationHandler extends QueryTracingObservationHandler { private static final String ERROR_TYPE = "error.type"; private static final String SANITIZED_ERROR_MESSAGE = "JDBC 쿼리 실행 실패"; - public SanitizingQueryTracingObservationHandler(Tracer tracer) { + public JdbcQueryErrorSanitizingObservationHandler(Tracer tracer) { super(tracer); } diff --git a/src/main/java/com/beachcheck/outbox/config/OutboxFirebaseConfig.java b/src/main/java/com/beachcheck/outbox/config/OutboxFirebaseConfig.java index d5c81d5d..f82c51a6 100644 --- a/src/main/java/com/beachcheck/outbox/config/OutboxFirebaseConfig.java +++ b/src/main/java/com/beachcheck/outbox/config/OutboxFirebaseConfig.java @@ -6,6 +6,7 @@ import com.beachcheck.outbox.service.OutboxPublisher; import com.beachcheck.outbox.tracing.OutboxTracing; import com.google.firebase.messaging.FirebaseMessaging; +import io.micrometer.tracing.Tracer; import org.springframework.beans.factory.annotation.Value; import org.springframework.boot.autoconfigure.condition.ConditionalOnProperty; import org.springframework.context.annotation.Bean; @@ -33,9 +34,10 @@ public class OutboxFirebaseConfig { public OutboxEventDispatcher outboxEventDispatcher( OutboxEventRepository outboxEventRepository, NotificationRepository notificationRepository, - FirebaseMessaging firebaseMessaging) { + FirebaseMessaging firebaseMessaging, + Tracer tracer) { return new OutboxEventDispatcher( - outboxEventRepository, notificationRepository, firebaseMessaging); + outboxEventRepository, notificationRepository, firebaseMessaging, tracer); } @Bean diff --git a/src/main/java/com/beachcheck/outbox/service/OutboxEventDispatcher.java b/src/main/java/com/beachcheck/outbox/service/OutboxEventDispatcher.java index 6289a5d9..93ed9531 100644 --- a/src/main/java/com/beachcheck/outbox/service/OutboxEventDispatcher.java +++ b/src/main/java/com/beachcheck/outbox/service/OutboxEventDispatcher.java @@ -11,12 +11,18 @@ import com.google.firebase.messaging.FirebaseMessagingException; import com.google.firebase.messaging.Message; import com.google.firebase.messaging.MessagingErrorCode; +import io.micrometer.tracing.Span; +import io.micrometer.tracing.Tracer; import java.time.Duration; import java.time.Instant; +import java.util.concurrent.atomic.AtomicBoolean; +import java.util.function.Supplier; import org.slf4j.Logger; import org.slf4j.LoggerFactory; import org.springframework.transaction.annotation.Propagation; import org.springframework.transaction.annotation.Transactional; +import org.springframework.transaction.support.TransactionSynchronization; +import org.springframework.transaction.support.TransactionSynchronizationManager; /** * Why: OutboxPublisher의 self-invocation 문제로 @Transactional(REQUIRES_NEW)가 프록시를 우회하는 것을 방지하기 위해 별도 @@ -31,14 +37,17 @@ public class OutboxEventDispatcher { private final OutboxEventRepository outboxEventRepository; private final NotificationRepository notificationRepository; private final FirebaseMessaging firebaseMessaging; + private final Tracer tracer; public OutboxEventDispatcher( OutboxEventRepository outboxEventRepository, NotificationRepository notificationRepository, - FirebaseMessaging firebaseMessaging) { + FirebaseMessaging firebaseMessaging, + Tracer tracer) { this.outboxEventRepository = outboxEventRepository; this.notificationRepository = notificationRepository; this.firebaseMessaging = firebaseMessaging; + this.tracer = tracer; } /** @@ -48,51 +57,98 @@ public OutboxEventDispatcher( */ @Transactional(propagation = Propagation.REQUIRES_NEW) public void dispatch(OutboxEvent event) { + Span span = startSpan("outbox dispatch"); + AtomicBoolean outcomeRecorded = new AtomicBoolean(false); + boolean transactionSynchronizationActive = + TransactionSynchronizationManager.isSynchronizationActive(); + if (transactionSynchronizationActive) { + registerCompletionCallback(span, outcomeRecorded, event); + } + try (Tracer.SpanInScope ignored = tracer.withSpan(span)) { + dispatchEvent(event, span, outcomeRecorded); + } catch (RuntimeException | Error exception) { + outcomeRecorded.set(true); + span.tag("outbox.item.outcome", "error"); + span.tag("outbox.failure.class", exception.getClass().getName()); + span.error(new IllegalStateException("Outbox dispatch 실패")); + throw exception; + } finally { + if (!transactionSynchronizationActive) { + span.end(); + } + } + } + + private void dispatchEvent(OutboxEvent event, Span dispatchSpan, AtomicBoolean outcomeRecorded) { // 1. Notification 조회 Notification notification = - notificationRepository - .findById(event.getNotificationId()) - .orElseThrow(() -> new IllegalArgumentException("Notification을 찾을 수 없습니다")); + traceChild( + "outbox notification lookup", + () -> + notificationRepository + .findById(event.getNotificationId()) + .orElseThrow(() -> new IllegalArgumentException("Notification을 찾을 수 없습니다"))); // 2. 멱등성: 이미 SENT 상태면 OutboxEvent만 SENT로 전이하고 스킵 if (notification.getStatus() == NotificationStatus.SENT) { - event.markAsSent(); - outboxEventRepository.save(event); - log.info( - "Outbox 이벤트 멱등 스킵 (이미 발송됨)", - kv("outboxEventId", event.getId()), - kv("notificationId", event.getNotificationId()), - kv("outboxEventType", event.getEventType())); + traceStateUpdate( + () -> { + event.markAsSent(); + outboxEventRepository.save(event); + }); + recordAfterCommit( + () -> { + outcomeRecorded.set(true); + dispatchSpan.tag("outbox.item.outcome", "skipped"); + dispatchSpan.tag("outbox.item.skip.reason", "already_sent"); + log.info( + "Outbox 이벤트 멱등 스킵 (이미 발송됨)", + kv("outboxEventId", event.getId()), + kv("notificationId", event.getNotificationId()), + kv("outboxEventType", event.getEventType())); + }); return; } // 3. FCM 전송 try { Message message = notification.toFcmMessage(); - firebaseMessaging.send(message); + sendFcm(message, event); + + traceStateUpdate( + () -> { + // 4. Notification 상태 업데이트 + notification.setStatus(NotificationStatus.SENT); + notification.setSentAt(Instant.now()); + notificationRepository.save(notification); - // 4. Notification 상태 업데이트 - notification.setStatus(NotificationStatus.SENT); - notification.setSentAt(Instant.now()); - notificationRepository.save(notification); - - // 5. OutboxEvent 상태 업데이트 - event.markAsSent(); - outboxEventRepository.save(event); - - log.info( - "Outbox 이벤트 발송 성공", - kv("outboxEventId", event.getId()), - kv("notificationId", event.getNotificationId()), - kv("outboxEventType", event.getEventType()), - kv("retryCount", event.getRetryCount())); + // 5. OutboxEvent 상태 업데이트 + event.markAsSent(); + outboxEventRepository.save(event); + }); + recordAfterCommit( + () -> { + outcomeRecorded.set(true); + dispatchSpan.tag("outbox.item.outcome", "success"); + log.info( + "Outbox 이벤트 발송 성공", + kv("outboxEventId", event.getId()), + kv("notificationId", event.getNotificationId()), + kv("outboxEventType", event.getEventType()), + kv("retryCount", event.getRetryCount())); + }); } catch (FirebaseMessagingException e) { // Exponential Backoff 재시도 로직 if (isPermanentFcmError(e)) { - event.markAsFailedPermanent(); - notification.markAsFailed("errorCode: " + e.getMessagingErrorCode()); - notificationRepository.save(notification); - outboxEventRepository.save(event); + traceStateUpdate( + () -> { + event.markAsFailedPermanent(); + notification.markAsFailed("errorCode: " + e.getMessagingErrorCode()); + notificationRepository.save(notification); + outboxEventRepository.save(event); + }); + tagFailureOutcome( + dispatchSpan, outcomeRecorded, "permanent_failure", event.getRetryCount()); log.warn( "Outbox 이벤트 발송 영구 실패", kv("outboxEventId", event.getId()), @@ -103,10 +159,15 @@ public void dispatch(OutboxEvent event) { Duration backoff = Duration.ofSeconds(1L << event.getRetryCount()); // 1s, 2s, 4s if (event.getRetryCount() >= 3) { // 최대 재시도 횟수 초과 시 영구 실패로 전이 - event.markAsFailedPermanent(); - notification.markAsFailed("errorCode: " + e.getMessagingErrorCode()); - notificationRepository.save(notification); - outboxEventRepository.save(event); + traceStateUpdate( + () -> { + event.markAsFailedPermanent(); + notification.markAsFailed("errorCode: " + e.getMessagingErrorCode()); + notificationRepository.save(notification); + outboxEventRepository.save(event); + }); + tagFailureOutcome( + dispatchSpan, outcomeRecorded, "permanent_failure", event.getRetryCount()); log.warn( "Outbox 이벤트 발송 영구 실패 (최대 재시도 초과)", kv("outboxEventId", event.getId()), @@ -114,8 +175,13 @@ public void dispatch(OutboxEvent event) { kv("retryCount", event.getRetryCount()), kv("messagingErrorCode", e.getMessagingErrorCode())); } else { - event.markAsFailedRetriable(backoff); - outboxEventRepository.save(event); + traceStateUpdate( + () -> { + event.markAsFailedRetriable(backoff); + outboxEventRepository.save(event); + }); + tagFailureOutcome( + dispatchSpan, outcomeRecorded, "retryable_failure", event.getRetryCount()); log.warn( "Outbox 이벤트 발송 실패 (재시도 예정)", kv("outboxEventId", event.getId()), @@ -126,6 +192,96 @@ public void dispatch(OutboxEvent event) { } } + private void sendFcm(Message message, OutboxEvent event) throws FirebaseMessagingException { + Span span = startClientSpan("outbox fcm send"); + try (Tracer.SpanInScope ignored = tracer.withSpan(span)) { + firebaseMessaging.send(message); + span.tag("outbox.fcm.outcome", "success"); + } catch (FirebaseMessagingException exception) { + String outcome = + isPermanentFcmError(exception) || event.getRetryCount() >= 3 + ? "permanent_failure" + : "retryable_failure"; + span.tag("outbox.fcm.outcome", outcome); + span.error(new IllegalStateException("FCM 전송 실패")); + throw exception; + } finally { + span.end(); + } + } + + private void traceStateUpdate(Runnable action) { + traceChild( + "outbox state update", + () -> { + action.run(); + return null; + }); + } + + private T traceChild(String name, Supplier action) { + Span span = startSpan(name); + try (Tracer.SpanInScope ignored = tracer.withSpan(span)) { + return action.get(); + } finally { + span.end(); + } + } + + private Span startSpan(String name) { + return tracer.nextSpan().name(name).start(); + } + + private Span startClientSpan(String name) { + return tracer + .spanBuilder() + .setParent(tracer.currentSpan().context()) + .name(name) + .kind(Span.Kind.CLIENT) + .start(); + } + + private void tagFailureOutcome( + Span span, AtomicBoolean outcomeRecorded, String outcome, int retryCount) { + outcomeRecorded.set(true); + span.tag("outbox.item.outcome", outcome); + span.tag("outbox.retry.count", retryCount); + } + + private void recordAfterCommit(Runnable action) { + if (TransactionSynchronizationManager.isSynchronizationActive()) { + TransactionSynchronizationManager.registerSynchronization( + new TransactionSynchronization() { + @Override + public void afterCommit() { + action.run(); + } + }); + return; + } + action.run(); + } + + private void registerCompletionCallback( + Span span, AtomicBoolean outcomeRecorded, OutboxEvent event) { + TransactionSynchronizationManager.registerSynchronization( + new TransactionSynchronization() { + @Override + public void afterCompletion(int status) { + if (status != TransactionSynchronization.STATUS_COMMITTED + && outcomeRecorded.compareAndSet(false, true)) { + span.tag("outbox.item.outcome", "error"); + span.error(new IllegalStateException("Outbox dispatch 커밋 실패")); + log.warn( + "Outbox 이벤트 상태 저장 커밋 실패", + kv("outboxEventId", event.getId()), + kv("notificationId", event.getNotificationId())); + } + span.end(); + } + }); + } + private boolean isPermanentFcmError(FirebaseMessagingException e) { MessagingErrorCode errorCode = e.getMessagingErrorCode(); return errorCode == MessagingErrorCode.UNREGISTERED diff --git a/src/test/java/com/beachcheck/global/tracing/JdbcTracingAutoConfigurationTest.java b/src/test/java/com/beachcheck/global/tracing/JdbcTracingAutoConfigurationTest.java index 405f23ff..82b28d23 100644 --- a/src/test/java/com/beachcheck/global/tracing/JdbcTracingAutoConfigurationTest.java +++ b/src/test/java/com/beachcheck/global/tracing/JdbcTracingAutoConfigurationTest.java @@ -48,7 +48,7 @@ void autoConfiguration_wrapsDataSourceAndEnablesQuerySpansOnly() { .hasSize(1) .allSatisfy( (name, handler) -> - assertThat(handler).isInstanceOf(SanitizingQueryTracingObservationHandler.class)); + assertThat(handler).isInstanceOf(JdbcQueryErrorSanitizingObservationHandler.class)); assertThat(context.getBeansOfType(OpenTelemetryMeterObservationHandler.class)).isEmpty(); } } diff --git a/src/test/java/com/beachcheck/outbox/config/OutboxFirebaseConditionContextTest.java b/src/test/java/com/beachcheck/outbox/config/OutboxFirebaseConditionContextTest.java index 4589dc38..4986af9e 100644 --- a/src/test/java/com/beachcheck/outbox/config/OutboxFirebaseConditionContextTest.java +++ b/src/test/java/com/beachcheck/outbox/config/OutboxFirebaseConditionContextTest.java @@ -15,6 +15,7 @@ import com.google.firebase.FirebaseApp; import com.google.firebase.FirebaseOptions; import com.google.firebase.messaging.FirebaseMessaging; +import io.micrometer.tracing.Tracer; import java.io.InputStream; import org.junit.jupiter.api.DisplayName; import org.junit.jupiter.api.Test; @@ -31,7 +32,8 @@ class OutboxFirebaseConditionContextTest { .withPropertyValues("app.outbox.polling.enabled=true", "app.outbox.polling.batch-size=10") .withBean(OutboxEventRepository.class, () -> mock(OutboxEventRepository.class)) .withBean(NotificationRepository.class, () -> mock(NotificationRepository.class)) - .withBean(OutboxTracing.class, () -> mock(OutboxTracing.class)); + .withBean(OutboxTracing.class, () -> mock(OutboxTracing.class)) + .withBean(Tracer.class, () -> mock(Tracer.class)); @Test @DisplayName("Firebase가 비활성화되면 Outbox 관련 빈 없이도 컨텍스트가 정상 기동된다") diff --git a/src/test/java/com/beachcheck/outbox/integration/OutboxPublisherIntegrationTest.java b/src/test/java/com/beachcheck/outbox/integration/OutboxPublisherIntegrationTest.java index d7202956..03ab3746 100644 --- a/src/test/java/com/beachcheck/outbox/integration/OutboxPublisherIntegrationTest.java +++ b/src/test/java/com/beachcheck/outbox/integration/OutboxPublisherIntegrationTest.java @@ -31,7 +31,10 @@ import com.google.firebase.messaging.FirebaseMessagingException; import com.google.firebase.messaging.Message; import com.google.firebase.messaging.MessagingErrorCode; +import io.micrometer.tracing.Tracer; +import io.opentelemetry.api.common.AttributeKey; import io.opentelemetry.api.trace.SpanKind; +import io.opentelemetry.api.trace.StatusCode; import io.opentelemetry.sdk.trace.SdkTracerProvider; import io.opentelemetry.sdk.trace.data.SpanData; import java.time.Instant; @@ -90,6 +93,8 @@ class OutboxPublisherIntegrationTest extends IntegrationTest { @Autowired private SdkTracerProvider tracerProvider; + @Autowired private Tracer tracer; + @TestConfiguration(proxyBeanMethods = false) static class OutboxTestConfig { @@ -97,9 +102,10 @@ static class OutboxTestConfig { OutboxEventDispatcher outboxEventDispatcher( OutboxEventRepository outboxEventRepository, NotificationRepository notificationRepository, - FirebaseMessaging firebaseMessaging) { + FirebaseMessaging firebaseMessaging, + Tracer tracer) { return new OutboxEventDispatcher( - outboxEventRepository, notificationRepository, firebaseMessaging); + outboxEventRepository, notificationRepository, firebaseMessaging, tracer); } @Bean @@ -138,6 +144,7 @@ void shouldProcessPendingEventAndMarkAsSent() throws FirebaseMessagingException // Given: 실제 DB에 Notification + OutboxEvent 저장 Notification notification = createAndSaveNotification(NotificationStatus.PENDING); OutboxEvent event = createAndSaveOutboxEvent(notification.getId()); + resetSpans(); // When: OutboxPublisher 수동 실행 (스케줄러 대신 직접 호출하여 테스트 제어) outboxPublisher.processPendingOutboxEvents(); @@ -160,6 +167,29 @@ void shouldProcessPendingEventAndMarkAsSent() throws FirebaseMessagingException // Then: FCM 전송 확인 then(firebaseMessaging).should().send(any(Message.class)); + + // Then: runtime trace 구조와 성공 결과 확인 + List spans = awaitSpans(exporter, tracerProvider, 5); + SpanData processSpan = onlySpanNamed(spans, "outbox process"); + SpanData dispatchSpan = onlySpanNamed(spans, "outbox dispatch"); + SpanData lookupSpan = onlySpanNamed(spans, "outbox notification lookup"); + SpanData fcmSpan = onlySpanNamed(spans, "outbox fcm send"); + SpanData stateSpan = onlySpanNamed(spans, "outbox state update"); + + assertThat(dispatchSpan.getParentSpanId()).isEqualTo(processSpan.getSpanId()); + assertThat(lookupSpan.getParentSpanId()).isEqualTo(dispatchSpan.getSpanId()); + assertThat(fcmSpan.getParentSpanId()).isEqualTo(dispatchSpan.getSpanId()); + assertThat(stateSpan.getParentSpanId()).isEqualTo(dispatchSpan.getSpanId()); + assertThat(dispatchSpan.getKind()).isEqualTo(SpanKind.INTERNAL); + assertThat(lookupSpan.getKind()).isEqualTo(SpanKind.INTERNAL); + assertThat(fcmSpan.getKind()).isEqualTo(SpanKind.CLIENT); + assertThat(stateSpan.getKind()).isEqualTo(SpanKind.INTERNAL); + assertThat(dispatchSpan.getAttributes().get(AttributeKey.stringKey("outbox.item.outcome"))) + .isEqualTo("success"); + assertThat(fcmSpan.getAttributes().get(AttributeKey.stringKey("outbox.fcm.outcome"))) + .isEqualTo("success"); + assertThat(tracer.currentSpan()).isNull(); + assertNoSensitiveTraceData(spans, notification); } @Test @@ -212,6 +242,7 @@ void shouldSkipAlreadySentNotification() throws FirebaseMessagingException { // Given: SENT 상태의 Notification + PENDING OutboxEvent Notification notification = createAndSaveNotification(NotificationStatus.SENT); OutboxEvent event = createAndSaveOutboxEvent(notification.getId()); + resetSpans(); // When: OutboxPublisher 실행 outboxPublisher.processPendingOutboxEvents(); @@ -225,6 +256,15 @@ void shouldSkipAlreadySentNotification() throws FirebaseMessagingException { // Then: FCM 전송 안 됨 then(firebaseMessaging).should(never()).send(any(Message.class)); + + List spans = awaitSpans(exporter, tracerProvider, 4); + SpanData dispatchSpan = onlySpanNamed(spans, "outbox dispatch"); + assertThat(dispatchSpan.getAttributes().get(AttributeKey.stringKey("outbox.item.outcome"))) + .isEqualTo("skipped"); + assertThat(dispatchSpan.getAttributes().get(AttributeKey.stringKey("outbox.item.skip.reason"))) + .isEqualTo("already_sent"); + assertThat(spans).noneMatch(span -> span.getName().equals("outbox fcm send")); + assertNoSensitiveTraceData(spans, notification); } @Test @@ -236,6 +276,7 @@ void shouldPersistFailedRetriableToDb_whenFcmThrows() throws FirebaseMessagingEx OutboxEvent event = createAndSaveOutboxEvent(notification.getId()); given(firebaseMessaging.send(any(Message.class))).willThrow(FirebaseMessagingException.class); + resetSpans(); // When: OutboxPublisher 실행 @@ -254,6 +295,13 @@ void shouldPersistFailedRetriableToDb_whenFcmThrows() throws FirebaseMessagingEx assertThat(processedEvent.getRetryCount()).isEqualTo(1); assertThat(processedEvent.getNextRetryAt()) .isBetween(before.plusSeconds(1), after.plusSeconds(1)); + + List spans = awaitSpans(exporter, tracerProvider, 5); + assertFailureTrace(spans, "retryable_failure", 1); + assertThat(onlySpanNamed(spans, "outbox process").getStatus().getStatusCode()) + .isEqualTo(StatusCode.UNSET); + assertThat(tracer.currentSpan()).isNull(); + assertNoSensitiveTraceData(spans, notification); } @Test @@ -266,6 +314,7 @@ void shouldPersistFailedPermanentToDb_whenRetryCountExceedsMax() event.setRetryCount(3); // 이미 3번 실패한 상태로 세팅 outboxEventRepository.save(event); given(firebaseMessaging.send(any(Message.class))).willThrow(FirebaseMessagingException.class); + resetSpans(); // When outboxPublisher.processPendingOutboxEvents(); @@ -276,6 +325,11 @@ void shouldPersistFailedPermanentToDb_whenRetryCountExceedsMax() .findById(event.getId()) .orElseThrow(() -> new IllegalStateException("OutboxEvent를 찾을 수 없습니다")); assertThat(saved.getStatus()).isEqualTo(OutboxEventStatus.FAILED_PERMANENT); + + List spans = awaitSpans(exporter, tracerProvider, 5); + assertFailureTrace(spans, "permanent_failure", 3); + assertThat(onlySpanNamed(spans, "outbox process").getStatus().getStatusCode()) + .isEqualTo(StatusCode.UNSET); } @Test @@ -393,6 +447,7 @@ void shouldPersistFailedPermanent_whenFcmReturnsUnregistered() throws FirebaseMe FirebaseMessagingException exception = mock(FirebaseMessagingException.class); given(exception.getMessagingErrorCode()).willReturn(MessagingErrorCode.UNREGISTERED); given(firebaseMessaging.send(any(Message.class))).willThrow(exception); + resetSpans(); // When outboxPublisher.processPendingOutboxEvents(); @@ -405,6 +460,11 @@ void shouldPersistFailedPermanent_whenFcmReturnsUnregistered() throws FirebaseMe assertThat(saved.getStatus()).isEqualTo(OutboxEventStatus.FAILED_PERMANENT); assertThat(saved.getRetryCount()).isEqualTo(0); assertThat(saved.getProcessedAt()).isNotNull(); + + List spans = awaitSpans(exporter, tracerProvider, 5); + assertFailureTrace(spans, "permanent_failure", 0); + assertThat(onlySpanNamed(spans, "outbox process").getStatus().getStatusCode()) + .isEqualTo(StatusCode.UNSET); } @Test @@ -519,6 +579,51 @@ private SpanData onlyProcessSpan(List spans) { return processSpans.getFirst(); } + private SpanData onlySpanNamed(List spans, String name) { + List namedSpans = spans.stream().filter(span -> span.getName().equals(name)).toList(); + assertThat(namedSpans).hasSize(1); + return namedSpans.getFirst(); + } + + private void resetSpans() { + flushSpans(tracerProvider); + exporter.clear(); + } + + private void assertFailureTrace(List spans, String outcome, long retryCount) { + SpanData dispatchSpan = onlySpanNamed(spans, "outbox dispatch"); + SpanData fcmSpan = onlySpanNamed(spans, "outbox fcm send"); + assertThat(dispatchSpan.getAttributes().get(AttributeKey.stringKey("outbox.item.outcome"))) + .isEqualTo(outcome); + assertThat(dispatchSpan.getAttributes().get(AttributeKey.longKey("outbox.retry.count"))) + .isEqualTo(retryCount); + assertThat(fcmSpan.getAttributes().get(AttributeKey.stringKey("outbox.fcm.outcome"))) + .isEqualTo(outcome); + } + + private void assertNoSensitiveTraceData(List spans, Notification notification) { + List runtimeSpans = + spans.stream().filter(span -> span.getName().startsWith("outbox ")).toList(); + assertThat(runtimeSpans) + .allSatisfy( + span -> { + String attributeKeys = span.getAttributes().asMap().keySet().toString(); + String attributeValues = span.getAttributes().asMap().values().toString(); + String eventValues = span.getEvents().toString(); + assertThat(attributeKeys) + .doesNotContainIgnoringCase("notificationId") + .doesNotContainIgnoringCase("outboxEventId") + .doesNotContainIgnoringCase("userId") + .doesNotContainIgnoringCase("token"); + assertThat(attributeValues) + .doesNotContain(notification.getId().toString()) + .doesNotContain(notification.getRecipientToken()); + assertThat(eventValues) + .doesNotContain(notification.getId().toString()) + .doesNotContain(notification.getRecipientToken()); + }); + } + private List processSpans(List spans) { return spans.stream().filter(span -> span.getName().equals("outbox process")).toList(); } diff --git a/src/test/java/com/beachcheck/outbox/service/OutboxEventDispatcherTest.java b/src/test/java/com/beachcheck/outbox/service/OutboxEventDispatcherTest.java index 7295a26c..407c1e72 100644 --- a/src/test/java/com/beachcheck/outbox/service/OutboxEventDispatcherTest.java +++ b/src/test/java/com/beachcheck/outbox/service/OutboxEventDispatcherTest.java @@ -9,8 +9,11 @@ import static org.mockito.ArgumentMatchers.any; import static org.mockito.BDDMockito.given; import static org.mockito.BDDMockito.then; +import static org.mockito.Mockito.atLeast; import static org.mockito.Mockito.mock; import static org.mockito.Mockito.never; +import static org.springframework.transaction.support.TransactionSynchronization.STATUS_COMMITTED; +import static org.springframework.transaction.support.TransactionSynchronization.STATUS_ROLLED_BACK; import com.beachcheck.notification.domain.Notification; import com.beachcheck.notification.repository.NotificationRepository; @@ -20,6 +23,9 @@ import com.google.firebase.messaging.FirebaseMessagingException; import com.google.firebase.messaging.Message; import com.google.firebase.messaging.MessagingErrorCode; +import io.micrometer.tracing.Span; +import io.micrometer.tracing.TraceContext; +import io.micrometer.tracing.Tracer; import java.time.Instant; import java.util.Optional; import java.util.UUID; @@ -30,6 +36,8 @@ import org.junit.jupiter.api.extension.ExtendWith; import org.mockito.Mock; import org.mockito.junit.jupiter.MockitoExtension; +import org.springframework.transaction.support.TransactionSynchronizationManager; +import org.springframework.transaction.support.TransactionSynchronizationUtils; /** * Why: OutboxEventDispatcher.dispatch()의 FCM 전송 및 상태 전이 로직 검증 @@ -49,13 +57,23 @@ class OutboxEventDispatcherTest { @Mock private OutboxEventRepository outboxEventRepository; @Mock private NotificationRepository notificationRepository; @Mock private FirebaseMessaging firebaseMessaging; + @Mock private Tracer tracer; + @Mock private Span span; + @Mock private Span.Builder spanBuilder; + @Mock private TraceContext traceContext; + @Mock private Tracer.SpanInScope spanInScope; private OutboxEventDispatcher dispatcher; @BeforeEach void setUp() { + given(tracer.nextSpan()).willReturn(span); + given(span.name(any())).willReturn(span); + given(span.start()).willReturn(span); + given(tracer.withSpan(any())).willReturn(spanInScope); dispatcher = - new OutboxEventDispatcher(outboxEventRepository, notificationRepository, firebaseMessaging); + new OutboxEventDispatcher( + outboxEventRepository, notificationRepository, firebaseMessaging, tracer); } @Nested @@ -72,6 +90,7 @@ void shouldSendFcmAndMarkAsSent_whenPendingEventExists() throws FirebaseMessagin given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); given(firebaseMessaging.send(any(Message.class))).willReturn("message-id-12345"); + givenClientSpan(); // When dispatcher.dispatch(event); @@ -86,6 +105,64 @@ void shouldSendFcmAndMarkAsSent_whenPendingEventExists() throws FirebaseMessagin then(outboxEventRepository).should().save(event); } + @Test + @DisplayName("TC1-1 - DB 커밋 전에는 성공 결과를 기록하지 않음") + void shouldRecordSuccessOnlyAfterTransactionCommit() throws FirebaseMessagingException { + // Given + UUID notificationId = UUID.randomUUID(); + Notification notification = createNotification(notificationId, NotificationStatus.PENDING); + OutboxEvent event = createPendingEvent(notificationId); + + given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); + given(firebaseMessaging.send(any(Message.class))).willReturn("message-id-12345"); + givenClientSpan(); + TransactionSynchronizationManager.initSynchronization(); + + try { + // When + dispatcher.dispatch(event); + + // Then: dispatch() 반환 시점에는 아직 커밋 전이므로 성공 결과를 기록하지 않음 + then(span).should(never()).tag("outbox.item.outcome", "success"); + + // When: 트랜잭션 커밋 완료 콜백 실행 + TransactionSynchronizationUtils.triggerAfterCommit(); + + // Then + then(span).should().tag("outbox.item.outcome", "success"); + TransactionSynchronizationUtils.triggerAfterCompletion(STATUS_COMMITTED); + } finally { + TransactionSynchronizationManager.clearSynchronization(); + } + } + + @Test + @DisplayName("TC1-2 - DB 롤백 시 성공 대신 오류 결과를 기록") + void shouldRecordErrorWhenTransactionRollsBack() throws FirebaseMessagingException { + // Given + UUID notificationId = UUID.randomUUID(); + Notification notification = createNotification(notificationId, NotificationStatus.PENDING); + OutboxEvent event = createPendingEvent(notificationId); + + given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); + given(firebaseMessaging.send(any(Message.class))).willReturn("message-id-12345"); + givenClientSpan(); + TransactionSynchronizationManager.initSynchronization(); + + try { + // When + dispatcher.dispatch(event); + TransactionSynchronizationUtils.triggerAfterCompletion(STATUS_ROLLED_BACK); + + // Then + then(span).should().tag("outbox.item.outcome", "error"); + then(span).should().error(any(IllegalStateException.class)); + then(span).should(never()).tag("outbox.item.outcome", "success"); + } finally { + TransactionSynchronizationManager.clearSynchronization(); + } + } + @Test @DisplayName("TC2 - 멱등성: 이미 SENT 상태인 Notification은 FCM 전송 스킵") void shouldSkipFcmSend_whenNotificationAlreadySent() throws FirebaseMessagingException { @@ -120,6 +197,11 @@ void shouldThrowException_whenNotificationNotFound() { assertThatThrownBy(() -> dispatcher.dispatch(event)) .isInstanceOf(IllegalArgumentException.class) .hasMessageContaining("Notification을 찾을 수 없습니다"); + then(span).should().tag("outbox.item.outcome", "error"); + then(span).should().tag("outbox.failure.class", IllegalArgumentException.class.getName()); + then(span).should().error(any(IllegalStateException.class)); + then(spanInScope).should(atLeast(2)).close(); + then(span).should(atLeast(2)).end(); } @Test @@ -133,6 +215,7 @@ void shouldMarkAsFailedRetriable_whenFcmFails() throws FirebaseMessagingExceptio given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); given(firebaseMessaging.send(any(Message.class))) .willThrow(mock(FirebaseMessagingException.class)); + givenClientSpan(); // When Instant before = Instant.now(); @@ -160,6 +243,7 @@ void shouldMarkAsFailedPermanent_whenRetryCountExceeded() throws FirebaseMessagi given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); given(firebaseMessaging.send(any(Message.class))) .willThrow(mock(FirebaseMessagingException.class)); + givenClientSpan(); // When dispatcher.dispatch(event); @@ -184,6 +268,7 @@ void shouldApplyDoubledBackoff_whenRetryCountIsOne() throws FirebaseMessagingExc given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); given(firebaseMessaging.send(any(Message.class))) .willThrow(mock(FirebaseMessagingException.class)); + givenClientSpan(); // When Instant before = Instant.now(); @@ -210,6 +295,7 @@ void shouldMarkAsFailedPermanent_whenFcmErrorIsUnregistered() given(exception.getMessagingErrorCode()).willReturn(MessagingErrorCode.UNREGISTERED); given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); given(firebaseMessaging.send(any(Message.class))).willThrow(exception); + givenClientSpan(); // When dispatcher.dispatch(event); @@ -236,6 +322,7 @@ void shouldMarkAsFailedPermanent_whenFcmErrorIsInvalidArgument() given(exception.getMessagingErrorCode()).willReturn(MessagingErrorCode.INVALID_ARGUMENT); given(notificationRepository.findById(notificationId)).willReturn(Optional.of(notification)); given(firebaseMessaging.send(any(Message.class))).willThrow(exception); + givenClientSpan(); // When dispatcher.dispatch(event); @@ -250,6 +337,16 @@ void shouldMarkAsFailedPermanent_whenFcmErrorIsInvalidArgument() } } + private void givenClientSpan() { + given(span.context()).willReturn(traceContext); + given(tracer.currentSpan()).willReturn(span); + given(tracer.spanBuilder()).willReturn(spanBuilder); + given(spanBuilder.setParent(any())).willReturn(spanBuilder); + given(spanBuilder.name(any())).willReturn(spanBuilder); + given(spanBuilder.kind(any())).willReturn(spanBuilder); + given(spanBuilder.start()).willReturn(span); + } + private Notification createNotification(UUID notificationId, NotificationStatus status) { Notification notification = Notification.createPending(