경과시간 09:08 → 18:03 점프 — 누적시간 이중 가산 원인 분석

마지막 업데이트 2026-07-22

모니터(호스트) 화면의 경과시간이 23:54~23:56 사이 09:08 → 18:03 으로 ~2배 점프한 현상. 근본 원인은 "같은 ~9분 구간을 두 개의 타이머가 따로 재고, 화면이 그 둘을 더해서" 보여준 이중 가산이다. (LogRocket 세션 019eab05…3750f7, 게스트 아동151 / lesson 23)
📌 한 장 요약 — 스톱워치 두 개가 같은 시간을 잰다
⏱️ DB 종료 세션535초 14:46 ~ 23:52 구간이
duration 으로 확정됨
+
⏱️ lessonStartedAt548초 14:46 부터 지금까지
계속 살아있는 라이브 카운터
=
🖥️ 화면 표시1083초 = 18:03
같은 9분을 두 번 더함
두 스톱워치는 거의 같은 구간(14:46~)을 재고 있다. 정상이면 둘 중 하나만 세야 하는데, 모니터 재접속 직후 둘 다 살아남아 합산됐다.

1. 무엇이 겹쳤나 — 시간축으로 보기

가로축은 실제 벽시계 시간(레슨 시작 ~ 현재). 같은 9분 구간을 두 소스가 각각 측정하고 있다.

14:46
레슨 시작
23:52
모니터 끊김
23:54
지금(표시 시점)
① DB 종료 세션
duration=535s
14:46 → 23:52 (확정된 535초)
② lessonStartedAt
live=548s
14:46 → 지금 (살아있는 548초)
합산 결과
①+②
535
+
= 1083초 = 18:03 ⚠️
① DB에 확정된 종료 세션(duration) ② lessonStartedAt 라이브 카운터
두 막대가 14:46~23:52 구간에서 거의 완전히 겹친다. 즉 같은 9분을 두 번 센다. 그래서 09:08 ≈ 18:03 ÷ 2 가 성립한다 (548×2 ≈ 1083, 오차는 ①이 23:52에 끊겨 13초 짧기 때문).

2. 왜 23:53에 갑자기 터졌나 — count 0 → 1

점프 직전까지 useCumulativeElapsed가 fetch한 세션 개수는 줄곧 0이었다. 세션 0개일 때는 ②(lessonStartedAt) 단독으로만 계산되어 정상값 09:08 이 나왔다.

점프 이전
(~23:53)
fetch 세션 = 0개 → ① 없음
경과시간 = ② lessonStartedAt 단독 = 09:08 ✅ (정상)
점프 이후
(23:53.798~)
모니터 소켓 재접속 → 세션 재조회 → fetch 세션 = 1개(종료·duration 채워짐)
경과시간 = ① 535초 + ② 548초 = 18:03 ⚠️ (이중 가산)
방아쇠는 모니터(호스트) 소켓의 짧은 끊김→재접속이다. 게스트가 아니라 치료사 쪽 소켓transport close로 끊겼다가 1.4초 만에 재접속하면서 룸 상태를 재동기화했고, 그 과정에서 세션 목록을 다시 불러와 ①이 합류했다.

3. 로그 흐름 — 결정적 라인

LogRocket 상대시각(mm:ss.mmm) 기준. 강조행이 점프를 만든 지점.

상대시각level메시지
23:52.263WARN[Socket] ⚠️ Disconnected. {reason:"transport close", role:monitor} — 모니터 소켓 끊김
23:52.264WARN[Mediasoup] Socket disconnected {role:"monitor"}
23:53.687LOG[Monitor] peer-joined event received — 재접속, 룸 재동기화 시작
23:53.709LOG[Monitor] Guest detected via peer-joined, setting guestInforefetchSessions() 트리거
23:53.782INFO[CLIENT_HOST_SOCKET] Room state synced after guest connected
23:53.798INFO[USE_CUMULATIVE_ELAPSED] Sessions loaded for cumulative elapsed {count: 1} ← 직전까지 count:0, 여기서 ① 합류 = 범인
23:53.820INFO[USE_CUMULATIVE_ELAPSED] … {count: 1} (리렌더)

검증: 09:08 = 548초, 18:03 = 1083초, 증가분 = 535초 ≈ 기존 경과시간. MAX_SINGLE_SESSION_SECONDS = 3600초라 캡과 무관.

4. 코드 — dedup이 새는 지점

apps/web/hooks/use-cumulative-elapsed.ts:58–90 의 합산 루프:

// 세션 목록을 돌며 누적
for (const s of sessions) {
  if (s.duration != null) {
    total += Math.min(s.duration, MAX);   // (A) 종료 세션 535초 가산
    continue;                             //     → liveCountedFromFetch 안 켜짐!
  }
  // 여기 아래는 duration==null(라이브) 일 때만 실행됨
  if (currentSessionEnteredAt == null) continue;
  if (!currentSessionId || s.sessionId === currentSessionId) {
    liveCountedFromFetch = true;          // dedup 플래그는 '라이브 세션'에서만 켜진다
  }
  total += elapsed(s.enteredAt);
}

