티스토리 뷰

통과하는 테스트가 늘 안심할 만한 것은 아닙니다

오픈소스 기여를 하려고 마음먹고 저장소를 열면, 대개는 "고칠 만한 버그"를 찾으려고 합니다. 저도 처음에는 그랬습니다. 그런데 Jenkins처럼 오래 굴러온 프로젝트에서 눈에 띄는 동작 버그를 찾기란 쉽지 않았습니다. 이미 많은 사람이 오래 들여다본 코드이기 때문입니다.

 

방향을 조금 틀어 본 곳이 test 모듈이었습니다. Jenkins 저장소의 test 모듈에는 src/main이 없습니다. 오직 JenkinsRule 기반의 기능 테스트만 들어 있는 모듈입니다. 그래서 이 모듈에서 찾을 수 있는 결함은 "실행하면 실패하는 코드"가 아니라 다른 종류입니다. 테스트가 통과하지만, 그 통과가 실제로는 아무것도 보장하지 않는 경우입니다.

 

이런 결함은 CI에서 절대로 빨간불을 켜지 않습니다. 빌드는 초록색이고 단언 개수도 넉넉해 보입니다. 그래서 오히려 오래 남습니다. 이 글은 그런 종류의 빈칸 하나를 찾아 두 줄을 고쳐 올린 기여(https://github.com/jenkinsci/jenkins/pull/26980)에 대한 기록입니다. 변경량은 두 줄이고, 그 두 줄에 도달하기까지 확인한 것들이 이 글의 대부분을 차지합니다.

같은 줄이 두 번 있었습니다

제가 들여다본 파일은 test/src/test/java/hudson/logging/LogRecorderManagerTest.java이고, 그 안의 logRecorderCheckName() 테스트였습니다. 이 테스트는 @Issue("JENKINS-62472")가 달려 있는, 로그 레코더 화면의 폼 검증 동작을 지키는 테스트입니다.

 

테스트의 구조는 단순합니다. LogRecorder를 하나 만들고, doCheckName(name, level)을 로그 레벨별로 호출하면서 결과가 경고인지 정상인지를 확인합니다. 단언이 스무 줄 넘게 이어지는데, 읽어 보면 의도가 분명합니다. java.util.logging의 레벨 계층을 낮은 쪽부터 높은 쪽까지 차례로 훑어 가면서 각 레벨을 한 번씩 확인하려는 구성입니다.

 

그런데 그 열거 중간에 이런 두 줄이 나란히 있었습니다.

assertEquals(warning, testRecorder.doCheckName("", Level.FINER.getName()).toString());
assertEquals(warning, testRecorder.doCheckName("", Level.FINER.getName()).toString());

글자 단위로 완전히 같은 줄이 두 번입니다. 그리고 조금 아래, 이름이 비어 있지 않은 경우를 다루는 블록에도 같은 일이 있었습니다.

assertEquals(FormValidation.ok(), testRecorder.doCheckName("a", Level.FINER.getName()));
assertEquals(FormValidation.ok(), testRecorder.doCheckName("a", Level.FINER.getName()));

같은 입력을 두 번 넣으면 단언 수는 늘지만 새로 확인되는 것은 없습니다. 그러니 이 두 자리는 원래 다른 값이 들어가야 했던 자리로 보였습니다.

 

무엇이 들어가야 했는지는 앞뒤 줄이 알려 줍니다. 위쪽은 ALL, FINEST, FINER로 올라오고, 아래쪽 블록은 CONFIG, INFO, WARNING, SEVERE, OFF로 이어집니다. java.util.logging.Level에서 FINER와 CONFIG 사이에 있는 표준 레벨은 FINE 하나뿐입니다. 열거하려던 목록에서 FINE만 빠져 있었던 것입니다.

하필 빠진 값이 경계였습니다

여기까지는 "중복된 줄이 있네" 정도의 이야기입니다. 이 자리를 채울 가치가 있는지 판단하려면 테스트가 지키려는 프로덕션 코드를 봐야 했습니다.

 

core/src/main/java/hudson/logging/LogRecorder.java의 doCheckName은 이렇게 분기합니다.

if ((Util.fixEmpty(level) == null || Level.parse(level).intValue() <= Level.FINE.intValue())
        && Util.fixEmpty(value) == null) {
    return FormValidation.warning(Messages.LogRecorder_Target_Empty_Warning());
}

로거 이름을 비워 둔 채로 낮은 레벨을 기록하려고 하면 경고를 띄우는 검증입니다. 로그 이름을 지정하지 않으면 모든 로거가 대상이 되는데, 거기에 FINE 이하의 상세한 레벨을 걸면 로그가 감당하기 어려울 만큼 쏟아질 수 있기 때문입니다. 사용자에게 "정말 이렇게 할 것이냐"고 알려 주는 성격의 경고입니다.

 

주목한 것은 조건식의 모양이었습니다. <= Level.FINE.intValue()입니다. 즉 FINE은 경고를 내는 구간과 내지 않는 구간이 갈리는 바로 그 지점입니다. Level의 정수값을 나열해 보면 FINEST가 300, FINER가 400, FINE이 500, CONFIG가 700입니다. 조건이 <=이므로 500은 경고 쪽에, 700은 정상 쪽에 들어갑니다.

 

그렇다면 이 조건이 언젠가 <=에서 <로 바뀌는 실수가 생겼을 때, 그것을 잡아낼 수 있는 입력은 정확히 FINE 하나뿐입니다. FINER(400)는 <로 바뀌어도 여전히 경고 쪽이고, CONFIG(700)는 어느 쪽이든 정상입니다. 경계에 정확히 걸리는 값만 부등호의 변화를 감지합니다.

정리하면, 이 테스트는 스무 줄 넘는 단언으로 표준 레벨을 훑으면서도 정작 부등호가 의미를 갖는 유일한 값을 빠뜨리고 있었습니다.

실수인지 의도인지부터 확인했습니다

여기서 바로 고치고 싶었지만, 한 단계를 더 두기로 했습니다. 오픈소스에서 남의 코드를 "실수"라고 단정하는 것은 조심스러운 일입니다. 겉보기에 이상한 코드가 사실은 의도된 경우를 여러 번 봤기 때문입니다. 예를 들어 어떤 값을 일부러 빼 둔 것일 수도 있고, 그 레벨에서만 다른 동작이 있어 별도 테스트로 뺐을 수도 있습니다.

 

확인한 것은 세 가지였습니다.

 

첫째, 이 줄들이 언제 들어왔는지 이력을 봤습니다. 두 개의 FINER 중복은 로그 레코더 화면을 개편한 커밋에서 함께 들어왔습니다. 레벨 목록을 새로 나열하는 과정에서 한 번에 생긴 중복이었고, 한쪽만 나중에 추가된 흔적은 아니었습니다. 복사·붙여넣기 과정에서 상수를 바꾸는 것을 잊은 형태에 가까웠습니다.

 

둘째, FINE을 일부러 제외했다는 근거가 있는지 찾았습니다. 이 자리를 설명하는 주석도, 현재 동작을 고정해 두는 다른 테스트도 없었습니다. 제외를 의도했다고 볼 만한 흔적은 나오지 않았습니다.

셋째, 고쳤을 때 테스트가 통과하는지를 코드로 먼저 따져 봤습니다. 이름이 비어 있고 레벨이 FINE이면 500 <= 500이 참이므로 경고가 나옵니다. 이는 앞 블록의 기대값과 같습니다. 이름이 "a"이면 레벨과 무관하게 이름이 비어 있지 않으므로 정상이 반환됩니다. 이 역시 뒤 블록의 기대값과 같습니다. 즉 이 변경은 "깨진 테스트를 고치는" 변경이 아니라 통과하던 테스트가 실제로 확인하는 범위를 넓히는 변경이었습니다.

 

이 구분이 중요하다고 생각했습니다. 리뷰어 입장에서는 "지금도 통과하는데 왜 바꾸느냐"가 첫 질문이 되기 때문입니다. 그 답이 "빠진 입력이 하필 프로덕션 분기의 경계값이라서"가 되어야 설득력이 생깁니다.

 

마지막으로 같은 수정을 이미 올린 사람이 있는지 검색해 봤습니다. 열려 있는 중복 PR은 없었습니다.

두 줄을 바꾸고, 그것을 실제로 실행했습니다

실제 변경은 두 줄의 상수를 바꾼 것이 전부입니다.

- assertEquals(warning, testRecorder.doCheckName("", Level.FINER.getName()).toString());
+ assertEquals(warning, testRecorder.doCheckName("", Level.FINE.getName()).toString());
...
- assertEquals(FormValidation.ok(), testRecorder.doCheckName("a", Level.FINER.getName()));
+ assertEquals(FormValidation.ok(), testRecorder.doCheckName("a", Level.FINE.getName()));

기존 단언들이 쓰던 Level.X.getName() 관용구를 그대로 따랐고, 새 헬퍼나 import는 추가하지 않았습니다. 형제 줄과 다른 모양으로 쓰면 그 자체가 리뷰에서 질문을 만듭니다. 여기서는 굳이 다르게 쓸 이유가 없었습니다.

 

정작 시간을 쓴 것은 실행 쪽이었습니다. Jenkins의 CONTRIBUTING.md는 테스트 프로파일이 세 가지라고 안내합니다. light-test는 단위 테스트만, smoke-test는 단위 테스트에 일부 기능 테스트를, all-tests는 재실행을 포함해 전부 돌립니다. 처음에는 빠른 light-test로 돌려 놓고 통과했다고 생각했는데, 제가 고친 테스트는 기능 테스트인 test 모듈에 있습니다. light-test에서는 이 모듈의 테스트가 건너뛰어집니다. 즉 초록색이 떴어도 제 변경 줄은 한 번도 실행되지 않은 상태였습니다.

 

이것을 알아차린 뒤에는 프로파일 없이 대상 테스트를 지정해서 실제로 돌렸습니다.

mvn -pl test -am test -Dtest='LogRecorderManagerTest#logRecorderCheckName' -DskipTests=false

결과는 Tests run: 1, Failures: 0, Errors: 0, Skipped: 0이었습니다. PR 템플릿의 Testing done 항목은 "최소한 컴퓨터가 변경된 줄을 실행했다는 증거"를 요구합니다. 그 문장을 읽고 나서야 제가 방금 무엇을 놓칠 뻔했는지 이해했습니다. 통과 표시를 근거로 삼기 전에, 그 표시가 무엇을 실행한 결과인지를 먼저 확인해야 했습니다. 비어 있는 경계 테스트를 찾아 놓고 정작 저도 비슷한 방식으로 안심할 뻔했던 셈입니다.

기여 규칙을 하나씩 맞춰 나갔습니다

코드보다 규칙 쪽에서 배운 것이 많았습니다. Jenkins의 CONTRIBUTING.md와 PR 템플릿에서 확인한 내용 중, 이번 변경에 실제로 적용된 것들을 정리해 둡니다.

 

기준 브랜치는 Weekly 릴리스를 향하는 master입니다. master에 직접 커밋하지 말고 작업 브랜치를 만드는 것이 권장됩니다. 빌드에는 JDK 21 또는 25가 필요합니다. 저는 test/logrecorder-checkname-fine-level이라는 브랜치를 따서 커밋 하나만 올렸습니다.

 

PR 제목은 영어 명령형 문장으로 씁니다. 이 PR의 제목은 Test the FINE log level boundary in LogRecorderManagerTest입니다. 처음에는 "Fix duplicated assertion"처럼 쓸까 했는데, 이 변경이 실제로 하는 일은 중복을 지우는 것이 아니라 경계 하나를 검증 대상에 넣는 것이라서 제목도 그 쪽으로 맞췄습니다. 제목이 changelog 문구로도 읽힐 수 있다는 점을 생각하면, 무엇이 달라졌는지를 그대로 적는 편이 낫다고 판단했습니다.

 

PR 템플릿의 섹션은 지우면 안 됩니다. 템플릿 맨 위에 이 점이 강조되어 있고, 이유도 적혀 있습니다. changelog 생성기를 비롯한 도구들이 이 섹션 구조를 기계로 읽기 때문입니다. 해당 사항이 없는 섹션도 지우지 말고 그대로 두라고 적혀 있습니다. 그래서 UI 변경이 없는데도 스크린샷 섹션과 그 아래 Before·After 소제목을 그대로 두고 해당 없음을 뜻하는 N/A만 적었고, 업그레이드 가이드 항목에도 같은 N/A를 남겼습니다.

 

changelog 카테고리는 /label 명령으로 답니다. 템플릿에는 bug, rfe, regression-fix, internal, dependencies, skip-changelog 등 선택지가 나열되어 있습니다. 이번 변경은 프로덕션 동작을 전혀 바꾸지 않는 테스트 전용 변경이라 사용자에게도 플러그인 개발자에게도 알릴 내용이 없습니다. 그래서 /label skip-changelog를 달고, changelog 항목에는 해당 없음을 적었습니다.

 

제출자 체크리스트에는 "자동 테스트가 있거나, 없다면 그 이유를 설명한다"는 항목이 있습니다. 이번 건은 변경 자체가 테스트이므로 이 항목은 자연스럽게 충족되었지만, 그래도 실행 명령과 결과를 본문에 적어 두었습니다.

 

체크리스트에는 API 쪽 항목도 있습니다. 새로 추가되는 public 클래스·필드·메서드에는 @Restricted를 붙이거나 @since TODO Javadoc을 달고, 새 deprecation에는 @Deprecated(since = "TODO")나 @Deprecated(forRemoval = true, since = "TODO")를 답니다. 이번 변경은 테스트 파일 한 개, 두 줄이고 프로덕션 API를 건드리지 않아 모두 해당 없음이었지만, 해당 없음이라는 결론도 확인을 거쳐서 적어야 한다는 점은 이번에 몸으로 익혔습니다.

 

머지 절차도 문서에 적혀 있습니다. 보통 리뷰어 승인 두 건과 요청된 변경 없음을 확인하고, 다른 사람이 의견을 낼 시간을 조금 더 둔 뒤에 머지합니다. 이 PR도 ready-for-merge 라벨이 붙은 뒤 머지되었습니다.

 

한 가지 더 눈에 들어온 것은 리뷰에 걸리는 시간이었습니다. CONTRIBUTING.md는 사흘이 지나도 피드백이 없으면 @jenkinsci/core-pr-reviewers를 멘션해도 된다고 안내합니다. 뒤집어 말하면 그 정도는 기다리는 것이 보통이라는 뜻입니다. 처음에는 이 속도가 답답하게 느껴졌습니다. 고칠 곳을 여러 개 찾아 두면 한꺼번에 올리고 싶어지기 때문입니다. 다만 한 건씩 결과를 확인하고 다음을 올리는 쪽으로 가다 보니, 그 편이 제게도 낫다는 생각이 들었습니다. 여러 건이 동시에 열려 있으면 각각에 달린 지적을 소화할 시간이 부족해집니다.

두 줄에서 남은 것

머지된 변경은 두 줄입니다. 숫자로만 보면 내세울 것이 없는 기여입니다. 그런데 그 두 줄에 이르기까지 한 일을 되짚어 보면, 제가 평소 회사 코드에서 잘 하지 않던 것들이 섞여 있었습니다.

 

먼저 테스트를 "통과 여부"가 아니라 "무엇을 확인하는가"로 읽는 연습이 됐습니다. 단언이 많다고 촘촘한 테스트가 아니고, 같은 입력을 여러 번 넣은 단언은 개수만 늘립니다. 반대로 잘 고른 입력 하나가 부등호 하나의 변화를 잡아냅니다. 어디에 경계가 있는지는 프로덕션 코드를 봐야 알 수 있으니, 테스트를 볼 때 대응하는 구현을 같이 여는 습관이 생겼습니다.

 

다음으로, 고치기 전에 "이게 정말 실수인가"를 확인하는 절차를 두게 됐습니다. 이력을 보고, 설명하는 주석이나 다른 테스트가 있는지 찾고, 고쳤을 때 결과가 어떻게 되는지를 코드로 먼저 따져 보는 일입니다. 이 과정에서 후보를 접은 적도 있습니다. 비어 있는 catch 블록을 발견해서 결함인 줄 알았는데, 동시성 테스트에서 스레드 중단을 일부러 무시하는 정상적인 패턴이었습니다. 남의 코드를 성급히 결함이라 부르지 않는 편이 좋다는 것을 그 때 배웠습니다.

 

마지막으로, 규칙을 읽는 일 자체가 기여의 일부라는 것입니다. 어떤 프로파일이 어떤 모듈을 건너뛰는지, 템플릿 섹션이 왜 기계로 읽히는지, 라벨 하나가 어디에 쓰이는지는 코드만 봐서는 알 수 없습니다. 문서에 적혀 있고, 읽으면 알 수 있습니다. 저는 그 중 하나를 놓쳐서 실행되지도 않은 초록불을 근거로 삼을 뻔했습니다.

 

작은 기여 한 건을 끝까지 끌고 가 보니, 배움의 대부분이 변경량과 무관한 자리에 있었습니다. 다음 건에서는 이번에 확인한 것들을 처음부터 순서대로 밟아 볼 생각입니다. 아직 익숙하지 않은 영역이 훨씬 많고, 그래서 당분간은 한 번에 한 건씩 천천히 가려 합니다.

출처 PR: https://github.com/jenkinsci/jenkins/pull/26980