Topic
IC4NOTICE: developerWorks Community will be offline May 29-30, 2015 while we upgrade to the latest version of IBM Connections. For more information, read our upgrade FAQ.
No replies
RaviThati
RaviThati
1 Post
ACCEPTED ANSWER

Pinned topic Windows IDS 11.50FC6, logical restore aborted onbar and IDS

‏2011-09-16T11:02:11Z |
Hi All,

I am trying to run a restore (onbar -r ) on my IDS 11.50FC6 on windows 2008 64 bit and (also on TC3 windows 2003 32 bit)
The restore is finishing physical restore and does the logical restore upto logN and getting aborted while trying logN+1.

from the Onbar debug logs i see this:
it is looking for log file 48 which is not actually there in finalized list NOR in ixbar file
and observes as do_log_restore: cur_log_found = 0 //failed to find.
and still continues to restore it resulting in aborting onbar, IDS also.
If I do the restore upto log 47 onbar -r -n 47, it all works fine. I have tried several times and observed that 'onbar -r' is always trying to restore a log that does not exist.

2011-09-16 14:42:27 29916 29916 read_bar_debug_value: enter
2011-09-16 14:42:27 29916 29916 read_bar_debug_value: return 0 (0x00)
2011-09-16 14:42:27 29916 29916 do_log_restore: looking for log 48 in
ccb->objlist
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
rootdbs, obj_type = R
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
dbspace1, obj_type = ND
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
1, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
2, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
3, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
4, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
5, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
6, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
7, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
8, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
9, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
10, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
11, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
12, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
13, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
14, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
15, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
16, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
17, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
18, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
19, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
20, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
21, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
22, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
23, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
24, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
25, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
26, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
27, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
28, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
29, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
30, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
31, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
32, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
33, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
34, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
35, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
36, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
37, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
38, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
39, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
40, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
41, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
42, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
43, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
44, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
45, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
46, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: examining obj_desc->obj_name =
47, obj_type = L
2011-09-16 14:42:27 29916 29916 do_log_restore: cur_log_found = 0
2011-09-16 14:42:27 29916 29916 init_objdesc: enter
2011-09-16 14:42:27 29916 29916 init_objnode: return
2011-09-16 14:42:27 29916 29916 barBeginTxn: enter
2011-09-16 14:42:27 29916 29916 bar_alarm: enter
2011-09-16 14:42:27 29916 29916 bar_alarm: return
2011-09-16 14:42:27 29916 29916 bar_loadXBSA: return 0
2011-09-16 14:42:27 29916 29916 barBeginTxn: return 0 (0x00)
2011-09-16 14:42:27 29916 29916 barQueryObject: enter
2011-09-16 14:42:27 29916 29916 barQueryObject input: bar_objdesc

obj_id 0 obj_name '48' obj_type 'L' act_id 0 act_type 0 act_status 0

act_start '' act_end ''

ins_time 0 rsam_time 0 seal_time 0 prev_seal_time 0 level 0 copyid hi:lo 0:0
req_act_id 0

logstream 0 est_pages hi:lo 0:0 first_log 0 chpt_log 0 last_log 0

partial_flag 0 do_query 1 ins_sm_id 0 ins_sm_name ''

ins_verify 0 ins_verify_date '' restore order 0:0

objInfo ''

retry 0 in_catalog 0 in_bootfile 0 child_pid 0 child_state 0

bkup_host '' backup_order 0
2011-09-16 14:42:27 29916 29916 initQryDesc: enter
2011-09-16 14:42:27 29916 29916 initQryDesc: output: object owner name
2011-09-16 14:42:27 29916 29916 initQryDesc: output: INFORMIX informix \
2011-09-16 14:42:27 29916 29916 initQryDesc: output: createTimeLB createTimeUB
expireTimeLB expireTimeUB copytype LGName cGName resource type status desc
2011-09-16 14:42:27 29916 29916 initQryDesc: output: 0 0 0 0 0 0 0 0 0 0 0 0 0
0 0 0 0 0 0 0 0 0 0 0 3 4 0
2011-09-16 14:42:27 29916 29916 initQryDesc: return
2011-09-16 14:42:27 29916 29916 buildObjName: enter
2011-09-16 14:42:27 29916 29916 buildObjName: bar_objdesc

