topic Re: question on smo restore in Data Protection

question on smo restore

jimshomer — Thu, 05 Jun 2025 07:11:29 GMT

Hi,

When restoring from an smo backup we can specify option -recover -nologs. I am not sure what recovery actions are actually performed by smo in this case, would smo just simply restore the datafiles from the backup in this case (i.e., applying no logs)? If this is the case can I just simply leave out the -recovery -nologs option entirely? And if I leave out option -recovery -nologs can I open the database sucessfully after restoring?

Many thanks,

Re: question on smo restore

anandr — Sat, 24 Jul 2010 22:25:02 GMT

Hi JS,

-nologs: Specifies that SnapManager recovers the database to the time of the backup and apply no logs. You can use this parameter for online or offline backups.

If you specify the -recover option then SMO will actually recover the db for you. You also have the option not to specify the -recover option in which case SMO only perform the restore and then you cna manually recover if u deseiro so.

Thanks

Anand.

Re: question on smo restore

jimshomer — Sun, 25 Jul 2010 15:44:24 GMT

Hi Anand, I appreciate for your input.

We have two databases running on separate servers, for the discussion say PROD and TEST but they actually have the same SID. TEST is a clone of PROD at some prior point in time. Please, is there a way to use an smo backup belonging to PROD to update TEST using something like 'smo backup restore'? I am aware that an smo backup is only associated with the profile created for a specific instance.

We have a requirement to be able to, while keeping a production database running at all time, open a second instance to allow the user to access the data they once had in the database at some point in the past.

Many thanks,

Re: question on smo restore

anandr — Mon, 26 Jul 2010 14:08:53 GMT

Hi JS,

Did u create TEST as a clone of PROD using SMO? If so then u can delete TEST using SMO and then re-create a clone from the latest backup of PROD.

If not, then one option is to destroy TEST manually and then clone a latest backup of PROD to the test server and use the same SID as PROD for TEST. Since both the databases are on diff servers, Oracle will not complain even if u use the same SID.

Will this work for you?

Also, if TEST has to be diff points in time of PROD then i would recommend taking backups of PROD frequently so u can clone those backups and recreate diff points in time of production data. So for example, backup PROD every 6 hrs and then you can create 4 clones in a day of PROD onto 4 diff servers so they can all the same SID:

TEST1 would be clone of PROD at 00:00

TEST2 would be clone of PROD at 06:00

TEST3 would be clone of PROD at 12:00

TEST4 would be clone of PROD at 18:00

Also, you are probably aware that SMO can also change the SID for you while cloning - so if having the same SID is not a requirement for the clones then u can have SMO create a couple of clones on the same test server as well.

Thanks

Anand.

Re: question on smo restore

jimshomer — Mon, 26 Jul 2010 16:52:37 GMT

Hi Anand,

Thank you again for your input.

I hope to be able to use restore instead of clone as to be able to execute option '-recover -nologs' as I mentioned previously in a different post. Secondly, I thought restore would be faster and lead to less changes to the system/environment (e.g., oratab), this is a nice-to-have consideration.

I know you've already given much of your time but maybe you can help with this issue too. I had this error when trying to clone an instance from an smo backup:

--[ERROR] SMO-13032: Cannot perform operation: Clone Create. Root cause: java.rmi.ServerError: Error occurred in server thread; nested exception is:
java.lang.UnsatisfiedLinkError: /home/oracle/OraHome1/lib/libocijdbc9.so: /home/oracle/OraHome1/lib/libocijdbc9.so: cannot open shared object file: No such file or directory

But when I checked the area /home/oracle/OraHome1/lib/ the shared library libocijdbc9.so did exist

Re: question on smo restore

jimshomer — Mon, 26 Jul 2010 16:59:01 GMT

to continue from my previous post (terminated accidentally), listing of error messages seen from the clone problem.

Many thanks,

The following is the full listing of the operation:

--[ INFO] SMO-13046: Operation GUID 2339899f2a0f840a012a0f8412570001 starting on Profile ORA9GF_PROFILE
--[ INFO] SMO-04030: Validating uniqueness of new SID "clonesid".
--[ INFO] SMO-04040: Using ORACLE_HOME of "/home/oracle/OraHome1" from clonespec for clone.
--[ INFO] SMO-04042: Using Oracle OS account "oracle" from clonespec for clone.
--[ INFO] SMO-04044: Using Oracle OS group "dba" from clonespec for clone.
--[ INFO] SMO-07127: Locked database for SnapManager operations - created lock file "/home/oracle/OraHome1/dbs/.sm_lock_clonesid" on host croix.se.houston.geoquest.slb.com.
--[ INFO] SD-00025: Beginning to connect filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0.
--[ INFO] SD-00016: Discovering storage resources for /home/oracle_CLONESID.
--[ INFO] SD-00017: Finished storage discovery for /home/oracle_CLONESID.
--[ INFO] SD-00026: Finished connecting filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0.
--[ INFO] SD-00025: Beginning to connect filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0.
--[ INFO] SD-00016: Discovering storage resources for /opt/NetApp/smo/mnt/-home-oracle-20100726110943683_0.
--[ INFO] SD-00017: Finished storage discovery for /opt/NetApp/smo/mnt/-home-oracle-20100726110943683_0.
--[ INFO] SD-00026: Finished connecting filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0.
--[ INFO] ORACLE-00502: Adding entry for database clonesid in /etc/oratab.
--[ INFO] SMO-07300: Beginning clone of database "ORA9GF" to SID "clonesid" on host "croix".
--[ INFO] SMO-07302: Generating parameter file for "clonesid" at "/home/oracle/OraHome1/dbs/initclonesid.ora".
--[ INFO] SMO-07303: Generating password file for "clonesid" at "/home/oracle/OraHome1/dbs/orapwclonesid".
--[ INFO] SMO-07304: Starting up database "clonesid" in NOMOUNT mode.
--[ INFO] SMO-07305: Generating control files for database "clonesid".
--[ INFO] SMO-07312: Create Control File - Database: clonesid.
--[ INFO] SMO-07313: Create Control File - Redolog: /home/oracle_CLONESID/redo_2.log.
--[ INFO] SMO-07313: Create Control File - Redolog: /home/oracle_CLONESID/redo_3.log.
--[ INFO] SMO-07313: Create Control File - Redolog: /home/oracle_CLONESID/redo_1.log.
--[ INFO] SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/system.dbf.
--[ INFO] SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/tsindex.dbf.
--[ INFO] SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/tsdata.dbf.
--[ INFO] SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/undotbs.dbf.
--[ INFO] SMO-07337: Recovering database clone "clonesid" to a consistent point using archived logs from the backup.
--[ERROR] SMO-13032: Cannot perform operation: Clone Create. Root cause: java.rmi.ServerError: Error occurred in server thread; nested exception is:
java.lang.UnsatisfiedLinkError: /home/oracle/OraHome1/lib/libocijdbc9.so: /home/oracle/OraHome1/lib/libocijdbc9.so: cannot open shared object file: No such file or directory
--[ INFO] SMO-07316: Shutting down database "clonesid".
--[ INFO] SMO-07317: Deleting file "/home/oracle/OraHome1/dbs/initclonesid.ora".
--[ INFO] SMO-07317: Deleting file "/home/oracle/admin/clonesid/udump".
--[ INFO] SMO-07317: Deleting file "/home/oracle/admin/clonesid/bdump".
--[ INFO] SMO-07317: Deleting file "/home/oracle/admin/clonesid/cdump".
--[ INFO] SMO-07317: Deleting file "/home/oracle/OraHome1/dbs/orapwclonesid".
--[ INFO] SMO-07317: Deleting file "/home/oracle_CLONESID/control01.ctl".
--[ INFO] SMO-04038: Deleting now empty directory "/home/oracle/admin/clonesid"
--[ INFO] ORACLE-00503: Removing entry for database clonesid from /etc/oratab.
--[ INFO] SD-00031: Beginning to disconnect filesystem(s) [/opt/NetApp/smo/mnt/-home-oracle-20100726110943683_0].
--[ INFO] SD-00032: Finished disconnecting filesystem(s) [/opt/NetApp/smo/mnt/-home-oracle-20100726110943683_0].
--[ INFO] SD-00031: Beginning to disconnect filesystem(s) [/home/oracle_CLONESID].
--[ INFO] SD-00032: Finished disconnecting filesystem(s) [/home/oracle_CLONESID].
--[ INFO] SMO-07131: Unlocked database for SnapManager operations - removed lock file "/home/oracle/OraHome1/dbs/.sm_lock_clonesid" on host croix.se.houston.geoquest.slb.com.
--[ INFO] SMO-13039: Successfully aborted operation: Clone Create
--[ERROR] SMO-13048: Clone Create Operation Status: FAILED
--[ INFO] SMO-13049: Elapsed Time: 0:00:45.117

