jMeter를 통한 성능테스트 환경을 만들고, 에이징 테스트를 진행하고 있었다.
초반에는 무난하게 진행이 되는가 싶더니 다음날 확인하니 WAS는 괜찮았는데, DB서버의 CPU 사용량이 95% 가 넘어가며 숨을 헐떡이고 있었다.
DB 서버는 MariaDB 를 사용하고 있다.
문제를 잡기 위해 mysql slow query 옵션을 찾아 3초 이상 수행된 쿼리를 찾아보았다.
slow query 를 보기 위해선 /etc/my.cnf
를 수정 해야한다.
# slow_query 로깅할래(1)
slow_query_log=1
# 로그 저장할 곳
slow_query_log_file=/var/log/mysql-slow.log
# slow query logging 기준 시간 (3초)
long_query_time=3
# slow query 가 설정되어있는 지 확인하는 법
show variables like 'slow_query%';
+---------------------+-------------------------+
| Variable_name | Value |
+---------------------+-------------------------+
| slow_query_log | ON |
| slow_query_log_file | /var/log/mysql-slow.log |
+---------------------+-------------------------+
2 rows in set (0.001 sec)
# 확인
select * from mysql.slow_log;
나의 경우 select문이 주로 검출되었고, 해당 where절 검색조건에 index가 필요함을 알게 되었다.
# table에 index 걸기
# uniqid 라는 컬럼에 idx_uniqid 라는 이름의 index 생성하여 my_table 테이블에 거는경우
create index idx_uniqid on my_table (uniqid);
# table에 걸려있는 index 확인하기
show index from my_table;
+-----------+------------+-----------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| Table | Non_unique | Key_name | Seq_in_index | Column_name | Collation | Cardinality | Sub_part | Packed | Null | Index_type | Comment | Index_comment |
+-----------+------------+-----------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
| my_table | 0 | PRIMARY | 1 | id | A | 182304 | NULL | NULL | | BTREE | | |
| my_table | 1 | idx_uniqid | 1 | uniqid | A | 182304 | NULL | NULL | | BTREE | | |
+-----------+------------+-----------------+--------------+-------------+-----------+-------------+----------+--------+------+------------+---------+---------------+
실행할 쿼리 앞에 explain 을 걸면 optimizer의 실행계획을 알 수 있다.
느렸던 쿼리의 before, after 를 비교해보면 좋다.
explain select * from my_table where uniqid='someid';
+------+-------------+-----------+------+---------------+------------+---------+-------+------+-----------------------+
| id | select_type | table | type | possible_keys | key | key_len | ref | rows | Extra |
+------+-------------+-----------+------+---------------+------------+---------+-------+------+-----------------------+
| 1 | SIMPLE | my_table | ref | idx_uniqid | idx_uniqid | 77 | const | 1 | Using index condition |
+------+-------------+-----------+------+---------------+------------+---------+-------+------+-----------------------+
눈여겨 본 부분은
key(실제 사용한 index) 가 예상대로 잘 먹히는지
rows(쿼리 수행을 위해 mysql 이 예상하는 검색할 row 수 (추정치)) 가 확실히 줄어드는지
였다.
여기까지 해주니 CPU 사용량이 정상으로 돌아옴을 확인할 수 있었다.
like 연산은 나도 참 좋아하는 연산이다. 하지만 패턴 검색을 위해 양쪽으로 % 를 걸게되는 경우 인덱스를 타지 못한다.
생각해보면 당연하다. tree 를 타고 내려가는 기준이 안서니까.
실행 계획으로 확인해 보아도 좋다. 알고 사용하자.
일반적으로 cardinality가 높은 컬럼에 index를 걸어야 트리를 잘 만들것이고 log time의 이점을 잘 살릴 수 있을것이다.
당연히 맞는말이다.
그런데 이번 성능 개선을 위해 이것 저것 시도하며 낮은 카디널리티도 성능개선에 효과를 주는 것을 보았다.
그 이유는 valid 라는 카디널리티가 2밖에 안되는 Boolean 필드가 있었는데, 실제 DB 데이터가 where절 검색 조건으로 사용하는 id 한개당 생성된 데이터 1000개가 있었고, 이중 999개가 false 이고 하나가 true 인 상황이었기 때문에 의미가 있었다. (애초에 정상적이지 않은 부하 테스트 시나리오를 만든건 맞다...)
적어보니 당연한 말이긴 한데, 나는 카디널리티가 낮으면 무조건 큰 의미 없는 인덱스일줄 알았다.
일반적으로 맞는 소리지만 실제 데이터가 편중되어있는 경우 상황에 따라 의미를 가질수도 있겠다.
나는 hibernate 에서 뽑아주는 디버그용 로그에서 실제 날아간 쿼리를 뽑아서 실행계획을 확인하기 위해 exaplain 을 해봤다.
아래 설정과 더불어
# application.yml
logging.level:
org.hibernate.type: trace
아래 플러그인을 받아주면
# build.gradle
implementation 'com.github.gavlyukovskiy:p6spy-spring-boot-starter:1.5.6'
?=? 이렇게 나오는 hibernate log 에 실제 날아간 값을 확인할 수 있다
index가 뭔지 머릿속으로는 이해했으나 감을 못잡고 있었는데 실제 사용해 보며 극적인 성능 개선을 볼 수 있었고 쌓인 데이터 형식과 비교하여 인덱스를 어떻게 걸 것인지 느낄 수 있었다.
설계 시 인덱스에 대해 고민하자.