검사 라인 불량 판정 사고를 정리한 C++ 인시던트 노트

처음 눈에 들어온 장면

가장 먼저 확인한 것은 실제로 버려진 부품이었습니다. NG 통에서 스무 개를 꺼내 육안으로 보고, 같은 부품을 검사 지그에 다시 올려 재검사했습니다. 스무 개 중 열일곱 개가 두 번째 통과에서 OK로 나왔습니다. 같은 부품, 같은 조명, 같은 모델인데 판정이 달랐습니다. 이 시점에서 "모델이 이 부품을 못 알아본다"는 설명은 이미 힘을 잃었습니다. 모델이 못 알아보는 것이라면 재검사에서도 똑같이 NG가 나와야 했습니다.

두 번째로 본 것은 NG로 저장된 이미지였습니다. 저희 시스템은 판정이 NG일 때 입력 프레임을 함께 남깁니다. 그 이미지들 중 일부는 부품 상단이 이전 부품의 잔상과 겹쳐 보였습니다. 위쪽 3분의 1은 A 부품, 아래쪽은 B 부품처럼 보이는 사진이 섞여 있었습니다. 카메라가 그런 사진을 만들 수는 없습니다. 저장 시점에 버퍼가 이미 다른 프레임으로 덮여 있었다는 뜻이었습니다.

반나절 동안 좁혀 간 기록

무엇을 쟀고 그 숫자가 무슨 뜻이었나

저희가 원래 보던 지표는 "프레임당 평균 처리 시간"이었습니다. 그 값은 사고 중에도 21ms 근처에서 거의 움직이지 않았습니다. 평균이 멀쩡했기 때문에 처음 한 시간 동안 아무도 타이밍을 의심하지 않았습니다. 지표를 분위수로 다시 그리자 이야기가 완전히 달라졌습니다.

구간                       p50      p95      p99      max
acquire -> queue         0.41ms   0.55ms   0.62ms   0.74ms
queue   -> infer_start    1.8ms    3.2ms   17.9ms   41.6ms
infer_start -> infer_end 18.6ms   19.1ms   19.8ms   21.3ms
total                    20.9ms   22.6ms   38.1ms   62.9ms

프레임 드롭: 0 / 시퀀스 결번: 0 / 큐 최대 깊이: 4 (용량 8)

추론 구간은 p50과 max의 차이가 3ms도 되지 않았습니다. GPU가 힘들어하고 있었다면 이 줄이 가장 먼저 무너졌어야 합니다. 무너진 것은 큐 대기 줄이었고, 그것도 평균이 아니라 꼬리만 무너졌습니다. 문제는 지연이 아니라 지터였습니다. 저희가 이후로 자주 쓰는 표현으로 말하면, 시스템은 느려진 게 아니라 가끔 느려졌습니다.

이 숫자가 왜 겹친 이미지로 이어지는지는 링 버퍼의 크기를 계산해 보면 나옵니다. 링 버퍼 슬롯은 여덟 개였고, 라인은 초당 약 45프레임을 밀어 넣고 있었습니다. 한 슬롯이 다시 돌아오기까지 대략 178ms가 걸립니다. 평소 대기 시간 2ms 앞에서는 넉넉한 여유입니다. 그런데 취득 스레드가 순간적으로 몰아치는 구간에서는 같은 슬롯이 20ms 안에 다시 쓰이는 경우가 생겼습니다. 그때 추론 스레드는 아직 그 슬롯을 읽고 있었습니다.

아래는 슬롯 번호를 붙인 뒤에 잡힌 로그입니다. 이 세 줄이 사실상 사건의 전부였습니다.

[08:24:11.402] acq seq=184203 slot=3 enqueue=0.41ms
[08:24:11.404] inf seq=184203 slot=3 start (wait=1.9ms)
[08:24:11.418] acq seq=184211 slot=3 enqueue=0.40ms  ## 같은 슬롯을 다시 씀
[08:24:11.423] inf seq=184203 slot=3 end   verdict=NG score=0.31
[08:24:11.423] inf seq=184203 dump  frames/ng_184203.png

추론은 184203번 프레임을 판정한다고 믿고 있었지만, 마지막 몇 밀리초 동안 실제로 읽은 픽셀은 184211번이었습니다. 저장된 NG 이미지가 두 부품의 합성처럼 보였던 이유도 여기 있었습니다. 판정 점수 0.31은 모델이 틀린 결과가 아니라, 존재하지 않는 부품에 대한 정직한 대답이었습니다.

