[main] [ 2019-08-21 22:08:23.818 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:08:23.824 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:08:23.859 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:08:23.864 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:08:23.876 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:08:23.876 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:08:23.880 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:08:23.880 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:08:23.880 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:08:23.881 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:08:23.881 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:08:23.882 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:08:23.882 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:08:23.884 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:08:23.885 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 41 [main] [ 2019-08-21 22:08:23.886 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_config failed with error code = 41 [main] [ 2019-08-21 22:08:23.886 AST ] [nativesystem.OCRNative.Native] JNI: error = Error retrieving ocrconfig_loc property. [main] [ 2019-08-21 22:08:23.886 AST ] [nativesystem.OCRNative.Native] getConf: procr_get_conf failed: invalid configuration [main] [ 2019-08-21 22:08:23.886 AST ] [OCR.isCluster:1059] OCR Result status = false [main] [ 2019-08-21 22:08:23.887 AST ] [OCR.isCluster:1066] error Message = [Ljava.lang.String;@5679c6c6 [main] [ 2019-08-21 22:08:23.892 AST ] [Cluster.isCluster:234] Failed to detect cluster: Error retrieving ocrconfig_loc property. Failed to detect cluster: Error retrieving ocrconfig_loc property. oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:283) oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:223) oracle.cluster.util.SRVMContext.init(SRVMContext.java:123) oracle.cluster.util.SRVMContext.init(SRVMContext.java:84) oracle.ops.util.ClusterUtil.main(ClusterUtil.java:301) [main] [ 2019-08-21 22:08:23.892 AST ] [SRVMContext.init:126] No CRS configuration found [main] [ 2019-08-21 22:08:23.893 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:08:23.893 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:08:23.893 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:08:23.894 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:08:23.894 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:08:23.895 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:08:23.899 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:08:23.899 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE,-status [main] [ 2019-08-21 22:08:23.902 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:08:23.903 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:08:23.912 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE,-status [main] [ 2019-08-21 22:08:23.912 AST ] [ClusterwareCkpt.getCkptStatus:329] Checking to see if checkpoint:ROOTCRS_FIRSTNODEhas successfuly completed [main] [ 2019-08-21 22:08:23.916 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:08:23.927 AST ] [CheckPointIndexSessionImpl.:94] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml not found. [main] [ 2019-08-21 22:08:23.928 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:08:23.929 AST ] [CheckPointSessionImpl.:101] Checkpoint:checkpointfile :/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml not found, one will be created for this session [main] [ 2019-08-21 22:08:23.929 AST ] [ClusterwareCkpt.getCkptStatus:353] Reading data for checkpoint: ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:08:23.930 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:10:16.115 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:10:16.128 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:10:16.202 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:10:16.206 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:10:16.261 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:10:16.262 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:10:16.297 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:10:16.299 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:10:16.299 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:10:16.300 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:10:16.302 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:10:16.303 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:10:16.303 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:10:16.312 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:10:16.315 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 41 [main] [ 2019-08-21 22:10:16.315 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_config failed with error code = 41 [main] [ 2019-08-21 22:10:16.315 AST ] [nativesystem.OCRNative.Native] JNI: error = Error retrieving ocrconfig_loc property. [main] [ 2019-08-21 22:10:16.316 AST ] [nativesystem.OCRNative.Native] getConf: procr_get_conf failed: invalid configuration [main] [ 2019-08-21 22:10:16.317 AST ] [OCR.isCluster:1059] OCR Result status = false [main] [ 2019-08-21 22:10:16.318 AST ] [OCR.isCluster:1066] error Message = [Ljava.lang.String;@5679c6c6 [main] [ 2019-08-21 22:10:16.352 AST ] [Cluster.isCluster:234] Failed to detect cluster: Error retrieving ocrconfig_loc property. Failed to detect cluster: Error retrieving ocrconfig_loc property. oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:283) oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:223) oracle.cluster.util.SRVMContext.init(SRVMContext.java:123) oracle.cluster.util.SRVMContext.init(SRVMContext.java:84) oracle.ops.util.ClusterUtil.main(ClusterUtil.java:301) [main] [ 2019-08-21 22:10:16.353 AST ] [SRVMContext.init:126] No CRS configuration found [main] [ 2019-08-21 22:10:16.354 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:10:16.356 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:10:16.356 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:10:16.356 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:10:16.357 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:10:16.358 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:10:16.366 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:10:16.366 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:10:16.371 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:10:16.373 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:10:16.388 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:10:16.388 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_FIRSTNODE exists [main] [ 2019-08-21 22:10:16.394 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:10:16.413 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml found. [main] [ 2019-08-21 22:10:16.687 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:10:16.688 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = oracle.cluster.impl.checkpoints.CheckPointImpl@17550481 [main] [ 2019-08-21 22:10:16.691 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:10:30.868 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:10:30.875 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:10:30.910 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:10:30.912 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:10:30.924 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:10:30.925 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:10:30.928 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:10:30.930 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:10:30.931 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:10:30.931 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:10:30.932 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:10:30.932 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:10:30.932 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:10:30.935 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:10:30.936 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 41 [main] [ 2019-08-21 22:10:30.936 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_config failed with error code = 41 [main] [ 2019-08-21 22:10:30.936 AST ] [nativesystem.OCRNative.Native] JNI: error = Error retrieving ocrconfig_loc property. [main] [ 2019-08-21 22:10:30.937 AST ] [nativesystem.OCRNative.Native] getConf: procr_get_conf failed: invalid configuration [main] [ 2019-08-21 22:10:30.937 AST ] [OCR.isCluster:1059] OCR Result status = false [main] [ 2019-08-21 22:10:30.937 AST ] [OCR.isCluster:1066] error Message = [Ljava.lang.String;@5679c6c6 [main] [ 2019-08-21 22:10:30.942 AST ] [Cluster.isCluster:234] Failed to detect cluster: Error retrieving ocrconfig_loc property. Failed to detect cluster: Error retrieving ocrconfig_loc property. oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:283) oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:223) oracle.cluster.util.SRVMContext.init(SRVMContext.java:123) oracle.cluster.util.SRVMContext.init(SRVMContext.java:84) oracle.ops.util.ClusterUtil.main(ClusterUtil.java:301) [main] [ 2019-08-21 22:10:30.942 AST ] [SRVMContext.init:126] No CRS configuration found [main] [ 2019-08-21 22:10:30.943 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:10:30.944 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:10:30.944 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:10:30.944 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:10:30.945 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:10:30.945 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:10:30.950 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:10:30.950 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_PARAM [main] [ 2019-08-21 22:10:30.953 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:10:30.954 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:10:30.963 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_PARAM [main] [ 2019-08-21 22:10:30.963 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_PARAM exists [main] [ 2019-08-21 22:10:30.967 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:10:30.978 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/testdb1/checkpoints/crsconfig/index.xml found. [main] [ 2019-08-21 22:10:31.099 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/testdb1/crsconfig/ckptGridHA_testdb1.xml [main] [ 2019-08-21 22:10:31.100 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = oracle.cluster.impl.checkpoints.CheckPointImpl@2c6a3f77 [main] [ 2019-08-21 22:10:31.100 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:10:46.170 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:10:46.176 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:10:46.211 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:10:46.213 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:10:46.227 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:10:46.227 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:10:46.230 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:10:46.231 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:10:46.231 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:10:46.232 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:10:46.232 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:10:46.233 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:10:46.233 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:10:46.237 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:10:46.238 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 41 [main] [ 2019-08-21 22:10:46.238 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_config failed with error code = 41 [main] [ 2019-08-21 22:10:46.238 AST ] [nativesystem.OCRNative.Native] JNI: error = Error retrieving ocrconfig_loc property. [main] [ 2019-08-21 22:10:46.239 AST ] [nativesystem.OCRNative.Native] getConf: procr_get_conf failed: invalid configuration [main] [ 2019-08-21 22:10:46.239 AST ] [OCR.isCluster:1059] OCR Result status = false [main] [ 2019-08-21 22:10:46.240 AST ] [OCR.isCluster:1066] error Message = [Ljava.lang.String;@5679c6c6 [main] [ 2019-08-21 22:10:46.244 AST ] [Cluster.isCluster:234] Failed to detect cluster: Error retrieving ocrconfig_loc property. Failed to detect cluster: Error retrieving ocrconfig_loc property. oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:283) oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:223) oracle.cluster.util.SRVMContext.init(SRVMContext.java:123) oracle.cluster.util.SRVMContext.init(SRVMContext.java:84) oracle.ops.util.ClusterUtil.main(ClusterUtil.java:301) [main] [ 2019-08-21 22:10:46.245 AST ] [SRVMContext.init:126] No CRS configuration found [main] [ 2019-08-21 22:10:46.245 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:10:46.246 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:10:46.246 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:10:46.247 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:10:46.247 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:10:46.247 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:10:46.252 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:10:46.252 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_GPNPSETUP [main] [ 2019-08-21 22:10:46.255 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:10:46.256 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:10:46.265 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_GPNPSETUP [main] [ 2019-08-21 22:10:46.265 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_GPNPSETUP exists [main] [ 2019-08-21 22:10:46.269 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:10:46.282 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/testdb1/checkpoints/crsconfig/index.xml found. [main] [ 2019-08-21 22:10:46.412 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/testdb1/crsconfig/ckptGridHA_testdb1.xml [main] [ 2019-08-21 22:10:46.412 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = null [main] [ 2019-08-21 22:10:46.413 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:11:39.340 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:11:39.343 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:11:39.380 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:11:39.382 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:11:39.394 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:11:39.395 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:11:39.398 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:11:39.400 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:11:39.401 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:11:39.401 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:11:39.402 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:11:39.402 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:11:39.402 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:11:39.405 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:11:39.406 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 41 [main] [ 2019-08-21 22:11:39.406 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_config failed with error code = 41 [main] [ 2019-08-21 22:11:39.406 AST ] [nativesystem.OCRNative.Native] JNI: error = Error retrieving ocrconfig_loc property. [main] [ 2019-08-21 22:11:39.406 AST ] [nativesystem.OCRNative.Native] getConf: procr_get_conf failed: invalid configuration [main] [ 2019-08-21 22:11:39.407 AST ] [OCR.isCluster:1059] OCR Result status = false [main] [ 2019-08-21 22:11:39.407 AST ] [OCR.isCluster:1066] error Message = [Ljava.lang.String;@5679c6c6 [main] [ 2019-08-21 22:11:39.412 AST ] [Cluster.isCluster:234] Failed to detect cluster: Error retrieving ocrconfig_loc property. Failed to detect cluster: Error retrieving ocrconfig_loc property. oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:283) oracle.ops.mgmt.cluster.Cluster.isCluster(Cluster.java:223) oracle.cluster.util.SRVMContext.init(SRVMContext.java:123) oracle.cluster.util.SRVMContext.init(SRVMContext.java:84) oracle.ops.util.ClusterUtil.main(ClusterUtil.java:301) [main] [ 2019-08-21 22:11:39.412 AST ] [SRVMContext.init:126] No CRS configuration found [main] [ 2019-08-21 22:11:39.413 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:11:39.414 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:11:39.414 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:11:39.414 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:11:39.415 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:11:39.415 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:11:39.421 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:11:39.422 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:11:39.425 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:11:39.426 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:11:39.435 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:11:39.436 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_FIRSTNODE exists [main] [ 2019-08-21 22:11:39.439 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:11:39.451 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml found. [main] [ 2019-08-21 22:11:39.572 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:11:39.572 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = oracle.cluster.impl.checkpoints.CheckPointImpl@17550481 [main] [ 2019-08-21 22:11:39.573 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:11:58.488 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:11:58.495 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:11:58.538 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:11:58.540 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:11:58.555 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:11:58.556 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:11:58.559 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:11:58.560 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:11:58.560 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:11:58.561 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:11:58.562 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:11:58.562 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:11:58.562 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:11:58.568 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:11:58.569 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:11:58.569 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:11:58.570 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:11:58.570 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:11:58.571 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:11:58.583 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:11:58.583 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:11:58.585 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:11:58.585 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:11:58.586 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:11:58.586 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:11:58.587 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:11:58.587 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:11:58.591 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:11:58.592 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_OHASD [main] [ 2019-08-21 22:11:58.592 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:11:58.595 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:11:58.597 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_OHASD [main] [ 2019-08-21 22:11:58.606 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_OHASD exists [main] [ 2019-08-21 22:11:58.611 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:11:58.625 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/testdb1/checkpoints/crsconfig/index.xml found. [main] [ 2019-08-21 22:11:58.784 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/testdb1/crsconfig/ckptGridHA_testdb1.xml [main] [ 2019-08-21 22:11:58.786 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = null [main] [ 2019-08-21 22:11:58.787 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:12:50.699 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:12:50.705 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:12:50.764 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:12:50.769 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:12:50.799 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:12:50.800 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:12:50.807 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:12:50.808 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:12:50.809 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:12:50.810 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:12:50.812 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:12:50.812 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:12:50.813 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:12:50.821 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:12:50.824 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:12:50.825 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:12:50.825 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:12:50.826 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:12:50.827 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:12:50.850 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:12:50.851 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:12:50.853 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:12:50.854 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:12:50.855 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:12:50.856 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:12:50.857 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:12:50.858 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:12:50.866 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:12:50.867 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:12:50.868 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:12:50.874 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:12:50.877 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:12:50.897 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_FIRSTNODE exists [main] [ 2019-08-21 22:12:50.904 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:12:50.924 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml found. [main] [ 2019-08-21 22:12:51.117 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:12:51.118 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = oracle.cluster.impl.checkpoints.CheckPointImpl@13fee20c [main] [ 2019-08-21 22:12:51.119 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:13:25.023 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:13:25.029 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:13:25.064 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:13:25.066 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:13:25.080 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:13:25.080 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:13:25.083 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:13:25.084 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:13:25.084 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:13:25.084 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:13:25.085 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:13:25.086 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:13:25.086 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:13:25.090 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:13:25.091 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:13:25.092 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:13:25.092 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:13:25.092 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:13:25.093 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:13:25.104 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:13:25.104 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:13:25.105 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:13:25.106 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:13:25.106 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:13:25.106 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:13:25.107 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:13:25.108 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:13:25.111 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:13:25.112 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-writeckpt,-name,ROOTCRS_FIRSTNODE,-state,START,-nodelist,testdb1,testdb2,-transferfile [main] [ 2019-08-21 22:13:25.112 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:13:25.115 AST ] [ClusterwareCkpt.executeCkpt:1122] Processing writeckpt command line arguments [main] [ 2019-08-21 22:13:25.116 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-writeckpt,-name,ROOTCRS_FIRSTNODE,-state,START,-nodelist,testdb1,testdb2,-transferfile [main] [ 2019-08-21 22:13:25.125 AST ] [ClusterwareCkpt.writeCheckPoint:544] Writing checkpoint [main] [ 2019-08-21 22:13:25.125 AST ] [ClusterwareCkpt.writeCheckPoint:545] Ckpt Name: ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:13:25.125 AST ] [ClusterwareCkpt.writeCheckPoint:546] Ckpt Desc: null [main] [ 2019-08-21 22:13:25.125 AST ] [ClusterwareCkpt.writeCheckPoint:547] Ckpt Level: null [main] [ 2019-08-21 22:13:25.126 AST ] [ClusterwareCkpt.writeCheckPoint:548] Ckpt State: START [main] [ 2019-08-21 22:13:25.126 AST ] [ClusterwareCkpt.writeCheckPoint:552] after assert of checkpoint name [main] [ 2019-08-21 22:13:25.130 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:13:25.142 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml found. [main] [ 2019-08-21 22:13:25.271 AST ] [ClusterwareCkpt.writeCheckPoint:567] ckpt debug 1 [main] [ 2019-08-21 22:13:25.271 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:13:25.272 AST ] [ClusterwareCkpt.writeCheckPoint:570] ckpt debug 2 [main] [ 2019-08-21 22:13:25.272 AST ] [ClusterwareCkpt.writeCheckPoint:574] ckpt debug 3 [main] [ 2019-08-21 22:13:25.272 AST ] [ClusterwareCkpt.writeCheckPoint:586] Setting checkpoint state to: 1 [main] [ 2019-08-21 22:13:25.273 AST ] [ClusterwareCkpt.writeCheckPoint:590] ckpt debug 4 [main] [ 2019-08-21 22:13:25.274 AST ] [ClusterwareCkpt.writeCheckPoint:595] ckpt debug 5 [main] [ 2019-08-21 22:13:25.281 AST ] [CheckPointSessionImpl.saveCheckPointSession:143] Checkpoint:Index file written and updated [main] [ 2019-08-21 22:13:25.281 AST ] [ClusterwareCkpt.writeCheckPoint:599] ckpt debug 6 [main] [ 2019-08-21 22:13:25.282 AST ] [ClusterwareCkpt.propagateGlobalCheckpoint:871] Propagating global checkpoints to nodes: testdb1,testdb2 [main] [ 2019-08-21 22:13:25.286 AST ] [ClusterwareCkpt.propagateGlobalCheckpoint:876] Closing global checkpoint session [main] [ 2019-08-21 22:13:25.287 AST ] [CheckPointIndexWriter.generatePropertiesNode:220] Checkpoint:Setting status in index file as passed,as no last failed checkpoint is available. [main] [ 2019-08-21 22:13:25.287 AST ] [CheckPointSessionImpl.closeCheckPointSession:183] Sending checkpoint files to remote nodes [main] [ 2019-08-21 22:13:25.288 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:13:25.288 AST ] [Utils.getNodeName:571] Hostname : testdb1 is converted to nodeName : testdb1 [main] [ 2019-08-21 22:13:25.288 AST ] [ClusterUtil.findLiveNodes:218] Attempt to find live nodes [main] [ 2019-08-21 22:13:25.296 AST ] [ClusterConfig.:240] ClusterConfig:Number of workers = 0 [main] [ 2019-08-21 22:13:25.298 AST ] [ClusterConfig.createWorkers:325] Started worker threads count=1 [Worker 0] [ 2019-08-21 22:13:25.300 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 0 m_count=0 [main] [ 2019-08-21 22:13:25.301 AST ] [ClusterConfig.isClusterInstalled:373] hasJarPresent=true [main] [ 2019-08-21 22:13:25.309 AST ] [GetActiveNodes.create:220] Going into GetActiveNodes constructor... [main] [ 2019-08-21 22:13:25.317 AST ] [HASContext.:125] moduleInit = 19 [main] [ 2019-08-21 22:13:25.318 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=3 [main] [ 2019-08-21 22:13:25.318 AST ] [HASContext.:136] Initialised SRVMContext [main] [ 2019-08-21 22:13:25.319 AST ] [has.HASContextNative.Native] prsr_trace: no lsf ctx, line=Native: allocHASContext [main] [ 2019-08-21 22:13:25.320 AST ] [has.HASContextNative.Native] allocHASContext: module_init = 19 [main] [ 2019-08-21 22:13:25.320 AST ] [has.HASContextNative.Native] allocHASContext: META context [1] [main] [ 2019-08-21 22:13:25.320 AST ] [has.HASContextNative.Native] allocHASContext: LSF context [1] [main] [ 2019-08-21 22:13:25.320 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_initCLSS [Thread-1] [ 2019-08-21 22:13:25.322 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.321: [ CSSCLNT][2]clsssInitNative [Thread-2] [ 2019-08-21 22:13:25.323 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.322: [ CSSCLNT][2]clsssInitNative: proplist len 16 properties - 1,2,3,4,5,6,7 [Thread-3] [ 2019-08-21 22:13:25.328 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.327: [ CSSCLNT][2]clsssConnect: Connect to CSSD completed, endpt 1b [Thread-4] [ 2019-08-21 22:13:25.329 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.328: [ CSSCLNT][2]clsssConnect: CSS daemon not up (1b) [Thread-5] [ 2019-08-21 22:13:25.331 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.330: [ CSSCLNT][2]clsssConnect: gipcDestroy 0 [Thread-6] [ 2019-08-21 22:13:25.331 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.331: [ CSSCLNT][2]clsssInitNative: CSS daemon in (ADDRESS=(PROTOCOL=ipc)(KEY=OCSSD_LL_testdb1_)) not up [Thread-7] [ 2019-08-21 22:13:25.332 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.332: [ CSSCLNT][2]clssgsAttrInit:attrdesc grpcount=6 mbrcount 8 [Thread-8] [ 2019-08-21 22:13:25.334 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.333: [ CSSCLNT][2]clsssterm: terminating gbl ctx 112f560 [Thread-9] [ 2019-08-21 22:13:25.334 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.334: [ CSSCLNT][2]clsss_gterm: terminating connection [Thread-10] [ 2019-08-21 22:13:25.335 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.335: [ CSSCLNT][2]clsss_gterm: destroying GIPC ctx [Thread-11] [ 2019-08-21 22:13:25.336 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.335: [ CSSCLNT][2]clsss_gterm: Shutting down GIPC [Thread-12] [ 2019-08-21 22:13:25.338 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.337: [ CSSCLNT][2]clsss_gterm: Completing LSF cleanup [Thread-13] [ 2019-08-21 22:13:25.339 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.338: [ CSSCLNT][2]clsss_gterm: Completing LPM cleanup [main] [ 2019-08-21 22:13:25.341 AST ] [has.HASContextNative.Native] prsr_trace: Native: clss error 3 [main] [ 2019-08-21 22:13:25.341 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_freeCLSS [main] [ 2019-08-21 22:13:25.343 AST ] [has.HASContextNative.Native] prsr_trace: prsr_throwException: class=oracle/ops/mgmt/has/HASContextException, prkhMsgID=CLSS_COM_ERROR, arg1=null, nativeError=null, debugMsg=Native: prsr_initCLSS [main] [ 2019-08-21 22:13:25.345 AST ] [ClusterConfig.init:437] Returning same instance to clientmain [main] [ 2019-08-21 22:13:25.346 AST ] [ClusterConfig.submit:502] Entering submit, cmdCount=1 [main] [ 2019-08-21 22:13:25.347 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread main m_count=1 [main] [ 2019-08-21 22:13:25.347 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread main m_count=1 [Worker 0] [ 2019-08-21 22:13:25.347 AST ] [Semaphore.release:85] SyncBufferEmpty:Release called by thread Worker 0 m_count=1 [main] [ 2019-08-21 22:13:25.348 AST ] [ClusterConfig.submit:537] submitted commands=1 [main] [ 2019-08-21 22:13:25.348 AST ] [ClusterConfig.block:610] block called by thread main commandNum 1 [main] [ 2019-08-21 22:13:25.349 AST ] [Semaphore.acquire:109] ClientResource Constructor:Blocking Semaphore owned by main:Acquire called by thread main m_count=0 [Worker 0] [ 2019-08-21 22:13:25.354 AST ] [sPlatform.getPingCmdArgs:89] Node=testdb2 Timeout=10 [Worker 0] [ 2019-08-21 22:13:25.471 AST ] [RuntimeExec.runCommand:269] runCommand: Waiting for the process [Worker 0] [ 2019-08-21 22:13:25.474 AST ] [RuntimeExec.runCommand:271] runCommand: process returns 0 [Thread-15] [ 2019-08-21 22:13:25.474 AST ] [StreamReader.run:62] In StreamReader.run [Thread-14] [ 2019-08-21 22:13:25.478 AST ] [StreamReader.run:62] In StreamReader.run [Thread-14] [ 2019-08-21 22:13:25.478 AST ] [StreamReader.run:66] OUTPUT>testdb2 is alive [Worker 0] [ 2019-08-21 22:13:25.479 AST ] [RuntimeExec.runCommand:297] RunTimeExec: error> [Worker 0] [ 2019-08-21 22:13:25.479 AST ] [RuntimeExec.runCommand:323] Returning from RunTimeExec.runCommand [Worker 0] [ 2019-08-21 22:13:25.479 AST ] [UnixSystem.isNodeAlive:5164] msgBuf=testdb2 is alive [Worker 0] [ 2019-08-21 22:13:25.481 AST ] [NodeLivenessCommand.postEvent:103] Inside NodeLivenessCommand.postEvent, listener size=0 [Worker 0] [ 2019-08-21 22:13:25.482 AST ] [ClusterConfig$ExecuteCommand.returnCommandToClient:3301] returnCommandToClient; fillCount=0 is full=false [Worker 0] [ 2019-08-21 22:13:25.482 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread Worker 0 m_count=50 [Worker 0] [ 2019-08-21 22:13:25.482 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread Worker 0 m_count=1 [Worker 0] [ 2019-08-21 22:13:25.482 AST ] [ClientResource.getListener:157] Calling getListener [Worker 0] [ 2019-08-21 22:13:25.482 AST ] [ClusterConfig$ExecuteCommand.run:3396] Owner Thread name of the blocking Semaphore main [Worker 0] [ 2019-08-21 22:13:25.483 AST ] [ClusterConfig$ExecuteCommand.run:3404] Obtained Semaphore [Worker 0] [ 2019-08-21 22:13:25.483 AST ] [Semaphore.release:85] ClientResource Constructor:Blocking Semaphore owned by main:Release called by thread Worker 0 m_count=1 [main] [ 2019-08-21 22:13:25.483 AST ] [ClusterConfig.block:622] block acquired semnum=0 [main] [ 2019-08-21 22:13:25.487 AST ] [ClusterConfig.submit:571] Out of block [main] [ 2019-08-21 22:13:25.488 AST ] [ClusterConfig.submit:588] status=true [main] [ 2019-08-21 22:13:25.488 AST ] [ClusterConfig.destroy:466] destroying resources for client thread Thread[main,5,main] [main] [ 2019-08-21 22:13:25.488 AST ] [ClusterUtil.findLiveNodes:258] All nodes are up [main] [ 2019-08-21 22:13:25.489 AST ] [ClusterConfig.isClusterInstalled:373] hasJarPresent=true [main] [ 2019-08-21 22:13:25.489 AST ] [GetActiveNodes.create:220] Going into GetActiveNodes constructor... [main] [ 2019-08-21 22:13:25.489 AST ] [HASContext.:125] moduleInit = 19 [main] [ 2019-08-21 22:13:25.490 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=4 [main] [ 2019-08-21 22:13:25.491 AST ] [HASContext.:136] Initialised SRVMContext [main] [ 2019-08-21 22:13:25.491 AST ] [has.HASContextNative.Native] prsr_trace: Native: allocHASContext [main] [ 2019-08-21 22:13:25.491 AST ] [has.HASContextNative.Native] allocHASContext: module_init = 19 [main] [ 2019-08-21 22:13:25.492 AST ] [has.HASContextNative.Native] allocHASContext: META context [1] [main] [ 2019-08-21 22:13:25.492 AST ] [has.HASContextNative.Native] allocHASContext: LSF context [1] [main] [ 2019-08-21 22:13:25.493 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_initCLSS [Thread-16] [ 2019-08-21 22:13:25.497 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.496: [ CSSCLNT][2]clsssInitNative [Thread-17] [ 2019-08-21 22:13:25.501 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.501: [ CSSCLNT][2]clsssInitNative: proplist len 16 properties - 1,2,3,4,5,6,7 [Thread-18] [ 2019-08-21 22:13:25.504 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.503: [ CSSCLNT][2]clsssConnect: Connect to CSSD completed, endpt 1b [Thread-19] [ 2019-08-21 22:13:25.506 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.505: [ CSSCLNT][2]clsssConnect: CSS daemon not up (1b) [Thread-20] [ 2019-08-21 22:13:25.506 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.506: [ CSSCLNT][2]clsssConnect: gipcDestroy 0 [Thread-21] [ 2019-08-21 22:13:25.507 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.506: [ CSSCLNT][2]clsssInitNative: CSS daemon in (ADDRESS=(PROTOCOL=ipc)(KEY=OCSSD_LL_testdb1_)) not up [Thread-22] [ 2019-08-21 22:13:25.508 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.507: [ CSSCLNT][2]clssgsAttrInit:attrdesc grpcount=6 mbrcount 8 [Thread-23] [ 2019-08-21 22:13:25.508 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.508: [ CSSCLNT][2]clsssterm: terminating gbl ctx 117a840 [Thread-24] [ 2019-08-21 22:13:25.510 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.509: [ CSSCLNT][2]clsss_gterm: terminating connection [Thread-25] [ 2019-08-21 22:13:25.510 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.510: [ CSSCLNT][2]clsss_gterm: destroying GIPC ctx [Thread-26] [ 2019-08-21 22:13:25.511 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.511: [ CSSCLNT][2]clsss_gterm: Shutting down GIPC [Thread-27] [ 2019-08-21 22:13:25.512 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.512: [ CSSCLNT][2]clsss_gterm: Completing LSF cleanup [Thread-28] [ 2019-08-21 22:13:25.513 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:25.512: [ CSSCLNT][2]clsss_gterm: Completing LPM cleanup [main] [ 2019-08-21 22:13:25.513 AST ] [has.HASContextNative.Native] prsr_trace: Native: clss error 3 [main] [ 2019-08-21 22:13:25.513 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_freeCLSS [main] [ 2019-08-21 22:13:25.514 AST ] [has.HASContextNative.Native] prsr_trace: prsr_throwException: class=oracle/ops/mgmt/has/HASContextException, prkhMsgID=CLSS_COM_ERROR, arg1=null, nativeError=null, debugMsg=Native: prsr_initCLSS [main] [ 2019-08-21 22:13:25.514 AST ] [ClusterConfig.init:437] Returning same instance to clientmain [main] [ 2019-08-21 22:13:25.515 AST ] [ClusterConfig.createWorkers:327] Started additional worker threads count=3 [main] [ 2019-08-21 22:13:25.518 AST ] [ClusterConfig.createDirInNode:1940] Creating dir in nodes: testdb2, /u01/app/grid/crsdata/@global/crsconfig, true, 700 [main] [ 2019-08-21 22:13:25.519 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread main m_count=1 [main] [ 2019-08-21 22:13:25.519 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread main m_count=1 [main] [ 2019-08-21 22:13:25.519 AST ] [ClusterConfig.block:610] block called by thread main commandNum 1 [main] [ 2019-08-21 22:13:25.519 AST ] [Semaphore.acquire:109] ClientResource Constructor:Blocking Semaphore owned by main:Acquire called by thread main m_count=0 [Worker 1] [ 2019-08-21 22:13:25.520 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 1 m_count=1 [Worker 1] [ 2019-08-21 22:13:25.520 AST ] [Semaphore.release:85] SyncBufferEmpty:Release called by thread Worker 1 m_count=1 [Worker 1] [ 2019-08-21 22:13:25.521 AST ] [DirCreateCommand.execute:70] In DirCreateCommand.execute, recurseFlag=false, modeFlag=false [Worker 1] [ 2019-08-21 22:13:25.521 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [Worker 1] [ 2019-08-21 22:13:25.521 AST ] [UnixSystem.checkRemoteExecutionSetup:3071] Client didn't specify for remote shell or remote copy [Worker 1] [ 2019-08-21 22:13:25.523 AST ] [Library.load:202] library.load [Worker 1] [ 2019-08-21 22:13:25.523 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [Worker 1] [ 2019-08-21 22:13:25.527 AST ] [UnixSystem.checkRemoteExecutionSetup:3082] checkRemoteExecutionSetup:: Checking user equivalence using Secured Shell '/usr/bin/ssh' [Worker 1] [ 2019-08-21 22:13:25.527 AST ] [UnixSystem.checkRemoteExecutionSetup:3084] checkRemoteExecutionSetup:: Running Unix command: /usr/bin/ssh -o FallBackToRsh=no -o PasswordAuthentication=no -o StrictHostKeyChecking=yes -o NumberOfPasswordPrompts=0 testdb2 /usr/bin/true [Worker 2] [ 2019-08-21 22:13:25.528 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 2 m_count=0 [Worker 3] [ 2019-08-21 22:13:25.529 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 3 m_count=0 [Worker 1] [ 2019-08-21 22:13:25.539 AST ] [RuntimeExec.runCommand:269] runCommand: Waiting for the process [Thread-30] [ 2019-08-21 22:13:25.541 AST ] [StreamReader.run:62] In StreamReader.run [Thread-29] [ 2019-08-21 22:13:25.542 AST ] [StreamReader.run:62] In StreamReader.run [Worker 0] [ 2019-08-21 22:13:25.542 AST ] [ClusterConfig$ExecuteCommand.run:3419] Released Semaphore by worker=Worker 0 [Worker 0] [ 2019-08-21 22:13:25.543 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 0 m_count=0 [Worker 1] [ 2019-08-21 22:13:25.748 AST ] [RuntimeExec.runCommand:271] runCommand: process returns 0 [Worker 1] [ 2019-08-21 22:13:25.748 AST ] [RuntimeExec.runCommand:297] RunTimeExec: error> [Worker 1] [ 2019-08-21 22:13:25.749 AST ] [RuntimeExec.runCommand:323] Returning from RunTimeExec.runCommand [Worker 1] [ 2019-08-21 22:13:25.749 AST ] [UnixSystem.checkRemoteExecutionSetup:3211] Using Remote Shell Command: '/usr/bin/ssh -o FallBackToRsh=no -o PasswordAuthentication=no -o StrictHostKeyChecking=yes -o NumberOfPasswordPrompts=0 ' [Worker 1] [ 2019-08-21 22:13:25.749 AST ] [UnixSystem.checkRemoteExecutionSetup:3212] Using Remote Copy Command: '/usr/bin/scp' [Worker 1] [ 2019-08-21 22:13:25.769 AST ] [RuntimeExec.runCommand:269] runCommand: Waiting for the process [Thread-32] [ 2019-08-21 22:13:25.774 AST ] [StreamReader.run:62] In StreamReader.run [Thread-31] [ 2019-08-21 22:13:25.776 AST ] [StreamReader.run:62] In StreamReader.run [Worker 1] [ 2019-08-21 22:13:26.009 AST ] [RuntimeExec.runCommand:271] runCommand: process returns 0 [Worker 1] [ 2019-08-21 22:13:26.009 AST ] [RuntimeExec.runCommand:297] RunTimeExec: error> [Worker 1] [ 2019-08-21 22:13:26.010 AST ] [RuntimeExec.runCommand:323] Returning from RunTimeExec.runCommand [Worker 1] [ 2019-08-21 22:13:26.010 AST ] [NativeSystem.isCmdScv:547] isCmdScv: cmd=[/usr/bin/ssh -o FallBackToRsh=no -o PasswordAuthentication=no -o StrictHostKeyChecking=yes -o NumberOfPasswordPrompts=0 testdb2 -n /usr/bin/mkdir -p -m 700 /u01/app/grid/crsdata/@global/crsconfig] [Worker 1] [ 2019-08-21 22:13:26.012 AST ] [NativeSystem.isCmdScv:597] isCmdScv: /usr/bin/ssh is present. [Worker 1] [ 2019-08-21 22:13:26.013 AST ] [NativeSystem.isCmdScv:599] isCmdScv: /usr/bin/ssh is a file. [Worker 1] [ 2019-08-21 22:13:26.013 AST ] [NativeSystem.isCmdScv:616] isCmdScv: returned true [Worker 1] [ 2019-08-21 22:13:26.013 AST ] [NativeSystem.rununixcmd:1283] NativeSystem.rununixcmd: RetString 1| :successful [Worker 1] [ 2019-08-21 22:13:26.015 AST ] [NativeResult.:93] NativeResult: The String obtained is1| :successful [Worker 1] [ 2019-08-21 22:13:26.015 AST ] [NativeResult.:101] The status string is: 1 [Worker 1] [ 2019-08-21 22:13:26.015 AST ] [NativeResult.:114] The result string is: :successful 1 [Worker 1] [ 2019-08-21 22:13:26.016 AST ] [ClusterConfig$ExecuteCommand.returnCommandToClient:3301] returnCommandToClient; fillCount=0 is full=false [Worker 1] [ 2019-08-21 22:13:26.016 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread Worker 1 m_count=50 [Worker 1] [ 2019-08-21 22:13:26.016 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread Worker 1 m_count=1 [Worker 1] [ 2019-08-21 22:13:26.019 AST ] [ClientResource.getListener:157] Calling getListener [Worker 1] [ 2019-08-21 22:13:26.019 AST ] [ClusterConfig$ExecuteCommand.run:3396] Owner Thread name of the blocking Semaphore main [Worker 1] [ 2019-08-21 22:13:26.020 AST ] [ClusterConfig$ExecuteCommand.run:3404] Obtained Semaphore [Worker 1] [ 2019-08-21 22:13:26.020 AST ] [Semaphore.release:85] ClientResource Constructor:Blocking Semaphore owned by main:Release called by thread Worker 1 m_count=1 [Worker 1] [ 2019-08-21 22:13:26.020 AST ] [ClusterConfig$ExecuteCommand.run:3419] Released Semaphore by worker=Worker 1 [Worker 1] [ 2019-08-21 22:13:26.021 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 1 m_count=0 [main] [ 2019-08-21 22:13:26.022 AST ] [ClusterConfig.block:622] block acquired semnum=0 [main] [ 2019-08-21 22:13:26.022 AST ] [ClusterConfig.destroy:466] destroying resources for client thread Thread[main,5,main] [main] [ 2019-08-21 22:13:26.022 AST ] [ClusterConfig.isClusterInstalled:373] hasJarPresent=true [main] [ 2019-08-21 22:13:26.023 AST ] [GetActiveNodes.create:220] Going into GetActiveNodes constructor... [main] [ 2019-08-21 22:13:26.023 AST ] [HASContext.:125] moduleInit = 19 [main] [ 2019-08-21 22:13:26.024 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=5 [main] [ 2019-08-21 22:13:26.025 AST ] [HASContext.:136] Initialised SRVMContext [main] [ 2019-08-21 22:13:26.026 AST ] [has.HASContextNative.Native] prsr_trace: Native: allocHASContext [main] [ 2019-08-21 22:13:26.026 AST ] [has.HASContextNative.Native] allocHASContext: module_init = 19 [main] [ 2019-08-21 22:13:26.026 AST ] [has.HASContextNative.Native] allocHASContext: META context [1] [main] [ 2019-08-21 22:13:26.027 AST ] [has.HASContextNative.Native] allocHASContext: LSF context [1] [main] [ 2019-08-21 22:13:26.027 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_initCLSS [Thread-33] [ 2019-08-21 22:13:26.028 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.027: [ CSSCLNT][2]clsssInitNative [Thread-34] [ 2019-08-21 22:13:26.029 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.028: [ CSSCLNT][2]clsssInitNative: proplist len 16 properties - 1,2,3,4,5,6,7 [Finalizer] [ 2019-08-21 22:13:26.051 AST ] [ClusterUtil.finalize:119] ClusterUtil: finalized called for oracle.ops.mgmt.has.ClusterUtil@5dc940c3 [Finalizer] [ 2019-08-21 22:13:26.052 AST ] [ClusterUtil.finalize:119] ClusterUtil: finalized called for oracle.ops.mgmt.has.ClusterUtil@530eb50a [Thread-35] [ 2019-08-21 22:13:26.055 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.033: [ CSSCLNT][2]clsssConnect: Connect to CSSD completed, endpt 1b [Thread-36] [ 2019-08-21 22:13:26.056 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.056: [ CSSCLNT][2]clsssConnect: CSS daemon not up (1b) [Thread-37] [ 2019-08-21 22:13:26.057 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.057: [ CSSCLNT][2]clsssConnect: gipcDestroy 0 [Thread-38] [ 2019-08-21 22:13:26.058 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.057: [ CSSCLNT][2]clsssInitNative: CSS daemon in (ADDRESS=(PROTOCOL=ipc)(KEY=OCSSD_LL_testdb1_)) not up [Thread-39] [ 2019-08-21 22:13:26.058 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.058: [ CSSCLNT][2]clssgsAttrInit:attrdesc grpcount=6 mbrcount 8 [Thread-40] [ 2019-08-21 22:13:26.059 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.058: [ CSSCLNT][2]clsssterm: terminating gbl ctx 118bde0 [Thread-41] [ 2019-08-21 22:13:26.059 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.059: [ CSSCLNT][2]clsss_gterm: terminating connection [Thread-42] [ 2019-08-21 22:13:26.060 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.059: [ CSSCLNT][2]clsss_gterm: destroying GIPC ctx [Thread-43] [ 2019-08-21 22:13:26.061 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.060: [ CSSCLNT][2]clsss_gterm: Shutting down GIPC [Thread-44] [ 2019-08-21 22:13:26.062 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.062: [ CSSCLNT][2]clsss_gterm: Completing LSF cleanup [Thread-45] [ 2019-08-21 22:13:26.062 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.062: [ CSSCLNT][2]clsss_gterm: Completing LPM cleanup [main] [ 2019-08-21 22:13:26.063 AST ] [has.HASContextNative.Native] prsr_trace: Native: clss error 3 [main] [ 2019-08-21 22:13:26.063 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_freeCLSS [main] [ 2019-08-21 22:13:26.064 AST ] [has.HASContextNative.Native] prsr_trace: prsr_throwException: class=oracle/ops/mgmt/has/HASContextException, prkhMsgID=CLSS_COM_ERROR, arg1=null, nativeError=null, debugMsg=Native: prsr_initCLSS [main] [ 2019-08-21 22:13:26.064 AST ] [ClusterConfig.init:437] Returning same instance to clientmain [main] [ 2019-08-21 22:13:26.065 AST ] [ClusterConfig.copyFileToNodesNonSynchronized:947] Number of nodes :1 [main] [ 2019-08-21 22:13:26.065 AST ] [ClusterConfig.copyFileToNodesNonSynchronized:949] 0th CopyFileToNodes localnode:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml to testdb2:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:13:26.065 AST ] [ClusterConfig.copyFileBetweenNodes:684] Checking: Copying files between nodes: localnode:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml testdb2:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:13:26.066 AST ] [ClusterConfig.copyFileBetweenNodes:696] Checking 2: Copying files between nodes: localnode:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml testdb2:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:13:26.067 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread main m_count=1 [main] [ 2019-08-21 22:13:26.067 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread main m_count=1 [main] [ 2019-08-21 22:13:26.067 AST ] [ClusterConfig.block:610] block called by thread main commandNum 1 [main] [ 2019-08-21 22:13:26.068 AST ] [Semaphore.acquire:109] ClientResource Constructor:Blocking Semaphore owned by main:Acquire called by thread main m_count=0 [Worker 2] [ 2019-08-21 22:13:26.068 AST ] [Semaphore.release:85] SyncBufferEmpty:Release called by thread Worker 2 m_count=1 [Worker 2] [ 2019-08-21 22:13:26.069 AST ] [UnixSystem.copyFile:1084] Copy file localnode:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml to testdb2:/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [Worker 2] [ 2019-08-21 22:13:26.070 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [Worker 2] [ 2019-08-21 22:13:26.070 AST ] [UnixSystem.remoteCopyFile:808] Copying files localnode/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml testdb2/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [Worker 2] [ 2019-08-21 22:13:26.071 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [Worker 2] [ 2019-08-21 22:13:26.071 AST ] [UnixSystem.remoteCopyFile:826] UnixSystem: /usr/bin/scp -p /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml testdb2:'/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml' [Worker 2] [ 2019-08-21 22:13:26.079 AST ] [RuntimeExec.runCommand:269] runCommand: Waiting for the process [Thread-47] [ 2019-08-21 22:13:26.096 AST ] [StreamReader.run:62] In StreamReader.run [Thread-46] [ 2019-08-21 22:13:26.097 AST ] [StreamReader.run:62] In StreamReader.run [Worker 2] [ 2019-08-21 22:13:26.324 AST ] [RuntimeExec.runCommand:271] runCommand: process returns 0 [Worker 2] [ 2019-08-21 22:13:26.325 AST ] [RuntimeExec.runCommand:297] RunTimeExec: error> [Worker 2] [ 2019-08-21 22:13:26.327 AST ] [RuntimeExec.runCommand:323] Returning from RunTimeExec.runCommand [Worker 2] [ 2019-08-21 22:13:26.328 AST ] [NativeSystem.isCmdScv:547] isCmdScv: cmd=[/usr/bin/scp -p /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml testdb2:'/u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml'] [Worker 2] [ 2019-08-21 22:13:26.334 AST ] [NativeSystem.isCmdScv:597] isCmdScv: /usr/bin/scp is present. [Worker 2] [ 2019-08-21 22:13:26.335 AST ] [NativeSystem.isCmdScv:599] isCmdScv: /usr/bin/scp is a file. [Worker 2] [ 2019-08-21 22:13:26.336 AST ] [NativeSystem.isCmdScv:616] isCmdScv: returned true [Worker 2] [ 2019-08-21 22:13:26.342 AST ] [NativeSystem.rununixcmd:1283] NativeSystem.rununixcmd: RetString 1| :successful [Worker 2] [ 2019-08-21 22:13:26.350 AST ] [CopyCommand.execute:171] CopyCommand.execute: native copyFile returns `1| :successful' [Worker 2] [ 2019-08-21 22:13:26.372 AST ] [NativeResult.:93] NativeResult: The String obtained is1| :successful [Worker 2] [ 2019-08-21 22:13:26.380 AST ] [NativeResult.:101] The status string is: 1 [Worker 2] [ 2019-08-21 22:13:26.380 AST ] [NativeResult.:114] The result string is: :successful 1 [Worker 2] [ 2019-08-21 22:13:26.381 AST ] [CopyCommand.execute:179] The copy command failed. Details: :successful [Worker 2] [ 2019-08-21 22:13:26.381 AST ] [ClusterConfig$ExecuteCommand.returnCommandToClient:3301] returnCommandToClient; fillCount=0 is full=false [Worker 2] [ 2019-08-21 22:13:26.381 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread Worker 2 m_count=50 [Worker 2] [ 2019-08-21 22:13:26.382 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread Worker 2 m_count=1 [Worker 2] [ 2019-08-21 22:13:26.382 AST ] [ClientResource.getListener:157] Calling getListener [Worker 2] [ 2019-08-21 22:13:26.382 AST ] [ClusterConfig$ExecuteCommand.run:3396] Owner Thread name of the blocking Semaphore main [Worker 2] [ 2019-08-21 22:13:26.383 AST ] [ClusterConfig$ExecuteCommand.run:3404] Obtained Semaphore [Worker 2] [ 2019-08-21 22:13:26.383 AST ] [Semaphore.release:85] ClientResource Constructor:Blocking Semaphore owned by main:Release called by thread Worker 2 m_count=1 [Worker 2] [ 2019-08-21 22:13:26.383 AST ] [ClusterConfig$ExecuteCommand.run:3419] Released Semaphore by worker=Worker 2 [Worker 2] [ 2019-08-21 22:13:26.383 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 2 m_count=0 [main] [ 2019-08-21 22:13:26.384 AST ] [ClusterConfig.block:622] block acquired semnum=0 [main] [ 2019-08-21 22:13:26.384 AST ] [ClusterConfig.destroy:466] destroying resources for client thread Thread[main,5,main] [main] [ 2019-08-21 22:13:26.384 AST ] [ClusterConfig.isClusterInstalled:373] hasJarPresent=true [main] [ 2019-08-21 22:13:26.385 AST ] [GetActiveNodes.create:220] Going into GetActiveNodes constructor... [main] [ 2019-08-21 22:13:26.385 AST ] [HASContext.:125] moduleInit = 19 [main] [ 2019-08-21 22:13:26.385 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=6 [main] [ 2019-08-21 22:13:26.386 AST ] [HASContext.:136] Initialised SRVMContext [main] [ 2019-08-21 22:13:26.386 AST ] [has.HASContextNative.Native] prsr_trace: Native: allocHASContext [main] [ 2019-08-21 22:13:26.386 AST ] [has.HASContextNative.Native] allocHASContext: module_init = 19 [main] [ 2019-08-21 22:13:26.387 AST ] [has.HASContextNative.Native] allocHASContext: META context [1] [main] [ 2019-08-21 22:13:26.387 AST ] [has.HASContextNative.Native] allocHASContext: LSF context [1] [main] [ 2019-08-21 22:13:26.387 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_initCLSS [main] [ 2019-08-21 22:13:26.393 AST ] [has.HASContextNative.Native] prsr_trace: Native: clss error 3 [main] [ 2019-08-21 22:13:26.394 AST ] [has.HASContextNative.Native] prsr_trace: Native: prsr_freeCLSS [main] [ 2019-08-21 22:13:26.394 AST ] [has.HASContextNative.Native] prsr_trace: prsr_throwException: class=oracle/ops/mgmt/has/HASContextException, prkhMsgID=CLSS_COM_ERROR, arg1=null, nativeError=null, debugMsg=Native: prsr_initCLSS [main] [ 2019-08-21 22:13:26.395 AST ] [ClusterConfig.init:437] Returning same instance to clientmain [main] [ 2019-08-21 22:13:26.395 AST ] [ClusterConfig.copyFileToNodesNonSynchronized:947] Number of nodes :1 [main] [ 2019-08-21 22:13:26.395 AST ] [ClusterConfig.copyFileToNodesNonSynchronized:949] 0th CopyFileToNodes localnode:/u01/app/grid/crsdata/@global/crsconfig/index.xml to testdb2:/u01/app/grid/crsdata/@global/crsconfig/index.xml [main] [ 2019-08-21 22:13:26.395 AST ] [ClusterConfig.copyFileBetweenNodes:684] Checking: Copying files between nodes: localnode:/u01/app/grid/crsdata/@global/crsconfig/index.xml testdb2:/u01/app/grid/crsdata/@global/crsconfig/index.xml [main] [ 2019-08-21 22:13:26.396 AST ] [ClusterConfig.copyFileBetweenNodes:696] Checking 2: Copying files between nodes: localnode:/u01/app/grid/crsdata/@global/crsconfig/index.xml testdb2:/u01/app/grid/crsdata/@global/crsconfig/index.xml [main] [ 2019-08-21 22:13:26.396 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread main m_count=1 [main] [ 2019-08-21 22:13:26.396 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread main m_count=1 [main] [ 2019-08-21 22:13:26.397 AST ] [ClusterConfig.block:610] block called by thread main commandNum 1 [main] [ 2019-08-21 22:13:26.397 AST ] [Semaphore.acquire:109] ClientResource Constructor:Blocking Semaphore owned by main:Acquire called by thread main m_count=0 [Thread-48] [ 2019-08-21 22:13:26.397 AST ] [Trace.nativeOut:838] 2019-08-21 22:13:26.388: [ CSSCLNT][2]clsssInitNative 2019-08-21 22:13:26.388: [ CSSCLNT][2]clsssInitNative: proplist len 16 properties - 1,2,3,4,5,6,7 2019-08-21 22:13:26.391: [ CSSCLNT][2]clsssConnect: Connect to CSSD completed, endpt 1b 2019-08-21 22:13:26.391: [ CSSCLNT][2]clsssConnect: CSS daemon not up (1b) 2019-08-21 22:13:26.392: [ CSSCLNT][2]clsssConnect: gipcDestroy 0 2019-08-21 22:13:26.392: [ CSSCLNT][2]clsssInitNative: CSS daemon in (ADDRESS=(PROTOCOL=ipc)(KEY=OCSSD_LL_testdb1_)) not up 2019-08-21 22:13:26.392: [ CSSCLNT][2]clssgsAttrInit:attrdesc grpcount=6 mbrcount 8 2019-08-21 22:13:26.392: [ CSSCLNT][2]clsssterm: terminating gbl ctx 1216200 2019-08-21 22:13:26.392: [ CSSCLNT][2]clsss_gterm: terminating connection 2019-08-21 22:13:26.392: [ CSSCLNT][2]clsss_gterm: destroying GIPC ctx 2019-08-21 22:13:26.392: [ CSSCLNT][2]clsss_gterm: Shutting down GIPC 2019-08-21 22:13:26.393: [ CSSCLNT][2]clsss_gterm: Completing LSF cleanup 2019-08-21 22:13:26.393: [ CSSCLNT][2]clsss_gterm: Completing LPM cleanu [Worker 3] [ 2019-08-21 22:13:26.398 AST ] [Semaphore.release:85] SyncBufferEmpty:Release called by thread Worker 3 m_count=1 [Worker 3] [ 2019-08-21 22:13:26.398 AST ] [UnixSystem.copyFile:1084] Copy file localnode:/u01/app/grid/crsdata/@global/crsconfig/index.xml to testdb2:/u01/app/grid/crsdata/@global/crsconfig/index.xml [Worker 3] [ 2019-08-21 22:13:26.399 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [Worker 3] [ 2019-08-21 22:13:26.399 AST ] [UnixSystem.remoteCopyFile:808] Copying files localnode/u01/app/grid/crsdata/@global/crsconfig/index.xml testdb2/u01/app/grid/crsdata/@global/crsconfig/index.xml [Worker 3] [ 2019-08-21 22:13:26.400 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [Worker 3] [ 2019-08-21 22:13:26.400 AST ] [UnixSystem.remoteCopyFile:826] UnixSystem: /usr/bin/scp -p /u01/app/grid/crsdata/@global/crsconfig/index.xml testdb2:'/u01/app/grid/crsdata/@global/crsconfig/index.xml' [Worker 3] [ 2019-08-21 22:13:26.409 AST ] [RuntimeExec.runCommand:269] runCommand: Waiting for the process [Thread-50] [ 2019-08-21 22:13:26.426 AST ] [StreamReader.run:62] In StreamReader.run [Thread-49] [ 2019-08-21 22:13:26.428 AST ] [StreamReader.run:62] In StreamReader.run [Worker 3] [ 2019-08-21 22:13:26.654 AST ] [RuntimeExec.runCommand:271] runCommand: process returns 0 [Worker 3] [ 2019-08-21 22:13:26.655 AST ] [RuntimeExec.runCommand:297] RunTimeExec: error> [Worker 3] [ 2019-08-21 22:13:26.655 AST ] [RuntimeExec.runCommand:323] Returning from RunTimeExec.runCommand [Worker 3] [ 2019-08-21 22:13:26.655 AST ] [NativeSystem.isCmdScv:547] isCmdScv: cmd=[/usr/bin/scp -p /u01/app/grid/crsdata/@global/crsconfig/index.xml testdb2:'/u01/app/grid/crsdata/@global/crsconfig/index.xml'] [Worker 3] [ 2019-08-21 22:13:26.656 AST ] [NativeSystem.isCmdScv:597] isCmdScv: /usr/bin/scp is present. [Worker 3] [ 2019-08-21 22:13:26.656 AST ] [NativeSystem.isCmdScv:599] isCmdScv: /usr/bin/scp is a file. [Worker 3] [ 2019-08-21 22:13:26.657 AST ] [NativeSystem.isCmdScv:616] isCmdScv: returned true [Worker 3] [ 2019-08-21 22:13:26.657 AST ] [NativeSystem.rununixcmd:1283] NativeSystem.rununixcmd: RetString 1| :successful [Worker 3] [ 2019-08-21 22:13:26.657 AST ] [CopyCommand.execute:171] CopyCommand.execute: native copyFile returns `1| :successful' [Worker 3] [ 2019-08-21 22:13:26.657 AST ] [NativeResult.:93] NativeResult: The String obtained is1| :successful [Worker 3] [ 2019-08-21 22:13:26.658 AST ] [NativeResult.:101] The status string is: 1 [Worker 3] [ 2019-08-21 22:13:26.658 AST ] [NativeResult.:114] The result string is: :successful 1 [Worker 3] [ 2019-08-21 22:13:26.658 AST ] [CopyCommand.execute:179] The copy command failed. Details: :successful [Worker 3] [ 2019-08-21 22:13:26.658 AST ] [ClusterConfig$ExecuteCommand.returnCommandToClient:3301] returnCommandToClient; fillCount=0 is full=false [Worker 3] [ 2019-08-21 22:13:26.659 AST ] [Semaphore.acquire:109] SyncBufferEmpty:Acquire called by thread Worker 3 m_count=50 [Worker 3] [ 2019-08-21 22:13:26.659 AST ] [Semaphore.release:85] SyncBufferFull:Release called by thread Worker 3 m_count=1 [Worker 3] [ 2019-08-21 22:13:26.659 AST ] [ClientResource.getListener:157] Calling getListener [Worker 3] [ 2019-08-21 22:13:26.659 AST ] [ClusterConfig$ExecuteCommand.run:3396] Owner Thread name of the blocking Semaphore main [Worker 3] [ 2019-08-21 22:13:26.660 AST ] [ClusterConfig$ExecuteCommand.run:3404] Obtained Semaphore [Worker 3] [ 2019-08-21 22:13:26.660 AST ] [Semaphore.release:85] ClientResource Constructor:Blocking Semaphore owned by main:Release called by thread Worker 3 m_count=1 [Worker 3] [ 2019-08-21 22:13:26.660 AST ] [ClusterConfig$ExecuteCommand.run:3419] Released Semaphore by worker=Worker 3 [Worker 3] [ 2019-08-21 22:13:26.660 AST ] [Semaphore.acquire:109] SyncBufferFull:Acquire called by thread Worker 3 m_count=0 [main] [ 2019-08-21 22:13:26.663 AST ] [ClusterConfig.block:622] block acquired semnum=0 [main] [ 2019-08-21 22:13:26.663 AST ] [ClusterConfig.destroy:466] destroying resources for client thread Thread[main,5,main] [main] [ 2019-08-21 22:13:26.663 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:14:25.858 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:14:25.873 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:14:26.088 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:14:26.091 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:14:26.111 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:14:26.111 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:14:26.116 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:14:26.120 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:14:26.120 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:14:26.121 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:14:26.122 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:14:26.122 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:14:26.123 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:14:26.126 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:14:26.128 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:14:26.128 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:14:26.128 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:14:26.129 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:14:26.130 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:14:26.149 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:14:26.149 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:14:26.151 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:14:26.152 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:14:26.152 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:14:26.153 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:14:26.153 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:14:26.154 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:14:26.160 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:14:26.160 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_ACFSINST,-status [main] [ 2019-08-21 22:14:26.161 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:14:26.164 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:14:26.166 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_ACFSINST,-status [main] [ 2019-08-21 22:14:26.178 AST ] [ClusterwareCkpt.getCkptStatus:329] Checking to see if checkpoint:ROOTCRS_ACFSINSThas successfuly completed [main] [ 2019-08-21 22:14:26.188 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:14:26.205 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/testdb1/checkpoints/crsconfig/index.xml found. [main] [ 2019-08-21 22:14:26.378 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/testdb1/crsconfig/ckptGridHA_testdb1.xml [main] [ 2019-08-21 22:14:26.378 AST ] [ClusterwareCkpt.getCkptStatus:353] Reading data for checkpoint: ROOTCRS_ACFSINST [main] [ 2019-08-21 22:14:26.379 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:15:28.523 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:15:28.530 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:15:28.567 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:15:28.569 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:15:28.583 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:15:28.583 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:15:28.587 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:15:28.587 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:15:28.588 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:15:28.588 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:15:28.589 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:15:28.589 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:15:28.589 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:15:28.594 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:15:28.595 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:15:28.595 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:15:28.596 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:15:28.596 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:15:28.597 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:15:28.608 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:15:28.609 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:15:28.610 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:15:28.610 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:15:28.611 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:15:28.611 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:15:28.612 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:15:28.612 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:15:28.616 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:15:28.616 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:15:28.617 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:15:28.619 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:15:28.621 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:15:28.630 AST ] [ClusterwareCkpt.isCkptExists:308] Checking if checkpoint:ROOTCRS_FIRSTNODE exists [main] [ 2019-08-21 22:15:28.634 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:15:28.646 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml found. [main] [ 2019-08-21 22:15:28.772 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:15:28.773 AST ] [ClusterwareCkpt.isCkptExists:322] ckpt = oracle.cluster.impl.checkpoints.CheckPointImpl@13fee20c [main] [ 2019-08-21 22:15:28.774 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:15:51.355 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:15:51.362 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:15:51.397 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:15:51.399 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:15:51.412 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:15:51.412 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:15:51.416 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:15:51.418 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:15:51.418 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:15:51.418 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:15:51.419 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:15:51.420 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:15:51.420 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:15:51.422 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:15:51.424 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:15:51.424 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:15:51.424 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:15:51.424 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:15:51.425 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:15:51.437 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:15:51.437 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:15:51.438 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:15:51.439 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:15:51.439 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:15:51.439 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:15:51.440 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:15:51.440 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:15:51.444 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:15:51.444 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE,-status [main] [ 2019-08-21 22:15:51.445 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:15:51.447 AST ] [ClusterwareCkpt.executeCkpt:1105] Processing chkckpt command line arguments [main] [ 2019-08-21 22:15:51.449 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-global,-oraclebase,/u01/app/grid,-chkckpt,-name,ROOTCRS_FIRSTNODE,-status [main] [ 2019-08-21 22:15:51.458 AST ] [ClusterwareCkpt.getCkptStatus:329] Checking to see if checkpoint:ROOTCRS_FIRSTNODEhas successfuly completed [main] [ 2019-08-21 22:15:51.463 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:15:51.475 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/crsdata/@global/crsconfig/index.xml found. [main] [ 2019-08-21 22:15:51.600 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/@global/crsconfig/ckptGridHA_global.xml [main] [ 2019-08-21 22:15:51.601 AST ] [ClusterwareCkpt.getCkptStatus:353] Reading data for checkpoint: ROOTCRS_FIRSTNODE [main] [ 2019-08-21 22:15:51.602 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0 [main] [ 2019-08-21 22:17:44.737 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:17:44.744 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:17:44.781 AST ] [ClusterUtil.main:296] Trace enabled [main] [ 2019-08-21 22:17:44.783 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=1 [main] [ 2019-08-21 22:17:44.797 AST ] [Version.isPre:661] version to be checked 12.2.0.1.0 major version to check against 10 [main] [ 2019-08-21 22:17:44.797 AST ] [Version.isPre:672] isPre.java: Returning FALSE [main] [ 2019-08-21 22:17:44.800 AST ] [OCR.loadLibrary:333] Inside constructor of OCR [main] [ 2019-08-21 22:17:44.801 AST ] [OCR.loadLibrary:341] Going to load the ocr library [main] [ 2019-08-21 22:17:44.801 AST ] [Library.load:202] library.load [main] [ 2019-08-21 22:17:44.802 AST ] [sPlatform.isHybrid:69] osName=SunOS osArch=amd64 JVM=64 rc=false [main] [ 2019-08-21 22:17:44.802 AST ] [OCR.loadLibrary:343] loaded ocr libraries [main] [ 2019-08-21 22:17:44.803 AST ] [SRVMContext.init:115] Performing SRVM Context init. Init Counter=2 [main] [ 2019-08-21 22:17:44.803 AST ] [OCR.isCluster:1055] Calling OCRNative for isCluster() [main] [ 2019-08-21 22:17:44.807 AST ] [nativesystem.OCRNative.Native] JNI: isCluster() Successfully initialized meta context [main] [ 2019-08-21 22:17:44.809 AST ] [nativesystem.OCRNative.Native] JNI: procr_get_conf() retValue = 0 [main] [ 2019-08-21 22:17:44.809 AST ] [nativesystem.OCRNative.Native] The OCR file is configured & local_only=false [main] [ 2019-08-21 22:17:44.809 AST ] [OCR.isCluster:1059] OCR Result status = true [main] [ 2019-08-21 22:17:44.810 AST ] [OCR.isCluster:1071] Bolean result = true [main] [ 2019-08-21 22:17:44.811 AST ] [cnative.ClusterNative.Native] Native:: CLSBInit [main] [ 2019-08-21 22:17:44.823 AST ] [cnative.ClusterNative.Native] in prcr_clsb:: successfully setup callback [main] [ 2019-08-21 22:17:44.823 AST ] [SRVMContext.init:140] SRVM Context init-ed [main] [ 2019-08-21 22:17:44.824 AST ] [ClusterUtil.parseArgs:138] m_ckpt=true [main] [ 2019-08-21 22:17:44.825 AST ] [ClusterUtil.parseArgs:139] m_copy=false [main] [ 2019-08-21 22:17:44.825 AST ] [ClusterUtil.parseArgs:140] m_isshared=false [main] [ 2019-08-21 22:17:44.825 AST ] [ClusterUtil.parseArgs:141] m_exec=false [main] [ 2019-08-21 22:17:44.826 AST ] [ClusterUtil.parseArgs:142] m_rmFile=false [main] [ 2019-08-21 22:17:44.826 AST ] [ClusterUtil.parseArgs:143] m_help=false [main] [ 2019-08-21 22:17:44.830 AST ] [Utils.getLocalHost:448] Hostname retrieved: testdb1.alfarisad.local, returned: testdb1 [main] [ 2019-08-21 22:17:44.831 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-writeckpt,-name,ROOTCRS_BOOTCFG,-state,FAIL [main] [ 2019-08-21 22:17:44.831 AST ] [ClusterwareCkpt.executeCkpt:1079] Parsed Arguments [main] [ 2019-08-21 22:17:44.834 AST ] [ClusterwareCkpt.executeCkpt:1122] Processing writeckpt command line arguments [main] [ 2019-08-21 22:17:44.835 AST ] [ClusterwareCkpt.parseArgs:284] args = -ckpt,-oraclebase,/u01/app/grid,-writeckpt,-name,ROOTCRS_BOOTCFG,-state,FAIL [main] [ 2019-08-21 22:17:44.845 AST ] [ClusterwareCkpt.writeCheckPoint:544] Writing checkpoint [main] [ 2019-08-21 22:17:44.845 AST ] [ClusterwareCkpt.writeCheckPoint:545] Ckpt Name: ROOTCRS_BOOTCFG [main] [ 2019-08-21 22:17:44.845 AST ] [ClusterwareCkpt.writeCheckPoint:546] Ckpt Desc: null [main] [ 2019-08-21 22:17:44.846 AST ] [ClusterwareCkpt.writeCheckPoint:547] Ckpt Level: null [main] [ 2019-08-21 22:17:44.846 AST ] [ClusterwareCkpt.writeCheckPoint:548] Ckpt State: FAIL [main] [ 2019-08-21 22:17:44.847 AST ] [ClusterwareCkpt.writeCheckPoint:552] after assert of checkpoint name [main] [ 2019-08-21 22:17:44.851 AST ] [CheckPointFactory.getIndexSession:92] Checkpoint:getting indexSession from checkpoint factory [main] [ 2019-08-21 22:17:44.868 AST ] [CheckPointIndexSessionImpl.:98] Checkpoint:Index file :/u01/app/grid/testdb1/checkpoints/crsconfig/index.xml found. [main] [ 2019-08-21 22:17:45.118 AST ] [ClusterwareCkpt.writeCheckPoint:567] ckpt debug 1 [main] [ 2019-08-21 22:17:45.118 AST ] [ClusterwareCkpt.getCkptFileLoc:274] ckpt file location is /u01/app/grid/crsdata/testdb1/crsconfig/ckptGridHA_testdb1.xml [main] [ 2019-08-21 22:17:45.119 AST ] [ClusterwareCkpt.writeCheckPoint:570] ckpt debug 2 [main] [ 2019-08-21 22:17:45.120 AST ] [ClusterwareCkpt.writeCheckPoint:574] ckpt debug 3 [main] [ 2019-08-21 22:17:45.120 AST ] [ClusterwareCkpt.writeCheckPoint:586] Setting checkpoint state to: 2 [main] [ 2019-08-21 22:17:45.121 AST ] [ClusterwareCkpt.writeCheckPoint:590] ckpt debug 4 [main] [ 2019-08-21 22:17:45.121 AST ] [ClusterwareCkpt.writeCheckPoint:595] ckpt debug 5 [main] [ 2019-08-21 22:17:45.179 AST ] [CheckPointSessionImpl.getAllFailedCheckPoints:306] Checkpoint:Failed Checkpoint found returning it for getAllFailedCheckPoints. [main] [ 2019-08-21 22:17:45.188 AST ] [CheckPointSessionImpl.saveCheckPointSession:143] Checkpoint:Index file written and updated [main] [ 2019-08-21 22:17:45.189 AST ] [ClusterwareCkpt.writeCheckPoint:599] ckpt debug 6 [main] [ 2019-08-21 22:17:45.196 AST ] [ClusterUtil.main:333] ClusterUtil.execute rc: 0