AI로 에러 로그 디버깅하기: 최초 오류 추출, 비밀값 마스킹, 가설 검증 순서

긴 에러 로그를 AI에 통째로 붙여 넣으면 요약은 빨리 나오지만, 마지막 줄의 오류를 원인으로 착각하거나 로그에 없는 원인을 그럴듯하게 지어내는 일이 생긴다. 이 글은 실제로 재현한 두 단계 오류를 예로, 시간순 최초 오류를 뽑고 비밀값을 가린 뒤 가설을 하나씩 검증하는 순서를 정리한다. 아래 로그와 실행 결과는 모두 2026-10-07에 Node.js 24.15로 실행한 출력이다.

재현한 오류: 마지막 줄은 원인이 아니다

재고 API 호출이 실패하면 캐시를 쓰는 작업자 코드다. 캐시가 비어 있으면 undefined를 돌려주고, 그 뒤에서 두 번째 오류가 난다.

// 재현용 앱: 재고 API 호출이 실패하면 캐시를 쓰는데, 캐시가 비어 있으면 두 번째 오류가 난다.
const log = (level, msg, extra = {}) =>
  console.log(JSON.stringify({ ts: new Date().toISOString(), level, msg, ...extra }));

const API_URL = process.env.INVENTORY_URL || 'http://127.0.0.1:9/inventory';
const cache = new Map();

async function loadInventory() {
  try {
    const res = await fetch(API_URL, { headers: { Authorization: 'Bearer sk-live-4f9a8c2e7b1d' } });
    return await res.json();
  } catch (err) {
    log('error', 'inventory fetch failed', { cause: err.cause?.code || err.cause?.message, url: API_URL, user: '[email protected]' });
    return cache.get('inventory'); // 캐시가 비어 있으면 undefined
  }
}

log('info', 'worker started', { pid: process.pid });
const inv = await loadInventory();
log('warn', 'using cached inventory');
try {
  console.log(inv.items.length);
} catch (err) {
  log('error', err.message, { stack: err.stack.split('\n').slice(0, 2).join(' | ') });
  process.exitCode = 1;
}

$ node app.mjs > app.log; cat app.log
{"ts":"2026-10-07T14:00:10.136Z","level":"info","msg":"worker started","pid":24664}
{"ts":"2026-10-07T14:00:10.158Z","level":"error","msg":"inventory fetch failed","cause":"bad port","url":"http://127.0.0.1:9/inventory","user":"[email protected]"}
{"ts":"2026-10-07T14:00:10.158Z","level":"warn","msg":"using cached inventory"}
{"ts":"2026-10-07T14:00:10.158Z","level":"error","msg":"Cannot read properties of undefined (reading 'items')","stack":"TypeError: Cannot read properties of undefined (reading 'items') |     at file:///.../app.mjs:22:19"}

로그의 마지막 오류는 TypeError지만, 이는 앞선 재고 API 실패의 결과다. 마지막 줄만 AI에 주면 "inv가 undefined이니 옵셔널 체이닝을 쓰라"는 답이 나오고, 실제 원인인 API 실패는 그대로 남는다.

1단계: 최초 오류와 직전 문맥만 뽑고 비밀값 가리기

AI에 넘기기 전에 시간순으로 첫 error와 직전 두 줄, 이후 오류 목록만 남긴다. 토큰·API 키·이메일·로컬 경로는 가린다. 코드에 들어 있던 Bearer 토큰처럼 로그에 찍힐 수 있는 값도 마스킹 규칙에 미리 넣어 둔다.

// 사용법: node first-error.mjs app.log
// JSON 줄 로그에서 시간순 첫 error와 직전 문맥을 뽑고, 비밀값을 가린 뒤 AI에 붙여 넣을 요약을 만든다.
import { readFileSync } from 'node:fs';