----

And the following is the smo log:

2010-07-26 09:22:43,267 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-13990: SnapManager for Oracle version 3.0.3.
2010-07-26 09:22:43,267 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-13991: SnapManager for Oracle version 3.0.3 build 20091217_0824 changeid 1006598 repository version 64 api version 9.
2010-07-26 09:22:43,268 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-13992: Java version: 1.5.0_09
Java vendor: Sun Microsystems Inc. Java home: /opt/NetApp/smo/jre Java classpath: /jdbc/lib/ojdbc5.jar:/opt/NetApp/smo/webapp/WEB-INF/lib/smo/smo.jar Java user: root Java dir: /opt/NetApp/smo.
2010-07-26 09:22:43,270 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: LD_LIBRARY_PATH:
/opt/NetApp/smo/jre/lib/amd64/server:/opt/NetApp/smo/jre/lib/amd64:/opt/NetApp/smo/jre/../lib/amd64:/opt/NetApp/smo/webapp/WEB-INF/native:/opt/NetApp/smo/webapp/WEB-INF/native:
2010-07-26 09:22:43,270 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: ORACLE_HOME:null
2010-07-26 09:22:43,270 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: ORACLE_SID:null
2010-07-26 09:22:43,277 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-13051: Process PID=5085
2010-07-26 09:22:43,277 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SPRING: Begin initialization...
2010-07-26 09:22:49,180 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SPRING: End initialization: 0:00:05.901
2010-07-26 09:22:49,222 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Profile name: ORA9GF_PROFILE, client username: root, effective username: root
2010-07-26 09:22:51,180 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-13036: Starting operation Clone Create on host croix.se.houston.geoquest.slb.com
2010-07-26 09:22:51,846 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: RepositoryDescriptor.getRawJdbcConnection smo303 connected to: jdbc:oracle:thin:@//croix:1521/smo
2010-07-26 09:22:51,850 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-20016: User "root" is authenticated for repository "smo303@smo/croix:1521".
2010-07-26 09:22:51,853 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Initializing Repository for descriptor: USERNAME='smo303', URL='jdbc:oracle:thin:@//croix:1521/smo'.
2010-07-26 09:22:51,854 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Repository Dialect: net.sf.hibernate.dialect.Oracle9Dialect
2010-07-26 09:22:51,854 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Repository DriverClass: oracle.jdbc.driver.OracleDriver
2010-07-26 09:22:56,210 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-09033: Connecting to repository: USERNAME='smo303', URL='jdbc:oracle:thin:@//croix:1521/smo'.
2010-07-26 09:22:56,582 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: RepositoryDescriptor.getRawJdbcConnection smo303 connected to: jdbc:oracle:thin:@//croix:1521/smo
2010-07-26 09:22:56,703 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-09034: Repository connection established.
2010-07-26 09:22:56,764 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Added 'repo.version' with value '64'
2010-07-26 09:22:56,764 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Repository passes version check.
2010-07-26 09:22:56,764 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Initialized Repository for descriptor: USERNAME='smo303', URL='jdbc:oracle:thin:@//croix:1521/smo'.
2010-07-26 09:22:56,785 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-20014: User "root" is authenticated for profile "ORA9GF_PROFILE".
2010-07-26 09:22:57,047 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Version: RHEL 4, FullVersion: RHEL 4U6
2010-07-26 09:22:57,050 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Using /dev/raw device analyzer
2010-07-26 09:22:57,065 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Using RHEL 4 MPIO handler
2010-07-26 09:22:57,181 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Oracle 9i clone check passed
2010-07-26 09:22:57,237 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Repository SYSDATE read as 2010-07-26 09:22:57.0
2010-07-26 09:22:57,238 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Initial heartbeat for OperationCycle null set to 2010-07-26 09:22:57.0
2010-07-26 09:22:57,466 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-13046: Operation GUID 2339899f2a0f2286012a0f228ed40001 starting on Profile ORA9GF_PROFILE
2010-07-26 09:22:57,479 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-13051: Process PID=5085
2010-07-26 09:22:57,597 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-04030: Validating uniqueness of new SID "clonesid".
2010-07-26 09:22:57,867 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-04040: Using ORACLE_HOME of "/home/oracle/OraHome1" from clonespec for clone.
2010-07-26 09:22:57,890 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-04042: Using Oracle OS account "oracle" from clonespec for clone.
2010-07-26 09:22:57,921 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-04044: Using Oracle OS group "dba" from clonespec for clone.
2010-07-26 09:22:59,039 [Thread-2] [DEBUG]: RepositoryDescriptor.getRawJdbcConnection smo303 connected to: jdbc:oracle:thin:@//croix:1521/smo
2010-07-26 09:22:59,248 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_ORIGINAL_SID]: [ora9gf]
2010-07-26 09:22:59,248 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_ORIGINAL_HOST]: [croix.se.houston.geoquest.slb.com]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_ORIGINAL_OS_USER]: [oracle]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_ORIGINAL_OS_GROUP]: [dba]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_TARGET_SID]: [clonesid]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_TARGET_HOST]: [croix]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_TARGET_OS_USER]: [oracle]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_TARGET_OS_GROUP]: [dba]
2010-07-26 09:22:59,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_TARGET_DB_PORT]: [1521]
2010-07-26 09:22:59,250 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_TARGET_GLOBAL_DB_NAME]: [clonesid]
2010-07-26 09:22:59,250 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [SM_BACKUP_LABEL]: [F_H_20100721081659CDT]
2010-07-26 09:22:59,250 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [ORACLE_HOME]: [/home/oracle/OraHome1]
2010-07-26 09:22:59,251 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [ORACLE_SID]: [clonesid]
2010-07-26 09:22:59,251 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: setting environment [PATH]: /opt/NetApp/smo/jre/bin:/opt/NetApp/smo/jre/bin:/sbin:/usr/sbin:/bin:/usr/bin:/usr/kerberos/sbin:/usr/kerberos/bin:/usr/local/bin:/bin:/usr/bin:/usr/X11R6/bin:/home/oracle/OraHome1/bin:/home/oracle/bin:/home/oracle/OraHome1/bin
2010-07-26 09:22:59,251 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: executing policy plugins
2010-07-26 09:22:59,251 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: plugin top level directory is /opt/NetApp/smo/plugins
2010-07-26 09:22:59,251 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: no pre plugins specified
2010-07-26 09:22:59,816 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: There is no storage component of type ASM File System in hierarchy for storage component /home/oracle/oradata/ora9gf/tsindex.dbf
2010-07-26 09:22:59,819 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: There is no storage component of type ASM File System in hierarchy for storage component /home/oracle/oradata/ora9gf/undotbs.dbf
2010-07-26 09:22:59,819 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: There is no storage component of type ASM File System in hierarchy for storage component /home/oracle/oradata/ora9gf/system.dbf
2010-07-26 09:22:59,819 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: There is no storage component of type ASM File System in hierarchy for storage component /home/oracle/oradata/ora9gf/tsdata.dbf
2010-07-26 09:22:59,856 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: ORACLE-00000: Executing SQL command:

