dev.to

My Health Check Watched the Wrong File

잘못된 파일을 감시한 헬스 체크

프로세스 ID와 로그 파일 수정 시각만으로 폴링 작업의 상태를 판단하다가 잘못된 결론에 도달한 사례입니다. 작성자는 각 파일을 갱신하는 코드 경로를 확인하고, 루프 실행·폴링 성공·메시지 처리·응답 전달을 구분해야 실제 상태를 알 수 있다고 설명합니다.

AI 요약

작성자는 자신의 에이전트에 적용하던 원칙인 “프로세스 ID보다 산출물의 나이가 중요하다”를 세 개의 Telegram 폴러에 시험했습니다. 작업 프로세스는 실행 중이었지만 로그 파일은 8월 11일 이후 바뀌지 않았습니다. 처음에는 세 작업이 멈췄다고 판단했지만, 로그를 기록하는 코드를 확인하자 성공적인 폴링 경로에는 출력이 없었습니다. 로그에는 시작 문구와 예외만 기록되므로 파일이 그대로라는 사실은 파일이 수정되지 않았다는 뜻일 뿐, 작업이 멈췄거나 예외가 없었다는 증거가 아니었습니다.

파일 시각이 알려주는 것

세 작업은 25초 동안 Telegram 업데이트를 기다린 뒤 20초를 쉽니다. 예외가 발생하면 30초를 쉰 뒤 일반 대기 시간도 거칩니다. 정상 경로에는 별도의 “여전히 폴링 중” 메시지가 없습니다. 따라서 로그 파일의 오래된 수정 시각을 실패 신호로 쓰려면 먼저 코드가 어떤 상황에서 파일을 갱신하는지 확인해야 합니다.

작성자는 상태 파일도 살펴봤습니다. courtside와 eye는 루프 바깥의 쓰기 코드가 매 반복마다 상태 파일을 갱신합니다. 예외를 잡은 뒤에도 이 코드에 도달하므로, 수정 시각이 새로워도 폴링이 성공했다는 뜻은 아닙니다. 반면 sentinel은 getUpdates가 반환된 뒤에만 상태 파일을 씁니다. 이 파일의 시각은 API 응답을 받아 JSON을 파싱하고 쓰기 지점까지 왔다는 더 강한 신호지만, API 작업의 성공이나 메시지 수신, 답장 전달까지 증명하지는 않습니다.

상태 파일의 내용도 셋이 달랐습니다. sentinel은 저장된 offset이 0이고 기록된 이력이 없었지만, courtside는 offset 51,848,716과 이력 4개, eye는 offset 63,652,330과 이력 8개를 저장했습니다. 세 프로세스가 launchctl에서 비슷하게 보인다는 이유로 같은 상태라고 볼 수 없었습니다. offset이나 이력도 현재 파일에 남은 값일 뿐, 작업의 전체 이력이나 답장 전달 여부를 보여주지는 않습니다.

로그 버퍼링과 예측의 실패

세 작업은 Python을 -u 없이 실행합니다. 비대화형 환경에서 stdout은 보통 블록 단위로 버퍼링되므로, print()가 실행돼도 내용이 곧바로 파일에 나타나지 않을 수 있습니다. -u나 PYTHONUNBUFFERED=1은 stdout과 stderr의 버퍼링을 끕니다. 같은 컴퓨터에서 -u를 쓰는 네 작업의 로그는 9월 22일에 모두 그날 갱신됐고, 쓰지 않는 세 작업의 로그는 그대로였습니다. 작성자는 이를 한 컴퓨터에서 관찰한 일곱 작업의 결과로 한정하고, 일반 법칙으로 제시하지 않습니다.

작성자는 로그가 10월 1일까지 바뀌지 않을 것이라는 예측을 기록했지만, 로그는 9월 25일에 이미 갱신됐습니다. 세 파일은 각각 8,173바이트, 8,188바이트, 8,184바이트 늘었습니다. 10월 3일 sentinel 로그에는 예외 673건이 있었고, 그중 594건이 URLError였습니다. 증가분과 예외 출력은 버퍼에 쌓인 내용이 나중에 기록됐다는 설명과 들어맞지만, 실제 쓰기를 추적하지 않았으므로 버퍼가 비워진 정확한 횟수나 계기는 입증하지 못합니다. 시작 문구도 결국 로그에 추가됐습니다. 재시작 때 사라졌다는 예측 역시 맞지 않았습니다.

