О-о-о! Зрители уже собираются!
Ну что ж - постараемся не обмануть ожиданий болельщиков... :)
Начало недели было занято праздничными днями, поэтому развития сюжета почти не было.
К решению вопроса 'Что делать?' еще не приступили. Однако кое-что интересное обнаружилось по поводу другого классического вопроса - 'Кто виноват?'. Думаю, что публике это тоже будет любопытно.
================================================================
Напомню, что изъян нашего проблемного архива состоит в том, что в него при создании ontape'ом не был автоматически включен log-файл, который содержит исходную checkpoint, соответствующую старту архивации (т.е. от которой нужно накатывть транзакции или на которой нужно остаться, если 'холодное' восстановление делается 'with no Logical Restore').
Из-за этого после завершения Physical Restore не может корректно начаться Fast Recovery, т.к. у IDS вообще нет текущего логического журнала (и, следовательно, отправной контрольной точки):
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
> % onstat -l
> . . .
> address number flags uniqid begin size used %used
> a499cdc 1 F------ 0 1010a7 2048 0 0.00
> a499cf8 2 F------ 0 1018a7 2048 0 0.00
> a499d14 3 F------ 0 1020a7 2048 0 0.00
> a499d30 4 F------ 0 1028a7 2048 0 0.00
> a499d4c 5 F------ 0 1030a7 2048 0 0.00
> a499d68 6 F------ 0 1038a7 2048 0 0.00
> a499d84 7 F------ 0 1040a7 2048 0 0.00
> a499da0 8 F------ 0 1048a7 2048 0 0.00
> a499dbc 9 F------ 0 1050a7 2048 0 0.00
> a499dd8 10 F------ 0 1058a7 2048 0 0.00
> a499df4 11 F------ 0 1060a7 2048 0 0.00
> a499e10 12 F------ 0 1068a7 2048 0 0.00
И здесь уже не важно - есть ли backup'ы log'ов (в т.ч. и критичного - с исходной контрольной точкой) или нет.
Накат транзакций (т.е. Logical Restore) просто не может корректно стартовать, т.к. у informix'а нет отправной точки для наката. Это оказывается неприятной неожиданностью и для него самого. Причем настолько неприятной, что при попытке выполнить накат он падает самым позорным образом:
1.
2.
3.
4.
5.
6.
7.
8.
> % ontape -l
> Please mount tape 1 on <...> and press Return to continue ...
>
> Roll forward should start with log number 28
>
> Logical restore failed - buc_fe.c : Archive API processing failed
> at line 920 for msgtype
>
> Program over.
Соответствующее место из online.log:
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.
# 21:59:09 Logical Recovery Started.
# 21:59:09 Checkpoint Completed: duration was 0 seconds.
# 21:59:09 Checkpoint loguniq 27, logpos 0x7ff018
#
# 21:59:09 Start Logical Recovery - Start Log 28, End Log ?
# 21:59:09 Starting Log Position - 27 0x7ff018
# 21:59:33 Logical Recovery ABORTED.
# Log recovery needs to start with log 28.
#
# 21:59:33 Assert Failed: Logical Recovery ABORTED.
# Dynamic Server 2000 must abort
# 21:59:33 Informix Dynamic Server 2000 Version 9.20.UC2
# 21:59:33 Who: Session(10, informix@dwarf, 21495, 202381548)
# Thread(31, ontape, c0d3cd8, 1)
# File: rslgr.c Line: 1079
# 21:59:33 stack trace for pid 21446 written to /tmp/af.40792f4
# 21:59:33 See Also: /tmp/af.40792f4
# 21:59:54 rslgr.c, line 1079, thread 31, proc id 21446,
# Logical Recovery ABORTED.
# Dynamic Server 2000 must abort.
# 21:59:54 The Master Daemon Died
# 21:59:54 PANIC: Attempting to bring system down
# 21:59:54 semctl: errno = 22
#
# 21:59:54 semctl: errno = 22
# . . .
Собственно, ДЛЯ РЕАНИМИРОВАНИЯ ДАННОГО INSTANC'А НУЖНО КАКИМ-ТО ОБРАЗОМ ПРОПИСАТЬ В LOG-ЖУРНАЛ ИНФОРМАЦИЮ О ТЕКУЩЕМ LOG-ФАЙЛЕ И О ОБ ИСХОДНОЙ КОНТРОЛЬНОЙ ТОЧКЕ (возможно, нужно скорректировать и еще какую-то связанную с этим информацию).
Обычными средствами (типа ontape) это, похоже, сделать невозможно.
Сейчас ожидаем ответа по своим древним связям с американским Informix'ом. Если ничего конструктивного не ответят, то, придется брать "помощь зала" (намекаю на GVF112GVF).
================================================================
Пока же, чтобы зрители не скучали, несколько слов о причинах (точнее об обстоятельствах) происшедшего.
Во-первых, получилось устойчиво воспроизводить ситуацию с созданием такого вот ущербного архива (log-журнал в котором не содержит текущего log-файла и текущей контрольной точки).
Условия возникновения ошибки несколько отличаются от тех, которые я предположил в первом посте.
Так вот:
- Совершенно не имеет значения, куда и как бэкапируются log-файлы - в /dev/null или 'на ленту' (в файл).
- Также не является существенным наличие других сеансов, которые бы вызывали заполнение текщего log-файла и его завершение как раз в момент старта архивирования.
А важно лишь то, что checkpoint, соответствующий старту архивации, оказывается самой последней записью в log-файле, а информация об архиве попадает уже в следующий файл.
См.выше в примере: размер файла log-журнала 2048, т.е. максимальный адрес - это 0x7fffff (точнее, 0x7fffff минус минимальный размер журнальной записи). Если 'архивная' контрольная точка получает адрес больше 0x7ff000, то создаваемый архив ГАРАНТИРОВАННО (по крайней мере, на моей инсталляции) НЕ БУДЕТ СОДЕРЖАТЬ НИКАКОГО LOG-ФАЙЛА и, следовательно, окажется невосстановимым.
(Напоминаю, все это происходит на IDS 9.20.UC2 Sun Solaris 8).
Onlog отображает эту последовательность так:
1.
2.
3.
4.
5.
6.
7.
8.
9.
10.
11.
12.
13.
14.
15.
16.
17.
18.
19.
20.
# log number: 27.
# addr len type xid id link
# ...
# 7fc7e4 56 HUPDAT 6 0 7fc7ac 500030 18e0b 0 128 128 1
# 7fd038 56 HUPDAT 6 0 7fc7e4 500030 18e0c 0 128 128 1
# 7fd070 36 COMMIT 6 0 7fd038 06/13/2007 18:34:32
# 7fe018 32 CKPOINT 1 27 0 0
# 7ff018 32 CKPOINT 1 27 0 0
#
# log number: 28.
#
# 18 52 ARCINFO 9 28 0 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# 4c 52 ARCINFO 9 0 18 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# 80 52 ARCINFO 9 0 4c 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# b4 52 ARCINFO 9 0 80 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# e8 52 ARCINFO 9 0 b4 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# 11c 52 ARCINFO 9 0 e8 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# 150 52 ARCINFO 9 0 11c 0 06/13/2007 18:35:03 0x17454d 27 0x7ff018
# 1018 32 CKPOINT 1 28 0 0
# 2018 52 LOGINFO 6 28 0 26 06/13/2007 20:46:35 0x1745ab
# 3018 52 LOGINFO 6 0 2018 27 06/13/2007 20:46:36 0x1745ac
CKPOINT(7fe018) - это результат ручного исполнения onmode -c.
CKPOINT(7ff018) - сделан автоматически при старте архивации.
-- - - -
Такой вот сюрприз - можно добросовестно бэкапировать все log'и, отключать все сессии перед запуском архиватора (хоть это никогда и не требуется) и в результате получить невосстановимый архив!
(Понятно, что зная эту коварную особенность, ее легко обойти - достаточно выполнить onmode -l перед стартом архивации. Вот я и подумал - может быть этот добрый совет приводится где-нибудь в документации?).
Интересно было бы проверить это и на других инсталляциях (у нас есть 9.40 для LINUX'а, доступен также 10 для Solaris'а - если будет время и желание, то поэкспериментирую).
========================================================================
