Infrastructure at your Service

I have recently faced an issue deleting database on an ODA. I was getting following error whatever database I wanted to delete : DCS-10001:Internal error encountered: null.

Through this blog, I would like to share with you my experience on this case hoping it will help you if you are facing same problem. On this project I was using ODA Release 18.5 and 18.8 and faced the same problem on both versions. On 18.3 and previous releases this was not the case.

Deleting the database

With odacli I tried to delete my TEST database, running following commands :

[[email protected] bin]# odacli delete-database -in TEST -fd
{
"jobId" : "bcdcbf59-0fe6-44b7-af7f-91f68c7697ed",
"status" : "Running",
"message" : null,
"reports" : [ {
"taskId" : "TaskZJsonRpcExt_858",
"taskName" : "Validate db d6542252-dfa4-47f9-9cfc-22b4f0575c51 for deletion",
"taskResult" : "",
"startTime" : "May 06, 2020 11:36:38 AM CEST",
"endTime" : "May 06, 2020 11:36:38 AM CEST",
"status" : "Success",
"taskDescription" : null,
"parentTaskId" : "TaskSequential_856",
"jobId" : "bcdcbf59-0fe6-44b7-af7f-91f68c7697ed",
"tags" : [ ],
"reportLevel" : "Info",
"updatedTime" : "May 06, 2020 11:36:38 AM CEST"
} ],
"createTimestamp" : "May 06, 2020 11:36:38 AM CEST",
"resourceList" : [ ],
"description" : "Database service deletion with db name: TEST with id : d6542252-dfa4-47f9-9cfc-22b4f0575c51",
"updatedTime" : "May 06, 2020 11:36:38 AM CEST"
}

The job was failing with DCS-10001 Error :

[[email protected] bin]# odacli describe-job -i "bcdcbf59-0fe6-44b7-af7f-91f68c7697ed"
 
Job details
----------------------------------------------------------------
ID: bcdcbf59-0fe6-44b7-af7f-91f68c7697ed
Description: Database service deletion with db name: TEST with id : d6542252-dfa4-47f9-9cfc-22b4f0575c51
Status: Failure
Created: May 6, 2020 11:36:38 AM CEST
Message: DCS-10001:Internal error encountered: null.
 
Task Name Start Time End Time Status
---------------------------------------- ----------------------------------- ----------------------------------- ----------
database Service deletion for d6542252-dfa4-47f9-9cfc-22b4f0575c51 May 6, 2020 11:36:38 AM CEST May 6, 2020 11:36:50 AM CEST Failure
database Service deletion for d6542252-dfa4-47f9-9cfc-22b4f0575c51 May 6, 2020 11:36:38 AM CEST May 6, 2020 11:36:50 AM CEST Failure
Validate db d6542252-dfa4-47f9-9cfc-22b4f0575c51 for deletion May 6, 2020 11:36:38 AM CEST May 6, 2020 11:36:38 AM CEST Success
Database Deletion May 6, 2020 11:36:39 AM CEST May 6, 2020 11:36:39 AM CEST Success
Unregister Db From Cluster May 6, 2020 11:36:39 AM CEST May 6, 2020 11:36:39 AM CEST Success
Kill Pmon Process May 6, 2020 11:36:39 AM CEST May 6, 2020 11:36:39 AM CEST Success
Database Files Deletion May 6, 2020 11:36:39 AM CEST May 6, 2020 11:36:40 AM CEST Success
Deleting Volume May 6, 2020 11:36:47 AM CEST May 6, 2020 11:36:50 AM CEST Success
database Service deletion for d6542252-dfa4-47f9-9cfc-22b4f0575c51 May 6, 2020 11:36:50 AM CEST May 6, 2020 11:36:50 AM CEST Failure

Troubleshooting

In the dcs-agent.log, located in /opt/oracle/dcs/log folder, you might see following errors :

