Всем привет.

Подскажите в каком направлении капать?

Система:
Solaris 10 + Informix 9.4

Предыстория:
Появилась необходимость создать на другом сервере образ БД и регулярно его обновлять.
Для этого я на новом сервере установил Informix, воссоздал структуру из чанков, натравил бэкап и выполнил рестор (onbar -r -p, onbar -r -l).

Судя по onbar-логу Рестор завершился без ошибок:
2009-12-26 15:57:38 3522 3520 Completed restore logical log 72955.
2009-12-26 15:59:11 3522 3520 Begin restore logical log 72956 (Storage Manager copy ID: 11261817373).
2009-12-26 15:59:18 3522 3520 Completed restore logical log 72956.
2009-12-26 16:03:22 3522 3520 Completed logical restore.
2009-12-26 16:03:23 4628 4626 /opt/informix/Ifx940FC6/bin/onbar_d -b -l
2009-12-26 16:03:23 4628 4626 Working with veritas-netbackup as generic storage manager.
2009-12-26 16:03:23 4628 4626 /opt/informix/Ifx940FC6/bin/onbar_d complete, returning 0 (0x00)
2009-12-26 16:03:37 3522 3520 /opt/informix/Ifx940FC6/bin/onbar_d complete, returning 0 (0x00)

Далее остановил сервер (onmode -k -y) и заново его запустил (oninit -v). В online-логе тоже все красиво:
-bash-3.00$ onstat -m

IBM Informix Dynamic Server Version 9.40.FC6 -- On-Line -- Up 00:23:27 -- 2965504 Kbytes

Message Log File: /opt/informix/Ifx940FC6/online.binf
12:32:40 10 recovery worker threads will be started.
12:32:43 Logical Recovery has reached the transaction cleanup phase.
12:32:43 Logical Recovery Complete.
0 Committed, 0 Rolled Back, 0 Open, 0 Bad Locks

12:32:45 Dataskip is now ON for dbspace:
12:32:45

12:32:45 Checkpoint Completed: duration was 0 seconds.
12:32:45 Checkpoint loguniq 72957, logpos 0x90018, timestamp: 0x18b013e5

12:32:45 Maximum server connections 0
12:32:45 On-Line Mode
12:32:45 Affinitied VP 4 to phys proc 5
12:32:45 Affinitied VP 5 to phys proc 6
12:32:45 Affinitied VP 1 to phys proc 4
12:32:45 Affinitied VP 7 to phys proc 8
12:32:45 Affinitied VP 6 to phys proc 7
12:32:45 Affinitied VP 9 to phys proc 10
12:32:45 Affinitied VP 8 to phys proc 9

При попытках подключиться к БД. Например через dbaccess получаю:
311: Cannot open system catalog (systables).
155: ISAM error: Primary and Mirror chunks are bad

И больше ничего найти не удалось. oncheck'и говорят тоже самое.

Т.к. выполнение рестора занимает более 10часов, то повторно его пока не запускал.

Из подозрений:
1) Железо (сервер и дисковый массив) - не своё, что тоже напрягает. Но ОС не кричит на них.
2) для Основного DBSpace'a (workdbs) использовались чанки размером 50gb. А диски в массиве по 34gb. Поэтому пришлось объединять слайсы разных дисков в один meta-девайс. Применял метадевайсы первый раз. Но знающие люди сказали что offset такойже как у слайсов разбитых по VTOC. Да и рестор вроде выполнился хорошо. С другой стороны используются raw-device'ы.... может рестор лился туда лился и лёг как получилось....

Пока пытаюсь раскачать Informix на диалог.

Может у кого была аналогичная ситуация? Или поделитесь опытом использования META-девайсов для чанков....

Спасибо.

Дополню:
onconfig, oncfg и inxbar были взяты с "боевой" - рабочей системы.

Структура dbspace'ов и размеры чанков - идентичны.

Права доступа к чанкам перепроверил + Рестор на них не ругался.

zaiets
что-то логи не все - 10 часов ну никак не видно чтобы восстанавливалось
а зачем так восстанавливали?
почему просто onbar -r вам не подходит?
правда, если на рабочем активно пишутся логи во время восстановления, то лучше указать на какое время или на какой лог восстанвливать - укажите, вроде у меня была трабла именно с этим, после чего начали восстанавливать на лог, давно это правда было.