2010-07-26 09:22:59,860 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00000: Executing shell command:
0:su oracle -p -c "sqlplus" "/NOLOG"
1:sqlplus /NOLOG
2:[]
2010-07-26 09:22:59,999 [Execution Monitor Thread [[]]] [DEBUG]: EXE-00001: Shell result [0:00:00.139] (Exit Value: 0):

SQL*Plus: Release 9.2.0.7.0 - Production on Mon Jul 26 09:22:59 2010

SQL> SQL> SQL> SQL> SQL> SQL> SQL> SQL> SQL> SQL> SQL>
2010-07-26 09:23:00,002 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Backup Oracle version 9.2.0.7.0, Destination /home/oracle/OraHome1 version 9.2.0.7.0
2010-07-26 09:23:00,061 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07127: Locked database for SnapManager operations - created lock file "/home/oracle/OraHome1/dbs/.sm_lock_clonesid" on host croix.se.houston.geoquest.slb.com.
2010-07-26 09:23:02,626 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: ASM-00007: No ASM instance detected on host croix.se.houston.geoquest.slb.com.
2010-07-26 09:23:02,645 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: ASM-00007: No ASM instance detected on host croix.se.houston.geoquest.slb.com.
2010-07-26 09:23:03,043 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: Assigning snapshot smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0 to user-defined mapping for source component /home/oracle
2010-07-26 09:23:03,293 [default0 7c1a5ca668bb723739bf102268bc4157] [INFO ]: SD-00025: Beginning to connect filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0.
2010-07-26 09:23:03,343 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "config" "show"
1:/usr/sbin/snapdrive config show
2010-07-26 09:23:04,590 [Execution Monitor Thread [/usr/sbin/snapdrive config show]] [DEBUG]: EXE-00001: Shell result [0:00:01.246] (Exit Value: 0):
#
# Snapdrive Configuration
#    file: /opt/NetApp/snapdrive/snapdrive.conf
#    Version 4.1.1    (Change 942392 Built Fri Jul 17 04:56:45 PDT 2009)
#
#
# Default values are shown by lines which are commented-out in this file.
# If there is no un-commented-out line in this file relating to a particular value, then
# the default value represented in the commented-out line is what SnapDrive will use.
#
# To change a value:
#
#     -- copy the line that is commented out to another line
#     -- Leave the commented-out line
#     -- Modify the new line to remove the '#' and to set the new value.
#     -- Save the file and exit
#
audit-log-file="/var/log/sd-audit.log" # audit log file
trace-log-file="/var/log/sd-trace.log" # trace log file
recovery-log-file="/var/log/sd-recovery.log" # recovery log file
client-trace-log-file="/var/log/sd-client-trace.log" # client trace log file
daemon-trace-log-file="/var/log/sd-daemon-trace.log" # daemon trace log file
autosupport-enabled=off # Enable autosupport (requires autosupport-filer be set)
autosupport-filer="" # Filer to use for autosupport (filer must be configured for autosupport)
audit-log-max-size=20480 # Maximum size (in bytes) of audit log file
audit-log-save=2 # Number of old copies of audit log file to save
available-lun-reserve=8 # Number of LUNs for which to reserve host resources
cluster-operation-timeout-secs=600 # Cluster Operation timeout in seconds
contact-http-port=80 # HTTP port to contact to access the filer
contact-http-dfm-port=8088 # HTTP server port to contact to access the DFM
contact-http-port-sdu-daemon=4094 # HTTP port on which sdu daemon will bind
contact-https-port-sdu-daemon=4095 # HTTPS port on which sdu daemon will bind
contact-ssl-port=443 # SSL port to contact to access the filer
contact-ssl-dfm-port=8488 # SSL server port to contact to access the DFM
device-retries=3 # Number of retries on Ontap filer LUN device inquiry
sfsr-polling-frequency=10 # Sleep for the given amount of seconds before attempting SFSR
device-retry-sleep-secs=1 # Number of seconds between Ontap filer LUN device inquiry retries
enable-implicit-host-preparation=on # Enable implicit host preparation for LUN creation
filer-restore-retries=1440 # Number of retries while doing lun restore
filer-restore-retry-sleep-secs=15 # Number of secs between retries while restoring lun
filesystem-freeze-timeout-secs=300 # File system freeze timeout in seconds
default-noprompt=off # A default value for -noprompt option in the command line
mgmt-retries=2 # Number of retries on ManageONTAP control channel
lun-onlining-in-progress-sleep-secs=3 # Number of secs between retries when lun onlining in progress after VBSR
lun-onlining-in-progress-retries=40 # Number of retries when lun onlining in progress after VBSR
mgmt-retry-sleep-secs=2 # Number of seconds between retries on ManageONTAP control channel
mgmt-retry-sleep-long-secs=90 # Number of seconds between retries on ManageONTAP control channel (failover error)
prepare-lun-count=16 # Number of LUNs for which to request host preparation
PATH="/sbin:/usr/sbin:/bin:/usr/bin:/opt/NTAP/SANToolkit/bin:/opt/sanlun/bin" # toolset search path
password-file="/opt/NetApp/snapdrive/.pwfile" # location of password file
sdu-password-file="/opt/NetApp/snapdrive/.sdupw" # location of SDU Daemon and DFM password file
prefix-filer-lun="" # Prefix for all filer LUN names internally generated by storage create
sdu-daemon-certificate-path="/opt/NetApp/snapdrive/snapdrive.pem" # location of https server certificate
recovery-log-save=20 # Number of old copies of recovery log file to save
snapcreate-consistency-retries=3 # Number of retries on best-effort snapshot consistency check failure
snapcreate-consistency-retry-sleep=1 # Number of seconds between best-effort snapshot consistency retries
snapcreate-must-make-snapinfo-on-qtree=off # snap create must be able to create snapinfo on qtree
snapcreate-cg-timeout="relaxed" # Timeout type used in snapshot creation with Consitency Groups. Possible values are "urgent", "medium" or "relaxed".
snapcreate-check-nonpersistent-nfs=on # Check that entries exist in /etc/fstab for specified nfs fs.
rbac-cache=off # Use RBAC cache when all DFM servers are down. Active only when rbac-method is dfm.
enable-split-clone="off" # Enable split clone volume or lun during connnect/disconnect
enable-parallel-operations=on # Enable support for parallel operations
snapconnect-nfs-removedirectories=off # NFS snap connect cleaup unwanted dirs;
snapdelete-delete-rollback-with-snap=off # Delete all rollback snapshots related to specified snapshot
snaprestore-snapmirror-check=on # Enable snapmirror destination volume check in snap restore
snaprestore-delete-rollback-after-restore=on # Delete rollback snapshot after a successfull restore
snaprestore-make-rollback=on # Create snap rollback before restore
snaprestore-must-make-rollback=on # Do not continue 'snap restore' if rollback creation fails
space-reservations-enabled=on # Enable space reservations when creating new luns
flexclone-writereserve-enabled=off # Enable space reservations during FlexClone creation
space-reservations-volume-enabled="snapshot" # Enable space reservation over volume, possible values snapshot, volume, none
vol-restore="off" # Method of restoring a volume. Possible values execute, preview and off
snapmirror-dest-multiple-filervolumes-enabled=off # Enable snap restore and snap connect commands to deal with snapshots moved to another filer volume (e.g. via SnapMirror) where snapshot spans multiple filers or volumes
default-transport="iscsi" # Transport type to use for storage provisioning, when a decision is needed
multipathing-type="none" # Multipathing software to use when more than one multipathing solution is available. Possible values are 'NativeMPIO' or 'none'
fstype="ext3" # File system to use when more than one file system is available
vmtype="lvm" # Volume manager to use when more than one volume manager is available
trace-enabled=on # Enable trace
secure-communication-among-cluster-nodes=off # Enable Secure Communication
trace-level=7 # Trace levels: 1=FatalError; 2=AdminError; 3=CommandError; 4=warning, 5=info, 6=verbose, 7=full
trace-log-max-size=10485760 # Maximum size of trace log file in bytes; 0 means one trace log file per command
trace-log-save=100 # Number of old copies of trace log file to save
all-access-if-rbac-unspecified=on # Allow all access if the RBAC permissions file is missing
san-clone-method="lunclone" # Clone methods for snap connect: unrestricted, optimal or lunclone
prefix-clone-name="" # Prefix string for naming FlexClone
rbac-method="native" # Role Based Access Control(RBAC) methods: native or dfm
dfm-rbac-retries=12 # Number of rbac access retries upon a DFM refresh
dfm-rbac-retry-sleep-secs=15 # Number of seconds between DFM rbac access retries upon a DFM refresh
use-https-to-filer=off # Communication with filer done via HTTPS instead of HTTP
use-https-to-dfm=on # Communication with DFM done via HTTPS instead of HTTP
use-https-to-sdu-daemon=off # Communication with daemon done via HTTPS instead of HTTP

