반응형
[출처] http://dba-jadelee.blogspot.kr/2014/10/mysql-innodb-status-monitoring.html
MySQL INNODB Status Monitoring
- 해당 STATUS출력내역은 각 상세내역 설명을 위해 특정장비를 기준으로 특정시점의 결과를 샘플링
- 세부적으로 설명한 부분도 있지만 직관적으로 상태정보를 보여주는 부분은 상세한 설명은 생략함. (이 부분들에 대한 추가적인 질문은 개인별로 문의하세요)
- 각 부분에 대한 간략한 기능적 설명이며 모니터링상 중요한 영역에 대한 코멘터리는 각 영역에 대한 설명 마지막 부분에 기재하였음.
-----------------------------------------------------------------
SQL> SHOW ENGINE INNODB STATUS\G
=====================================
131129 12:58:12 INNODB MONITOR OUTPUT <--- 분석시점에 대한 출력시간
=====================================
Per second averages calculated from the last 30 seconds <--- 분석에 대한 대상시간범위 (출력시간으로부터 *초 전까지의 범위)
----------------------------
BACKGROUND THREAD
----------------------------
InnoDB 메인 백그라운드 스레드의 작업실행 통계 : 각 숫자는 Innodb Engine이 시작된 이후부터의 카운트 값
srv_master_thread loops: 18613866 1_second, 18613864 sleeps, 1861347 10_second, 1755 background, 1739 flush
<--- 순서대로 초당 루프횟수 / 초당 슬립횟수 / 10초당 루프횟수 / User Transaction이 없는 유휴시간대 백그라운드 연산의 루프횟수, 플러시 루프횟수를 의미
srv_master_thread log flush and writes: 18683584
<--- 로그 메시지를 기록하고 플러시한 횟수를 의미 (Redo + Undo)
-----------------
SEMAPHORES
-----------------
InnoDB 내부 세마포어(뮤텍스나 리드/라이트 락 세마포어를 기다리는 스레드에 대한 정보)의 통계 : 각 숫자는 Innodb Engine이 시작된 이후부터의 카운트 값이며 각 카운트 값이 갑자기 높은 시간대에 대해서는 DISK I/O 성능 및 InnoDB 엔진경합을 의심
OS WAIT ARRAY INFO: reservation count 1206724952, signal count 3304987791
<--- 전역 대기 배열정보 : 배열이 생성된 후에 셀을 예약한 횟수 / 객체가 시그널을 받은 횟수를 의미
Mutex spin waits 39567225498, rounds 173270862365, OS waits 330572230
<--- 뮤텍스 대기 스핀정보 : 뮤텍스를 기다리는 스핀락의 호출횟수 / 스핀루프의 반복횟수 / OS의 호출을 기다린 횟수를 의미
RW-shared spins 2945944901, rounds 37722913141, OS waits 601963335
<--- 공유 리드락 스핀정보 : 공유 리드락이 걸린 시간동안 스핀락이 기다린 횟수 / 스핀루프의 반복횟수 / OS의 호출을 기다린 횟수를 의미
RW-excl spins 684786004, rounds 12265810889, OS waits 163680647
<--- 배타적 라이트락 스핀정보 : 배타적 라이트락이 걸린 시간동안 스핀락이 기다린 횟수 / 스핀루프의 반복횟수 / OS의 호출을 기다린 횟수를 의미
Spin rounds per wait: 4.38 mutex, 12.81 RW-shared, 17.91 RW-excl
<--- 각 뮤텍스에 대해 OS의 호출을 기다리며 스핀루프가 기다린 횟수를 의미
------------------------------------
LATEST FOREIGN KEY ERROR
------------------------------------
최근 발생한 트랜잭션별 참조키 에러내역 히스토리 : 제약조건에 위배되는 내역에 대한 트랜잭션 및 쿼리 정보 확인
세부 에러 내역은 생략
------------------------------------
LATEST DETECTED DEADLOCK
------------------------------------
최근 발생한 트랜잭션별 데드락내역 히스토리 : 가장 최근 발생한 트랜잭션간 데드락 이슈에 대한 처리내역 확인 (경합된 트랜잭션간의 내역 및 데드락 해결을 위한 트랜잭션 처리내역)
세부 데드락 내역은 생략
-------------------
TRANSACTIONS
-------------------
현재 트랜잭션별 락모니터링 정보 : 실제 수행되고 있는 트랜잭션별 작업내역에 대한 락 핸들링 정보 및 락 사용 세부쿼리 내역을 확인
세부 트랜잭션 내역은 생략
----------
FILE I/O
----------
다양한 I/O 연산에 대한 Innodb 스레드 실행내역 및 통계 : 내부적인 I/O 스레드의 현재 상태 및 전체 통계값 제공하며 만약 I/O상의 부하나 상태이상이 의심될 때 참조될 수 있음.
I/O thread 0 state: waiting for i/o request (insert buffer thread)
I/O thread 1 state: waiting for i/o request (log thread)
I/O thread 2 state: waiting for i/o request (read thread)
I/O thread 3 state: waiting for i/o request (read thread)
I/O thread 4 state: waiting for i/o request (read thread)
I/O thread 5 state: waiting for i/o request (read thread)
I/O thread 6 state: waiting for i/o request (write thread)
I/O thread 7 state: waiting for i/o request (write thread)
I/O thread 8 state: waiting for i/o request (write thread)
I/O thread 9 state: waiting for i/o request (write thread)
---> 현재 Innodb엔진이 사용중인 I/O 스레드들의 현재 상태 (각 스레드의 역할에 대한 명칭은 각 줄 끝 괄호내역 확인)
Pending normal aio reads: 0 [0, 0, 0, 0] , aio writes: 0 [0, 0, 0, 0] ,
ibuf aio reads: 0, log i/o's: 0, sync i/o's: 0
Pending flushes (fsync) log: 0; buffer pool: 0
---> 대기하는 연산에 대한 정보 (aio 는 비동기 입출력을 의미)
21113936456 OS file reads, 7012874230 OS file writes, 5248276317 OS fsyncs
---> Innodb 엔진이 시작된 이후 전체통계 카운트
670.33 reads/s, 16384 avg bytes/read, 387.61 writes/s, 196.80 fsyncs/s
---> 마지막으로 통계를 출력한 이후의 전체통계 값에 대한 초단위 처리 카운트
------------------------------------------------------
INSERT BUFFER AND ADAPTIVE HASH INDEX
------------------------------------------------------
인서트 버퍼와 적응형 해시에 대한 정보 : 버퍼와 해시의 효율에 대한 통계정보 확인
Ibuf: size 38747, free list len 48247, seg size 86995, 183927359 merges
---> 페이지에 있는 삽입버퍼의 인덱스트리 사이즈 / 사용가능한 프리리스트의 길이 / 삽입버퍼트리와 헤더를 갖고 있는 파일에 할당된 페이지수 / 합병된 페이지수 를 의미
merged operations:
insert 1037160756, delete mark 902047899, delete 260585507
---> 인덱스 페이지에 합병한 각 DML연산의 횟수를 의미
discarded operations:
insert 110253, delete mark 5399, delete 2043
---> 테이블스페이스나 인덱스가 삭제되어 합병하지 않고 버려진 각 DML연산의 횟수를 의미
Hash table size 4425293, node heap has 1037 buffer(s)
---> 적응형 해시 인덱스 테이블에 있는 셀의 개수와 예약된 버퍼프레임의 개수를 의미
1057.94 hash searches/s, 1352.65 non-hash searches/s
---> 검색한 적응형 해시 인덱스 검색에 성공한 횟수 / 적응형 해시 인덱스를 사용할 수 없을때 B-tree 인덱스를 검색한 횟수를 의미
-------
LOG
-------
Innodb Log 활동에 대한 통계
Log sequence number 7804454235313
---> 현재 로그 일련번호 (lsn)
Log flushed up to 7804454234099
---> 로그파일에서 플러시된 항목의 개수
Last checkpoint at 7804369829116
---> 가장 최근의 체크포인트된 lsn 정보
0 pending log writes, 0 pending chkp writes
4882215617 log i/o's done, 153.85 log i/o's/second
log switch 이슈와 관련
VIEW POINT : (Log flushed up to - Last checkpoint at) 값은 체크포인트가 얼마나 오래되었는지를 확인할 수 있음.
체크 포인트값이 (innodb_log_file_size * innodb_log_files_in_group)의 77% 이상이 되지 않게 모니터링하고 유지되어야 함. (권장된 모니터링수치)
만약 이 비율에 가깝거나 큰 비율 값이 나온다면 Innodb엔진은 공격적으로 플러싱을 시도하게 되며 이로 인한 DB연산이 멈출 수 있음.
------------------------------------
BUFFER POOL AND MEMORY
------------------------------------
Innodb 버퍼풀과 메모리 사용량에 대한 통계정보 : Innodb 버퍼에 대한 LRU 관리방법에 의한 할당내역 및 사용내역(byte단위)과 버퍼사용율에 대한 세부통계수치 확인
Total memory allocated 2197815296; in additional pool allocated 0
---> 버퍼로 할당된 메모리 전체사이즈 / 추가풀에 할당된 메모리사이즈를 의미
Dictionary memory allocated 8409400
---> 데이터딕셔너리 테이블과 인덱스에 할당된 메모리사이즈를 의미
Buffer pool size 131072
Free buffers 21
---> 버퍼풀 사이즈를 페이지 단위로 알려주고 / 버퍼풀에 있는 해재된(free) 버퍼의 개수를 의미 : 프리버퍼가 없는 경우가 잦으면 버퍼사이즈를 늘려주는 것을 권장.
Database pages 130014
Old database pages 47973
Modified db pages 5660
---> 버퍼의 현재 LRU큐의 길이 / 과거 LRU큐의 길이 / 플러시해야할 페이지의 개수를 의미 : 기본적으로 Innodb는 버퍼풀을 LRU로 관리하며 할당과 해제에 대해서 페이지단위로 관리됨.
Pending reads 0
Pending writes: LRU 0, flush list 0, single page 0
---> 대기하고 있는 읽기연산의 개수 / LRU 관리방식에 따른 플러시하기 위해 대기하고 있는 페이지의 개수 / Buf_flush_list에서 플러시하기위해 기다리고 있는 페이지의 개수 / Buf_flush_single_page 리스트에서 플러시하기 위해 기다리고 있는 페이지의 개수를 의미
Pages made young 47722254403, not young 0
3258.74 youngs/s, 0.00 non-youngs/s
---> 최근에 접근한 페이지의 개수 / 최근에 접근하지 않은 페이지의 개수를 의미
Pages read 25295158134, created 95903681, written 2392506665
670.33 reads/s, 2.00 creates/s, 235.76 writes/s
---> 페이지의 읽기 연산 카운트 / 버퍼풀에 생성했지만 읽지않은 페이지의 개수 / 쓰기 연산 카운트를 의미
Buffer pool hit rate 997 / 1000, young-making rate 19 / 1000 not 0 / 1000
---> 획득한 버퍼풀 페이지 수와 비교하여 읽은 페이지 수의 비율 / 획득한 버퍼풀 페이지 수와 비교 및 접근한 페이지 수의 비율 / 획득한 버퍼풀 페이지 수와 비교 및 접근하지 않은 페이지 수의 비율을 의미
Pages read ahead 0.00/s, evicted without access 0.00/s, Random read ahead 0.00/s
---> 미리 읽기 비율 / 접근하지 않아서 제거된 미리 읽기 페이지수의 비율 / 랜덤 미리 읽기 비율
LRU len: 130014, unzip_LRU len: 0
I/O sum[108645]:cur[907], unzip sum[0]:cur[0]
----------------------
ROW OPERATIONS
----------------------
메인 스레드의 행 연산에 대한 통계 정보
2 queries inside InnoDB, 0 queries in queue
5 read views open inside InnoDB
---> 현재 실행중인 쿼리 / innodb_thread_concurrency 큐에 있는 쿼리의 개수 / 읽은 뷰의 개수를 의미
Main thread process no. 16530, id 140226923562752, state: sleeping
---> 메인 스레드의 ID 및 상태정보를 의미 (첫번째 no.는 OS의 프로세스ID)
Number of rows inserted 3941662945, updated 2611269253, deleted 1052306048, read 11030869627676
39.96 inserts/s, 57.94 updates/s, 2.00 deletes/s, 908015.98 reads/s
---> innodb 엔진 시작된 이후의 각 DML연산의 총합계 카운트 / 초당 각 DML연산의 횟수 카운트를 의미
--------------------------------------------------------
END OF INNODB MONITOR OUTPUT
========================================================
[출처] http://intomysql.blogspot.kr/2010/12/innodb-lock.html
- 우선 각 트랜잭션은 “TRANSACTION 999999 999999”으로 시작된다. (TRANSACTION ID는 8바이트 숫자 값인데, 이러한 형태의 8바이트 숫자 값은 모두 상위 4바이트와 하위 4바이트 두 영역으로 나뉘어서 출력된다.)
- 그러므로, 여기 예제에서는 현재 3개의 트랜잭션 (09번 라인, 13번 라인, 23번 라인)이 존재한다는 것을 확인할 수 있다.
- 각 TRANSACTION 라인에는 현재 해당 트랜잭션이 어떤 작업을 하고 있는지 어떤 상태인지를 알려 주는 키워드가 표시되며, 해당 트랜잭션이 몇 초 동안 진행 중인지도 보여 준다.- 09번 라인 : not started è 현재 트랜잭션이 진행 중이지 않음을 의미- 13번 라인 : ACTIVE è 현재 트랜잭션이 4초 동안 활성화된 상태임 (경우에 따라 문장 끝에 어떤 작업 중인지를 표시해 줌 : starting index read)- 23번 라인 : ACTIVE è 현재 트랜잭션이 17251초 동안 활성화된 상태임
- 각각의 트랜잭션들은 “MySQL thread id”라는 항목(10, 16, 24번 라인)을 가지는데, 이 thread id값은 MySQL에서 “SHOW PROCESSLIST” 명령의 결과에 보여지는 “id”와 동일한 값을 가지게 된다. 즉, 현재 트랜잭션 목록에서 제일 밑 트랜잭션 (TRANSACTION 0 1809458)을 종료하고자 하면, “kill 4”명령으로 트랜잭션을 종료시킬 수 있다.
- 13번 라인의 트랜잭션은 “TRX HAS BEEN WAITING 4 SEC FOR THIS LOCK TO BE GRANTED:”이라는 항목을 가지고 있는데, 이는 현재 트랜잭션 (TRANSACTION 0 1809460)이 다른 트랜잭션이 이미 점유한 Lock 때문에 Blocking(대기) 상태임을 표시하며, 어떤 Lock을 기다리고 있는지 상세히 보여 준다. 하지만, 안타깝게도 이 결과로는 어떤 트랜잭션이 그 Lock을 가지고 있는지는 알아낼 수 없다. 대략 짐작해 보건데 그 밑에 있는 트랜잭션이 지금 17251초 동안 트랜잭션이 ACTIVE 상태인 것으로 보아서 문제를 유발하고 있을 것이라는 것 정도는 짐작해 볼 수 있게 된다. 조금 더 자세히 확인하기 위해서는 “innodb_lock_monitor” 가 필요한데, 이 내용은 하단의 “InnoDB Lock monitoring” 을 참조 바란다.
- 19번 라인을 보면, 레코드 Lock에 관련된 정보가 나오는데, 이것은 현재 트랜잭션이 대기 중인 레코드(인덱스)를 의미하며, 그 인덱스의 정보를 20, 21번 라인에 걸쳐서 보여 주고 있다. 19번 라인에는 지금 대기하고 있는 Lock이 Shared-lock인지 Exclusive-lock인지를 그리고 Gap까지 잠그고 있는지 아닌지를 보여 준다. 일반적으로 Gap lock이 아니라고 표현되는 경우를 제외하고는 거의 모두 Gap까지 잠그고 있다고 생각하면 될 듯 하다. (Gap을 잠그고 있는지 아닌지 판단하는 또 다른 방법은 “undo entries” 항목의 수가 “row lock(s)”의 수보다 작으면 대부분 Gap lock 으로 판단할 수 있다. 하지만 이 방법도 정확한 것은 아니다. 예를 들어서 한 트랜잭션에서 하나의 레코드만 계속 업데이트하게 되면 undo entries가 row locks보다 커질 수 있기 때문이다.)
- 21번 라인을 보면, 드디어 이해 불가능의 단어들이 출력되는데, 사실 이 부분이 의외로 문제 해결에 도움이 될 수 있다. 우선 이 라인에 표시되는 내용은 인덱스 레코드의 필드 값들을 출력해서 보여 주는데, HEX값과 ASCII값을 동시에 보여 준다. 21번 라인의 내용을 정리해 보면 아래와 같이 잘라서 생각해 볼 수 있다. (구분자는 ;; 임)- 0: len 1; hex 70; asc p;;- 1: len 1; hex 02; asc ;;- 2: len 4; hex 00000009; asc ;;- 3: len 4; hex 00000000; asc ;;각 라인은 [인덱스상에서의 번호 : 필드 길이 : 16진수 필드 값(HEX) : ASCII 필드 값(ASC) ] 포맷으로 구성되어 있다. 그리고 이 필드들의 개수는 20번 라인의 n_fields와 동일한 값을 가지게 된다.이 값들과 19번 라인의 테이블 및 인덱스 명을 이용하면 어느 테이블의 어떤 레코드를 지금 기다리고 있는지를 알아낼 수 있다.
- "SHOW ENGINE INNODB STATUS"의 "DEADLOCK" 섹션에 출력되는 내용도 지금까지의 설명한 내용과 동일한 패턴으로 출력되므로, DEADLOCK 정보를 확인할 때에도 이와 같은 방식으로 해석할 수 있다.
지금까지 간단히 트랜잭션의 내용을 읽는 방법을 확인해 보았다.
InnoDB Lock monitoring
우선 InnoDB의 Lock을 모니터링 하기 위해서는 아래와 같은 테이블을 생성해야 한다.
Create table innodb_lock_monitor (fd1 int) engine=innodb;
- 이 테이블을 생성하면, 매 몇 초 단위로 SHOW ENGINE INNODB STATUS 결과를 MySQL 에러 로그 파일에 기록하므로 모니터링이완료되면 테이블을 삭제 해주는 것이 좋다.
- 위의 테이블을 생성 후, “SHOW ENGINE INNODB STATUS” 명령을 실행하면 아래와 같은 좀 더 상세한 트랜잭션 정보를 확인할 수 있다.
- 어떤 트랜잭션이 다른 트랜잭션의 처리를 Blocking(막고) 하고 있는지를 판단하기 위해서는, 각 트랜잭션에서 가지고 있거나 또는 기다리고 있는 테이블 및 인덱스 그리고 그 인덱스 페이지 번호로 추적해 볼 수 있다. (물론 이 방법도 정확하게 찾을 수 있는 방법은 아니다. 하지만 더 자세히는 지금의 InnoDB 에서는 무리일지도 모른다)
- 아래 빨간색으로 표기된 부분을 비교해 봄으로써 두 개의 트랜잭션이 서로 Racing 상태임을 확인할 수 있다. (동일 테이블의 동일 인덱스에서 같은 인덱스 페이지 번호 4를 참조하고 있음)
------------
TRANSACTIONS
------------
01 Trx id counter 0 1809465
02 Purge done for trx's n:o < 0 1809462 undo n:o < 0 0
03 History list length 22
04 LIST OF TRANSACTIONS FOR EACH SESSION:
05 ---TRANSACTION 0 0, not started, process no 5975, OS thread id 1099274560
06 MySQL thread id 10, query id 442 localhost root
07 show engine innodb status
08
09
10 ---TRANSACTION 0 1809464, ACTIVE 12 sec, process no 5975, OS thread id 1281038656 starting index read
11 mysql tables in use 1, locked 1
12 LOCK WAIT 2 lock struct(s), heap size 368, 1 row lock(s)
13 MySQL thread id 9, query id 400 localhost root Updating
반응형
