Re: [pgsql-ru-general] несколько upadate + убитие процесса + защита мультитранзакций + останов кластера

Доброго всем.

На слабеньком тестовом двухядерном компе 2Гб RAM запустил приличную
базу данных.

На приличной таблице стал оптимизировать столбцы, запускал разные
update, что-то останавливал по Ctrl+C, запускал в разных сеансах psql.

Потом заметил, что не остановился ненужный update, причем прошло
больше суток по времени и видимо наросла большая транзакция. Посмотрел
его pid и сделал kill <pid>, потом еще зачем-то kill -9 <pid>. И вот.

logfile:
СООБЩЕНИЕ: процесс сервера (PID 16263) был завершён по сигналу 9: Killed
ПОДРОБНОСТИ: Завершившийся процесс выполнял действие: update ...
СООБЩЕНИЕ: завершение всех остальных активных серверных процессов
ПРЕДУПРЕЖДЕНИЕ: закрытие подключения из-за краха другого серверного процесса
ПОДРОБНОСТИ: Управляющий процесс отдал команду этому серверному
процессу откатить текущую транзакцию и завершиться, так как другой
серверный процесс завершился аварийно и возможно разрушил разделяемую память.
ПОДСКАЗКА: Вы сможете переподключиться к базе данных и повторить вашу
команду сию минуту.
....
ВАЖНО: система баз данных в режиме восстановления
СООБЩЕНИЕ: все серверные процессы завершены... переинициализация
ВАЖНО: система баз данных в режиме восстановления
СООБЩЕНИЕ: работа системы БД была прервана; последний момент работы:
2016-07-28 17:42:05 YEKT
СООБЩЕНИЕ: система БД была остановлена нештатно; производится
автоматическое восстановление
ВАЖНО: система баз данных в режиме восстановления
СООБЩЕНИЕ: запись REDO начинается со смещения 4/443CBA40
СООБЩЕНИЕ: запись нулевой длины по смещению 4/443D4730
СООБЩЕНИЕ: записи REDO обработаны до смещения 4/443D4700
СООБЩЕНИЕ: последняя завершённая транзакция была выполнена в
2016-07-28 17:43:11.917649+06
ВАЖНО: система баз данных в режиме восстановления
ВАЖНО: система баз данных в режиме восстановления
ВАЖНО: система баз данных в режиме восстановления
ВАЖНО: система баз данных в режиме восстановления
СООБЩЕНИЕ: Защита от наложения мультитранзакций сейчас включена
СООБЩЕНИЕ: система БД готова принимать подключения
СООБЩЕНИЕ: процесс запуска автоочистки создан

При этом в другом процессе тоже шел большой update той же таблицы. Там вышло:

ПРЕДУПРЕЖДЕНИЕ: закрытие подключения из-за краха другого серверного процесса
ПОДРОБНОСТИ: Управляющий процесс отдал команду этому серверному
процессу откатить текущую транзакцию и завершиться, так как другой
серверный процесс завершился аварийно и возможно разрушил разделяемую
память.
ПОДСКАЗКА: Вы сможете переподключиться к базе данных и повторить вашу
команду сию минуту.
КОНТЕКСТ: при изменении кортежа (73696,1) в отношении "tableXXX"
сервер неожиданно закрыл соединение
Скорее всего сервер прекратил работу из-за сбоя
до или в процессе выполнения запроса.
Подключение к серверу потеряно. Попытка восстановления неудачна.

Через несколько минут зашел psql - данных в таблицах нет, не
показываются, во всех таблицах 0 строк.

Стал останавливать сервер:
СООБЩЕНИЕ: получен запрос на "вежливое" выключение
СООБЩЕНИЕ: процесс запуска автоочистки завершается
ВАЖНО: система баз данных останавливается
...

Все. Больше суток система висит или делаются откаты транзакций, не
понятно. Ощущение, что не дождусь позитивного останова сервера. Что
можно сделать, чтобы перезапустить кластер, пусть с потерями последних
транзакций?

--
---
С уважением,
Михаил

> Все. Больше суток система висит или делаются откаты транзакций, не
> понятно. Ощущение, что не дождусь позитивного останова сервера. Что
> можно сделать, чтобы перезапустить кластер, пусть с потерями последних
> транзакций?