헬스 체크를 설계할 때 확인할 것

작성자는 프로세스 존재, 로그 수정 시각, 상태 파일 수정 시각, 저장된 offset을 각각 어떤 사실의 근거로 쓸 수 있는지 표로 정리합니다. 어떤 신호도 폴링 성공이나 결과 전달을 직접 기록하지 않았습니다. 이를 확인하려면 성공한 폴링을 나타내는 기록과 전달된 결과를 나타내는 기록을 따로 만들어야 합니다. 다만 일이 없는 정상적인 빈 폴링과, 메시지는 받았지만 답장 전달에 실패한 경우도 구분해야 합니다.

글의 결론은 “더 최신인 파일을 감시하라”가 아닙니다. 먼저 어떤 작업을 확인할지 정하고, 그 작업이 어떤 증거를 남기는지, 그 증거가 없을 때 어떤 조건에서 실패로 판단할지 정의해야 합니다. macOS에서는 pgrep으로 프로세스를 확인하고, stat으로 파일 시각과 크기를 살피며, grep으로 코드의 출력 지점을 찾는 명령을 제시합니다. Linux에서는 stat -c와 서비스 관리자 설정을 확인하라고 덧붙입니다. 날짜를 정해 예측을 검증한다면 확인 작업도 스케줄러에 등록해야 합니다. 실행하지 않은 검증은 테스트가 아니라 메모에 그칩니다.

dev.to 반응

  • @reidmarlow — courtside와 eye의 루프 수준 쓰기는 헬스 체크를 잘못된 초록 상태로 만드는 정확한 패턴입니다. try/except 블록 바깥에서 state.json을 쓰면 감시기는 감독자가 스레드를 계속 돌렸는지 확인할 뿐, 실제 소켓에서 데이터가 빠져나왔는지 또는 시간 초과가 났는지는 확인하지 못합니다. 조용한 폴러에서 도움이 됐던 방식은 heartbeat를 loop_tick_ts와 work_completed_ts 두 필드로 나누는 것입니다. 예상 폴링 간격에 백오프를 더한 시간보다 work_completed가 오래 멈춰도 loop_tick이 움직이면, 버퍼링된 stdout 로그를 파싱하지 않고도 스레드 정체를 알릴 수 있습니다.
  • @launchgatecheck — 성공한 빈 폴링을 처리된 메시지나 전달된 답장 기록과 분리하겠습니다. 조용한 리스너도 할 일이 없을 뿐 정상 작동할 수 있고, cursor가 새로워도 전송은 실패할 수 있습니다. 빈 성공 폴링을 반환하는 테스트와, 메시지를 반환하지만 답장은 실패하는 테스트를 함께 만들 수 있습니다. 첫 번째는 전달 여부를 꾸며내지 않고 폴링 상태를 정상으로 유지해야 하고, 두 번째는 루프와 폴링 시각이 갱신돼도 전달 실패를 보여줘야 합니다. 계획 중인 기록은 API 수준의 성공과 JSON 파싱 성공도 구분하나요?
  • @panthpatel — :177의 courtside 쓰기는 독자 한 명이 제 heartbeat에서 발견한 문제와 같습니다. 제 티켓 추적기에서는 에이전트가 작업하는 동안 오케스트레이터가 60초마다 heartbeat를 보내고, 75초 동안 heartbeat가 없으면 보드를 빨간색으로 바꿉니다. heartbeat는 에이전트를 감싸는 루프에서 나오므로, 에이전트가 멈춰도 heartbeat는 계속 뛰고 메시지는 멈출 수 있습니다. 새 타임스탬프가 증명한 건 래퍼가 돌았다는 사실이지, 작업이 진척됐다는 사실이 아닙니다. sentinel처럼 getUpdates 뒤에 쓰는 방식을 따라 하겠습니다.
  • @innokentyb — 실제로는 대리 지표가 살아 있다는 점만 보여주는 초록색 체크의 좋은 사례입니다. 헬스 신호를 도입할 때마다 신호가 관찰한다고 주장하는 정확한 산출물이나 의존성을 고장 내고, 신호가 빨간색으로 바뀌는지 확인하는 승인 단계를 추가하는 방식을 좋아합니다. 작은 변경 테스트로 경로 불일치, 오래된 별칭, “엉뚱한 대상을 정상으로 보는” 문제를 대시보드가 신뢰받는 증거가 되기 전에 잡을 수 있습니다.

원문: dev.to / 번역·요약: Trawling