RedisCommandExecutionException 오류 발생!
며칠 전, 내가 개발한 기능과 관련하여 Redis 저장 시 오류가 발생하였다.
해당 기능을 간단히 설명하자면 현재 시간과 자정의 시간을 비교하여 초 차이만큼을 TTL로 설정하는 특수한(?) 스펙을 가지고 있다.
그래서 6시에 API 요청을 하는 사용자와 9시에 API 요청을 하는 사용자가 서로 다른 TTL을 가지게 된다.
데이터독을 살펴보니 23시 59분 59초에 조회한 사용자에게서 해당 오류가 발생했다.
사실 이 부분에 있어서 테스트를 분명 작성해두었는데 오류가 발생해서 조금 당황스러웠다.
다행히도 자정 이후에 다시 시도하여 이슈가 해결은 되었으나
점점 해당 기능을 사용하는 사용자가 많아지면 동일한 이슈가 또 발생할 가능성이 높았기 때문에 원인을 분석하고, 수정을 진행했다.
우리는 보통 구글링을 통해 원인과 해결방법을 모두 찾기 마련인데, 공식 문서를 활용하여 문제를 해결한 경험을 공유해 보고자 글을 작성하게 되었다.
1. 오류 원인 찾기
사실 RedisCommandExecutionException 오류를 처음 보아서 당황스러웠다.
그래서 우선 요즘 다시 신뢰성이 떨어지고는 있지만 그래도 나보다는 믿음직스러운 chatGPT에게 물어보았다.
RedisCommandExecutionException: ERR invalid expire time in setex 오류는 Redis의 setex 커맨드를 실행할 때,
expire time 파라미터의 값이 올바르지 않을 때 발생하는 오류입니다.Redis의 setex 커맨드는 특정 key에 대한 값을 설정하고, 해당 key의 TTL을 동시에 설정하는 기능을 수행합니다.
이때 expire time 파라미터는 TTL을 지정하는 데 사용되는데, 만약 이 값이 0보다 작거나 31,536,000보다 큰 경우에는
"ERR invalid expire time in setex" 오류가 발생합니다.이 오류와 관련된 자세한 내용은 Redis의 공식 문서인 https://redis.io/topics/errors#invalid-expire-time-in-setex
에서 확인할 수 있습니다. 해당 문서에서는 Redis에서 발생하는 다양한 오류에 대한 내용과 해결 방법을 제공하고 있습니다.
chatGPT 뿐만 아니라 구글에 검색해 보아도 invalid expire time, 즉 당시 계산된 TTL에 문제가 있어 발생한 이슈였다.
(링크를 삭제한 EU... 궁금하면 복붙 해보세요 ㅎㅎ)
2. LocalDateTime.now() 의 함정에 빠졌다?!
흔히 다들 현재 시간 정보를 가져오기 위해 LocalDateTime.now()를 많이 사용할 것이다.
하지만 이런 LocalDateTime 클래스의 now() 메서드를 살펴보면 조그만(?) 함정 아닌 함정을 발견할 수 있다.
/**
* Obtains the current date-time from the specified clock.
* <p>
* This will query the specified clock to obtain the current date-time.
* Using this method allows the use of an alternate clock for testing.
* The alternate clock may be introduced using {@link Clock dependency injection}.
*
* @param clock the clock to use, not null
* @return the current date-time, not null
*/
public static LocalDateTime now(Clock clock) {
Objects.requireNonNull(clock, "clock");
final Instant now = clock.instant(); // called once
ZoneOffset offset = clock.getZone().getRules().getOffset(now);
return ofEpochSecond(now.getEpochSecond(), now.getNano(), offset);
}그렇다. LocalDateTime 을 사용하게 되면 시/분/초뿐만 아니라 나노초 단위까지 저장한다.
또한 당시 TTL을 계산하기 위해 내가 구현한 코드는 아래와 같았다.
private fun calculateTTL(): Long {
val startAt = LocalDateTime.now()
val endAt = startAt.with(LocalTime.MIDNIGHT) + Duration.ofDays(1)
return Duration.between(startAt, endAt).seconds
}현재 시간과 현재 시간 기준 자정에 해당하는 시간의 시간 차이를 계산하여 초 단위로 반환하고 있다.
그러므로 요청 당시의 시간이 23시 59분 59.1초인 경우 TTL이 0초가 되고,
레디스에 저장시 RedisCommandExecutionException 오류가 발생하게 된 것이다.
3. 테스트는 왜 통과했을까?
사실 그런데 여기서 하나의 의문이 생겼다. 개발 당시에도 23시 59분 59초, 00시 00분 01초에 대한 경계값 테스트를 작성하였지만 잘 통과했었다는 점이다.
약간의 의문을 가지고 다시 테스트 코드를 살펴보니 문제를 바로 알 수 있었다.
기준 시작 시간 정보를 LocalDateTime.now()로 가져오다 보니 테스트에서는 실제 구현된 코드를 활용한 검증이 불가능했기 때문에,
실제 메서드를 호출하지 않고 LocalDateTime.of()를 적용했던 것이 문제였다.
context("23시 59분 59초이면") {
it("자정과의 차이는 1초 이다") {
val startAt = LocalDateTime.of(2023, 1, 1, 23, 59, 59)
val endAt = startAt.with(LocalTime.MIDNIGHT) + Duration.ofDays(1)
val result = Duration.between(startAt, endAt).seconds
result shouldBe 1
}
}
테스트 코드의 LocalDateTime.of(2023, 1, 1, 23, 59, 59)를 바로 LocalDateTime.of(2023, 1, 1, 23, 59, 59, 500)로 수정했더니 바로 실패하는 것을 확인할 수 있었다 😭
일종의 학습 테스트를 진행했던 것이었는데, 애초에 잘못 만들어진 테스트였던 것이다.
4. 문제 해결과 동시에 또 다른 문제 발견
그래서 LocalDateTime.now() 에서 나노초 단위를 버림 처리하는 truncatedTo(ChronoUnit.SECONDS)를 적용했다. 링크
또한 테스트에도 나노초를 추가한 시간에 대해 비교하는 테스트를 추가하는 것으로 문제는 해결되는 듯.. 하였으나
아까 위의 chatGPT가 알려준 링크를 기억하는가?
해당 링크는 클릭을 해보면 404 오류가 발생하고 조회가 되지 않는다.
공식 문서의 링크가 사라진 게 의아하여 redis 저장 시 사용한 SETEX에 대해 검색을 해보았다.
그랬다. 이 친구는 Redis 2.6.12 버전부터 deprecated, 이제 더 이상 사용하지 않는 기능이었다...
(참고로 기능이 적용된 repo의 Redis 버전은... 2.3.9이다 ^_^)
