pg_terminate_backend, pg_cancel_backend
PostgreSQL 에서 쿼리를 취소시키위한 함수로 pg_terminate_backend, pg_cancel_backend 를 제공 합니다. 공식문서에는 다음과 같이 나와 있습니다.
– pg_cancel_backend(pidint) : Cancel a backend’s current query. You can execute this against another backend that has exactly the same role as the user calling the function. In all other cases, you must be a superuser.
– pg_terminate_backend(pidint) : Terminate a backend. You can execute this against another backend that has exactly the same role as the user calling the function. In all other cases, you must be a superuser.pg_cancel_backend and pg_terminate_backend send signals (SIGINT or SIGTERM respectively) to backend processes identified by process ID. The process ID of an active backend can be found from the pid column of the pg_stat_activity view, or by listing the postgres processes on the server (using ps on Unix or the Task Manager on Windows). The role of an active backend can be found from the usename column of the pg_stat_activity view.
이 함수를 이용해서 다음과 같이 30초이상 지속된 쿼리들을 차단할 수 있습니다.
1 2 |
=# select pg_terminate_backend(pid) from (select pid from pg_stat_activity where query_start < now() - '30 seconds'::interval) as t; =# select pg_cancel_backend(pid) from (select pid from pg_stat_activity where query_start < now() - '30 seconds'::interval) as t; |
프로세스에 시그널(Signal)을 보내는거는 똑같은데, 하나는 SIGINT을 다른 하나는 SIGTERM을 받습니다.
SIGINT는 인터럽트(Interrupt) 시그널을 말합니다. 가장 흔하게 볼 수 있는게 어떤 프로그램을 포그라운드(Foreground)로 실행중에 Ctr+C 를 누르는 것이 바로 SIGINT 입니다. 이 시그널을 받은 프로그램은 별도의 행동을 정의하지 않았다면 프로그램을 종료 됩니다.
SIGTERM 은 Kill 시그널로 프로그램 종료 시그널 입니다. 이 시그널을 받은 프로그램은 이 신호를 무시하거나 접속을 차단하고 프로그램 종료를 위한 프로세스를 진행합니다. 한마디로 말해서 안전한 종료 입니다.
우리가 흔히 쓰는 ‘kill -9 pid’ 는 SIGKILL인데, 이것은 시그널을 받은 프로그램의 후속 행동과는 상관없이 즉시 프로그램을 강제 종료시키도록 합니다.
테스트
테스트는 PostgreSQL 의 프로세스에게 SIGTERM, SIGKILL, SIGINT를 보내 이에 어떤 반응을 보이는지를 보는 것이 주 목적입니다. 이를 위해 Linux 쉘 상에서 SIGTERM, SIGKILL을 주는 방법과 PostgreSQL 쉘상에서 위에서 소개했던 두개의 함수를 사용하는 방법을 채택했습니다.
모든 테스트는 화면과 PostgreSQL이 기록하는 로그를 기반으로 평가되었습니다.
테스트 쿼리
테스트를 위해서 실행했던 테스트 쿼리는 다음과 같습니다.
1 2 3 4 |
testdb=> SELECT pg_sleep(10); pg_sleep ---------- (1 row) |
위와같이 pg_sleep 함수를 사용한 상태에서 pg_stat_activity 를 보면 다음과 같이 나옵니다.
1 2 3 |
datid | datname | pid | usesysid | usename | application_name | client_addr | client_hostname | client_port | backend_start | xact_start | query_start | state_change | waiting | state | query -------+---------+-------+----------+---------+------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+---------+--------+--------------------------------- 16386 | testdb | 14014 | 16385 | test | psql | | | -1 | 2015-09-22 13:18:13.553564+09 | 2015-09-22 14:43:58.054511+09 | 2015-09-22 14:43:58.054511+09 | 2015-09-22 14:43:58.054514+09 | f | active | SELECT pg_sleep(100); |
Linux 쉘상에서 SIGTERM
먼저 Linux 쉘상에서 SIGTERM 을 테스트 입니다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
saltmaster ~ # ps aux | grep post postgres 6129 0.0 0.0 145096 15740 ? S 10:57 0:00 /usr/lib/postgresql/9.2/bin/postgres -D /var/lib/postgresql/9.2/main -c config_file=/etc/postgresql/9.2/main/postgresql.conf postgres 6130 0.0 0.0 102748 1344 ? Ss 10:57 0:00 postgres: logger process root 6510 0.0 0.0 90232 4748 pts/10 S 11:01 0:00 su - postgres postgres 6517 0.0 0.0 24224 5800 pts/10 S+ 11:01 0:00 -su postgres 6537 0.0 0.0 145096 3488 ? Ss 11:01 0:00 postgres: checkpointer process postgres 6538 0.0 0.0 145096 4204 ? Ss 11:01 0:00 postgres: writer process postgres 6539 0.0 0.0 145096 3488 ? Ss 11:01 0:00 postgres: wal writer process postgres 6540 0.0 0.0 145916 5800 ? Ss 11:01 0:00 postgres: autovacuum launcher process postgres 6541 0.0 0.0 104840 3732 ? Ss 11:01 0:00 postgres: stats collector process root 13977 0.0 0.0 90232 4624 pts/0 S 13:18 0:00 su - postgres postgres 13984 0.0 0.0 24224 5932 pts/0 S 13:18 0:00 -su postgres 14003 0.0 0.0 101452 7188 pts/0 S+ 13:18 0:00 /usr/lib/postgresql/9.2/bin/psql -U test testdb postgres 14014 0.0 0.0 146444 9552 ? Ss 13:18 0:00 postgres: test testdb [local] SELECT <--- 쿼리가 실행중입니다. ]# kill 14014 |
SIGTERM 을 Linux 쉘에서 보내자 PostgreSQL 쉘에서도 다음과 같은 반응 했습니다.
1 2 3 4 5 6 |
testdb=> SELECT pg_sleep(100); FATAL: terminating connection due to administrator command server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. The connection to the server was lost. Attempting reset: Succeeded. |
다음은 PostgreSQL 로그 입니다.
1 2 3 4 |
2015-09-22 14:47:45 KST [14014-9] test@testdb FATAL: terminating connection due to administrator command 2015-09-22 14:47:45 KST [14014-10] test@testdb STATEMENT: SELECT pg_sleep(200); 2015-09-22 14:47:45 KST [14014-11] test@testdb LOG: disconnection: session time: 1:29:32.146 user=test database=testdb host=[local] 2015-09-22 14:47:45 KST [19073-1] [unknown]@[unknown] LOG: connection received: host=[local] |
PostgreSQL은 쿼리를 취소한게 아니라 Connection 을 차단하고 있음을 보여주고 있습니다.
Linux 쉘상에서 SIGKILL
이번에는 Linux 쉘상에서 SIGKILL에 대해 테스트 입니다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 |
saltmaster ~ # ps aux | grep post postgres 6129 0.0 0.0 145096 15740 ? S 10:57 0:00 /usr/lib/postgresql/9.2/bin/postgres -D /var/lib/postgresql/9.2/main -c config_file=/etc/postgresql/9.2/main/postgresql.conf postgres 6130 0.0 0.0 102748 1344 ? Ss 10:57 0:00 postgres: logger process root 6510 0.0 0.0 90232 4748 pts/10 S 11:01 0:00 su - postgres postgres 6517 0.0 0.0 24224 5800 pts/10 S+ 11:01 0:00 -su postgres 6537 0.0 0.0 145096 3488 ? Ss 11:01 0:00 postgres: checkpointer process postgres 6538 0.0 0.0 145096 4204 ? Ss 11:01 0:00 postgres: writer process postgres 6539 0.0 0.0 145096 3488 ? Ss 11:01 0:00 postgres: wal writer process postgres 6540 0.0 0.0 145916 5800 ? Ss 11:01 0:00 postgres: autovacuum launcher process postgres 6541 0.0 0.0 104840 3732 ? Ss 11:01 0:00 postgres: stats collector process root 13977 0.0 0.0 90232 4624 pts/0 S 13:18 0:00 su - postgres postgres 13984 0.0 0.0 24224 5932 pts/0 S 13:18 0:00 -su postgres 14003 0.0 0.0 101452 7188 pts/0 S+ 13:18 0:00 /usr/lib/postgresql/9.2/bin/psql -U test testdb postgres 19073 0.0 0.0 146848 8504 ? Ss 14:47 0:00 postgres: test testdb [local] SELECT ]# kill -9 19073 |
‘kill -9 ‘ 는 SIGKILL 을 의미합니다. PostgreSQL 쉘은 다음과 같이 되었습니다.
1 2 3 4 5 6 |
testdb=> SELECT pg_sleep(100); server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. The connection to the server was lost. Attempting reset: Failed. !> <----- 쉘모양도 깨졌습니다. |
SIGTERM과는 달리 “FATAL: terminating connection due to administrator command” 메시지도 없이 바로 접속이 차단되었습니다. 그리고 쉘 모양도 깨졌습니다.
PostgreSQL 에서의 로그는 다음과 같습니다.
1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24 25 |
2015-09-22 14:53:28 KST [6129-6] LOG: server process (PID 19073) was terminated by signal 9: Killed 2015-09-22 14:53:28 KST [6129-7] DETAIL: Failed process was running: SELECT pg_sleep(200); 2015-09-22 14:53:28 KST [6129-8] LOG: terminating any other active server processes 2015-09-22 14:53:28 KST [6540-2] WARNING: terminating connection because of crash of another server process 2015-09-22 14:53:28 KST [6540-3] DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 2015-09-22 14:53:28 KST [6540-4] HINT: In a moment you should be able to reconnect to the database and repeat your command. 2015-09-22 14:53:28 KST [19452-1] [unknown]@[unknown] LOG: connection received: host=[local] 2015-09-22 14:53:28 KST [19452-2] test@testdb FATAL: the database system is in recovery mode 2015-09-22 14:53:28 KST [6129-9] LOG: all server processes terminated; reinitializing 2015-09-22 14:53:28 KST [19453-1] LOG: database system was interrupted; last known up at 2015-09-22 11:01:35 KST 2015-09-22 14:53:28 KST [19453-2] DEBUG: checkpoint record is at 0/176D970 2015-09-22 14:53:28 KST [19453-3] DEBUG: redo record is at 0/176D970; shutdown TRUE 2015-09-22 14:53:28 KST [19453-4] DEBUG: next transaction ID: 0/725; next OID: 16387 2015-09-22 14:53:28 KST [19453-5] DEBUG: next MultiXactId: 1; next MultiXactOffset: 0 2015-09-22 14:53:28 KST [19453-6] DEBUG: oldest unfrozen transaction ID: 711, in database 1 2015-09-22 14:53:28 KST [19453-7] DEBUG: transaction ID wrap limit is 2147484358, limited by database with OID 1 2015-09-22 14:53:28 KST [19453-8] LOG: database system was not properly shut down; automatic recovery in progress 2015-09-22 14:53:28 KST [19453-9] DEBUG: resetting unlogged relations: cleanup 1 init 0 2015-09-22 14:53:28 KST [19453-10] LOG: record with zero length at 0/176D9D0 2015-09-22 14:53:28 KST [19453-11] LOG: redo is not required 2015-09-22 14:53:28 KST [19453-12] DEBUG: resetting unlogged relations: cleanup 0 init 1 2015-09-22 14:53:28 KST [19453-13] LOG: checkpoint starting: end-of-recovery immediate 2015-09-22 14:53:28 KST [19453-14] LOG: checkpoint complete: wrote 0 buffers (0.0%); 0 transaction log file(s) added, 0 removed, 0 recycled; write=0.000 s, sync=0.000 s, total=0.003 s; sync files=0, longest=0.000 s, average=0.000 s 2015-09-22 14:53:28 KST [19457-1] LOG: autovacuum launcher started 2015-09-22 14:53:28 KST [6129-10] LOG: database system is ready to accept connections |
SIGTERM 때와는 달리 서버가 재시작되었습니다. Recovery Mode 로 전환해 트랜잭션을 복구하고 checkpoint 를 날려 메모리를 리셋했습니다. checkpoint 는 PostgreSQL의 shared_buffer 메모리에 있는 모든 데이터를 디스크에 Flush 하도록하는 것으로 메모리 초기화로 부르기도 합니다. 이렇게 되면 메모리 그래프상으로는 갑자기 메모리 사용량이 줄어드는 현상을 보입니다.
어쨌든 SIGKILL은 PostgreSQL을 재시작하는 결과를 가지고 옵니다. 이는 프로세스의 시작시간이 바뀌것으로도 판단할 수 있습니다.
1 2 3 4 5 6 7 8 9 10 11 12 13 |
postgres@saltmaster ~/9.2/main/pg_log $ ps aux | grep post postgres 6129 0.0 0.0 145096 15704 ? S 10:57 0:00 /usr/lib/postgresql/9.2/bin/postgres -D /var/lib/postgresql/9.2/main -c config_file=/etc/postgresql/9.2/main/postgresql.conf postgres 6130 0.0 0.0 102748 1344 ? Ss 10:57 0:00 postgres: logger process root 6510 0.0 0.0 90232 4748 pts/10 S 11:01 0:00 su - postgres postgres 6517 0.0 0.0 24224 5800 pts/10 S+ 11:01 0:00 -su root 13977 0.0 0.0 90232 4624 pts/0 S 13:18 0:00 su - postgres postgres 13984 0.0 0.0 24224 5936 pts/0 S+ 13:18 0:00 -su postgres 19454 0.0 0.0 145096 3488 ? Ss 14:53 0:00 postgres: checkpointer process postgres 19455 0.0 0.0 145096 4204 ? Ss 14:53 0:00 postgres: writer process postgres 19456 0.0 0.0 145096 3488 ? Ss 14:53 0:00 postgres: wal writer process postgres 19457 0.0 0.0 145784 5664 ? Ss 14:53 0:00 postgres: autovacuum launcher process postgres 19458 0.0 0.0 104840 3564 ? Ss 14:53 0:00 postgres: stats collector process >프로세스시작시간< |
프로세스 시작시간이 14:53분으로 이전과 달라졌습니다.
PostgreSQL 쉘 상에서 SIGTERM
PostgreSQL 쉘 상에서 SIGTERM은 pg_terminate_backend 함수를 사용함으로서 이루어집니다. pg_stat_activity 테이블에서 pid를 알아낸 다음 다음과 같이 쿼리를 했습니다.
1 2 3 4 5 |
postgres=# select pg_terminate_backend(19954); pg_terminate_backend ---------------------- t (1 row) |
쿼리를 수행중이던 다른 PostgreSQL 쉘에서는 다음과 같이 메시지가 나왔습니다.
1 2 3 4 5 6 7 |
testdb=> SELECT pg_sleep(200); LOG: disconnection: session time: 0:01:36.779 user=test database=testdb host=[local] FATAL: terminating connection due to administrator command server closed the connection unexpectedly This probably means the server terminated abnormally before or while processing the request. The connection to the server was lost. Attempting reset: Succeeded. |
그리고 PostgreSQL 의 로그는 다음과 같습니다.
1 2 3 4 |
2015-09-22 15:03:55 KST [20142-4] postgres@postgres LOG: duration: 2.154 ms statement: select pg_terminate_backend(19954); 2015-09-22 15:03:55 KST [19954-3] test@testdb FATAL: terminating connection due to administrator command 2015-09-22 15:03:55 KST [19954-4] test@testdb STATEMENT: SELECT pg_sleep(200); 2015-09-22 15:03:55 KST [19954-5] test@testdb LOG: disconnection: session time: 0:01:36.779 user=test database=testdb host=[local] |
이는 Linux 쉘 상에서 SIGTERM을 보낸것과 같은 결과 입니다.
PostgreSQL 쉘 상에서 SIGINT
이번에는 SIGINT에 관한 것입니다.
1 2 3 4 5 |
postgres=# select pg_cancel_backend(20197); pg_cancel_backend ------------------- t (1 row) |
PostgreSQL 쉘에서 쿼리를 보냈던 화면에는 다음과 같이 나왔습니다.
1 2 |
testdb=> SELECT pg_sleep(200); ERROR: canceling statement due to user request |
위 내용은 PostgreSQL 로그에도 동일 했습니다.
1 2 3 |
2015-09-22 15:11:37 KST [20142-6] postgres@postgres LOG: duration: 1.750 ms statement: select pg_cancel_backend(20197); 2015-09-22 15:11:37 KST [20197-3] test@testdb ERROR: canceling statement due to user request 2015-09-22 15:11:37 KST [20197-4] test@testdb STATEMENT: SELECT pg_sleep(200); |
결론
SIGINT 은 SIGTERM과 중요한 차이점을 보여주고 있습니다. SIGTERM은 connection 자체를 차단하게 합니다. 따라서 쿼리를 하기위해서는 반드시 PostgreSQL로 재 접속이 이루어져야 합니다. 반면에, SIGINT은 쿼리문(statement) 자체를 취소(cancel)하게 함으로써 connection 자체에는 아무런 영향을 주지 않습니다.