obj_id 0 obj_name '48' obj_type 'L' act_id 0 act_type 0 act_status 0

act_start '' act_end ''

ins_time 0 rsam_time 0 seal_time 0 prev_seal_time 0 level 0 copyid hi:lo 0:0
req_act_id 0

logstream 0 est_pages hi:lo 0:0 first_log 0 chpt_log 0 last_log 0

partial_flag 0 do_query 2 ins_sm_id 0 ins_sm_name ''

ins_verify 0 ins_verify_date '' restore order 0:0

objInfo ''

retry 0 in_catalog 0 in_bootfile 0 child_pid 0 child_state 0

bkup_host '' backup_order 0
2011-09-16 14:42:27 29916 29916 buildObjName: set server_name to ol_ids_1150_1
2011-09-16 14:42:27 29916 29916 buildObjName: output objectSpaceName
\ol_ids_1150_1, pathName \ol_ids_1150_1\0\48
2011-09-16 14:42:27 29916 29916 buildObjName: return 0 (0x00)
2011-09-16 14:42:27 29916 29916 bar_loadXBSA: return 0
2011-09-16 14:42:27 29916 29916 bar_except_hdlr: enter
2011-09-16 14:42:27 29916 29916 barEndTxn: enter
2011-09-16 14:42:27 29916 29916 bar_loadXBSA: return 0
2011-09-16 14:42:27 29916 29916 barEndTxn: return 0 (0x00)
2011-09-16 14:42:27 29916 29916 barTerminate: enter
2011-09-16 14:42:27 29916 29916 bar_loadXBSA: return 0
2011-09-16 14:42:34 29916 29916 barTerminate: return 0 (0x00)
2011-09-16 14:42:34 29916 29916 NT_KillAllChildren: enter

The Servers' logs say this:

14:42:00 Maximum server connections 0
14:42:00 Start Logical Recovery - Start Log 46, End Log ?
14:42:00 Starting Log Position - 46 0x4674
14:42:00 Clearing the physical and logical logs has started
14:42:05 Cleared 283 MB of the physical and logical logs in 5 seconds
14:42:27 Logical Log 46 Complete, timestamp: 0x13d7cd.
14:42:27 Checkpoint Completed: duration was 0 seconds.
14:42:27 Fri Sep 16 - loguniq 47, logpos 0x3018, timestamp: 0x13d7e8 Interval: 21968

14:42:27 Maximum server connections 0
14:42:27 Checkpoint Statistics - Avg. Txn Block Time 0.000, # Txns blocked 0, Plog used 22, Llog used 0

14:42:48 Logical Recovery ABORTED.
Aborted by client.
14:42:48 Assert Failed: Logical Recovery ABORTED.
Dynamic Server must abort
14:42:49 IBM Informix Dynamic Server Version 11.50.TC3
14:42:49 Who: Session(12, informix@tao, 29916, 00000000)
Thread(27, ontape, 0, 1)
File: rslgr.c Line: 1305
14:42:49 stack trace for pid 27800 written to C:\PROGRA~1\IBM\IBMINF~1\11.50\tmp\af.4031310
14:42:52 See Also: C:\PROGRA~1\IBM\IBMINF~1\11.50\tmp\af.4031310, shmem.4031310.0
14:42:54 Releasing server from system block
14:43:01 PANIC: Attempting to bring system down
14:43:01 rslgr.c, line 1305, thread 27, proc id 27800, Logical Recovery ABORTED.
Dynamic Server must abort.
I can send the shm dump and af files if required.

please suggest.