Ontape restore : Fast recovery hangs

Hi, I've launched an 'ontape -r -rename -f <file>' to restore an instance version 940 from a tape. But since 2 hours the instance is in Fast Recovery mode as 'onstat -' shows below : informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onstat - IBM Informix Dynamic Server Version 9.40.FC9 -- Fast Recovery (CKPT REQ) -- Up 03:40:16 -- 9457424 KbytesBlocked:CKPT This is what I have in the online.log file : 08:41:16 IBM Informix Dynamic Server Started. 08:41:16 WARNING: If you intend to use J/Foundation or GLS for Unicode feature(GLU) with this Server instance, please make sure that your SHMBASE value specifies in onconfig is 0x700000010000000 or above. Otherwise you will have problems while attaching or dynamimically adding virtual shared memory segme nts. Please refer to Server machine notes for more information. 08:41:21 Requested shared memory segment size rounded from 1068168KB to 1068176KB 08:41:21 Dynamically allocated new virtual shared memory segment (size 1068176KB) 08:41:21 Memory sizes:resident:4194288 KB, virtual:5262464 KB, no SHMTOTAL limit 08:41:21 VP pid=553078 priority fixed at 60, former = 98 Fri Apr 23 08:41:21 2010 08:41:21 Event alarms enabled. ALARMPROG = '/bases/informix/pcoipcoi/admin/ontape/sh/log_full.sh' 08:41:21 Booting Language <c> from module <> 08:41:21 Loading Module <CNULL> 08:41:21 Booting Language <builtin> from module <> 08:41:21 Loading Module <BUILTINNULL> 08:41:26 AIX MP latch code enabled 08:41:26 Dynamically allocated new message shared memory segment (size 672KB) 08:41:26 Memory sizes:resident:4194288 KB, virtual:5263136 KB, no SHMTOTAL limit 08:41:27 IBM Informix Dynamic Server Version 9.40.FC9 Software Serial Number AAA#B000000 08:41:27 IBM Informix Dynamic Server Initialized -- Shared Memory Initialized. 08:41:27 Data replication type and state information reset. To start DR, use the 'onmode -d' command and wait for the pair to be operational, before shutting down the database server 08:41:27 Onconfig parameter SHMVIRT_ALLOCSEG modified from 12884901888 to 3. 08:41:27 Dataskip is now OFF for all dbspaces 08:41:27 Restartable Restore has been ENABLED 08:41:27 Recovery Mode 08:41:31 Physical Restore of rootdbs, log1dbs1, phys1dbs1, hisdat1dbs1, hisidx1dbs1, comdat1dbs1, comidx1dbs1, clidat1dbs1, cliidx1dbs1, chqdat1dbs1, ch qidx1dbs1, slcomdat1dbs1, slcomidx1dbs1, slddat1dbs1, sldidx1dbs1, evedat1dbs1, eveidx1dbs1, mvtdat1dbs1, mvtidx1dbs1, cridat1dbs1, criidx1dbs1, dardat1d bs1, daridx1dbs1, haridx1dbs1, hardat1dbs1, dat1dbs1, idx1dbs1, datadbs, rgdatadbs started. 08:41:50 The chunk path (/appl/informix/dev/root1dbs1_chk01:8) is renamed to new chunk path (/bases/informix/pcoipcoi/sys/d01/rootdbs_01.dbf:8) 08:41:51 Checkpoint Completed: duration was 0 seconds. ...... 1.dbf:8) 10:44:13 Checkpoint Completed: duration was 0 seconds. 10:44:13 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc2e4 10:44:13 Maximum server connections 0 10:44:15 Physical Restore of rootdbs, log1dbs1, phys1dbs1, hisdat1dbs1, hisidx1dbs1, comdat1dbs1, comidx1dbs1, clidat1dbs1, cliidx1dbs1, chqdat1dbs1, ch qidx1dbs1, slcomdat1dbs1, slcomidx1dbs1, slddat1dbs1, sldidx1dbs1, evedat1dbs1, eveidx1dbs1, mvtdat1dbs1, mvtidx1dbs1, cridat1dbs1, criidx1dbs1, dardat1d bs1, daridx1dbs1, haridx1dbs1, hardat1dbs1, dat1dbs1, idx1dbs1, datadbs, rgdatadbs Completed. 10:44:15 Checkpoint Completed: duration was 0 seconds. 10:44:15 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc2ef 10:44:15 Maximum server connections 0 Can someone explain why 'ontape' is hanging and if there's a solution for this problem Thanks

