Saturday, July 18, 2020

Oracle database 19c "srvctl status service" fails with Java.lang.NullPointerException

The following errors occur while running "srvctl status service -db <db_name>" command from 19.7 database home on AIX and Linux x86_64,
$ srvctl status service -db orcl
Exception in thread "main" java.lang.NullPointerException
        at oracle.ops.opsctl.StatusAction.internalExecuteService(StatusAction.java:2077)
        at oracle.ops.opsctl.StatusAction.executeSIHAService(StatusAction.java:1692)
        at oracle.ops.opsctl.Action.executeSIHA(Action.java:445)
        at oracle.ops.opsctl.OPSCTLDriver.execute(OPSCTLDriver.java:537)
        at oracle.ops.opsctl.OPSCTLDriver.main(OPSCTLDriver.java:252)

It was reported as 19c bug 29839229 from 19.1 until 19.5. To confirm bug 29839229 is fixed in 19.7,
$ $ORACLE_HOME/OPatch/opatch lsinventory -bugs_fixed | grep 29839229
29839229   30894985  Mon Jul 13 17:00:03 EDT 2020   SRVCTL STATUS SERVICE -D DB FAILES IN 19C WITH

However, same error message still occurs in 19.7, but it is reported as a new bug 31414282 instead of 29839229.

Enable trace to get more details,
$ export SRVM_TRACE=true
$ export SRVCTL_TRACEFILE=/tmp/srvctl.trc
$
$ srvctl status service -db orcl

Environment variable SRVM_TRACE is set to true to enable trace option of srvctl.

When environment variable SRVCTL_TRACEFILE is configured, srvctl will redirect output to specified file.

Check trace file /tmp/srvctl.trc, will find following message
[main] [ 2020-07-17 22:34:31.827 EDT ] [ServiceArgs.setServiceType:230]  set serviceType to MAIN
[main] [ 2020-07-17 22:34:31.827 EDT ] [ServiceArgs.setServiceType:230]  set serviceType to MAIN
[main] [ 2020-07-17 22:34:31.829 EDT ] [CRSCache.getAttributesFromCRS:155]  CRS: name: ora.orcl.dbservice.svc, type 1, node: null
[main] [ 2020-07-17 22:34:31.830 EDT ] [CRSCache.getAttributesFromCRS:156]  attrs: [SERVER_POOLS]
[main] [ 2020-07-17 22:34:31.840 EDT ] [CRSCache.getAttributesFromCRS:163]  CRS: [<SERVER_POOLS:>]
[main] [ 2020-07-17 22:34:31.842 EDT ] [ServiceImpl.getServiceCardinality:3437]  value of SERVER_POOLS attr :
[main] [ 2020-07-17 22:34:31.843 EDT ] [CRSCache.getAttributesFromCRS:155]  CRS: name: ora.orcl.dbservice.svc, type 1, node: null
[main] [ 2020-07-17 22:34:31.844 EDT ] [CRSCache.getAttributesFromCRS:156]  attrs: [CARDINALITY]
[main] [ 2020-07-17 22:34:31.859 EDT ] [CRSCache.getAttributesFromCRS:163]  CRS: [<CARDINALITY:1>]
[main] [ 2020-07-17 22:34:31.860 EDT ] [ServiceImpl.getServiceCardinality:3447]  value of CARDINALITY attr : 1
[main] [ 2020-07-17 22:34:31.861 EDT ] [ServiceImpl.getServiceCardinality:3474]  this is a SIHA service
[main] [ 2020-07-17 22:34:31.876 EDT ] [CRSCache.getAttributesFromCache:229]  CRS cache: ora.orcl.db [<DATABASE_TYPE:SINGLE>]
[main] [ 2020-07-17 22:34:31.879 EDT ] [CRSCache.getAttributesFromCRS:155]  CRS: name: ora.orcl.db, type 1, node: null
[main] [ 2020-07-17 22:34:31.879 EDT ] [CRSCache.getAttributesFromCRS:156]  attrs: [HOSTING_MEMBERS]
[main] [ 2020-07-17 22:34:31.893 EDT ] [CRSCache.getAttributesFromCRS:163]  CRS: [<HOSTING_MEMBERS:>]  
[main] [ 2020-07-17 22:34:31.894 EDT ] [CRSCache.getAttributesFromCRS:155]  CRS: name: ora.orcl.db, type 1, node: null
[main] [ 2020-07-17 22:34:31.895 EDT ] [CRSCache.getAttributesFromCRS:156]  attrs: [SERVER_POOLS]
[main] [ 2020-07-17 22:34:31.906 EDT ] [CRSCache.getAttributesFromCRS:163]  CRS: [<SERVER_POOLS:>]
Exception in thread "main"
java.lang.NullPointerException
        at oracle.ops.opsctl.StatusAction.internalExecuteService(StatusAction.java:2077)
        at oracle.ops.opsctl.StatusAction.executeSIHAService(StatusAction.java:1692)
        at oracle.ops.opsctl.Action.executeSIHA(Action.java:445)
        at oracle.ops.opsctl.OPSCTLDriver.execute(OPSCTLDriver.java:537)
        at oracle.ops.opsctl.OPSCTLDriver.main(OPSCTLDriver.java:252)
[Thread-10] [ 2020-07-17 22:34:31.943 EDT ] [InnerInterruptHandler.run:116]  Running the shutdown hook
[Thread-10] [ 2020-07-17 22:34:31.945 EDT ] [InnerInterruptHandler.run:120]  Calling Interrupt handler....ctrlCHandler
[Finalizer thread] [ 2020-07-17 22:34:31.946 EDT ] [Util.finalize:136]  Util: finalized called for oracle.ops.mgmt.has.Util@c6714395
[Thread-10] [ 2020-07-17 22:34:31.946 EDT ] [CommandLineParser.<init>:506]  Is this a cluster? : false
[Thread-10] [ 2020-07-17 22:34:31.949 EDT ] [OPSCTLDriver.ctrlCHandler:306]  Stopped srvctl execution

The message indicates the procedure in which srvctl retrieves the configuration/status information of service dbservice (CRS resource name is ora.orcl.dbservice.svc) created in database orcl (CRS resource name is ora.orcl.db). The exceptional messge line is
[main] [ 2020-07-17 22:34:31.893 EDT ] [CRSCache.getAttributesFromCRS:163]  CRS: [<HOSTING_MEMBERS:>]  

Here, HOSTING_MEMBERS is expected to be followed by host name of current server, it should be something like following,
[main] [ 2020-07-17 22:34:31.893 EDT ] [CRSCache.getAttributesFromCRS:163]  CRS: [<HOSTING_MEMBERS:host01>]  

Surely the patch 31414282 can help fix this issue on AIX and Linux x86_64 platform. The bug is also seen on Solaris Sparc 64.

No comments: