search

oravirt / ansible-oracle

Oracle related stuff. Installs RAC/RAC One Node/Single Instance
MIT License
341 stars 249 forks source link

create controlfile failed #107

Closed daverod24 closed 5 years ago

daverod24 commented 5 years ago

Hello

  I have this issue when I run the ansible playbook I get this error at the end I am installing oracle 12c 12.1.0.2 the binaries are: linuxamd64_12102_database_1of2.zip, linuxamd64_12102_database_2of2.zip

here I put the logs because I'm not creating the controlfile of the redo

I hope you can help me, it would be excellent to document a little more that should be changed to make a cleaner installation with the ansible.

thanks in advance, best regards

##ansible log verbose -vvvv
 fatal: [db-fs-1]: FAILED! => {
       "changed": true,
       "cmd": "time /u01/app/oracle/12.1.0.2/db1-base/bin/dbca -createDatabase -responseFile 
/u01/stage/rsp/dbca_orcl.rsp -silent  -initParams db_name=orcl,db_create_file_dest=/u02/oradata,db_create_online_log_dest_1=/u02/fra",
       "delta": "0:02:31.089884",
       "end": "2018-10-05 23:57:55.614014",
       "invocation": {
           "module_args": {
               "_raw_params": "time /u01/app/oracle/12.1.0.2/db1-base/bin/dbca -createDatabase -responseFile /u01/stage/rsp/dbca_orcl.rsp -silent  -initParams db_name=orcl,db_create_file_dest=/u02/oradata,db_create_online_log_dest_1=/u02/fra",
               "_uses_shell": true,
               "argv": null,
               "chdir": null,
               "creates": null,
               "executable": null,
               "removes": null,
               "stdin": null,
               "warn": true
           }
       },
       "msg": "non-zero return code",
       "rc": 1,
       "start": "2018-10-05 23:55:24.524130",
       "stderr": "\nreal\t2m31.042s\nuser\t0m2.716s\nsys\t0m0.887s",
       "stderr_lines": [
           "",
           "real\t2m31.042s",
           "user\t0m2.716s",
           "sys\t0m0.887s"
       ],
       "stdout": "Cleaning up failed steps\n5% complete\nCopying database files\n7% complete\n9% complete\n16% complete\n23% complete\n30% complete\n41% complete\nCreating and starting Oracle instance\nDBCA Operation failed.\nLook at the log file \"/u01/app/oracle/cfgtoollogs/dbca/orcl/orcl1.log\" for further details.",
       "stdout_lines": [
           "Cleaning up failed steps",
           "5% complete",
           "Copying database files",
           "7% complete",
           "9% complete",
           "16% complete",
           "23% complete",
           "30% complete",
           "41% complete",
           "Creating and starting Oracle instance",
           "DBCA Operation failed.",
           "Look at the log file \"/u01/app/oracle/cfgtoollogs/dbca/orcl/orcl1.log\" for further details."
       ]
   }
           to retry, use: --limit @/home/david/Documentos/indevsecops-ibk/ubuntutest/testing/vagrant2/vagrant-vbox-si-fs/extra-provision/ansible-oracle/vbox-si-fs-install.retry

   PLAY RECAP **************************************************************************************************************************************************************************
   db-fs-1                    : ok=60   changed=2    unreachable=0    failed=1
