Thursday, October 30, 2014

ORA-12514 During OEM Database Control Configuration for RAC

While configuring OEM Database Control for 2 nodes 11.2.0.3 RAC (On windows), I faced error "ORA-12514: TNS:listener does not currently know of service requested in connect descriptor", about which I would be discussing in the following that what was the reason for this error and how I resolved it. 

Following screenshot shows the error message during configuration steps.


EMCA Log was showing following messages. Error has also been highlighted in bold/red

#############################################
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.OUIInventoryUtil setOUILoc
CONFIG: Setting oracle.installer.oui_loc to D:\oracle\11203\DB\oui
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil isHASInstalled
CONFIG: isHAInstalled: false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag '-migrate' set to false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'migrateFromDBControl' set to false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'migrateToCentralAgent' set to false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'migrateFromCentralAgent' set to false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'migrateToDBControl' set to false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'STANDALONE_MODE' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag '-config' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'UPDATE_EMAIL' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'dbcontrol' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'db' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'create' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag '-cluster' set to true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: CLUSTER_NAME value: GRID
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: EM_NODE value: hjpmsdb1
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: EM_SID_LIST value: db1,db2
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: ORACLE_HOME value: D:\oracle\11203\DB
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil isCRSInstalled
CONFIG: isCRSInstalled: true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil isHASInstalled
CONFIG: isHAInstalled: false
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil isCRSInstalled
CONFIG: isCRSInstalled: true
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: Cluster.isCluster: true. Calling getLocalNode
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil getHostName
CONFIG: Specified node: hjpmsdb1
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.util.ClusterUtil getHostName
CONFIG: Node: hjpmsdb1 Host: HJPMSDB1
Sep 25, 2014 12:18:24 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: EM_HOME value: D:\oracle\11203\DB
Sep 25, 2014 12:18:28 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: DB_UNIQUE_NAME value: db
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: SERVICE_NAME value: db
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter SYSMAN_PWD.
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter PORT.
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.util.ClusterUtil getHostName
CONFIG: Specified node: hjpmsdb1
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.util.ClusterUtil isCRSHomeInstantaited
CONFIG: Value of CRS_HOME in D:\oracle\11203\DB\sysman\config\emca.properties is D:/oracle/11203/grid
Sep 25, 2014 12:18:30 PM oracle.sysman.emcp.ParamsManager getRepDbPort
CONFIG: Couldn't get listener port. File D:\oracle\11203\DB\hjpmsdb1_db\sysman\config\emoms.properties does not exists
Sep 25, 2014 12:18:33 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: PORT value: 1522
Sep 25, 2014 12:18:37 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: LISTENER_OH value: D:\oracle\11203\grid
Sep 25, 2014 12:18:41 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:41 PM oracle.sysman.emcp.ParamsManager getVersion
CONFIG: Failed to obtain paraller server version
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager setConfiguredNodeSidList
CONFIG: db1 running from node : hjpmsdb1
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager setConfiguredNodeSidList
CONFIG: db2 running from node : hjpmsdb2
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager getConfiguredDBNodeList
CONFIG: Node list having Instances configured: [hjpmsdb1, hjpmsdb2]
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager getConfiguredDBSidList
CONFIG: Sid List of the running Instances: [db1, db2]
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter SYS_PWD.
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter ASM_OH.
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter REP_DB_RUNNING_HOST.
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:42 PM oracle.sysman.emcp.util.ClusterUtil getHostName
CONFIG: Specified node: hjpmsdb1
Sep 25, 2014 12:18:44 PM oracle.sysman.emcp.ParamsManager getHost
CONFIG: Host having instnces running for database db : hjpmsdb2
Sep 25, 2014 12:18:44 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: REP_DB_RUNNING_HOST value: hjpmsdb2
Sep 25, 2014 12:18:44 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter SYSMAN_PWD.
Sep 25, 2014 12:18:44 PM oracle.sysman.emcp.ParamsManager getRepDbPort
CONFIG: Listener Port: 1522
Sep 25, 2014 12:18:44 PM oracle.sysman.emcp.util.GeneralUtil isLocalConnectionRequired
CONFIG: isLocalConnectionRequired: false
Sep 25, 2014 12:18:44 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngine
CONFIG: isLocalConnectionRequired: false. Connecting to database instance remotely.
Sep 25, 2014 12:18:45 PM oracle.sysman.emcp.util.ClusterUtil getScanName
CONFIG: Sacn Name: HJPMSDBSCAN
Sep 25, 2014 12:18:45 PM oracle.sysman.emcp.util.ClusterUtil getScanPort
CONFIG: Sacn Port: 1522
Sep 25, 2014 12:18:45 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngineRemotely
CONFIG: SQLEngine connecting with Service Name: db, oracleHome: D:\oracle\11203\DB, and user: SYS scan name: HJPMSDBSCAN scan port: 1522
Sep 25, 2014 12:18:46 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngineRemotely
WARNING: Error during db connection : ORA-12514: TNS:listener does not currently know of service requested in connect descriptor