const MASKS = [
  [/Bearer\s+[A-Za-z0-9._-]+/g, 'Bearer [MASKED]'],
  [/\bsk-[A-Za-z0-9-]{8,}/g, '[MASKED_KEY]'],
  [/[\w.+-]+@[\w-]+\.[\w.]+/g, '[EMAIL]'],
  [/file:\/\/\/[^\s"|]+\/([^/\s"|]+:\d+:\d+)/g, '<repo>/$1'], // 로컬 경로 대신 파일명:줄만 남긴다
];
const mask = (s) => MASKS.reduce((acc, [re, to]) => acc.replace(re, to), s);

const lines = readFileSync(process.argv[2], 'utf8').trim().split('\n').map((l) => JSON.parse(l));
lines.sort((a, b) => a.ts.localeCompare(b.ts));
const idx = lines.findIndex((l) => l.level === 'error');
if (idx < 0) {
  console.log('error 레벨 로그가 없습니다.');
  process.exit(0);
}
const context = lines.slice(Math.max(0, idx - 2), idx + 1);
const later = lines.slice(idx + 1).filter((l) => l.level === 'error');

console.log('## 최초 오류와 직전 문맥');
context.forEach((l) => console.log(mask(JSON.stringify(l))));
console.log(`\n## 이후 오류 ${later.length}건 (최초 오류의 결과일 수 있음)`);
later.forEach((l) => console.log(mask(`- ${l.ts} ${l.msg}`)));

$ node first-error.mjs app.log
## 최초 오류와 직전 문맥
{"ts":"2026-10-07T14:00:10.136Z","level":"info","msg":"worker started","pid":24664}
{"ts":"2026-10-07T14:00:10.158Z","level":"error","msg":"inventory fetch failed","cause":"bad port","url":"http://127.0.0.1:9/inventory","user":"[EMAIL]"}

## 이후 오류 1건 (최초 오류의 결과일 수 있음)
- 2026-10-07T14:00:10.158Z Cannot read properties of undefined (reading 'items')

이 요약에 실행 명령, 기대 동작, 최근 변경 사항을 붙여 AI에 요청한다. 요청 문장은 답을 원인 후보·근거·확인 명령으로 나눠 받도록 쓴다.

아래는 Node.js 24 작업자 로그 요약이다. 비밀값은 가렸다.
- 실행: node app.mjs (INVENTORY_URL 미설정)
- 기대: 재고 목록 길이 출력 / 실제: TypeError로 종료
- 최근 변경: 재고 API 주소 기본값 변경

[요약 붙여 넣기]

다음 형식으로 답해라.
1. 원인 후보 (가능성 순, 최대 3개)
2. 후보별 근거가 되는 로그 줄
3. 후보별로 확인할 명령 1개
4. 로그만으로 배제할 수 있는 가능성

2단계: 첫 로그에는 원인 코드가 없었다

처음 작성한 코드는 오류 객체에서 err.cause?.code만 기록했고, 로그에는 code 필드 자체가 빠져 있었다. "연결 거부(ECONNREFUSED)겠지"라는 가설을 세우기 쉬운 상황이다. 오류 객체를 직접 확인하면 다른 결과가 나온다.

$ node -e "fetch('http://127.0.0.1:9/inventory').catch(e => { const c = e.cause; console.log(Object.getOwnPropertyNames(c), '|', c.message, '|', c.code) })"
[ 'stack', 'message' ] | bad port | undefined

원인은 연결 거부가 아니라 bad port였다. WHATWG Fetch 표준은 1, 7, 9(discard), 22, 6000, 5060, 6665~6669 등을 "bad port"로 정해 두고, fetch는 이 포트로 연결을 시도하기 전에 요청을 막는다. 이 경우 cause에 code가 없어서 code만 기록하는 로그 코드는 원인을 잃는다. 위 앱 코드는 이 확인 뒤 err.cause?.code || err.cause?.message를 기록하도록 고친 버전이다. 같은 앱을 차단되지 않는 포트로 실행하면 비로소 우리가 아는 오류가 나온다.

