Engineering
1899-12-31T23:27:52.000+08:27:52의 정체
2023년 5월 15일
원문에서 보기 ↗
들어가며
안녕하세요. NHN Cloud의 다양한 서비스에서 공통적으로 사용되는 Framework(결제, 인증, 권한 등)를 개발하고 있는 프레임워크개발팀 박시우입니다. 이 글에서는 1900-01-01의 시간 오류와 관련하여, 우리가 흔히 알고 있는 시간과 오프셋(offSet)에 대한 해답을 얻기 위한 탐험기를 소개합니다.
Royal Observatory, Greenwich
(Source: https://pixabay.com/)
본격적으로 들어가기 전에 사진부터 살펴보시죠. '뭐야? 영국인 것 같은데 기술 블로그에서 웬 관광지 사진?'이라고 생각셨을 수도 있을 것 같은데요, 😅 사진 속 장소가 바로 오늘날 우리가 사용하는 시간이 정해진 기준점입니다.
맞습니다. 이 글에서는 최근 NHN Cloud 빌링에서 발생된 1900-01-01의 DateTime parsing 문제 , 그리고 잃어버린 30분에 대한 분석 내용과 디버깅하면서 알게된 정보에 대해 공유하고자 합니다. 좀 길더라도 재밌게 읽어 주시면 감사하겠습니다.
문제 발생(원인)
어느 날 프론트로부터 카운터 네임 호출 시 month From 값에 오류가 발생한다는 연락이 옵니다. NHN Cloud의 과금에 필요한 정보의 시간 범위는 특별한 경우가 아니면 1900-01-01 이 monthFrom으로, 2999-12-31이 monthTo로 설정되어 있습니다.
'타임존 세팅이 뭔가 깨졌나? 우리는 코드를 수정한 게 없는 것 같은데...'
여기서 눈치채신 분도 있겠지만 이 글의 주제는 시간에 관한 이야기입니다. 거두절미하고 단순히 머릿속으로 몇 가지 생각해 본 경우의 수를 토대로 코드를 보기 시작했습니다.
의심 포인트
제 머릿속에 떠오른 이슈가 될 만한 경우의 수는 4가지였습니다.
- DB에 Date 타입이 실수로 변경되었거나 데이터가 잘못 insert 되어 있을 것. 또는 MySQL의 버전을 업그레이드해 Date에 대한 처리 방식이 바뀐 것일까?
- mybatis resultMap 맵핑 시 무언가 업데이트 작업이 있으면서 버그가 생겼을 것.
- Boot 버전업 시 Date에 대한 변환이 무언가 잘못되었을 것.
- 프론트에서 KST 처리를 잘못하는 경우가 발생했을 것.
우선 무죄 추정 원칙에 따라 4번은 배제하고 위의 3가지 경우의 수로 디버깅을 시작합니다.
분석
바뀐 게 없는데...😭 멀쩡하게 설정된 카운터 네임의 적용 기간이 왜 프론트에서 INVALID FORMAT으로 나오는 걸까요? 무엇이 변경되었는지부터 찾기 시작합니다. DB상 Date로 정상적으로 들어가 있고 (1900-01-01) mybatis를 통해 값을 가져와 잘 처리하는 것 같은데 말이죠.
파고들어 보기
경우의 수 1) DB에 Date 타입이 실수로 변경되었거나 데이터가 잘못 insert되어 있을 것. 또는 MySQL의 버전을 업그레이드해 Date에 대한 처리 방식이 바뀐 것일까?
DB에 Date로 1900-01-01이 들어 있고, 조회 쿼리 요청 시 정상적으로 값은 가져오고 있었습니다. 
테이블 확인 결과 변경점도 없고, MySQL 업데이트 사항도 없었습니다.
→ 1번 의심 포인트 제거 완료
경우의 수 2) mybatis resultMap 맵핑 시 무언가 업데이트 작업이 있으면서 버그가 생겼을 것.
1번에서 끝나길 바랐지만, 이제부터는 긴 디버깅 싸움을 시작해야 합니다. ibatis.binding과 ibatis.executor.resultset에 맵핑하는 과정을 디버깅하기 시작했습니다. DB 데이터를 mybatis로 읽어 들이는 과정은 다음과 같습니다.
- MapperProxy 클래스를 내부에 InvocationHandler의 구현체인 invoke()를 호출하게 되고 이때 Object에 args에 대한 변환 작업이 시작됩니다.
- 이후 MapperMethod 내 execute() 실행 시 각 DDL에 따라 case별로 구분되며 로직이 수행됩니다.
다음으로 MapperMethod에서 얻은 command 값(쿼리 로직, type (SELECT))을 가지고 sqlSession에 selectList를 호출합니다. 이때 parameter 로 DB 에서 얻어온 값들이 각각 Map으로 구성됩니다. 이 정보를 모두 얻은 뒤 ResultSetHandler를 호출하여 applyMapping 작업을 시작하고 각각의 Object(예를 들어 month_from, month_to 등)는 MetaObject로 각 value 값들을 가지고 오게 됩니다.
이후에는 당연하듯 ObjectWrapper.set을 통해 property와 value로 객체를 생성해 냅니다.
눈치채셨나요? 이쯤 왔을 때 저도 눈치챘고, 마음 속에 슬픔이 생겼습니다. 😭
최종 BeanProperty에 Set 하는 과정까지 데이터가 1900-01-01 그대로 담겨 있기 때문이었습니다. 결국 MethodInvoker까지 무사히 전달되었고 target으로 잡힌 month_from은 너무나 멀쩡하게 1900-01-01을 나타내고 있었습니다. 최종 Billing 코드 단까지 진입하여 객체를 생성하는 과정에서 setMonthFrom 까지조차도 1900-01-01은 존재했습니다.
→ 2번 의심 포인트 아쉽지만 제거 완료
경우의 수 3) Boot 버전업 시 Date에 대한 변환이 무언가 잘못되었을 것.
아무리 생각해도 이상했습니다. 😥 버전을 업그레이드했고, 최신화했다고 한들 설마 날짜와 시간에 대한 게 변할 수가 있나? '우리나라는 UTC+9(Timezone Asia/Seoul)을 사용한다.' 이것은 '빨간불엔 멈추고 초록불엔 건넌다'처럼 너무 자연스럽게 머릿속에 있는 내용인데...🤔 '이게 건들여질 수 있나?'라는 생각이 들었습니다.
mybatis 문제가 아니니, 이제 코드에 문제가 될 만한 부분을 찾습니다.
이 단계까지 디버깅이 올 줄 몰랐고, 또 하나의 의심 포인트가 생겼습니다. Date to DateTime? 여기서 문제가 될까? 일단 보는 게 우선이니 간단하게 테스트 코드를 하나 만들어 보았습니다.
오...프론트에서 말한 invalid가 발생했습니다. 그런데 왜 32분 8초가 차이 날까요? 이러면 또 한 번의 긴 여정을 떠나야 합니다. 이제 Git의 커밋 이력을 다 살펴봅니다.
발견
아... Boot 버전업할 때 하는 김에 라이브러리들도 모두 최신화하였는데 그때 joda-time도 업그레이드했었습니다. 이제 얼추 윤곽이 드러났으니, 버전이 어떻게 바뀌었는지 비교해 보면 될 것 같았습니다.
joda-time의 버전은 2.3 → 2.12.1로 변경되었습니다. 그럼 이 버전 사이에 어떤 일이 있었다는 것이고, 그걸 찾아내 수정하면 이 문제는 해결됩니다.
2.12.1 버전부터 디버깅을 시작합니다. 쭉 파고들며 1900-01-01을 밀리초로 환산하고, -2209021200000를 epoch time으로 환산해 보니...
- Your time zone: 1899년 12월 31일 일요일 오후 11:27:52 GMT+08:27
잡았습니다. 결국 여기가 문제였습니다. 그럼 이제 2.3 버전에서는 왜 되었는지 다시 확인하기 위해 버전을 돌려 봅니다.
2.3 버전에서도 동일한 작업을 수행합니다. 아마도 예상하건대 2.3 버전에서는 -2208988800이 나와야 할 것 같습니다. 그대로 테스트 코드를 돌려 봅니다.
+08:30? Asia/Seoul이 왜 08:30이지?
일단 원인은 알았습니다. 2.3에서는 +08:30으로 명시하고 정확히 30분 차이가 났기 때문에 변환 작업에 문제가 없었던 겁니다. 그럼 대체 +9가 아닌 +08:30이 되었는지, 어디부터 문제인지 확인해 보기 위해 테스트 코드를 조금 변형해 보았습니다.
다시 2.12.1로 돌아와서 테스트 코드를 수행했습니다. 
무언가 이상합니다. Timezone Asia/Seoul은 일본과 같이 UTC+9 입니다. 근데 1900년부터 1908년까지는 +9가 아닌 것을 발견할 수 있었습니다. 그럼 2023년까지 쭉 돌렸을 때, 이상한 값으로 들어간 연도는 다음과 같았습니다.
=========================== 문제가 되는 연도 ===========================
1900년 = 1899-12-31T23:27:52.000+08:27:52
1901년 = 1901-01-01T00:00:00.000+08:27:52
1902년 = 1902-01-01T00:00:00.000+08:27:52
1903년 = 1903-01-01T00:00:00.000+08:27:52
1904년 = 1904-01-01T00:00:00.000+08:27:52
1905년 = 1905-01-01T00:00:00.000+08:27:52
1906년 = 1906-01-01T00:00:00.000+08:27:52
1907년 = 1907-01-01T00:00:00.000+08:27:52
1908년 = 1908-01-01T00:00:00.000+08:27:52
1909년 = 1909-01-01T00:00:00.000+08:30
1910년 = 1910-01-01T00:00:00.000+08:30
1911년 = 1911-01-01T00:00:00.000+08:30
1912년 = 1912-01-01T00:30:00.000+09:00
1955년 = 1955-01-01T00:00:00.000+08:30
1956년 = 1956-01-01T00:00:00.000+08:30
1957년 = 1957-01-01T00:00:00.000+08:30
1958년 = 1958-01-01T00:00:00.000+08:30
1959년 = 1959-01-01T00:00:00.000+08:30
1960년 = 1960-01-01T00:00:00.000+08:30
1961년 = 1961-01-01T00:00:00.000+08:30
데이터를 추출해 보면 문제가 되는 부분이 몇 년씩 나오고 있습니다. 처음에 의심한 건 윤초를 잡기 위해 저렇게 이루어진 건가? 근데 'UTC가 태양계 시간의 오차 범위를 조절하기 위한 것이라면 연속 연도로는 하지 않을 텐데...'라는 생각이 들었고, 윤초 수정이 있었던 연도를 검색해 보았습니다. 
연도를 보면 알 수 있듯 윤초는 아닌 것 같습니다. 그럼 대체 쟤들은 무엇일까? 구글링해 보면 1900년 이전에는 LMT 정보가 고려되지 않았다고는 하지만 이건 1900년 이후이기 때문에 미스터리한 순간에 빠졌습니다. 여기서 포기하긴 좀 그러니까. 😪 (사실 원인은 알았기 때문에 버전을 돌릴까도 생각했지만...) 좀 딥하게 파고들어 보기로 합니다.
그럼 이제 시간의 기원을 찾아서...
+9는 그리니치 천문대 기준으로 동경 135도(일본)에 위치한 UTC 시간대를 따릅니다. 이게 결국 timezone이 Asia/Seoul은 +9의 값으로 계산되는것이고, 우리나라는 그리니치 천문대 기준으로 동경에 있기 때문에 9시간이 빠릅니다. 시차의 계산은 경(각도)을 기준으로 나누기 15를 하면 되는데, 우리는 135도이기 때문에 135/15=9가 되어 UTC +9가 되는 겁니다.
이곳이 GMT와 UTC의 기준인 그리니치 천문대의 위치입니다(영국 런던에 있습니다). 결국 동경/서경은 저곳을 기준으로 각도를 계산하게 됩니다. 
우리나라는 동경 135도로 일본과 같은 시간대를 사용하고 있습니다.
그럼 이제 의문점이 생기면서 역사를 좀 들여다볼 필요가 있습니다. 언제부터 우린 135도였나? 우린 누가 봐도 125도인데? 위키백과에 한국 표준시를 검색해 보면 다음과 같은 정보를 얻을 수 있었습니다.
음? UTC+08:30을 쓴 적도 있다고 합니다. (그럼 우리의 잃어버린 30분을 찾을 수 있을 것 같습니다.)
1434년 세종 UTC+08:28
1908년 UTC+08:30
1912년 UTC+09:00
1954년 UTC+08:30
1961년 UTC+09:00
아까 문제가 되었던 시간대를 다시 보겠습니다.
1900년 = 1899-12-31T23:27:52.000+08:27:52
1901년 = 1901-01-01T00:00:00.000+08:27:52
1902년 = 1902-01-01T00:00:00.000+08:27:52
1903년 = 1903-01-01T00:00:00.000+08:27:52
1904년 = 1904-01-01T00:00:00.000+08:27:52
1905년 = 1905-01-01T00:00:00.000+08:27:52
1906년 = 1906-01-01T00:00:00.000+08:27:52
1907년 = 1907-01-01T00:00:00.000+08:27:52
1908년 = 1908-01-01T00:00:00.000+08:27:52
1909년 = 1909-01-01T00:00:00.000+08:30
1910년 = 1910-01-01T00:00:00.000+08:30
1911년 = 1911-01-01T00:00:00.000+08:30
1912년 = 1912-01-01T00:30:00.000+09:00
1955년 = 1955-01-01T00:00:00.000+08:30
1956년 = 1956-01-01T00:00:00.000+08:30
1957년 = 1957-01-01T00:00:00.000+08:30
1958년 = 1958-01-01T00:00:00.000+08:30
1959년 = 1959-01-01T00:00:00.000+08:30
1960년 = 1960-01-01T00:00:00.000+08:30
1961년 = 1961-01-01T00:00:00.000+08:30
오 맞았습니다. 🤭
역사적으로 변경이 있는 것을 실제로 Timezone에서는 반영을 해 주고 있던 겁니다. 그럼 결론이 슬슬 보이기 시작합니다. 1900-01-01이 맵핑되지 않은 이유는 23:27:52로 초 단위까지 무언가 시간대가 꼬여 있었기 때문입니다.
+08:27:52라는 건 계산될 수 없기에 포맷팅이 안 되었던 것이고, 여기서 얻어갈 수 있는 정보는 DateTimeZone에 Asia/Seoul을 하는 것 자체가 역사적으로 UTC 변경점을 포함한다는 내용이,고 우리의 상식대로 +9로 강제로 하면 왠지 될 것 같습니다.
원하는 결과값이 출력되었습니다. 하지만 마냥 좋진 않았습니다. joda-time 2.3에선 그럼 왜 27분으로 안 나오지? 역사를 보면 1908년에 08:30으로 변경되었는데? joda 의 git 페이지에 가서 업데이트 이력을 살펴보았습니다. 
2014j로 08:30에서 08:27:52로 변경이 있었습니다. 무려 8년이나 되었네요. joda 2.3이 8년이 넘은 버전이었구나...😨
이로써 제가 가진 모든 의문점이 풀렸습니다. TimeZone의 Asia/Seoul은 현재는 +09:00이지만, 역사적으로는 +09:00이 아닌 적도 있었고, 그렇기 때문에 오늘날 1900-01-01의 +09의 잘못된 계산값이 나오게 된 것이었습니다.
마지막으로
그럼 joda는 이제 알겠고, java time은 어떨까? OffSetDateTime은 어떻게 될까? 궁금증이 생겨났습니다. java.time의 OffsetDateTime, ZoneDateTime 등도 혹시 다를까 하여 간단한 문제이니 테스트 코드로 실험을 진행해 봅니다. 
Document를 참조해 보면 java.time 역시 그리니치를 기준으로 잡고 있고 ISO-8601 달력 시스템을 기반으로 합니다. 그럼 차이가 없을 것 같은데...
그래도 LocalDateTime으로 1900-01-01을 지정하고, 돌려 보니 타임존 offSet만 다르게 표현될 뿐 1899년으로 가 버리진 않았습니다. 결과적으로 +08:27은 동일한 부분을 확인했습니다.
나가며
joda는 결국 tzdb를 반영하고, https://www.iana.org/time-zones에서 tzdb는 관리되고 있었습니다.
2014j 버전으로 IANA에서 Asia/Seoul에 대한 타임을 조정하는 작업이 있었고, 그게 반영된 이후 버전인 2.12.1을 사용하면서 문제가 발생한 케이스였습니다. 결국 +09:00으로 정확하게 사용하고자 한다면, 그리고 1970년 이전의 데이터를 다루어야 한다면 Asia/Seoul은 역사적 변경점을 알고 계셔야 합니다. 추가적으로 1970년 이전의 날짜는 가능하면 사용하지 않는 것이 좋겠습니다.
위 긴 이슈를 해결하기 위해 Joda-time의 버전을 롤백하는 것 대신 빌링의 코드상에 Asia/Seoul이 아닌 +09:00으로 맵핑하여 수정될 예정입니다. 이렇게 잃어버린 30분을 찾을 수 있게 되어 너무 기쁩니다. 어디선가 저와 같은 문제와 마주하셨을 때 이 글이 떠오르셔서 도움이 되었으면 좋겠습니다.
마지막으로 저 혼자만 재밌었던 긴 글을 읽어 주셔서 감사합니다.😅