MySQL에서 특정 쿼리가 얼마나 많은 시간이 걸렸는지 확인하려면 프로파일링(profiling) 정보를 활용해야 합니다. 프로파일링 정보는 현재 세션에서 실행된 각 구문의 리소스 사용량과 소요 시간을 보여주는 유용한 도구로, SHOW PROFILE 및 SHOW PROFILES 구문을 통해 조회할 수 있습니다.
1. 프로파일링 세션 변수 활성화
프로파일링 관련 구문을 실행하기 전에 먼저 세션 변수 profiling을 1로 설정해야 합니다. 아래와 같이 입력하면 됩니다.
mysql> set profiling = 1; Query OK, 0 rows affected (0.00 sec)
2. SHOW PROFILES로 전체 쿼리 목록 확인
프로파일링을 활성화한 후 SHOW PROFILES 구문을 실행하면, 서버로 전송된 최근 쿼리 목록과 함께 각 쿼리의 고유 ID(Query_ID)와 실행 시간(Duration)이 표시됩니다.
mysql> show profiles; +----------+------------+--------------------------------------+ | Query_ID | Duration | Query | +----------+------------+--------------------------------------+ | 1 | 0.01602200 | drop table if exists t1 | | 2 | 0.57223450 | create table t1(id int) | | 3 | 0.00015425 | show profile for query1 | | 4 | 0.22945050 | create table e1(id int) | | 5 | 0.09977025 | insert into e1(id) values(3),(4),(5) | +----------+------------+--------------------------------------+ 5 rows in set (0.00 sec)
3. SHOW PROFILE로 특정 쿼리의 상세 시간 분석
전체 목록이 아니라 특정 쿼리의 소요 시간만 자세히 확인하고 싶다면, SHOW PROFILE FOR QUERY 쿼리번호 형식으로 구문을 실행하면 됩니다. 예를 들어 Query_ID가 5인 쿼리를 분석하면 다음과 같은 결과가 출력됩니다.
mysql> show profile for query 5; +------------------------------+--------------+ | Status | Duration | +------------------------------+--------------+ | starting | 0.000138 | | checking permissions | 0.000024 | | Opening tables | 0.000057 | | System lock | 0.035186 | | init | 0.000035 | | update | 0.021484 | | Waiting for query cache lock | 0.000021 | | update | 0.000005 | | end | 0.000024 | | query end | 0.042700 | | closing tables | 0.000017 | | freeing items | 0.000076 | | logging slow query | 0.000003 | | cleaning up | 0.000002 | +------------------------------+--------------+ 14 rows in set (0.00 sec)
위 결과를 보면 해당 INSERT 쿼리가 실행되는 동안 권한 검사, 테이블 열기, 시스템 락 대기, 실제 업데이트 처리 등 각 단계별로 얼마나 시간이 소요되었는지 세부적으로 파악할 수 있습니다. 이를 통해 쿼리 성능 병목 지점을 정확하게 진단하고 최적화 방향을 잡는 데 큰 도움이 됩니다.