Ontape finished the restore. If it hasn't exited it is because it is pompting you to ask whether you want to restore any logical logs. If it already asked that and you answered, either by restoring logs or by replying 'N', then it should have exited. Now the engine is waiting for you to bring it online with: onmode -m Do NOT shutdown the instance after a restore until you have run the onmode -m and seen the engine return to full online mode. If you do, you will have to start the restore all over again. Art Art S. Kagel Advanced DataTools (www.advancedatatools.com) IIUG Board of Directors (art@iiug.org) See you at the 2010 IIUG Informix Conference April 25-28, 2010 Overland Park (Kansas City), KS www.iiug.org/conf Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Advanced DataTools, the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Fri, Apr 23, 2010 at 8:28 AM, GILLES TCHAPPI <ntgilfr@voila.fr> wrote: > Hi, > > I've launched an 'ontape -r -rename -f <file>' to restore an instance > version > 940 from a tape. But since 2 hours the instance is in Fast Recovery mode as > 'onstat -' shows below : > > informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onstat - > > IBM Informix Dynamic Server Version 9.40.FC9 -- Fast Recovery (CKPT REQ) --> Up > 03:40:16 -- 9457424 Kbytes > Blocked:CKPT > > This is what I have in the online.log file : > > 08:41:16 IBM Informix Dynamic Server Started. > 08:41:16 WARNING: If you intend to use J/Foundation or GLS for Unicode > feature(GLU) with this Server instance, please make sure that your SHMBASE > value > specifies in onconfig is 0x700000010000000 or above. Otherwise you will > have > problems while attaching or dynamimically adding virtual shared memory > segme > nts. Please refer to Server machine notes for more information. > > 08:41:21 Requested shared memory segment size rounded from 1068168KB to > 1068176KB > 08:41:21 Dynamically allocated new virtual shared memory segment (size > 1068176KB) > 08:41:21 Memory sizes:resident:4194288 KB, virtual:5262464 KB, no SHMTOTAL > limit > 08:41:21 VP pid=553078 priority fixed at 60, former = 98 > > Fri Apr 23 08:41:21 2010 > > 08:41:21 Event alarms enabled. ALARMPROG = > '/bases/informix/pcoipcoi/admin/ontape/sh/log_full.sh' > 08:41:21 Booting Language <c> from module <> > 08:41:21 Loading Module <CNULL> > 08:41:21 Booting Language <builtin> from module <> > 08:41:21 Loading Module <BUILTINNULL> > 08:41:26 AIX MP latch code enabled > 08:41:26 Dynamically allocated new message shared memory segment (size > 672KB) > 08:41:26 Memory sizes:resident:4194288 KB, virtual:5263136 KB, no SHMTOTAL > limit > 08:41:27 IBM Informix Dynamic Server Version 9.40.FC9 Software Serial > Number > AAA#B000000 > 08:41:27 IBM Informix Dynamic Server Initialized -- Shared Memory > Initialized. > > 08:41:27 Data replication type and state information reset. To start DR, > use > > the 'onmode -d' command and wait for the pair to be operational, > > before shutting down the database server > > 08:41:27 Onconfig parameter SHMVIRT_ALLOCSEG modified from 12884901888 to > 3. > 08:41:27 Dataskip is now OFF for all dbspaces > 08:41:27 Restartable Restore has been ENABLED > 08:41:27 Recovery Mode > 08:41:31 Physical Restore of rootdbs, log1dbs1, phys1dbs1, hisdat1dbs1, > hisidx1dbs1, comdat1dbs1, comidx1dbs1, clidat1dbs1, cliidx1dbs1, > chqdat1dbs1, > ch > qidx1dbs1, slcomdat1dbs1, slcomidx1dbs1, slddat1dbs1, sldidx1dbs1, > evedat1dbs1, eveidx1dbs1, mvtdat1dbs1, mvtidx1dbs1, cridat1dbs1, > criidx1dbs1, > dardat1d > bs1, daridx1dbs1, haridx1dbs1, hardat1dbs1, dat1dbs1, idx1dbs1, datadbs, > rgdatadbs started. > > 08:41:50 The chunk path (/appl/informix/dev/root1dbs1_chk01:8) is renamed > to > new chunk path (/bases/informix/pcoipcoi/sys/d01/rootdbs_01.dbf:8) > 08:41:51 Checkpoint Completed: duration was 0 seconds. > > ....... > 1.dbf:8) > 10:44:13 Checkpoint Completed: duration was 0 seconds. > 10:44:13 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc2e4 > > 10:44:13 Maximum server connections 0 > 10:44:15 Physical Restore of rootdbs, log1dbs1, phys1dbs1, hisdat1dbs1, > hisidx1dbs1, comdat1dbs1, comidx1dbs1, clidat1dbs1, cliidx1dbs1, > chqdat1dbs1, > ch > qidx1dbs1, slcomdat1dbs1, slcomidx1dbs1, slddat1dbs1, sldidx1dbs1, > evedat1dbs1, eveidx1dbs1, mvtdat1dbs1, mvtidx1dbs1, cridat1dbs1, > criidx1dbs1, > dardat1d > bs1, daridx1dbs1, haridx1dbs1, hardat1dbs1, dat1dbs1, idx1dbs1, datadbs, > rgdatadbs Completed. > 10:44:15 Checkpoint Completed: duration was 0 seconds. > 10:44:15 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc2ef > > 10:44:15 Maximum server connections 0 > > Can someone explain why 'ontape' is hanging and if there's a solution for > this > problem > > Thanks > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001636e0b92a6ce7b40484e6b9a3

