에러 응답에 없는 성공 키

외부로 나가는 전송에서 실패가 6,406건 쌓여 있었다. 로그를 열어 보니 전부 Undefined index: Result 한 문구였다.

SELECT last_log, COUNT(*) FROM distribution_product_jobs
 WHERE status = 'fail' GROUP BY last_log;

GROUP BY 결과가 한 줄이었다.

Open Table of contents

증상 — 같은 문구로 쌓인 6,406건

이러면 인증 문제인지 파라미터 문제인지 권한 문제인지 안 나온다. 사유가 전부 같으면 원인이 하나라는 뜻일 수도 있지만 진짜 사유가 덮였다는 뜻일 수도 있어서 그 문구가 어디서 나온 것인지를 먼저 확인했다.

grep 으로 찾아보니 그것은 외부 시스템이 준 문구가 아니라 우리 코드가 던지는 Exception 의 문구였다. 로그에 저쪽 사유가 아니라 우리 쪽 예외가 들어가 있었던 것이다.

문구가 나는 자리는 응답 처리 부분이었다.

$xml = simplexml_load_string($body);
$response = json_decode(json_encode($xml), true);

if ($response['Result'] == '1') {   // 여기
}

simplexml_load_string 으로 읽은 XML 을 배열로 바꾼 뒤 Result 에 isset 확인 없이 접근하고 있었고 명세를 보니 Result 는 성공 응답에만 있는 키였다.

에러 응답은 아예 다른 구조로 오고 있었고 거기에는 그 키 대신 사유 코드와 메시지가 들어 있었다. 두 응답의 구조가 다르다는 것을 코드가 전제하지 않고 있었다.

그래서 저쪽이 사유를 제대로 보내 줬어도 우리 코드가 그것을 읽기 전에 Exception 으로 빠지고 있었다. catch 에서 남기는 문구가 로그에 들어가니 모든 실패가 같은 문구가 된다.

수천 건의 로그가 전부 같은 문구라는 것 자체가 신호였는데 그것을 처음에는 원인이 하나인 것으로 읽었다. 로그 문구가 우리 코드의 예외 형식이면 덮인 것으로 보는 것이 맞았다.

이 상태에서 실패 건을 다시 보내는 것은 아무 의미가 없었는데 응답을 읽는 코드가 그대로이기 때문이다. 몇 번을 보내도 같은 자리에서 같은 예외가 나고 사유는 계속 덮인다.

그래서 재시도보다 코드 수정이 먼저였고 고친 뒤에 다시 보내야 실제 사유가 로그에 남는다. 순서를 바꿨으면 6,406건을 한 번 더 실패시키고 같은 자리로 돌아왔을 것이다.

같은 방식으로 응답을 읽는 자리가 여기 하나만은 아닐 것 같아서 코드 전체를 grep 해 봤다. 같은 키를 isset 없이 꺼내는 곳이 여러 군데였고 전부 같은 문제를 안고 있었다.

한 자리만 고치면 다른 연동에서 같은 일이 그대로 난다. 명세가 바이너리 문서로 와 있어서 검색이 안 됐던 것도 이 문제가 늦게 드러난 이유 중 하나였다.