Get All The Wait Events With Respect To Their Class Oracle
SELECT distinct name,wait_class FROM v$event_name;Executes (SQL) in AWR report
What is Executes (SQL) in the AWR report?
This statistics tell the total number of SQL executions in the database during the snap time period.
Add up all the SQL executions in the database with respect to parse, cpu, elapsed, shared memory, version count, buffer gets, physical IO reads etc.. and those counts lead to Executes (SQL)
SQL> SELECT dhs.STARTUP_TIME,count(dhash.sql_id) "Executes (SQL)" FROM dba_hist_snapshot dhs, dba_hist_active_sess_history dhash where dhs.snap_id = dhash.snap_id group by dhs.STARTUP_TIME;
STARTUP_TIME Executes (SQL)
-------------------- --------------
23-NOV-23 01.42.32.0 829
00 PM
27-NOV-23 06.24.18.0 10374
00 PM
20-NOV-23 10.35.26.0 6634
00 AM
28-NOV-23 08.25.34.0 282
00 PM
STARTUP_TIME Executes (SQL)
-------------------- --------------
22-NOV-23 09.57.28.0 2516
00 AM
Determine the SQL response time In Oracle Database
SYSMETRIC views contain a metric called “SQL Service Response Time ” which is essential to determine the response time of all the SQL statements executed in the database to the baseline.
SQL> SELECT METRIC_NAME,VALUE from v$sysmetric WHERE METRIC_NAME like '%SQL Service%';
METRIC_NAME VALUE
---------------------------------------------------------------- ----------
SQL Service Response Time .011957718
SQL> SELECT dhs.begin_interval_time,dhss.metric_name,dhss.minval,dhss.maxval,dhss.average,dhss.standard_deviation FROM dba_hist_snapshot dhs
2 INNER JOIN dba_hist_sysmetric_summary dhss on (dhs.snap_id = dhss.snap_id) WHERE dhss.metric_name like '%SQL Servic%';
BEGIN_INTERVAL_TIME METRIC_NAME MINVAL MAXVAL AVERAGE STANDARD_DEVIATION
-------------------- -------------------- ---------- ---------- ---------- ------------------
20-NOV-23 10.35.26.0 SQL Service Response 0 1.40889148 .575633399 .395105987
00 AM Time
20-NOV-23 01.30.26.3 SQL Service Response 0 .045405956 .01109194 .007332756
94 PM Time
20-NOV-23 02.30.00.5 SQL Service Response 0 .032247838 .013252627 .00527279
62 PM Time
20-NOV-23 07.30.09.3 SQL Service Response 0 .453042102 .044202427 .064546493
11 PM Time
22-NOV-23 03.30.54.2 SQL Service Response 0 .197997813 .074285082 .032879824
01 PM Time
Intermittent ORA-12012, ORA-00054, ORA-06512 Errors During Auto Stats Job
- Intermittent ORA-12012, ORA-00054, ORA-06512 Errors During Auto Stats Job
- High CPU usage is observed
Snap Time Load %busy %user %sys %idle %iowait
14-Apr 22:15:55 18.66 95.52<======= 69.32 26.20 4.48 2.83
*** SERVICE NAME:(SYS$USERS) 2023-04-06 22:01:59.511
*** MODULE NAME:(DBMS_SCHEDULER) 2023-04-06 22:01:59.511
*** ACTION NAME:(ST$AUTO10778_99) 2023-04-06 22:01:59.511
*** CLIENT DRIVER:() 2023-04-06 22:01:59.511
ORA-12012: error on auto execute of job “SYS”.”ST$AUTO10778_99″
<error barrier> at 0xfffffffffff1970 placed
ORA-00054: resource busy and acquire with NOWAIT specified or timeout expired
ORA-06512: at “SYS.DBMS_STATS”, line 40807
ORA-06512: at “SYS.DBMS_STATS”, line 40361
ORA-06512: at “SYS.DBMS_STATS”, line 40083
ORA-06512: at “SYS.DBMS_STATS”, line 38960
ORA-06512: at “SYS.DBMS_STATS”, line 17786
ORA-04022: nowait requested, but had to wait to lock dictionary object
ORA-06512: at “SYS.DBMS_STATS”, line 1800
ORA-06512: at “SYS.DBMS_STATS”, line 17545
ORA-06512: at “SYS.DBMS_STATS”, line 38910
ORA-06512: at “SYS.DBMS_STATS”, line 39786
ORA-06512: at “SYS.DBMS_STATS”, line 40344
ORA-06512: at “SYS.DBMS_STATS”, line 40780
ORA-06512: at line 1
- ‘concurrent’ option is enabled for statistics preference globally.
- Auto stats jobs wait on event ‘library cache lock’ to acquire dictionary object with nowait.
Blocking Sid (Inst) % Activity Event Caused % Event User Program # Samples Active XIDs
208,63039( 1) 1.13 library cache lock 1.13 SYS oracle (J017) 6/180 [ 3%] 0
- High cpu usage is observed and Resource manager throttles the cpu usage due to consumer group threshold.
Event Waits Total Wait Time (sec) Avg Wait % DB time Wait Class
resmgr:cpu quantum 22,817 4736,7 207.59ms 28.5 Scheduler
enq: TM – contention 502 3461,9 6896.28ms 20.8 Application
- Concurrent sessions compete to access the same object and wait for enq: TM – contention.
SQL ID Plan Hash Executions % Activity Event % Event Top Row Source % Row Source SQL Text
gkq5kmbqpm2rf 171 13.80 enq: TM – contention 13.80 ** Row Source Not Available ** 13.80 lock table wri$_optstat_histhe…
ft7wcqu3hzvca 3729177937 93 6.84 enq: TM – contention 6.72 LOAD TABLE CONVENTIONAL 6.72 insert /* QOSH:OPEN_COL_STATS …
Either add more resource to the database, if concurrent option is set.
or
Lock the table statistics sys.WRI$_OPTSTAT_HISTHEAD_HISTORY which gets failed with ora-00054 during the time of auto stats job and regather manual statistics with ‘FORCE=>TRUE’ to override the lock at a later time. Check the size and purging history for the table and reorg if needed.
EXEC dbms_stats.lock_table_stats(‘SYS’,’WRI$_OPTSTAT_HISTHEAD_HISTORY’);
or
Changing concurrent = ‘false’ solved the issue without deadlocks.
EXEC dbms_stats.set_global_prefs(‘concurrent’,’false’);
DBMS_STATS Waits on Streams AQ: waiting for messages in the queue
High Streams AQ: waiting for messages in the queue event observed during execution of stats job with DBMS_STATS with concurrent setting.
SQL ID: 44pgaj5vdubxy Plan Hash: 0
BEGIN dbms_stats.gather_database_stats(); END;
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 3.51 11156.78 734 1484 934 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 3.51 11156.78 734 1484 934 0
Misses in library cache during parse: 1
Optimizer mode: ALL_ROWS
Parsing user id: SYS
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
Disk file operations I/O 4 0.00 0.00
db file sequential read 721 0.34 6.75
control file sequential read 600 0.00 0.00
latch: shared pool 1 0.00 0.00
Streams AQ: waiting for messages in the queue
1106 12.53 11146.59
SQL*Net break/reset to client 1 0.00 0.00
SQL*Net message to client 1 0.00 0.00
OVERALL TOTALS FOR ALL NON-RECURSIVE STATEMENTS
call count cpu elapsed disk query current rows
------- ------ -------- ---------- ---------- ---------- ---------- ----------
Parse 1 0.00 0.00 0 0 0 0
Execute 1 3.51 11156.78 734 1484 934 0
Fetch 0 0.00 0.00 0 0 0 0
------- ------ -------- ---------- ---------- ---------- ---------- ----------
total 2 3.51 11156.78 734 1484 934 0
Misses in library cache during parse: 1
Elapsed times include waiting on following events:
Event waited on Times Max. Wait Total Waited
---------------------------------------- Waited ---------- ------------
SQL*Net message to client 2 0.00 0.00
SQL*Net message from client 1 39.74 39.74
Disk file operations I/O 4 0.00 0.00
db file sequential read 750 0.34 6.78
control file sequential read 600 0.00 0.00
latch: shared pool 1 0.00 0.00
Streams AQ: waiting for messages in the queue
1106 12.53 11146.59
SQL*Net break/reset to client 1 0.00 0.00
Workaround:
Disable concurrent with DBMS_STATS
select 'AUTOSTATS_TARGET =====> '||DBMS_STATS.GET_PREFS('AUTOSTATS_TARGET')||'' as "STATS_PARAM" from dual
union all
select 'CASCADE =====> '||DBMS_STATS.GET_PREFS('CASCADE')||'' from dual
union all
select 'CONCURRENT =====> '||DBMS_STATS.GET_PREFS('CONCURRENT')||'' as "STATS_PARAM" from dual
union all
select 'DEGREE =====> '||DBMS_STATS.GET_PREFS('DEGREE')||'' from dual
union all
select 'ESTIMATE_PERCENT =====> '||DBMS_STATS.GET_PREFS('ESTIMATE_PERCENT')||'' from dual
union all
select 'GRANULARITY =====> '||DBMS_STATS.GET_PREFS('GRANULARITY')||'' from dual
union all
select 'INCREMENTAL =====> '||DBMS_STATS.GET_PREFS('INCREMENTAL')||'' from dual
union all
select 'INCREMENTAL_LEVEL =====> '||DBMS_STATS.GET_PREFS('INCREMENTAL_LEVEL')||'' from dual
union all
select 'INCREMENTAL_STALENESS =====> '||DBMS_STATS.GET_PREFS('INCREMENTAL_STALENESS')||'' from dual
union all
select 'METHOD_OPT =====> '||DBMS_STATS.GET_PREFS('METHOD_OPT')||'' from dual
union all
select 'OPTIONS =====> '||DBMS_STATS.GET_PREFS('OPTIONS')||'' from dual
2 union all
select 'STALE_PERCENT =====> '||DBMS_STATS.GET_PREFS('STALE_PERCENT')||'' from dual;
STATS_PARAM
--------------------------------------------------------------------------------
CONCURRENT =====> TRUE
Use procedure.
EXEC dbms_stats.set_global_prefs('CONCURRENT','FALSE');
PL/SQL procedure successfully completed.WHY DO WE REQUIRE LOCAL UNDO IN ORACLE MULTITENANT?
During the introduction of multitenant in 12.1.0.2 , there used to be global or shared undo tablespace for all pdb which had lot of challenges like ,
- cold clone of pdb in open read only mode
- Unable to refresh snapshot of pdb
- Flashback
- Relocation of pdb
From 12.2, local undo was introduced, which lead to lot of new features
In 12c, there was no option to check local undo.
In 19c, there is an automatic option for local undo which is enabled. It is up to the DBA, to switch on or off local undo. But disabling it, may have lot of features useless.
Local undo is used and should be recommended to use to get the following benefits
- Hot cloning
- PDB relocation
- PDB proxy
By default, the undo mode is true in 19c
kIsH<X>col PROPERTY_NAME for a20
kIsH<X>col PROPERTY_VALUE for a20
kIsH<X>SELECT DISTINCT property_name, property_value FROM cdb_properties WHERE property_name like '%LOCAL_UNDO%';
PROPERTY_NAME PROPERTY_VALUE
-------------------- --------------------
LOCAL_UNDO_ENABLED TRUE
HOW TO ENABLE AND DISABLE SPM IN ORACLE
If a auto baseline is already enabled in database and if that baseline is always used for a sql from the management base, then that may cause interruptions for a user defined query.
I expect optimizer to use result cache for a query but as the baseline is accepted for this query with a different plan,
SQL> set autotrace traceonly
SQL> SELECT /*+ RESULT_CACHE */ count(*) from dspm;
Execution Plan
----------------------------------------------------------
Plan hash value: 3894984268
-------------------------------------------------------------------
| Id | Operation | Name | Rows | Cost (%CPU)| Time |
-------------------------------------------------------------------
| 0 | SELECT STATEMENT | | 1 | 1569 (1)| 00:00:01 |
| 1 | SORT AGGREGATE | | 1 | | |
| 2 | TABLE ACCESS FULL| DSPM | 219K| 1569 (1)| 00:00:01 |
-------------------------------------------------------------------
Note
-----
- dynamic statistics used: dynamic sampling (level=2)
- SQL plan baseline "SQL_PLAN_bmkkb8jb4c4yx9671ac91" used for this statement
To disable SPM for the query, i use the below procedure to do it.
SQL> var xnum number;
SQL> EXEC :xnum := dbms_spm.alter_sql_plan_baseline(plan_name=>'SQL_PLAN_bmkkb8jb4c4yx9671ac91',attribute_name=>'ENABLED',attribute_value=>'NO');
PL/SQL procedure successfully completed.
To enable SPM for the query, i use the below procedure to do it.
SQL> var xnum number;
SQL> EXEC :xnum := dbms_spm.alter_sql_plan_baseline(plan_name=>'SQL_PLAN_bmkkb8jb4c4yx9671ac91',attribute_name=>'ENABLED',attribute_value=>'YES');LATCH FREE :space background task
Latch free is a memory related specifically shared pool event which occur due to lack of space for the session to hold a latch.
~~~~~~~~~~~~~~~~~~ wait Call
Event Waits Time (s) (ms) Time
----------------------------------------- ------------ ----------- ------ ------
CPU time 3,914 47.2
latch free 234,621 2,162 9 26.1
In AWR report, the top latch with high sleep activity is space background task which is a background task which manage the latch space with the slaves.
Latch Activity DB/Inst: DB9ZX/DB9 Snaps: 14242-14243
->"Get Requests", "Pct Get Miss" and "Avg Slps/Miss" are statistics for
willing-to-wait latch get requests
->"NoWait Requests", "Pct NoWait Miss" are for no-wait latch get requests
->"Pct Misses" for both should be very close to 0.0
Pct Avg Wait Pct
Get Get Slps Time NoWait NoWait
Latch Requests Miss /Miss (s) Requests Miss
------------------------ -------------- ------ ------ ------ ------------ ------
space background task la 37,163 20.4 0.6 2 6,132 3.4
Top sleep breakdown related to this latch is also significant
Latch Sleep breakdown DB/Inst: DB9ZX/DB9 Snaps: 14242-14243 -> ordered by misses desc
space background task latc 37,163 7,595 4,309 3,360
Latch Miss Sources DB/Inst: DB9ZX/DB9 Snaps: 14242-14243
-> only latches with sleeps are shown
-> ordered by name, sleeps desc
NoWait Waiter
Latch Name Where Misses Sleeps Sleeps
------------------------ -------------------------- ------- ---------- --------
space background task la ktsj_grab_task 0 2,603 4,239
space background task la ktsj_detach_task 0 1,625 69
space background task la ktsj_smco_purgeexpired 0 75 0
space background task la ktsjCreateTask 0 6 1
Solution:
Please increase the parameter to cache the cursors for efficient parsing and also reduce the space background process slaves which spawn higher.
.
alter system set session_cached_cursors=150 scope=spfile;
alter system set "_max_spacebg_slaves"=64;
Note: Reboot is required to set the parameter.
SGA: allocation forcing component growth
This event is printed, when the SGA is not sufficient to handle the memory load. If this event is continuously printed in the database, then there may be chances of ora-04031 or ora-04036 to occur etc..
USERNAM W_CHAINS TIMER_SEC CHART_WCLASS SQL_ID TOTAVGACT PER%AS
------- -------------------------------------------------- ---------- -------------------- ------------- ---------- ----------
SYS |SGA: allocation forcing component growth [|]<~~~ 160626 OOOOOOOOOOOOOOOOOOO .42 1608.8
SGA: allocation forcing component growth| OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
OOOOOOOOOOOOOOOOOOOO
Solution:
This is capacity issue of SGA and the components inside SGA grows beyond current memory size either it be AMM or ASMM.
Increase SGA.
Blocking Session And Final Blocking Session In v$session Oracle
- What is the difference between blocking session and final blocking session?
- Can they both be same or different?
- When do they occur?
- How to identify them?
Blocking session means the session which blocks another session currently and acts as the parent blocker.
Final blocking session means the child blocker which blocks another session from a parent blocker. They are part of wait chains which occur on top of the chain.
If the table is locked in exclusive mode, then the consequent sessions are blocked from this session.
SQL> LOCK table dspm in exclusive mode;
Table(s) Locked.
In another session, there is another session which execute direct path insert.SQL> INSERT /*+APPEND PARALLEL(8) */ into dspm select * from dba_source;
====>waiting in DML lockBoth blocking and final blocking sessions are same here because session 272 is both blocking and final blocking session and need to release the lock to provide access to other sessions.
SELECT blocking_session,final_blocking_session,sid,serial# from v$session;
BLOCKING_SESSION FINAL_BLOCKING_SESSION SID SERIAL#
---------------- ---------------------- ---------- ----------
30 53527
33 43650
272 272 255 57902
Another scenario where blocking and final blocking sessions both are totally different. Blocking sid is 10 and final blocking sid is 247.
BLOCKING_SESSION FINAL_BLOCKING_SESSION SID SERIAL#
---------------- ---------------------- ---------- ----------
10 247 255 62576
257 58720
258 52129
259 54077
261 50178
10 247 262 27004
263 9138
264 22396
10 247 269 62628
10 247 273 43140
280 1236
BLOCKING_SESSION FINAL_BLOCKING_SESSION SID SERIAL#
---------------- ---------------------- ---------- ----------
282 42139
10 247 286 47997
57 rows selected.
If we further check the details, they both are derived from log writer master and slave processes where slaves are the final blocker on top of the wait chains.
SQL> col EVENT for a20
SQL> SELECT sid,username,program,module,action,event from v$session where sid in (10,247);
SID USERNAME PROGRAM MODULE ACTION EVENT
---------- -------------------- -------------------- -------------------- -------------------- --------------------
10 oracle@xhydra (LGWR) rdbms ipc message
247 oracle@xhydra (LG00) LGWR worker group id
leAnother situation where multiple blockers are having different final blocking sid.
SQL> SELECT blocking_session,final_blocking_session,sid,serial# from v$session;
BLOCKING_SESSION FINAL_BLOCKING_SESSION SID SERIAL#
---------------- ---------------------- ---------- ----------
1 54950
2 61194
3 43260
5 37310
6 51617
7 21945
8 35927
9 22842
10 3966
11 53786
286 10 12 15482
10 10 13 32839
10 10 15 63226
17 29137
52 10 18 26731
19 32942
20 13561
23 24998
24 59432
30 6971
15 10 31 56748
35 7537
10 10 36 10042
37 25337
262 10 38 47235
46 51123
277 10 47 63031
10 10 48 41990
10 10 52 36831
238 56860
239 8282
240 8263
241 60647
242 36474
243 45151
244 26719
245 26867
246 47090
247 10706
248 40117
249 9474
250 33411
251 26321
252 38322
253 2770
254 57166
10 10 255 30058
257 58720
258 52129
259 54077
261 50178
10 10 262 27004
263 9138
10 10 269 62628
10 10 273 43140
48 10 277 8681
280 1236
282 42139
10 10 285 46456
10 10 286 47997
60 rows selected.
There are background processes which acts as blockers and final blockers. Most of the processes are blocked by a root blocker LGWR process to further not progress.
SQL> SELECT sid,username,program,module,action,event from v$session where sid in (10,247,48,286,262,15,277,52);
SID USERNAME PROGRAM MODULE ACTION EVENT
---------- -------------------- -------------------- -------------------- -------------------- --------------------
10 oracle@xhydra (LGWR) rdbms ipc message
15 oracle@xhydra (W001) KTSJ KTSJ Slave log file switch (arc
hiving needed)
48 oracle@xhydra (W006) KTSJ KTSJ Slave log file switch (arc
hiving needed)
52 oracle@xhydra (M000) MMON_SLAVE Auto-Flush Slave Act log file switch (arc
ion hiving needed)
247 oracle@xhydra (LG00) LGWR worker group id
le
262 oracle@xhydra (W003) KTSJ KTSJ Slave log file switch (arc
hiving needed)
277 oracle@xhydra (J000) buffer busy waits
286 oracle@xhydra (W005) KTSJ KTSJ Slave log file switch (arc
hiving needed)
8 rows selected.
SID 10 is the final blocker which is the LGWR culprit which causes other processes to wait on log file switch (archiving needed) , LGWR worker group idle etc..
*** 2023-11-14T21:43:46.367100+05:30 (CDB$ROOT(1))
HM: Early Warning - Session ID 254 serial# 57166 OS PID 67156 (M001)
is waiting on 'row cache lock' for 32 seconds, wait id 8
p1: 'cache id'=0x16, p2: 'mode'=0x0, p3: 'request'=0x3
Blocked by Session ID 52 serial# 36831 on instance 1
which is waiting on 'log file switch (archiving needed)' for 32 seconds
p1: ''=0x0, p2: ''=0x0, p3: ''=0x0
Final Blocker is Session ID 10 serial# 3966 on instance 1
which is waiting on 'rdbms ipc message' for 0 seconds
p1: 'timeout'=0xe1, p2: ''=0x0, p3: ''=0x0
IO
Total Self- Total Total Outlr Outlr Outlr
Hung Rslvd Rslvd Wait WaitTm Wait WaitTm Wait
Sess Hangs Hangs Count Secs Count Secs Count Wait Event
------ ------ ------ ------ ------ ------ ------ ------ -----------
0 0 0 0 0 0 0 0 row cache lock
HM: Dumping Short Stack of pid[37.67156] (sid:254, ser#:57166)
Short stack dump:
ksedsts()+426<-ksdxfstk()+58<-ksdxcb()+872<-sspuser()+200<-__sighandler()<-semtimedop()+14<-skgpwwait()+187<-ksliwat()+2218<-kslwaitctx()+188<-kqrget()+1574<-kqrLockPo()+246<-kqrpre2()+1117<-kqrpre()+35<-kewrgns_get_next_snaphdl()+115<-kerpiGetSnapshotId()+19<-kerpiSaveReport()+90<-kerpiReportFlushActionCb()+769<-kebmscw_slave_cb_wrapper()+21<-kebmiasc_invoke_action_switch_cb()+154<-kebmpsp_pdb_switch_private()+113<-kebm_slave_main()+800<-ksvrdp_int()+1941<-opirip()+583<-opidrv()+581<-sou2o()+165<-opimai_real()+173<-ssthrdmain()+417<-main()+256<-__libc_start_main()+243<-0x5541F689495641D7
HM: Current SQL: none
*** 2023-11-14T21:43:48.522177+05:30 (CDB$ROOT(1))
HM: Early Warning - Session ID 18 serial# 26731 OS PID 56573 (MMON)
is waiting on 'log file switch (archiving needed)' for 32 seconds, wait id 4573
p1: ''=0x0, p2: ''=0x0, p3: ''=0x0
Final Blocker is Session ID 10 serial# 3966 on instance 1
which is waiting on 'rdbms ipc message' for 0 seconds
p1: 'timeout'=0x10b, p2: ''=0x0, p3: ''=0x0
IO
Total Self- Total Total Outlr Outlr Outlr
Hung Rslvd Rslvd Wait WaitTm Wait WaitTm Wait
Sess Hangs Hangs Count Secs Count Secs Count Wait Event
------ ------ ------ ------ ------ ------ ------ ------ -----------
6 0 0 12 1344 11 1344 0 log file switch (archiving needed)Summary:
- Always focus on the final blocker rather than the initial blocker as they are the root blockers.