틀린 가설: GPU 스로틀링을 반나절 붙잡고 있었습니다

솔직히 적자면, 저희는 오전 내내 다른 곳을 파고 있었습니다. 가장 유력했던 가설은 "추론 장비가 스로틀링에 걸려 판정 품질이 떨어졌다"였습니다. 근거도 있었습니다. 사고가 시작된 시각은 공장 냉방 스케줄이 바뀌는 시간대와 겹쳤고, 장비 온도 로그는 평소보다 8도 높았습니다. 스로틀링이 걸리면 처리 시간이 늘고, 시간이 부족해진 파이프라인이 프레임을 대충 처리하다가 오판정이 늘어난다는 그림이 머릿속에 아주 자연스럽게 그려졌습니다.

이 가설을 죽인 것은 논쟁이 아니라 한 번의 재생 실험이었습니다. 저희는 사고 구간 30분치의 원본 프레임을 디스크에 통째로 덤프해 두고 있었습니다. 그 프레임들을 라인과 무관한 오프라인 장비에서, 카메라도 큐도 없이 단일 스레드로 순서대로 넣어 돌렸습니다. 같은 모델, 같은 전처리, 같은 임계값이었습니다.

$ ./replay --frames dump/0820-0850 --model insp_v7.onnx --threads 1
frames        : 81,204
NG            : 902  (1.11%)
라인 당시 NG  : 4,876 (6.00%)
라벨 불일치   : 0
평균 추론시간 : 18.7ms   (라인 측정치 18.6ms)

결과는 명확했습니다. 같은 프레임을 다시 넣으니 NG 비율이 평소 수준으로 돌아왔고, 라인에서 나온 라벨과 오프라인 라벨이 어긋난 프레임은 한 장도 없었습니다. 모델은 같은 입력에 대해 언제나 같은 답을 냈습니다. 추론 시간도 라인과 사실상 동일했습니다. 스로틀링이 원인이라면 오프라인에서는 더 빨라져야 하는데, 차이가 0.1ms였습니다.

이 실험이 준 것은 "GPU가 범인이 아니다"라는 결론만이 아니었습니다. 더 중요한 것은 입력이 같으면 결과가 같다는 사실이 확인됐다는 점입니다. 그렇다면 라인에서 결과가 달랐던 이유는 하나뿐입니다. 라인에서는 입력이 저희가 생각한 그 입력이 아니었던 겁니다. 이 한 문장이 조사 방향을 모델에서 버퍼로 완전히 돌려놓았습니다. 온도 로그는 그냥 여름이었습니다.

돌아보면 저 반나절을 줄일 수 있었던 신호는 처음부터 있었습니다. 재검사에서 열일곱 개가 OK로 나왔다는 사실이 그것입니다. 결정론적인 함수가 같은 입력에 다른 답을 낸다면 의심해야 할 것은 함수가 아니라 입력입니다. 저희는 그 신호를 보고도 익숙한 가설을 먼저 붙잡았습니다.

실제로 바꾼 코드

원래 코드는 취득 스레드가 링 버퍼 슬롯의 포인터와 인덱스를 큐에 넣고, 추론 스레드가 그 인덱스로 다시 접근하는 구조였습니다. 슬롯을 언제 회수해도 되는지 아무도 모르는 구조였고, 정상 부하에서는 시간 여유가 그 결함을 가려 주고 있었습니다.

// [기존] 슬롯 인덱스만 넘긴다. 회수 시점에 대한 약속이 없다.
void AcquisitionThread::onFrame(int slot) {
  ring_[slot].stamp = Clock::now();
  queue_.push(FrameRef{ ring_[slot].data, slot, seq_++ });  // 참조만 전달
}

// [변경] 읽는 쪽이 살아 있는 동안 슬롯을 회수하지 않는다.
using FramePtr = std::shared_ptr<const Frame>;

FramePtr FramePool::acquire() {
  std::unique_lock<std::mutex> lk(mu_);
  if (free_.empty()) {
    ++stats_.starved;            // 재사용 대신 굶주림을 카운트한다
    return nullptr;              // 호출자가 드롭 여부를 결정한다
  }
  Frame* raw = free_.back();
  free_.pop_back();
  // 삭제자가 마지막 참조 해제 시점에 슬롯을 풀로 돌려준다.
  return FramePtr(raw, [this](const Frame* f) { this->release(f); });
}

void FramePool::release(const Frame* f) {
  std::lock_guard<std::mutex> lk(mu_);
  free_.push_back(const_cast<Frame*>(f));
}

