BUG · 원인 확정 · 수정 미적용

예비 활동 19분 스킵 오작동 — 누적 시간 4분 누락 원인 분석 및 해결

마지막 업데이트 2026-08-03

작성 2026-08-03 사례 이소헌 4회기 · 2026-07-27 영역 예비 콘텐츠 자동 건너뛰기 · 누적 경과시간

한 줄 결론

레슨 세션 레코드(LessonSession)가 "수업 시작"이 아니라 "첫 AI 대화 스텝이 붙는 순간"에 생성된다. 오프닝이 영상 스텝으로 구성된 회기는 그 길이만큼(사례에서 3분 59초) 누적 경과시간이 통째로 사라지고, 그 결과 19분을 넘긴 수업이 예비 활동 2개를 건너뛰지 않고 그대로 재생했다.

예비 콘텐츠 자동 건너뛰기(PPI-580 65e5ae49)의 의도는 "누적 19분 이상이면 예비 그룹을 통째로 skip" 이다. 판정 자체는 정상 동작했고, 판정에 들어간 누적 시간이 틀렸다. 같은 계열 결함이 PPI-714(3834ce77), PPI-850(c7bca5db, 한 번 revert 후 재랜딩)에서 이미 두 차례 수정된 자리다.

"예비 하나 더 나온 것" 으로 축소하면 안 되는 이유

같은 누적값이 DB sessionSummary.totalDuration(수업 시간 집계)과 입장 제어의 누적 1시간 한도에도 쓰인다. 사례의 DB duration은 21분 54초로 기록됐지만 실제 수업은 25분 53초였다.

인과 체인

아동 "시작" 버튼 → 수업 첫 스텝 재생 (오프닝 = 영상 3스텝) ↓ 이 시점엔 AI 세션이 없으므로 createSession 이 호출되지 않는다 /sessions 조회 → count 0 → 프론트 fallbackStartTimeRef 로만 카운트 (DB 기록 없음) ↓ 4분 경과 (오프닝 영상 3개) 첫 AI 대화 스텝 진입 → aiSession.isActive = true ↓ guest-layout useEffect([session.isActive]) → createSession() ↓ 서버가 enteredAt = now 로 레코드 생성 (수업 시작보다 4분 늦음) /sessions 재조회 → count 1 → fallback 폐기, 누적 기준이 enteredAt 으로 리베이스 ↓ 단조 클램프(finalize)가 값 하락만 막아 4분간 239s 에서 정지 이후 누적은 정상 증가하지만 항상 실제보다 4분 적다 ↓ 예비 그룹 진입 판정 cumulativeElapsedSeconds < 1140 이 잘못 통과 ↓ 19분 넘은 수업에서 예비 활동 2개가 그대로 재생 (+ DB duration 4분 과소 기록)

실사례 타임라인 — 이소헌 4회기 / 진행자 노아 (2026-07-27)

룸 a7f84096-25c5-47f3-abdc-d4ae8337ce6c_45 · 활동 8개 (0 오프닝 / 1 지용대화 / 2 서아대화 / 3 하랑대화1 / 4 하랑대화2 / 5 예비 하랑대화3 / 6 예비 하랑대화4 / 7 체크아웃)

17:28:49 아동 페이지 로드 (LogRocket 세션 시작)

17:30:04 수업 시작 — Loki Guest step update {activityIndex:0, stepIndex:0}

17:30:07 USE_CUMULATIVE_ELAPSED Sessions loaded {count: 0} → fallback 앵커 설정

17:31:36 / 17:32:53 / 17:33:29 오프닝 영상 3스텝 자동 전환 (누적 89 → 165 → 202s, 정상 증가)

17:34:03 레슨 세션 레코드 최초 생성 45#1785141243445 (enteredAt 17:34:03) — 첫 AI 대화 스텝 진입 직후

17:34:07 Sessions loaded {count: 1} → 누적 기준 리베이스, 239s 에서 정지

17:37:27 스텝 전환 로그의 누적 여전히 239 (3분 21초째 동결)

17:38:21 누적 258s — 새 앵커 기준값이 클램프를 추월, 이후 정상 증가 (단, 항상 −239s)

17:50:02 예비 하랑대화3 진입 — reason: new-group-under-threshold, 누적 958s (실제 1198s)

17:52:26 예비 하랑대화4 진입 — 누적 1102s (실제 1342s)

17:53:14 체크아웃 진입 (non-spare-direct)

17:55:57 INTERNAL_END_PENDING_SESSIONS_API closedSessionIds: ["45#1785141243445"] — duration 21분 54초 기록

판정 대조 — 누적값이 맞았다면 두 건 모두 skip

시각	진입 활동	판정 누적	실제 경과	임계 1140s	실제 동작 / 기대
17:50:02	예비) 하랑대화3	958s	1198s (19분 58초)	초과	진입 / skip
17:52:26	예비) 하랑대화4	1102s	1342s (22분 22초)	초과	진입 / skip