2010-07-26 09:23:04,595 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: RBAC is not enabled for snapdrive
2010-07-26 09:23:04,596 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "snap" "connect" "-fs" "/home/oracle" "/home/oracle_CLONESID" "-destfv" "netapp:/vol/vol1" "SnapManager_2010072609230365_vol1" "-snapname" "netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0" "-autorename" "-noreserve"
1:/usr/sbin/snapdrive snap connect -fs /home/oracle /home/oracle_CLONESID -destfv netapp:/vol/vol1 SnapManager_2010072609230365_vol1 -snapname netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0 -autorename -noreserve
2010-07-26 09:23:07,988 [Execution Monitor Thread [/usr/sbin/snapdrive snap connect -fs /home/oracle /home/oracle_CLONESID -destfv netapp:/vol/vol1 SnapManager_2010072609230365_vol1 -snapname netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0 -autorename -noreserve]] [DEBUG]: EXE-00001: Shell result [0:00:03.392] (Exit Value: 0):

connecting /home/oracle_CLONESID
      to filer directory: netapp:/vol/SnapManager_2010072609230365_vol1/home/oracle
    Volume copy netapp:/vol/SnapManager_2010072609230365_vol1 ... created
         (original: vol1)
Successfully connected to snapshot netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0
    file system: /home/oracle_CLONESID
    filer directory: netapp:/vol/SnapManager_2010072609230365_vol1/home/oracle
2010-07-26 09:23:07,991 [default0 7c1a5ca668bb723739bf102268bc4157] [INFO ]: SD-00016: Discovering storage resources for /home/oracle_CLONESID.
2010-07-26 09:23:08,004 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "storage" "show" "-fs" "/home/oracle_CLONESID"
1:/usr/sbin/snapdrive storage show -fs /home/oracle_CLONESID
2010-07-26 09:23:10,525 [Execution Monitor Thread [/usr/sbin/snapdrive storage show -fs /home/oracle_CLONESID]] [DEBUG]: EXE-00001: Shell result [0:00:02.520] (Exit Value: 0):
NFS device: netapp:/vol/SnapManager_2010072609230365_vol1/home/oracle    mount point: /home/oracle_CLONESID (persistent)