void AcquisitionThread::onFrame() {
  FramePtr frame = pool_.acquire();
  if (!frame) {                  // 덮어쓰기 대신 명시적 드롭
    metrics_.inc("frame_dropped_pool_empty");
    return;
  }
  camera_.copyInto(frame->buffer);
  queue_.push(std::move(frame)); // 소유권이 큐로 이동한다
}

핵심은 성능 최적화가 아니라 약속의 명시화입니다. 바뀐 코드에서 프레임은 마지막 독자가 손을 놓을 때까지 반드시 살아 있습니다. 그리고 풀이 비면 조용히 덮어쓰는 대신 드롭을 카운트하고 지표에 올립니다. 실제로 배포 첫날 frame_dropped_pool_empty가 하루 40여 건 찍혔는데, 그건 새로 생긴 문제가 아니라 원래 있었지만 겹친 이미지로 숨어 있던 손실이 드디어 이름을 얻은 것이었습니다. 이후 풀 크기를 8에서 16으로 올려 그 값도 0에 수렴시켰습니다.

같이 넣은 변경이 두 가지 더 있습니다. 하나는 프레임에 시퀀스 번호를 담고 추론 결과에 그 번호를 되돌려 적어, 판정과 입력이 어긋나면 즉시 어서션에 걸리게 한 것입니다. 다른 하나는 대시보드에서 평균 지표를 아예 지우고 p50/p95/p99를 나란히 띄운 것입니다. 이 두 가지가 없었다면 같은 사고를 또 반나절 걸려 찾았을 겁니다. 감이 아니라 측정으로 성능을 이야기하는 방법은 C++ 성능 가이드에도 같은 결로 정리되어 있습니다.

주의 공유 버퍼를 shared_ptr로 감싸는 것만으로 모든 경쟁 상태가 사라지지는 않습니다. 수명은 해결되지만 동시 쓰기는 그대로 남습니다. 저희는 프레임을 const로만 노출해 취득 이후에는 아무도 쓰지 못하게 막았고, 그 경계를 리뷰 항목으로 고정했습니다.

팀이 다시 적어 둔 규칙

• 파이프라인 경계를 넘는 버퍼는 인덱스가 아니라 소유권을 가진 타입으로 전달합니다.
• 자원이 부족할 때의 기본 동작은 덮어쓰기가 아니라 드롭이며, 드롭은 반드시 지표로 셉니다.
• 지연 지표는 평균 대신 분위수로 봅니다. 평균은 지터를 숨기는 데 특히 능합니다.
• 결정론적 모듈이 같은 입력에 다른 답을 내면 모듈이 아니라 입력을 의심합니다.
• 오프라인 재생이 가능하도록 원본 프레임 덤프를 상시 유지합니다. 이 사고의 결론은 그 덤프가 냈습니다.

재발 방지 테스트도 하나 추가했습니다. 풀 크기를 2로 줄이고 추론에 인위적인 지연을 넣어 슬롯 재사용을 강제로 유발한 뒤, 모든 판정의 시퀀스 번호가 입력과 일치하는지 검증하는 테스트입니다. 옛 코드에서는 즉시 실패하고 새 코드에서는 통과합니다. 이런 식으로 사고를 테스트로 굳히는 방법은 C++ 테스트 가이드에 정리된 접근과 같은 맥락입니다.

남은 원칙

이 사고에서 얻은 가장 일반적인 교훈은 C++나 비전과 무관합니다. 공유된 가변 상태에서 정확성 문제는 성능 문제로 위장해서 나타난다는 것입니다. 저희 눈에 처음 보인 것은 품질 지표였고, 그다음에 보인 것은 타이밍 지표였지만, 진짜 결함은 "이 메모리를 언제까지 읽어도 되는가"에 대해 두 스레드가 서로 다른 답을 갖고 있었다는 점이었습니다. 부하가 낮을 때는 그 불일치가 시간 여유에 가려 보이지 않습니다. 그래서 이런 결함은 늘 가장 바쁜 날에 처음 모습을 드러냅니다.

실무로 옮기면 이렇게 정리됩니다. 어떤 자원을 두 실행 흐름이 함께 만진다면, 그 자원의 수명은 주석이 아니라 타입으로 표현되어야 합니다. 타입으로 표현할 수 없다면 최소한 계측으로라도 드러나야 합니다. 그리고 어떤 지표든 평균 하나만 보고 있다면, 그 지표는 시스템이 가장 아플 때 가장 조용합니다. 비슷한 결의 언어별 실무 기록은 심층 가이드 목록에서 이어 볼 수 있습니다.