마지막 업데이트 2026-07-29
End of file)이 발생.
추적 결과 이는 손상된 파일도, 깨진 파이프라인의 결과도 아니다. producer 교체마다 세그먼트가 갈라지며 생기는 빈/짧은 세그먼트가 상시 발생하고,
녹음 종료 시 캡션 빌드가 크기 필터 없이 전 세그먼트를 probe하기 때문에 찍히는 WARN 노이즈다. 최종 녹음물·캡션 결과에는 영향이 없다.
reserveLocalUdpPort)은
빈 세그먼트의 ~8%만 설명하는 별개의 소수 이슈로 §6에 분리 정리.
| 관측 환경 | Grafana ppi-logs · Loki 직접 집계 · service=ppi-socket, env=prod |
| 관측 기준 | now−24h (2026-06-09 20:05 ~ 06-10 20:05 KST) |
| 증상 | ffprobe duration measurement failed ... : End of file WARN 대량(≈1,200/24h) |
| 실제 원인 | ① 세그먼트 로테이션이 빈/짧은 세그먼트를 상시 생성 + ② 캡션 probe 경로(oggSegments)에 size>0 필터 부재 |
| 데이터 영향 | 🟢 없음 — 오디오 합치기 경로는 빈 파일을 이미 제외. WARN은 노이즈 |
| 별개 이슈 | 🟠 reserveLocalUdpPort 포트 충돌(=ffmpeg 비정상 종료 7건/일) — §6 |
| 관련 코드 | apps/socket/src/recording/{recordingManager,ffprobe,udpPort}.ts |
RecordingManager는 producer가 교체될 때마다 세그먼트를 끊는다(dual-spawn). 교체가 잦거나 연달아 일어나면
방금 연 세그먼트가 오디오를 거의 못 받고 닫혀 빈 OGG가 된다(방당 ~20개). 녹음 종료 시 캡션 빌드는
oggSegments를 크기 검사 없이 전부 probe한다 — 오디오 경로엔 있는
size>0 필터가 캡션 경로엔 없다. 그래서 빈 파일마다 End of file WARN이 찍힌다.
녹음·캡션 결과물은 정상이고, 이건 데이터 손실이 아니라 로그 노이즈다.
발단은 Grafana였다. ppi-socket 운영 서버의 하루치 로그를 열어보니 WARN의 거의 절반이 같은 문장 — ffprobe duration measurement failed ... End of file — 이었다. 매일 1,200건씩 찍히는 경보라면 진짜 화재인지 오작동 사이렌인지부터 가려야 했다. 규모 집계부터 시작했다.
| 메시지 | 건수 | level | 분류 |
|---|---|---|---|
ffprobe duration measurement failed | 1,224 (warn의 45%) | warn | 본 문서 주제 — 노이즈 |
└ 그중 End of file | 1,051 (86%) | warn | 빈 파일 |
| Failed to stop recording | 29 | error | 드문 최악 케이스 |
| No valid recording segments | 27 | error | 한 세션 전 세그먼트가 무효 |
| Active ffmpeg exited abnormally | 24 | error | 별개: 포트 충돌(§6) |
| Failed to resume consumer | 28 | error | 별개: SFU 미디어 계층 |
| Failed to consume | 12 | error | 별개: SFU 미디어 계층 |
cf. 초기 AI 스냅샷(WARN 1,738 / ffprobe 896)과 시점 차이로 절대값은 다르나 "ffprobe가 WARN 최다·대부분 End of file" 구조는 동일. 단 AI가 "No valid segments 1건"이라 한 것은 실제 27건으로 과소집계였음.
1,224건이라는 규모가 확인됐다. 다음 질문은 "이 파일들은 어떤 상태인가"였다. 손상된 파일을 probe하다 실패하는 것이라면 파이프라인 어딘가가 데이터를 깨뜨리고 있다는 뜻이 된다. 에러 메시지별로 부검해 봤다.
ffprobe 실패 1,224건을 에러 종류로 분류하면, 구조가 깨진(손상된) 파일을 가리키는 Invalid data found는 0건이다.
| 에러 메시지 | 건수 | 비율 | 실제 파일 상태 |
|---|---|---|---|
End of file | 1,051 | 86% | 빈 파일 (0바이트 / OGG 페이지 없음) |
No such file or directory | ~116 | ~9% | probe 시점에 파일 미존재 |
invalid duration (N/A) | 57 | ~5% | 스트림/길이 없음 = 사실상 빈 파일 |
Invalid data found (= 진짜 손상) | 0 | 0% | 없음 |
Invalid data found를 낸다. 한 건도 없다. 즉 "손상된 OGG를 probe하다 실패"가 아니라 "비었거나 존재하지 않는 세그먼트를 probe"가 정확한 표현이다.
파일이 "비어 있다"면 누가 비웠는가. 본 문서 초판이 지목한 용의자는 ffmpeg 포트 충돌 크래시였다 — 크래시가 세그먼트를 빈 채로 남긴다는 그럴듯한 체인. 하지만 체포 전에 알리바이를 확인해야 했다. 실패 건수의 분포를 방(room) 단위로 대조했다.
| 항목 | 값 |
|---|---|
| ffprobe 실패가 발생한 고유 방 수 | 50개에 분산 |
| ffmpeg 비정상 종료(포트 충돌) 방에 속한 실패 | ~8%뿐 |
| ffprobe 실패 최다 Top 10 방 | 전부 크래시·bind 실패 0건 (방당 19~25건) |
수십 건(consumer 실패 28+12, ffmpeg 크래시 24)의 사고가 1,200건의 빈 세그먼트를 만들 수 없다. 빈 세그먼트는 거의 모든 수업에서 방당 ~20개씩 고르게 나오는 상시 현상이다.
사고범 가설은 무너졌다. 방당 ~20개씩, 거의 모든 수업에서 고르게 나오는 상시 현상이라면 범인은 예외 상황이 아니라 정상 동작 경로 안에 있다. 수사망을 로그에서 코드로 옮겼다 — 빈 세그먼트는 왜 늘 생기고, 왜 하필 probe까지 가는가.
recordingManager.ts — replaceChildConsumer/replaceAiConsumer → transitionFfmpeg
if (session.childPair) {
session.childProducer = childProducer;
if (session.ffmpegProcess) {
await this.transitionFfmpeg(session, router); // ← 매 producer 교체마다 새 세그먼트
}
}
…
private async transitionFfmpeg(session, router) {
…
const segNum = ++this.segmentCounter;
session.recordingPath = join(RECORDING_TMP_DIR, `${roomId}_${startedAt}_seg${segNum}.ogg`); // 새 .ogg
await this.startFfmpeg(session); // 새 ffmpeg + pushOggSegment 등록
}
아동 마이크/핑퐁이(AI) 오디오 트랙이 재발행될 때마다(발화 단위·활동 전환·재접속) producer가 교체되고, 그때마다 세그먼트가 끊긴다. 교체가 연달아 일어나면 방금 연 세그먼트가 오디오를 거의 못 받고 닫혀 빈 OGG가 된다. → 방당 ~20개 누적.
seg1119 같은 높은 번호는 private segmentCounter = 0이 서버 전체 공통 카운터라 그렇다. 한 방에 1119개가 아니라 기동 후 전 세션 누적값이다.
oggSegments — 캡션 타이밍용모든 세그먼트를 무조건 등록, 필터 없음, 정리 안 함. (pushOggSegment @ :554/1057/1225)
segmentPaths — 오디오 합치기용size>0일 때만 push → 빈 파일 제외. (collectSegment @ :1064)
// ② 오디오 경로 — 빈 파일을 제대로 거른다 private async collectSegment(session) { const fileStat = await stat(session.recordingPath); if (fileStat.size > 0) session.segmentPaths.push(session.recordingPath); } // ① 캡션 경로 — 크기 검사 없이 전부 probe (← WARN 노이즈의 출처) private async buildAndUploadCaptions(session, mp3S3Key) { const segments = await Promise.all( session.oggSegments.map(async (seg) => ({ ...seg, audioDurationMs: (await probeAudioDurationMsSafe(seg.filePath)) ?? 0, // 빈/없는 파일도 그대로 probe })), ); }
캡션을 MP3 타임라인에 맞추려 각 세그먼트 duration이 필요해서 oggSegments를 순회하는데, ②에 있는 size>0 가드가 ①엔 없다.
그래서 오디오에선 버려진 빈/없는 파일이 캡션 probe에선 검사되고 → ffprobe duration measurement failed WARN → null(=0ms) 반환.
ffprobe.ts의 probeAudioDurationMsSafe는 실패를 잡아 WARN 로깅 후 null 반환 → 캡션 계산엔 0ms로 무해하게 처리됨.
transitionFfmpeg가 새 seg{N}.ogg + 새 ffmpeg 생성. 교체가 잦음.segmentPaths)는 size>0로 빈 파일 제외 → 녹음 정상
oggSegments)는 필터 없이 전 세그먼트 probe
buildAndUploadCaptions가 빈/없는 파일도 probeAudioDurationMsSafe 호출.End of file WARN → 하루 ~1,200건 노이즈
null(0ms)로 흡수되어 결과엔 무해. 로그만 시끄러움.초판에서 주범으로 몰렸던 포트 충돌은 WARN 노이즈에 대해선 무죄였지만, 조사 과정에서 별건 혐의가 드러났다 — ffprobe 실패의 ~8%가 아니라, ffmpeg 크래시와 간헐적 녹음 손실이라는 그 자체의 죄목이다. 별도 조서로 남긴다.
위 노이즈와 독립적으로, ffmpeg 비정상 종료(Active ffmpeg exited abnormally, 24건/24h) 중 다수는 RTP 수신 UDP 포트 bind 충돌이다.
오늘 7건 분석에서 5건이 bind failed: Address already in use였다.
// udpPort.ts — 포트를 bind해 번호만 읽고 소켓을 닫아버림 (TOCTOU) socket.bind(0, "127.0.0.1", () => { const port = socket.address().port; socket.close(() => resolve(port)); // 닫는 순간부터 포트 free → ffmpeg가 늦게 bind하면 충돌 });
확보(close)와 ffmpeg 실제 bind 사이에 다른 reserve(ai 입력·dual-spawn 새 ffmpeg·다른 방)가 같은 포트를 선점 → code=1 종료 → 그 세그먼트 1개가 빈다.
ffprobe 실패의 ~8%만 설명하므로 WARN 노이즈의 주범은 아니나, 크래시·간헐적 녹음 손실 위험이 있어 별도 처리가 필요하다.
buildAndUploadCaptions의 probe 루프 전에 oggSegments를 size>0/존재 여부로 거르거나, 빈/없는 파일은 0ms로 조용히 스킵(WARN 미발생). 하루 ~1,200건 노이즈 즉시 제거, 결과 동일.reserveLocalUdpPort가 소켓을 닫지 말고 fd를 ffmpeg에 인계하거나, EADDRINUSE 감지 시 새 포트로 세그먼트 재시작. ffmpeg 크래시 24건/일 제거.