Вводная
В СУБД PostgreSQL есть такое интересное техническое решение — перед тем как собственно начать что то менять в файлах самой базы данных СУБД пишет уже переведенные во внутренний формат команды в специальный журнал — Write-Ahead Log, а после успешного завершения транзакции делает в этом журнале пометку. Сделано это было для восстановления после сбоев, но в итоге пытливый ум разработчиков дошел до идеи использовать этот журнал для резервирования и репликации. В принципе логично, все ходы в нём записаны, более того можно не просто восстановить данные из бэкапа, но и восстановить состояние базы на определенный момент времени, прервав проигрывание записей WAL-лога в нужный момент.
Однако давайте рассмотрим такой сценарий — допустим в понедельник вы сделали базовый бэкап и запустили архивацию WAL-логов, в среду вы выполнили запрос на удаление с ошибочной маской, а обнаружили это только в пятницу, когда менеджер сообщил об исчезновении какой то нужной ему записи. В данной ситуации мы можем только восстановиться из бэкапа до среды, потеряв всю работу менеджеров за четверг и пятницу.
Возникает логичный вопрос, а нельзя ли сделать проигрывание WAL-логов с понедельника по пятницу, при этом исключив наш «ошибочный» запрос?
В обычной ситуации я ограничился бы вопросом на форум, но у меня было 2 дистрибутива FreeBSD, 10 тарболлов с исходниками PostgreSQL разных версий, 10Гб места на винте, gcc, две относительно незагруженных недели, а также текила, ром, ящик пива и обрывочные воспоминания о синтаксисе языка C. Не то чтобы это был необходимый запас для решения, но раз уж заглянул в исходные коды, то сложно остановиться…
Итак, для экспериментов взяты FreeBSD 10 и PostgreSQL 9.2.8 из её портов. Клиент соответствующей версии можно поставить с помощью pkg, в нем ничего менять не нужно. Заранее извиняюсь за возможное капитанство, но текст писался как для новичков, так и для того чтобы быстро всё освежить в голове в случае необходимости, поэтому все команды расписаны подробно.
Установка и базовая настройка сервера
root@leninzhiv> cd /usr/ports/databases/postgresql92-server
root@leninzhiv> make fetch
root@leninzhiv> make extract
Скачанный файл с исходниками разворачивается в папку work в директории порта. Я честно говоря так и не понял как пересобирать исходники после изменений, какого то make rebuild вроде нету, make clean в свою очередь просто сносит эту папку со всеми изменениями. Поэтому я просто скопировал папку work в свою домашнюю директорию, вносил изменения там, затем копировал в папку порта и запускал make install.
Пока что ничего не меняем, просто ставим постгрес:
root@leninzhiv> make install
Создаем папки для архивов:
root@leninzhiv> mkdir -p /usr/db_archive/wal
root@leninzhiv> mkdir -p /usr/db_archive/data
root@leninzhiv> chown -R pgsql:wheel /usr/pg_archive
Постгрес требует чтобы у директории с данными был доступ только для юзера поэому меняем права:
root@leninzhiv> chmod 0700 /usr/pg_archive/data
Делаем примитивную настройку. Здесь имеет смысл перейти под постгресовую учетку pgsql чтобы было меньше возни с правами на файлы.
root@leninzhiv> su - pgsql
pgsql@leninzhiv> initdb -D /usr/local/pgsql/data
Раскомментируем и правим параметры архивации WAL-логов в /usr/local/pgsql/data/postgresql.conf:
archive_mode=on
wal_level = archive
archive_command = 'test! -f /usr/db_archive/wal/%f && cp %p /usr/db_archive/wal/%f'
(пример там рядом в камментах)
max_wal_senders = 1
В /usr/local/pgsql/data/pg_hba.conf раскомментируем строку
local replication pgsql trust
Стартуем сервер
pgsql@leninzhiv> /usr/local/etc/rc.d/postgresql start
Делаем базовый бэкап
pgsql@leninzhiv> pg_basebackup -D /usr/db_archive/data/
Проверяем, в папке /usr/db_archive/data/ должна лежать копия директории данных, в /usr/db_archive/wal/ должны лежать WAL файлы вида примерно 000000010000000000000003
Копируем в папку с бэкапом директории данных конфиг для восстановления
cp /usr/local/share/postgresql/recovery.conf.sample /usr/db_archive/data/recovery.conf
и в нём раскомменитруем и правим команду восстановления (пример тоже рядом в комментах).
restore_command = 'cp /usr/db_archive/data/%f %p'
Вносим записи:
pgsql@leninzhiv> psql -U pgsql -d postgres
postgres=# CREATE TABLE z (z_id serial, z_text character(50));
postgres=# INSERT INTO z (z_text) VALUES ('Karlin');
postgres=# INSERT INTO z (z_text) VALUES ('Petrov');
postgres=# INSERT INTO z (z_text) VALUES ('Ivanov');
postgres=# INSERT INTO z (z_text) VALUES ('Kaplan');
postgres=# INSERT INTO z (z_text) VALUES ('Karas');
postgres=# INSERT INTO z (z_text) VALUES ('Bukova');
postgres=# INSERT INTO z (z_text) VALUES ('Sidorova');
postgres=# INSERT INTO z (z_text) VALUES ('Karman');
postgres=# INSERT INTO z (z_text) VALUES ('Nikolaev');
Удаляем записи:
postgres=# DELETE FROM z WHERE z_text ILIKE 'Ka%';
Изменяем записи, вносим новые, дискотека
postgres=# UPDATE z SET z_text='Petrova' WHERE z_text='Sidorova';
postgres=# INSERT INTO z (z_text) VALUES ('Kruglov');
postgres=# UPDATE z SET z_text='Alexeeva' WHERE z_text='Bukova';
postgres=# INSERT INTO z (z_text) VALUES ('Kvadrat');
Обнаруживаем что удалять записи по маске было не очень хорошей идеей и вместе с Карлиным мы удалили Каплана, Карася и Кармана.
Останавливаем сервер
pgsql@leninzhiv> /usr/local/etc/rc.d/postgresql stop
pgsql@leninzhiv> exit
root@leninzhiv>
и начинаем думать что же делать.
Идём в исходники
Как вы помните, после make extract я скопировал папку work из директории порта в свою домашнюю папку, и делал изменения в ней. Поэтому переходим туда. Если кто то может подсказать как делать изменения в исходниках в самой папке порта чтобы всё нормально пересобиралось после внесённых в код изменений буду крайне благодарен.
Вначале я поставил себе цель найти то место где считываются из файла записи WAL-логов.
Файл с кодом относящимся к WAL я нашел с помощью поиска строки «WAL» в содержимом файлов директории work/postgresql-9.2.8/src и здравого смысла, это оказался файл xlog.c
Я не умею в трассировку программ на C, поэтому просто в начале каждой функции добавил запись её названия в файл, собрал и запустил.
В файле получился такой вот результат:
bool check_wal_buffers(int *newval, void **extra, GucSource source)
void assign_xlog_sync_method(int new_sync_method, void *extra)
Size XLOGShmemSize(void)
static int XLOGChooseNumBuffers(void)
bool check_wal_buffers(int *newval, void **extra, GucSource source)
void XLOGShmemInit(void)
Size XLOGShmemSize(void)
static void ReadControlFile(void)
void StartupXLOG(void)
static void ReadControlFile(void)
static char * str_time(pg_time_t tnow)
static void ValidateXLOGDirectoryStructure(void)
static void readRecoveryCommandFile(void)
static List * readTimeLineHistory(TimeLineID targetTLI)
static bool read_backup_label(XLogRecPtr *checkPointLoc, bool *backupEndRequired, bool *backupFromStandby)
static XLogRecord * ReadCheckpointRecord(XLogRecPtr RecPtr, int whichChkpt)
static XLogRecord * ReadRecord(XLogRecPtr *RecPtr, int emode, bool fetching_ckpt)
static bool XLogPageRead(XLogRecPtr *RecPtr, int emode, bool fetching_ckpt, bool randAccess)
static int XLogFileReadAnyTLI(uint32 log, uint32 seg, int emode, int sources)
...
static XLogRecord * ReadRecord(XLogRecPtr *RecPtr, int emode, bool fetching_ckpt)
static bool XLogPageRead(XLogRecPtr *RecPtr, int emode, bool fetching_ckpt, bool randAccess)
static bool RecordIsValid(XLogRecord *record, XLogRecPtr recptr, int emode)
static bool recoveryStopsHere(XLogRecord *record, bool *includeThis)
static void CheckRecoveryConsistency(void)
static XLogRecord * ReadRecord(XLogRecPtr *RecPtr, int emode, bool fetching_ckpt)
static bool XLogPageRead(XLogRecPtr *RecPtr, int emode, bool fetching_ckpt, bool randAccess)
...
В общем, у меня сложилось впечатление что основное действие происходит в цикле ReadRecord -> XLogPageRead -> RecordIsValid -> RecoveryStopsHere -> CheckRecoveryConsistency.
Более близкое знакомтсво с функицей ReadRecord показало что она возвращает запись в двух местах — как return record и как return (XLogRecord *) buffer, вышеуказанным нехитрым способом уточняем что в процессе восстановления с WAL-логов возврат идёт через return (XLogRecord *) buffer. Прекрасно! Пишем результат в файл.
Структуру типа XLogRecord можно посмотреть в файле xlog.h и она достаточно лаконична:
typedef struct XLogRecord
{
pg_crc32 xl_crc; /* CRC for this record */
XLogRecPtr xl_prev; /* ptr to previous record in log */
TransactionId xl_xid; /* xact id */
uint32 xl_tot_len; /* total len of entire record */
uint32 xl_len; /* total len of rmgr data */
uint8 xl_info; /* flag bits, see below */
RmgrId xl_rmid; /* resource manager for this record */
/* ACTUAL LOG DATA FOLLOWS AT END OF STRUCT */
} XLogRecord;
Отлично, если у нас есть длина, то и используем её для вывода содержимого записи в файл, перед return (XLogRecord *) buffer добавляем:
FILE *pf2 = fopen("/usr/local/pgsql/data/log3.txt", "a"); char *buf_poi = buffer;
for (uint32 i=0; i < record->xl_tot_len; i++) {fputc(*buf_poi, pf2); buf_poi++;}
fprintf(pf2, "\n crc32: %u \n xl_xid=%i \n", record->xl_crc, record->xl_xid);
fclose(pf2);
Сносим старый Постгрес, собираем и устаналиваем новый:
root@leninzhiv> cd /usr/ports/databases/postgresql92-server
root@leninzhiv> make deinstall
Напоминаю что мы скопировали директорию work в домашнюю папку и все изменения кода вносили там. Теперь копируем её на место папки work в директории порта.
root@leninzhiv> rm -R /usr/ports/databases/postgresql92-server/work
root@leninzhiv> cp -R ~/work /usr/ports/databases/postgresql92-server/work
root@leninzhiv> make install
Удаляем файлы базы данных и копируем на их место базовый бэкап. WAL-файлы сами подтянутся.
root@leninzhiv> su - pgsql
pgsql@leninzhiv> /usr/local/etc/rc.d/postgresql stop
pgsql@leninzhiv> rm -R /usr/local/pgsql/data
pgsql@leninzhiv> cp -R /usr/db_archive/data /usr/local/pgsql/data
pgsql@leninzhiv> /usr/local/etc/rc.d/postgresql start
pgsql@leninzhiv> psql -U pgsql -d postgres
postgres=# select * from z;
postgres=# \q
pgsql@leninzhiv> /usr/local/etc/rc.d/postgresql stop
Смотрим содержимое файла log3.txt, вначале идем много больших записей, видимо создание служебных таблиц и данных, ближе к концу видим:
Г#{Ы####РT##к###r###R####
##########0###@###### #e######## ###gNikolaev
crc32: 3682278083
l_xid=1002
W#
М#####U##к###,###
###`#######Т›ЩЌ%ћ######
crc32: 3423214679
xl_xid=1002
r"Х ####xU##л###5########
##########0###@########Я##
crc32: 2698322546
xl_xid=1003
#Щ%2####ЁU##л###5########
##########0###@########Я##
crc32: 841341184
xl_xid=1003
ь#Wз####аU##л###5########
##########0###@########Я##
crc32: 3881244668
xl_xid=1003
Z7#р#####V##л###5########
##########0###@########Я##
crc32: 4028315482
xl_xid=1003
µЄЈђ####PV##л###,###
###`########ЄЩЌ%ћ######
crc32: 2426645173
xl_xid=1003
Уњ-B####€V##м###y###Y###@
##########0###@########I#####
####Ђ#(######gPetrova
crc32: 1110285523
xl_xid=1004
Видим что между знакомыми фамилиями Николаев и Петрова есть 4 похожие записи и одна непохожая, под одним номером транзакции. Видимо, это команды удаления, значит в WAL-лог записываются уже команды типа «стереть строку 50 в таблице 64822». В принципе, как и ожидалось. Дописываем проверку, которая при значении xl_xid=1003 вместо записи возвращает NULL.
Опять удаляем старый Постгрес, собираем и устанавливаем новый, запускаем восстановление…
Удаленные записи на месте! Правда все что должно было произойти после удаления не произошло :( Что ж, с наскока взять не получилось. В общем то понятно, ведь перед проигрыванием записи проходят проверки целостности и всего такого.
Значит цель номер 2 — найти где идет «проигрывание» записи. Быстрый поиск использования readRecord в том же файле привел меня к функции void StartupXLOG(void)… И вот тут я отчетливо понял что до сего момента шел не тем путем, потому что почти сразу после второго-третьего появления в этой функции вызова readRecord (они там рядом) сразу идёт во первых шикарный диагностический кусок, а во вторых, сразу после комментария «Now apply the WAL record itself» — команда проигрыша записи RmgrTable[record->xl_rmid].rm_redo(EndRecPtr, record);
Изменим этот кусок кода на
if (record->xl_xid==1003)
{}
else RmgrTable[record->xl_rmid].rm_redo(EndRecPtr, record);
Опять пересобираем, запускаем, проверяем… Победа! Удаленные записи на месте и изменения, сделанные после удаления тоже на месте!
Ориентируемся на местности
Что ж, это, несомненно, хорошо, но задачу мы решили на крайне ограниченном наборе данных, а вот как найти нужную запись в логах рабочей базы?
Вернемся к упомянутому шикарному диагностическому куску в функции StartupXLOG:
#ifdef WAL_DEBUG
if (XLOG_DEBUG ||
(rmid == RM_XACT_ID && trace_recovery_messages <= DEBUG2) ||
(rmid != RM_XACT_ID && trace_recovery_messages <= DEBUG3))
{
StringInfoData buf;
initStringInfo(&buf);
appendStringInfo(&buf, "REDO @ %X/%X; LSN %X/%X: ",
ReadRecPtr.xlogid, ReadRecPtr.xrecoff,
EndRecPtr.xlogid, EndRecPtr.xrecoff);
xlog_outrec(&buf, record);
appendStringInfo(&buf, " - ");
RmgrTable[record->xl_rmid].rm_desc(&buf,
record->xl_info,
XLogRecGetData(record));
elog(LOG, "%s", buf.data);
pfree(buf.data);
}
#endif
Можно просто включить вывод в логи, раскомментировав #define WAL_DEBUG в pg_config_manual.h и добавив wal_debug=on в файл postgresql.conf, но я, по привычке, направил вывод в отдельный файл. Этот кусок, как я понял, выводит описание команды с помощью функции rm_desc (в данном случае RmgrTable является массивом функций?), выглядит оно примерно так:
REDO @ 0/3015500; LSN 0/3015578: prev 0/30154D0; xid 1002; len 82: Heap - insert: rel 1663/12318/16386; tid 0/9
REDO @ 0/3015578; LSN 0/30155A8: prev 0/3015500; xid 1002; len 12: Transaction - commit: 2014-06-06 08:38:27.537874+00
REDO @ 0/30155A8; LSN 0/30155E0: prev 0/3015578; xid 1003; len 21: Heap - delete: rel 1663/12318/16386; tid 0/1
REDO @ 0/30155E0; LSN 0/3015618: prev 0/30155A8; xid 1003; len 21: Heap - delete: rel 1663/12318/16386; tid 0/4
REDO @ 0/3015618; LSN 0/3015650: prev 0/30155E0; xid 1003; len 21: Heap - delete: rel 1663/12318/16386; tid 0/5
REDO @ 0/3015650; LSN 0/3015688: prev 0/3015618; xid 1003; len 21: Heap - delete: rel 1663/12318/16386; tid 0/8
REDO @ 0/3015688; LSN 0/30156B8: prev 0/3015650; xid 1003; len 12: Transaction - commit: 2014-06-06 08:38:27.54153+00
REDO @ 0/30156B8; LSN 0/3015738: prev 0/3015688; xid 1004; len 89: Heap - hot_update: rel 1663/12318/16386; tid 0/7; new 0/10
Это уже знакомый нам кусок с номером транзакции 1003, и по нему мы можем увидеть что да, это четыре команды на удаление и одно подтверждение транзакции. В командах на удаление мы видим rel — идентификатор таблицы в формате «oid пространства имен/oid базы данных/oid таблицы». Соответствующие циферки можно получить запросами
SELECT oid, spcname FROM pg_catalog.pg_tablespace;
SELECT oid, datname FROM pg_catalog.pg_database;
и, внезапно,
SELECT oid, relname FROM pg_catalog.pg_class;
Второй ориентир — в описании транзакции есть отметка времени. Ну, тут ничего объяснять не надо, если мы знаем когда этот самый crime был commited, то и соответсвующие записи найдем.
Ну и, как альтернативный способ, можно вернуться к просмотру записей в кракозябрах, и ориентироваться по обрывкам текстов которые были переданы как параметры командам INSERT и UPDATE, если мы помним запросы с какими параметрами делались незадолго до или после искомого «ошибочного» запроса. В случае UPDATE, правда, можно найти только те, строки которые использовались как новое значение, если строка использовалась для поиска записей, то в WAL-логах она не встречается.
Ну и напоследок могу отметить что в контрибах PostgreSQL 9.3 появилась утилита pg_xlogdump, которая, вроде бы, как раз нацелена на решение задачи предоставления содержимого WAL-логов в человекочитаемом виде. Если вы заинтересованы в каких то фичах то имеет смысл писать разработчикам.
Вполне возможно что использование этого метода на архивах рабочей БД будет иметь какие то подводные камни. Например как отработают UPDATE-ы, если мы «пропустим» удаление части записей на базе данных в которой используется частое вакуумирование? Я не проверял. Но в любом случае в случае лучше иметь хоть какую то надежду исправить ошибку, чем совсем никакой.
