Hi all,
That’s an interesting case with OEM. A client reported the metric “Tablespace Allocation Metric” is not being updated on OEM for a specific database. In this case, the last gathering was in Nov/2020, as you’ll see.
When checking for it, the first try as usual was checking on the OEM agent status, and here is what I got:
oracle:dbserver@mydb02 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl status agent
Oracle Enterprise Manager Cloud Control 12c Release 5
Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved.
---------------------------------------------------------------
Agent Version : 12.1.0.5.0
OMS Version : (unknown)
Protocol Version : 12.1.0.1.0
Agent Home : /u01/app/oracle/product/agent12c/agent_inst
Agent Log Directory : /u01/app/oracle/product/agent12c/agent_inst/sysman/log
Agent Binaries : /u01/app/oracle/product/agent12c/core/12.1.0.5.0
Agent Process ID : 61641
Parent Process ID : 61394
Currently initializing component : Target Manager (2) (54 of 70)
Receivelet Interaction Manager Current Activity: Outstanding receivelet event tasks
----------------------------------
TargetID = oracle_pdb.c4test_PDB1 - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c3test_CDBROOT - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c3test_PDB2 - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:30
TargetID = oracle_pdb.c4test_CDBROOT - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c6test_CDBROOT - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c3test_PDB3 - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:30
TargetID = rac_database.c1prod - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:30
Target Manager Current Activity : Compute Dynamic Properties (total operations: 37, active: 7, finished: 28)
Current target operations in progress
-------------------------------------
oracle_pdb.c6test_CDBROOT - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c4test_PDB1 - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c3test_PDB2 - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c3test_CDBROOT - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c4test_CDBROOT - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c3test_PDB3 - LOAD_TARGET_DYNAMIC running for 120 seconds
rac_database.c1test - LOAD_TARGET_DYNAMIC running for 120 seconds
Dynamic property executor tasks running
------------------------------
---------------------------------------------------------------
Agent is Running but Not Ready
Agent not ready, that’s interesting.
Trying then to clear the agent state as this has solved some previous similar cases:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl clearstate agent Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. EMD clearstate completed successfully Now running the problematic metric manually: oracle:dbserver02@c1test2 /u01/app/oracle: runCollection c1test_DW:oracle_pdb tbspAllocation < Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. --------------------------------------------------------------- EMD runCollection error:The agent is running but is currently not ready to accept client requests
Ok, trying to just upload the case:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl upload Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. --------------------------------------------------------------- EMD upload error:The agent is running but is currently not ready to accept client requests
Maybe something is stuck, so let’s kill the process and start all over again:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl stop agent Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. Stopping agent ... stopped.
Making sure we have no agent process running:
oracle:dbserver02@c1test2 /u01/app/oracle: ps -ef | grep java | agent oracle:dbserver02@c1test2 /u01/app/oracle:
Also adjusting the threshod for metric running:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl setproperty agent -a Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. EMD setproperty succeeded oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl setproperty agent -allow_new -name _cancelThread -value 210 Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. EMD setproperty succeeded
And starting the agent:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl start agent Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. Starting agent ........................................................................................................................... started but not ready.
On the Agent log:
oracle:dbserver02@c1test2 /u01/app/oracle: tail /u01/app/oracle/product/agent12c/agent_inst/sysman/log/gcagent.log oracle:dbserver02@c1test2 /u01/app/oracle: 2020-12-20 13:15:03,457 [35:686116F5] DEBUG - StatusAgentAction: satisfyRequest Begin 2020-12-20 13:15:03,457 [35:686116F5] DEBUG - Agent Overall Health: 0 2020-12-20 13:15:03,457 [35:686116F5] DEBUG - StatusAgentAction: satisfyRequest End Response: initializing 2020-12-20 13:15:03,457 [35:686116F5] INFO - >>> Reporting response: StatusAgentResponse (initializing) (request id 1) <<< 2020-12-20 13:15:03,457 [35:686116F5] DEBUG - closing request input stream for "StatusAgentRequest (AGENT timeout:300)" 2020-12-20 13:15:03,457 [35:686116F5] DEBUG - overriding the buffer with a thread local copy (size: 8192b) 2020-12-20 13:15:03,458 [35:686116F5] DEBUG - closing request output stream for "StatusAgentRequest (AGENT timeout:300)" 2020-12-20 13:15:03,458 [35:686116F5] DEBUG - StatusAgentAction.call() is complete. 2020-12-20 13:15:03,458 [35:B5326F3F:HTTP Listener-35 - /emd/lifecycle/main/] DEBUG - removing entry for emdctl@18081@dbserver02=>[160849530330001] completely 2020-12-20 13:15:03,458 [35:B5326F3F] DEBUG - requests executed. 2020-12-20 13:15:03,458 [35:B5326F3F] DEBUG - HTTPListener Threads deallocated resource back to LifecycleRequestHandler partition 2020-12-20 13:15:03,458 [35:3C0B0663:HTTP Listener-35] DEBUG - using connection SCEP@1197017148 [d=true,io=1,w=true,b=false|false],NOT_HANDSHAKING, in/out=0/0 Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 5 bytesProduced = 26 2020-12-20 13:15:03,780 [35:3C0B0663] DEBUG - using connection SCEP@1197017148 [d=true,io=1,w=true,b=false|false],NOT_HANDSHAKING, in/out=0/0 Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 26 bytesProduced = 5 2020-12-20 13:15:06,986 [31:858161EB] DEBUG - Submitting task SchedulerHeartbeat for execution 2020-12-20 13:15:06,986 [395:1AE716D8] DEBUG - Begin task SchedulerHeartbeat on Thread: GC.SysExecutor.8 2020-12-20 13:15:06,986 [395:F944F4C8:GC.SysExecutor.8 (SchedulerHeartbeat)] DEBUG - Scheduler heartbeat 2020-12-20 13:15:06,988 [395:F944F4C8] DEBUG - Scheduling next SchedulerHeartbeat after delay 29998 including periodShift of 0 milliseconds 2020-12-20 13:15:06,988 [395:1AE716D8:GC.SysExecutor.8] DEBUG - End task SchedulerHeartbeat 2020-12-20 13:15:07,016 [31:858161EB] DEBUG - Submitting task HeapMonitorTask for execution 2020-12-20 13:15:07,017 [396:1AE716D9] DEBUG - Begin task HeapMonitorTask on Thread: GC.SysExecutor.9 2020-12-20 13:15:07,017 [396:391F60D7:GC.SysExecutor.9 (HeapMonitorTask)] DEBUG - Scheduling next HeapMonitorTask after delay 5000 including periodShift of 0 milliseconds 2020-12-20 13:15:07,017 [396:1AE716D9:GC.SysExecutor.9] DEBUG - End task HeapMonitorTask 2020-12-20 13:15:12,017 [31:858161EB] DEBUG - Submitting task HeapMonitorTask for execution 2020-12-20 13:15:12,017 [37:1AE716D0] DEBUG - Begin task HeapMonitorTask on Thread: GC.SysExecutor.0 2020-12-20 13:15:12,017 [37:FE21F10E:GC.SysExecutor.0 (HeapMonitorTask)] DEBUG - Scheduling next HeapMonitorTask after delay 5000 including periodShift of 0 milliseconds 2020-12-20 13:15:12,017 [37:1AE716D0:GC.SysExecutor.0] DEBUG - End task HeapMonitorTask 2020-12-20 13:15:12,189 [33:6D553CF6] DEBUG - HTTPListener Threads deallocated resource back to LifecycleRequestHandler partition 2020-12-20 13:15:12,190 [35:3C0B0663] DEBUG - using connection SCEP@1611645943 [d=true,io=1,w=true,b=false|false],NOT_HANDSHAKING, in/out=0/0 Status = OK HandshakeStatus = NOT_HANDSHAKING bytesConsumed = 100 bytesProduced = 121 2020-12-20 13:15:12,191 [35:7107E334:HTTP Listener-35 - /emd/persistence/main/] DEBUG - HTTPListener Threads allocated resource from LifecycleRequestHandler partition 2020-12-20 13:15:17,017 [31:858161EB] DEBUG - Submitting task HeapMonitorTask for execution 2020-12-20 13:15:17,018 [45:1AE716D1] DEBUG - Begin task HeapMonitorTask on Thread: GC.SysExecutor.1 2020-12-20 13:15:17,018 [45:CBCC52CF:GC.SysExecutor.1 (HeapMonitorTask)] DEBUG - Scheduling next HeapMonitorTask after delay 5000 including periodShift of 0 milliseconds 2020-12-20 13:15:17,018 [45:1AE716D1:GC.SysExecutor.1] DEBUG - End task HeapMonitorTask
Following MOS Enterprise Manager12c: Oracle Database Tablespace Monthly Space Usage shows no data (Doc ID 1536654.1), a few changes were made:
$/AGENT_INST/bin/emctl setproperty agent -allow_new -name MaxInComingConnections -value 150 $/AGENT_INST/bin/emctl setproperty agent -allow_new -name _cancelThread -value 210
The status before the change:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl status agent
Oracle Enterprise Manager Cloud Control 12c Release 5
Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved.
---------------------------------------------------------------
Agent Version : 12.1.0.5.0
OMS Version : (unknown)
Protocol Version : 12.1.0.1.0
Agent Home : /u01/app/oracle/product/agent12c/agent_inst
Agent Log Directory : /u01/app/oracle/product/agent12c/agent_inst/sysman/log
Agent Binaries : /u01/app/oracle/product/agent12c/core/12.1.0.5.0
Agent Process ID : 61641
Parent Process ID : 61394
Currently initializing component : Target Manager (2) (54 of 70)
Receivelet Interaction Manager Current Activity: Outstanding receivelet event tasks
----------------------------------
TargetID = oracle_pdb.c4test_PDB1 - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c3test_CDBROOT - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c3test_PDB2 - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:30
TargetID = oracle_pdb.c4test_CDBROOT - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c6test_CDBROOT - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:29
TargetID = oracle_pdb.c3test_PDB3 - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:30
TargetID = rac_database.c1test - EventType - TARGET_EVENT for operation LOAD_TARGET submitted at 2020-12-20 12:54:30
Target Manager Current Activity : Compute Dynamic Properties (total operations: 37, active: 7, finished: 28)
Current target operations in progress
-------------------------------------
oracle_pdb.c6test_CDBROOT - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c4test_PDB1 - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c3test_PDB2 - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c3test_CDBROOT - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c4test_CDBROOT - LOAD_TARGET_DYNAMIC running for 120 seconds
oracle_pdb.c3test_PDB3 - LOAD_TARGET_DYNAMIC running for 120 seconds
rac_database.c1test - LOAD_TARGET_DYNAMIC running for 120 seconds
Dynamic property executor tasks running
------------------------------
---------------------------------------------------------------
Agent is Running but Not Ready
And the status after the change:
oracle:dbserver02@c1test2 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl status agent Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. --------------------------------------------------------------- Agent Version : 12.1.0.5.0 OMS Version : 12.1.0.5.0 Protocol Version : 12.1.0.1.0 Agent Home : /u01/app/oracle/product/agent12c/agent_inst Agent Log Directory : /u01/app/oracle/product/agent12c/agent_inst/sysman/log Agent Binaries : /u01/app/oracle/product/agent12c/core/12.1.0.5.0 Agent Process ID : 56994 Parent Process ID : 56654 Agent URL : https://dbserver02:3872/emd/main/ Local Agent URL in NAT : https://dbserver02:3872/emd/main/ Repository URL : https://omsweb:4903/empbs/upload Started at : 2020-12-20 13:08:35 Started by user : oracle Operating System : Linux version 3.10.0-957.27.2.el7.x86_64 (amd64) Last Reload : (none) Last successful upload : 2020-12-20 13:40:41 Last attempted upload : 2020-12-20 13:40:41 Total Megabytes of XML files uploaded so far : 1.02 Number of XML files pending upload : 0 Size of XML files pending upload(MB) : 0 Available disk space on upload filesystem : 10.85% Collection Status : Collections enabled Heartbeat Status : Ok Last attempted heartbeat to OMS : 2020-12-20 13:40:40 Last successful heartbeat to OMS : 2020-12-20 13:40:40 Next scheduled heartbeat to OMS : 2020-12-20 13:41:40 --------------------------------------------------------------- Agent is Running and Ready
Great! Agent issue resolved.
However, the metric is not being gathered not even after running it manually:
oracle:dbserver01@c1test1 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl control agent runCollection c1test_CDBROOT:oracle_pdb tbspAllocation Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. --------------------------------------------------------------- EMD runCollection completed successfully oracle:dbserver01@c1test1 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl status agent scheduler | grep tbspAllocation 2020-12-28 23:05:14.562 : rac_database:c1test:tbspAllocation_cdb 2020-12-29 03:07:21.988 : rac_database:c4prod:tbspAllocation_cdb 2020-12-29 03:08:11.888 : rac_database:c6prod:tbspAllocation_cdb 2020-12-29 03:09:39.103 : rac_database:c2prod:tbspAllocation_cdb 2020-12-29 03:09:55.372 : rac_database:c3prod:tbspAllocation_cdb oracle:dbserver01@c1test1 /u01/app/oracle: /u01/app/oracle/product/agent12c/core/12.1.0.5.0/bin/emctl control agent runCollection c1test_DW:oracle_pdb tbspAllocation Oracle Enterprise Manager Cloud Control 12c Release 5 Copyright (c) 1996, 2015 Oracle Corporation. All rights reserved. --------------------------------------------------------------- EMD runCollection completed successfully
On OEM Repository database:
SQL> select TARGET_NAME,TARGET_TYPE,TARGET_GUID,max(ROLLUP_TIMESTAMP ) from mgmt$metric_daily where TARGET_NAME like '%c1test%' and TARGET_TYPE='oracle_pdb' and METRIC_NAME='tbspAllocation' group by TARGET_NAME,TARGET_TYPE,TARGET_GUID; 2 3 4 5 TARGET_NAME TARGET_TYPE TARGET_GUID MAX(ROLLUP_TIMESTAM ------------------------------ -------------------- -------------------------------- ------------------- c1test_DW oracle_pdb 7B1DF5DD4555EB978330A6D522004D44 2020-11-12 00:00:00 c1test_CDBROOT oracle_pdb 4CE72911295C0287E053837F649B7D0E 2020-11-12 00:00:00 SQL> select TARGET_NAME,TARGET_TYPE,TARGET_GUID,ROLLUP_TIMESTAMP from mgmt$metric_daily where TARGET_NAME like '%c1test%' and TARGET_TYPE='oracle_pdb' and ROLLUP_TIMESTAMP>sysdate-3 order by 4 TARGET_NAME TARGET_TYPE ROLLUP_TIMESTAMP AVERAGE ------------------------------ -------------------- ------------------- ---------- c1test_DW oracle_pdb 2020-11-06 00:00:00 1575.9375 c1test_DW oracle_pdb 2020-11-07 00:00:00 1575.9375 c1test_DW oracle_pdb 2020-11-08 00:00:00 1575.9375 c1test_DW oracle_pdb 2020-11-09 00:00:00 1575.9375 c1test_DW oracle_pdb 2020-11-10 00:00:00 1575.9375 c1test_DW oracle_pdb 2020-11-11 00:00:00 1575.9375 c1test_DW oracle_pdb 2020-11-12 00:00:00 1575.9375 c1test_CDBROOT oracle_pdb 2020-11-05 00:00:00 37581.5625 TARGET_NAME TARGET_TYPE ROLLUP_TIMESTAMP AVERAGE ------------------------------ -------------------- ------------------- ---------- c1test_CDBROOT oracle_pdb 2020-11-08 00:00:00 227138.75 c1test_CDBROOT oracle_pdb 2020-11-09 00:00:00 455087.688 c1test_CDBROOT oracle_pdb 2020-11-10 00:00:00 278230.875 c1test_CDBROOT oracle_pdb 2020-11-11 00:00:00 208727.188 c1test_CDBROOT oracle_pdb 2020-11-12 00:00:00 454964.063
Ok, so in summary: After fixing all issues on OEM side, everything running fine, still the database metrics are not being updated.
Long story short: After some investigation, bumped in MOS Database Hangs With Simple Queries like on view dba_data_files & dba_free_space (Doc ID 2665935.1)
Turns out this seemed to be a match. So proceeding with the recommendation:
SQL> alter session set container=DW;
Session altered.
SQL> show pdbs
CON_ID CON_NAME OPEN MODE RESTRICTED
---------- ------------------------------ ---------- ----------
3 DW READ WRITE NO
SQL> select count(*) from dba_recyclebin;
COUNT(*)
----------
28522
SQL> purge recyclebin;
Recyclebin purged.
SQL> purge dba_recyclebin;
DBA Recyclebin purged.
Once done, all issues solved and metric being collected again:
Some additional reference:
- Database Tablespace Metrics: Tablespace Allocation Is Not Collected (Metric tbspAllocation) (Doc ID 404692.1)
- EM 12c : emctl start agent Fails With Error ‘Starting agent … started but not ready’ (Doc ID 1591477.1)
- EM12c : emctl start / status agent ‘Agent Running but Not Ready’ ‘ERROR – The agent is overloaded [current requests: 30]’ Reported in gcagent.log (Doc ID 1546529.1)
I hope it helps!
