모니터링 습관화하기

최근들어 근무시간에 틈이 날때마다 서버 모니터링을 습관화하려고 모니터링 솔루션을 이용해 자주 들여다보곤한다.

 

우리가 기대하는 서버의 히트맵은 아래와 같지만,

 

특정 API, 특정 로직, 특정 쿼리에 병목지점이 있다면 아래와 같이 히트맵이 위로 튀곤한다.

 

 

이걸 분석해서 병목지점을 해소하고 원인을 파악하는 재미가 은근 쏠쏠하다고 느꼈다.

 

대부분의 경우에는 정말 간단한 휴먼 에러의 경우가 많은 것 같은데, 이런 것들을 잡아내기 어려운 이유가 간헐적으로 발생하며 서버 모니터링을 주기적으로 하지 않는 이상 병목 지점이라는 것조차 느끼기 힘든 것 같다.

 

서버에 대해 에러 응답 비율이 높아지면 알림을 받을 수 있도록 별도의 설정을 하더라도 간헐적으로 발생하기 때문에 방치되는 경우가 많다.

 

 

---

 

실제로 모니터링 중 발견한 간헐적 slow api에 대한 사례를 하나 말해보자면

 

 

간헐적으로 Timeout이 발생하는 api를 발견하였는데, db에서 설정한 최대 timeout 설정을 초과하여 db단에서 slow query로 판단해 연결이 끊어지고 있었다.

 

특이한점은 매번 timeout이 발생하는 것은 아니고 어떨때는 빠르게 어떨때는 말도 안되게 느린 응답을 받았다.

 

해당 api는 단순히 JPA를 사용해 데이터를 원테이블과 히스토리 테이블에 insert만 하는 역할을 하고 있었는데 Spring Data JPA를 사용하고 있었기에 JpaRepository에서 제공되는 save() 메서드를 호출하고 있었다.

 

여기서 예상되는 한가지 병목 지점이 있었는데, JPA를 사용한 사람이라면 아마 알고 있을듯하다.

 

JpaRepository에는 save()만 제공될뿐 update()는 제공되지 않는다. 수정시에도 save(entity)를 호출하면 된다.

이는 save() 내부 동작과정을 보면 알 수 있듯이 EntityManager는 save() 메서드가 호출되면 먼저 해당 엔티티가 이미 존재하는 엔티티인지 아닌지를 판단하기 위해 PK를 사용해 DB에 select 쿼리를 먼저 날린다.

 

즉, 엔티티에 매핑된 PK가 없다면 insert 이미 존재한다면 update로 정리할 수 있겠다.

 

따라서, 엔티티에 PK가 잘못매핑되었고 그로 인해 DB Full Scan이 발생하는데 운이 좋으면 빠르게 조회가 될 것이고 운이 나쁘면 느리게 조회가 되지 않을까라는 예상을 할 수 있었다.

 

실제로 히스토리 테이블의 PK는 (id + 이력일시)가 복합키로 설정되어 있는데 엔티티에는 PK가 (id + 수정일시)로 설정되어 있었다.

 

히스토리 테이블의 경우에는 별도의 조회없이 무조건 insert가 되어야했기에 해당 부분만 MyBatis를 사용해 직접 Insert하도록 변경하였고 수정 후의 결과는 아래와 같다.

 

---

 

 

위 사례는 2020년에 개발되어 만 3년동안 발견되지 않은채 간헐적인 timeout을 발생시키고 있었는데 이런 나쁜 냄새를 풍기는 병목 지점을 제거하기 위해서 팀 레벨에서 활발한 코드리뷰도 필요하겠지만 배포 이후 지속적이고 꾸준한 모니터링을 통해 개선해나가야한다는 것을 이번기회에 더더욱 느낄 수 있었다.

 

이런게 바로 진짜 운영이자 유지보수에 해당하는 영역이 아닐까 싶다.