Лог выложил только концовку, т.к. он длинный. Логи пишутся активно и за тот день более сотни логов изменений относительно последнего бэкапа 1го уровня.

2009-12-25 13:32:36 2269 2267 /opt/informix/Ifx940FC6/bin/onbar_d -r -p
2009-12-25 13:32:36 2269 2267 Working with veritas-netbackup as generic storage manager.
2009-12-25 13:32:36 2269 2267 Error parsing bootfile /opt/informix/Ifx940FC6/etc/ixbar.7.
2009-12-25 13:34:19 2269 2267 Successfully connected to Storage Manager.
2009-12-25 13:38:35 2269 2267 Begin cold level 0 restore rootdbs (Storage Manager copy ID: 1 1261173627).
2009-12-25 13:39:10 2269 2267 Completed cold level 0 restore rootdbs.
2009-12-25 13:39:10 2334 2269 Process 2334 2269 successfully forked.
2009-12-25 13:39:10 2333 2269 Process 2333 2269 successfully forked.
2009-12-25 13:39:10 2338 2269 Process 2338 2269 successfully forked.
2009-12-25 13:39:10 2336 2269 Process 2336 2269 successfully forked.
2009-12-25 13:39:10 2334 2269 Successfully connected to Storage Manager.
2009-12-25 13:39:10 2333 2269 Successfully connected to Storage Manager.
2009-12-25 13:39:10 2338 2269 Successfully connected to Storage Manager.
2009-12-25 13:39:10 2335 2269 Process 2335 2269 successfully forked.
2009-12-25 13:39:10 2337 2269 Process 2337 2269 successfully forked.
2009-12-25 13:39:10 2336 2269 Successfully connected to Storage Manager.
2009-12-25 13:39:11 2335 2269 Successfully connected to Storage Manager.
2009-12-25 13:39:11 2337 2269 Successfully connected to Storage Manager.
2009-12-25 13:39:50 2334 2269 Begin cold level 0 restore log_dbs (Storage Manager copy ID: 1 1261173734).
2009-12-25 13:39:56 2335 2269 Begin cold level 0 restore blobs_2 (Storage Manager copy ID: 1 1261173774).
2009-12-25 13:39:57 2334 2269 Completed cold level 0 restore log_dbs.
2009-12-25 13:39:57 2334 2269 Process 2334 2269 completed.
2009-12-25 13:41:35 2333 2269 Begin cold level 1 restore rootdbs (Storage Manager copy ID: 1 1261692050).
2009-12-25 13:42:27 2333 2269 Completed cold level 1 restore rootdbs.
2009-12-25 13:42:27 2333 2269 Process 2333 2269 completed.
2009-12-25 13:39:10 2338 2269 Warning: BAR_TIMEOUT Storage Manager Progress may be stalled.
2009-12-25 13:39:10 2336 2269 Warning: BAR_TIMEOUT Storage Manager Progress may be stalled.
2009-12-25 13:39:11 2337 2269 Warning: BAR_TIMEOUT Storage Manager Progress may be stalled.
2009-12-25 14:18:25 2336 2269 Begin cold level 0 restore idx_dbs (Storage Manager copy ID: 1 1261175288).
2009-12-25 14:18:27 2335 2269 Completed cold level 0 restore blobs_2.
2009-12-25 14:18:27 2335 2269 Process 2335 2269 completed.
2009-12-25 14:20:46 2337 2269 Begin cold level 0 restore sblobs (Storage Manager copy ID: 1 1261175460).
2009-12-25 14:20:48 2336 2269 Completed cold level 0 restore idx_dbs.
2009-12-25 14:20:48 2336 2269 Process 2336 2269 completed.
2009-12-25 14:20:50 2338 2269 Begin cold level 0 restore workdbs (Storage Manager copy ID: 1 1261175497).
2009-12-25 14:20:53 2337 2269 Completed cold level 0 restore sblobs.
2009-12-25 14:20:53 2337 2269 Process 2337 2269 completed.
2009-12-25 14:20:53 2436 2269 Process 2436 2269 successfully forked.
2009-12-25 14:20:53 2435 2269 Process 2435 2269 successfully forked.
2009-12-25 14:20:53 2437 2269 Process 2437 2269 successfully forked.
2009-12-25 14:20:53 2438 2269 Process 2438 2269 successfully forked.
2009-12-25 14:20:53 2436 2269 Successfully connected to Storage Manager.
2009-12-25 14:20:53 2435 2269 Successfully connected to Storage Manager.
2009-12-25 14:20:53 2437 2269 Successfully connected to Storage Manager.
2009-12-25 14:20:53 2438 2269 Successfully connected to Storage Manager.
2009-12-25 14:22:49 2438 2269 Begin cold level 1 restore sblobs (Storage Manager copy ID: 1 1261693079).
2009-12-25 14:22:56 2438 2269 Completed cold level 1 restore sblobs.
2009-12-25 14:22:56 2438 2269 Process 2438 2269 completed.
2009-12-25 14:23:38 2435 2269 Begin cold level 1 restore log_dbs (Storage Manager copy ID: 1 1261692174).
2009-12-25 14:23:43 2436 2269 Begin cold level 1 restore blobs_2 (Storage Manager copy ID: 1 1261692214).
2009-12-25 14:23:45 2435 2269 Completed cold level 1 restore log_dbs.
2009-12-25 14:23:45 2435 2269 Process 2435 2269 completed.
2009-12-25 14:20:53 2437 2269 Warning: BAR_TIMEOUT Storage Manager Progress may be stalled.
2009-12-25 14:36:13 2437 2269 Begin cold level 1 restore idx_dbs (Storage Manager copy ID: 1 1261693006).
2009-12-25 14:36:15 2436 2269 Completed cold level 1 restore blobs_2.
2009-12-25 14:36:15 2436 2269 Process 2436 2269 completed.
2009-12-25 14:42:12 2437 2269 Completed cold level 1 restore idx_dbs.
2009-12-25 14:42:12 2437 2269 Process 2437 2269 completed.
2009-12-25 17:30:41 2338 2269 Completed cold level 0 restore workdbs.
2009-12-25 17:30:41 2338 2269 Process 2338 2269 completed.
2009-12-25 17:30:41 2623 2269 Process 2623 2269 successfully forked.
2009-12-25 17:30:41 2623 2269 Successfully connected to Storage Manager.
2009-12-25 17:35:21 2623 2269 Begin cold level 1 restore workdbs (Storage Manager copy ID: 1 1261693120).
2009-12-25 19:32:59 2623 2269 Completed cold level 1 restore workdbs.
2009-12-25 19:32:59 2623 2269 Process 2623 2269 completed.
2009-12-25 19:32:59 2269 2267 Physical restore complete. Logical restore required before work can
continue. Use 'onbar -r -l' to do logical restore.
2009-12-25 19:32:59 2269 2267 /opt/informix/Ifx940FC6/bin/onbar_d complete, returning 0 (0x00)
2009-12-26 12:07:54 3522 3520 /opt/informix/Ifx940FC6/bin/onbar_d -r -l
2009-12-26 12:07:55 3522 3520 Working with veritas-netbackup as generic storage manager.
2009-12-26 12:07:55 3522 3520 Error parsing bootfile /opt/informix/Ifx940FC6/etc/ixbar.7.
2009-12-26 12:07:57 3522 3520 Successfully connected to Storage Manager.
2009-12-26 12:11:50 3522 3520 Begin restore logical log 72820 (Storage Manager copy ID: 1 1261692453).
2009-12-26 12:12:04 3522 3520 Completed restore logical log 72820.
2009-12-26 12:12:44 3522 3520 Begin restore logical log 72821 (Storage Manager copy ID: 1 1261692830).
2009-12-26 12:12:57 3522 3520 Completed restore logical log 72821.
2009-12-26 12:13:38 3522 3520 Begin restore logical log 72822 (Storage Manager copy ID: 1 1261693214).
2009-12-26 12:13:51 3522 3520 Completed restore logical log 72822.