2019-11-27 13:54:30,106 ERROR [database Service deletion for 89e11f5d-9789-44a3-a09d-2444f0fda99e : JobId=05a2d017-9b64-4e92-a7df-3ded603d0644] [] c.o.d.c.j.JsonRequestProcessor: RPC request invocation failed on request: {"classz":"com.oracle.dcs.agent.rpc.service.dataguard.DataguardActions","method":"deleteListenerEntry","params":[{"type":"com.oracle.dcs.agent.model.DB","value":{"updatedTime":1573023492194,"id":"89e11f5d-9789-44a3-a09d-2444f0fda99e","name":"TEST","createTime":1573023439244,"state":{"status":"CONFIGURED"},"dbName":"TEST","databaseUniqueName":"TEST_RZB","dbVersion":"11.2.0.4.190115","dbHomeId":"c58cdcfd-e5b2-4041-b993-8df5a5d5ada4","dbId":null,"isCdb":false,"pdBName":null,"pdbAdminUserName":null,"enableTDE":false,"isBcfgInSync":null,"dbType":"SI","dbTargetNodeNumber":"0","dbClass":"OLTP","dbShape":"odb1","dbStorage":"ACFS","dbOnFlashStorage":false,"level0BackupDay":"sunday","instanceOnly":true,"registerOnly":false,"rmanBkupPassword":null,"dbEdition":"SE","dbDomainName":"ksbl.local","dbRedundancy":null,"dbCharacterSet":{"characterSet":"AL32UTF8","nlsCharacterset":"AL16UTF16","dbTerritory":"AMERICA","dbLanguage":"AMERICAN"},"dbConsoleEnable":false,"backupDestination":"NONE","cloudStorageContainer":null,"backupConfigId":null,"isAutoBackupDisabled":false}}],"revertable":false,"threadId":111}
! java.lang.NullPointerException: null
! at com.oracle.dcs.agent.rpc.service.dataguard.DataguardOperations.deleteListenerEntry(DataguardOperations.java:2258)
! at com.oracle.dcs.agent.rpc.service.dataguard.DataguardActions.deleteListenerEntry(DataguardActions.java:24)
! at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
! at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
! at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
! at java.lang.reflect.Method.invoke(Method.java:498)
! at com.oracle.dcs.commons.jrpc.JsonRequestProcessor.invokeRequest(JsonRequestProcessor.java:33)
! ... 23 common frames omitted
! Causing: com.oracle.dcs.commons.exception.DcsException: DCS-10001:Internal error encountered: null.
! at com.oracle.dcs.commons.exception.DcsException$Builder.build(DcsException.java:68)
! at com.oracle.dcs.commons.jrpc.JsonRequestProcessor.invokeRequest(JsonRequestProcessor.java:45)
! at com.oracle.dcs.commons.jrpc.JsonRequestProcessor.process(JsonRequestProcessor.java:74)
! at com.oracle.dcs.agent.task.TaskZJsonRpcExt.callInternal(TaskZJsonRpcExt.java:65)
! at com.oracle.dcs.agent.task.TaskZJsonRpc.call(TaskZJsonRpc.java:182)
! at com.oracle.dcs.agent.task.TaskZJsonRpc.call(TaskZJsonRpc.java:26)
! at com.oracle.dcs.commons.task.TaskWrapper.call(TaskWrapper.java:82)
! at com.oracle.dcs.commons.task.TaskApi.call(TaskApi.java:37)
! at com.oracle.dcs.commons.task.TaskSequential.call(TaskSequential.java:39)
! at com.oracle.dcs.commons.task.TaskSequential.call(TaskSequential.java:10)
! at com.oracle.dcs.commons.task.TaskWrapper.call(TaskWrapper.java:82)
! at com.oracle.dcs.commons.task.TaskApi.call(TaskApi.java:37)
! at com.oracle.dcs.commons.task.TaskSequential.call(TaskSequential.java:39)
! at com.oracle.dcs.agent.task.TaskZLockWrapper.call(TaskZLockWrapper.java:64)
! at com.oracle.dcs.agent.task.TaskZLockWrapper.call(TaskZLockWrapper.java:21)
! at com.oracle.dcs.commons.task.TaskWrapper.call(TaskWrapper.java:82)
! at com.oracle.dcs.commons.task.TaskApi.call(TaskApi.java:37)
! at com.oracle.dcs.commons.task.TaskSequential.call(TaskSequential.java:39)
! at com.oracle.dcs.commons.task.TaskSequential.call(TaskSequential.java:10)
! at com.oracle.dcs.commons.task.TaskWrapper.call(TaskWrapper.java:82)
! at com.oracle.dcs.commons.task.TaskWrapper.call(TaskWrapper.java:17)
! at java.util.concurrent.FutureTask.run(FutureTask.java:266)
! at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
! at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
! at java.lang.Thread.run(Thread.java:748)
2019-11-27 13:54:30,106 INFO [database Service deletion for 89e11f5d-9789-44a3-a09d-2444f0fda99e : JobId=05a2d017-9b64-4e92-a7df-3ded603d0644] [] c.o.d.a.z.DCSZooKeeper: DCS node id is - node_0
2019-11-27 13:54:30,106 DEBUG [database Service deletion for 89e11f5d-9789-44a3-a09d-2444f0fda99e : JobId=05a2d017-9b64-4e92-a7df-3ded603d0644] [] c.o.d.a.t.TaskZJsonRpc: Task[TaskZJsonRpcExt_124] RPC request 'Local:[email protected]()' completed: Failure

