[2015-11-02 13:00:09,680] DEBUG: Workflow : mount started with workflow id : 927
[2015-11-02 13:00:09,680] DEBUG: Version: Snap Creator Framework 4.1.2
[2015-11-02 13:00:09,680] DEBUG: Profile: SCCASE
[2015-11-02 13:00:09,680] DEBUG: Config: ORA_mount_start
[2015-11-02 13:00:09,680] DEBUG: Action: mount
[2015-11-02 13:00:09,680] DEBUG: Plugin: null
[2015-11-02 13:00:09,680] DEBUG: Policy: null
[2015-11-02 13:00:09,680] DEBUG: Volume Name: OVM_DB7_Data,OVM_DB7_Fra
[2015-11-02 13:00:09,680] DEBUG: Snapshot Name: SC_hotORA_recent
########## Agent validation ##########
[2015-11-02 13:00:09,811] INFO: Application commands and plug-in not defined. Skipping Agent validation task
########## Plugin validation ##########
[2015-11-02 13:00:09,814] INFO: Application not defined. Skipping Plugin validation task
########## Pre Clone Create commands ##########
[2015-11-02 13:00:09,833] INFO: Pre Clone Create commands are not defined
[2015-11-02 13:00:09,833] INFO: Pre Clone Create commands finished successfully
########## Performing cloning on controller 192.168.8.176 ##########
[2015-11-02 13:00:09,867] INFO: Creating Volume Clone from Snapshot copy SC_hotORA-daily_recent of 192.168.8.176:OVM_DB7_Data
[2015-11-02 13:00:16,160] INFO: STORAGE-02036: Creating clone [cl_ORA_mount_start_OVM_DB7_Data_20151102130009] of volume [OVM_DB7_Data] based on Snapshot copy [SC_hotORA-daily_recent]
[2015-11-02 13:00:16,160] DEBUG:
OVM_DB7_Data
SC_hotORA-daily_recent
cl_ORA_mount_start_OVM_DB7_Data_20151102130009
none
/cl_ORA_mount_start_OVM_DB7_Data_20151102130009
true
[2015-11-02 13:00:16,160] INFO: STORAGE-02037: Creating clone [cl_ORA_mount_start_OVM_DB7_Data_20151102130009] of volume [OVM_DB7_Data] based on Snapshot copy [SC_hotORA-daily_recent] finished successfully.
[2015-11-02 13:00:16,160] INFO: Creating Volume Clone from Snapshot copy SC_hotORA-daily_recent of 192.168.8.176:OVM_DB7_Fra
[2015-11-02 13:00:18,808] INFO: STORAGE-02036: Creating clone [cl_ORA_mount_start_OVM_DB7_Fra_20151102130009] of volume [OVM_DB7_Fra] based on Snapshot copy [SC_hotORA-daily_recent]
[2015-11-02 13:00:18,808] DEBUG:
OVM_DB7_Fra
SC_hotORA-daily_recent
cl_ORA_mount_start_OVM_DB7_Fra_20151102130009
none
/cl_ORA_mount_start_OVM_DB7_Fra_20151102130009
true
[2015-11-02 13:00:18,808] INFO: STORAGE-02037: Creating clone [cl_ORA_mount_start_OVM_DB7_Fra_20151102130009] of volume [OVM_DB7_Fra] based on Snapshot copy [SC_hotORA-daily_recent] finished successfully.
[2015-11-02 13:00:18,808] INFO: Skipping igroup mapping for filer192.168.8.176, the NTAP_CLONE_IGROUP_MAP parameter in config is empty
########## PRE MOUNT COMMANDS ##########
[2015-11-02 13:00:51,889] INFO: SCF-00203: Executing [Pre mount] command [/SC41/OSAP_cDOT/sc_clone_rename.py config/OVM_DB7.luns ORA_mount_start 20151102130009 "^DATA|^FRA"] on server
[2015-11-02 13:00:51,889] INFO: stdout:### Snap Creator Clone Rename - start timestamp: 2015-11-02 13:00:18.915408 ###
Renaming volume cl_ORA_mount_start_OVM_DB7_Data_20151102130009 to OVM_DB7_Data_clone on 192.168.8.222 .... renamed
Renaming LUN /vol/OVM_DB7_Data_clone/ovm_db7_data1.lun to /vol/OVM_DB7_Data_clone/ovm_db7_data1_clone.lun .... renamed
Renaming LUN /vol/OVM_DB7_Data_clone/ovm_db7_data2.lun to /vol/OVM_DB7_Data_clone/ovm_db7_data2_clone.lun .... renamed
Renaming volume cl_ORA_mount_start_OVM_DB7_Fra_20151102130009 to OVM_DB7_Fra_clone on 192.168.8.222 .... renamed
Renaming LUN /vol/OVM_DB7_Fra_clone/ovm_db7_fra1.lun to /vol/OVM_DB7_Fra_clone/ovm_db7_fra1_clone.lun .... renamed
Renaming LUN /vol/OVM_DB7_Fra_clone/ovm_db7_fra2.lun to /vol/OVM_DB7_Fra_clone/ovm_db7_fra2_clone.lun .... renamed
2 clones volumes and 4 cloned LUNs have been renamed.
### Snap Creator Clone Rename - finish timestamp: 2015-11-02 13:00:44.580398 ###
[2015-11-02 13:00:51,889] DEBUG: Pre mount: /SC41/OSAP_cDOT/sc_clone_rename.py config/OVM_DB7.luns ORA_mount_start 20151102130009 "^DATA|^FRA" finished with
exit code: 0
[2015-11-02 13:00:51,889] INFO: SCF-00203: Executing [Pre mount] command [/SC41/OSAP_cDOT/sc_clone_setlunserial.py config/OVM_DB7.luns "^DATA|^FRA"] on server
[2015-11-02 13:00:51,889] INFO: stdout:### Snap Creator Clone LUN Set Serial - start timestamp: 2015-11-02 13:00:44.642541 ###
Setting LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data1_clone.lun to offline ... LUN is now offline
Changing LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data1_clone.lun serial number from Pgg8b$Gjg4z4 to Pgg8b$Gjg4wc ... done!
Setting LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data1_clone.lun to online ... LUN is now online
Setting LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data2_clone.lun to offline ... LUN is now offline
Changing LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data2_clone.lun serial number from Pgg8b$Gjg4z5 to Pgg8b$Gjg4wd ... done!
Setting LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data2_clone.lun to online ... LUN is now online
Setting LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra1_clone.lun to offline ... LUN is now offline
Changing LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra1_clone.lun serial number from Pgg8b$Gjg4z6 to Pgg8b$Gjg4wi ... done!
Setting LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra1_clone.lun to online ... LUN is now online
Setting LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra2_clone.lun to offline ... LUN is now offline
Changing LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra2_clone.lun serial number from Pgg8b$Gjg4z7 to Pgg8b$Gjg4wj ... done!
Setting LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra2_clone.lun to online ... LUN is now online
4 cloned LUNs serial numbers have been changed
### Snap Creator Clone LUN Set Serial - finish timestamp: 2015-11-02 13:00:51.879961 ###
[2015-11-02 13:00:51,889] DEBUG: Pre mount: /SC41/OSAP_cDOT/sc_clone_setlunserial.py config/OVM_DB7.luns "^DATA|^FRA" finished with
exit code: 0
[2015-11-02 13:00:51,889] INFO: Pre mount completed successfully
[2015-11-02 13:00:51,889] INFO: Pre Mount commands finished successfully
########## MOUNT COMMANDS ##########
[2015-11-02 13:00:53,917] INFO: SCF-00203: Executing [Mount] command [/SC41/OSAP_cDOT/sc_clone_lunmap.py config/OVM_DB7.luns "^DATA|^FRA"] on server
[2015-11-02 13:00:53,917] INFO: stdout:### Snap Creator Clone LUN mapping - start timestamp: 2015-11-02 13:00:51.977084 ###
Mapping LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data1_clone.lun to IGRP OVM_access_group as ID 21 ... mapped
Mapping LUN 192.168.8.222:/vol/OVM_DB7_Data_clone/ovm_db7_data2_clone.lun to IGRP OVM_access_group as ID 22 ... mapped
Mapping LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra1_clone.lun to IGRP OVM_access_group as ID 23 ... mapped
Mapping LUN 192.168.8.222:/vol/OVM_DB7_Fra_clone/ovm_db7_fra2_clone.lun to IGRP OVM_access_group as ID 24 ... mapped
4 LUNs have been mapped.
### Snap Creator Clone LUN mapping - finish timestamp: 2015-11-02 13:00:53.908799 ###
[2015-11-02 13:00:53,917] DEBUG: Mount: /SC41/OSAP_cDOT/sc_clone_lunmap.py config/OVM_DB7.luns "^DATA|^FRA" finished with
exit code: 0
[2015-11-02 13:00:53,918] INFO: Mount completed successfully
########## MOUNT COMMANDS FINISHED SUCCESSFULLY ##########
########## POST MOUNT COMMANDS ##########
[2015-11-02 13:03:45,000] INFO: [192.168.8.103:9090 (4.1.1.1)] Executing Post mount command [/opt/NetApp/OSAP/sc_oradb_recovery_log.sh mount wait 3] on 192.168.8.103
[2015-11-02 13:03:45,000] TRACE: Command [/opt/NetApp/OSAP/sc_oradb_recovery_log.sh mount wait 3] finished with
exit code: [0]
stdout: [Start!
Time stamp: 2015-11-02 13:00:57
Mounting ASM disk groups +DB1DATA and +DB1FRA
Mount +DB1DATA ... OK
Time stamp: 2015-11-02 13:01:04
Mount +DB1FRA ... OK
Time stamp: 2015-11-02 13:01:04]
stderr: []
[2015-11-02 13:03:45,000] DEBUG: [192.168.8.103:9090 (4.1.1.1)] Command [/opt/NetApp/OSAP/sc_oradb_recovery_log.sh mount wait 3] finished successfully with message [Start!
Time stamp: 2015-11-02 13:00:57
Mounting ASM disk groups +DB1DATA and +DB1FRA
Mount +DB1DATA ... OK
Time stamp: 2015-11-02 13:01:04
Mount +DB1FRA ... OK
Time stamp: 2015-11-02 13:01:04]
[2015-11-02 13:03:45,000] INFO: [192.168.8.103:9090 (4.1.1.1)] Executing Post mount command [/opt/NetApp/OSAP/sc_oradb_recovery_log.sh recover ] on 192.168.8.103
[2015-11-02 13:03:45,000] TRACE: Command [/opt/NetApp/OSAP/sc_oradb_recovery_log.sh recover ] finished with
exit code: [-1]
stdout: [Failed to execute command: /opt/NetApp/OSAP/sc_oradb_recovery_log.sh recover
Reason: null]
stderr: []
[2015-11-02 13:03:45,001] ERROR: [192.168.8.103:9090 (4.1.1.1)] Command [/opt/NetApp/OSAP/sc_oradb_recovery_log.sh recover ] failed with return code [-1] and stderr [] and stdout [Failed to execute command: /opt/NetApp/OSAP/sc_oradb_recovery_log.sh recover
Reason: null]
[2015-11-02 13:03:45,003] DEBUG: Workflow : mount_OnFailure started with workflow id : 928
########## Agent Workflow Finalization ##########
[2015-11-02 13:03:45,004] INFO: Agent Workflow Finalization started
[2015-11-02 13:03:50,196] INFO: [192.168.8.103:9090 (4.1.1.1)] Finalized workflow with id 927
[2015-11-02 13:03:50,196] INFO: Agent Workflow Finalization finished successfully
########## Snap Creator Framework 4.1.2 failed ##########
[2015-11-02 13:03:50,207] INFO: Pre Exit commands are not defined. Skipping !