Sep 25, 2014 12:18:46 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngineRemotely
CONFIG: Waiting for 5 second before reconnection
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngineRemotely
CONFIG: SQLEngine connecting with Service Name: db, oracleHome: D:\oracle\11203\DB, and user: SYS host: hjpmsdb2 port: 1522
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngineRemotely
CONFIG: SQLEngine created successfully and connected
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.util.ClusterUtil getHostName
CONFIG: Specified node: hjpmsdb1
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter NODE_LIST.
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.ParamsManager getInaccessibleNodeList
CONFIG: Invalid Node/Sid List specified.
Sep 25, 2014 12:18:51 PM oracle.sysman.emcp.ParamsManager getVersion
CONFIG: Failed to obtain paraller server version
Sep 25, 2014 12:18:53 PM oracle.sysman.emcp.ParamsManager setConfiguredNodeSidList
CONFIG: db1 running from node : hjpmsdb1
Sep 25, 2014 12:18:53 PM oracle.sysman.emcp.ParamsManager setConfiguredNodeSidList
CONFIG: db2 running from node : hjpmsdb2
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil isCardinal
CONFIG: isServiceCentric: false
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil isCardinal
CONFIG: Database Type : RAC
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil isCardinal
CONFIG: isRacOne: false
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil isCardinal
CONFIG: isCardinal: false
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil areNodesAlive
CONFIG: Alive node cache contents: []
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil areNodesAlive
CONFIG: hjpmsdb1 not found in alive node cache
Sep 25, 2014 12:18:54 PM oracle.sysman.emcp.util.ClusterUtil areNodesAlive
CONFIG: hjpmsdb2 not found in alive node cache
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil areNodesAlive
CONFIG: Node: hjpmsdb1 is accessible.
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil areNodesAlive
CONFIG: Node: hjpmsdb2 is accessible.
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getInaccessibleNodeList
CONFIG: All nodes are up. Nodes: [hjpmsdb1, hjpmsdb2]
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getInaccessibleSidList
CONFIG: All nodes are up. Nodes: [hjpmsdb1, hjpmsdb2] Sids: [db1, db2]
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: NODE_LIST value: hjpmsdb1,hjpmsdb2
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: SID_LIST value: db1,db2
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getConfiguredDBNodeList
CONFIG: Node list having Instances configured: [hjpmsdb1, hjpmsdb2]
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getConfiguredDBSidList
CONFIG: Sid List of the running Instances: [db1, db2]
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil isCardinal
CONFIG: isCardinal: false
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil getLocalNode
CONFIG: isLocalNodeDone: true localNode: hjpmsdb1
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.ClusterUtil getHostName
CONFIG: Specified node: hjpmsdb1
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: HOST value: HJPMSDB1
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.DBControlUtil isDBConsoleConfigured
CONFIG: Sid: db Host: HJPMSDB1 Node: hjpmsdb1 OH: D:\oracle\11203\DB isDBC: false
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.CentralAgentUtil isCentralAgentConfigured
CONFIG: Sid: db Host: HJPMSDB1 Node: hjpmsdb1 OH: D:\oracle\11203\DB agentHome: null isCentral: false
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.CentralAgentUtil isCentralAgentConfigured
CONFIG: Sid: db Host: HJPMSDB1 Node: hjpmsdb1 OH: D:\oracle\11203\DB agentHome: null isCentral: false
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getHost
CONFIG: Host having instnces running for database db : hjpmsdb2
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: REP_DB_RUNNING_HOST value: hjpmsdb2
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getParam
CONFIG: No value was set for the parameter SYSMAN_PWD.
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager getRepDbPort
CONFIG: Listener Port: 1522
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.GeneralUtil isLocalConnectionRequired
CONFIG: isLocalConnectionRequired: false
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngine
CONFIG: isLocalConnectionRequired: false. Connecting to database instance remotely.
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.util.GeneralUtil initSQLEngineRemotely
CONFIG: SQLEngine created successfully and connected
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'asm_db' set to true
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setFlag
CONFIG: Flag 'asm_db' set to true
Sep 25, 2014 12:18:55 PM oracle.sysman.emcp.ParamsManager setParam
CONFIG: Setting param: ASM_USER_ROLE value: SYSDBA
#############################################