2010-07-26 09:23:10,530 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: Version: RHEL 4, FullVersion: RHEL 4U6
2010-07-26 09:23:10,531 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: Using /dev/raw device analyzer
2010-07-26 09:23:10,531 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: Using RHEL 4 MPIO handler
2010-07-26 09:23:10,531 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "config" "list" "-mgmtpath"
1:/usr/sbin/snapdrive config list -mgmtpath
2010-07-26 09:23:10,914 [Execution Monitor Thread [/usr/sbin/snapdrive config list -mgmtpath]] [DEBUG]: EXE-00001: Shell result [0:00:00.383] (Exit Value: 0):
system name   management interface   datapath interface
-------------------------------------------------------
2010-07-26 09:23:10,979 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "config" "show"
1:/usr/sbin/snapdrive config show
2010-07-26 09:23:12,350 [Execution Monitor Thread [/usr/sbin/snapdrive config show]] [DEBUG]: EXE-00001: Shell result [0:00:01.370] (Exit Value: 0):
#
# Snapdrive Configuration
#    file: /opt/NetApp/snapdrive/snapdrive.conf
#    Version 4.1.1    (Change 942392 Built Fri Jul 17 04:56:45 PDT 2009)
#
#
# Default values are shown by lines which are commented-out in this file.
# If there is no un-commented-out line in this file relating to a particular value, then
# the default value represented in the commented-out line is what SnapDrive will use.
#
# To change a value:
#
#     -- copy the line that is commented out to another line
#     -- Leave the commented-out line
#     -- Modify the new line to remove the '#' and to set the new value.
#     -- Save the file and exit
#
audit-log-file="/var/log/sd-audit.log" # audit log file
trace-log-file="/var/log/sd-trace.log" # trace log file
recovery-log-file="/var/log/sd-recovery.log" # recovery log file
client-trace-log-file="/var/log/sd-client-trace.log" # client trace log file
daemon-trace-log-file="/var/log/sd-daemon-trace.log" # daemon trace log file
autosupport-enabled=off # Enable autosupport (requires autosupport-filer be set)
autosupport-filer="" # Filer to use for autosupport (filer must be configured for autosupport)
audit-log-max-size=20480 # Maximum size (in bytes) of audit log file
audit-log-save=2 # Number of old copies of audit log file to save
available-lun-reserve=8 # Number of LUNs for which to reserve host resources
cluster-operation-timeout-secs=600 # Cluster Operation timeout in seconds
contact-http-port=80 # HTTP port to contact to access the filer
contact-http-dfm-port=8088 # HTTP server port to contact to access the DFM
contact-http-port-sdu-daemon=4094 # HTTP port on which sdu daemon will bind
contact-https-port-sdu-daemon=4095 # HTTPS port on which sdu daemon will bind
contact-ssl-port=443 # SSL port to contact to access the filer
contact-ssl-dfm-port=8488 # SSL server port to contact to access the DFM
device-retries=3 # Number of retries on Ontap filer LUN device inquiry
sfsr-polling-frequency=10 # Sleep for the given amount of seconds before attempting SFSR
device-retry-sleep-secs=1 # Number of seconds between Ontap filer LUN device inquiry retries
enable-implicit-host-preparation=on # Enable implicit host preparation for LUN creation
filer-restore-retries=1440 # Number of retries while doing lun restore
filer-restore-retry-sleep-secs=15 # Number of secs between retries while restoring lun
filesystem-freeze-timeout-secs=300 # File system freeze timeout in seconds
default-noprompt=off # A default value for -noprompt option in the command line
mgmt-retries=2 # Number of retries on ManageONTAP control channel
lun-onlining-in-progress-sleep-secs=3 # Number of secs between retries when lun onlining in progress after VBSR
lun-onlining-in-progress-retries=40 # Number of retries when lun onlining in progress after VBSR
mgmt-retry-sleep-secs=2 # Number of seconds between retries on ManageONTAP control channel
mgmt-retry-sleep-long-secs=90 # Number of seconds between retries on ManageONTAP control channel (failover error)
prepare-lun-count=16 # Number of LUNs for which to request host preparation
PATH="/sbin:/usr/sbin:/bin:/usr/bin:/opt/NTAP/SANToolkit/bin:/opt/sanlun/bin" # toolset search path
password-file="/opt/NetApp/snapdrive/.pwfile" # location of password file
sdu-password-file="/opt/NetApp/snapdrive/.sdupw" # location of SDU Daemon and DFM password file
prefix-filer-lun="" # Prefix for all filer LUN names internally generated by storage create
sdu-daemon-certificate-path="/opt/NetApp/snapdrive/snapdrive.pem" # location of https server certificate
recovery-log-save=20 # Number of old copies of recovery log file to save
snapcreate-consistency-retries=3 # Number of retries on best-effort snapshot consistency check failure
snapcreate-consistency-retry-sleep=1 # Number of seconds between best-effort snapshot consistency retries
snapcreate-must-make-snapinfo-on-qtree=off # snap create must be able to create snapinfo on qtree
snapcreate-cg-timeout="relaxed" # Timeout type used in snapshot creation with Consitency Groups. Possible values are "urgent", "medium" or "relaxed".
snapcreate-check-nonpersistent-nfs=on # Check that entries exist in /etc/fstab for specified nfs fs.
rbac-cache=off # Use RBAC cache when all DFM servers are down. Active only when rbac-method is dfm.
enable-split-clone="off" # Enable split clone volume or lun during connnect/disconnect
enable-parallel-operations=on # Enable support for parallel operations
snapconnect-nfs-removedirectories=off # NFS snap connect cleaup unwanted dirs;
snapdelete-delete-rollback-with-snap=off # Delete all rollback snapshots related to specified snapshot
snaprestore-snapmirror-check=on # Enable snapmirror destination volume check in snap restore
snaprestore-delete-rollback-after-restore=on # Delete rollback snapshot after a successfull restore
snaprestore-make-rollback=on # Create snap rollback before restore
snaprestore-must-make-rollback=on # Do not continue 'snap restore' if rollback creation fails
space-reservations-enabled=on # Enable space reservations when creating new luns
flexclone-writereserve-enabled=off # Enable space reservations during FlexClone creation
space-reservations-volume-enabled="snapshot" # Enable space reservation over volume, possible values snapshot, volume, none
vol-restore="off" # Method of restoring a volume. Possible values execute, preview and off
snapmirror-dest-multiple-filervolumes-enabled=off # Enable snap restore and snap connect commands to deal with snapshots moved to another filer volume (e.g. via SnapMirror) where snapshot spans multiple filers or volumes
default-transport="iscsi" # Transport type to use for storage provisioning, when a decision is needed
multipathing-type="none" # Multipathing software to use when more than one multipathing solution is available. Possible values are 'NativeMPIO' or 'none'
fstype="ext3" # File system to use when more than one file system is available
vmtype="lvm" # Volume manager to use when more than one volume manager is available
trace-enabled=on # Enable trace
secure-communication-among-cluster-nodes=off # Enable Secure Communication
trace-level=7 # Trace levels: 1=FatalError; 2=AdminError; 3=CommandError; 4=warning, 5=info, 6=verbose, 7=full
trace-log-max-size=10485760 # Maximum size of trace log file in bytes; 0 means one trace log file per command
trace-log-save=100 # Number of old copies of trace log file to save
all-access-if-rbac-unspecified=on # Allow all access if the RBAC permissions file is missing
san-clone-method="lunclone" # Clone methods for snap connect: unrestricted, optimal or lunclone
prefix-clone-name="" # Prefix string for naming FlexClone
rbac-method="native" # Role Based Access Control(RBAC) methods: native or dfm
dfm-rbac-retries=12 # Number of rbac access retries upon a DFM refresh
dfm-rbac-retry-sleep-secs=15 # Number of seconds between DFM rbac access retries upon a DFM refresh
use-https-to-filer=off # Communication with filer done via HTTPS instead of HTTP
use-https-to-dfm=on # Communication with DFM done via HTTPS instead of HTTP
use-https-to-sdu-daemon=off # Communication with daemon done via HTTPS instead of HTTP

2010-07-26 09:23:12,450 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: Using username root for storageSystem netapp
2010-07-26 09:23:12,479 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: ZEPHYR-10001: Executing ZAPI request "nfs-exportfs-storage-path" to "netapp":
<nfs-exportfs-storage-path>
<pathname>/vol/SnapManager_2010072609230365_vol1/home/oracle</pathname>
</nfs-exportfs-storage-path>

2010-07-26 09:23:12,587 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: ZEPHYR-10002: Received ZAPI response for "nfs-exportfs-storage-path" from "netapp":
<results status='passed'>
<actual-pathname>/vol/SnapManager_2010072609230365_vol1/home/oracle</actual-pathname>
</results>

2010-07-26 09:23:12,589 [default0 7c1a5ca668bb723739bf102268bc4157] [INFO ]: SD-00017: Finished storage discovery for /home/oracle_CLONESID.
2010-07-26 09:23:12,598 [default0 7c1a5ca668bb723739bf102268bc4157] [INFO ]: SD-00026: Finished connecting filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081707_f_h_1_2339899f29f526640129f5266e1c0001_0.
2010-07-26 09:23:12,614 [default0 7c1a5ca668bb723739bf102268bc4157] [DEBUG]: Chowning file /home/oracle_CLONESID to User: oracle Group: dba
2010-07-26 09:23:12,881 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: CON-00009: Auto-generated File System name /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0 for connection for source storage component /home/oracle (and snapshot smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0).
2010-07-26 09:23:12,898 [default0 86da74872e66fac25b58ded043b04122] [INFO ]: SD-00025: Beginning to connect filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0.
2010-07-26 09:23:12,914 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "snap" "connect" "-fs" "/home/oracle" "/opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0" "-destfv" "netapp:/vol/vol1" "SnapManager_20100726092312898_vol1" "-snapname" "netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0" "-autorename" "-noreserve"
1:/usr/sbin/snapdrive snap connect -fs /home/oracle /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0 -destfv netapp:/vol/vol1 SnapManager_20100726092312898_vol1 -snapname netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0 -autorename -noreserve
2010-07-26 09:23:18,315 [Execution Monitor Thread [/usr/sbin/snapdrive snap connect -fs /home/oracle /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0 -destfv netapp:/vol/vol1 SnapManager_20100726092312898_vol1 -snapname netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0 -autorename -noreserve]] [DEBUG]: EXE-00001: Shell result [0:00:05.400] (Exit Value: 0):

connecting /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0
      to filer directory: netapp:/vol/SnapManager_20100726092312898_vol1/home/oracle
    Volume copy netapp:/vol/SnapManager_20100726092312898_vol1 ... created
         (original: vol1)
