Re: Fwd: pg_cancel_backend() не снимает зависшие транзакции

17.10.07, Sergey Konoplev<gray(dot)ru(at)gmail(dot)com> написал(а):
> 03.10.07, Заяц Алексей<az(at)antora(dot)ru> написал(а):
> > Sergey Konoplev пишет:
> > > Если ты хотел посмотреть на другие запросы, то они отрабатывают
> > > нормально, т.е. вместе с одним запросом никто другой не висит.
> > >
> > Я хотел взглянуть именно на весь запрос.
> > А точнее, на используемые им функции.
> >
> > > Кстати, где посмотреть кто умеет CHECK_FOR_INTERRUPTS, а кто нет?
> > >
> > Очень я сомневаюсь в том, что где-то можно получить этот список....
> >
> > Предположение насчет CHECK_FOR_INTERRUPTS сделано было на основе вот этого:
> > http://www.nabble.com/what-to-do-when-pg_cancel_backend()-doesnt-work--t3865604.html
> > Там проблема в "неубиваемости" процесса была именно из-за этого -
> > использование некой функции
> > buffer() из PostGIS, которая не умела выходить "по просьбе" админа.
> >
>
> Привет, сорри за молчание. Если интересно, по этому поводу
> развернулась интересная дискуссия в pgsql-general -
> "pg_cancel_backend() does not work with buzz queries".
>

Привет снова,

Мне удалось повторить ситуацию и найти корень зла.

Я запустил один из тяжелых запросов на клиенте (Delphi,
psqlodbc.8.01.0101), затем не дожидаясь окончания (время выполнения
запроса примерно 5 мин) снял процесс через диспетчер задач. Нашел
backend postgres'а:

pgdb:/base/PG-Data # ps -ef |awk '/postgres.*konoplev.*SELECT/'
postgres 8590 8073 2 15:46 ? 00:00:36 postgres: konoplev
transport localhost(35442) SELECT
root 8973 7642 0 16:10 pts/0 00:00:00 awk /postgres.*konoplev.*SELECT/

Посмотрел статус TCP netstat'ом:

pgdb:/base/PG-Data # netstat -pna |grep 8590
tcp 1 0 127.0.0.1:5432 127.0.0.1:35442
CLOSE_WAIT 8590/postgres: kono

Удалённый адрес 127.0.0.1 потому, что клиент коннектится к postgres
через SSH-туннель. Запустил strace, убедился, что процесс активен.
Дождался его окончательного зависания:

