MediaMTX 훅의 stdout·stderr를 서버 로거로 보내는 로컬 구현을 시험했습니다. 훅 하나가 50,000줄을 출력할 때 파일 로그 유실률 중앙값은 0%였습니다. 하지만 같은 양을 출력하는 훅 16개가 함께 끝나는 조건에서는 32.220%가 빠졌고, 마지막 훅의 exit→로그 지연 중앙값은 2,832ms였습니다. 오류를 더 잘 보려고 모은 출력이 종료 경로에 어떤 부담을 주는지도 확인해야 했습니다.
저는 일부 시험을 생략하고 한계만 적는 대신 전체 시험을 진행하도록 했고, 동시 훅을 왜 8개로 정했는가도 다시 확인했습니다. 훅 종류별 배선과 한꺼번에 끝나는 명령의 수는 다른 질문이어서, 13종의 연결 검사와 동시성 1·4·8·16 실험을 나눴습니다. 구현·실측·리뷰는 AI와 협업했고, 제가 확정한 부분은 이 검증 범위와 결과 해석입니다. 아래는 상류에 제출·병합된 기능이 아닌 당시 로컬 구현의 기록입니다.
출력의 목적지를 바꾸면 완료 조건도 달라진다
로컬 옵션 logHookOutput은 기본을 꺼진 상태로 두고, 켜면 훅의 stdout·stderr를 부모 로거에 전달하는 방식이었습니다. 긴 줄을 제한된 크기로 나누고, UTF-8 문자가 바이트 중간에서 잘리지 않도록 불완전한 꼬리를 다음 조각으로 넘겼습니다. 개행 없는 마지막 줄과 실행 파일 자체를 시작하지 못한 오류도 별도로 다뤘습니다.
문제는 읽은 바이트를 어디까지 전달해야 “명령이 끝났다”고 볼 것인가입니다. 로그 목적지가 느리면 출력 복사가 끝나지 않고, cmd.Wait()와 명령 풀 종료에 대기가 전해질 수 있습니다. 일정 시간 뒤 출력을 포기하면 종료는 빨라질 수 있지만 줄이 사라집니다. 모두 보존하려 기다리면 느린 목적지나 종료하지 않는 훅의 시간을 함께 떠안습니다.
Go의 os/exec 문서에 있는 WaitDelay도 모든 외부 로거 호출의 완료 시간을 보장하는 일반적인 타임아웃으로 읽어서는 안 됩니다. 이 로컬 구현에서 설정한 1초 제한은 느린 로거 호출 전체의 대기 상한이 아니었습니다. 코드 흐름상 받는 쪽이 멈추면 풀 종료도 길어질 수 있다는 한계를 남겼습니다.
13종 훅과 동시 훅 16개는 다른 축이다
MediaMTX의 훅 종류별로 출력이 로거에 배선되는지 확인하는 것과, 여러 명령이 한꺼번에 끝날 때 출력이 밀리는지 확인하는 것은 별개의 질문입니다. 그래서 13종의 호출부 연결 검사와 1·4·8·16 동시성 실험을 나눴습니다. “훅이 8종쯤 있으니 8개를 실행한다”는 식의 숫자는 부하 조건의 근거가 될 수 없었습니다.
2026년 9월 8일 대량 출력 시험에서는 훅 하나가 50,000줄을 출력하게 하고, 동시성마다 10회씩 실행했습니다. 총 40회 실행입니다. 훅별 기록은 290행이지만, 같은 실행 안의 여러 훅을 290번의 독립 실험으로 세지 않았습니다.
회차마다 전체 기대 출력과 실제 파일 로그를 대조해 유실률을 구한 뒤, 같은 동시성의 10회 중앙값을 비교했습니다. 파일·syslog의 결과를 합쳐 같은 줄을 두 번 세지 않았습니다. 아래 표는 CSV의 파일 로그 계수를 사용한 값입니다.
| 동시 훅 수 | 파일 로그 유실률 중앙값 | 회차에서 가장 늦은 훅의 exit→로그 지연 중앙값 |
|---|---|---|
| 1 | 0% | 315ms |
| 4 | 1.864% | 1,296ms |
| 8 | 29.252% | 1,371ms |
| 16 | 32.220% | 2,832ms |
16개 조건에서는 한 훅에서 최대 23,877줄이 빠졌습니다. 특히 동시 4개에서 8개로 바꾸자 유실률 중앙값이 1.864%에서 29.252%로 커졌습니다. 단일 훅의 0%만 확인하고 종료 시 보존을 보장할 수 없는 이유가 드러났습니다. 이 값은 당시 file+syslog를 사용한 스파이크 형상과 입력의 결과이며, 현재 버전의 운영 장애율은 아닙니다.
평균 대신 마지막 훅의 꼬리를 봤다
출력 수집은 대부분의 훅이 빨리 끝나도 마지막 훅 때문에 종료가 늦어질 수 있습니다. 그래서 각 회차에서 가장 늦게 기록된 훅의 exit→로그 지연을 골랐고, 그 최댓값들의 중앙값을 비교했습니다. 모든 훅의 평균 지연과 다른 지표입니다.
측정 대상은 서버 요청 전체의 지연이 아니라 훅 종료 뒤 로그 처리의 꼬리입니다. 16개 조건에서는 유실률이 높으면서 마지막 기록까지의 대기도 길었습니다. 출력 보존율만 보거나 종료 시간만 보면 한쪽 비용을 놓칩니다. 같은 회차 단위로 두 값을 함께 읽어야, 빨리 끝내기 위해 줄을 버린 것인지 남은 출력을 기다리는 것인지 확인할 수 있습니다.
후속 리로드 시험은 다른 질문이었다
2026년 9월 23일에는 당시 로거 수명 수정인 가드 v2 위에서 출력 라우팅을 다시 검증했습니다. 로거 설정이 바뀌면 훅과 출력 복사가 끝날 때까지 기다린 뒤 로거를 교체하는 형태였습니다. 이전 문서의 “로거가 비어 있는 동안 출력 폐기” 설명을 “완료까지 대기”로 고쳤습니다. 구현의 전제가 달라졌다면 설명도 바뀌어야 했습니다.
이번 질문은 느린 목적지에서 대량 출력이 얼마나 유실되는지가 아니라, 로거 재설정 시점에 준비한 줄이 사라지는지였습니다. 코드 204195ad의 같은 비-race 바이너리에서 옵션 한 줄만 바꾸고, 로컬 파일 목적지와 SIGINT에 바로 종료하는 훅을 사용했습니다. 재설정 전 훅이 출력한 1,000줄을 PID별로 세어 새로 시작한 훅의 출력을 중복 집계하지 않았습니다.
| 가드 v2 재설정 시험 | OFF 10회 | ON 10회 |
|---|---|---|
| 합계 10,000줄의 목적지 | 상속 stdout 전량 | 파일 로그 전량 |
| ON의 stdout 누출·유실 | 해당 없음 | 0줄·0줄 |
| 리스너 부재 중앙값 | 0.610ms | 0.598ms |
표의 반올림값 차이는 0.012ms로 표본 산포 안에 있었습니다. 이 차이에서 속도 개선은 확인할 수 없지만, ON 조건의 10,000줄이 파일에 남고 stdout 누출과 유실이 각각 0줄이라는 보존 결과는 확인했습니다. 앞선 시험은 대량 출력이 겹칠 때의 부하였고, 이번 시험은 로컬 파일 목적지와 즉시 종료하는 훅으로 reload 경계를 통제했습니다. 32.220%→0% 개선으로 이어 붙일 수 없는 서로 다른 실험입니다.
상류에 연결하기 전에 다시 검증할 것
가드 v2의 선행 제안이었던 #6206은 이후 병합 없이 닫혔고, 유지보수자가 #6326으로 대체했습니다. 따라서 과거 가드 위의 보존 결과가 현재 상류와의 호환성이나 운영 동작을 보장하지 않습니다. 느린 목적지와 reload가 겹치는 경우, 훅이 종료하지 않는 경우도 별도 검증이 필요합니다.
단일 훅의 0% 유실과 후속 시험의 1만 줄 보존만으로는 종료 시 무손실을 보장할 수 없었습니다. 동시 종료를 늘린 실험에서는 유실과 지연이 함께 커졌고, 가드 v2에서는 출력 복사의 완료를 기다리는 쪽으로 동작이 바뀌었습니다. 그래서 저는 검증 조건을 분리하고, “재설정 중 출력을 버린다”던 설명도 “완료를 기다린다”로 고쳤습니다.
상류의 새 로거 수명 구조에 연결하려면 느린 목적지와 reload가 겹치는 경우, 끝나지 않는 훅의 대기를 다시 확인해야 합니다. 로그를 얼마나 모았는지와 그 로그를 기다리느라 어디가 멈추는지를 함께 재는 것이 이 기능을 다음 단계로 가져갈 조건입니다.
이 글은 PokeClip·MediaMTX 기술 기록 모음의 일부입니다. 포트폴리오 전체본 42쪽에서 연결된 사례도 함께 볼 수 있습니다.