Reason of the Problem
This will be pertinent to mention that OEM Database control for RAC needs SCAN Listener to be configured and all instances (including ASM) are registered with the SCAN. If SCAN is configured on port 1521, we don't need any extra steps, but, in my case, my SCAN (and local listeners) were listening on port 1522 and hence SCAN Listener was not able to register both instances, as can been seen in bellow screenshot where SCAN Listener has no registered instance. 

Since my application does not utilize SCAN Listener and connects through local listeners, hence I did not face any issue in normal database operations by my application.


Solution
Starting 11.2, Oracle recommends to use SCAN Listener which runs from Grid Infrastructure home and set REMOTE_LISTENER parameter to the address of SCAN Listener so that each instance (including ASM instances) register themselves with the SCAN Listener. Since my application does not support SCAN, I needed to set REMOTE_LISTENER to be resolved to the local listeners. In this case, I needed to add ADDRESS of SCAN Listener to my TNS entry I was using in REMOTE_LISTENER so that SCAN Listener can also register my instances. In the following you can see (highlighted in red) how I added address of SCAN Listener. This needs to be done for ASM instances REMOTE_LISTENER TNS entry also so that ASM instances from both nodes could also get them registered with the SCAN Listener.

LISTENER_SCAN =
  (DESCRIPTION =
    (ADDRESS_LIST =
      (ADDRESS = (PROTOCOL = TCP)(HOST = myhost1vip)(PORT = 1522))
      (ADDRESS = (PROTOCOL = TCP)(HOST = myhost2vip)(PORT = 1522))
      (ADDRESS = (PROTOCOL = TCP)(HOST = db_scan)(PORT = 1522))
    )
    (CONNECT_DATA =
      (SERVER = DEDICATED)
      (SERVICE_NAME = db)
    )

  )

After this, my SCAN Listener was able to register both RAC instances and also both ASM instances


After this, I was successfully able to configure the OEM for this RAC setup


C:\>emca -config dbcontrol db -repos recreate -cluster -CLUSTER_NAME GRID -EM_NODE hjpmsdb1 -EM_SID_LIST db1,db2

STARTED EMCA at Sep 25, 2014 2:04:26 PM
EM Configuration Assistant, Version 11.2.0.3.0 Production
Copyright (c) 2003, 2011, Oracle.  All rights reserved.

Enter the following information:
Database unique name: db
Service name: db
Listener port number: 1522
Listener ORACLE_HOME [ D:\oracle\11203\grid ]:
Password for SYS user:
Password for DBSNMP user:
Password for SYSMAN user:
Password for SYSMAN user: Email address for notifications (optional):
Outgoing Mail (SMTP) server for notifications (optional):
ASM ORACLE_HOME [ D:\oracle\11203\grid ]:
ASM port [ 1522 ]:
ASM username [ ASMSNMP ]:
ASM user password:
ASM user password: -----------------------------------------------------------------

