“로그를 Debug로 올리면 보이지 않을까?”

개발하다 보면 참 자주 나오는 말이다.

나도 이번에 같은 질문을 받았다. 데이터베이스 클라이언트가 다음 결과를 가져갈 때 쓰는 nextUri가 프록시에서 어떻게 바뀌는지, Debug 로그만으로 확인할 수 있느냐는 질문이었다.

겉으로는 간단해 보였다.

로그 레벨을 올린다. 쿼리를 한 번 날린다. 로그에서 nextUri를 검색한다. 끝.

그런데 실제로 해보니 결과는 꽤 재미있었다.

Target 응답의 nextUri: 확인됨
Proxy 응답의 nextUri: 확인됨
URI가 Proxy 주소로 바뀐 것: 확인됨
Debug 로그의 nextUri: 0개

스위치는 분명 켰는데, 찾던 장면은 한 프레임도 찍히지 않았다.

이 작은 실험이 재현 도구 전체를 한 단계 고치는 계기가 됐다.

로그 레벨은 볼륨 다이얼이지 마이크가 아니다

먼저 오해 하나부터 풀자.

Debug 레벨을 켠다고 모든 내부 값이 갑자기 기록되는 건 아니다.

로그 레벨은 이미 설치된 마이크의 볼륨을 조절한다. 애초에 마이크가 없는 방의 대화까지 들려주지는 않는다.

코드가 이런 로그를 갖고 있다면 보인다.

originalNextUri=...
rewrittenNextUri=...

하지만 URI를 바꾸는 코드만 있고 그 전후를 기록하는 문장이 없다면, Debug를 켜도 결과는 조용하다.

이번 실험에서도 실제 응답을 직접 비교하니 URI 변환은 정상적으로 보였다. 하지만 같은 시간대 로그에서는 원본 URI도, 변환된 URI도 나오지 않았다.

여기서 중요한 교훈이 하나 생겼다.

“코드상 보일 것 같다”와 “실행 증거에서 실제로 보였다”는 전혀 다른 문장이다.

그래서 추측 대신 실제 Target 응답, Proxy 응답, 짧게 잘라낸 Debug 로그 구간을 따로 수집했다.

그런데 실험 장치가 더 무서웠다

Debug 로그를 확인하려면 잠시 로그 레벨을 바꿔야 한다.

문제는 여기서 시작한다.

기존 레벨 조회
→ Debug 적용
→ 쿼리 실행
→ 원래 레벨 복원

정상 실행만 생각하면 쉽다. 하지만 쿼리 중간에 예외가 나면? Debug 적용 직후 확인 요청이 실패하면? 복원 요청은 보냈지만 실제 상태가 돌아오지 않았다면?

재현 도구는 버그를 잡으러 갔다가 새로운 운영 문제를 만들면 안 된다.

그래서 로그 레벨 변경을 ‘설정 변경’이 아니라 ‘대여’로 다루기 시작했다.

도서관에서 책을 빌리면 반납까지가 한 동작인 것처럼 말이다.

LogLevelLease
├─ 빌리기 전 상태 기록
├─ Debug 적용
├─ 실제 적용 상태 재조회
├─ 정상·예외 모두 원복
└─ 원복된 상태 다시 확인

특히 재미있는 경계가 하나 있었다.

보통 finally에서 원복하면 안전하다고 생각한다. 하지만 context manager가 들어가는 도중, 즉 __enter__ 단계에서 실패하면 body의 finally까지 도달하지 못할 수 있다.

그래서 “실험 도중 실패”뿐 아니라 “실험실 문을 열다가 실패”해도 원복되는 테스트를 따로 넣었다.

자동화의 품질은 성공 경로보다 문턱에서 미끄러졌을 때 드러난다.

nextUri에도 모자이크가 필요하다

두 번째 문제는 증거의 밀도였다.

Trino의 nextUri에는 host와 port만 있는 게 아니다. 다음 페이지를 찾기 위한 query ID와 일회성 continuation token도 path에 들어갈 수 있다.

이 값을 통째로 JSON에 저장하면 분석은 편하다. 하지만 증거 파일에 굳이 남길 필요가 없는 값까지 퍼진다.

그래서 URI를 그대로 보관하지 않고 ‘안전한 모양’으로 바꿨다.

scheme
host
port
pathTemplate
pathSha256
queryId
sequence

실제 path는 이렇게 일반화한다.

/v1/statement/queued/{queryId}/{token}/{sequence}

userinfo, query string, fragment, continuation token 원문은 저장하지 않는다.

필요한 건 “어디로 연결하려 했는가”와 “두 경로가 같은 형태인가”이지, 일회성 token을 기념품처럼 간직하는 게 아니다.

좋은 증거는 많이 남기는 증거가 아니다.

판정에 필요한 만큼만 남기는 증거다.

로그 원문 대신 지문만 남기기

Debug 로그에는 SQL, 식별자, 개인 정보가 섞일 수 있다.

그렇다고 매번 로그 전체를 압축해 결과 폴더에 넣는 것도 부담스럽다. 이번 질문에 필요한 건 사실 몇 개의 문자열 개수뿐이었다.

nextUri
originalNextUri
rewrittenNextUri
Next Content
Next Json

그래서 새로운 방식은 로그 원문을 새 파일로 보관하지 않는다.

