Hi All,
I restored a development database last Friday and ran into some odd behavior.  Below are the first 25 lines from the bar_act.log file.  I issued the command "onbar_d -r -w -p" at 05:29:42 but it didn't connect to the Storage manager until 06:40:45 and it didn't start restoring anything until 08:41:10.  This is 3 hour and 10 minutes since issuing the command.  Does anyone have any experience with this behavior.  The version of Informix is "IBM Informix Dynamic Server Version 11.70.FC7"  running on Solaris

2020-01-31 05:29:42 25344 25342 /opt/informix/bin/onbar_d -r -w -p
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 37560 Current log id: 54611
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 55200 Current log id: 55202
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 55681 Current log id: 55683
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 56071 Current log id: 56073
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 73698 Current log id: 73700
2020-01-31 06:40:45 25344 25342 Successfully connected to Storage Manager.
2020-01-31 06:40:46 25344 25342 Begin reserved pages restore (level 0 of rootdbs, Storage Manager copy ID: 606940 0).
2020-01-31 06:40:46 25344 25342 Completed reserved pages restore (level 0 of rootdbs).
2020-01-31 08:41:10 25344 25342 Successfully connected to Storage Manager.
2020-01-31 08:41:10 25344 25342 Begin cold level 0 restore rootdbs (Storage Manager copy ID: 606940 0).
2020-01-31 08:41:55 25344 25342 Completed cold level 0 restore rootdbs.
2020-01-31 08:41:58 25475 25344 Process 25475 25344 successfully forked.
2020-01-31 08:41:58 25476 25344 Process 25476 25344 successfully forked.
2020-01-31 08:41:58 25475 25344 Successfully connected to Storage Manager.
2020-01-31 08:41:58 25476 25344 Successfully connected to Storage Manager.
2020-01-31 08:41:59 25475 25344 Begin cold level 0 restore gimdbs1 (Storage Manager copy ID: 606944 0).
2020-01-31 08:41:59 25476 25344 Begin cold level 0 restore gtxlog1 (Storage Manager copy ID: 606942 0).
2020-01-31 08:42:01 25476 25344 Completed cold level 0 restore gtxlog1.
2020-01-31 08:42:01 25476 25344 Process 25476 25344 completed.
2020-01-31 08:46:59 25475 25344 0x0532dbb pages of gimdbs1 have been restored.
2020-01-31 08:52:00 25475 25344 0x0a1df7e pages of gimdbs1 have been restored.
2020-01-31 08:57:01 25475 25344 0x0f89058 pages of gimdbs1 have been restored.
2020-01-31 09:02:02 25475 25344 0x014c8147 pages of gimdbs1 have been restored

------------------------------
John Henry
------------------------------

#Informix

Original Message------

Hi All,
I restored a development database last Friday and ran into some odd behavior.  Below are the first 25 lines from the bar_act.log file.  I issued the command "onbar_d -r -w -p" at 05:29:42 but it didn't connect to the Storage manager until 06:40:45 and it didn't start restoring anything until 08:41:10.  This is 3 hour and 10 minutes since issuing the command.  Does anyone have any experience with this behavior.  The version of Informix is "IBM Informix Dynamic Server Version 11.70.FC7"  running on Solaris