You have specified the following settings

Database ORACLE_HOME ................ D:\oracle\11203\DB

Database instance hostname ................ Listener ORACLE_HOME ................ D:\oracle\11203\grid
Listener port number ................ 1522
Cluster name ................ GRID
Database unique name ................ db
Email address for notifications ...............
Outgoing Mail (SMTP) server for notifications ...............
ASM ORACLE_HOME ................ D:\oracle\11203\grid
ASM port ................ 1522
ASM user role ................ SYSDBA
ASM username ................ ASMSNMP

-----------------------------------------------------------------
----------------------------------------------------------------------
WARNING : While repository is dropped the database will be put in quiesce mode.
----------------------------------------------------------------------
Do you wish to continue? [yes(Y)/no(N)]: y
Sep 25, 2014 2:05:12 PM oracle.sysman.emcp.EMConfig perform
INFO: This operation is being logged at D:\orabase\cfgtoollogs\emca\db\emca_2014_09_25_14_04_25.log.
Sep 25, 2014 2:05:24 PM oracle.sysman.emcp.EMReposConfig invoke
INFO: Dropping the EM repository (this may take a while) ...
Sep 25, 2014 2:07:26 PM oracle.sysman.emcp.EMReposConfig invoke
INFO: Repository successfully dropped
Sep 25, 2014 2:07:27 PM oracle.sysman.emcp.EMReposConfig createRepository
INFO: Creating the EM repository (this may take a while) ...
Sep 25, 2014 2:13:52 PM oracle.sysman.emcp.EMReposConfig invoke
INFO: Repository successfully created
Sep 25, 2014 2:13:59 PM oracle.sysman.emcp.EMReposConfig uploadConfigDataToRepository
INFO: Uploading configuration data to EM repository (this may take a while) ...
Sep 25, 2014 2:14:47 PM oracle.sysman.emcp.EMReposConfig invoke
INFO: Uploaded configuration data successfully
Sep 25, 2014 2:14:49 PM oracle.sysman.emcp.EMDBCConfig instantiateOC4JConfigFiles
INFO: Propagating D:\oracle\11203\DB\oc4j\j2ee\OC4J_DBConsole_hjpmsdb1_db to remote nodes ...
Sep 25, 2014 2:14:49 PM oracle.sysman.emcp.EMDBCConfig instantiateOC4JConfigFiles
INFO: Propagating D:\oracle\11203\DB\oc4j\j2ee\OC4J_DBConsole_hjpmsdb2_db to remote nodes ...
Sep 25, 2014 2:14:53 PM oracle.sysman.emcp.EMAgentConfig deployStateDirs
INFO: Propagating D:\oracle\11203\DB\hjpmsdb1_db to remote nodes ...
Sep 25, 2014 2:14:54 PM oracle.sysman.emcp.EMAgentConfig deployStateDirs
INFO: Propagating D:\oracle\11203\DB\hjpmsdb2_db to remote nodes ...
Sep 25, 2014 2:15:13 PM oracle.sysman.emcp.util.DBControlUtil secureDBConsole
INFO: Securing Database Control (this may take a while) ...
Sep 25, 2014 2:15:24 PM oracle.sysman.emcp.util.DBControlUtil startOMS
INFO: Starting Database Control (this may take a while) ...
Sep 25, 2014 2:16:46 PM oracle.sysman.emcp.EMDBPostConfig performConfiguration
INFO: Database Control started successfully
Sep 25, 2014 2:16:46 PM oracle.sysman.emcp.EMDBPostConfig performConfiguration
INFO: >>>>>>>>>>> The Database Control URL is https://HJPMSDB1:1158/em <<<<<<<<<<<
Sep 25, 2014 2:16:48 PM oracle.sysman.emcp.EMDBPostConfig showClusterDBCAgentMessage
INFO:
****************  Current Configuration  ****************
 INSTANCE            NODE           DBCONTROL_UPLOAD_HOST
