Tagged: 포스트큐엘

09/28/2015

리눅스 공유 메모리

리눅스 공유 메모리는 아주 특별하고 중요합니다. 튜닝하는데 있어서 매우 중요한 요소이기 때문입니다. PostgreSQL 를 세팅할때에도 반드시 해줘야 하는 것이기에 정확하게 무엇인지 짚고 넘어가고자 아는 선에 적습니다.

페이지(Page)

가장 먼저 이야기할 것이 바로 페이지(Page) 입니다. 리눅스 시스템은 메모리를 가상으로 만들어 관리합니다. 웃기게도 리눅스 시스템에서 동작하는 프로그램들은 자신들이 시스템의 모든 메모리를 사용할 수 있다, 아니 그보다 더 많은 메모리를 사용할 수 있다라고 착각을 합니다. 이는 리눅스 시스템이 메모리를 가상화해서 프로그램들에게 보여주기 때문입니다.

문제는 리눅스 시스템은 가상화된 메모리들을 페이지(Page)라는 단위로 쪼개서 관리합니다. 특정 크기를 정해서 페이지단위로 나뉘어 관리를 하는데 이렇게 해야지만이 가상화를 하기에 훨씬 쉽고 운영체제를 제작하는데 손이 덜 간다고 합니다.

그런데 이 페이지는 크기를 가지고 있으며 이를 확인하는 방법은 다음과 같습니다.

]# getconf PAGESIZE
4096

1 2	]# getconf PAGESIZE 4096

단위는 bytes 여서 정확하게 4kb 가 됩니다.

이게 무척이나 중요한 것이 PostgreSQL 데이터베이스 세스템에서 Shared_Buffer 값을 계산할때에 페이지 크기를 알아야 합니다.

공유 메모리(Shared Memory)

리눅스 시스템은 놀랍게도 공유메모리(Shared Memory)를 제공합니다. 이게 정말로 뚱딴지 같은 소리인데 왜냐하면 이 공유 메모리는 프로세스간에 서로 공유하기위해서 메모리이기 때문입니다.

프로세스는 자신만의 메모리를 필요로 합니다. 그것으로 끝입니다. 하나의 프로세스가 다른 프로세스의 메모리에 자료를 가져가면 그건 잘못된 것이고 절대로 그렇게 동작하지도 않습니다. 그런데 프로세스 사이에 자료를 공유하고 싶을때 어떻게 해야 할까요?

이럴때 바로 공유 메모리를 사용합니다. 공유 메모리의 특징은 다음과 같습니다.

공유메모리는 최초로 공유 메모리를 만드는 프로세스에 의해서 만들어 집니다. 이렇게 만들어진 메모리는 커널이 관리해 줍니다.
한번 만들어진 공유 메모리 공간은 직접 삭제를 하거나 리눅스 시스템이 재부팅을 하거나 해야지만 없어집니다. 모든 프로세스가 더 이상 공유 메모리를 사용하지 않는다고 자동 삭제되는 일은 결코 없습니다.

뭔가 대단히 있어보이는 듯한데, 한마디로 정의 하면

프로세스간에 데이터를 공유하고자 할때 사용하는 메모리로 커널에 의해서 관리 되어진다.

입니다. 참 쉽조잉~

그런데, 이 공유 메모리는 아주 많이 사용되어지기 때문에 이 공유메모리 양을 얼마로 해주냐가 리눅스 튜닝의 시작입니다. 실제로 커널 파라메터에 다음과 같은게 있습니다.

kernel.shmmax = 4294967296

1	kernel.shmmax = 4294967296

많이들 하는 튜닝입니다. 최대 공유 메모리를 얼마나 할 것인가 하는 겁니다.

공유 메모리는 최소(SHMMNI), 최대(SHMAX), 그리고 시스템을 통틀어 모든 공유 메모리 세그먼트의 총합(SHMALL) 로 구분이 되는데 이들의 최대 용량(제한 용량)은 다음과 같이 확인할 수 있습니다.

]# ipcs -lm

------ Shared Memory Limits --------
max number of segments = 4096          <--- SHMMAX
max seg size (kbytes) = 67108864       
max total shared memory (kbytes) = 17179869184   <---- SHMALL
min seg size (bytes) = 1

]# ipcs -lm

