OK, worked out to increase logging level of some components (thanks to
Martin Bach's blog).
Drilled down to the exception below.
Note I don't think the "select cdb from v$database" is the giving the
exception (it runs fine from SQLPlus).
Maybe I can identify what the failing SQL is via SQL trace somehow?
2016-06-15 16:06:52.875102 : USRTHRD:4074: {0:0:819}
DbAgent::DedicatedThread::run setLocalListener Exception
OCRCtxCreateException
2016-06-15 16:06:52.875141 : USRTHRD:4074: {0:0:819}
DbAgent::DedicatedThread::run setLocalListenrPCW Internal Error: Ocr
Context creation failed:
2016-06-15 16:06:52.880215 : USRTHRD:4074: {0:0:819} ORA-01405: fetched
column value is NULL
2016-06-15 16:06:52.880287 : USRTHRD:4074: {0:0:819}
InstConnection::queryValueFromVParameter OCI exception [1405]ORA-01405:
fetched column value is NULL
2016-06-15 16:06:52.880352 : USRTHRD:4074: {0:0:819} Agent::getResName
resName:12cf0c58 ora.xtso.db
2016-06-15 16:06:52.880373 : USRTHRD:4074: {0:0:819} CrsCmd::CrsCmd
constructor 2 resname:ora.xtso.db
2016-06-15 16:06:52.880393 : USRTHRD:4074: {0:0:819} CrsCmd::CrsCmd
constructor 2 m_pAgent:12cf0a88
2016-06-15 16:06:52.880568 : USRTHRD:4074: {0:0:819} Agent::getResName
resName:12cf0c58 ora.xtso.db
2016-06-15 16:06:52.880591 : USRTHRD:4074: {0:0:819} CrsCmd::ClscrsCmdData
constructor 2
On 15 June 2016 at 11:19, Patrick Jolliffe <jolliffe@xxxxxxxxx> wrote:
Clusterware performing "ALTER SYTEM REGISTER" on database every minute
DB and GI (non RAC - restart only) on 12.1.0.2 April 2016 PSU, running on
AIX 7.2 (!).
We have sys auditing enabled, and I have noticed from audit trail, that
every minute, GI use connects to database and performs the following:
ACTION :[7] 'CONNECT'
ACTION :[26] 'select cdb from v$database'
ACTION :[59] 'ALTER SESSION SET EVENTS '10165 TRACE NAME CONTEXT FOREVER''
ACTION :[39] 'ALTER SESSION SET "_notify_crs" = false'
ACTION :[21] 'ALTER SYSTEM REGISTER'
ACTION :[53] 'BEGIN DBMS_SESSION.USE_DEFAULT_EDITION_DEFERRED; END;'
Identified the relevant section in ohasd_oraagent_grid.trc file that seems
to correspond to this, extract below.
I have just filtered out entries from non-relevent threads.
Note the connectstr built seems fine (I can connect via sqlplus with it),
which also seems to be confirmed by the fact it does actually seem to
connect to perform registration.
Any ideas what the "OCR Context Creation" refers to and why it might
fail?
Or how to enable additional trace for this component - found some
documnetation/blogs about additional trace, but I can't work out which
component this might be.
Support have been going round in circles on this, and I'm not making much
progess either.
Suspect is AIX bug, wonder how many using restart with AIX, but could be
wrong.
TIA for any ideas,
Patrick
2016-06-15 03:59:19.612849 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::run {
2016-06-15 03:59:19.612971 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::run getConnxn
2016-06-15 03:59:19.613204 : USRTHRD:3860: {0:0:819} DbAgent:getConnection
oracleHome:/u01/app/oracle/product/12.1.0.2/dbhome oracleSid:XTSO
usrOraEnv: resVersion:12.1.0.2.0
2016-06-15 03:59:19.613269 : USRTHRD:3860: {0:0:819}
InstConnection:InstConnection: init:11de8330
oracleHome:/u01/app/oracle/product/12.1.0.2/dbhome oracleSid:XTSO
instanceT
ype:1 instanceVersion:12.1.0.2.0
2016-06-15 03:59:19.613689 : USRTHRD:3860: {0:0:819}
clsnInstConnection::makeConnectStr UsrOraEnv ,ORACLE_BASE= m_oracleHome
/u01/app/oracle/product/12.1.0.2/dbhome Crshome
/u01/app/12.1.0/grid
2016-06-15 03:59:19.613765 : USRTHRD:3860: {0:0:819}
clsnInstConnection::makeConnectStr LIBPATH ,LIBPATH=/u01/app/oracle/product/
12.1.0.2/dbhome/lib
2016-06-15 03:59:19.613879 : USRTHRD:3860: {0:0:819} makeConnectStr =
(DESCRIPTION=(ADDRESS=(PROTOCOL=beq)(PROGRAM=/u01/app/oracle/product/
12.1.0.2/dbhome/bin/oracle)(ARGV0=
oracleXTSO)(ENVS='ORACLE_HOME=/u01/app/oracle/product/
12.1.0.2/dbhome,ORACLE_SID=XTSO,LD_LIBRARY_PATH=,LIBPATH=,LIBPATH=/u01/app/oracle/product/12.1.0.2/dbhome/lib,ORACLE_BA
SE=')(ARGS='(DESCRIPTION=(LOCAL=YES)(ADDRESS=(PROTOCOL=beq)))')(CONNECT_DATA=(SID=XTSO))))
2016-06-15 03:59:19.614488 : USRTHRD:3860: {0:0:819}
InstConnection::connectInt: server not attached
2016-06-15 03:59:19.690172 : USRTHRD:3860: {0:0:819}
InstConnection:connectInt connected
2016-06-15 03:59:19.695114 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::setLocalListener entry
2016-06-15 03:59:19.718869 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::run setLocalListener Exception
OCRCtxCreateException
2016-06-15 03:59:19.718910 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::run setLocalListenrPCW Internal Error: Ocr
Context creation failed:
2016-06-15 03:59:24.719671 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::run ALTER SYSTEM REGISTER
2016-06-15 03:59:24.720091 : USRTHRD:3860: {0:0:819}
InstConnection:~InstConnection: this 11de8330
2016-06-15 03:59:24.721133 : USRTHRD:3860: {0:0:819}
DbAgent::DedicatedThread::run exit }
2016-06-15 03:59:24.721159 : USRTHRD:3860: {0:0:819}
Thread:DedicatedThread isRunning is reset to false here