$ INVENTORY_URL=http://127.0.0.1:59999/inventory node app.mjs | head -2
{"ts":"2026-10-07T14:00:10.274Z","level":"info","msg":"worker started","pid":15432}
{"ts":"2026-10-07T14:00:10.304Z","level":"error","msg":"inventory fetch failed","cause":"ECONNREFUSED","url":"http://127.0.0.1:59999/inventory","user":"[email protected]"}

curl은 되는데 fetch만 실패하는 경우

로컬 개발 서버를 6000번 포트에 띄웠다면 같은 증상이 난다. 아래 스크립트로 같은 서버를 curl과 fetch로 각각 호출했다.

// 같은 로컬 서버를 curl과 fetch로 각각 호출해 결과를 비교한다.
// execFileSync를 쓰면 이벤트 루프가 막혀 같은 프로세스의 서버가 응답하지 못하므로 비동기 execFile을 쓴다.
import http from 'node:http';
import { execFile } from 'node:child_process';
import { promisify } from 'node:util';
import { devNull } from 'node:os';

const run = promisify(execFile);
const server = http.createServer((req, res) => res.end('{"items":[1,2,3]}')).listen(6000, async () => {
  const { stdout } = await run('curl', ['-s', '-o', devNull, '-w', '%{http_code}', 'http://127.0.0.1:6000/']);
  console.log(`curl  → HTTP ${stdout}`);
  try {
    const res = await fetch('http://127.0.0.1:6000/');
    console.log(`fetch → HTTP ${res.status}`);
  } catch (err) {
    console.log(`fetch → ${err.message} (cause: ${err.cause?.message})`);
  }
  server.close();
});

$ node port-check.mjs
curl  → HTTP 200
fetch → fetch failed (cause: bad port)

이 비교 스크립트를 만들 때도 두 번 막혔다. 처음에는 execFileSync로 curl을 불러 이벤트 루프가 멈췄고, 같은 프로세스의 서버가 응답하지 못해 120초 동안 끝나지 않았다. 비동기 execFile로 바꾼 뒤에는 Windows의 curl이 /dev/null에 쓰지 못해 HTTP 200을 받고도 종료 코드 23으로 실패했다. os.devNull을 쓰면 두 OS에서 모두 동작한다. AI에 "curl은 되는데 fetch는 안 된다"고만 물으면 CORS나 프록시 같은 브라우저 쪽 원인을 먼저 떠올리기 쉬우므로, 오류 객체의 cause를 함께 붙여 넣어야 한다.

3단계: 가설은 하나씩, 확인 명령으로 검증한다

1. AI가 낸 원인 후보를 가능성 순으로 적고, 후보마다 근거 로그 줄이 실제로 있는지 확인한다. 근거 줄이 없는 후보는 지운다.
2. 가장 가능성이 높은 후보 하나에 대해 확인 명령(위의 node -e처럼 오류 객체를 직접 출력하는 명령)을 실행한다.
3. 결과가 가설과 다르면 그 결과를 다시 요약에 추가해 후보를 갱신한다. 여러 수정을 한꺼번에 적용하지 않는다.
4. 원인이 확인되면 증상 대신 원인을 고친다. 이 예에서는 포트 설정을 바꾸고, 캐시가 비었을 때 빈 목록 대신 명시적인 오류를 던지게 해 두 번째 오류가 원인을 가리지 않게 한다.
5. 로그 코드도 고친다. 오류 객체의 code가 없을 수 있으므로 message까지 기록한다.

AI가 존재하지 않는 설정 파일이나 쓰지 않는 라이브러리를 원인으로 들면, 2단계의 근거 확인에서 바로 걸러진다. 반복 호출이 실패하는 에이전트 흐름이라면 서킷 브레이커와 재시도 전략으로 재시도 대상 오류와 즉시 중단할 오류를 나누고, 운영 중 오류율 추적은 LLM 호출 로그 집계를 참고한다.