2020-01-31 05:29:42 25344 25342 /opt/informix/bin/onbar_d -r -w -p
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 37560 Current log id: 54611
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 55200 Current log id: 55202
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 55681 Current log id: 55683
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 56071 Current log id: 56073
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 73698 Current log id: 73700
2020-01-31 06:40:45 25344 25342 Successfully connected to Storage Manager.
2020-01-31 06:40:46 25344 25342 Begin reserved pages restore (level 0 of rootdbs, Storage Manager copy ID: 606940 0).
2020-01-31 06:40:46 25344 25342 Completed reserved pages restore (level 0 of rootdbs).
2020-01-31 08:41:10 25344 25342 Successfully connected to Storage Manager.
2020-01-31 08:41:10 25344 25342 Begin cold level 0 restore rootdbs (Storage Manager copy ID: 606940 0).
2020-01-31 08:41:55 25344 25342 Completed cold level 0 restore rootdbs.
2020-01-31 08:41:58 25475 25344 Process 25475 25344 successfully forked.
2020-01-31 08:41:58 25476 25344 Process 25476 25344 successfully forked.
2020-01-31 08:41:58 25475 25344 Successfully connected to Storage Manager.
2020-01-31 08:41:58 25476 25344 Successfully connected to Storage Manager.
2020-01-31 08:41:59 25475 25344 Begin cold level 0 restore gimdbs1 (Storage Manager copy ID: 606944 0).
2020-01-31 08:41:59 25476 25344 Begin cold level 0 restore gtxlog1 (Storage Manager copy ID: 606942 0).
2020-01-31 08:42:01 25476 25344 Completed cold level 0 restore gtxlog1.
2020-01-31 08:42:01 25476 25344 Process 25476 25344 completed.
2020-01-31 08:46:59 25475 25344 0x0532dbb pages of gimdbs1 have been restored.
2020-01-31 08:52:00 25475 25344 0x0a1df7e pages of gimdbs1 have been restored.
2020-01-31 08:57:01 25475 25344 0x0f89058 pages of gimdbs1 have been restored.
2020-01-31 09:02:02 25475 25344 0x014c8147 pages of gimdbs1 have been restored

------------------------------
John Henry
------------------------------

#Informix

Original Message------

Most likely your storage manager was busy performing some other archive or restore and didn't respond beyond acknowledging the request. I have seen that behavior with multiple storage engines.

Art

Art S. Kagel, President and Principal Consultant

ASK Database Management

www.askdbmgt.com

Blog: http://informix-myview.blogspot.com/

Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on 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.

#Informix

Thank you Alexandre,  I apologies for the multiple posts, this is my first time on the forum since it has moved to this new site and I haven't navigated around it very successfully.  I couldn't find my posts.   How do I "check the job execution history on the SM itself"

------------------------------
John Henry
------------------------------

Original Message:
Sent: Tue February 04, 2020 12:21 PM
From: Alexandre Marini
Subject: Database Restore Question

Hello.

You can have a better conclusive idea looking at the job execution history on the SM itself.

Then you will know if this slowliness is internal to SM or external.

HTH

Best regards

Alexandre Marini

Original Message------

Most likely your storage manager was busy performing some other archive or restore and didn't respond beyond acknowledging the request. I have seen that behavior with multiple storage engines.

Art

Art S. Kagel, President and Principal Consultant

ASK Database Management

www.askdbmgt.com

Blog: http://informix-myview.blogspot.com/

Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on 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.

#Informix

Original Message------

Thank you Alexandre,  I apologies for the multiple posts, this is my first time on the forum since it has moved to this new site and I haven't navigated around it very successfully.  I couldn't find my posts.   How do I "check the job execution history on the SM itself"

------------------------------
John Henry
------------------------------

#Informix

Thank you Art,  I apologies for the multiple posts, this is my first time on the forum since it has moved to this new site and I haven't navigated around it very successfully.  I couldn't find my posts.   Can I ask, is there way to stop and restart the storage manager to clear anything that may be running.  It is my belief that there was no backups or restores taking place at the time I started the restore.

------------------------------
John Henry
------------------------------

Original Message:
Sent: Tue February 04, 2020 12:05 PM
From: Art Kagel
Subject: Database Restore Question

Most likely your storage manager was busy performing some other archive or restore and didn't respond beyond acknowledging the request. I have seen that behavior with multiple storage engines.

Art

Art S. Kagel, President and Principal Consultant

ASK Database Management

www.askdbmgt.com

Blog: http://informix-myview.blogspot.com/

Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on 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.

Original Message------