if (currentSessionEnteredAt && !liveCountedFromFetch) {
  total += elapsed(currentSessionEnteredAt);  // (B) lessonStartedAt 548초 또 가산
}                                             // (A)+(B) = 1083초 = 18:03

왜 막히지 못했나 (두 가지 구멍)

  1. dedup이 duration == null(라이브) 케이스만 처리한다. 23:52 끊김 무렵 서버 backstop(endPendingSessions)이 라이브 세션을 duration이 채워진 종료 세션으로 확정하면, fetch 결과는 (A) 경로를 타고 liveCountedFromFetch켜지 않는다. 그래서 (B)가 같은 구간을 다시 더한다.
  2. 호출부에서 currentSessionId를 안 넘긴다. monitor-dashboard/[group]/[roomId]/page.tsx:337–343currentSessionEnteredAt만 전달하고 currentSessionId는 생략 → 기본값 null. 따라서 sessionId 기반 중복 방지(s.sessionId === currentSessionId)는 사실상 죽은 코드.
추가로 lessonStartedAtguestInfo===null / isUnmuted===false 일 때만 리셋되는 클라이언트 로컬 앵커라 (page.tsx:329–358), 모니터 재접속 중에도 원래 시작점(14:46)을 유지한 채 계속 카운트한다. DB가 그 구간을 duration으로 확정한 사실과 동기화되지 않아 겹침이 발생한다.

5. 이미 알려진 회귀 영역

이 영역은 Jacob 인수인계에서 회귀 다발 지점으로 명시돼 있다.

기존 문서가 다룬 건 주로 "라이브 vs 폴백" 이중이고, 이번 케이스는 "종료세션(duration!=null) + 라이브" 이중이라는 변종이다 — 문서에 이 변종은 아직 없음.

6. 적용된 해결 (PR #703)

✅ 해결됨 — PR #703 · apps/web/hooks/use-cumulative-elapsed.ts 한 파일. "진행 중 세션 식별 → 종료 세션 duration 클램프"로 이중 가산을 없애고, 코드리뷰에서 추가로 발견한 누락 회귀까지 보강했다.

1차 — 이중 가산 제거 (commit id-047)

2차 — duration 누락 보강 (commit id-012, 코드리뷰 반영)

1차 초안은 "[anchor, now]와 겹치는 종료 세션의 duration 을 통째로 skip"했는데, 이건 anchor ≈ enteredAt 일 때만 안전하다. 앵커가 세션 시작보다 늦게 찍히면(앵커 리셋 후 늦은 재설정 등) [enteredAt, anchor] 구간이 통째로 누락된다.

예: 600초짜리 종료 세션, 앵커가 종료 1초 전에 찍히면 → 600초 중 대부분이 사라지고 [anchor, now](몇 초)만 남음 (시뮬 결과 6초, 정답 ~605초).

그래서 종료 세션 전체를 버리지 않고 anchor 이전 부분만 더하도록 구간을 클램프한다. anchor 이후는 (B)가 커버하므로 중복도 누락도 없다. 정확 연산이라 기존의 허용오차 상수(CURRENT_SESSION_MATCH_TOLERANCE_MS)는 제거했다.

// 진행 중 세션 = 라이브 레코드 존재 여부로 판정 (기존 정상 동작 보존)
const hasLiveCurrentRecord =
  anchor != null &&
  sessions.some(s => s.duration == null &&
    (currentSessionId == null || s.sessionId === currentSessionId));

for (const s of sessions) {
  if (s.duration != null) {
    // 라이브 레코드 없음 + 앵커 존재: [anchor, now]는 (B)가 더하므로
    // 이 종료 세션은 anchor 이전 부분만 더한다 (겹침 제거 + 누락 방지)
    if (!hasLiveCurrentRecord && anchor != null) {
      const endMs = s.enteredAt + s.duration * 1000;
      total += cap(Math.floor((Math.min(endMs, anchor) - s.enteredAt) / 1000));
      continue;
    }
    total += Math.min(s.duration, MAX);   // 과거(앵커 이전 종료) 세션: 전체 가산
    continue;
  }
  if (anchor == null) continue;
  total += cap(elapsed(s.enteredAt));      // 라이브 레코드
}

if (anchor != null && !hasLiveCurrentRecord) {
  total += cap(elapsed(anchor));           // (B) [anchor, now] 를 한 번만
}

제안 2(currentSessionId 전달)는 왜 그대로 안 갔나

모니터(진행자)는 서버 sessionId를 보유하지 않는다(guestInfopeerId/joinedAt만, lessonStartedAt은 로컬 앵커). 그래서 모니터 호출부는 ID를 넘길 수 없고, 위 구간 기반 로직으로 해결했다. 게스트 호출부는 이미 currentSessionId를 넘기므로 ID 정확 매칭도 함께 동작한다. 더 정밀하게 가려면 서버가 guest-session-state에 현재 sessionId를 실어 모니터에 내려주는 후속(소켓 핸들러 변경)이 정공법.

검증: 단일 세션 버그(548초), 다중 세션(180초), 늦은 앵커(605초), straddle(500초) 등 13개 케이스 로직 시뮬 통과 · tsc --noEmit 클린.

관련 문서

분석 작성: 2026-06-10 / chulsu · 해결: PR #703 (commit id-047 → id-012) · LogRocket 019eab05…3750f7