Thanks a lot, I followed you're recomendations and .... its OK now : see below informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onmode -m informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onstat - IBM Informix Dynamic Server Version 9.40.FC9 -- Fast Recovery (CKPT REQ) -- Up 04:10:37 -- 9457424 KbytesBlocked:CKPT informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> tail -f online.log 10:44:13 Maximum server connections 0 10:44:15 Physical Restore of rootdbs, log1dbs1, phys1dbs1, hisdat1dbs1, hisidx1dbs1, comdat1dbs1, comidx1dbs1, clidat1dbs1, cliidx1dbs1, chqdat1dbs1, chqidx1dbs1, slcomdat1dbs1, slcomidx1dbs1, slddat1dbs1, sldidx1dbs1, evedat1dbs1, eveidx1dbs1, mvtdat1dbs1, mvtidx1dbs1, cridat1dbs1, criidx1dbs1, dardat1dbs1, daridx1dbs1, haridx1dbs1, hardat1dbs1, dat1dbs1, idx1dbs1, datadbs, rgdatadbs Completed. 10:44:15 Checkpoint Completed: duration was 0 seconds. 10:44:15 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc2ef 10:44:15 Maximum server connections 0 12:51:56 No logical log restore will be performed. 12:51:56 Preparing Physical Log for Fast Recovery ... 12:51:56 Clearing the physical and logical logs has started 12:52:54 Cleared 1273 MB of the physical and logical logs in 58 seconds 12:52:54 Dropping temporary TBLspace 0x1a01261, recovering 2144 pages. 12:52:54 Physical Recovery Started at Page (3:8425). 12:52:54 Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored. 12:52:54 The chunk path (chunk number 28 of temp dbspace number 28) is renamed to new chunk path (/bases/informix/pcoipcoi/sys/d04/tempdbs_01.dbf:8). 12:52:54 The chunk path (chunk number 29 of temp dbspace number 29) is renamed to new chunk path (/bases/informix/pcoipcoi/sys/d05/tempdbs_02.dbf:8). 12:52:54 Logical Recovery Started. 12:52:54 10 recovery worker threads will be started. 12:52:55 Checkpoint Completed: duration was 0 seconds. 12:52:55 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc310 12:52:55 Maximum server connections 0 12:52:58 Logical Recovery has reached the transaction cleanup phase. 12:53:06 Logical Recovery Complete. 0 Committed, 9 Rolled Back, 0 Open, 0 Bad Locks 12:53:06 Bringing system to On-Line Mode with no Logical Restore. 12:53:07 On-Line Mode 12:53:07 Checkpoint Completed: duration was 0 seconds. 12:53:07 Checkpoint loguniq 264451, logpos 0x298d018, timestamp: 0xf7dea73a 12:53:07 Maximum server connections 0 informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onstat - IBM Informix Dynamic Server Version 9.40.FC9 -- On-Line -- Up 04:12:04 --9457424 Kbytes Best regards