[...]

2009-12-26 15:57:22 3522 3520 Begin restore logical log 72955 (Storage Manager copy ID: 1 1261817214).
2009-12-26 15:57:38 3522 3520 Completed restore logical log 72955.
2009-12-26 15:59:11 3522 3520 Begin restore logical log 72956 (Storage Manager copy ID: 1 1261817373).
2009-12-26 15:59:18 3522 3520 Completed restore logical log 72956.
2009-12-26 16:03:22 3522 3520 Completed logical restore.
2009-12-26 16:03:23 4628 4626 /opt/informix/Ifx940FC6/bin/onbar_d -b -l
2009-12-26 16:03:23 4628 4626 Working with veritas-netbackup as generic storage manager.
2009-12-26 16:03:23 4628 4626 /opt/informix/Ifx940FC6/bin/onbar_d complete, returning 0 (0x00)
2009-12-26 16:03:37 3522 3520 /opt/informix/Ifx940FC6/bin/onbar_d complete, returning 0 (0x00)


Можно былоб и просто onbar -r, но не суть. Рестор то выполняю рабочей функционирующей системы. Ничего не крашилось и т.п.

Пока считаю, что где-то накосячил с чанками...

vasilisonstat -d не помешал бы...

-bash-3.00$ onstat -d

IBM Informix Dynamic Server Version 9.40.FC6 -- On-Line -- Up 22:38:44 -- 2965504 Kbytes