대신 실행 직전 offset을 찍고, 실행 후 추가된 구간만 읽고, 민감값을 가린 뒤 다음만 남긴다.

읽은 byte 수
시작·종료 offset
로그 rotation 여부
구간 hash
검색 패턴별 개수

이번 실험에서는 약 7KB의 구간을 검사했고 찾던 문자열은 모두 0개였다.

‘없었다’는 결론도 이렇게 측정 과정을 남겨야 증거가 된다.

그냥 검색해서 안 나왔다는 말과, 어느 파일의 어느 구간을 어떤 패턴으로 검사했는지는 신뢰도가 다르다.

같은 것처럼 보이는 두 증거를 구분하기

이번에 가장 유익했던 교훈은 이름 짓기였다.

Target에 직접 보낸 쿼리 A와 Proxy를 통해 보낸 쿼리 B를 비교하면, URI host와 port가 달라진 걸 확인할 수 있다.

하지만 A와 B는 서로 다른 쿼리다.

따라서 이 실험이 증명한 것은 이것이다.

endpointRewriteBehaviorObserved=true

이렇게 말하면 안 된다.

correlatedResponseRewriteObserved=true

두 번째 문장은 동일한 upstream 응답이 Proxy 내부에서 어떻게 바뀌었는지 같은 session과 query로 연결했을 때만 쓸 수 있다.

둘 다 “URI가 바뀌었다”처럼 보이지만 증명의 강도는 다르다.

엔지니어링에서 꽤 많은 오해가 거짓 데이터보다 과한 이름에서 시작된다.

측정값보다 큰 이름을 붙이지 않는 것. 이것도 테스트 품질이다.

특수 기능에는 작업 허가서가 필요하다

일반 재현 흐름 밖에는 가끔 특별한 진단 명령이 생긴다.

이번의 Debug nextUri 검사도 그렇다. 잠시 runtime 설정을 바꾸고, 추가 evidence를 만들고, 반드시 원복해야 한다.

예전에는 이런 명령이 manifest에 이름만 올라갔다. 이제는 capability 계약으로 책임까지 선언한다.

capabilities:
  nextUriObservability:
    command: inspect-debug-nexturi
    requiredArtifacts:
      - nexturi-observability.json
    temporaryMutations:
      - proxy-log-level
    restoresState: true

이건 작업 허가서와 비슷하다.

무슨 작업을 하는지, 어떤 흔적을 남겨야 하는지, 무엇을 원복해야 하는지 시작 전에 적어둔다.

임시 변경이 있는데 restoresState: true가 없다면 검증 단계에서 바로 거부한다.

“어느 커밋에서 돌렸나요?”만으로 부족하다

재현 결과에는 보통 commit hash를 적는다.

그런데 working tree에 수정 중인 파일이나 아직 추적되지 않은 runner가 있다면, HEAD commit만으로는 실제 실행 코드를 복원할 수 없다.

이 상태에서 commit hash만 적으면 꽤 그럴듯한 거짓말이 된다.

그래서 provenance도 더 솔직해졌다.

source commit
harness commit
source working tree dirty 여부
harness working tree dirty 여부
status hash
runner hash
manifest hash

이제 결과를 보는 사람은 안다.

“이 실행은 이 commit을 기반으로 했지만, 아직 commit되지 않은 변경도 포함했다.”

재현 가능성은 완벽한 환경에서만 나오는 게 아니다.

불완전한 환경을 불완전하다고 정확히 기록할 때도 올라간다.

개선한 뒤 일부러 다시 흔들어봤다

모듈을 분리한 뒤에는 전체 흐름을 다시 돌렸다.

공통 모듈 단위 테스트: 15개 통과
시나리오 manifest 계약: 16개 통과
Proxy 정상 쿼리: 20회 중 20회 성공
Debug 적용과 원복: 성공
Target·Proxy continuation cleanup: HTTP 204
비밀값 검사: 0건
실행 후 관련 port: 모두 정리

여기서 가장 마음에 드는 숫자는 20/20이 아니다.

마지막의 “모두 정리”다.

재현 도구는 멋진 실패 화면을 만드는 능력만큼, 실험이 끝난 뒤 아무 일도 없었던 것처럼 퇴근하는 능력이 중요하다.

작은 질문이 도구의 철학을 바꾼다

시작은 정말 작은 질문이었다.

“Debug로 올리면 nextUri가 남나요?”

답은 “아니요”였다.

하지만 그 답을 제대로 증명하려다 보니 더 좋은 질문들이 따라왔다.

임시 설정은 예외가 나도 돌아오는가?
증거에 불필요한 token이 남지 않는가?
로그 원문 없이도 결론을 검증할 수 있는가?
A/B 관찰과 동일-response 증명을 구분했는가?
실행 코드가 dirty했다는 사실을 숨기지 않았는가?
특수 진단 명령의 책임이 manifest에 선언됐는가?

좋은 재현 도구는 버그를 한 번 더 잘 만드는 도구가 아니다.

실험이 무엇을 증명했고, 무엇은 증명하지 못했으며, 실험 후 환경이 원래대로 돌아왔는지를 솔직하게 말하는 도구다.

Debug 스위치를 켰는데 아무것도 보이지 않았던 건 실패가 아니었다.

그 덕분에 ReproKit에는 더 안전한 스위치, 더 작은 증거, 더 솔직한 영수증이 생겼다.