------ Shared Memory Limits --------

max number of segments = 4096 <--- SHMMAX

max seg size (kbytes) = 67108864

max total shared memory (kbytes) = 17179869184 <---- SHMALL

min seg size (bytes) = 1

그런데, 여기서 주의해야 할 것이 있습니다. 커널은 이값을 지정할때에 shmmax 는 ‘bytes’ 단위이고 shmall 은 ‘pages’ 단위 입니다.

]# cat /proc/sys/kernel/shmmax
68719476736
]# cat /proc/sys/kernel/shmall
4294967296
]# ipcs -lm

------ Shared Memory Limits --------
max number of segments = 4096
max seg size (kbytes) = 67108864
max total shared memory (kbytes) = 17179869184
min seg size (bytes) = 1

]# cat /proc/sys/kernel/shmmax

68719476736

]# cat /proc/sys/kernel/shmall

4294967296

]# ipcs -lm

------ Shared Memory Limits --------

max number of segments = 4096

max seg size (kbytes) = 67108864

max total shared memory (kbytes) = 17179869184

min seg size (bytes) = 1

위에 보시면 커널에 할당된 shmall 값과 ‘ipcs -lm’ 해서 나온 값이 다릅니다. 이는 단위의 차이로 인한 것으로 커널의 shmall 값은 page 단위이기 때문에 다음과 같이 계산하면 ‘ipcs -lm’가 똑같아 집니다.

(4294967296 * 4096)/1024
17179869184

1 2	(4294967296 * 4096)/1024 17179869184

SHMMAX 값은 새로운 메모리 영역을 할당할때, 그러니까 shmget() 함수를 호출할때에 사용가능한 최대 메모리 양을 말합니다. 다시 강조하면 shmget()함수를 이용할때입니다. 이는 단일 프로세스가 공유메모리를 호출하기 위한 최대 값이라는 이야기 입니다.

SHMALL 은 시스템을 통틀어 모든 프로세스가 사용 가능한 공유메모리 양입니다.

이게 왜 중요해?

대부분 데이터베이스 시스템을 다룰때에 이 부분이 문제가 됩니다. ORACLE, PosgreSQL의 경우에 바로 이 공유 메모리 설정이 작으면 설치가 진행이 안된다거나 서버가 구동된다하더라도 오류 메시를 내보내고 오류를 내는 경우가 많습니다.

어떻게 설정해야 잘 하는 것일까? 혹은 적절한 값은 무엇인가는 어떤 시스템을 다루느냐에 따라서 달라집니다. PostgreSQL 의 경우에 Shared_buffers 값이 있는데, 이 값은 PostgreSQL에서 데이터를 캐쉬하는데 얼마의 RAM을 사용할 것인지를 지정합니다. PostgreSQL의 경우에 Subprocess 모델 기반으로 각 프로세스별 데이터를 공유하기위해서는 바로 공유메모리가 필요하고 Shared_buffers 는 결국 공유 메모리 입니다. 따라서 운영체제에서 PostgreSQL이 요구하는 Shared_buffers 메모리 값보다 적은 공유 메모리를 설정하면 PostgreSQL이 동작하지 않습니다.

PostgreSQL 의 경우에 Shared_buffers 메모리는 32GB 경우에 8GB 를 Shared_buffers 로 권장하고 있습니다. Shared_buffers 메모리는 공유메모리이고 단일 프로그램이 사용할 것이 때문에 SHMMAX 는 최소 8GB로 해야 합니다.

최대 공유메모리는 32GB-4GB 정도해서 28GB를 SHMALL로 지정해줍니다. 정리를하면

shmmax=8589934592 (8GB)
shmall=7340032 (32-2GB/4096)

1 2	shmmax=8589934592 (8GB) shmall=7340032 (32-2GB/4096)

위와같이 지정할 수 있겠습니다.

공유 메모리 사용현황

공유메모리 사용현황은 ‘ipcs -a’ 명령어를 이용해서 확인할 수 있습니다.

]# ipcs -a