Successfully connected to snapshot netapp:/vol/vol1:smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0
    file system: /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0
    filer directory: netapp:/vol/SnapManager_20100726092312898_vol1/home/oracle
2010-07-26 09:23:18,315 [default0 86da74872e66fac25b58ded043b04122] [INFO ]: SD-00016: Discovering storage resources for /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0.
2010-07-26 09:23:18,334 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "storage" "show" "-fs" "/opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0"
1:/usr/sbin/snapdrive storage show -fs /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0
2010-07-26 09:23:20,741 [Execution Monitor Thread [/usr/sbin/snapdrive storage show -fs /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0]] [DEBUG]: EXE-00001: Shell result [0:00:02.407] (Exit Value: 0):
NFS device: netapp:/vol/SnapManager_20100726092312898_vol1/home/oracle    mount point: /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0 (persistent)

2010-07-26 09:23:20,742 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: Version: RHEL 4, FullVersion: RHEL 4U6
2010-07-26 09:23:20,742 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: Using /dev/raw device analyzer
2010-07-26 09:23:20,742 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: Using RHEL 4 MPIO handler
2010-07-26 09:23:20,743 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "config" "list" "-mgmtpath"
1:/usr/sbin/snapdrive config list -mgmtpath
2010-07-26 09:23:22,118 [Execution Monitor Thread [/usr/sbin/snapdrive config list -mgmtpath]] [DEBUG]: EXE-00001: Shell result [0:00:01.375] (Exit Value: 0):
system name management interface datapath interface
-------------------------------------------------------
2010-07-26 09:23:22,119 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: Using username root for storageSystem netapp
2010-07-26 09:23:22,126 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: ZEPHYR-10001: Executing ZAPI request "nfs-exportfs-storage-path" to "netapp":
<nfs-exportfs-storage-path>
<pathname>/vol/SnapManager_20100726092312898_vol1/home/oracle</pathname>
</nfs-exportfs-storage-path>

2010-07-26 09:23:22,234 [default0 86da74872e66fac25b58ded043b04122] [DEBUG]: ZEPHYR-10002: Received ZAPI response for "nfs-exportfs-storage-path" from "netapp":
<results status='passed'>
<actual-pathname>/vol/SnapManager_20100726092312898_vol1/home/oracle</actual-pathname>
</results>

2010-07-26 09:23:22,235 [default0 86da74872e66fac25b58ded043b04122] [INFO ]: SD-00017: Finished storage discovery for /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0.
2010-07-26 09:23:22,284 [default0 86da74872e66fac25b58ded043b04122] [INFO ]: SD-00026: Finished connecting filesystem(s) [/home/oracle] from snapshot smo_ora9gf_profile_ora9gf_on20100721_at081722_f_h_2_2339899f29f526640129f5266e1c0001_0.
2010-07-26 09:23:22,703 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: ORACLE-00502: Adding entry for database clonesid in /etc/oratab.
2010-07-26 09:23:22,785 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07300: Beginning clone of database "ORA9GF" to SID "clonesid" on host "croix".
2010-07-26 09:23:23,454 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07302: Generating parameter file for "clonesid" at "/home/oracle/OraHome1/dbs/initclonesid.ora".
2010-07-26 09:23:23,588 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-07310: Created directory "/home/oracle/admin/clonesid".
2010-07-26 09:23:23,597 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: chmod 750 /home/oracle/admin/clonesid
2010-07-26 09:23:23,609 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-07310: Created directory "/home/oracle/admin/clonesid/udump".
2010-07-26 09:23:23,612 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: chmod 750 /home/oracle/admin/clonesid/udump
2010-07-26 09:23:23,615 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-07310: Created directory "/home/oracle/admin/clonesid/bdump".
2010-07-26 09:23:23,617 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: chmod 750 /home/oracle/admin/clonesid/bdump
2010-07-26 09:23:23,621 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: SMO-07310: Created directory "/home/oracle/admin/clonesid/cdump".
2010-07-26 09:23:23,627 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: chmod 750 /home/oracle/admin/clonesid/cdump
2010-07-26 09:23:23,634 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07303: Generating password file for "clonesid" at "/home/oracle/OraHome1/dbs/orapwclonesid".
2010-07-26 09:23:23,643 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00000: Executing shell command:
0:su oracle -p -c "orapwd" "file=/home/oracle/OraHome1/dbs/orapwclonesid" "password=^^^^^" "entries=30"
1:orapwd file=/home/oracle/OraHome1/dbs/orapwclonesid password=^^^^^ entries=30
2010-07-26 09:23:23,782 [Execution Monitor Thread [orapwd file=/home/oracle/OraHome1/dbs/orapwclonesid password=^^^^^ entries=30]] [DEBUG]: EXE-00001: Shell result [0:00:00.139] (Exit Value: 0):

