ivada-infra/DOCS
2
0
Fork 0
Code Issues Pull Requests Actions Packages Projects Releases Wiki Activity
DOCS/journey/research/260309_9시_네이버이메일분석_미전송_실패은닉_리서치.md

7.3 KiB
Raw Blame History

tags
tags
infra
robeing
rb8001
skill-email
naverworks
research

260309 9시 네이버 이메일 분석 미전송 실패 은닉 리서치

상위 원칙

관련 문서

목적

  • 오늘 09:00 네이버 이메일 분석 미전송의 원인을 스케줄 문제와 실행 실패 은닉 문제로 분리해 특정합니다.
  • 실제 실패 지점이 rb8001, skill-email, auth-server, NAVER WORKS 외부 API 중 어디인지 좁힙니다.
  • 이후 계획 문서가 우회 없이 원인 경로를 직접 수정할 수 있도록 실패 표현 구조를 분해합니다.

Facts

1. 스케줄 등록과 실행은 정상이다

  • rb8001 로그에는 2026-03-09 09:00:00에 naverworks_daily가 실행된 기록이 있다.
  • 같은 시각 활성 잡 목록에도 naverworks_daily가 포함된다.
  • DB scheduled_jobs 테이블에도 name=naverworks_daily, job_type=naverworks_briefing, cron_expression=0 9 * * mon-fri, enabled=true가 존재한다.

2. 실패는 rb8001의 메일 조회 단계에서 발생했다

  • rb8001/app/services/skills/naverworks_briefing.py는 process_briefing()에서 _fetch_recent_emails()를 먼저 호출한다.
  • 실제 09:00 로그에는 메일 조회 파라미터가 기록된 뒤 09:00:30에 httpx.ReadTimeout 예외가 남아 있다.
  • 예외는 http://localhost:8501/messages 요청에서 발생했으며, 이 요청은 skill-email 컨테이너를 향한다.

3. 현재 구현은 실패와 0건을 구분하지 않는다

  • naverworks_briefing.py에서 _fetch_recent_emails()는 비200 응답이면 return [], 예외가 나도 return []를 반환한다.
  • 같은 함수의 호출부 process_briefing()는 if not emails: 분기에서 모두 No emails in the last 24 hours로 처리한다.
  • 이 구조 때문에 타임아웃, 토큰 갱신 실패, 실제 메일 없음이 동일한 결과값으로 합쳐진다.

4. skill-email의 NAVER WORKS 조회 경로에는 토큰 만료와 외부 API 호출이 포함된다

  • skill-email/services/naverworks_provider.py는 _get_account_context()에서 DB naverworks_token을 읽고, expires_at < now이면 auth-server /auth/naverworks/passport/refresh를 호출한다.
  • 그 뒤 list_messages()에서 https://www.worksapis.com/v1.0/users/{account_id}/mail/mailfolders/0/children를 호출해 실제 메일 목록을 가져온다.
  • 즉 조회 경로에는 DB -> auth-server refresh -> NAVER WORKS 외부 API 단계가 포함된다.

5. 당시 토큰은 실제로 만료돼 있었다

  • main_db.naverworks_token 조회 결과, 해당 사용자 3550cef6-63e1-4ceb-8802-a25c9d1c6917의 expires_at는 09시 조사 시점 기준 2026-03-05였다.
  • 따라서 09:00 요청은 skill-email 내부에서 토큰 갱신 경로를 먼저 탔을 가능성이 높다.
  • 수동 갱신 후 현재 expires_at가 2026-03-09 13:59:37로 바뀐 것도 확인됐다.

6. 현재 시점에는 같은 요청이 정상 응답한다

  • 같은 파라미터로 127.0.0.1:8501/messages를 호출했을 때 HTTP 200, 0.612889초로 응답했다.
  • 127.0.0.1:9000/auth/naverworks/passport/refresh 수동 호출도 HTTP 200, 0.233118초로 성공했다.
  • 127.0.0.1:9000/health도 HTTP 200으로 정상이다.

7. 만료 판단 경로에는 시간대와 컬럼 타입 취약성이 있다

  • rb8001 컨테이너 시간대는 KST +0900이고, skill-email, auth-server 컨테이너 시간대는 UTC +0000이다.
  • main_db.naverworks_token.expires_at 컬럼 타입은 timestamp without time zone이다.
  • 검증용으로 호스트 SQL에서 expires_at = NOW() - INTERVAL '10 minutes'를 기록한 뒤 /messages를 다시 호출했을 때, 요청은 HTTP 200, 0.253145초로 바로 끝났고 같은 시각 auth-server에는 refresh 요청 로그가 남지 않았다.
  • 즉 expires_at 만료 판단은 기록 시점의 시간대 해석에 따라 흔들릴 수 있는 취약한 구조다.

8. 현재 근거만으로는 외부 NAVER WORKS 지연과 내부 refresh 지연을 최종 분리할 수 없다

  • 09:00 당시 skill-email과 auth-server 로그에는 요청 단계별 세부 로그가 충분히 남아 있지 않다.
  • skill-email 09:00 구간 로그가 거의 비어 있어 refresh에서 멈췄는지, worksapis 조회에서 멈췄는지 단정할 직접 로그가 없다.
  • 따라서 현재 확정 가능한 직접 원인은 skill-email /messages read timeout, 구조 원인은 실패 은닉, 보조 위험 요인은 만료 토큰 상태까지다.

Interpretation

  • 오늘 사건의 핵심 문제는 9시 스케줄이 안 돌았다가 아니라 9시 스케줄은 돌았지만 실패가 성공처럼 기록됐다는 점이다.
  • 운영상 가장 먼저 고쳐야 할 부분은 실패 원인 분리이며, 그래야 그 다음에 refresh 지연인지 NAVER WORKS 외부 API 지연인지 재발 시 확정할 수 있다.
  • 현재 구조는 관측 불가능한 실패를 만든다. 이는 상위 SSOT의 Truth First와 충돌한다.
  • expires_at가 timestamp without time zone이고 컨테이너 시간대가 섞여 있는 점은, 오늘 사건의 직접 원인과 별개로 토큰 만료 판단을 불안정하게 만드는 구조 위험이다.
  • 따라서 수정 우선순위는 1. 실패 은닉 제거, 2. 단계별 원인 로그 추가, 3. expires_at 시간대 정합성 교정, 4. 토큰 만료/외부 API 지연 재발 여부 관측 순서가 맞다.

Unresolved

  • 09:00 시점 read timeout의 최종 블로킹 지점이 auth-server refresh인지 NAVER WORKS 외부 API인지는 직접 로그가 부족해 아직 확정하지 못했다.
  • skill-email의 /messages 경로에서 단계별 소요시간 로그가 없어, 같은 증상이 재발해도 현재 구조만으로는 즉시 구분이 어렵다.
  • expires_at 시간대 취약성이 실제 운영 경로에서도 재현되는지, 아니면 호스트 SQL 갱신 같은 예외 경로에서만 드러나는지도 별도 확인이 더 필요하다.
  • 따라서 다음 계획 문서는 실패 은닉 제거와 함께 단계별 원인 로그 보강, expires_at 타입/시간대 정합성 교정 여부 판단을 포함해야 한다.

한 줄 결론

  • 이번 사건의 직접 원인은 rb8001 -> skill-email /messages read timeout이고, 더 큰 구조 문제는 이 실패가 현재 코드에서 No emails로 은닉된다는 점이다.