pgdb:/base/PG-Data # strace -dfirtvx -p 8590
Process 8590 attached - interrupt to quit
[wait(0x137f) = 8590]
pid 8590 stopped, [SIGSTOP]
[wait(0x57f) = 8590]
pid 8590 stopped, [SIGTRAP]
0.000000 [ffffe410] send(11,
"\x30\x30\x37\x2d\x31\x30\x2d\x31\x39\x20\x32\x32\x3a\x31"...,
8192, 0

[Вывод остановился и спустя несколько минут я прервал strace с помошью Ctrl-C]

cleanup: looking at pid 8590
<unfinished ...>
Process 8590 detached

Запустил gdb и просмотрел callstack:

pgdb:/base/PG-Data # gdb /opt/PostgreSQL/bin/postgres 8590
GNU gdb 6.1
Copyright 2004 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and you are
welcome to change it and/or distribute copies of it under certain conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB. Type "show warranty" for details.
This GDB was configured as "i586-suse-linux"...Using host libthread_db library
"/lib/tls/libthread_db.so.1".

Attaching to program: /opt/PostgreSQL/bin/postgres, process 8590
Reading symbols from /usr/lib/libssl.so.0.9.7...done.
Loaded symbols for /usr/lib/libssl.so.0.9.7
Reading symbols from /usr/lib/libcrypto.so.0.9.7...done.
Loaded symbols for /usr/lib/libcrypto.so.0.9.7
Reading symbols from /lib/libcrypt.so.1...done.
Loaded symbols for /lib/libcrypt.so.1
Reading symbols from /lib/libdl.so.2...done.
Loaded symbols for /lib/libdl.so.2
Reading symbols from /lib/tls/libm.so.6...done.
Loaded symbols for /lib/tls/libm.so.6
Reading symbols from /lib/tls/libc.so.6...done.
Loaded symbols for /lib/tls/libc.so.6
Reading symbols from /lib/ld-linux.so.2...done.
Loaded symbols for /lib/ld-linux.so.2
Reading symbols from /usr/lib/gconv/KOI8-R.so...done.
Loaded symbols for /usr/lib/gconv/KOI8-R.so
Reading symbols from /lib/libnss_files.so.2...done.
Loaded symbols for /lib/libnss_files.so.2
Reading symbols from /opt/PostgreSQL/lib/postgresql/plpgsql.so...done.
Loaded symbols for /opt/PostgreSQL/lib/postgresql/plpgsql.so
0xffffe410 in ?? ()
(gdb) bt
#0 0xffffe410 in ?? ()
#1 0xbfffd718 in ?? ()
#2 0x082f16c0 in sock_path ()
#3 0xbfffd6f0 in ?? ()
#4 0x40254781 in send () from /lib/tls/libc.so.6
#5 0x0814bdf2 in secure_write ()
#6 0x08151632 in internal_flush ()
#7 0x08151704 in internal_putbytes ()
#8 0x08151782 in pq_putmessage ()
#9 0x08152c6a in pq_endmessage ()
#10 0x0807e5fc in printtup ()
#11 0x08134417 in ExecutorRun ()
#12 0x081b50f4 in PortalRunSelect ()
#13 0x081b6271 in PortalRun ()
#14 0x081b1d96 in exec_simple_query ()
#15 0x081b3552 in PostgresMain ()
#16 0x0818e169 in ServerLoop ()
#17 0x0818ed10 in PostmasterMain ()
#18 0x08153841 in main ()
(gdb) quit
The program is running. Quit anyway (and detach it)? (y or n) y
Detaching from program: /opt/PostgreSQL/bin/postgres, process 8590

Убедился, что TCP-стек процесса всё ещё в состоянии CLOSE_WAIT:

pgdb:/base/PG-Data # netstat -pna |grep 8590
tcp 1 0 127.0.0.1:5432 127.0.0.1:35442
CLOSE_WAIT 8590/postgres: kono

Попытался послать SIGINT этому процессу (то же самое, что делает
pg_cancel_backend()):

pgdb:/base/PG-Data # kill -INT 8590

pgdb:/base/PG-Data # ps -ef |grep 8590
postgres 8590 8073 0 15:46 ? 00:00:36 postgres: konoplev
transport localhost(35442) SELECT
root 9869 7642 0 17:17 pts/0 00:00:00 grep 8590

Он всё ещё жив.

Единственное действие которым мне удалось его завершить без
некорректного убивания бэкэнда это завершить SSH процесс, который
взаимодействует с нашим бэкэндом. Получаем PID этого процесса и
убиваем его:

pgdb:/base/PG-Data # netstat -pna |grep 35442
tcp 1 131072 127.0.0.1:5432 127.0.0.1:35442
CLOSE_WAIT 8590/postgres: kono
tcp 65536 0 127.0.0.1:35442 127.0.0.1:5432
FIN_WAIT2 7944/sshd: dcsshcli
pgdb:/base/PG-Data # kill -HUP 7944
pgdb:/base/PG-Data # ps -ef |grep 8590
root 9951 7642 0 17:24 pts/0 00:00:00 grep 8590

Как видно проблемный бэкэнд завершился.

Думаю написать скрипт, который будет убивать соответствующие бэкэндам
в состоянии CLOSE_WAIT SHH процессы с большим временем ожидания. Если
кто-нибудь знает лучшее решение, буду очень благодарен если
поделитесь.

Спасибо.

p.s. Кроспост в pgsql-general - "pg_cancel_backend() does not work
with buzz queries".

--
Regards,
Sergey Konoplev