----------        ----------        ---------------------

Db1             hjpmsdb1             HJPMSDB1
Db2             hjpmsdb2             HJPMSDB1


Sep 25, 2014 2:16:48 PM oracle.sysman.emcp.EMDBPostConfig invoke
WARNING:
************************  WARNING  ************************

Management Repository has been placed in secure mode wherein Enterprise Manager data will be encrypted.  The encryption key has been placed in the file: D:/oracle/11203/DB/hjpmsdb1_db/sysman/config/emkey.ora. Ensure this file is backed up as the encrypted data will become unusable if this file is lost.

***********************************************************
Enterprise Manager configuration completed successfully
FINISHED EMCA at Sep 25, 2014 2:16:48 PM

C:\>




Monday, September 22, 2014

Issues with Bind Variables and Bind Peeking

I would explain bellow that how bind peeking played a disastrous role  in one of my database. For usage of bind variables, a good post by Arup Nanda is available here

From one of my OLTP databases (10.2.0.4), suddenly I started receiving OEM alerts for “run queue length” as follows. (My server has total 24 CPUs)

------------------------------------------------
Target Name=<TARGET_NAME>
Target type=Host
Host=<HOST_NAME>
Occurred At=11-Sep-2014 06:04:13 SGT
Message=CPU Load is 27.08, crossed warning (18) or critical (24) threshold.
Metric=Run Queue Length (5 minute average)
Metric value=27.08
Severity=Critical
Acknowledged=No
Notification Rule Name=Host Availability and Critical States
Notification Rule Owner=SYSMAN
------------------------------------------------

While further investigating the issue, I found that most of the time was consumed by a query which was part of every transaction (at the particular time) executed by each session. This meant that each session was executing this query and hence overall most of the resources consumption was only by this single query.  In OEM (or you can query v$sql_plan using SQL_ID), I could see multiple plans listed for this SQL and I suspected that perhaps this current plan caused this query to take longer time to finish, and since each session had to execute this query, session would not return until this query finishes. Since each session was executing this SQL, the session was not leaving the CPU and new sessions were waiting for the CPU to be released and eventually raising “Run Queue Length”.

Since my SQL was using bind variables, immediate thing which came into my mind was that probably this SQL was aged out of shared pool and when it was reloaded, it loaded a new execution plan (the bad one) into the shared pool (plan could change because of bind peeking). So, I issued “alter system flush shared pool” (not a good idea actually to invalidate all cursors), to invalidate the cursors in the shared pool and let it reload all cursors again (including this SQL) and saw if it load a good plan this time. This thing worked; as I saw a new plan for this SQL and “run queue length” immediately came down to less than 10.

From dba_hist_sql_plan, I found that there were total 6 different execution plans for this SQL and then I used awrsqrpt.sql script to fetch the execution details for this SQL against each of this plan from AWR repository, and following was the interesting detail which I extracted from SQL AWR reports

Plan with hash value 465940006, Average Physical Reads per execution => 319
Plan with hash value 1122690139, Average Physical Reads per execution => 36
Plan with hash value 976138646, Average Physical Reads per execution => 1285
Plan with hash value 2677530476, Average Physical Reads per execution => 144
Plan with hash value 3841102669, Average Physical Reads per execution => 37
Plan with hash value 2920758856, Average Physical Reads per execution => 155

You can see that plan 976138646 is doing a lot of physical reads and this was actually the culprit at this time as it was slowing down the execution of this particular SQL. After I flushed the shared pool, this plan (976138646) was gone and next plan which was loaded was 1122690139 which made the things better for me. The other better plan here is 3841102669 which was also in use in the past.

Solution for the problem
Invalidating the cursor can help to reload the new and better plan, but this is not the permanent solution. Starting 11g, adaptive cursor sharing feature is very helpful as Oracle may select a different execution plan based on the values in bind variables during different executions of same SQL.