The key error to note would be : Local:[email protected]()’ completed: Failure

Explaination

This problem comes from the fact that the listener.ora file has been customized. As per Oracle Support, on an ODA, the listener.ora should never be customized and default listener.ora file should be used. I still have a SR opened with Oracle Support to clarify the situation as I’m fully convinced that this is a regression :

  1. It was always possible in previous ODA versions to delete a database with a customized listener file
  2. We need to customize the listener when setting Data Guard on Oracle 11.2.0.4 Version (still supported on ODA)
  3. We need to customize the listener when doing duplication as dynamic registration is not possible when the database is in nomount state and database is restarted during the duplication.

Moreover other ODA documentations are still referring customization of the listener.ora file when using ODA :
White paper : STEPS TO MIGRATE NON-CDB DATABASES TO ACFS ON ORACLE DATABASEAPPLIANCE 12.1.2
Deploying Oracle Data Guard with Oracle Database Appliance – A WhitePaper (2016-7) (Doc ID 2392307.1)

I will update the post as soon as I have some feedback from Oracle support on this.

The workaround would be to set back the default listener.ora file time of the deletion, which would request a maintenance windows for some customer.

Solution/Workaround

Backup of the current listener configuration

OK, so let’s backup our current listener configuration first :

[email protected]:/home/grid/ [+ASM1] cd $TNS_ADMIN
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] cp -p listener.ora ./history/listener.ora.20200506

Default ODA listener configuration

The backup of the default listener configuration is the following one :

[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] cat listener19071611AM2747.bak
LISTENER=(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=IPC)(KEY=LISTENER)))) # line added by Agent
ASMNET1LSNR_ASM=(DESCRIPTION=(ADDRESS_LIST=(ADDRESS=(PROTOCOL=IPC)(KEY=ASMNET1LSNR_ASM)))) # line added by Agent
ENABLE_GLOBAL_DYNAMIC_ENDPOINT_ASMNET1LSNR_ASM=ON # line added by Agent
VALID_NODE_CHECKING_REGISTRATION_ASMNET1LSNR_ASM=SUBNET # line added by Agent
ENABLE_GLOBAL_DYNAMIC_ENDPOINT_LISTENER=ON # line added by Agent
VALID_NODE_CHECKING_REGISTRATION_LISTENER=SUBNET # line added by Agent

Stopping the listener

Let’s stop the listener :

[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl stop listener -listener listener
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl status listener -listener listener
Listener LISTENER is enabled
Listener LISTENER is not running

Put default listener configuration

[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] mv listener.ora listener.ora.before_db_del_20200506
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] cp -p listener19071611AM2747.bak listener.ora

Start the listener