Dbspaces
address number flags fchunk nchunks flags owner name
142190e58 1 0x1 1 1 N informix rootdbs
14324e688 2 0x2001 2 1 N T informix temp_dbs
14324e808 3 0x40005 3 6 ND B informix workdbs
14324e988 4 0x1 6 1 N informix idx_dbs
14324eb08 5 0x1 7 1 N informix log_dbs
14324ec88 7 0x40011 9 1 N BB informix blobs_2
14324ee08 8 0x8001 10 1 N S informix sblobs
7 active, 2047 maximum

Note: For BLOB chunks, the number of free pages shown is out of date.
Run 'onstat -d update' for current stats.

Chunks
address chunk/dbs offset size free bpages flags pathname
142191028 1 1 5 1000000 842753 PO-- /opt/informix/chunks_IDS940FC6/root_chunk
14324d4a0 2 2 5 1000000 999947 PO-- /opt/informix/chunks_IDS940FC6/temp_sp
14324d638 3 3 5 1000000 0 PD-- /opt/informix/chunks_IDS940FC6/data_1
14324d7d0 4 3 5 1000000 0 PD-- /opt/informix/chunks_IDS940FC6/data_2
14324d968 5 3 5 1000000 0 PD-- /opt/informix/chunks_IDS940FC6/data_3
14324db00 6 4 5 1000000 459667 PO-- /opt/informix/chunks_IDS940FC6/idx_sp
14324dc98 7 5 5 900000 152427 PO-- /opt/informix/chunks_IDS940FC6/logs_sp
14324de30 8 3 100 24999500 0 PD-B /opt/informix/chunks_IDS940FC6/data_5
14324e028 9 7 5 11000000 ~2750000 2750000 POBB /opt/informix/chunks_IDS940FC6/blob_2
14324e1c0 10 8 5 1000000 932620 932620 POS- /opt/informix/chunks_IDS940FC6/smartB
Metadata 67327 50099 67327
14324e358 11 3 5 14999990 0 PD-B /opt/informix/chunks_IDS940FC6/data_4
14324e4f0 12 3 100 24999500 0 PD-B /opt/informix/chunks_IDS940FC6/data_6
12 active, 32766 maximum

Expanded chunk capacity mode: enabled