Hi All,
I restored a development database last Friday and ran into some odd behavior.  Below are the first 25 lines from the bar_act.log file.  I issued the command "onbar_d -r -w -p" at 05:29:42 but it didn't connect to the Storage manager until 06:40:45 and it didn't start restoring anything until 08:41:10.  This is 3 hour and 10 minutes since issuing the command.  Does anyone have any experience with this behavior.  The version of Informix is "IBM Informix Dynamic Server Version 11.70.FC7"  running on Solaris

2020-01-31 05:29:42 25344 25342 /opt/informix/bin/onbar_d -r -w -p
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 37560 Current log id: 54611
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 55200 Current log id: 55202
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 55681 Current log id: 55683
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 56071 Current log id: 56073
2020-01-31 05:33:38 25344 25342 Warning: The ixbar file is missing an entry for one or more logical logs. Last log id: 73698 Current log id: 73700
2020-01-31 06:40:45 25344 25342 Successfully connected to Storage Manager.
2020-01-31 06:40:46 25344 25342 Begin reserved pages restore (level 0 of rootdbs, Storage Manager copy ID: 606940 0).
2020-01-31 06:40:46 25344 25342 Completed reserved pages restore (level 0 of rootdbs).
2020-01-31 08:41:10 25344 25342 Successfully connected to Storage Manager.
2020-01-31 08:41:10 25344 25342 Begin cold level 0 restore rootdbs (Storage Manager copy ID: 606940 0).
2020-01-31 08:41:55 25344 25342 Completed cold level 0 restore rootdbs.
2020-01-31 08:41:58 25475 25344 Process 25475 25344 successfully forked.
2020-01-31 08:41:58 25476 25344 Process 25476 25344 successfully forked.
2020-01-31 08:41:58 25475 25344 Successfully connected to Storage Manager.
2020-01-31 08:41:58 25476 25344 Successfully connected to Storage Manager.
2020-01-31 08:41:59 25475 25344 Begin cold level 0 restore gimdbs1 (Storage Manager copy ID: 606944 0).
2020-01-31 08:41:59 25476 25344 Begin cold level 0 restore gtxlog1 (Storage Manager copy ID: 606942 0).
2020-01-31 08:42:01 25476 25344 Completed cold level 0 restore gtxlog1.
2020-01-31 08:42:01 25476 25344 Process 25476 25344 completed.
2020-01-31 08:46:59 25475 25344 0x0532dbb pages of gimdbs1 have been restored.
2020-01-31 08:52:00 25475 25344 0x0a1df7e pages of gimdbs1 have been restored.
2020-01-31 08:57:01 25475 25344 0x0f89058 pages of gimdbs1 have been restored.
2020-01-31 09:02:02 25475 25344 0x014c8147 pages of gimdbs1 have been restored

------------------------------
John Henry
------------------------------

#Informix

Original Message------

Thank you Art,  I apologies for the multiple posts, this is my first time on the forum since it has moved to this new site and I haven't navigated around it very successfully.  I couldn't find my posts.   Can I ask, is there way to stop and restart the storage manager to clear anything that may be running.  It is my belief that there was no backups or restores taking place at the time I started the restore.

------------------------------
John Henry
------------------------------

#Informix

Thank You Art

------------------------------
John Henry
------------------------------

Original Message:
Sent: Wed February 05, 2020 01:35 PM
From: Art Kagel
Subject: Database Restore Question

John:

That's going to depend on your storage manager and honestly I almost never get to interact with them, so not familiar with any (except for PSM of course, but that would not be the problem). Reach out to your Storage or Systems Adminstrators.

Art S. Kagel, President and Principal Consultant

ASK Database Management

www.askdbmgt.com

Blog: http://informix-myview.blogspot.com/

Disclaimer: Please keep in mind that my own opinions are my own opinions and do not reflect on 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.

Original Message------

Thank you Art,  I apologies for the multiple posts, this is my first time on the forum since it has moved to this new site and I haven't navigated around it very successfully.  I couldn't find my posts.   Can I ask, is there way to stop and restart the storage manager to clear anything that may be running.  It is my belief that there was no backups or restores taking place at the time I started the restore.

------------------------------
John Henry
------------------------------

#Informix