누적 손실량은 상수 239s

수업 시작(17:30:04)과 세션 레코드 enteredAt(17:34:03)의 차이 그대로다. 두 판정 모두 이 239s만 복구되면 임계를 넘긴다 — 다른 계산 오류는 없었다.

코드 레벨 원인

1. 세션 레코드 생성 트리거가 "AI 세션 활성"

apps/web/widgets/guest/guest-layout/ui/guest-layout.tsx:169

useEffect(() => {
  if (session.isActive && !session.isLoading) {   // isActive = aiSession.isActive
    createSession().then(() => session.refetchCumulativeElapsed());
  }
}, [session.isActive, session.isLoading, createSession, session.refetchCumulativeElapsed]);

session.isActive는 use-guest-page-session.ts:2798에서 aiSession.isActive를 그대로 노출한 값 — OpenAI/TTS 대화 세션의 활성 여부이지 수업 시작 여부가 아니다.
오프닝이 영상(full:video)으로만 구성된 회기는 그 구간 내내 AI 세션이 없다 → 레코드가 생기지 않는다.
서버 lesson-session.service.ts:31의 enteredAt은 요청 도착 시각(Date.now())이라, 늦게 부르면 늦은 시각이 그대로 정본이 된다.

2. 레코드가 도착하면 fallback 경과분이 버려진다

apps/web/hooks/use-cumulative-elapsed.ts:129-136

// sessions 가 비어 있을 때만 fallback 을 쓴다 → count 1 이 되는 순간 이 경로는 죽는다
if (!disableFallbackStart && sessions.length === 0 && anchor == null && fallbackStartTimeRef.current) {
  return finalize(Math.floor((now - fallbackStartTimeRef.current) / 1000));
}

fallbackStartTimeRef에 담긴 "레코드 이전 구간"을 이후 계산에 넘겨주는 경로가 없다. 남는 것은 finalize()의 단조 클램프뿐이라, 값이 줄지는 않지만(239s 유지) 늘지도 않는 동결 구간이 생긴 뒤 새 앵커 기준값이 이를 추월하면서 그 차이만큼 영구 손실된다.

3. 판정부는 정상

apps/web/lib/spare-content-utils.ts:135의 임계 비교, 그룹 판정, skip 루프는 로그상 모두 설계대로 동작했다. findNextStepSkippingSpare:iteration이 cumulativeElapsedSeconds: 1102를 받아 1140과 비교한 것이 전부다.

부수 발견

예비 그룹 판정이 운영 타이틀 포맷에서 사실상 무의미하다. getActivityBaseName()은 _로 자른 3번째 토큰을 base name으로 쓰는데 (주석 예시는 예비 기초_공통_밸런스게임+_3_1_지우 → 밸런스게임+), 실제 운영 타이틀은 예비)두부핑퐁_4회기_하랑대화3 → 하랑대화3, …하랑대화4 → 하랑대화4로 예비마다 base name이 달라 항상 "새 그룹"이 된다. 이번 사례에선 매번 19분 판정을 타서 오히려 다행이었지만, "같은 콘텐츠 묶음은 끊지 않는다"는 그룹 개념은 이 명명 규칙에서 동작하지 않는다.
수업 시간 집계도 같이 틀린다. 사례의 DB duration 1314s(21분 54초) vs 실제 1553s(25분 53초). 입장 제어의 누적 1시간 한도, 통계, 진행자 화면 타이머가 모두 이 값을 공유한다.
영상으로 시작하는 모든 회기에 상시 발생한다. 특정 기기·네트워크 조건이 아니라 커리큘럼 구성에만 의존한다.

판별법

1. Grafana Loki — 수업 시작과 레코드 생성의 간격

# 첫 스텝 시각
{instance=~".+"} |= "<roomId>" |= "Guest step update"
→ 17:30:04  {"activityIndex":0,"stepIndex":0,...}

# 세션 레코드 생성/종료 (sessionId 의 뒤 숫자가 enteredAt epoch ms)
{instance=~".+"} |= "<userId>" |~ "LESSON_SESSION|lesson session|45#"
→ 17:55:57  Ended pending lesson sessions  closedSessionIds:["45#1785141243445"]
   1785141243445 = 17:34:03  ← 첫 스텝보다 3분 59초 늦음 = 손실량

2. LogRocket (아동 세션) — 누적 동결 구간

[USE_CUMULATIVE_ELAPSED] Sessions loaded {count: 0} → 이후 {count: 1}로 바뀌는 시각을 찾는다
[LessonSession] Creating session / Session created가 수업 시작보다 늦으면 확정
[SPARE_CONTENT_UTILS] findNextStepSkippingSpare:iteration의 cumulativeElapsedSeconds가 연속 두 스텝에서 같은 값으로 멈춰 있으면 동결 구간
예비 진입 판정은 :return의 reason으로 구분 — new-group-under-threshold(19분 판정 통과) / same-group-continue(판정 없이 진입, 정상)

해결 방법