[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl start listener -listener listener
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl status listener -listener listener
Listener LISTENER is enabled
Listener LISTENER is running on node(s): oda01

Delete database

We will try to delete the database again by running the same odacli command :

[[email protected] bin]# odacli delete-database -in TEST -fd
{
"jobId" : "5655be19-e0fe-4452-b8a9-35382c67bf96",
"status" : "Running",
"message" : null,
"reports" : [ {
"taskId" : "TaskZJsonRpcExt_1167",
"taskName" : "Validate db d6542252-dfa4-47f9-9cfc-22b4f0575c51 for deletion",
"taskResult" : "",
"startTime" : "May 06, 2020 11:45:01 AM CEST",
"endTime" : "May 06, 2020 11:45:01 AM CEST",
"status" : "Success",
"taskDescription" : null,
"parentTaskId" : "TaskSequential_1165",
"jobId" : "5655be19-e0fe-4452-b8a9-35382c67bf96",
"tags" : [ ],
"reportLevel" : "Info",
"updatedTime" : "May 06, 2020 11:45:01 AM CEST"
} ],
"createTimestamp" : "May 06, 2020 11:45:01 AM CEST",
"resourceList" : [ ],
"description" : "Database service deletion with db name: TEST with id : d6542252-dfa4-47f9-9cfc-22b4f0575c51",
"updatedTime" : "May 06, 2020 11:45:01 AM CEST"
}

Unfortunately the deletion will fail with another error : DCS-10011:Input parameter ‘ACFS Device for delete’ cannot be NULL.

This is due to the fact that previous deletion has already removed the corresponding ACFS volume for the database (DATA and REDO). We will have to create them manually again. I have already described this solution in a previous post : Database deletion stuck in deleting-status.

After restoring the corresponding ACFS Volume, we can retry our database deletion again :

[[email protected] bin]# odacli delete-database -in TEST -fd
{
"jobId" : "5e227755-478b-46c5-a5cd-36687cb21ed8",
"status" : "Running",
"message" : null,
"reports" : [ {
"taskId" : "TaskZJsonRpcExt_1443",
"taskName" : "Validate db d6542252-dfa4-47f9-9cfc-22b4f0575c51 for deletion",
"taskResult" : "",
"startTime" : "May 06, 2020 11:47:53 AM CEST",
"endTime" : "May 06, 2020 11:47:53 AM CEST",
"status" : "Success",
"taskDescription" : null,
"parentTaskId" : "TaskSequential_1441",
"jobId" : "5e227755-478b-46c5-a5cd-36687cb21ed8",
"tags" : [ ],
"reportLevel" : "Info",
"updatedTime" : "May 06, 2020 11:47:53 AM CEST"
} ],
"createTimestamp" : "May 06, 2020 11:47:53 AM CEST",
"resourceList" : [ ],
"description" : "Database service deletion with db name: TEST with id : d6542252-dfa4-47f9-9cfc-22b4f0575c51",
"updatedTime" : "May 06, 2020 11:47:53 AM CEST"
}

Which this time will be successful :

[[email protected] bin]# odacli describe-job -i "5e227755-478b-46c5-a5cd-36687cb21ed8"
 
Job details
----------------------------------------------------------------
ID: 5e227755-478b-46c5-a5cd-36687cb21ed8
Description: Database service deletion with db name: TEST with id : d6542252-dfa4-47f9-9cfc-22b4f0575c51
Status: Success
Created: May 6, 2020 11:47:53 AM CEST
Message:
 
Task Name Start Time End Time Status
---------------------------------------- ----------------------------------- ----------------------------------- ----------
Validate db d6542252-dfa4-47f9-9cfc-22b4f0575c51 for deletion May 6, 2020 11:47:53 AM CEST May 6, 2020 11:47:53 AM CEST Success
Database Deletion May 6, 2020 11:47:53 AM CEST May 6, 2020 11:47:54 AM CEST Success
Unregister Db From Cluster May 6, 2020 11:47:54 AM CEST May 6, 2020 11:47:54 AM CEST Success
Kill Pmon Process May 6, 2020 11:47:54 AM CEST May 6, 2020 11:47:54 AM CEST Success
Database Files Deletion May 6, 2020 11:47:54 AM CEST May 6, 2020 11:47:54 AM CEST Success
Deleting Volume May 6, 2020 11:48:01 AM CEST May 6, 2020 11:48:05 AM CEST Success
Delete File Groups of Database TEST May 6, 2020 11:48:05 AM CEST May 6, 2020 11:48:05 AM CEST Success

Restore our customized listener configuration

We can now restore our customized configuration as follows :

[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl stop listener -listener listener
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl status listener -listener listener
Listener LISTENER is enabled
Listener LISTENER is not running
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] mv listener.ora.before_db_del_20200506 listener.ora
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl start listener -listener listener
 
[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] srvctl status listener -listener listener
Listener LISTENER is enabled
Listener LISTENER is running on node(s): oda01

We could also confirm that the listener started successfully by displaying the tnslsnr running processes :

[email protected]:/u01/app/18.0.0.0/grid/network/admin/ [+ASM1] ps -ef | grep tnslsnr | grep -v grep
grid 14922 1 0 10:52 ? 00:00:00 /u01/app/18.0.0.0/grid/bin/tnslsnr ASMNET1LSNR_ASM -no_crs_notify -inherit
grid 97812 1 0 12:07 ? 00:00:00 /u01/app/18.0.0.0/grid/bin/tnslsnr LISTENER -no_crs_notify -inherit

Conclusion

Starting ODA Release 18.5, database deletion will fail if the listener has been customized. Workaround is to to restore the listener default configuration for executing the deletion. This might imply for some customers to have a maintenance windows.

Leave a Reply

This site uses Akismet to reduce spam. Learn how your comment data is processed.

Marc Wagner
Marc Wagner

Consultant