2010-07-26 09:23:23,783 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07304: Starting up database "clonesid" in NOMOUNT mode.
2010-07-26 09:23:23,789 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: ORACLE-00000: Executing SQL command:
STARTUP NOMOUNT EXCLUSIVE PFILE=/home/oracle/OraHome1/dbs/initclonesid.ora;
2010-07-26 09:23:23,791 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00000: Executing shell command:
0:su oracle -p -c "sqlplus" "-S" "/NOLOG"
1:sqlplus -S /NOLOG
2:[STARTUP NOMOUNT EXCLUSIVE PFILE=/home/oracle/OraHome1/dbs/initclonesid.ora;]
2010-07-26 09:23:24,558 [Execution Monitor Thread [[STARTUP NOMOUNT EXCLUSIVE PFILE=/home/oracle/OraHome1/dbs/initclonesid.ora;]]] [DEBUG]: EXE-00001: Shell result [0:00:00.766] (Exit Value: 0):
Connected to an idle instance.
ORACLE instance started.
Total System Global Area 958994332 bytes
Fixed Size             452508 bytes
Variable Size          301989888 bytes
Database Buffers      654311424 bytes
Redo Buffers            2240512 bytes
2010-07-26 09:23:24,559 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07305: Generating control files for database "clonesid".
2010-07-26 09:23:24,564 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07312: Create Control File - Database: clonesid.
2010-07-26 09:23:24,570 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07313: Create Control File - Redolog: /home/oracle_CLONESID/redo_3.log.
2010-07-26 09:23:24,576 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07313: Create Control File - Redolog: /home/oracle_CLONESID/redo_2.log.
2010-07-26 09:23:24,594 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07313: Create Control File - Redolog: /home/oracle_CLONESID/redo_1.log.
2010-07-26 09:23:24,601 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/tsdata.dbf.
2010-07-26 09:23:24,606 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/undotbs.dbf.
2010-07-26 09:23:24,612 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/system.dbf.
2010-07-26 09:23:24,617 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07314: Create Control File - Datafile: /home/oracle_CLONESID/oradata/ora9gf/tsindex.dbf.
2010-07-26 09:23:24,622 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: ORACLE-00000: Executing SQL command:
CREATE CONTROLFILE SET DATABASE "clonesid" RESETLOGS NOARCHIVELOG
MAXLOGHISTORY 226
MAXLOGMEMBERS 3
MAXDATAFILES 100
MAXLOGFILES 5
MAXINSTANCES 1
LOGFILE
GROUP 2(
'/home/oracle_CLONESID/redo_2.log'
) SIZE 102400K,
GROUP 1(
'/home/oracle_CLONESID/redo_1.log'
) SIZE 102400K,
GROUP 3(
'/home/oracle_CLONESID/redo_3.log'
) SIZE 102400K
DATAFILE
'/home/oracle_CLONESID/oradata/ora9gf/tsdata.dbf',
'/home/oracle_CLONESID/oradata/ora9gf/undotbs.dbf',
'/home/oracle_CLONESID/oradata/ora9gf/system.dbf',
'/home/oracle_CLONESID/oradata/ora9gf/tsindex.dbf'
CHARACTER SET WE8ISO8859P1
;
2010-07-26 09:23:24,624 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00000: Executing shell command:
0:su oracle -p -c "sqlplus" "-S" "/NOLOG"
1:sqlplus -S /NOLOG
2:[CREATE CONTROLFILE SET DATABASE "clonesid" RESETLOGS NOARCHIVELOG, MAXLOGHISTORY 226, MAXLOGMEMBERS 3, MAXDATAFILES 100, MAXLOGFILES 5, MAXINSTANCES 1, LOGFILE, GROUP 2( , '/home/oracle_CLONESID/redo_2.log', ) SIZE 102400K,, GROUP 1( , '/home/oracle_CLONESID/redo_1.log', ) SIZE 102400K,, GROUP 3( , '/home/oracle_CLONESID/redo_3.log', ) SIZE 102400K, DATAFILE, '/home/oracle_CLONESID/oradata/ora9gf/tsdata.dbf',, '/home/oracle_CLONESID/oradata/ora9gf/undotbs.dbf',, '/home/oracle_CLONESID/oradata/ora9gf/system.dbf',, '/home/oracle_CLONESID/oradata/ora9gf/tsindex.dbf', CHARACTER SET WE8ISO8859P1, ;]
2010-07-26 09:23:25,977 [Execution Monitor Thread [[CREATE CONTROLFILE SET DATABASE "clonesid" RESETLOGS NOARCHIVELOG, MAXLOGHISTORY 226, MAXLOGMEMBERS 3, MAXDATAFILES 100, MAXLOGFILES 5, MAXINSTANCES 1, LOGFILE, GROUP 2( , '/home/oracle_CLONESID/redo_2.log', ) SIZE 102400K,, GROUP 1( , '/home/oracle_CLONESID/redo_1.log', ) SIZE 102400K,, GROUP 3( , '/home/oracle_CLONESID/redo_3.log', ) SIZE 102400K, DATAFILE, '/home/oracle_CLONESID/oradata/ora9gf/tsdata.dbf',, '/home/oracle_CLONESID/oradata/ora9gf/undotbs.dbf',, '/home/oracle_CLONESID/oradata/ora9gf/system.dbf',, '/home/oracle_CLONESID/oradata/ora9gf/tsindex.dbf', CHARACTER SET WE8ISO8859P1, ;]]] [DEBUG]: EXE-00001: Shell result [0:00:01.353] (Exit Value: 0):
Connected.
2010-07-26 09:23:26,067 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07337: Recovering database clone "clonesid" to a consistent point using archived logs from the backup.
2010-07-26 09:23:26,080 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Opening connection for JDBC descriptor jdbc:oracle:oci:/@
2010-07-26 09:23:26,108 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: RemoteObjectFactoryRegistryImpl: getting registry at //163.185.9.31:27215
2010-07-26 09:23:26,111 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Using RMI Registry //163.185.9.31:27215
2010-07-26 09:23:26,116 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00000: Executing shell command:
0:su oracle -p -c "./bin/launch-java" "com.netapp.common.remote.RemoteObjectFactoryImpl" "163.185.9.31" "27215" "efb5ce5235f9c78733c8113f6f17a8ab"
1:./bin/launch-java com.netapp.common.remote.RemoteObjectFactoryImpl 163.185.9.31 27215 efb5ce5235f9c78733c8113f6f17a8ab
2010-07-26 09:23:26,127 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00007: Jvm for class com.netapp.common.remote.RemoteObjectFactoryImpl launched and still running. Result:

2010-07-26 09:23:26,140 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Waiting for RemoteObjectFactory to be registered with GUID efb5ce5235f9c78733c8113f6f17a8ab ...
2010-07-26 09:23:27,145 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Waiting for RemoteObjectFactory to be registered with GUID efb5ce5235f9c78733c8113f6f17a8ab ...
2010-07-26 09:23:28,249 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Successfully bound to RemoteObjectFactory with GUID efb5ce5235f9c78733c8113f6f17a8ab
2010-07-26 09:23:28,466 [RMI TCP Connection(1)-163.185.9.31] [ERROR]: SMO-13032: Cannot perform operation: Clone Create. Root cause: java.rmi.ServerError: Error occurred in server thread; nested exception is:
    java.lang.UnsatisfiedLinkError: /home/oracle/OraHome1/lib/libocijdbc9.so: /home/oracle/OraHome1/lib/libocijdbc9.so: cannot open shared object file: No such file or directory
java.lang.RuntimeException: java.rmi.ServerError: Error occurred in server thread; nested exception is:
    java.lang.UnsatisfiedLinkError: /home/oracle/OraHome1/lib/libocijdbc9.so: /home/oracle/OraHome1/lib/libocijdbc9.so: cannot open shared object file: No such file or directory
    at com.netapp.oracle.jdbc.OracleConnectionFactory.createOCIJDBCConnectionInNewJvm(OracleConnectionFactory.java:98)
    at com.netapp.oracle.jdbc.OracleConnectionFactory.createConnection(OracleConnectionFactory.java:74)
    at com.netapp.oracle.jdbc.OracleConnectionFactory.createSoftConnection(OracleConnectionFactory.java:60)
    at com.netapp.oracle.database.OracleInstance.getOpenConnection(OracleInstance.java:122)
    at com.netapp.oracle.database.OracleInstance.getJDBCTemplate(OracleInstance.java:114)
    at com.netapp.oracle.database.LocalOracleDatabaseInstance.doQueryState(LocalOracleDatabaseInstance.java:59)
    at com.netapp.oracle.database.LocalOracleDatabaseInstance.queryState(LocalOracleDatabaseInstance.java:51)
    at com.netapp.oracle.database.LocalOracleDatabaseInstance.getDatabaseName(LocalOracleDatabaseInstance.java:134)
    at com.netapp.oracle.database.recovery.DatabaseRecoverer.recover(DatabaseRecoverer.java:69)
    at com.netapp.dlm.services.vdi.DatabaseCloneWorkUnit.recoverDatabaseUsingClonedArchiveLogs(DatabaseCloneWorkUnit.java:567)
    at com.netapp.dlm.services.vdi.DatabaseCloneWorkUnit.processEnd(DatabaseCloneWorkUnit.java:409)
    at com.netapp.dlm.services.common.WorkUnit.end(WorkUnit.java:195)
    at com.netapp.dlm.services.vdi.DatabaseSession.cloneDatabase(DatabaseSession.java:834)
    at com.netapp.dlm.process.operation.CloneOperation.doExecute(CloneOperation.java:398)
    at com.netapp.dlm.process.common.OpCycleOperation.execute(OpCycleOperation.java:143)
    at com.netapp.dlm.server.RemoteOperationImpl.execute(RemoteOperationImpl.java:62)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
    at java.lang.reflect.Method.invoke(Unknown Source)
    at sun.rmi.server.UnicastServerRef.dispatch(Unknown Source)
    at sun.rmi.transport.Transport$1.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.rmi.transport.Transport.serviceCall(Unknown Source)
    at sun.rmi.transport.tcp.TCPTransport.handleMessages(Unknown Source)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)