In 10g, oracle profiles and starting from 11g, sql plan management features could be used to attach the plans with particular SQLs to avoid this kind of situation.

Tuesday, September 9, 2014

Privileges Analysis in 12c

In Oracle 12c, we can do an analysis of privileges used by the users. This analysis can actually help to know if there are some privileges granted to some user which were never used by that user and hence can be revoked. This can be even more useful in a situation where DBA realizes that someone (probably previous DBA) has granted a lot of privileges to some users which are apparently not required but may be a threat to the security of the data and he can do a privilege analysis to decide which privileges were never used and can be revoked.

There are three steps involved in privilege analysis
Create capture (DBMS_PRIVILEGE_CAPTURE.CREATE_CAPTURE)
Enable capture (DBMS_PRIVILEGE_CAPTURE.ENABLE_CAPTURE)
Disable capture (DBMS_PRIVILEGE_CAPTURE.DISABLE_CAPTURE)
Generate result (DBMS_PRIVILEGE_CAPTURE.GENERATE_RESULT)

Following is the list of data dictionary views which would contain the analysis information
DBA_USED_PUBPRIVS
DBA_USED_OBJPRIVS
DBA_USED_SYSPRIVS
DBA_USED_PRIVS
DBA_USED_OBJPRIVS_PATH
DBA_USED_SYSPRIVS_PATH
DBA_UNUSED_OBJPRIVS
DBA_UNUSED_SYSPRIVS
DBA_UNUSED_PRIVS
DBA_UNUSED_OBJPRIVS_PATH
DBA_UNUSED_SYSPRIVS_PATH

Privileges analysis can be done at 1) Database Level, 2) Role level, 3) Context level and 4) Role + Context level.

Here I will be doing Context level (Based on logged in USER) privileges analyses to check the privileges usage by a single database user.

Creating a new user (in a PDB) and grant privileges

###########################################
SQL> create user salman identified by salman;
User created.

SQL> alter user salman default tablespace users quota unlimited on users;
User altered

SQL> grant connect to salman;

Grant succeeded.
SQL> grant resource to salman;

Grant succeeded.
SQL> grant create table to salman;

Grant succeeded.
SQL> grant select any table to salman;

Grant succeeded.
 ###########################################

Create capture
exec dbms_privilege_capture.create_capture(name=>'CHECK_PRIVILEGES', Description=>' Capture privileges for user SALMAN', type=>dbms_privilege_capture.g_context, condition=> 'SYS_CONTEXT(''USERENV'',''SESSION_USER'')=''SALMAN''');

Database level capture can be created as follows.
exec dbms_privilege_capture.create_capture(name=>'CHECK_PRIVILEGES', Description=>' Capture privileges for whole database', type=>dbms_privilege_capture.g_database);

For capture based on Module from the session context, following method would be used
Exec SYS.DBMS_PRIVILEGES_CAPTURE(- NAME=>’Privs_AcctPayable_capture’, - Description=> ‘All privileges used by module’, - Type=> ‘SYS_CONTEXT(“USERENV”, “MODULE”)= “SQLPLUS’)

Enable Capture
exec  dbms_privilege_capture.enable_capture('CHECK_PRIVILEGES')

Log in as user SALMAN and utilize a couple of privileges granted to it.

SQL> conn salman/salman@pdb1
Connected.
SQL> create table test (id number);

Table created.

SQL> insert into test values (1);

1 row created.

SQL> commit;

Commit complete.

Disable the capture
SQL> exec dbms_privilege_capture.disable_capture('CHECK_PRIVILEGES')

PL/SQL procedure successfully completed.

Generate Results
SQL> exec dbms_privilege_capture.generate_result('CHECK_PRIVILEGES')

PL/SQL procedure successfully completed.

