[PostgreSQL 9.6 New Feature] wait_event_type 및 wait_event 칼럼을 이용한 대기이벤트 모니터링

PostgreSQL도 버전 9.6부터 pg_stat_activity 테이블의 wait_event_typewait_event 칼럼을 통해 대기이벤트를 모니터링할 수 있습니다. (세부 내용은 매뉴얼 참조) 현재는 4개의 wait_event_type과 100개 이내의 wait_event를 제공할 뿐이지만, 이전버전까지는 waiting 칼럼을 통해 락 대기 여부만을 판단할 수 있던 것에 비하면 획기적인 변화의 시작임은 분명합니다.

부하를 주고 모니터링을 해본 결과, 오라클과 같이 아주 세세한 부분까지 디버깅을 할 수는 없지만 심각한 문제에 대해서는 어느 정도 문제를 유추할 수 있는 수준의 데이터는 제공하는 것 같습니다. 아래는 동시에 10여개의 세션에서 동일 테이블에 INSERT를 수행하는 부하 테스트 시의 모니터링 결과입니다.

보시는 것과 같이 WALWriteLock 대기이벤트를 대기하는 세션이 다수이고, 이를 통해 해당 세션들은 WAL 버퍼가 디스크로 기록되기를 대기한다는 것을 알 수 있습니다.

Note
이전 버전까지 제공되던 waiting 칼럼은 9.6 버전에서는 제공되지 않습니다. 따라서 waiting=’t’ 조건을 이용해서 락 대기 세션을 모니터링했던 쿼리들은 wait_event_type=’Lock’으로 조건을 변경해야 합니다.

예시. wait_event_type 및 wait_event 칼럼을 이용한 대기이벤트 모니터링
test=# select pid, wait_event_type, wait_event, current_timestamp-xact_start as txn_time, query from pg_stat_activity;
 
  pid  | wait_event_type |  wait_event  |     txn_time     |     query
-------+-----------------+--------------+------------------+---------------------------------
 32572 |                 |              | 03:29:30.451393  | select loop_insert_t1(10000000);
 32598 | LWLockNamed     | WALWriteLock | 00:00:00.000653  | INSERT INTO t1 SELECT '3810212'
   427 | LWLockNamed     | WALWriteLock | 00:00:00.001069  | INSERT INTO t1 SELECT '3831263'
 32751 |                 |              | 03:29:17.380626  | select loop_insert_t1(100000000);
   521 |                 |              | 03:25:06.032286  | select loop_insert_t1(100000000);
   522 |                 |              |                  | INSERT INTO t1 SELECT '3683652'
   669 |                 |              | 03:25:04.224235  | select loop_insert_t1(100000000);
   670 | LWLockNamed     | WALWriteLock | 00:00:00.001333  | INSERT INTO t1 SELECT '3679654'
   773 |                 |              | 03:25:00.344482  | select loop_insert_t1(100000000);
   774 |                 |              | 00:00:00.001249  | INSERT INTO t1 SELECT '3689628'
   868 |                 |              | 03:25:45.836126  | select loop_insert_t1(100000000);
   870 | LWLockNamed     | WALWriteLock | 00:00:00.000672  | INSERT INTO t1 SELECT '3708035'
  1138 |                 |              | 03:22:13.689574  | select loop_insert_t1(100000000);
  1139 | LWLockNamed     | WALWriteLock | 00:00:00.000892  | INSERT INTO t1 SELECT '3628461'
  1248 |                 |              | 03:21:42.46344   | select loop_insert_t1(100000000);
  1249 | LWLockNamed     | WALWriteLock | -00:00:00.000289 | INSERT INTO t1 SELECT '3632619'
  1341 |                 |              | 03:21:12.328308  | select loop_insert_t1(100000000);
  1342 | LWLockNamed     | WALWriteLock | 00:00:00.002372  | INSERT INTO t1 SELECT '3619281'
  1433 |                 |              | 03:20:49.765249  | select loop_insert_t1(100000000);
  1435 | LWLockNamed     | WALWriteLock | 00:00:00.000924  | INSERT INTO t1 SELECT '3608915'


Advertisements

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s