Caused by: java.rmi.ServerError: Error occurred in server thread; nested exception is:
    java.lang.UnsatisfiedLinkError: /home/oracle/OraHome1/lib/libocijdbc9.so: /home/oracle/OraHome1/lib/libocijdbc9.so: cannot open shared object file: No such file or directory
    at sun.rmi.server.UnicastServerRef.dispatch(Unknown Source)
    at sun.rmi.transport.Transport$1.run(Unknown Source)
    at java.security.AccessController.doPrivileged(Native Method)
    at sun.rmi.transport.Transport.serviceCall(Unknown Source)
    at sun.rmi.transport.tcp.TCPTransport.handleMessages(Unknown Source)
    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(Unknown Source)
    at java.lang.Thread.run(Unknown Source)
    at sun.rmi.transport.StreamRemoteCall.exceptionReceivedFromServer(Unknown Source)
    at sun.rmi.transport.StreamRemoteCall.executeCall(Unknown Source)
    at sun.rmi.server.UnicastRef.invoke(Unknown Source)
    at java.rmi.server.RemoteObjectInvocationHandler.invokeRemoteMethod(Unknown Source)
    at java.rmi.server.RemoteObjectInvocationHandler.invoke(Unknown Source)
    at com.netapp.oracle.jdbc.$Proxy64.createRemoteConnection(Unknown Source)
    at com.netapp.oracle.jdbc.OracleConnectionFactory.createOCIJDBCConnectionInNewJvm(OracleConnectionFactory.java:92)
    ... 26 more
Caused by: java.lang.UnsatisfiedLinkError: /home/oracle/OraHome1/lib/libocijdbc9.so: /home/oracle/OraHome1/lib/libocijdbc9.so: cannot open shared object file: No such file or directory
    at java.lang.ClassLoader$NativeLibrary.load(Native Method)
    at java.lang.ClassLoader.loadLibrary0(Unknown Source)
    at java.lang.ClassLoader.loadLibrary(Unknown Source)
    at java.lang.Runtime.loadLibrary0(Unknown Source)
    at java.lang.System.loadLibrary(Unknown Source)
    at oracle.jdbc.oci8.OCIDBAccess.logon(OCIDBAccess.java:267)
    at oracle.jdbc.driver.OracleConnection.<init>(OracleConnection.java:371)
    at oracle.jdbc.driver.OracleDriver.getConnectionInstance(OracleDriver.java:551)
    at oracle.jdbc.driver.OracleDriver.connect(OracleDriver.java:351)
    at com.netapp.oracle.jdbc.OCIJDBCDescriptor.createConnection(OCIJDBCDescriptor.java:77)
    at com.netapp.oracle.jdbc.RemoteConnectionFactoryImpl.createRemoteConnection(RemoteConnectionFactoryImpl.java:31)
    ... 11 more
2010-07-26 09:23:28,486 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07316: Shutting down database "clonesid".
2010-07-26 09:23:28,494 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: ORACLE-00000: Executing SQL command:
SHUTDOWN ABORT
2010-07-26 09:23:28,496 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: EXE-00000: Executing shell command:
0:su oracle -p -c "sqlplus" "-S" "/NOLOG"
1:sqlplus -S /NOLOG
2:[SHUTDOWN ABORT]
2010-07-26 09:23:28,618 [Execution Monitor Thread [[SHUTDOWN ABORT]]] [DEBUG]: EXE-00001: Shell result [0:00:00.122] (Exit Value: 0):
Connected.
ORACLE instance shut down.
2010-07-26 09:23:28,620 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07317: Deleting file "/home/oracle/OraHome1/dbs/initclonesid.ora".
2010-07-26 09:23:28,628 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07317: Deleting file "/home/oracle/admin/clonesid/udump".
2010-07-26 09:23:28,637 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07317: Deleting file "/home/oracle/admin/clonesid/bdump".
2010-07-26 09:23:28,648 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07317: Deleting file "/home/oracle/admin/clonesid/cdump".
2010-07-26 09:23:28,657 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07317: Deleting file "/home/oracle/OraHome1/dbs/orapwclonesid".
2010-07-26 09:23:28,667 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07317: Deleting file "/home/oracle_CLONESID/control01.ctl".
2010-07-26 09:23:28,690 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-04038: Deleting now empty directory "/home/oracle/admin/clonesid"
2010-07-26 09:23:28,752 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: ORACLE-00503: Removing entry for database clonesid from /etc/oratab.
2010-07-26 09:23:29,199 [default0 5dd1109d50adc20f288a3dbbc8b52bfd] [INFO ]: SD-00031: Beginning to disconnect filesystem(s) [/opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0].
2010-07-26 09:23:29,206 [default0 5dd1109d50adc20f288a3dbbc8b52bfd] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "snap" "disconnect" "-fs" "/opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0"
1:/usr/sbin/snapdrive snap disconnect -fs /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0
2010-07-26 09:23:32,609 [Execution Monitor Thread [/usr/sbin/snapdrive snap disconnect -fs /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0]] [DEBUG]: EXE-00001: Shell result [0:00:03.402] (Exit Value: 0):

delete file system /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0
- fs /opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0 ... deleted
destroying snapdrive-generated flexclone netapp:/vol/SnapManager_20100726092312898_vol1 ... done

2010-07-26 09:23:32,610 [default0 5dd1109d50adc20f288a3dbbc8b52bfd] [INFO ]: SD-00032: Finished disconnecting filesystem(s) [/opt/NetApp/smo/mnt/-home-oracle-20100726092312879_0].
2010-07-26 09:23:32,674 [default0 e21a6767577feee4ddf2ec35e9f3e680] [INFO ]: SD-00031: Beginning to disconnect filesystem(s) [/home/oracle_CLONESID].
2010-07-26 09:23:32,729 [default0 e21a6767577feee4ddf2ec35e9f3e680] [DEBUG]: EXE-00000: Executing shell command:
0:/bin/sh -c "/usr/sbin/snapdrive" "snap" "disconnect" "-fs" "/home/oracle_CLONESID"
1:/usr/sbin/snapdrive snap disconnect -fs /home/oracle_CLONESID
2010-07-26 09:23:35,283 [Execution Monitor Thread [/usr/sbin/snapdrive snap disconnect -fs /home/oracle_CLONESID]] [DEBUG]: EXE-00001: Shell result [0:00:02.554] (Exit Value: 0):

delete file system /home/oracle_CLONESID
- fs /home/oracle_CLONESID ... deleted
destroying snapdrive-generated flexclone netapp:/vol/SnapManager_2010072609230365_vol1 ... done

2010-07-26 09:23:35,284 [default0 e21a6767577feee4ddf2ec35e9f3e680] [INFO ]: SD-00032: Finished disconnecting filesystem(s) [/home/oracle_CLONESID].
2010-07-26 09:23:35,295 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-07131: Unlocked database for SnapManager operations - removed lock file "/home/oracle/OraHome1/dbs/.sm_lock_clonesid" on host croix.se.houston.geoquest.slb.com.
2010-07-26 09:23:35,300 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-13039: Successfully aborted operation: Clone Create
2010-07-26 09:23:35,318 [RMI TCP Connection(1)-163.185.9.31] [ERROR]: SMO-13048: Clone Create Operation Status: FAILED
2010-07-26 09:23:35,328 [Thread-2] [DEBUG]: Heartbeat thread interrupted
2010-07-26 09:23:35,328 [Thread-2] [DEBUG]: Heartbeat thread finished
2010-07-26 09:23:35,329 [RMI TCP Connection(1)-163.185.9.31] [INFO ]: SMO-13049: Elapsed Time: 0:00:46.100
2010-07-26 09:23:35,363 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Operation ENDED
2010-07-26 09:23:35,366 [RMI TCP Connection(1)-163.185.9.31] [DEBUG]: Destroying all spawned RemoteObjectFactories