а WAL-лог был включен?
можно попробовать откатиться назад по чекпоинту и WAL, правда если
запрос висел несколько часов - хз
--

. ''`. Dmitry E. Oboukhov
: :’ : email: unera(at)debian(dot)org jabber://UNera(at)uvw(dot)ru
`. `~’ GPGKey: 1024D / F8E26537 2006-11-21
`- 1B23 D4F8 8EC0 D902 0555 E438 AB8C 00CF F8E2 6537

>На слабеньком тестовом двухядерном компе 2Гб RAM запустил приличную
>базу данных.
>
>На приличной таблице стал оптимизировать столбцы, запускал разные
>update, что-то останавливал по Ctrl+C, запускал в разных сеансах psql.
...
>Стал останавливать сервер:
>СООБЩЕНИЕ: получен запрос на "вежливое" выключение
>СООБЩЕНИЕ: процесс запуска автоочистки завершается
>ВАЖНО: система баз данных останавливается
>...
>
>Все. Больше суток система висит или делаются откаты транзакций, не
>понятно. Ощущение, что не дождусь позитивного останова сервера. Что
>можно сделать, чтобы перезапустить кластер, пусть с потерями последних
>транзакций?

fsync был в каком состоянии?

--
Ай ам

Добрый день,

> On 29 Jul 2016, at 08:50, Михаил <m(dot)nasedkin(at)gmail(dot)com> wrote:
>
> Доброго всем.
>
> На слабеньком тестовом двухядерном компе 2Гб RAM запустил приличную
> базу данных.
>
> На приличной таблице стал оптимизировать столбцы, запускал разные
> update, что-то останавливал по Ctrl+C, запускал в разных сеансах psql.
>
> Потом заметил, что не остановился ненужный update, причем прошло
> больше суток по времени и видимо наросла большая транзакция. Посмотрел
> его pid и сделал kill <pid>, потом еще зачем-то kill -9 <pid>.

Лучше делать SELECT pg_terminate_backend(pid) из SQL запроса. Это эквивалентно kill <pid>.

> И вот.
>
> logfile:
> СООБЩЕНИЕ: процесс сервера (PID 16263) был завершён по сигналу 9: Killed
> ПОДРОБНОСТИ: Завершившийся процесс выполнял действие: update ...
> СООБЩЕНИЕ: завершение всех остальных активных серверных процессов
> ПРЕДУПРЕЖДЕНИЕ: закрытие подключения из-за краха другого серверного процесса
> ПОДРОБНОСТИ: Управляющий процесс отдал команду этому серверному
> процессу откатить текущую транзакцию и завершиться, так как другой
> серверный процесс завершился аварийно и возможно разрушил разделяемую память.
> ПОДСКАЗКА: Вы сможете переподключиться к базе данных и повторить вашу
> команду сию минуту.
> ....
> ВАЖНО: система баз данных в режиме восстановления
> СООБЩЕНИЕ: все серверные процессы завершены... переинициализация
> ВАЖНО: система баз данных в режиме восстановления
> СООБЩЕНИЕ: работа системы БД была прервана; последний момент работы:
> 2016-07-28 17:42:05 YEKT
> СООБЩЕНИЕ: система БД была остановлена нештатно; производится
> автоматическое восстановление
> ВАЖНО: система баз данных в режиме восстановления
> СООБЩЕНИЕ: запись REDO начинается со смещения 4/443CBA40
> СООБЩЕНИЕ: запись нулевой длины по смещению 4/443D4730
> СООБЩЕНИЕ: записи REDO обработаны до смещения 4/443D4700
> СООБЩЕНИЕ: последняя завершённая транзакция была выполнена в
> 2016-07-28 17:43:11.917649+06
> ВАЖНО: система баз данных в режиме восстановления
> ВАЖНО: система баз данных в режиме восстановления
> ВАЖНО: система баз данных в режиме восстановления
> ВАЖНО: система баз данных в режиме восстановления
> СООБЩЕНИЕ: Защита от наложения мультитранзакций сейчас включена
> СООБЩЕНИЕ: система БД готова принимать подключения
> СООБЩЕНИЕ: процесс запуска автоочистки создан
>
> При этом в другом процессе тоже шел большой update той же таблицы. Там вышло:
>
> ПРЕДУПРЕЖДЕНИЕ: закрытие подключения из-за краха другого серверного процесса
> ПОДРОБНОСТИ: Управляющий процесс отдал команду этому серверному
> процессу откатить текущую транзакцию и завершиться, так как другой
> серверный процесс завершился аварийно и возможно разрушил разделяемую
> память.
> ПОДСКАЗКА: Вы сможете переподключиться к базе данных и повторить вашу
> команду сию минуту.
> КОНТЕКСТ: при изменении кортежа (73696,1) в отношении "tableXXX"
> сервер неожиданно закрыл соединение
> Скорее всего сервер прекратил работу из-за сбоя
> до или в процессе выполнения запроса.
> Подключение к серверу потеряно. Попытка восстановления неудачна.

