Thread: несколько 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@debian.org jabber://UNera@uvw.ru
`. `~’              GPGKey: 1024D / F8E26537 2006-11-21
  `- 1B23 D4F8 8EC0 D902 0555  E438 AB8C 00CF F8E2 6537

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

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

--
Ай ам

Добрый день, 

> On 29 Jul 2016, at 08:50, Михаил <m.nasedkin@gmail.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@hintbits.com> написал(а):
> Добрый день,
>
>> On 29 Jul 2016, at 08:50, Михаил <m.nasedkin@gmail.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. Я никогда этим не пользовался и если честно не понимаю.

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

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

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

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