Python 구조화 로그 prefix 매칭: 재시도 횟수 필드를 잘못 읽는 파서 회귀 막기
timestamp INFO pipeline retry_count=2만 유효한 입력이라면, Python 구조화 로그 prefix 매칭은 retry_count=를 찾는 일이 아니라 그 값이 최상위 파일 로그 행에 속하는지 확인하는 일이다. retry_count=(\d+)처럼 짧게 검색하면 agent의 중첩 출력에 적힌 9나 retry_count=2x의 앞자리 2까지 정상 값으로 읽을 수 있다.
2026년 8월 11일 Linux 7.0.0-1009-aws와 CPython 3.12.3에서 표준 라이브러리 re·unittest로 이 차이를 검증했다. 실제 HuntLab 커밋 7fdb827과 9b41208은 재시도 횟수를 파싱한 변경이 아니라 성공 이벤트와 run_id의 중첩 오인식을 고친 기록이다. 이 글의 숫자 예제는 그 결함 모양을 옮긴 목적 제작 fixture이며, 운영 로그나 인증정보는 검증 범위에 포함하지 않았다.
20초 핵심 요약
- 무엇: 파일 formatter가 만든
timestamp + level + emitterprefix와retry_count값 뒤 delimiter를 한 패턴으로 검사한다. - 왜: 부분 검색은 중첩 agent 출력의
9와 불완전한2x의2를 읽어 재시도 판단을 바꿀 수 있다. - 어떻게: 정상·bare message·nested output·잘못된 delimiter를 같은 fixture 표에 넣고 추출 결과와 상위 제어 흐름을 함께 테스트한다.
먼저 parser가 받을 한 행을 고정한다
Python logging의 출력 형식은 고정돼 있지 않다. Formatter는 설정된 LogRecord 속성을 문자열로 만들고, formatter를 지정하지 않은 handler는 message만 출력할 수 있다. HuntLab의 날짜별 파일 handler는 %(asctime)s %(levelname)s %(message)s와 %Y-%m-%dT%H:%M:%S%z를 사용하지만 stream handler에는 formatter가 없다.
따라서 이 parser의 양성 입력은 넓은 의미의 “Python 로그”가 아니다. 날짜별 파일에서 읽은 다음 모양의 한 행이다.
2026-08-11T02:00:00+0900 INFO pipeline retry_count=2 status=failed
이 제한은 의도적이다. formatter 없는 pipeline retry_count=2까지 받도록 패턴을 느슨하게 만들면, 다른 로그 행의 output= 안에 들어간 같은 문자열과 최상위 이벤트를 구분하기 어려워진다.
부분 문자열 검색은 값과 행의 소유권을 확인하지 않는다
문제가 되는 최소 패턴은 짧다.
import re
old_pattern = re.compile(r"retry_count=(\d+)")
이 패턴은 두 가지를 묻지 않는다. 매치가 실제 로그 행 시작에서 이어진 pipeline 이벤트인지 확인하지 않고, 숫자 뒤가 필드 delimiter인지도 검사하지 않는다. 그래서 다음 중첩 메시지의 9도 캡처한다.
2026-08-11T02:00:00+0900 INFO agent output='pipeline retry_count=9 status=failed'
실제로 “중첩 출력에는 매치하지 않아야 한다”는 assertion을 짧은 패턴에 적용하자 테스트는 비정상 종료했다.
$ .venv/bin/python <짧은 retry_count 패턴의 nested-output unittest>
test_nested_output_is_not_top_level_retry_count ... FAIL
AssertionError: <re.Match object; span=(60, 73), match='retry_count=9'> is not None
Ran 1 test in 0.000s
FAILED (failures=1)
exit_status=1
이는 regex engine의 오류가 아니다. 입력 계약이 빠진 결과다. HuntLab의 실제 수정에서도 같은 형태가 확인됐다. 7fdb827 이전 코드는 로그 어디에든 pipeline event=end failed=false가 있으면 성공으로 판단했고, agent가 과거 성공 문구를 output=에 인용하면 최상위 실패를 성공으로 오인할 수 있었다.
수정 커밋은 (?m)^ 뒤에 timestamp, INFO, pipeline을 차례로 요구했다. 이어진 9b41208은 formatter가 붙은 정상 성공 행과, 중첩 성공 문구 다음에 최상위 ERROR 행이 오는 음성 fixture를 테스트에 추가했다. 이 두 커밋이 입증하는 것은 retry_count 자체의 장애가 아니라 “행 안에 문자열이 있다”와 “그 행을 소유한 최상위 이벤트다”를 구분해야 한다는 점이다.
행 시작과 값 끝을 한 정규식에 넣는다
현재 날짜별 파일 로그만 읽는다면 최소 패턴은 다음처럼 쓸 수 있다.
import re
RETRY_COUNT_PATTERN = re.compile(
r"(?m)^[^\n ]+ INFO pipeline retry_count=(\d+)(?=\s|$)"
)
각 조각의 역할은 서로 다르다.
(?m)^는 전체 문자열의 시작뿐 아니라 newline 직후도 행 시작으로 취급한다.[^\n ]+는 현재 date format이 만드는 공백 없는 timestamp 한 token을 받는다.INFO pipeline은 level과 emitter 위치를 고정한다.(\d+)는 재시도 횟수만 캡처한다.(?=\s|$)는 숫자를 소비한 다음 공백 또는 문자열 끝이 오는지 확인한다.
[^\n ]+는 범용 timestamp 정규식이 아니다. 현재 formatter에 맞춘 조건이다. timestamp에 공백이 들어가거나 logger 이름이 추가되거나 탭으로 필드를 나누면 parser와 fixture를 함께 바꿔야 한다.
값 끝에 \b를 붙이는 것만으로는 로그 schema를 표현할 수 없다. \b는 \w와 \W 사이의 word boundary이지 공백, 쉼표, 닫는 따옴표 같은 필드 구분 규칙이 아니다. 이 입력은 공백으로 다음 필드를 나누므로 (?=\s|$)가 실제 문법을 더 정확하게 드러낸다. 동적으로 literal prefix를 조합해야 할 때는 해당 literal에만 re.escape()를 적용하고 replacement string을 만드는 용도로 쓰지 않는다.
네 fixture가 허용과 거부를 함께 고정한다
양성 예제 하나만으로는 패턴이 지나치게 넓은지 알 수 없다. 같은 parser에 다음 네 조건을 넣어야 한다.
| case | 입력의 핵심 모양 | 기대값 | 이유 |
|---|---|---|---|
bare |
pipeline retry_count=2 |
None |
파일 formatter prefix가 없다 |
formatted |
timestamp INFO pipeline retry_count=2 ... |
2 |
지정한 행과 값 경계를 모두 만족한다 |
nested |
INFO agent output='pipeline retry_count=9 ...' |
None |
agent message 안의 인용 문자열이다 |
bad_boundary |
timestamp INFO pipeline retry_count=2x |
None |
숫자 뒤 delimiter가 올바르지 않다 |
동일한 네 입력에 짧은 패턴과 prefix-aware 패턴을 적용한 결과는 다음과 같았다.
$ .venv/bin/python <동일 네 fixture 비교 스크립트>
bare: old=2 new=None
formatted: old=2 new=2
nested: old=9 new=None
bad_boundary: old=2 new=None
exit_status=0
formatted만 통과한 것이 이 파일 소비자의 성공 조건이다. bare 거부는 새 패턴이 모든 로그에 더 뛰어나다는 뜻이 아니라, 읽는 채널을 날짜별 파일로 제한했다는 뜻이다.
반복 입력은 unittest.subTest()로 이름을 보존할 수 있다.
import re
import unittest
PATTERN = re.compile(
r"(?m)^[^\n ]+ INFO pipeline retry_count=(\d+)(?=\s|$)"
)
class RetryCountParserTests(unittest.TestCase):
def test_file_log_boundaries(self):
cases = {
"bare": ("pipeline retry_count=2", None),
"formatted": (
"2026-08-11T02:00:00+0900 INFO "
"pipeline retry_count=2 status=failed",
"2",
),
"nested": (
"2026-08-11T02:00:00+0900 INFO agent "
"output='pipeline retry_count=9 status=failed'",
None,
),
"bad_boundary": (
"2026-08-11T02:00:00+0900 INFO "
"pipeline retry_count=2x",
None,
),
}
for name, (line, expected) in cases.items():
with self.subTest(name=name):
match = PATTERN.search(line)
actual = match.group(1) if match else None
self.assertEqual(actual, expected)
fixture 이름은 실패한 경계를 바로 보여줘야 한다. 테스트 개수를 늘리는 것보다 nested와 bad_boundary 중 무엇이 다시 열렸는지 출력에서 구분되는 편이 운영 진단에 유용하다.
추출값 다음의 재시도 결정도 테스트한다
parser 테스트가 통과해도 상위 코드가 None을 0으로 바꾸면 판정 불가 로그를 첫 재시도로 오해할 수 있다. 추출 결과가 실제 제어 흐름에 쓰인다면 상위 테스트에서 다음 두 층을 분리한다.
- parser는 계약을 만족한 행에서만 숫자를 반환한다.
- 재시도 정책은 유효한 count와 현재 run state를 받아 resume·skip·fresh 중 애플리케이션이 정의한 결과를 고른다.
이번 목적 제작 fixture는 count의 최대값이나 각 상태의 의미를 임의로 정하지 않았다. 운영 코드에 적용할 때는 parser의 None을 “0회”로 추측하지 말고 판정 불가로 남겨야 한다. 그래야 새로운 formatter나 알 수 없는 producer가 들어왔을 때 조용히 잘못된 재시도를 실행하지 않는다.
기존 근거와의 연결도 여기서 구분해야 한다. 저장소 HEAD 9b41208에서 DailyRetryTests 네 개를 실행한 결과는 모두 통과했다.
$ .venv/bin/python -m unittest tests.test_daily_pipeline.DailyRetryTests -v
test_noon_retry_does_not_mistake_nested_agent_output_for_success ... ok
test_noon_retry_replans_manufactured_build_log ... ok
test_noon_retry_skips_after_daily_success ... ok
test_noon_retry_starts_fresh_without_a_run ... ok
Ran 4 tests in 0.001s
OK
exit status: 0
이 결과는 실제 성공 이벤트 parser의 회귀 방지가 유지됨을 확인한다. 새 숫자 fixture가 production retry_count parser에 이미 적용됐다는 증거는 아니다.
formatter가 바뀌면 정규식을 느슨하게 풀지 않는다
채택 조건은 현재 날짜별 파일의 실제 formatter 출력 한 줄이 양성 fixture와 같고, 기존 DailyRetryTests와 새 네 fixture가 함께 통과하는 것이다. 반대로 JSON logger, 여러 공백이나 탭, 다른 level, multiline message는 이번 검증 범위 밖이다. 공식 웹 문서는 조사일 기준 Python 3.14.7이었고 직접 실행은 3.12.3이지만, 사용한 ^·MULTILINE·lookahead·Formatter 동작에서 관측 충돌은 없었다.
formatter 변경으로 테스트가 깨졌다면 짧은 포함 검사로 되돌리는 방식은 안전한 롤백이 아니다. 새 schema에 맞춰 parser와 fixture를 같은 변경에서 갱신하거나 producer별 parser를 나눈다. 중첩 메시지가 계속 늘고 format 변경도 잦다면 한 이벤트 record 자체를 JSON으로 직렬화하고 json.loads() 결과의 retry_count 키를 읽는 편이 낫다. 이때도 message 문자열 안에서 JSON처럼 보이는 부분을 다시 검색해서는 안 되며, 신뢰할 수 없는 입력의 크기 제한을 별도로 둬야 한다.
실제 formatter 출력 한 줄을 양성 fixture로 복사하고, agent가 같은 문자열을 인용한 nested-output 행을 음성 fixture로 추가해 두자. 이 두 입력이 함께 있어야 다음 format 수정이 호환 변경인지 오탐 회귀인지 테스트가 구분해 준다.