1차 (근본) — 세션 레코드 생성을 "시작" 시점으로 옮긴다

아동이 시작 버튼을 누르면 guest-layout-content.tsx:171 → session.confirmReady()가 호출된다. 이 시점이 수업 시작의 정본이며, 모니터 대시보드도 같은 신호(guest-video-unmuted)를 타이머 앵커로 쓴다.

// apps/web/entities/guest-page-session/model/use-guest-page-session.ts
+ const [hasConfirmedReady, setHasConfirmedReady] = useState(false);

  const confirmReady = useCallback(() => {
    logger.info("User confirmed ready, starting session");
    guestSocket.confirmReady();
    ...
    socket.emit("guest-video-unmuted", { roomId, isUnmuted: true });
+   setHasConfirmedReady(true);
  }, [...]);

  return { ..., hasConfirmedReady };

// apps/web/widgets/guest/guest-layout/ui/guest-layout.tsx:169
  useEffect(() => {
-   if (session.isActive && !session.isLoading) {
+   if (session.hasConfirmedReady && !session.isLoading) {
      createSession().then(() => session.refetchCumulativeElapsed());
    }
-  }, [session.isActive, ...]);
+  }, [session.hasConfirmedReady, ...]);

재접속 시 confirmReady가 다시 불리지만 createSession의 중복 가드(isEnteredRef/sessionIdRef, use-lesson-session.ts:61)가 그대로 막는다 — 사례 로그의 Session already created, skipping이 그 경로다.
서버 enteredAt이 실제 시작 시각이 되므로 DB totalDuration과 입장 제어 한도까지 함께 교정된다. 이것이 클라이언트만 고치는 2차안과의 결정적 차이다.
createSession은 endPendingSessions auto-close를 먼저 수행하므로, 호출 시점이 빨라져도 이전 회차 정리 순서는 그대로다.

2차 (방어) — 레코드가 늦게 와도 fallback 구간을 잃지 않는다

1차를 적용해도 레코드 생성 실패·응답 지연이면 같은 손실이 재발한다. 누적 계산에 offset을 남긴다.

// apps/web/hooks/use-cumulative-elapsed.ts — getCumulativeElapsedSeconds 내부
+ // 세션 레코드 생성 이전에 이미 진행된 구간(fallback 앵커 ~ 최초 enteredAt)을 보존한다.
+ // 재접속 케이스에서는 최초 enteredAt 이 fallback 보다 과거라 조건이 성립하지 않아 이중 가산되지 않는다.
+ const preRecordOffset = () => {
+   const fb = fallbackStartTimeRef.current;
+   if (!fb || sessions.length === 0) return 0;
+   const earliest = Math.min(...sessions.map((s) => s.enteredAt));
+   return earliest > fb ? Math.floor((earliest - fb) / 1000) : 0;
+ };

  return finalize(total + preRecordOffset());

2차만 적용하면 안 되는 이유

클라이언트 판정은 맞아지지만 서버 enteredAt은 여전히 늦어, DB 수업 시간과 입장 한도는 계속 4분 짧게 기록된다. 1차가 본체이고 2차는 보험이다.

검증

오프닝이 영상으로 시작하는 회기로 게스트 입장 → 시작 버튼 직후 LogRocket/콘솔에 [LessonSession] Session created가 영상 재생 전에 찍히는지
Loki에서 Guest step update {activityIndex:0} 시각과 sessionId의 epoch가 수 초 이내인지
findNextStepSkippingSpare:iteration의 cumulativeElapsedSeconds가 수업 경과 시간과 어긋나지 않는지 (동결 구간 없음)
19분 경계 검증은 /api/lessons/<userId>/<index>/sessions/inject(테스트 모드 분 주입, PPI-580에서 추가)로 경과를 밀어 넣어 예비 skip 여부를 확인
수업 종료 후 sessionSummary.totalDuration이 실제 수업 길이와 일치하는지

현황

원인 확정까지 완료. 코드 수정은 아직 적용하지 않았다 — 위 1차/2차는 제안 diff다.

교훈 · 재발 방지

"수업 시작"의 정본을 하나로 정한다. 지금은 아동 confirmReady, 모니터 lessonStartedAt, 서버 enteredAt, 프론트 fallbackStartTimeRef 네 개가 각자 다른 시각을 가리킨다. 누적 시간 버그가 PPI-580 이후 세 번 반복된 이유가 이 다중 정본이다.
단조 클램프는 손실을 숨긴다. finalize()는 값 하락을 막아 회귀는 없앴지만, 이번처럼 "멈춰 있는" 형태로 손실을 가려 로그를 자세히 보기 전엔 정상처럼 보였다. 클램프가 발동하면 그 자체를 warn으로 남기는 편이 낫다.
시간 임계로 분기하는 기능은 임계 근처 로그를 남긴다. 이번 진단이 빨랐던 것은 SPARE_CONTENT_UTILS가 판정 입력값을 전부 찍어둔 덕이다(PPI-850에서 추가).