SQL> desc dba_used_sysprivs
 Name                                      Null?    Type
 ----------------------------------------- -------- ----------------------------
 CAPTURE                                   NOT NULL VARCHAR2(128)
 SEQUENCE                                  NOT NULL NUMBER
 OS_USER                                            VARCHAR2(128)
 USERHOST                                           VARCHAR2(128)
 MODULE                                             VARCHAR2(64)
 USERNAME                                  NOT NULL VARCHAR2(128)
 USED_ROLE                                          VARCHAR2(128)
 SYS_PRIV                                           VARCHAR2(40)
 ADMIN_OPTION                                       NUMBER

SQL>  select module,used_role,sys_priv from dba_used_privs where capture='CHECK_PRIVILEGES' and username='SALMAN';

MODULE                                   USED_ROLE  SYS_PRIV
---------------------------------------- ---------- ----------------------------------------
sqlplus@salman1.salman.com (TNS V1-V3)   CONNECT    CREATE SESSION
sqlplus@salman1.salman.com (TNS V1-V3)   PUBLIC
sqlplus@salman1.salman.com (TNS V1-V3)   PUBLIC
sqlplus@salman1.salman.com (TNS V1-V3)   PUBLIC
sqlplus@salman1.salman.com (TNS V1-V3)   PUBLIC
SQL*Plus                                 PUBLIC
SQL*Plus                                 RESOURCE   CREATE TABLE
SQL*Plus                                 RESOURCE   CREATE TABLE

SQL> desc dba_unused_sysprivs
 Name                                      Null?    Type
 ----------------------------------------- -------- ----------------------------
 CAPTURE                                   NOT NULL VARCHAR2(128)
 USERNAME                                           VARCHAR2(128)
 ROLENAME                                           VARCHAR2(128)
 SYS_PRIV                                           VARCHAR2(40)
 ADMIN_OPTION                                       NUMBER


SQL>  select sys_priv from dba_unused_sysprivs where capture='CHECK_PRIVILEGES' and username='SALMAN';

SYS_PRIV
----------------------------------------
SET CONTAINER
CREATE PROCEDURE
CREATE CLUSTER
CREATE INDEXTYPE
CREATE OPERATOR
CREATE TRIGGER
CREATE SEQUENCE
SELECT ANY TABLE
CREATE TYPE


Drop Capture
exec dbms_privilege_capture.drop_capture('CHECK_PRIVILEGES') – Name is case sensitive

So after all this exercise, we can easily identify which privileges are not in use. DBAs can enable the capture for a longer period of time (may be for a few weeks) to avoid any chance of mistake as there could be a possibility that after revoke an “unnecessary” privilege, suddenly a bi-weekly report stops working because privilege(s) needed by this report was listed under “dba_unused_sysprivs “ as this privilege was not in use during capture was enabled

Tuesday, August 19, 2014

WARNING: inbound connection timed out (ORA-3136)

Warning message inbound connection timed out (ORA-3136) can be seen in the alert log file if a client was failed to authenticate itself within a specified period of time, since connection was initiated first time. SQLNET.INBOUND_CONNECT_TIMEOUT parameter is used to specify a value in number of seconds which database would wait for connection to be established, before logging this warning message in alert log file.

This parameter has no default value set in 9i, but has a default value of 60 seconds in later versions. This parameter serves for the security, and alerts (by issuing warning), if someone tries to connect with the database and initial connection effort was turned down (because of wrong password) and session has not tried to reconnect during this specified period of time. With the warning message in alert log file, the IP address of the client is also logged in SQLNET.LOG file.

In the following, you can see how this WARNING message can be deliberately produced.

In my 10.2.0.4 database, I have not set any value for SQLNET.INBOUND_CONNECT_TIMEOUT in SQLNET.ORA and hence it has default value of 60 seconds. In the following image, upper screen shows my initial attempt to connect with the database with wrong password, and in lower screen, exactly after 60 seconds of initial session attempt, this warning message is logged in alert log file.

If you don't want to see this kind of warnings in alert log file, you can set the value of this parameter to 0, which would mean that database would indefinitely wait for the session to be authenticated without logging any error message