Yup, if you do not restore logical logs the engine waits for you to complete recovery by forcing it to online mode like this. If you restore logs that doesn't happen. Art Art S. Kagel Advanced DataTools (www.advancedatatools.com) IIUG Board of Directors (art@iiug.org) See you at the 2010 IIUG Informix Conference April 25-28, 2010 Overland Park (Kansas City), KS www.iiug.org/conf Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on my employer, Advanced DataTools, the IIUG, nor any other organization with which I am associated either explicitly, implicitly, or by inference. Neither do those opinions reflect those of other individuals affiliated with any entity with which I am affiliated nor those of the entities themselves. On Fri, Apr 23, 2010 at 9:00 AM, GILLES TCHAPPI <ntgilfr@voila.fr> wrote: > Thanks a lot, > > I followed you're recomendations and .... its OK now : see below > > informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onmode -m > informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onstat - > > IBM Informix Dynamic Server Version 9.40.FC9 -- Fast Recovery (CKPT REQ) --> Up > 04:10:37 -- 9457424 Kbytes > Blocked:CKPT > > informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> tail -f > online.log > > 10:44:13 Maximum server connections 0 > 10:44:15 Physical Restore of rootdbs, log1dbs1, phys1dbs1, hisdat1dbs1, > hisidx1dbs1, comdat1dbs1, comidx1dbs1, clidat1dbs1, cliidx1dbs1, > chqdat1dbs1, > chqidx1dbs1, slcomdat1dbs1, slcomidx1dbs1, slddat1dbs1, sldidx1dbs1, > evedat1dbs1, eveidx1dbs1, mvtdat1dbs1, mvtidx1dbs1, cridat1dbs1, > criidx1dbs1, > dardat1dbs1, daridx1dbs1, haridx1dbs1, hardat1dbs1, dat1dbs1, idx1dbs1, > datadbs, rgdatadbs Completed. > 10:44:15 Checkpoint Completed: duration was 0 seconds. > 10:44:15 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc2ef > > 10:44:15 Maximum server connections 0 > 12:51:56 No logical log restore will be performed. > 12:51:56 Preparing Physical Log for Fast Recovery ... > 12:51:56 Clearing the physical and logical logs has started > 12:52:54 Cleared 1273 MB of the physical and logical logs in 58 seconds > 12:52:54 Dropping temporary TBLspace 0x1a01261, recovering 2144 pages. > 12:52:54 Physical Recovery Started at Page (3:8425). > 12:52:54 Physical Recovery Complete: 0 Pages Examined, 0 Pages Restored. > 12:52:54 The chunk path (chunk number 28 of temp dbspace number 28) > > is renamed to new chunk path > (/bases/informix/pcoipcoi/sys/d04/tempdbs_01.dbf:8). > 12:52:54 The chunk path (chunk number 29 of temp dbspace number 29) > > is renamed to new chunk path > (/bases/informix/pcoipcoi/sys/d05/tempdbs_02.dbf:8). > 12:52:54 Logical Recovery Started. > 12:52:54 10 recovery worker threads will be started. > 12:52:55 Checkpoint Completed: duration was 0 seconds. > 12:52:55 Checkpoint loguniq 264451, logpos 0x28bf018, timestamp: 0xf7ddc310 > > 12:52:55 Maximum server connections 0 > 12:52:58 Logical Recovery has reached the transaction cleanup phase. > 12:53:06 Logical Recovery Complete. > > 0 Committed, 9 Rolled Back, 0 Open, 0 Bad Locks > > 12:53:06 Bringing system to On-Line Mode with no Logical Restore. > > 12:53:07 On-Line Mode > 12:53:07 Checkpoint Completed: duration was 0 seconds. > 12:53:07 Checkpoint loguniq 264451, logpos 0x298d018, timestamp: 0xf7dea73a > > 12:53:07 Maximum server connections 0 > > informix@pcoi01:pcoipcoi_tcp:/bases/informix/pcoipcoi/var/bdump> onstat - > > IBM Informix Dynamic Server Version 9.40.FC9 -- On-Line -- Up 04:12:04 --> 9457424 Kbytes > > Best regards > > > > ******************************************************************************* > Forum Note: Use "Reply" to post a response in the discussion forum. > > --001636e0a7f556e74e0484e73030