-bash-3.00$ ls -l
total 24
lrwxrwxrwx 1 informix informix 18 Dec 16 13:09 blob_2 -> /dev/rdsk/c0t2d0s6
lrwxrwxrwx 1 informix informix 18 Dec 24 17:13 data_1 -> /dev/rdsk/c0t3d0s0
lrwxrwxrwx 1 informix informix 18 Dec 24 17:13 data_2 -> /dev/rdsk/c0t3d0s1
lrwxrwxrwx 1 informix informix 18 Dec 24 17:13 data_3 -> /dev/rdsk/c0t3d0s3
lrwxrwxrwx 1 informix informix 18 Dec 24 17:14 data_4 -> /dev/rdsk/c0t4d0s6
lrwxrwxrwx 1 informix informix 15 Dec 24 17:14 data_5 -> /dev/md/rdsk/d5
lrwxrwxrwx 1 informix informix 15 Dec 24 17:14 data_6 -> /dev/md/rdsk/d6
lrwxrwxrwx 1 informix informix 18 Dec 16 13:08 idx_sp -> /dev/rdsk/c0t2d0s1
lrwxrwxrwx 1 informix informix 18 Dec 16 13:08 logs_sp -> /dev/rdsk/c0t2d0s3
lrwxrwxrwx 1 informix informix 18 Dec 16 13:08 root_chunk -> /dev/rdsk/c0t2d0s0
lrwxrwxrwx 1 informix informix 18 Dec 16 13:08 smartB -> /dev/rdsk/c0t2d0s4
lrwxrwxrwx 1 informix informix 18 Dec 16 13:09 temp_sp -> /dev/rdsk/c0t2d0s5

-bash-3.00$ metastat
d30: Mirror
Submirror 0: d31
State: Okay
Submirror 1: d32
State: Okay
Pass: 1
Read option: roundrobin (default)
Write option: parallel (default)
Size: 8392160 blocks (4.0 GB)

d31: Submirror of d30
State: Okay
Size: 8392160 blocks (4.0 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t0d0s3 0 No Okay Yes


d32: Submirror of d30
State: Okay
Size: 8392160 blocks (4.0 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t1d0s3 0 No Okay Yes


d10: Mirror
Submirror 0: d11
State: Okay
Submirror 1: d12
State: Okay
Pass: 1
Read option: roundrobin (default)
Write option: parallel (default)
Size: 4196080 blocks (2.0 GB)

d11: Submirror of d10
State: Okay
Size: 4196080 blocks (2.0 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t0d0s1 0 No Okay Yes


d12: Submirror of d10
State: Okay
Size: 4196080 blocks (2.0 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t1d0s1 0 No Okay Yes


d0: Mirror
Submirror 0: d1
State: Okay
Submirror 1: d2
State: Okay
Pass: 1
Read option: roundrobin (default)
Write option: parallel (default)
Size: 12583160 blocks (6.0 GB)

d1: Submirror of d0
State: Okay
Size: 12583160 blocks (6.0 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t0d0s0 0 No Okay Yes


d2: Submirror of d0
State: Okay
Size: 12583160 blocks (6.0 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t1d0s0 0 No Okay Yes


d40: Mirror
Submirror 0: d41
State: Okay
Submirror 1: d42
State: Okay
Pass: 1
Read option: roundrobin (default)
Write option: parallel (default)
Size: 45923200 blocks (21 GB)

d41: Submirror of d40
State: Okay
Size: 45923200 blocks (21 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t0d0s4 0 No Okay Yes


d42: Submirror of d40
State: Okay
Size: 45923200 blocks (21 GB)
Stripe 0:
Device Start Block Dbase State Reloc Hot Spare
c0t1d0s4 0 No Okay Yes


d6: Concat/Stripe
Size: 106583480 blocks (50 GB)
Stripe 0:
Device Start Block Dbase Reloc
c0t8d0s6 0 No Yes
Stripe 1:
Device Start Block Dbase Reloc
c1t0d0s1 0 No Yes

d5: Concat/Stripe
Size: 106771440 blocks (50 GB)
Stripe 0:
Device Start Block Dbase Reloc
c0t5d0s6 0 No Yes
Stripe 1:
Device Start Block Dbase Reloc
c1t0d0s0 5080 No Yes

Device Relocation Information:
Device Reloc Device ID
c0t8d0 Yes id1,sd@x00000e11004964e8
c1t0d0 Yes id1,sd@x00e09e002fbd6524
c0t5d0 Yes id1,sd@x00000e11001dd4de
c0t1d0 Yes id1,sd@x0004cffffe713317
c0t0d0 Yes id1,sd@x0004cffffe5a6db2

Пересоздал заново чанки.
Выполнил восстановление - все в норме.

В чём была проблема - осталось неясным....

Спасибо всем.