My Oracle Support Banner

ACFS-05020: ACFS acfsutil repl init primary failed due to cannot start replication daemons (Doc ID 2411590.1)

Last updated on AUGUST 04, 2018

Applies to:

Oracle Database - Enterprise Edition - Version 12.2.0.1 and later
Information in this document applies to any platform.

Symptoms

ACFS Replication not starting on a primary node due to the following errors.

 

On the Primary node,

crggdboraprd11 $ sudo -E /usr/sbin/acfsutil repl info -c -u oragrid crgg-prd2-gg /u02/ogg_shared
A valid 'ssh' connection was detected for standby node crgg-prd2-gg as user oragrid.

crggdboraprd11 $ sudo -E /usr/sbin/acfsutil repl init primary -i 15m -s oragrid@crgg-prd2-gg /u02/ogg_shared
acfsutil repl init: ACFS-05020: cannot start replication daemons                            
acfsutil repl init: ACFS-05020: cannot start replication daemons

crggdboraprd11 $ ps -ef|grep repl
root 15598334 1 0 21:07:29 - 0:00 /u01/grid/12.2.0/grid/bin/acfsrepl_dupd.bin /u02/ogg_shared

crggdboraprd11 $ sudo -E /usr/sbin/acfsutil repl bg info /u02/ogg_shared
acfsutil repl bg: ACFS-05014: cannot verify replication configuration

crggdboraprd11 $ crsctl stat res -t |grep repl
<return nothing>

crggdboraprd11 $ sudo -E /usr/sbin/acfsutil repl info -c -v /u02/ogg_shared
<return nothing>

crggdboraprd11 $ sudo -E /usr/sbin/acfsutil repl info /u02/ogg_shared
Time: Tue Jun 12 21:07:31 2018
Event: Error
Severity: 0
Message: repl init primary failed

Time: Tue Jun 12 21:07:30 2018
Transfer completed at: Tue Jun 12 21:07:30 2018
Transfer status: 0

Time: Tue Jun 12 21:07:30 2018
Event: Clone created
Session started at: Tue Jun 12 21:07:30 2018
Session ended at: Tue Jun 12 21:07:30 2018
Number of bytes transmitted: 20759

Time: Tue Jun 12 21:07:30 2018
Create completed at: Tue Jun 12 21:07:30 2018
Create status: 0

Time: Tue Jun 12 21:07:30 2018
Create started at: Tue Jun 12 21:07:30 2018

Time: Tue Jun 12 21:07:30 2018
Transfer started at: Tue Jun 12 21:07:30 2018

Number of Events: 6

crggdboraprd11 $ ls -l /u02/ogg_shared/.ACFS/repl/ready
total 0
-rwxr-xr-x 1 root system 0 Jun 12 21:07 CreateRunning*
-rwxr-xr-x 1 root system 0 Jun 12 21:07 DupdRunning*

----------------------------------------------------------------------------------

On Standby node,

crggdboraprd21 $ sudo -E /usr/sbin/acfsutil repl bg info /u02/ogg_shared
acfsutil repl bg: ACFS-05058: command issued on the incorrect replication site

crggdboraprd21 $ sudo -E /usr/sbin/acfsutil repl info -c -v /u02/ogg_shared
Primary hostname: crggdboraprd11
Primary path: /u02/ogg_shared

Standby connect string: oragrid@crgg-prd2-gg
Standby path: /u02/ogg_shared
Replication interval: 0 days, 0 hours, 15 minutes, 0 seconds
Last sync time with primary: Tue Jun 12 21:07:29 2018
Receiving primary as of: Tue Jun 12 21:07:29 2018
Status: Receive Completed
Last receive started at: Tue Jun 12 21:07:30 2018
Last receive completed at: Tue Jun 12 21:07:30 2018
Elapsed time for last receive: 0 days, 0 hours, 0 minutes, 0 seconds
Data transfer compression: Off
ssh strict host key checking: On
Debug log level: 3

crggdboraprd21 $ $ sudo -E /usr/sbin/acfsutil repl info /u02/ogg_shared
Time: Tue Jun 12 21:07:30 2018
Apply completed at: Tue Jun 12 21:07:30 2018

Time: Tue Jun 12 21:07:30 2018
Event: Clone applied
Session started at: Tue Jun 12 21:07:30 2018
Session ended at: Tue Jun 12 21:07:30 2018
Number of bytes applied: 20759

Time: Tue Jun 12 21:07:30 2018
Apply started at: Tue Jun 12 21:07:30 2018

Time: Tue Jun 12 20:59:08 2018
Event: Replication Initialization Started
Initialization Start Time: Tue Jun 12 20:59:08 2018

Number of Events: 4

crggdboraprd21 $ ls -l /u02/ogg_shared/.ACFS/repl/ready
total 0
-rw-rw---- 1 oragrid dba 0 Jun 12 21:07 ApplyRunning

 

/u01/app/oracle/diag/crs/crggdboraprd11/crs/trace/acfsutil_14287172.trc:

Oracle Database 12c Clusterware Release 12.2.0.1.0 - Production Copyright 1996, 2016 Oracle. All rights reserved.

2018-05-22 12:21:24.051 :REPLINIT:1: [14287172] Start: /usr/sbin/acfsutil.bin repl init primary -i 1h -s oragrid@crgg-prd2-gg /u02/ogg_shared

2018-05-22 12:21:24.053 :REPLINIT:1: [14287172]Unable to set logfile owner permissions for /u01/app/oracle/diag/crs/crggdboraprd11/crs/trace/acfsutil_14287172.trc