Это следствие kill -9. Сервер увидел, что один из процессов завершился аварийно.
Так как этот процесс мог навредить в разделяемой памяти, в которой хранятся “грязные” данные из таблиц - сервер завершил все остальные процессы

>
> Через несколько минут зашел psql - данных в таблицах нет, не
> показываются, во всех таблицах 0 строк.

Это странно. Были ли какие-нибудь еще сообщения об ошибках?
Были ли это временные или нежурналируемые таблицы?
Были ли в этих таблицах данные до запуска транзакций, которые были в процессе работы на момент аварийного завершения процессов?

>
> Стал останавливать сервер:
> СООБЩЕНИЕ: получен запрос на "вежливое" выключение
> СООБЩЕНИЕ: процесс запуска автоочистки завершается
> ВАЖНО: система баз данных останавливается

Обычный pg_ctl stop ждет, пока все соединения не завершатся.

> ...
>
> Все. Больше суток система висит или делаются откаты транзакций, не
> понятно. Ощущение, что не дождусь позитивного останова сервера. Что
> можно сделать, чтобы перезапустить кластер, пусть с потерями последних
> транзакций?

Попробуйте pg_ctl -mf fast stop (быстрая остановка) и потом pg_ctl start.

--
Oleksii

29.07.16, Oleksii Kliukin<alexk(at)hintbits(dot)com> написал(а):
> Добрый день,
>
>> On 29 Jul 2016, at 08:50, Михаил <m(dot)nasedkin(at)gmail(dot)com> wrote:
>>
>> Доброго всем.
>>
>> На слабеньком тестовом двухядерном компе 2Гб RAM запустил приличную
>> базу данных.
>>
>> На приличной таблице стал оптимизировать столбцы, запускал разные
>> update, что-то останавливал по Ctrl+C, запускал в разных сеансах psql.
>>
>> Потом заметил, что не остановился ненужный update, причем прошло
>> больше суток по времени и видимо наросла большая транзакция. Посмотрел
>> его pid и сделал kill <pid>, потом еще зачем-то kill -9 <pid>.
>
> Лучше делать SELECT pg_terminate_backend(pid) из SQL запроса. Это
> эквивалентно kill <pid>.

Хорошо.

