스프링부트 버전업 이슈 LocalTime 값을 DB에서 조회시 Invalid value for NanoOfSecond 오류 분석

현상 

스프링부트 버전업 이후 LocalTime 필드를 가지는 Entity를 조회할 때, 아래와 같이 LocalTime의 nano second에 음수 값이 할당되어 에러가 발생했음.

PostgreSQL DB에 저장된 TIME 타입 컬럼을 java의 LocalTime 변환 시에 아래와 같은 오류 발생

java.time.DateTimeException: Invalid value for NanoOfSecond (valid values 0 - 999999999): -843000000

LocalTime 변환 시, 나노초 값으로 음수가 유입되면서 발생

원인

변경된 스프링부트 버전업에 대응되는 하이버네이트 버전에서 변경이 있었고 이 부분에 버그가 존재했음.

• 스프링 부트 버전: 2.6.4 ➡️ 3.2.4
• 하이버네이트 버전: 5.6.5 ➡️ 6.5.5

하이버네이트 버전이 변경되면서 DB에 LocalTime 저장 로직이 변경됨.

• LocalTime → Time 객체로 변환하는 로직이 변경됨 
• 5.6.5 버전에서는 ms 를 버린채(=0 고정) Time 객체를 생성했으나 
• 6.5.5 버전에서는 LocalTime의 nano second에서 ms (소숫점 3자리)를 추출하여 Time 객체에 할당해줌. 즉 ms가 0이 아님
• DB에 저장할 때는 ms값을 잘 변환하여 실제 ms와 동일한 양수의 값으로 잘 저장된다.

DB에서 시간값을 조회한 후 Time을 LocalTime으로 변환할 때 버그가 존재함

• DB에서 시간 값을 읽어서 Time 객체를 생성하는 과정은 이상이 없음 
• Time 객체를 LocalTime 객체로 변환할 때, Time 객체로부터 ms를 계산하여 초기화하고있는데 time 객체의 getTime 메서드 값이 음수가 나오는 경우가 있음 
  • ms 계산 로직: time.getTime() % 1000 
• LocalTime은 날짜 정보(년,월,일)를 가지지 않아서 default 날짜(유닉스 시간(Unix time)인 1970년 1월 1일 00:00:00 UTC에서 년원일)가 임의로 지정됨. 
  • 1970년 1월 1일 00:00:00일 때 time.getTime() = 0 
• KST 타임존인 경우에는 UTC의 기준을 맞추기 위해서 9시간을 빼주게 되고 이때, 0시~9시 시간일 경우 time.getTime()은 음수가 되고 ms값도 음수가 됨

재현 조건

1. 타임존 설정
   • KST TimeZone인 경우에 DateTimeException 에러 발생
   • UTC TimeZone인 경우에는 에러 발생 X
2. 특정 시간대
   • 0 ~ 8시: DateTimeException 에러 발생 
   • 9 ~ 23시: 에러 발생 X
3. 나노초 여부
   • 나노초 O: DateTimeException 에러 발생 
   • 나노초 X: 에러 발생 X 
4. 나노초의 소수점 자릿수
   • 소수점 3자리 존재: DateTimeException 에러 발생
   • 소수점 3자리 이후(4~9자리) 존재: 에러 발생 X (소수점 4번째 자리가 5이상인 경우 반올림되어서 예외 발생)

원인 분석 상세 

• LocalTime 객체는 원래부터 ms를 가지고있다. 
• 1970년 이전은 timestamp가 음수 
• Localtime 은 날짜가 없기 떄문에 timestamp계산을 위해 1970으로 날짜 셋팅 
• Long type의 timestamp는 zone이 없기때문에 UTC TimeZone을기본으로 사용 
• 우리시스템은 서울이므로 -9시간을 해줌. 1970/1/1 00:09:00 - 9시간 -> 음수발생. 하지만 ms를 사용하지 않아서 마지막은 000으로 끝나서 그동안 이슈없었음 우리에러는 timestamp에서 ms를 추출하기위해 timestamp % 1,000을 사용하는데 이게 음수여서 발생

✅ Application 에서 (PostgreSQL) DB로 시간을 저장하는 과정

LocalTime 타입을 DB에 저장할 때는 TimeJdbcType.getBinder 메서드를 호출하게된다. 이 내부에서 TemporalJavaType.unwrap 메서드를 호출하여 Time 객체로 변환한다. … ➡️ TimeJdbcType.doBind ➡️ LocalTimeJavaType.unwrap ➡️ new Time(time.getTime() + DateTimeUtils.roundToPrecision( value.getNano(), 3 ) / 1000000)

HikariProxyPreparedStatement.setTime ➡️ PreparedStatementSpy.setTime(index, time)

DB에 저장할 떄는 RdbmsSpecifics.formatParameterObject 메서드를 호출하여 (DML 쿼리를 위한) 문자열로 변경하여 new SimpleDateFormat(dateFormat).format(object) 를 호출하여  MM/dd/yyyy HH:mm:ss.SSS 문자열 포맷으로 파싱하여 저장한다. 이때 object로 들어가는 값은 LocalTimeJavaType.unwrap으로 생성한 Time 이다. 

실제로 저장하려고했던 LocalTime은 08:32:00.943476 으로 ms 까지 잘 변환된 것으로 보인다. (4번째 자리 반올림)

❌ DB에서 Application으로 시간값을 조회하는 과정

DB에 저장된 데이터를 읽어오는 경우 
TimeJdbcType.doExtract ➡️ LocalTimeJavaType.wrap 호출하여  LocalTime 으로 변환하게 된다.

Time 객체는 unwrap했을 때(Application → DB)와 동일한 값의 Time 객체를 생성했다. 하지만 ms를 구하는 로직에서 문제가있어 음수의 값이 도출되게 된다.

LocalTime은 날짜 정보(년,월,일)를 가지지 않지만 Time 계산을 위해서는 날짜 정보가 필요하다. 따라서 default 날짜(epochTime or 유닉스 시간(Unix time)인 1970년 1월 1일 00:00:00 UTC에서 년원일)을 임의로 지정해준다. 여기에서 KST 타임존인 경우에는 UTC의 기준을 맞추기 위해서 9시간을 빼주게되고 이때, epochTime은 음수가 나오게된다.   (위에서 언급한 유닉스 시간의 경우 0) LocalTime을 Time으로 변환하여 DB에 저장할 때는 문제가 없지만 Time을 LocalTime으로 변환하는 과정에서는 0 ~  UTC와 KST의 시간차이 - 1 시간인 경우에는 fastTime(Time 객체의 상태값) 이 음수가되는데 ms를 이 값에서 1000을 나눈 나머지로 계산하기 때문에 음수 ms가 발생하게된다.

참고로 해당 버그 fix된 것으로 보이지만 아직 release가 안된 상태이다. 
LocalTime 객체를 저장하거나 조회할 때는 nano seconds를 제거(or 0으로 초기화)하는 Converter를 구현하여 설정해주어서 저장 혹은 조회 시, nano second가 저장되지 않도록 임시 방편을 취했고 추후 버그 fix 버전으로 release되면 hibernate 버전 업을 진행하려고한다.