------ Shared Memory Segments --------
key        shmid      owner      perms      bytes      nattch     status
0x0052e2c1 98304      postgres   600        32955408384 37

------ Semaphore Arrays --------
key        semid      owner      perms      nsems
0x00000000 0          root       600        1
0x00000000 32769      root       600        1
0x0052e2c1 2654210    postgres   600        17
0x0052e2c2 2686979    postgres   600        17
0x0052e2c3 2719748    postgres   600        17
0x0052e2c4 2752517    postgres   600        17
0x0052e2c5 2785286    postgres   600        17
0x0052e2c6 2818055    postgres   600        17
0x0052e2c7 2850824    postgres   600        17
0x0052e2c8 2883593    postgres   600        17

------ Message Queues --------
key        msqid      owner      perms      used-bytes   messages

]# ipcs -a

------ Shared Memory Segments --------

key shmid owner perms bytes nattch status

0x0052e2c1 98304 postgres 600 32955408384 37

------ Semaphore Arrays --------

key semid owner perms nsems

0x00000000 0 root 600 1

0x00000000 32769 root 600 1

0x0052e2c1 2654210 postgres 600 17

0x0052e2c2 2686979 postgres 600 17

0x0052e2c3 2719748 postgres 600 17

0x0052e2c4 2752517 postgres 600 17

0x0052e2c5 2785286 postgres 600 17

0x0052e2c6 2818055 postgres 600 17

0x0052e2c7 2850824 postgres 600 17

0x0052e2c8 2883593 postgres 600 17

------ Message Queues --------

key msqid owner perms used-bytes messages

09/24/2015

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초이상 지속된 쿼리들을 차단할 수 있습니다.

=# 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;

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이 기록하는 로그를 기반으로 평가되었습니다.

테스트 쿼리

테스트를 위해서 실행했던 테스트 쿼리는 다음과 같습니다.

testdb=> SELECT pg_sleep(10);
 pg_sleep
----------
(1 row)

testdb=> SELECT pg_sleep(10);

pg_sleep

----------

(1 row)

위와같이 pg_sleep 함수를 사용한 상태에서 pg_stat_activity 를 보면 다음과 같이 나옵니다.

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);

-------+---------+-------+----------+---------+------------------+-------------+-----------------+-------------+-------------------------------+-------------------------------+-------------------------------+-------------------------------+---------+--------+---------------------------------

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 을 테스트 입니다.

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

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 쉘에서도 다음과 같은 반응 했습니다.

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.

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 로그 입니다.

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]

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에 대해 테스트 입니다.

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

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 쉘은 다음과 같이 되었습니다.

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.
!>  <----- 쉘모양도 깨졌습니다.

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 에서의 로그는 다음과 같습니다.

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

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을 재시작하는 결과를 가지고 옵니다. 이는 프로세스의 시작시간이 바뀌것으로도 판단할 수 있습니다.

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
                                                 >프로세스시작시간<

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를 알아낸 다음 다음과 같이 쿼리를 했습니다.

postgres=# select pg_terminate_backend(19954);
 pg_terminate_backend
----------------------
 t
(1 row)

postgres=# select pg_terminate_backend(19954);

pg_terminate_backend

----------------------

(1 row)

쿼리를 수행중이던 다른 PostgreSQL 쉘에서는 다음과 같이 메시지가 나왔습니다.

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.

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 의 로그는 다음과 같습니다.

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]

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에 관한 것입니다.

postgres=# select pg_cancel_backend(20197);
 pg_cancel_backend
-------------------
 t
(1 row)

postgres=# select pg_cancel_backend(20197);

pg_cancel_backend

-------------------

(1 row)

PostgreSQL 쉘에서 쿼리를 보냈던 화면에는 다음과 같이 나왔습니다.

testdb=> SELECT pg_sleep(200);
ERROR:  canceling statement due to user request

1 2	testdb=> SELECT pg_sleep(200); ERROR: canceling statement due to user request

위 내용은 PostgreSQL 로그에도 동일 했습니다.

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);

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 자체에는 아무런 영향을 주지 않습니다.

2024 4월
일	월	화	수	목	금	토
	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	26	27
28	29	30