>
>> И вот.
>>
>> logfile:
>> СООБЩЕНИЕ: процесс сервера (PID 16263) был завершён по сигналу 9: Killed
>> ПОДРОБНОСТИ: Завершившийся процесс выполнял действие: update ...
>> СООБЩЕНИЕ: завершение всех остальных активных серверных процессов
>> ПРЕДУПРЕЖДЕНИЕ: закрытие подключения из-за краха другого серверного
>> процесса
>> ПОДРОБНОСТИ: Управляющий процесс отдал команду этому серверному
>> процессу откатить текущую транзакцию и завершиться, так как другой
>> серверный процесс завершился аварийно и возможно разрушил разделяемую
>> память.
>> ПОДСКАЗКА: Вы сможете переподключиться к базе данных и повторить вашу
>> команду сию минуту.
>> ....
>> ВАЖНО: система баз данных в режиме восстановления
>> СООБЩЕНИЕ: все серверные процессы завершены... переинициализация
>> ВАЖНО: система баз данных в режиме восстановления
>> СООБЩЕНИЕ: работа системы БД была прервана; последний момент работы:
>> 2016-07-28 17:42:05 YEKT
>> СООБЩЕНИЕ: система БД была остановлена нештатно; производится
>> автоматическое восстановление
>> ВАЖНО: система баз данных в режиме восстановления
>> СООБЩЕНИЕ: запись REDO начинается со смещения 4/443CBA40
>> СООБЩЕНИЕ: запись нулевой длины по смещению 4/443D4730
>> СООБЩЕНИЕ: записи REDO обработаны до смещения 4/443D4700
>> СООБЩЕНИЕ: последняя завершённая транзакция была выполнена в
>> 2016-07-28 17:43:11.917649+06
>> ВАЖНО: система баз данных в режиме восстановления
>> ВАЖНО: система баз данных в режиме восстановления
>> ВАЖНО: система баз данных в режиме восстановления
>> ВАЖНО: система баз данных в режиме восстановления
>> СООБЩЕНИЕ: Защита от наложения мультитранзакций сейчас включена
>> СООБЩЕНИЕ: система БД готова принимать подключения
>> СООБЩЕНИЕ: процесс запуска автоочистки создан
>>
>> При этом в другом процессе тоже шел большой update той же таблицы. Там
>> вышло:
>>
>> ПРЕДУПРЕЖДЕНИЕ: закрытие подключения из-за краха другого серверного
>> процесса
>> ПОДРОБНОСТИ: Управляющий процесс отдал команду этому серверному
>> процессу откатить текущую транзакцию и завершиться, так как другой
>> серверный процесс завершился аварийно и возможно разрушил разделяемую
>> память.
>> ПОДСКАЗКА: Вы сможете переподключиться к базе данных и повторить вашу
>> команду сию минуту.
>> КОНТЕКСТ: при изменении кортежа (73696,1) в отношении "tableXXX"
>> сервер неожиданно закрыл соединение
>> Скорее всего сервер прекратил работу из-за сбоя
>> до или в процессе выполнения запроса.
>> Подключение к серверу потеряно. Попытка восстановления неудачна.
>
> Это следствие kill -9. Сервер увидел, что один из процессов завершился
> аварийно.
> Так как этот процесс мог навредить в разделяемой памяти, в которой хранятся
> “грязные” данные из таблиц - сервер завершил все остальные процессы
>

Все верно.

>> Через несколько минут зашел psql - данных в таблицах нет, не
>> показываются, во всех таблицах 0 строк.
>
> Это странно. Были ли какие-нибудь еще сообщения об ошибках?

Пара строк про кортежи таблицы. И еще:
СООБЩЕНИЕ: запись REDO начинается со смещения 4/443CBA40
СООБЩЕНИЕ: запись нулевой длины по смещению 4/443D4730
СООБЩЕНИЕ: записи REDO обработаны до смещения 4/443D4700

> Были ли это временные или нежурналируемые таблицы?
Вот да. Таблицы в базе нежурналируемые. Я попал?

> Были ли в этих таблицах данные до запуска транзакций, которые были в
> процессе работы на момент аварийного завершения процессов?
Все были заполнены.

>>
>> Стал останавливать сервер:
>> СООБЩЕНИЕ: получен запрос на "вежливое" выключение
>> СООБЩЕНИЕ: процесс запуска автоочистки завершается
>> ВАЖНО: система баз данных останавливается
>
> Обычный pg_ctl stop ждет, пока все соединения не завершатся.

Все соединения сам завершил. Сейчас при заходе psql выдает:
psql: ВАЖНО: система баз данных останавливается

>>
>> Все. Больше суток система висит или делаются откаты транзакций, не
>> понятно. Ощущение, что не дождусь позитивного останова сервера. Что
>> можно сделать, чтобы перезапустить кластер, пусть с потерями последних
>> транзакций?
>
> Попробуйте pg_ctl -mf fast stop (быстрая остановка) и потом pg_ctl start.

Буду пробовать. Несколько дней висит.

> --
> Oleksii
>
>

Еще отвечу про fsync. Я никогда этим не пользовался и если честно не понимаю.

Спасибо за ответы.

--
---
С уважением,
Михаил

Да это все. Данные в нежурналируемых таблицах грохнулись.

--
---
С уважением,
Михаил Наседкин