tail: /u01/app/oracle/cfgtoollogs/dbca/orcl/trace.log: file truncated
[main] [ 2018-10-05 23:56:04.141 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[main] [ 2018-10-05 23:56:04.141 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[main] [ 2018-10-05 23:56:04.141 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[main] [ 2018-10-05 23:56:04.141 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[main] [ 2018-10-05 23:56:04.141 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[main] [ 2018-10-05 23:56:04.141 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[main] [ 2018-10-05 23:56:04.141 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:56:04.141 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:56:04.142 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[main] [ 2018-10-05 23:56:04.144 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[main] [ 2018-10-05 23:56:04.144 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[main] [ 2018-10-05 23:56:04.144 CEST ] [Host.getAuditNextGen:9054]  NextGen Audit /u01/app/oracle/audit
[main] [ 2018-10-05 23:56:04.144 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[main] [ 2018-10-05 23:56:04.144 CEST ] [Host.getFolders:10740]  adding path for DB_RECOVERY_FILE_DETS/u02/fra
[main] [ 2018-10-05 23:56:04.145 CEST ] [Host.getFolders:10750]  RedoLogDestName db_create_online_log_dest_1
[main] [ 2018-10-05 23:56:04.145 CEST ] [Host.getFolders:10750]  RedoLogDestName db_create_online_log_dest_2
[main] [ 2018-10-05 23:56:04.145 CEST ] [Host.getFolders:10750]  RedoLogDestName db_create_online_log_dest_3
[main] [ 2018-10-05 23:56:04.145 CEST ] [Host.getFolders:10750]  RedoLogDestName db_create_online_log_dest_4
[main] [ 2018-10-05 23:56:04.145 CEST ] [Host.getFolders:10750]  RedoLogDestName db_create_online_log_dest_5
[main] [ 2018-10-05 23:56:04.145 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle/12.1.0.2/db1-base
[main] [ 2018-10-05 23:56:04.145 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[main] [ 2018-10-05 23:56:04.145 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle/12.1.0.2/db1-base
[main] [ 2018-10-05 23:56:04.145 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[main] [ 2018-10-05 23:56:04.145 CEST ] [Host.getFolders:10786]  adding path for /u01/app/oracle/12.1.0.2/db1-base/dbs
[main] [ 2018-10-05 23:56:04.146 CEST ] [Host.getFolders:10808]  adding path for /u02/oradata
[main] [ 2018-10-05 23:56:04.147 CEST ] [Host.setUpForOperation:4253]  Folder[0]=/u01/app/oracle
[main] [ 2018-10-05 23:56:04.147 CEST ] [Host.setUpForOperation:4253]  Folder[1]=/u01/app/oracle/12.1.0.2/db1-base/dbs
[main] [ 2018-10-05 23:56:04.147 CEST ] [Host.setUpForOperation:4253]  Folder[2]=/u01/app/oracle/admin/orcl/adump
[main] [ 2018-10-05 23:56:04.154 CEST ] [Host.setUpForOperation:4253]  Folder[3]=/u01/app/oracle/admin/orcl/dpdump
[main] [ 2018-10-05 23:56:04.155 CEST ] [Host.setUpForOperation:4253]  Folder[4]=/u01/app/oracle/admin/orcl/pfile
[main] [ 2018-10-05 23:56:04.155 CEST ] [Host.setUpForOperation:4253]  Folder[5]=/u01/app/oracle/audit
[main] [ 2018-10-05 23:56:04.155 CEST ] [Host.setUpForOperation:4253]  Folder[6]=/u01/app/oracle/cfgtoollogs/dbca/orcl
[main] [ 2018-10-05 23:56:04.155 CEST ] [Host.setUpForOperation:4253]  Folder[7]=/u02/fra
[main] [ 2018-10-05 23:56:04.155 CEST ] [Host.setUpForOperation:4253]  Folder[8]=/u02/oradata
[main] [ 2018-10-05 23:56:04.155 CEST ] [Host.executeSteps:6091]  setupForOperation returned: true
[main] [ 2018-10-05 23:56:04.156 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:56:04.156 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:56:04.156 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[main] [ 2018-10-05 23:56:04.163 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[main] [ 2018-10-05 23:56:04.164 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[main] [ 2018-10-05 23:56:04.164 CEST ] [Host.createStepSQLInterface:8605]  sid =orcl
[main] [ 2018-10-05 23:56:04.164 CEST ] [Host.createStepSQLInterface:8606]  sidOrConnectString orcl
[main] [ 2018-10-05 23:56:04.164 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: null
[main] [ 2018-10-05 23:56:04.165 CEST ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[main] [ 2018-10-05 23:56:04.165 CEST ] [OracleHome.getVersion:1010]  Homeinfo /u01/app/oracle/12.1.0.2/db1-base,1
[main] [ 2018-10-05 23:56:04.273 CEST ] [OracleHome.getVersion:1038]  OracleHome.server.getVersion Version: 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.273 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.274 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.274 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.274 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.274 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.274 CEST ] [SQLPlusEngine.getCmmdParams:225]  m_home 12.1.0.2.0
[main] [ 2018-10-05 23:56:04.274 CEST ] [SQLPlusEngine.getCmmdParams:226]  version > 112 true
[main] [ 2018-10-05 23:56:04.274 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:56:04.274 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:56:04.274 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[main] [ 2018-10-05 23:56:04.278 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[main] [ 2018-10-05 23:56:04.278 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[main] [ 2018-10-05 23:56:04.279 CEST ] [SQLEngine.getEnvParams:602]  Default NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[main] [ 2018-10-05 23:56:04.279 CEST ] [SQLEngine.getEnvParams:612]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[main] [ 2018-10-05 23:56:04.279 CEST ] [SQLEngine.initialize:358]  Execing SQLPLUS/SVRMGR process...
[main] [ 2018-10-05 23:56:04.285 CEST ] [SQLEngine.initialize:395]  m_bReaderStarted: false
[main] [ 2018-10-05 23:56:04.286 CEST ] [SQLEngine.initialize:399]  Starting Reader Thread... 
[Thread-48] [ 2018-10-05 23:56:04.288 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.288 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.289 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:04.294 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.294 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.296 CEST ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[Thread-48] [ 2018-10-05 23:56:04.297 CEST ] [InventoryUtil.getHomeName:113]  homeName = OraDB12Home1
[Thread-48] [ 2018-10-05 23:56:04.298 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.298 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.298 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:04.300 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.300 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.301 CEST ] [StepManager.getSteps:275]  logging folder set: /u01/app/oracle/cfgtoollogs/dbca/orcl
[Thread-48] [ 2018-10-05 23:56:04.301 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.301 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.301 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:04.303 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.303 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.304 CEST ] [StepManager.getSteps:295]  ckFileName /u01/app/oracle/cfgtoollogs/dbca/orcl/OraDB12Home1_orcl_creation_checkpoint.xml ckContext oracle.sysman.assistants.util.CheckpointContext@32b95f72
[Thread-48] [ 2018-10-05 23:56:04.322 CEST ] [CheckpointContext.isCleanupNeeded:140]   failedChkFiles {/u01/app/oracle/cfgtoollogs/dbca/orcl/OraDB12Home1_orcl_creation_checkpoint.xml=null}
[Thread-48] [ 2018-10-05 23:56:04.322 CEST ] [CheckpointContext.isCleanupNeeded:149]  Failed check files iterator java.util.HashMap$KeyIterator@629ca1fb
[Thread-48] [ 2018-10-05 23:56:04.322 CEST ] [CheckpointContext.isCleanupNeeded:155]  failed chjeckpoint file /u01/app/oracle/cfgtoollogs/dbca/orcl/OraDB12Home1_orcl_creation_checkpoint.xml
[Thread-48] [ 2018-10-05 23:56:04.322 CEST ] [CheckpointContext.isCleanupNeeded:160]  getting all check point list
[Thread-48] [ 2018-10-05 23:56:04.323 CEST ] [CheckpointContext.getAllCheckPoints:224]  getting all check point list
[Thread-48] [ 2018-10-05 23:56:04.323 CEST ] [CheckpointContext.getAllCheckPoints:226]  returning all check point list
[Thread-48] [ 2018-10-05 23:56:04.323 CEST ] [CheckpointContext.isCleanupNeeded:163]   all check point list size 1
[Thread-48] [ 2018-10-05 23:56:04.323 CEST ] [CheckpointContext.isCleanupNeeded:189]  adding cleanup step since it is a retry operation.
[Thread-48] [ 2018-10-05 23:56:04.323 CEST ] [CheckpointContext.isCleanupNeeded:196]  old checkpoint file deleted: true
[Thread-48] [ 2018-10-05 23:56:04.324 CEST ] [CheckpointContext.retrieveCheckPoint:338]  check point db_orcl retrieved from file oracle.sysman.oic.oics.OicsCheckPoint@6ce931d9
[Thread-48] [ 2018-10-05 23:56:04.324 CEST ] [StepManager.getSteps:326]  checkpoint from file oracle.sysman.oic.oics.OicsCheckPoint@6ce931d9
[Thread-48] [ 2018-10-05 23:56:04.324 CEST ] [StepManager.getSteps:332]  adding checkpoint to session
[Thread-48] [ 2018-10-05 23:56:04.324 CEST ] [StepManager.getSteps:334]  saved new checkpoint session for DB creation
[Thread-48] [ 2018-10-05 23:56:04.324 CEST ] [StepManager.getSteps:430]  StepManager isHARegistrationRequired : false
[Thread-48] [ 2018-10-05 23:56:04.333 CEST ] [StepContext$ModeRunner.run:2873]  ---- Progress Needed:=true
[Thread-48] [ 2018-10-05 23:56:04.333 CEST ] [BasicStep.execute:250]  Executing Step : CLEANUP
[Thread-48] [ 2018-10-05 23:56:04.334 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=null
[Thread-48] [ 2018-10-05 23:56:04.334 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.334 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.334 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:04.337 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.338 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.339 CEST ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[Thread-48] [ 2018-10-05 23:56:04.339 CEST ] [InventoryUtil.getHomeName:113]  homeName = OraDB12Home1
[Thread-48] [ 2018-10-05 23:56:04.339 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=oracle.sysman.assistants.util.SilentMessageHandler@4f2d26d2
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [StepContext$ModeRunner.run:2873]  ---- Progress Needed:=true
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [BasicStep.execute:250]  Executing Step : CLONE_DB_CREATION_RMAN_RESTORE
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-01092
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-01034
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-03114
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-12560
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-01109
[Thread-48] [ 2018-10-05 23:56:04.340 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=null
[Thread-48] [ 2018-10-05 23:56:04.342 CEST ] [Host.getRMANConnectionInfo:1171]  Connect to Instance orcl
[Thread-48] [ 2018-10-05 23:56:04.346 CEST ] [BasicStep.execute:250]  Executing Step : INSTANCE_CREATION
[Thread-48] [ 2018-10-05 23:56:04.346 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=null
[Thread-48] [ 2018-10-05 23:56:04.348 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.348 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:04.349 CEST ] [InitParamAttributes.sortParams:3916]  m_sortOn:-1 sortOn:4
[Thread-48] [ 2018-10-05 23:56:04.360 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_block_size
[Thread-48] [ 2018-10-05 23:56:04.360 CEST ] [InitParamAttributes.createInitFile:1816]  The value is 8192
[Thread-48] [ 2018-10-05 23:56:04.360 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param open_cursors
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1816]  The value is 300
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_domain
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1816]  The value is ""
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_name
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1816]  The value is "orcl"
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param control_files
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1816]  The value is ("/u02/oradata/orcl/control01.ctl", "/u02/fra/orcl/control02.ctl")
[Thread-48] [ 2018-10-05 23:56:04.361 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_create_file_dest
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1816]  The value is "/u02/oradata"
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_create_online_log_dest_1
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1816]  The value is /u02/fra
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_recovery_file_dest
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1816]  The value is "/u02/fra"
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param db_recovery_file_dest_size
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1816]  The value is 4560m
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param compatible
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1816]  The value is 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param diagnostic_dest
[Thread-48] [ 2018-10-05 23:56:04.362 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1816]  The value is /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param memory_target
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1816]  The value is 1024m
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param processes
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1816]  The value is 300
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param audit_file_dest
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1816]  The value is "/u01/app/oracle/admin/orcl/adump"
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param audit_trail
[Thread-48] [ 2018-10-05 23:56:04.363 CEST ] [InitParamAttributes.createInitFile:1816]  The value is db
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param remote_login_passwordfile
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [InitParamAttributes.createInitFile:1816]  The value is EXCLUSIVE
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param dispatchers
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [InitParamAttributes.createInitFile:1816]  The value is "(PROTOCOL=TCP) (SERVICE=orclXDB)"
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [InitParamAttributes.createInitFile:1811]  Processing init param undo_tablespace
[Thread-48] [ 2018-10-05 23:56:04.364 CEST ] [InitParamAttributes.createInitFile:1816]  The value is UNDOTBS1
[Thread-48] [ 2018-10-05 23:56:04.365 CEST ] [HADatabaseUtils.isGridMgmtDB:2842]  Mgmt DBName from srvm _mgmtdb
[Thread-48] [ 2018-10-05 23:56:04.366 CEST ] [InstanceStep.executeImpl:280]  Checking Register with HA Listener
[Thread-48] [ 2018-10-05 23:56:04.366 CEST ] [Host.noEntryinOratab:7194]  Check made for oratab arg passed............
[Thread-48] [ 2018-10-05 23:56:04.366 CEST ] [Oratab.getTempFile:805]  Temp oratab: /tmp/oratab
[Thread-48] [ 2018-10-05 23:56:04.368 CEST ] [InstanceStep.executeImpl:331]  Password file location prior to parsing /u01/app/oracle/12.1.0.2/db1-base/dbs/orapworcl
[Thread-48] [ 2018-10-05 23:56:04.368 CEST ] [InstanceStep.executeImpl:333]  Password file location prior to parsing /u01/app/oracle/12.1.0.2/db1-base/dbs/orapworcl
[Thread-48] [ 2018-10-05 23:56:04.368 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.368 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.368 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.368 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.369 CEST ] [CommonUtils.createPasswordFile:1243]  calling new orapwd for 11.1 or higher
[Thread-48] [ 2018-10-05 23:56:04.369 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.369 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.369 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.369 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.369 CEST ] [CommonUtils.getPasswordFileCreateCmd:1182]  for new orapwd for 11.1 or higher
[Thread-48] [ 2018-10-05 23:56:04.370 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.370 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [CommonUtils.getPasswordFileCreateCmd:1213]  /u01/app/oracle/12.1.0.2/db1-base/bin/orapwd
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [CommonUtils.getPasswordFileCreateCmd:1213]  file=/u01/app/oracle/12.1.0.2/db1-base/dbs/orapworcl
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [CommonUtils.getPasswordFileCreateCmd:1213]  force=y
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [CommonUtils.getPasswordFileCreateCmd:1213]  format=12
[Thread-48] [ 2018-10-05 23:56:04.371 CEST ] [OsUtilsBase.execProg:2123]  beginning execProg with input array.
[Thread-48] [ 2018-10-05 23:56:04.385 CEST ] [OsUtilsBase.execProg:2160]  finished execProg with input array. Status:0
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [InstanceStep.setASMAdminGID:373]  isWindows: false Storage Type: 0
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=oracle.sysman.assistants.util.SilentMessageHandler@4f2d26d2
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [CloneRmanRestoreStep.executeImpl:270]  Instance Creation went fine..........
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [CloneRmanRestoreStep.executeImpl:277]  db_recovery_file_dest="/u02/fra"
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [CloneRmanRestoreStep.executeImpl:280]  db_recovery_file_dest_size=4560m
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [InitParameterFile.getLongValue:687]  May have unit. Stripping unit and trying with 4560
[Thread-48] [ 2018-10-05 23:56:04.386 CEST ] [CloneRmanRestoreStep.executeImpl:297]  Setting NLS_LANG to AMERICA.AL32UTF8
[Thread-48] [ 2018-10-05 23:56:04.387 CEST ] [SQLEngine.done:2278]  Done called
[Thread-48] [ 2018-10-05 23:56:04.388 CEST ] [SQLEngine.reInitialize:785]  Reinitializing SQLEngine...
[Thread-48] [ 2018-10-05 23:56:04.388 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.388 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [SQLPlusEngine.getCmmdParams:225]  m_home 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [SQLPlusEngine.getCmmdParams:226]  version > 112 true
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:04.389 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:04.392 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.392 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:04.392 CEST ] [SQLEngine.getEnvParams:612]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[Thread-48] [ 2018-10-05 23:56:04.392 CEST ] [SQLEngine.initialize:358]  Execing SQLPLUS/SVRMGR process...
[Thread-48] [ 2018-10-05 23:56:04.407 CEST ] [SQLEngine.initialize:395]  m_bReaderStarted: false
[Thread-48] [ 2018-10-05 23:56:04.408 CEST ] [SQLEngine.initialize:399]  Starting Reader Thread... 
[Thread-48] [ 2018-10-05 23:56:04.410 CEST ] [SQLEngine.initialize:448]  Waiting for m_bReaderStarted to be true 
[Thread-48] [ 2018-10-05 23:56:05.455 CEST ] [SQLEngine.setSpool:2056]  old Spool  = null
[Thread-48] [ 2018-10-05 23:56:05.456 CEST ] [SQLEngine.setSpool:2057]  Setting Spool  = /u01/app/oracle/cfgtoollogs/dbca/orcl/CloneRmanRestore.log
[Thread-48] [ 2018-10-05 23:56:05.457 CEST ] [SQLEngine.setSpool:2058]  Is spool appendable? --> true
[Thread-48] [ 2018-10-05 23:56:05.458 CEST ] [CloneRmanRestoreStep.executeImpl:323]  _diag_hm_rc_enabled to false
[Thread-48] [ 2018-10-05 23:56:05.458 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:05.459 CEST ] [CloneRmanRestoreStep.executeImpl:358]  Using control file: /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.ctl; sourceDBName: seeddata
[Thread-48] [ 2018-10-05 23:56:05.460 CEST ] [OsUtilsBase.copyFile:1505]  OsUtilsBase.copyFile: 
[Thread-48] [ 2018-10-05 23:56:05.523 CEST ] [OsUtilsBase.copyFile:1553]  **write of file at destination complete...
[Thread-48] [ 2018-10-05 23:56:05.526 CEST ] [OsUtilsBase.copyFile:1588]  **file copy status:= true
[Thread-48] [ 2018-10-05 23:56:05.527 CEST ] [CloneRmanRestoreStep.executeImpl:383]  set _enable_pluggable_database to true
[Thread-48] [ 2018-10-05 23:56:24.283 CEST ] [CloneRmanRestoreStep.executeImpl:399]  update db alert log File
[Thread-48] [ 2018-10-05 23:56:24.316 CEST ] [CloneRmanRestoreStep.executeImpl:402]  Clearing v$datafile_copy entries
[Thread-48] [ 2018-10-05 23:56:24.412 CEST ] [CloneRmanRestoreStep.executeImpl:404]  Clearing all backup entries
[Thread-48] [ 2018-10-05 23:56:24.473 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:24.672 CEST ] [CloneRmanRestoreStep.executeImpl:457]  Getting the map of data file ids and names for restore
[Thread-63] [ 2018-10-05 23:56:24.674 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: 32768
[Thread-63] [ 2018-10-05 23:56:24.676 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: -1
[Thread-48] [ 2018-10-05 23:56:24.682 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:24.685 CEST ] [CloneRmanRestoreStep.getDatafileIdNameMapping:586]  newname for datafile is  null for OMF mode
[Thread-48] [ 2018-10-05 23:56:24.686 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:24.686 CEST ] [CloneRmanRestoreStep.getDatafileIdNameMapping:586]  newname for datafile is  null for OMF mode
[Thread-48] [ 2018-10-05 23:56:24.687 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:24.688 CEST ] [CloneRmanRestoreStep.getDatafileIdNameMapping:586]  newname for datafile is  null for OMF mode
[Thread-48] [ 2018-10-05 23:56:24.691 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:56:24.692 CEST ] [CloneRmanRestoreStep.getDatafileIdNameMapping:586]  newname for datafile is  null for OMF mode
[Thread-48] [ 2018-10-05 23:56:24.776 CEST ] [RMANUtil.getRMANUtil:147]   creating new util instance
[Thread-48] [ 2018-10-05 23:56:24.776 CEST ] [RMANUtil.getRMANUtil:148]   target sid orcl
[Thread-48] [ 2018-10-05 23:56:24.776 CEST ] [CommonAttributes.replaceVariables:1402]  var2 /u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:24.800 CEST ] [RMANEngine.getCmmdParams:343]   using rman from  /u01/app/oracle/12.1.0.2/db1-base/bin/rman
[Thread-48] [ 2018-10-05 23:56:24.809 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:24.813 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:56:24.814 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:56:24.872 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:24.872 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:56:24.876 CEST ] [RMANEngine.getEnvParams:436]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[Thread-48] [ 2018-10-05 23:56:24.882 CEST ] [RMANEngine.initialize:195]  Execing RMAN process from initialize...
[Thread-48] [ 2018-10-05 23:56:24.902 CEST ] [RMANEngine.initialize:221]  Created RMAN process from initialize...
[Thread-48] [ 2018-10-05 23:56:24.908 CEST ] [RMANEngine.initialize:235]  Starting Reader Thread... 
[Thread-48] [ 2018-10-05 23:56:24.910 CEST ] [RMANEngine.initialize:239]  Started reader thread for RMAN process in initialize...
[Thread-66] [ 2018-10-05 23:56:24.944 CEST ] [RMANEngine.run:803]  Started reader thread for RMAN process from initialize...
[Thread-66] [ 2018-10-05 23:56:24.945 CEST ] [RMANEngine.run:807]  Set m_bReaderStarted  to true  in initialize...
[Thread-48] [ 2018-10-05 23:56:24.959 CEST ] [RMANEngine.initialize:247]  Started error thread for RMAN process from initialize...
[Thread-48] [ 2018-10-05 23:56:24.965 CEST ] [RMANEngine.initialize:252]  Created output writer for RMAN process from initialize...
[Thread-48] [ 2018-10-05 23:56:24.975 CEST ] [RMANEngine.initialize:290]  Created Log writer for RMAN process from initialize...
[Thread-48] [ 2018-10-05 23:56:24.975 CEST ] [RMANEngine.initialize:295]  Value of m_bReaderStarted in initialize=true
[Thread-48] [ 2018-10-05 23:56:24.976 CEST ] [RMANEngine.initialize:310]  Made sure reader has started for RMAN process from initialize...
[Thread-48] [ 2018-10-05 23:56:24.980 CEST ] [RMANEngine.connect:775]  NOT using OS auth to connect
[Thread-48] [ 2018-10-05 23:56:24.984 CEST ] [RMANEngine.executeImpl:1186]  m_bExecQuery=false
[Thread-48] [ 2018-10-05 23:56:24.987 CEST ] [RMANEngine.executeImpl:1194]  Command being written to rman process=connect target SYS/******
[Thread-48] [ 2018-10-05 23:56:24.996 CEST ] [RMANEngine.executeImpl:1222]  Notify reader to start reading
[Thread-66] [ 2018-10-05 23:56:25.010 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:25.010 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Recovery Manager: Release 12.1.0.2.0 - Production on Fri Oct 5 23:56:25 2018
[Thread-66] [ 2018-10-05 23:56:25.011 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:25.011 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Copyright (c) 1982, 2014, Oracle and/or its affiliates.  All rights reserved.
[Thread-66] [ 2018-10-05 23:56:25.079 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:25.083 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=RMAN> 
[Thread-66] [ 2018-10-05 23:56:25.737 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=connected to target database: SEEDDATA (DBID=4180948263, not open)
[Thread-66] [ 2018-10-05 23:56:25.746 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:25.753 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=RMAN> 
[Thread-66] [ 2018-10-05 23:56:25.755 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=echo set on
[Thread-66] [ 2018-10-05 23:56:25.768 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=set echo off;
[Thread-66] [ 2018-10-05 23:56:25.770 CEST ] [RMANEngine.readSqlOutput:1033]  Notifying writer to proceed because m_bInterrupted=falsebNotify=truem_bReaderDone=falsem_bFatalErrorOccured=false
[Thread-66] [ 2018-10-05 23:56:25.771 CEST ] [RMANEngine.run:817]  Return Value from readSqlOutput=set echo off;
[Thread-48] [ 2018-10-05 23:56:25.771 CEST ] [RMANEngine.executeImpl:1234]  Completed wait from reader
[Thread-48] [ 2018-10-05 23:56:25.772 CEST ] [RMANEngine.executeImpl:1281]  DONE EXECUTING GIVEN COMMAND=connect target SYS/******
[Thread-48] [ 2018-10-05 23:56:25.784 CEST ] [RMANUtil.getRMANEngine:197]  RMANUtil spooling to=/u01/app/oracle/cfgtoollogs/dbca/orcl/rmanUtil
[Thread-48] [ 2018-10-05 23:56:25.785 CEST ] [RMANUtil.catalogBackup:471]   catalog command CATALOG START WITH   '/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates//Seed_Database.dfb'  NOPROMPT  
[Thread-48] [ 2018-10-05 23:56:25.786 CEST ] [RMANEngine.executeImpl:1186]  m_bExecQuery=false
[Thread-48] [ 2018-10-05 23:56:25.786 CEST ] [RMANEngine.executeImpl:1194]  Command being written to rman process=CATALOG START WITH   '/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates//Seed_Database.dfb'  NOPROMPT;
[Thread-48] [ 2018-10-05 23:56:25.786 CEST ] [RMANEngine.executeImpl:1222]  Notify reader to start reading
[Thread-66] [ 2018-10-05 23:56:25.788 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=echo set off
[Thread-66] [ 2018-10-05 23:56:25.802 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:25.802 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=RMAN> 
[Thread-66] [ 2018-10-05 23:56:25.836 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Starting implicit crosscheck backup at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:25.850 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=using target database control file instead of recovery catalog
[Thread-66] [ 2018-10-05 23:56:26.083 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=allocated channel: ORA_DISK_1
[Thread-66] [ 2018-10-05 23:56:26.086 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: SID=23 device type=DISK
[Thread-66] [ 2018-10-05 23:56:26.280 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Finished implicit crosscheck backup at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:26.281 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.282 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Starting implicit crosscheck copy at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:26.283 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=using channel ORA_DISK_1
[Thread-66] [ 2018-10-05 23:56:26.299 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Finished implicit crosscheck copy at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:26.301 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.302 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=searching for all files in the recovery area
[Thread-66] [ 2018-10-05 23:56:26.315 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=cataloging files...
[Thread-66] [ 2018-10-05 23:56:26.523 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=no files cataloged
[Thread-66] [ 2018-10-05 23:56:26.526 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.671 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=searching for all files that match the pattern /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates//Seed_Database.dfb
[Thread-66] [ 2018-10-05 23:56:26.682 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.683 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=List of Files Unknown to the Database
[Thread-66] [ 2018-10-05 23:56:26.685 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output======================================
[Thread-66] [ 2018-10-05 23:56:26.686 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=File Name: /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb
[Thread-66] [ 2018-10-05 23:56:26.690 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=cataloging files...
[Thread-66] [ 2018-10-05 23:56:26.776 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=cataloging done
[Thread-66] [ 2018-10-05 23:56:26.779 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.781 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=List of Cataloged Files
[Thread-66] [ 2018-10-05 23:56:26.786 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output========================
[Thread-66] [ 2018-10-05 23:56:26.790 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=File Name: /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb
[Thread-66] [ 2018-10-05 23:56:26.861 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.866 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=RMAN> 
[Thread-66] [ 2018-10-05 23:56:26.867 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=echo set on
[Thread-66] [ 2018-10-05 23:56:26.873 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=set echo off;
[Thread-66] [ 2018-10-05 23:56:26.877 CEST ] [RMANEngine.readSqlOutput:1033]  Notifying writer to proceed because m_bInterrupted=falsebNotify=truem_bReaderDone=falsem_bFatalErrorOccured=false
[Thread-48] [ 2018-10-05 23:56:26.878 CEST ] [RMANEngine.executeImpl:1234]  Completed wait from reader
[Thread-48] [ 2018-10-05 23:56:26.879 CEST ] [RMANEngine.executeImpl:1281]  DONE EXECUTING GIVEN COMMAND=CATALOG START WITH   '/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates//Seed_Database.dfb'  NOPROMPT;
[Thread-48] [ 2018-10-05 23:56:26.879 CEST ] [RMANUtil.catalogBackup:474]  done catalog
[Thread-48] [ 2018-10-05 23:56:26.879 CEST ] [RMANUtil.getRestoreCommandForDataFiles:296]   generate set new name/restore command per datafile basis
[Thread-66] [ 2018-10-05 23:56:26.878 CEST ] [RMANEngine.run:817]  Return Value from readSqlOutput=set echo off;
[Thread-48] [ 2018-10-05 23:56:26.881 CEST ] [RMANUtil.restoreDataFilesFromBackup:343]   set new name command RUN {  

set newname for datafile 3 to new; 

set newname for datafile 1 to new; 

set newname for datafile 6 to new; 

set newname for datafile 4 to new; 

restore datafile 3; 

restore datafile 1; 

restore datafile 6; 

restore datafile 4; }
[Thread-48] [ 2018-10-05 23:56:26.884 CEST ] [RMANEngine.executeImpl:1186]  m_bExecQuery=false
[Thread-48] [ 2018-10-05 23:56:26.885 CEST ] [RMANEngine.executeImpl:1194]  Command being written to rman process=RUN {  

set newname for datafile 3 to new; 

set newname for datafile 1 to new; 

set newname for datafile 6 to new; 

set newname for datafile 4 to new; 

restore datafile 3; 

restore datafile 1; 

restore datafile 6; 

restore datafile 4; }
[Thread-48] [ 2018-10-05 23:56:26.886 CEST ] [RMANEngine.executeImpl:1222]  Notify reader to start reading
[Thread-66] [ 2018-10-05 23:56:26.887 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=echo set off
[Thread-66] [ 2018-10-05 23:56:26.888 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.889 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=RMAN> 2> 3> 4> 5> 6> 7> 8> 9> 10> 11> 12> 13> 14> 15> 16> 17> 
[Thread-66] [ 2018-10-05 23:56:26.890 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=executing command: SET NEWNAME
[Thread-66] [ 2018-10-05 23:56:26.908 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.909 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=executing command: SET NEWNAME
[Thread-66] [ 2018-10-05 23:56:26.920 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.921 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=executing command: SET NEWNAME
[Thread-66] [ 2018-10-05 23:56:26.938 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.939 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=executing command: SET NEWNAME
[Thread-66] [ 2018-10-05 23:56:26.954 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:26.983 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Starting restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:26.991 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=using channel ORA_DISK_1
[Thread-66] [ 2018-10-05 23:56:27.016 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:27.122 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: starting datafile backup set restore
[Thread-66] [ 2018-10-05 23:56:27.124 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: specifying datafile(s) to restore from backup set
[Thread-66] [ 2018-10-05 23:56:27.126 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restoring datafile 00003 to /u02/oradata/ORCL/datafile/o1_mf_sysaux_%u_.dbf
[Thread-66] [ 2018-10-05 23:56:27.127 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: reading from backup piece /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb
[Thread-63] [ 2018-10-05 23:56:34.723 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: -1
[Thread-63] [ 2018-10-05 23:56:44.763 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: -1
[Thread-66] [ 2018-10-05 23:56:52.234 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: piece handle=/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb tag=TAG20140707T070542
[Thread-66] [ 2018-10-05 23:56:52.277 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restored backup piece 1
[Thread-66] [ 2018-10-05 23:56:52.326 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restore complete, elapsed time: 00:00:25
[Thread-66] [ 2018-10-05 23:56:52.368 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Finished restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:52.468 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:52.509 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Starting restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:56:52.531 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=using channel ORA_DISK_1
[Thread-66] [ 2018-10-05 23:56:52.596 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:56:52.742 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: starting datafile backup set restore
[Thread-66] [ 2018-10-05 23:56:52.756 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: specifying datafile(s) to restore from backup set
[Thread-66] [ 2018-10-05 23:56:52.766 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restoring datafile 00001 to /u02/oradata/ORCL/datafile/o1_mf_system_%u_.dbf
[Thread-66] [ 2018-10-05 23:56:52.780 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: reading from backup piece /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb
[Thread-63] [ 2018-10-05 23:56:54.783 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: 817
[Thread-63] [ 2018-10-05 23:57:04.883 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: -1
[Thread-63] [ 2018-10-05 23:57:14.913 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: -1
[Thread-63] [ 2018-10-05 23:57:24.924 CEST ] [CloneRmanRestoreStep$ProgressTracker.run:860]  numBytesRead: 1068
[Thread-66] [ 2018-10-05 23:57:27.804 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: piece handle=/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb tag=TAG20140707T070542
[Thread-66] [ 2018-10-05 23:57:27.809 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restored backup piece 1
[Thread-66] [ 2018-10-05 23:57:27.821 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restore complete, elapsed time: 00:00:35
[Thread-66] [ 2018-10-05 23:57:27.849 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Finished restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:57:27.928 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:57:27.965 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Starting restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:57:27.971 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=using channel ORA_DISK_1
[Thread-66] [ 2018-10-05 23:57:27.999 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:57:28.117 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: starting datafile backup set restore
[Thread-66] [ 2018-10-05 23:57:28.119 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: specifying datafile(s) to restore from backup set
[Thread-66] [ 2018-10-05 23:57:28.120 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restoring datafile 00006 to /u02/oradata/ORCL/datafile/o1_mf_users_%u_.dbf
[Thread-66] [ 2018-10-05 23:57:28.126 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: reading from backup piece /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb
[Thread-66] [ 2018-10-05 23:57:29.126 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: piece handle=/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb tag=TAG20140707T070542
[Thread-66] [ 2018-10-05 23:57:29.154 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restored backup piece 1
[Thread-66] [ 2018-10-05 23:57:29.154 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
[Thread-66] [ 2018-10-05 23:57:29.163 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Finished restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:57:29.224 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:57:29.257 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Starting restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:57:29.266 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=using channel ORA_DISK_1
[Thread-66] [ 2018-10-05 23:57:29.277 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:57:29.378 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: starting datafile backup set restore
[Thread-66] [ 2018-10-05 23:57:29.384 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: specifying datafile(s) to restore from backup set
[Thread-66] [ 2018-10-05 23:57:29.385 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restoring datafile 00004 to /u02/oradata/ORCL/datafile/o1_mf_undotbs1_%u_.dbf
[Thread-66] [ 2018-10-05 23:57:29.386 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: reading from backup piece /u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb
[Thread-66] [ 2018-10-05 23:57:30.397 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: piece handle=/u01/app/oracle/12.1.0.2/db1-base/assistants/dbca/templates/Seed_Database.dfb tag=TAG20140707T070542
[Thread-66] [ 2018-10-05 23:57:30.399 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restored backup piece 1
[Thread-66] [ 2018-10-05 23:57:30.404 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=channel ORA_DISK_1: restore complete, elapsed time: 00:00:01
[Thread-66] [ 2018-10-05 23:57:30.422 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=Finished restore at 05-OCT-18
[Thread-66] [ 2018-10-05 23:57:30.521 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=
[Thread-66] [ 2018-10-05 23:57:30.525 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=RMAN> 
[Thread-66] [ 2018-10-05 23:57:30.526 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=echo set on
[Thread-66] [ 2018-10-05 23:57:30.531 CEST ] [RMANEngine.readSqlOutput:889]  Log RMAN Output=set echo off;
[Thread-66] [ 2018-10-05 23:57:30.531 CEST ] [RMANEngine.readSqlOutput:1033]  Notifying writer to proceed because m_bInterrupted=falsebNotify=truem_bReaderDone=falsem_bFatalErrorOccured=false
[Thread-66] [ 2018-10-05 23:57:30.534 CEST ] [RMANEngine.run:817]  Return Value from readSqlOutput=set echo off;
[Thread-48] [ 2018-10-05 23:57:30.534 CEST ] [RMANEngine.executeImpl:1234]  Completed wait from reader
[Thread-48] [ 2018-10-05 23:57:30.535 CEST ] [RMANEngine.executeImpl:1281]  DONE EXECUTING GIVEN COMMAND=RUN {  

set newname for datafile 3 to new; 

set newname for datafile 1 to new; 

set newname for datafile 6 to new; 

set newname for datafile 4 to new; 

restore datafile 3; 

restore datafile 1; 

restore datafile 6; 

restore datafile 4; }
[Thread-48] [ 2018-10-05 23:57:30.537 CEST ] [RMANUtil.restoreDataFilesFromBackup:346]  done with set new name
[Thread-48] [ 2018-10-05 23:57:30.587 CEST ] [CloneRmanRestoreStep.setDataFileNames:638]  Updated datafile name:/u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf
[Thread-48] [ 2018-10-05 23:57:30.590 CEST ] [CloneRmanRestoreStep.setDataFileNames:638]  Updated datafile name:/u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf
[Thread-48] [ 2018-10-05 23:57:30.592 CEST ] [CloneRmanRestoreStep.setDataFileNames:638]  Updated datafile name:/u02/oradata/ORCL/datafile/o1_mf_undotbs1_fvhql9dj_.dbf
[Thread-48] [ 2018-10-05 23:57:30.596 CEST ] [CloneRmanRestoreStep.setDataFileNames:638]  Updated datafile name:/u02/oradata/ORCL/datafile/o1_mf_users_fvhql85w_.dbf
[Thread-48] [ 2018-10-05 23:57:30.596 CEST ] [CloneRmanRestoreStep.executeImpl:508]  Restored datafiles
[Thread-48] [ 2018-10-05 23:57:30.596 CEST ] [SQLEngine.spoolOff:2124]  Setting spool off = /u01/app/oracle/cfgtoollogs/dbca/orcl/CloneRmanRestore.log
[Thread-48] [ 2018-10-05 23:57:30.597 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u01/app/oracle/cfgtoollogs/dbca/orcl/initorclTempOMF.ora
[Thread-48] [ 2018-10-05 23:57:30.605 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=oracle.sysman.assistants.util.SilentMessageHandler@4f2d26d2
[Thread-48] [ 2018-10-05 23:57:30.608 CEST ] [StepContext$ModeRunner.run:2873]  ---- Progress Needed:=true
[Thread-48] [ 2018-10-05 23:57:30.610 CEST ] [BasicStep.execute:250]  Executing Step : CLONE_DB_CREATION
[Thread-48] [ 2018-10-05 23:57:30.611 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-01503
[Thread-48] [ 2018-10-05 23:57:30.611 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-01034
[Thread-48] [ 2018-10-05 23:57:30.612 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-01092
[Thread-48] [ 2018-10-05 23:57:30.612 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-03113
[Thread-48] [ 2018-10-05 23:57:30.612 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-03114
[Thread-48] [ 2018-10-05 23:57:30.612 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-19502
[Thread-48] [ 2018-10-05 23:57:30.613 CEST ] [StepErrorHandler.setFatalErrors:323]  setting Fatal Error: ORA-01219
[Thread-48] [ 2018-10-05 23:57:30.613 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-01109
[Thread-48] [ 2018-10-05 23:57:30.613 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-12712
[Thread-48] [ 2018-10-05 23:57:30.614 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-00942
[Thread-48] [ 2018-10-05 23:57:30.614 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-04043
[Thread-48] [ 2018-10-05 23:57:30.614 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-44304
[Thread-48] [ 2018-10-05 23:57:30.615 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-44305
[Thread-48] [ 2018-10-05 23:57:30.615 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-06512
[Thread-48] [ 2018-10-05 23:57:30.617 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-06510
[Thread-48] [ 2018-10-05 23:57:30.618 CEST ] [StepErrorHandler.setIgnorableErrors:251]  setting Ignorable Error: ORA-01403
[Thread-48] [ 2018-10-05 23:57:30.618 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=null
[Thread-48] [ 2018-10-05 23:57:30.691 CEST ] [SQLEngine.setSpool:2056]  old Spool  = null
[Thread-48] [ 2018-10-05 23:57:30.691 CEST ] [SQLEngine.setSpool:2057]  Setting Spool  = /u01/app/oracle/cfgtoollogs/dbca/orcl/cloneDBCreation.log
[Thread-48] [ 2018-10-05 23:57:30.692 CEST ] [SQLEngine.setSpool:2058]  Is spool appendable? --> true
[Thread-48] [ 2018-10-05 23:57:30.694 CEST ] [CloneDBCreationStep.executeImpl:356]   size of datfiles in create db 4
[Thread-48] [ 2018-10-05 23:57:30.695 CEST ] [CloneDBCreationStep.executeImpl:382]  a.createCtlFileSql = Create controlfile reuse set database "orcl"
MAXINSTANCES 8
MAXLOGHISTORY 1
MAXLOGFILES 16
MAXLOGMEMBERS 3
MAXDATAFILES 100
Datafile 
'/u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf',
[Thread-48] [ 2018-10-05 23:57:30.695 CEST ] [CloneDBCreationStep.executeImpl:386]  b.createCtlFileSql = Create controlfile reuse set database "orcl"
MAXINSTANCES 8
MAXLOGHISTORY 1
MAXLOGFILES 16
MAXLOGMEMBERS 3
MAXDATAFILES 100
Datafile 
'/u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_undotbs1_fvhql9dj_.dbf',
[Thread-48] [ 2018-10-05 23:57:34.858 CEST ] [CloneDBCreationStep.executeImpl:400]  pfile for startup=/u01/app/oracle/admin/orcl/pfile/init.ora
[Thread-48] [ 2018-10-05 23:57:48.409 CEST ] [CloneDBCreationStep.executeImpl:405]  createCtl=Create controlfile reuse set database "orcl"
MAXINSTANCES 8
MAXLOGHISTORY 1
MAXLOGFILES 16
MAXLOGMEMBERS 3
MAXDATAFILES 100
Datafile 
'/u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_undotbs1_fvhql9dj_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_users_fvhql85w_.dbf',
[Thread-48] [ 2018-10-05 23:57:48.469 CEST ] [CloneDBCreationStep.executeImpl:412]  crtCtl=Create controlfile reuse set database "orcl"
MAXINSTANCES 8
MAXLOGHISTORY 1
MAXLOGFILES 16
MAXLOGMEMBERS 3
MAXDATAFILES 100
Datafile 
'/u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_undotbs1_fvhql9dj_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_users_fvhql85w_.dbf'
[Thread-48] [ 2018-10-05 23:57:48.523 CEST ] [CloneDBCreationStep.executeImpl:428]  Length of OriginalRedoLogsGrNames=3
[Thread-48] [ 2018-10-05 23:57:48.577 CEST ] [RedoLogGroupSQLGenerator.filespecsClause:68]  LOG FILE size in MB = 50
[Thread-48] [ 2018-10-05 23:57:48.579 CEST ] [RedoLogGroupSQLGenerator.filespecsClause:74]  RedoFile space clause ('/u02/oradata/{DB_UNIQUE_NAME}/redo01.log') SIZE 50M
[Thread-48] [ 2018-10-05 23:57:48.580 CEST ] [CloneDBCreationStep.executeImpl:437]  0th redoLogText = GROUP 1 ('/u02/oradata/{DB_UNIQUE_NAME}/redo01.log') SIZE 50M
[Thread-48] [ 2018-10-05 23:57:48.582 CEST ] [RedoLogGroupSQLGenerator.filespecsClause:68]  LOG FILE size in MB = 50
[Thread-48] [ 2018-10-05 23:57:48.583 CEST ] [RedoLogGroupSQLGenerator.filespecsClause:74]  RedoFile space clause ('/u02/oradata/{DB_UNIQUE_NAME}/redo02.log') SIZE 50M
[Thread-48] [ 2018-10-05 23:57:48.584 CEST ] [CloneDBCreationStep.executeImpl:437]  1th redoLogText = GROUP 2 ('/u02/oradata/{DB_UNIQUE_NAME}/redo02.log') SIZE 50M
[Thread-48] [ 2018-10-05 23:57:48.585 CEST ] [RedoLogGroupSQLGenerator.filespecsClause:68]  LOG FILE size in MB = 50
[Thread-48] [ 2018-10-05 23:57:48.585 CEST ] [RedoLogGroupSQLGenerator.filespecsClause:74]  RedoFile space clause ('/u02/oradata/{DB_UNIQUE_NAME}/redo03.log') SIZE 50M
[Thread-48] [ 2018-10-05 23:57:48.585 CEST ] [CloneDBCreationStep.executeImpl:437]  2th redoLogText = GROUP 3 ('/u02/oradata/{DB_UNIQUE_NAME}/redo03.log') SIZE 50M
[Thread-48] [ 2018-10-05 23:57:48.590 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:48.597 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:48.599 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:48.601 CEST ] [CloneDBCreationStep.executeImpl:458]  createCTLSql=Create controlfile reuse set database "orcl"
MAXINSTANCES 8
MAXLOGHISTORY 1
MAXLOGFILES 16
MAXLOGMEMBERS 3
MAXDATAFILES 100
Datafile 
'/u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_undotbs1_fvhql9dj_.dbf',
'/u02/oradata/ORCL/datafile/o1_mf_users_fvhql85w_.dbf'
LOGFILE GROUP 1 ('/u02/oradata/orcl/redo01.log') SIZE 50M,
GROUP 2 ('/u02/oradata/orcl/redo02.log') SIZE 50M,
GROUP 3 ('/u02/oradata/orcl/redo03.log') SIZE 50M RESETLOGS;
[Thread-48] [ 2018-10-05 23:57:48.906 CEST ] [SQLEngine.done:2278]  Done called
[Thread-48] [ 2018-10-05 23:57:49.089 CEST ] [SQLEngine.spoolOff:2124]  Setting spool off = /u01/app/oracle/cfgtoollogs/dbca/orcl/cloneDBCreation.log
[Thread-48] [ 2018-10-05 23:57:49.136 CEST ] [BasicStep.configureSettings:353]  messageHandler being set=oracle.sysman.assistants.util.SilentMessageHandler@4f2d26d2
[Thread-48] [ 2018-10-05 23:57:49.138 CEST ] [StepContext$ModeRunner.run:2899]  ORA-01503: CREATE CONTROLFILE failed
ORA-00200: control file could not be created
ORA-00202: control file: '/u02/oradata/orcl/control01.ctl'
ORA-27040: file create error, unable to create file

oracle.sysman.assistants.dbca.backend.CloneDBCreationStep.executeImpl(CloneDBCreationStep.java:1134)
oracle.sysman.assistants.util.step.BasicStep.execute(BasicStep.java:259)
oracle.sysman.assistants.util.step.Step.execute(Step.java:135)
oracle.sysman.assistants.util.step.StepContext$ModeRunner.run(StepContext.java:2883)
java.lang.Thread.run(Thread.java:682)
[Thread-48] [ 2018-10-05 23:57:49.145 CEST ] [SQLEngine.done:2278]  Done called
[Thread-48] [ 2018-10-05 23:57:49.153 CEST ] [Host.createStepSQLInterface:8605]  sid =orcl
[Thread-48] [ 2018-10-05 23:57:49.154 CEST ] [Host.createStepSQLInterface:8606]  sidOrConnectString orcl
[Thread-48] [ 2018-10-05 23:57:49.161 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: null
[Thread-48] [ 2018-10-05 23:57:49.297 CEST ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[Thread-48] [ 2018-10-05 23:57:49.299 CEST ] [OracleHome.getVersion:1010]  Homeinfo /u01/app/oracle/12.1.0.2/db1-base,1
[Thread-48] [ 2018-10-05 23:57:49.777 CEST ] [OracleHome.getVersion:1038]  OracleHome.server.getVersion Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.780 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.780 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.780 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.781 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.782 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.782 CEST ] [SQLPlusEngine.getCmmdParams:225]  m_home 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:49.782 CEST ] [SQLPlusEngine.getCmmdParams:226]  version > 112 true
[Thread-48] [ 2018-10-05 23:57:49.794 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:57:49.797 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:57:49.800 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:57:49.875 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:57:49.875 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:57:49.875 CEST ] [SQLEngine.getEnvParams:612]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[Thread-48] [ 2018-10-05 23:57:49.879 CEST ] [SQLEngine.initialize:358]  Execing SQLPLUS/SVRMGR process...
[Thread-48] [ 2018-10-05 23:57:49.881 CEST ] [SQLEngine.initialize:395]  m_bReaderStarted: false
[Thread-48] [ 2018-10-05 23:57:49.881 CEST ] [SQLEngine.initialize:399]  Starting Reader Thread... 
[Thread-48] [ 2018-10-05 23:57:50.056 CEST ] [CloneRmanRestoreStep.cancel:722]  Cleaning up partially extracted files failed
[Thread-48] [ 2018-10-05 23:57:50.443 CEST ] [SQLEngine.done:2278]  Done called
[Thread-48] [ 2018-10-05 23:57:50.458 CEST ] [CloneRmanRestoreStep.cancel:737]  RMAN cleanup failed
[Thread-48] [ 2018-10-05 23:57:50.458 CEST ] [CloneRmanRestoreStep.cancel:738]  ORA-01507: database not mounted

oracle.sysman.assistants.util.sqlEngine.SQLEngine.executeImpl(SQLEngine.java:1739)
oracle.sysman.assistants.util.sqlEngine.SQLEngine.executeQuery(SQLEngine.java:878)
oracle.sysman.assistants.dbca.backend.CloneRmanRestoreStep.generateCancelScript(CloneRmanRestoreStep.java:772)
oracle.sysman.assistants.dbca.backend.CloneRmanRestoreStep.cancel(CloneRmanRestoreStep.java:732)
oracle.sysman.assistants.util.step.StepContext$ModeRunner.cancel(StepContext.java:2979)
oracle.sysman.assistants.util.step.StepContext$ModeRunner.run(StepContext.java:2940)
java.lang.Thread.run(Thread.java:682)
[Thread-48] [ 2018-10-05 23:57:50.461 CEST ] [CloneDBCreationStep.cancel:1178]  CloneDBCreationStep.cancel(): nodeList= null
[Thread-48] [ 2018-10-05 23:57:50.462 CEST ] [SQLEngine.reInitialize:785]  Reinitializing SQLEngine...
[Thread-48] [ 2018-10-05 23:57:50.462 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.462 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.462 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.462 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.463 CEST ] [OracleHome.getVersion:991]  OracleHome.getVersion called.  Current Version: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.463 CEST ] [OracleHome.getVersion:1059]  Current Version From Inventory: 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.463 CEST ] [SQLPlusEngine.getCmmdParams:225]  m_home 12.1.0.2.0
[Thread-48] [ 2018-10-05 23:57:50.464 CEST ] [SQLPlusEngine.getCmmdParams:226]  version > 112 true
[Thread-48] [ 2018-10-05 23:57:50.464 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:57:50.464 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[Thread-48] [ 2018-10-05 23:57:50.464 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[Thread-48] [ 2018-10-05 23:57:50.475 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[Thread-48] [ 2018-10-05 23:57:50.475 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[Thread-48] [ 2018-10-05 23:57:50.475 CEST ] [SQLEngine.getEnvParams:612]  NLS_LANG: AMERICAN_AMERICA.AL32UTF8
[Thread-48] [ 2018-10-05 23:57:50.476 CEST ] [SQLEngine.initialize:358]  Execing SQLPLUS/SVRMGR process...
[Thread-48] [ 2018-10-05 23:57:50.478 CEST ] [SQLEngine.initialize:395]  m_bReaderStarted: false
[Thread-48] [ 2018-10-05 23:57:50.478 CEST ] [SQLEngine.initialize:399]  Starting Reader Thread... 
[Thread-48] [ 2018-10-05 23:57:50.481 CEST ] [SQLEngine.initialize:448]  Waiting for m_bReaderStarted to be true 
[Thread-48] [ 2018-10-05 23:57:54.882 CEST ] [Oratab.getTempFile:805]  Temp oratab: /tmp/oratab
[Thread-48] [ 2018-10-05 23:57:54.890 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u01/app/oracle/12.1.0.2/db1-base/dbs/orapworcl
[Thread-48] [ 2018-10-05 23:57:54.909 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u01/app/oracle/12.1.0.2/db1-base/dbs/initorcl.ora
[Thread-48] [ 2018-10-05 23:57:54.909 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u01/app/oracle/admin/orcl/pfile/init.ora
[Thread-48] [ 2018-10-05 23:57:54.914 CEST ] [CloneDBCreationStep.cancel:1225]  CloneDBCreationStep.cancel(): bRaw=false
[Thread-48] [ 2018-10-05 23:57:54.916 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/ORCL/datafile/o1_mf_sysaux_fvhqjc4g_.dbf
[Thread-48] [ 2018-10-05 23:57:54.918 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/ORCL/datafile/o1_mf_system_fvhqk4qt_.dbf
[Thread-48] [ 2018-10-05 23:57:54.918 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/ORCL/datafile/o1_mf_undotbs1_fvhql9dj_.dbf
[Thread-48] [ 2018-10-05 23:57:54.918 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/ORCL/datafile/o1_mf_users_fvhql85w_.dbf
[Thread-48] [ 2018-10-05 23:57:54.918 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:54.918 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/orcl/redo01.log
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/orcl/redo02.log
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/orcl/redo03.log
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/oradata/orcl/control01.ctl
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [CommonAttributes.replaceVariables:1402]  var2 orcl
[Thread-48] [ 2018-10-05 23:57:54.919 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u02/fra/orcl/control02.ctl
[Thread-48] [ 2018-10-05 23:57:55.000 CEST ] [SQLEngine.done:2278]  Done called
[main] [ 2018-10-05 23:57:55.014 CEST ] [Host.cleanup:3928]  Dbca exit status is: 1
[main] [ 2018-10-05 23:57:55.014 CEST ] [Host.cleanup:3931]  check point context oracle.sysman.assistants.util.CheckpointContext@32b95f72
[main] [ 2018-10-05 23:57:55.023 CEST ] [InventoryUtil.getOUIInvSession:349]  setting OUI READ level to ACCESSLEVEL_READ_LOCKLESS
[main] [ 2018-10-05 23:57:55.023 CEST ] [InventoryUtil.getHomeName:113]  homeName = OraDB12Home1
[main] [ 2018-10-05 23:57:55.023 CEST ] [OsUtilsBase.getBaseFromOrabase:659]  oraBaseUtility /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:57:55.025 CEST ] [OsUtilsBase.getBaseFromOrabase:668]  cmds: /u01/app/oracle/12.1.0.2/db1-base/bin/orabase
[main] [ 2018-10-05 23:57:55.025 CEST ] [OsUtilsBase.getBaseFromOrabase:672]  envs:  ORACLE_HOME=/u01/app/oracle/12.1.0.2/db1-base
[main] [ 2018-10-05 23:57:55.032 CEST ] [OsUtilsBase.getBaseFromOrabase:682]  baseLocation from orabase 
/u01/app/oracle
[main] [ 2018-10-05 23:57:55.032 CEST ] [OsUtilsBase.getBaseFromOrabase:707]   orabaseLocation= /u01/app/oracle
[main] [ 2018-10-05 23:57:55.034 CEST ] [Host.cleanup:3957]  check point  oracle.sysman.oic.oics.OicsCheckPoint@6ce931d9
[main] [ 2018-10-05 23:57:55.143 CEST ] [OsUtilsBase.copyFile:1505]  OsUtilsBase.copyFile: 
[main] [ 2018-10-05 23:57:55.143 CEST ] [OsUtilsBase.copyFile:1553]  **write of file at destination complete...
[main] [ 2018-10-05 23:57:55.143 CEST ] [OsUtilsBase.copyFile:1588]  **file copy status:= true
[main] [ 2018-10-05 23:57:55.143 CEST ] [OsUtilsBase.deleteFile:1803]  OsUtilsBase.deleteFile: /u01/app/oracle/cfgtoollogs/dbca/silent.log_2018-10-05_11-55-26-PM
[Thread-15] [ 2018-10-05 23:57:55.152 CEST ] [DbcaCleanupHook.run:44]  Cleanup started
[Thread-15] [ 2018-10-05 23:57:55.152 CEST ] [OracleHome.cleanupDBOptionsIntance:1671]  DB Options dummy instance sid=null
[Thread-15] [ 2018-10-05 23:57:55.152 CEST ] [DbcaCleanupHook.run:49]  Cleanup ended

Unique database identifier check passed.

/u02/ has enough space. Required space is 5990 MB , available space is 76726 MB.
File Validations Successful.
Cleaning up failed steps
DBCA_PROGRESS : 5%
Copying database files
DBCA_PROGRESS : 7%
DBCA_PROGRESS : 9%
DBCA_PROGRESS : 16%
DBCA_PROGRESS : 23%
DBCA_PROGRESS : 30%
DBCA_PROGRESS : 41%
Creating and starting Oracle instance
ORA-01503: CREATE CONTROLFILE failed
ORA-00200: control file could not be created
ORA-00202: control file: '/u02/oradata/orcl/control01.ctl'
ORA-27040: file create error, unable to create file

ORA-01503: CREATE CONTROLFILE failed
ORA-00200: control file could not be created
ORA-00202: control file: '/u02/oradata/orcl/control01.ctl'
ORA-27040: file create error, unable to create file

DBCA_PROGRESS : DBCA Operation failed.
/u01/app/oracle/cfgtoollogs/dbca/orcl/orcl1.log (END)
Rendanic commented 5 years ago

This is not a bug in ansible-oracle. Oracle did some changes in DBCA in 12.1.0.2 which breaks a lot of configurations arround the control_files:

Controlfiles Are Not Getting Created In The Specified Location When Using DBCA Template To Create Database (Doc ID 2405522.1)

Mikaeel told me that he is already working on the workarround from Oracle. We have to use an undocumented parameter in dbca to fix the problem which is related to a changed behavior of the DBCA in 12.1 and 12.2. I didn't checked it against 18c but I won't be surprised when we see a similar issue in DBCA.

It is similar to the problem with db_recovery_file_dest_size. Always use bytes as a value for this parameter. Otherwise the DBCA will mess it up and you struggle with problems during the execution...

The bugs in 12.1.0.2 cost me some hours in the last 2 weeks.

Rendanic commented 5 years ago

I forgot a simpel fix

Use uppercase names for db_name and db_unique_name. That should work: db_name=ORCL db_unique_name=ORCL

The db_unique_name is not mandatory but when you like to use the parameter please use uppercase, because the DBCA tries to create the files inside of <db_create_file_dest>/<db_unique_name | default(db_name)>

daverod24 commented 5 years ago

Hi, thanks for the help. @Rendanic

I have another little detail with that same thing I put in the file config.rb that is in vagrant-vbox-si-fs the names in capital letters of the cbd and pdb but I'm getting an error with the tablespace that the listener can not connect.

TASK [oradb-manage-tablespace : Manage tablespaces (pdb)] **********************
failed: [db-fs-1] (item=({u'users': [{u'state': u'present', u'grants': [u'approle1'], u'default_tablespace': u'appuser1_data', u'schema': u'appuser1'}], u'cdb': u'orclcdb', u'init_parameters': [{u'scope': u'both', u'state': u'present', u'name': u'db_create_file_dest', u'value': u'/u02/oradata/'}], u'pdb_name': u'orclpdb1', u'datafile_dest': u'/u02/oradata/', u'state': u'present', u'roles': [{u'state': u'present', u'grants': [u'create session', u'create table', u'select any table', u'select any dictionary'], u'name': u'approle1'}], u'services': [{u'state': u'started', u'name': u'app1_service'}], u'home': u'18300-base'}, {u'name': u'users', u'autoextend': False, u'state': u'present', u'next': u'5M', u'content': u'permanent', u'maxsize': u'500M', u'bigfile': True, u'size': u'10M'})) => {"changed": false, "item": [{"cdb": "orclcdb", "datafile_dest": "/u02/oradata/", "home": "18300-base", "init_parameters": [{"name": "db_create_file_dest", "scope": "both", "state": "present", "value": "/u02/oradata/"}], "pdb_name": "orclpdb1", "roles": [{"grants": ["create session", "create table", "select any table", "select any dictionary"], "name": "approle1", "state": "present"}], "services": [{"name": "app1_service", "state": "started"}], "state": "present", "users": [{"default_tablespace": "appuser1_data", "grants": ["approle1"], "schema": "appuser1", "state": "present"}]}, {"autoextend": false, "bigfile": true, "content": "permanent", "maxsize": "500M", "name": "users", "next": "5M", "size": "10M", "state": "present"}], "msg": "Could not connect to database - ORA-12514: TNS:listener does not currently know of service requested in connect descriptor, connect descriptor: (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=db-fs-1)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=orclpdb1)))"}
failed: [db-fs-1] (item=({u'users': [{u'state': u'present', u'grants': [u'approle1'], u'default_tablespace': u'appuser1_data', u'schema': u'appuser1'}], u'cdb': u'orclcdb', u'init_parameters': [{u'scope': u'both', u'state': u'present', u'name': u'db_create_file_dest', u'value': u'/u02/oradata/'}], u'pdb_name': u'orclpdb1', u'datafile_dest': u'/u02/oradata/', u'state': u'present', u'roles': [{u'state': u'present', u'grants': [u'create session', u'create table', u'select any table', u'select any dictionary'], u'name': u'approle1'}], u'services': [{u'state': u'started', u'name': u'app1_service'}], u'home': u'18300-base'}, {u'name': u'appuser1_data', u'autoextend': False, u'state': u'present', u'next': u'5M', u'content': u'permanent', u'maxsize': u'500M', u'bigfile': True, u'size': u'10M'})) => {"changed": false, "item": [{"cdb": "orclcdb", "datafile_dest": "/u02/oradata/", "home": "18300-base", "init_parameters": [{"name": "db_create_file_dest", "scope": "both", "state": "present", "value": "/u02/oradata/"}], "pdb_name": "orclpdb1", "roles": [{"grants": ["create session", "create table", "select any table", "select any dictionary"], "name": "approle1", "state": "present"}], "services": [{"name": "app1_service", "state": "started"}], "state": "present", "users": [{"default_tablespace": "appuser1_data", "grants": ["approle1"], "schema": "appuser1", "state": "present"}]}, {"autoextend": false, "bigfile": true, "content": "permanent", "maxsize": "500M", "name": "appuser1_data", "next": "5M", "size": "10M", "state": "present"}], "msg": "Could not connect to database - ORA-12514: TNS:listener does not currently know of service requested in connect descriptor, connect descriptor: (DESCRIPTION=(ADDRESS=(PROTOCOL=TCP)(HOST=db-fs-1)(PORT=1521))(CONNECT_DATA=(SERVICE_NAME=orclpdb1)))"}
oravirt commented 5 years ago

Hi, This should really be reported in the correct repo (http://github.com/oravirt/vagrant-vbox-si-fs, as this doesn't really have anything to do with) the ansible-oracle repo.

But, the problem is that I haven't had time (yet) to externalize the oracle_pdbs dictionary in config/oracle.rb & Vagrantfile, so it falls back to the default name of oraclepdb1 and most likely (haven't tested the theory yet) that's why you're getting the error (as the pdb orclpdb1 doesn't exist)

daverod24 commented 5 years ago

thank you I made the changes you told me and it worked