2018-05-22 12:21:24.054 :REPLINIT:1: [14287172]uscgCtxInit: Set tracing level: 3

2018-05-22 12:21:24.080 :REPLINIT:1: [14287172]usrgeVerifyStandbyV2: Entered. stbyhost=crgg-prd2-gg, stbyuser=oragrid, USC_RACSTBYMP=/u02/ogg_shared, USC_RACSTBYSNAP=, flags=0x8

2018-05-22 12:21:24.080 :REPLINIT:1: [14287172]usrgeVerifyStandbyV2: acfsutil path set to /sbin/acfsutil

2018-05-22 12:21:24.080 :REPLINIT:1: [14287172]uscgInvokeCommand: invoking '/usr/sbin/ping -c 1 -w 3 crgg-prd2-gg > /dev/null 2>&1'

2018-05-22 12:21:24.163 :REPLINIT:1: [14287172]usrgeVerifyStandbyV2: ping standby OK (/usr/sbin/ping -c 1 -w 3 crgg-prd2-gg > /dev/null 2>&1)

2018-05-22 12:21:24.163 :REPLINIT:1: [14287172]uscgInvokeCommand: invoking '/usr/bin/ssh -o Ciphers=aes128-ctr -o BatchMode=true -x oragrid@crgg-prd2-gg "/bin/sh -c 'true'" >> /usr/tmp/oracle_ssh.out 2>&1'

2018-05-22 12:21:24.734 :REPLINIT:1: [14287172]usrgeVerifyStandbyV2: ssh to standby OK (/usr/bin/ssh -o Ciphers=aes128-ctr -o BatchMode=true -x oragrid@crgg-prd2-gg "/bin/sh -c 'true'" >> /usr/tmp/oracle_ssh.out 2>&1)

2018-05-22 12:21:24.734 :REPLINIT:1: [14287172]uscgInvokeCommand: invoking '/usr/bin/ssh -o Ciphers=aes128-ctr -o BatchMode=true -x oragrid@crgg-prd2-gg "/bin/sh -c '/sbin/acfsutil repl info -c /u02/ogg_shared >/dev/null'"'

2018-05-22 12:21:25.438 :REPLINIT:1: [14287172]usrgeVerifyStandbyV2: repl is initialized (/usr/bin/ssh -o Ciphers=aes128-ctr -o BatchMode=true -x oragrid@crgg-prd2-gg "/bin/sh -c '/sbin/acfsutil repl info -c /u02/ogg_shared >/dev/null'")

2018-05-22 12:21:25.561 :GIPCXCPT:1: gipcInternalSetAttribute: failed during gipcInternalSetAttribute, ret gipcretInvalidAttribute (5)

2018-05-22 12:21:25.561 :GIPCXCPT:1: gipcSetAttributeNativeF [clscrsconGipcConnect : clscrscon.c : 655]: EXCEPTION[ ret gipcretInvalidAttribute (5) ] failure for obj 11041f4b0 [0000000000000046] { gipcEndpoint : localAddr '', remoteAddr '', numPend 0, numReady 0, numDone 0, numDead 0, numTransfer 0, objFlags 0x0, pidPeer 0, readyRef 0, ready 0, wobj 0, sendp 0 status 13flags 0x20000000, flags-2 0x0, usrFlags 0x0 }, name 'traceLevel', val ffffffffffed170, len 4, flags 0x0

2018-05-22 12:21:25.594 :GIPCXCPT:1: gipcInternalSetAttribute: failed during gipcInternalSetAttribute, ret gipcretInvalidAttribute (5)

2018-05-22 12:21:25.594 :GIPCXCPT:1: gipcSetAttributeNativeF [clscrsconGipcConnect : clscrscon.c : 655]: EXCEPTION[ ret gipcretInvalidAttribute (5) ] failure for obj 1103dbbf0 [00000000000000ca] { gipcEndpoint : localAddr '', remoteAddr '', numPend 0, numReady 0, numDone 0, numDead 0, numTransfer 0, objFlags 0x0, pidPeer 0, readyRef 0, ready 0, wobj 0, sendp 0 status 13flags 0x20000000, flags-2 0x0, usrFlags 0x0 }, name 'traceLevel', val fffffffffffb080, len 4, flags 0x0

2018-05-22 12:21:27.745 :REPLINIT:1: acfsutil repl init: ACFS-05020: cannot start replication daemons

2018-05-22 12:21:27.745 :REPLINIT:1: [14287172]usrgcrsStartProc: usrgcrsStart() failed. Ret=0

2018-05-22 12:21:27.745 :REPLINIT:1: acfsutil repl init: ACFS-05020: cannot start replication daemons

2018-05-22 12:21:29.349 :REPLINIT:1: [14287172]uscgLogbookWriteV2: Entering mntpt= /u02/ogg_shared, rectype = 5, size = 48

2018-05-22 12:21:29.386 :REPLINIT:1: [14287172]uscgRemoveReplV2Snaps: entered, deleting primary snaps, searchstring = REPL_BASEFS_*

2018-05-22 12:21:29.389 :REPLINIT:1: [14287172]uscgInvokeCommand: invoking '/sbin/acfsutil snap delete -R -S REPL_BASEFS_1527016887 /u02/ogg_shared 2> /dev/null'

2018-05-22 12:21:29.817 :REPLINIT:1: [14287172] Returned: 1

 

Changes

 

Cause

To view full details, sign in with your My Oracle Support account.

Don't have a My Oracle Support account? Click to get started!


My Oracle Support provides customers with access to over a million knowledge articles and a vibrant support community of peers and Oracle experts.