Tales From A Lazy Fat DBA

Its all about Databases, their performance, troubleshooting & much more …. ยฏ\_(ใƒ„)_/ยฏ

Posts Tagged ‘troubleshooting’

A simple lovely Python script to get complete row locking details in Oracle database …

Posted by FatDBA on August 12, 2023

Hi Guys,

Recently I was working on one row locking contention where the a particular row was locked in exclusive mode caused all subsequent sessions trying to modify that row went in to waiting mode and were were waiting on ‘enq: TX row lock contention‘ wait event. This was a classic pessimistic row locking scenario which was happening due to application design problem.

The situation is not new for most of the DBAs, and they know what is causing the block, the relationship of parent and child blockers, the blocking and block SIDs, lock modes etc., but things are sometimes difficult for non-DBA users who don’t know where to go, what to call and what to check where there is locking in the database stopping their program to finish and they are scratching their head.

I have tried to write a Python script which connects with the Oracle Database using cx_Oracle module using connection details and start executing blocking specific SQL statements embedded inside the python code. I have even tried to add exception handling for the cases when there is any syntax errors or any grammar issues. Tried to add color coding too with result seperators to make the output easy to read. The embedd code makes it self-reliant and complete and makes it very easy to run on any system.

The code is pasted below and is also available on my GitHub website. Here is the link to download the source code —> https://github.com/fatdba/OtherScripts/blob/main/Python-Locking-Main.py

We only have to make sure that we have Python, PIP and Python Module cx_Oracle installed on the server/host.

[oracle@fatdba ~]$ python --version
Python 2.7.5
[root@fatdba ~]# pip install cx_Oracle==7.3
Collecting cx_Oracle==7.3
  Downloading https://files.pythonhosted.org/packages/71/2a/91eb1ccb37a249772a93620ee0539a3f902b187ddb82978d8519abe03899/cx_Oracle-7.3.0-cp27-cp27mu-manylinux1_x86_64.whl (728kB)
    100% |โ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆโ–ˆ| 737kB 1.3MB/s
Installing collected packages: cx-Oracle
Successfully installed cx-Oracle-7.3.0
You are using pip version 8.1.2, however version 23.2.1 is available.
You should consider upgrading via the 'pip install --upgrade pip' command.
[root@fatdba ~]#
[root@fatdba ~]$ pip --version
pip 8.1.2 from /usr/lib/python2.7/site-packages (python 2.7)


Here is the code of the tool.
import cx_Oracle

# Database connection details
db_username = "system"
db_password = "xxxx"
db_host = "hostname-fqdn"
db_port = "1521"
db_service = "xxxx"

bold_start = "\033[1m"
color_green = "\033[32m"
reset_format = "\033[0m"

def print_colored(text, color_code):
    colored_text = "{}{}{}".format(color_code, text, reset_format)
    print(colored_text)

# Define the SQL statements
sql_statements = [
'''
SELECT rpad(instance_name, 17) current_instance, status, STARTUP_TIME, HOST_NAME, version, DATABASE_STATUS FROM v$instance
''',
"""
alter session set nls_date_format = 'DD-MON-YYYY HH24:MI:SS'
""",
"""
SELECT
    OUTPUT || CHR(10) || RPAD('-', LENGTH(OUTPUT) - LENGTH(REPLACE(OUTPUT, CHR(10), '')), '-') AS OUTPUT
FROM (
    SELECT
    'INST_ID -->  '||x.INST_ID || CHR(10) ||
    'Serial ID -->  '||x.sid || CHR(10) ||
    'Serial Num -->  '||x.serial# || CHR(10) ||
    'User Name -->  '||x.username || CHR(10) ||
    'Session Status -->  '||x.status || CHR(10) ||
    'Program -->  '||x.program || CHR(10) ||
    'Module -->  '||x.Module || CHR(10) ||
    'Action -->  '||x.action || CHR(10) ||
    'Machine -->  '||x.machine || CHR(10) ||
    'OS_USER -->  '||x.OSUSER || CHR(10) ||
    'Process -->  '||x.process || CHR(10) ||
    'State -->  '||x.State || CHR(10) ||
    'EVENT -->  '||x.event || CHR(10) ||
    'SECONDS_IN_WAIT -->  '||x.SECONDS_IN_WAIT || CHR(10) ||
    'LAST_CALL_ET -->  '||x.LAST_CALL_ET || CHR(10) ||
    'SQL_PROFILE --> '||SQL_PROFILE || CHR(10) ||
    'ROWS_PROCESSED --> '||ROWS_PROCESSED || CHR(10) ||
    'BLOCKING_SESSION_STATUS --> '||BLOCKING_SESSION_STATUS || CHR(10) ||
    'BLOCKING_INSTANCE --> '||BLOCKING_INSTANCE || CHR(10) ||
    'BLOCKING_SESSION --> '||BLOCKING_SESSION || CHR(10) ||
    'FINAL_BLOCKING_SESSION_STATUS --> '||FINAL_BLOCKING_SESSION_STATUS || CHR(10) ||
    'SQL_ID -->  '||x.sql_id || CHR(10) ||
    'SQL_TEXT -->  '||SQL_TEXT || CHR(10) ||
    'Logon Time -->  '||TO_CHAR(x.LOGON_TIME, 'MM-DD-YYYY HH24MISS') || CHR(10) ||
    'RunTime -->  '||ltrim(to_char(floor(x.LAST_CALL_ET/3600), '09')) || ':'
    || ltrim(to_char(floor(mod(x.LAST_CALL_ET, 3600)/60), '09')) || ':'
    || ltrim(to_char(mod(x.LAST_CALL_ET, 60), '09')) || CHR(10) AS OUTPUT,
    x.LAST_CALL_ET AS RUNT
    FROM   gv$sqlarea sqlarea
    ,gv$session x
    WHERE  x.sql_hash_value = sqlarea.hash_value
    AND    x.sql_address    = sqlarea.address
    AND    x.status='ACTIVE'
    AND x.event like '%row lock contention%'
    AND SQL_TEXT not like '%SELECT     OUTPUT || CHR(10)%'
    AND x.USERNAME IS NOT NULL
    AND x.SQL_ADDRESS    = sqlarea.ADDRESS
    AND x.SQL_HASH_VALUE = sqlarea.HASH_VALUE
)
ORDER BY RUNT DESC
""",
"""
with lk as (select blocking_instance||'.'||blocking_session blocker, inst_id||'.'||sid waiter
 from gv$session where blocking_instance is not null and blocking_session is not null and username is not null)
 select lpad(' ',2*(level-1))||waiter lock_tree from
 (select * from lk
 union all
 select distinct 'root', blocker from lk
 where blocker not in (select waiter from lk))
 connect by prior waiter=blocker start with blocker='root'
""",
"""
SELECT DECODE (l.BLOCK, 0, 'Waiting', 'Blocking ->') user_status
,CHR (39) || s.SID || ',' || s.serial# || CHR (39) sid_serial
,(SELECT instance_name FROM gv$instance WHERE inst_id = l.inst_id)
conn_instance
,s.SID
,s.PROGRAM
,s.inst_id
,s.osuser
,s.machine
,DECODE (l.TYPE,'RT', 'Redo Log Buffer','TD', 'Dictionary'
,'TM', 'DML','TS', 'Temp Segments','TX', 'Transaction'
,'UL', 'User','RW', 'Row Wait',l.TYPE) lock_type
,DECODE (l.lmode,0, 'None',1, 'Null',2, 'Row Share',3, 'Row Excl.'
,4, 'Share',5, 'S/Row Excl.',6, 'Exclusive'
,LTRIM (TO_CHAR (lmode, '990'))) lock_mode
,ctime
,object_name
FROM
   gv$lock l
JOIN
   gv$session s
ON (l.inst_id = s.inst_id
AND l.SID = s.SID)
JOIN gv$locked_object o
ON (o.inst_id = s.inst_id
AND s.SID = o.session_id)
JOIN dba_objects d
ON (d.object_id = o.object_id)
WHERE (l.id1, l.id2, l.TYPE) IN (SELECT id1, id2, TYPE
FROM gv$lock
WHERE request > 0)
ORDER BY id1, id2, ctime DESC
""",
"""
select l1.sid, ' IS BLOCKING ', l2.sid
from gv$lock l1, gv$lock l2 where l1.block =1 and l2.request > 0
and l1.id1=l2.id1
and l1.id2=l2.id2
""",
"""
select s2.inst_id,s1.username || '@' || s1.machine
 || ' ( SID=' || s1.sid || ' )  is blocking '
 || s2.username || '@' || s2.machine || ' ( SID=' || s2.sid || ' ) ' AS blocking_status
  from gv$lock l1, gv$session s1, gv$lock l2, gv$session s2
  where s1.sid=l1.sid and s2.sid=l2.sid and s1.inst_id=l1.inst_id and s2.inst_id=l2.inst_id
  and l1.BLOCK=1 and l2.request > 0
  and l1.id1 = l2.id1
  and l2.id2 = l2.id2
order by s1.inst_id
""",
"""
SELECT sid,
                                TYPE,
                                DECODE( block, 0, 'NO', 'YES' ) BLOCKER,
        DECODE( request, 0, 'NO', 'YES' ) WAITER,
        decode(LMODE,1,'    ',2,'RS',3,'RX',4,'S',5,'SRX',6,'X','NONE') lmode,
                                 decode(REQUEST,1,'    ',2,'RS',3,'RX',4,'S',5,'SRX',6,'X','NONE') request,
                                TRUNC(CTIME/60) MIN ,
                                ID1,
                                ID2,
        block
                        FROM  gv$lock
      where request > 0 OR block =1
""",
"""
select  sn.USERNAME,
        m.SID,
        sn.SERIAL#,
        m.TYPE,
        decode(LMODE,
                0, 'None',
                1, 'Null',
                2, 'Row-S (SS)',
                3, 'Row-X (SX)',
                4, 'Share',
                5, 'S/Row-X (SSX)',
                6, 'Exclusive') lock_type,
        decode(REQUEST,
                0, 'None',
                1, 'Null',
                2, 'Row-S (SS)',
                3, 'Row-X (SX)',
                4, 'Share',
                5, 'S/Row-X (SSX)',
                6, 'Exclusive') lock_requested,
        m.ID1,
        m.ID2,
        t.SQL_TEXT
from    v$session sn,
        v$lock m ,
        v$sqltext t
where   t.ADDRESS = sn.SQL_ADDRESS
and     t.HASH_VALUE = sn.SQL_HASH_VALUE
and     ((sn.SID = m.SID and m.REQUEST != 0)
or      (sn.SID = m.SID and m.REQUEST = 0 and LMODE != 4 and (ID1, ID2) in
        (select s.ID1, s.ID2
         from   gv$lock S
         where  REQUEST != 0
         and    s.ID1 = m.ID1
         and    s.ID2 = m.ID2)))
order by sn.USERNAME, sn.SID, t.PIECE
"""
]

banner = """
=========================================================
      Locking Stats Report
        Author: Prashant Dixit
        Version : 1.0
       Date : 2023-August-11
========================================================
"""
print_colored(banner, color_green)

try:
    # Establishing a database connection
    dsn = cx_Oracle.makedsn(db_host, db_port, service_name=db_service)
    connection = cx_Oracle.connect(user=db_username, password=db_password, dsn=dsn)

    # Executing each SQL statement
    cursor = connection.cursor()
    for idx, statement in enumerate(sql_statements):
        statement = statement.strip()
        if statement:
            try:
                cursor.execute(statement)

                if statement.upper().startswith("SELECT"):
                    result = cursor.fetchall()
                    if result:
                        column_names = [desc[0] for desc in cursor.description]
                        print_colored("Column Headers: " + ", ".join(column_names), color_green)
                        print("Results:")

                        for row in result:
                            print("Row:")
                            for col_name, col_value in zip(column_names, row):
                                print("{}: {}".format(col_name, col_value))
                            print("\n")

                    else:
                        print("No results.")

                    # Add a newline after the output of the first two SQL statements
                    #if idx == 1:
                     #   print("\n")

                #print("\n" * 1)  # Add a gap of one  lines

            except Exception as e:
                print("Error executing statement:", statement)
                print("Error details:", str(e))

    connection.commit()
    print("SQL statements execution completed.")

except Exception as e:
    connection.rollback()
    print("An error occurred:", str(e))

finally:
    if connection:
        connection.close()

…..

……

……

The output will look like this.

[oracle@fatdbatest ~]$ python locking.py

=========================================================
      Locking Stats Report
        Author: Prashant Dixit 
        Version : 1.0
       Date : 2023-August-11
========================================================

Column Headers: CURRENT_INSTANCE, STATUS, STARTUP_TIME, HOST_NAME, VERSION, BLOCKED, DATABASE_STATUS
Results:
Row:
CURRENT_INSTANCE: fatdba
STATUS: OPEN
STARTUP_TIME: 2023-06-03 19:42:57
HOST_NAME: fatdba.com
VERSION: 19.0.0.0.0
BLOCKED: NO
DATABASE_STATUS: ACTIVE


Column Headers: OUTPUT
Results:
Row:
OUTPUT: INST_ID -->  1
Serial ID -->  5065
Serial Num -->  17982
User Name -->  SYS
Session Status -->  ACTIVE
Program -->  sqlplus@fatdba.com (TNS V1-V3)
Module -->  sqlplus@fatdba.com (TNS V1-V3)
Action -->
Machine -->  fatdba.com
OS_USER -->  oracle
Process -->  6873
State -->  WAITING
EVENT -->  enq: TX - row lock contention
SECONDS_IN_WAIT -->  3
LAST_CALL_ET -->  4
SQL_PROFILE -->
ROWS_PROCESSED --> 0
BLOCKING_SESSION_STATUS --> VALID
BLOCKING_INSTANCE --> 1
BLOCKING_SESSION --> 5062
FINAL_BLOCKING_SESSION_STATUS --> VALID
SQL_ID -->  vdksq7js9b0cp
SQL_TEXT -->  update locking set id=100
Logon Time -->  08-11-2023 215112
RunTime -->  00:00:04

-------------------------

Column Headers: USER_STATUS, SID_SERIAL, CONN_INSTANCE, SID, PROGRAM, INST_ID, OSUSER, MACHINE, LOCK_TYPE, LOCK_MODE, CTIME, OBJECT_NAME
Results:
Row:
USER_STATUS: Blocking ->
SID_SERIAL: '5062,50729'
CONN_INSTANCE: fatdba
SID: 5062
PROGRAM: sqlplus@fatdba.com (TNS V1-V3)
INST_ID: 1
OSUSER: oracle
MACHINE: fatdba.com
LOCK_TYPE: Transaction
LOCK_MODE: Exclusive
CTIME: 9241
OBJECT_NAME: LOCKING


Row:
USER_STATUS: Waiting
SID_SERIAL: '5065,17982'
CONN_INSTANCE: fatdba
SID: 5065
PROGRAM: sqlplus@fatdba.com (TNS V1-V3)
INST_ID: 1
OSUSER: oracle
MACHINE: fatdba.com
LOCK_TYPE: Transaction
LOCK_MODE: None
CTIME: 5
OBJECT_NAME: LOCKING

Column Headers: SID, 'ISBLOCKING', SID
Results:
Row:
SID: 5062
'ISBLOCKING':  IS BLOCKING
SID: 5065


Column Headers: INST_ID, BLOCKING_STATUS
Results:
Row:
INST_ID: 1
BLOCKING_STATUS: SYS@fatdba.com ( SID=5062 )  is blocking SYS@fatdba.com ( SID=5065 )


Column Headers: SID, TYPE, BLOCKER, WAITER, LMODE, REQUEST, MIN, ID1, ID2, BLOCK
Results:
Row:
SID: 5062
TYPE: TX
BLOCKER: YES
WAITER: NO
LMODE: X
REQUEST: NONE
MIN: 154
ID1: 327688
ID2: 5988830
BLOCK: 1


Row:
SID: 5065
TYPE: TX
BLOCKER: NO
WAITER: YES
LMODE: NONE
REQUEST: X
MIN: 0
ID1: 327688
ID2: 5988830
BLOCK: 0


Column Headers: USERNAME, SID, SERIAL#, TYPE, LOCK_TYPE, LOCK_REQUESTED, ID1, ID2, SQL_TEXT
Results:
Row:
USERNAME: SYS
SID: 5065
SERIAL#: 17982
TYPE: TX
LOCK_TYPE: None
LOCK_REQUESTED: Exclusive
ID1: 327688
ID2: 5988830
SQL_TEXT: update locking set id=100

Hope It Helped!
Prashant Dixit

Posted in Uncategorized | Tagged: , , , | 1 Comment »

Golden Gate Classic Version 21 with XAG Agents failed to start

Posted by FatDBA on July 25, 2023

Hi Guys,

Recently while working on a Golden Gate setup Classic version 21 with XAG GI bundled agents version 9.1 (standalone deployment) on the top of Oracle 21.3.0 faced a strange issues where the GG failed to start and throwing errors ..

CRS-2672: Attempting to start 'xag.ggtest.goldengate' on 'host'
CRS-2674: Start of 'xag.ggtest.goldengate' on 'host' failed
CRS-2679: Attempting to clean 'xag.ggtest.goldengate' on 'host'
CRS-2681: Clean of 'xag.ggtest.goldengate' on 'host' succeeded
CRS-4000: Command Start failed, or completed with errors.

I checked for XAG errors in /diag/crs/crs_scriptagent_oracle.trc and I have observed that every time I try to start the GG, it prints “DATASTORETYPE 0 not found” in the logs but giving no hint about the cause.
Next I have checked for the version of XAG pointing to ($GRID_HOME/bin/crsctl stat res xag.ggtest.goldengate -f ) and it was pointing to the older version of the GG. It says 9.x was registered with the CRS even when the PATH is pointing to the new GG version 10.x

As an action next you will have to remove the GG resource from clusterware registry which is pointing to the old or incorrect version (9.x in my case).

[oracle@fatdba-07-test bin]$ /u01/app/grid/xag/bin/agctl remove goldengate ggtest

[oracle@fatdba-07-test bin]$

Once it is removed from the clusterware registry, next add the new version while pointing to the correct version.

[oracle@fatdba-07-test bin]$ ./agctl add goldengate ggtest --gg_home /ogg/newgg/version10.2 --nodes rac01,rac02 --vip_name ogg_vip --filesystems ora.acfs.oggvol.acfs --databases ora.racdb.db --oracle_home /u01/app/oracle/product/21.3.0/dbhome_1 --mo nitor_extracts ext1 --critical_extracts ext1

Start your Golden Gate now ... 

[oracle@fatdba-07-test bin]$ ./agctl status goldengate ogg_ha
Goldengate instance 'ggtest' is running on rac01

I highly recommend that you totally remove the old 9.x or any previous version to avoid such cases if they are no longer in use and there is no dependency on previous version.

Hope It Helped!
Prashant Dixit

Posted in Uncategorized | Tagged: , , | Leave a Comment »

An Oracle Deadlock scenario and the importance of Event 10027 trace …

Posted by FatDBA on February 16, 2023

Hi Guys,

Recently someone asked me about Oracle debug 10027 trace event which we use in case of a deadlock scenario i.e. ORA-0060. Though the deadlock itself creates a trace file in DIAG directory, but 10027 trace event gives you a better control over the amount and type of DIAG information generated in response to the deadlock case. I mean the default trace file for deadlock (ora-60) contains cached cursors, a deadlock graph, process state info, current SQL Statements of the session involved and session wait history.
Event 10027 may be used to augment the trace information with a system state dump or a call stack in an attempt to find the root cause of the deadlocks. The minimum amount of trace information is written at level 1, at this level it will hardly contain deadlock graph and current AQL statements of the sessions involved.

In todays post I will try to simulate a deadlock scenario in one of my test box and will generate the 10027 trace with level 2 to get more information. Level 2 will give you cached cursors, process state info, session wait history for all sessions and the system state which is not possible in case of level 1. I am going to try with the Level 4 here as I want to get system state dump and don’t want to complicate this scenario.

I am going to create two tables – TableB is child table of TableA and some supporting objects to simulate the deadlock case.
Will try to simulate a deadlock scenario when insert/update/delete happens on TableB we need to sum the amount(amt) and then update it in TableA.total_amt column.

[oracle@oracleontario ~]$ sqlplus dixdroid/oracle90

SQL*Plus: Release 19.0.0.0.0 - Production on Thu Feb 16 03:58:12 2023
Version 19.15.0.0.0

Copyright (c) 1982, 2022, Oracle.  All rights reserved.

Last Successful login time: Thu Feb 16 2023 03:04:03 -05:00

Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.15.0.0.0

SQL> create table tableA (pk_id number primary key, total_amt number);

Table created.

SQL> create table tableB (pk_id number primary key, fk_id number references tableA(pk_id) not null, amt number);

Table created.

SQL>
SQL> CREATE OR REPLACE PACKAGE global_pkg
IS
fk_id tableA.pk_id%TYPE;
END global_pkg;  
/

Package created.

SQL>
SQL> CREATE OR REPLACE TRIGGER tableB_ROW_TRG
BEFORE INSERT OR UPDATE OR DELETE
ON tableB
FOR EACH ROW
BEGIN
IF INSERTING OR UPDATING
THEN
global_pkg.fk_id := :new.fk_id;
ELSE
global_pkg.fk_id := :old.fk_id;
END IF;
END tableB_ROW_TRG;
/

Trigger created.

SQL>
SQL>
SQL>
SQL> CREATE OR REPLACE TRIGGER tableB_ST_trg
AFTER INSERT OR UPDATE OR DELETE
ON tableB
BEGIN
IF UPDATING OR INSERTING
THEN
UPDATE tableA
SET total_amt =
(SELECT SUM (amt)
FROM tableB
WHERE fk_id = global_pkg.fk_id)
WHERE pk_id = global_pkg.fk_id;
ELSE
UPDATE tableA
SET total_amt =
(SELECT SUM (amt)
FROM tableB
WHERE fk_id = global_pkg.fk_id)
WHERE pk_id = global_pkg.fk_id;
END IF;
END tableB_ST_trg;

Trigger created.

SQL>
SQL>
SQL> insert into tableA values (1, 0);

1 row created.

SQL> insert into tableA values (2, 0);

1 row created.

SQL> insert into tableB values (123, 1, 100);

1 row created.

SQL> insert into tableB values (456,1, 200);

1 row created.

SQL> insert into tableB values (789, 1, 100);

1 row created.

SQL> insert into tableB values (1011, 2, 50);

1 row created.

SQL> insert into tableB values (1213,2, 150);

1 row created.

SQL> insert into tableB values (1415, 2, 50);

1 row created.

SQL> commit;

Commit complete.

SQL>

Lets query the table and see the record count and next will delete an entry from tableB and won’t commit. At the same time will check the locks — TM lock on tableA.

SQL>
SQL> select * from tableA;

     PK_ID  TOTAL_AMT
---------- ----------
         1        400
         2        250

SQL> delete tableB where pk_id = 1415;

1 row deleted.

SQL> SELECT sid,
(SELECT username
FROM v$session s
WHERE s.sid = v$lock.sid)
uname,
TYPE,
id1,
id2,
(SELECT object_name
FROM user_objects
WHERE object_id = v$lock.id1)
nm
FROM v$lock
WHERE sid IN (SELECT sid
FROM v$session
WHERE username IN (USER)); 


       SID UNAME                          TY        ID1        ID2 NM
---------- ------------------------------ -- ---------- ---------- ------------------------------
       440 DIXDROID                       AE        134          0
       440 DIXDROID                       TX     589853       3078
       440 DIXDROID                       TM      82284          0 TABLEB
       440 DIXDROID                       TM      82282          0 TABLEA


I will now connect to another session (sesion 2) and delete from tableB and that will induce a locking scenario in the database and session 2 will go into hung/waiting state.

---- from session 2:
SQL>
SQL>
SQL> delete tableB where pk_id = 1213;
.....
.........
............. <HUNG > <HUNG > <HUNG > <HUNG > <HUNG > 

Lets see more stats on the blocking session.

SQL>
SQL> SELECT (SELECT username
FROM v$session
WHERE sid = a.sid)
blocker,
a.sid,
' is blocking ',
(SELECT username
FROM v$session
WHERE sid = b.sid)
blockee,
b.sid
FROM v$lock a, v$lock b
WHERE a.block = 1 AND b.request > 0 AND a.id1 = b.id1 AND a.id2 = b.id2;  


BLOCKER                     SID 'ISBLOCKING'  BLOCKEE                               SID
-------------------- ---------- ------------- ------------------------------ ----------
DIXDROID                    440  is blocking  DIXDROID                              427

And as expected 440 SID is now blocking 427. Now lets go back to the original (session 1) and will try to delete from tableB again and this will snipe the session 2 which is still in hung/wait state and will throw a deadlock error (ORA-00060). Though we have already collected blocking information from v$lock + v$session but to get more clarify about blocking sessions, I will set the 10027 trace event with level 2.

This will increase our chance of finding the root cause of the deadlocks. If the setting shall persist across instance startups, you need to use the initialization parameter EVENT.

i.e. EVENT=”10027 trace name contex forever, level 2″ otherwise use ALTER SYSTEM version of it.

------------------------------------------------------------
-- Execute below statement in session1
------------------------------------------------------------
delete tableB where pk_id = 1213;





---------------------------------------------------------------------------------------
-- Oracle is throwing deadlock error as below in session2
---------------------------------------------------------------------------------------
SQL>
SQL> ALTER SYSTEM SET EVENTS '10027 trace name context forever, level 2';

System altered.

SQL> delete tableB where pk_id = 1213;
delete tableB where pk_id = 1213
       *
ERROR at line 1:
ORA-00060: deadlock detected while waiting for resource
ORA-06512: at "DIXDROID.TABLEB_ST_TRG", line 11
ORA-04088: error during execution of trigger 'DIXDROID.TABLEB_ST_TRG'

-- same captured in alert log too.
2023-02-16T04:02:57.648156-05:00
Errors in file /u01/app/oracle/diag/rdbms/dixitdb/dixitdb/trace/dixitdb_ora_29389.trc:
2023-02-16T04:03:00.019794-05:00
ORA-00060: Deadlock detected. See Note 60.1 at My Oracle Support for Troubleshooting ORA-60 Errors. More info in file /u01/app/oracle/diag/rdbms/dixitdb/dixitdb/trace/dixitdb_ora_29389.trc.

And we done, we were able to simulate the deadlock case in the database. Now lets dig into the trace file generated by the deadlock along with information flushed by 10027 trace event. It has all crucial information associated with the deadlock.

2023-02-16 04:13:34.115*:ksq.c@13192:ksqdld_hdr_dump():
DEADLOCK DETECTED ( ORA-00060 )
See Note 60.1 at My Oracle Support for Troubleshooting ORA-60 Errors

[Transaction Deadlock]


Deadlock graph:
                                          ------------Blocker(s)-----------  ------------Waiter(s)------------
Resource Name                             process session holds waits serial  process session holds waits serial
TX-00080009-00000C62-00000000-00000000         45     427     X        13193      24     440           X  22765
TX-0004001A-00000C1E-00000000-00000000         24     440     X        22765      45     427           X  13193




----- Information for waiting sessions -----
Session 427:
  sid: 427 ser: 13193 audsid: 3390369 user: 115/DIXDROID
    flags: (0x41) USR/- flags2: (0x40009) -/-/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 45 O/S info: user: oracle, term: UNKNOWN, ospid: 30174
    image: oracle@oracleontario.ontadomain (TNS V1-V3)
  client details:
    O/S info: user: oracle, term: pts/1, ospid: 30173
    machine: oracleontario.ontadomain program: sqlplus@oracleontario.ontadomain (TNS V1-V3)
    application name: SQL*Plus, hash value=3669949024
  current SQL:
  UPDATE TABLEA SET TOTAL_AMT = (SELECT SUM (AMT) FROM TABLEB WHERE FK_ID = :B1 ) WHERE PK_ID = :B1

Session 440:
  sid: 440 ser: 22765 audsid: 3380369 user: 115/DIXDROID
    flags: (0x41) USR/- flags2: (0x40009) -/-/INC
    flags_idl: (0x1) status: BSY/-/-/- kill: -/-/-/-
  pid: 24 O/S info: user: oracle, term: UNKNOWN, ospid: 29847
    image: oracle@oracleontario.ontadomain (TNS V1-V3)
  client details:
    O/S info: user: oracle, term: pts/2, ospid: 29846
    machine: oracleontario.ontadomain program: sqlplus@oracleontario.ontadomain (TNS V1-V3)
    application name: SQL*Plus, hash value=3669949024
  current SQL:
  delete tableB where pk_id = 1213

.....
.......


----- Current SQL Statement for this session (sql_id=duw5q5rpd5xvs) -----
UPDATE TABLEA SET TOTAL_AMT = (SELECT SUM (AMT) FROM TABLEB WHERE FK_ID = :B1 ) WHERE PK_ID = :B1
----- PL/SQL Call Stack -----
  object      line  object
  handle    number  name
0x8ed34c98        11  DIXDROID.TABLEB_ST_TRG
.......
.........


----- VKTM Time Drifts Circular Buffer -----
session 427: DID 0001-002D-000000D9     session 440: DID 0001-0018-0000001C
session 440: DID 0001-0018-0000001C     session 427: DID 0001-002D-000000D9

Rows waited on:
  Session 427: obj - rowid = 0001416A - AAAUFqAAHAAAMgvAAB
  (dictionary objn - 82282, file - 7, block - 51247, slot - 1)
  Session 440: obj - rowid = 0001416C - AAAUFsAAHAAAMg/AAE
  (dictionary objn - 82284, file - 7, block - 51263, slot - 4)
.....
.......


Current Wait Stack:
     0: waiting for 'enq: TX - row lock contention'
        name|mode=0x54580006, usn<<16 | slot=0x4001a, sequence=0xc1e
        wait_id=69 seq_num=70 snap_id=1
        wait times: snap=18.173838 sec, exc=18.173838 sec, total=18.173838 sec
        wait times: max=infinite, heur=18.173838 sec
        wait counts: calls=6 os=6
        in_wait=1 iflags=0x15a0
    There is at least one session blocking this session.
      Dumping 1 direct blocker(s):
        inst: 1, sid: 440, ser: 22765
      Dumping final blocker:
        inst: 1, sid: 440, ser: 22765
    There are 1 sessions blocked by this session.
    Dumping one waiter:
      inst: 1, sid: 440, ser: 22765
      wait event: 'enq: TX - row lock contention'
        p1: 'name|mode'=0x54580006
        p2: 'usn<<16 | slot'=0x80009
        p3: 'sequence'=0xc62
      row_wait_obj#: 82284, block#: 51263, row#: 4, file# 7
      min_blocked_time: 0 secs, waiter_cache_ver: 33942
    Wait State:
      fixed_waits=0 flags=0x22 boundary=(nil)/-1
    Session Wait History:
        elapsed time of 0.004677 sec since current wait
........
............


24: USER ospid 29847 sid 440 ser 22765, waiting for 'enq: TX - row lock contention'
          Cmd: DELETE
          Blocked by inst: 1, sid: 427, ser: 13193
          Final Blocker inst: 1, sid: 427, ser: 13193
.....
.............


45: USER ospid 30174 sid 427 ser 13193, waiting for 'enq: TX - row lock contention'
          Cmd: UPDATE
          Blocked by inst: 1, sid: 440, ser: 22765
          Final Blocker inst: 1, sid: 440, ser: 22765
.........
.............


 The history is displayed in reverse chronological order.

    sample interval: 1 sec, max history 120 sec
    ---------------------------------------------------
      [19 samples,                                         04:13:16 - 04:13:34]
        waited for 'enq: TX - row lock contention', seq_num: 70
          p1: 'name|mode'=0x54580006
          p2: 'usn<<16 | slot'=0x4001a
          p3: 'sequence'=0xc1e
      [14 samples,                                         04:13:01 - 04:13:15]
        idle wait at each sample
      [session created at: 04:13:01]
    ---------------------------------------------------
    Sampled Session History Summary:
      longest_non_idle_wait: 'enq: TX - row lock contention'
      [19 samples, 04:13:16 - 04:13:34]
    ---------------------------------------------------
.........
..........


      Virtual Thread:
      kgskvt: 0x9b0e7f10, sess: 0x9ccdd4b8, pdb: 0, sid: 427 ser: 13193
      vc: (nil), proc: 0x9db42028, idx: 427
      consumer group cur: OTHER_GROUPS (pdb 0) (upd? 0)
mapped: DEFAULT_CONSUMER_GROUP, orig:  (pdb 0)
      vt_state: 0x2, vt_flags: 0xE030, blkrun: 0, numa: 1
      inwait: 1, wait event: 307, posted_run: 0
      lastmodrngcnt: 0, lastmodrngcnt_loc: '(null)'
      lastmodrblcnt: 0, lastmodrblcnt_loc: '(null)'
      location where insched last set: kgskbwt
      location where insched last cleared: kgskbwt
      location where inwait last set: kgskbwt
      location where inwait last cleared: NULL
      is_assigned: 1, in_scheduler: 0, insched: 0
      vt_active: 0 (pending: 1)
      vt_pq_active: 0, dop: 0, pq_servers (cur: 0 cg: 0)
      ps_allocs: 0, pxstmts (act: 0, done: 0 cg: 0)
      used quanta (usecs):
      stmt: 57272, accum: 0, mapped: 0, tot: 57272
      exec start consumed time lapse: 164377 usec
      exec start elapsed time lapse: 18179246 usec
      idle time: 0 ms, active time: 57272 (cg: 57272) usec
      last updnumps: 0 usec, active time (pq: 0 ps: 0) ms
      cpu yields:       stmt: 0, accum: 0, mapped: 0, tot: 0
      cpu waits:       stmt: 0, accum: 0, mapped: 0, tot: 0
      cpu wait time (usec):       stmt: 0, accum: 0, mapped: 0, tot: 0
      ASL queued time outs: 0, time: 0 (cur 0, cg 0)
      PQQ queued time outs: 0, time: 0 (cur 0, cg 0)
      Queue timeout violation: 0
      calls aborted: 0, num est exec limit hit: 0
      KTU Session Commit Cache Dump for IDLs:
      KTU Session Commit Cache Dump for Non-IDLs:
      ----------------------------------------
........
.............

Hope It Helped!
Prashant Dixit

Posted in Uncategorized | Tagged: , , , | 2 Comments »

Here goes my first blog post on Real Application Testing on Oracle Blogging platform …

Posted by FatDBA on January 30, 2023

I’m excited to announce that I’ve authored my first blog post on Oracle’s multi-cloud observability and management platform.ย 
My post “Real Application Testing for Capture and Replay in a PDB, a great addition in 19c.” recently got published by Oracle Corporation on their blogging platform ๐Ÿ™‚ ๐Ÿ™‚ ๐Ÿ™‚ ๐Ÿ™‚

https://blogs.oracle.com/observability/post/real-application-testing-for-capture-and-replay-in-a-pdb-a-great-addition-was-made-in-19c

Hope It Helped!
Prashant Dixit

Posted in Advanced | Tagged: , , | Leave a Comment »

What is Cluster Health Advisor GUI or CHAG ?

Posted by FatDBA on January 4, 2023

CHA GUI (CHAG) is a graphical user interface for Cluster Health Advisor (CHA) which was earlier internal to Oracle teams but its now available to the customers. It is a standalone, interactive, real-time capable front-end/GUI to the classic CHA utility. Oracle 12.2 is the first version that is supported by CHA GUI (CHAG). You only require RAC license and there is no need for any additional license to use CHAG tool.

CHAG communicates directly with the Grid Infrastructure Management Repository (GIMR) using a JDBC connection.. GIMR is mandatory for CHAG to work as it fetches the data out of the GIMR repository. In case you don’t have the GIMR repo installed, for example on 19c databases as GIMR is optional there, you can use the local mode for CHAG to work, but in absence of GIMR mgmt repo you will not get the historical abilities to go back in time.

Installation is quite simple, you have to download and unzip the software on one of your cluster machines and I recommend not to dump it inside your ORACLE HOME, but in a separate place. CHAG requires X11 or XHost and Java as it uses Java Swing to open the GUI. CHAG can operate in several modes:

  • With a default connection to GIMR Database. This option initiate a live session and provide real-time monitoring.
  • With a user specified location of a GIMR Database (option -P). This option initiate a live session and provide real-time monitoring.
  • Read in a text file with monitoring data (option -f). This initiates a passive session, which allow to analyze textual data extracted from a GIMR, or data collected during a live session. This data is held in a “*.mdb” file.
  • Parse text file with data and generate JSON object with information similar to query “diagnosis” (option -C). This mode of operation ‘chag -C -f ‘ directs CHAG to parse a *.mdb file and to generate a summary of its content in JSON format.

For the offline mode you can get the “mdb” file to analyze using below command. Depending on the time model you will get n number of mdb files for the period.

chactl export repository -format mdb -start <timestamp> -end <timestamp>

About the usage, CHAG is invoked using the ‘chag’ script available in the bin directory of the CHA Home. CHAG is designed primarily for Cluster or Database experts. Usage is quite simple and straight forward, you can move the pointer/slider to choose any particular timeframe to catch problems, their cause and the corrective actions. You can use it both in real time and offline version, its just that for real time you have to be on any of the cluster node, for offline you can generate the MDB file (cha datafile) and can run it anywhere on the client machine with no need of oracle home and only Java will be needed.

Below is the CHAG look and feel, its running on a 2 node RAC cluster where we have two databases installed. Here you see few color codes, where red colors means there were few problems during that interval.

Next is how it explains more about any particular problem caught for the timeslot. Gives you cause and the corrective action, for example in below screenshot it has detected that the ASM IO service time is higher than the expected which points to the underlying IO Subsystem used by ASM disks.

You can use SHIFT keys combinations to get wait event specific details for the selected time period.

You can use few other SHIFT key combinations to present the same data in the form of line graphs.

Few more examples or problems detected by the CHAG. This time it was reporting for redo log writes which are slower and that is something expected as ASM IO is slow too means the entire IO subsystem is impacted.

I highly recommend all readers to go through Doc ID 2340062.1 on metalink for more details on Cluster Health Advisor Graphical User Interface – CHAG.

Hope It Helped!
Prashant Dixit

Posted in Advanced, troubleshooting | Tagged: , , , | Leave a Comment »

TRANLOGOPTIONS, a crucial performance parameter, Golden Gate 21c, a BUG and a quick workaround โ€ฆ

Posted by FatDBA on October 23, 2022

One of the crucial performance parameter for Golden gate extract process is TRANLOGOPTIONS which controls the way that it interacts with the transaction log. You can use multiple TRANLOGOPTIONS statements in the same parameter file, or you can specify multiple options within the same TRANLOGOPTIONS statement.

There are lot of performance related options i.e. INCLUDEAUX (AUX trails when reading audit trails), DBLOGREADERBUFSIZE etc. that you can use with TRANLOGOPTIONS parameter, but recently I’d tried one of the tuning parameter PERFORMANCEPROFILE with our medium intensity workload. It can be set to HIGH and MEDIUM (default). It helps achieve better performance by grouping the parameters that affect performance. Once the performance profile is set up, this option automatically configures the applicable parameters, to achieve the desired throughput and latency.

We’d used this parameter in one of our 21c (21.7.0) GG installation with TRANLOGOPTIONS PERFORMANCEPROFILE HIGH, but immediately we’d started seeing spikes in extract’s latency. This was might be because it increases the Extract’s read buffer size to 8MB and the rule to purge the extract read buffer is either when the buffer is full or there is no ingress records for 0.2 seconds. Therefore, any uninterrupted workload with Extract consumption rate below 8MB will result in integrated Extract latency to exceed 1 second.

We’d checked with Oracle support and as a quick temporary solution they’d suggested to not use PERFORMANCEPROFILE parameter with HIGH flag, as the Extract consumption/intake rates are below specific value, such as ~15 MB/sec to get ~0.5 second extract response times. Hence we’d set the buffer size to one-third of the redo generation rate in MB/sec to get ~0.3 second maximum Extract latency. They also marked this as Bug 33772499 for GG 21c for July 2022 release.

Hope It Helped!
Prashant Dixit

Posted in Advanced, troubleshooting | Tagged: , , , | Leave a Comment »

Differences I have noticed in the Query Block Registry section of an execution plan between Oracle 19c and 21c

Posted by FatDBA on October 10, 2022

Hi Guys,

Todays post is a quick one about the difference that I have noticed in one of the extended execution plan section ‘Query block registry‘ between Oracle 19c (19.8) and Oracle 21c (21.3). I am not going to explain about query blocks etc. here as I’ve already made few blog posts on those topics in the past, this one is about the difference that you will observe between two said database versions for QBR section in execution plans.

First I am going to use the option/flag ‘qbregistry‘ (for Query block registry info) in Oracle database version 19.16, and next will repeat same steps in Oracle 21.3. Query block registy information can also be collect from the 10053 optimizer traces, but I always notice that one’s there in CBO traces are more repetitive that what you see as a concise version through execution plans with ‘qbregistry‘ option.

So, I have already set the playground, for testing purpose, created two sample tables and have written two outer join queries. One for each table. Then combining the results of these using union all.

--
-- In Oracle 19.16 Database
--
SQL*Plus: Release 19.0.0.0.0 - Production on Sun Oct 9 03:17:19 2022
Version 19.8.0.0.0

SQL> explain plan for select /*+ GATHER_PLAN_STATISTICS */ *
from   toys, bricks
where  toy_id = brick_id (+)
union all
select *
from   toys, bricks
where  toy_id (+) = brick_id
and    toy_id is null;  

Explained.


SQL> select * from table(dbms_xplan.display('PLAN_TABLE',NULL,'+alias +outline +qbregistry'));

PLAN_TABLE_OUTPUT
--------------------------------------------------------------------------------
Plan hash value: 731550672

-------------------------------------------------------------------------------
| Id  | Operation            | Name   | Rows  | Bytes | Cost (%CPU)| Time     |
-------------------------------------------------------------------------------
|   0 | SELECT STATEMENT     |        |     6 |   354 |     8   (0)| 00:00:01 |
|   1 |  UNION-ALL           |        |       |       |            |          |
|*  2 |   HASH JOIN OUTER    |        |     3 |   177 |     4   (0)| 00:00:01 |
|   3 |    TABLE ACCESS FULL | TOYS   |     3 |    96 |     2   (0)| 00:00:01 |
|   4 |    TABLE ACCESS FULL | BRICKS |     3 |    81 |     2   (0)| 00:00:01 |
|*  5 |   FILTER             |        |       |       |            |          |
|*  6 |    HASH JOIN OUTER   |        |     3 |   177 |     4   (0)| 00:00:01 |
|   7 |     TABLE ACCESS FULL| BRICKS |     3 |    81 |     2   (0)| 00:00:01 |
|   8 |     TABLE ACCESS FULL| TOYS   |     3 |    96 |     2   (0)| 00:00:01 |
-------------------------------------------------------------------------------

Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SET$1
   2 - SEL$1
   3 - SEL$1 / TOYS@SEL$1
   4 - SEL$1 / BRICKS@SEL$1
   5 - SEL$2
   7 - SEL$2 / BRICKS@SEL$2
   8 - SEL$2 / TOYS@SEL$2

Outline Data
-------------

  /*+
      BEGIN_OUTLINE_DATA
      USE_HASH(@"SEL$1" "BRICKS"@"SEL$1")
      LEADING(@"SEL$1" "TOYS"@"SEL$1" "BRICKS"@"SEL$1")
      FULL(@"SEL$1" "BRICKS"@"SEL$1")
      FULL(@"SEL$1" "TOYS"@"SEL$1")
      USE_HASH(@"SEL$2" "TOYS"@"SEL$2")
      LEADING(@"SEL$2" "BRICKS"@"SEL$2" "TOYS"@"SEL$2")
      FULL(@"SEL$2" "TOYS"@"SEL$2")
      FULL(@"SEL$2" "BRICKS"@"SEL$2")
      OUTLINE_LEAF(@"SET$1")
      OUTLINE_LEAF(@"SEL$2")
      OUTLINE_LEAF(@"SEL$1")
      ALL_ROWS
      DB_VERSION('19.1.0')
      OPTIMIZER_FEATURES_ENABLE('19.1.0')
      IGNORE_OPTIM_EMBEDDED_HINTS
      END_OUTLINE_DATA
  */

Predicate Information (identified by operation id):
---------------------------------------------------

   2 - access("TOY_ID"="BRICK_ID"(+))
   5 - filter("TOY_ID" IS NULL)
   6 - access("TOY_ID"(+)="BRICK_ID")

Note
-----
   - dynamic statistics used: dynamic sampling (level=2)

Query Block Registry:
---------------------
<q o="2" f="y"><n><![CDATA[SET$1]]></n><f><h><t><![CDATA[NULL_HALIAS]]></t><s><![CDATA[SET$1]]></s></h></f></q>
<q o="2" f="y"><n><![CDATA[SEL$1]]></n><f><h><t><![CDATA[BRICKS]]></t><s><![CDATA[SEL$1]]></s></h><h><t><![CDATA[TOYS]]></t><s><![CDATA[SEL$1]]> </s></h></f></q>
<q o="2" f="y"><n><![CDATA[SEL$2]]></n><f><h><t><![CDATA[BRICKS]]></t><s><![CDATA[SEL$2]]></s></h><h><t><![CDATA[TOYS]]></t><s><![CDATA[SEL$2]]> </s></h></f></q>

73 rows selected.

SQL>
SQL> 

Above ‘Query Block Registry’ XML translates to something like this
SET$1 NULL_HALIAS|SET$1
SEL$1 BRICKS|SEL$1|TOYS|SEL$1
SEL$2 BRICKS|SEL$2|TOYS|SEL$2

Considering we have a two SELECT statements, one for each table, internally optimizer has created two query blocks SEL$1 and SEL$2, one for each of the select. Here its using a hint alias name ‘NULL_HALIAS‘, and points to both of the two SELECT statements used in the original query.

Next, lets execute the same statement in Oracle 21c (21.3.0) version and see the difference in QBR section.

--
-- In Oracle 21.3 Database
--
-- Skipping few sections to have more clarity about discussed topic
SQL*Plus: Release 21.0.0.0.0 - Production on Sat Oct 8 23:57:12 2022
Version 21.3.0.0.0

SQL>  select * from table(dbms_xplan.display('PLAN_TABLE',NULL,'+alias +outline +qbregistry'));

PLAN_TABLE_OUTPUT
----------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 731550672
...
.....
Query Block Name / Object Alias (identified by operation id):
-------------------------------------------------------------

   1 - SET$1
   2 - SEL$1
   3 - SEL$1 / "TOYS"@"SEL$1"
   4 - SEL$1 / "BRICKS"@"SEL$1"
   5 - SEL$2
   7 - SEL$2 / "BRICKS"@"SEL$2"
   8 - SEL$2 / "TOYS"@"SEL$2"

Outline Data
-------------
......
Predicate Information (identified by operation id):
---------------------------------------------------
.....

Query Block Registry:
---------------------

  SEL$1 (PARSER) [FINAL]
  SEL$2 (PARSER) [FINAL]
  SET$1 (PARSER) [FINAL]

SQL>

Here with 21c (21.3), first thing is its no more coming in the form of an XML, The curious part out of the entire output is the ‘Query Block Registry‘ where the [FINAL] is the transformation that is chosen by the CBO. This assures that time was used on a query block which has been selected for an optimal plan.

That’s it, just a small tidbit this time! ๐Ÿ™‚

Hope It Helped!
Prashant Dixit

Posted in Advanced, troubleshooting | Tagged: , , , , | Leave a Comment »

A cool perl script to generate AWR report time series in any given timeframe …

Posted by FatDBA on October 2, 2022

Hi All,

Recently I was doing an analysis on a slothful database where I had to generate multiple AWR reports to cover almost 12 hours of the problem period. I usually go with few of the SQL scripts or AWR generator tools for my trend analysis, but I was little lucky in making unexpected and fortunate discovery on Metalink, found a cool Doc ID 2857522.1 which explains about an Oracle provided perl script to generate AWR report time series in any given timeframe. The script works with RDBMS 12.1 and later.

The script generates all the AWR reports with [begin snapid:end snapid] equal to [n,n+1] with n falling into a given time interval. The script is very handy and interactive, gives you option to choose between standard Text or HTML format, report type (RAC or Non-RAC type reports). You can call it in both command line or interactive mode.

This script generates a timeseries of awr report for a given database in a awr repository. It connects to database via oracle sid on the db server or via tnsalias. To run the script just execute B . To connect via oracle sid do not specify username password and tnsalias. In order to have sixty minutes time-series reports do not specify frequency if awr snapshot is executed every 60 minutes (default awr setting), set frequency 2 if awr snapshot is executed every 30 mins , 4 if awr snapshot is executed every 15 mins and so on. Leaving frequency blank will generate a series based on the awr snapshot frequency. All reports generated during execution will be saved in dumpdir, if the directory does not exist it will be automatically created.

By default awr reports will be generated in text format. To generate pluggable database awr reports connect to database by specifying username , password and tns alias of the pluggable db.

-- Call perl script awrdmp.pl to run the AWR extraction.
[oracle@fatdba ~]$ perl ./awrdmp.pl 
Enter usrname: - 
Enter password: - 
Enter tnsalias: - 
Enter frequency - 
Enter mode
(text/html) - text
CONNECTED AS SYSDBA  
RDBMS VERSION: 19.0.0.0.0

---- ---------- ------- ---------- ---------- -------------------- ------
NUM       DBID  INSTID     DBNAME     INSTID              MACHINE CONTID
---- ---------- ------- ---------- ---------- -------------------- ------
0 2511273110       2      DIXITD       fat2             racnode2      0
1 2511273110       1      DIXITD       fat1             racnode1      0

Enter database num: [0,1] -: 0
 0 2511273110       2      DIXITD       fat2             racnode2
RANGE AVAILABLE IN REPOSITORY FOR DBID 2511273110 INST 2:
------------------------------------------------------
[191 04-SEP-22 07.58.34.180 AM : 420 05-SEP-22 06.28.18.307 AM] 
Enter the minimum date interval (DD/MM/YYYY) -: 04/09/2022
Enter the maximum date interval (DD/MM/YYYY) -: 05/09/2022
GENERATING FILES
[  12 %] writing file : report_2_DIXITD_191_192.text 



--
--
--
-- In case if want to execute it in command line format.
perl awrdmp.pl --batch --freq 1 --instid 1 --dbid 2511273110  --dbn DIXITD --begin 04/09/2022 --end 05/09/2022 --rac --mode html


--
--
--
-- Output under dumpdir directory.
ls -ltr ./dumpdir
[...]
-rw-r--r-- 1 oracle oinstall 145147 Sep 05 14:16 report_1_DIXITD_196_197.text
-rw-r--r-- 1 oracle oinstall 159775 Sep 05 14:16 report_1_DIXITD_197_198.text
-rw-r--r-- 1 oracle oinstall 157100 Sep 05 14:16 report_1_DIXITD_198_199.text
-rw-r--r-- 1 oracle oinstall 148216 Sep 05 14:16 report_1_DIXITD_199_200.text
-rw-r--r-- 1 oracle oinstall 144003 Sep 05 14:16 report_1_DIXITD_200_201.text
-rw-r--r-- 1 oracle oinstall 146216 Sep 05 14:16 report_1_DIXITD_201_202.text

Hope It Helped
Prashant Dixit

Posted in Advanced, troubleshooting | Tagged: , , , | Leave a Comment »

Are you looking for a method to stop automatic SQL quarantine without disabling the entire SQL Quarantine feature ? Welcome to Oracle 21c …

Posted by FatDBA on September 23, 2022

Hi All,

Recently I was working on a 21c database for a POC where at one point I want to disable automatic creation of SQL Quarantine, but without disabling the entire statement Quarantine feature. This 21.3.0.0.0 Database had got the resource manager enabled, and one of the SQL was taking long time to complete, longer than the allowed directive limits on IO & CPU TIME, and as expected the SQL was killed with message “ORA-00040: active time limit exceeded – call aborted” and the SQL plan was quarantined. I wanted to stop or disable the auto creation of SQL Quarantines for the SQL in question, after RM terminates the SQL.

If you want to read more about SQL Quarantine, please click this link to my earlier post with a demo about it.

I remember in 19c there wasn’t any way to achieve that and can only regulate behavior using two of the underscore parameters _quarantine_enabled or _optimizer_quarantine_sql. Oracle 21c has introduced two two new parameters to control the behavior of SQL Quarantine, and that specially solves this issue.

First one is optimizer_capture_sql_quarantine, if set to FALSE, would disable the automatic creation of SQL Quarantine configurations after RM termination of a SQL query execution. This is FALSE by default.

The second parameter is optimizer_use_sql_quarantine, if set to FALSE would disable the use of existing SQL Quarantine configurations in a database. This parameter determines whether the optimizer considers SQL Quarantine configurations when choosing an execution plan for a SQL statement. This is TRUE by default, thereby allowing users to manually create and use SQL Quarantine configurations.

Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0

-- Default Setting
SQL> show parameter OPTIMIZER_CAPTURE_SQL_QUARANTINE

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
optimizer_capture_sql_quarantine     boolean     FALSE
SQL>
SQL>

-- Default Setting
SQL> sho parameter OPTIMIZER_USE_SQL_QUARANTINE

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
optimizer_use_sql_quarantine         boolean     TRUE
SQL>
SQL>

Hope It Helped!
Prashant Dixit

Posted in Uncategorized | Tagged: , , , | Leave a Comment »

FRA full with archives ORA-38706 ORA-38708 ? Not always think of a BUG … And when that proud little DBA in me missed common sense

Posted by FatDBA on September 11, 2022

Hi All,
Some time back I was working on an 19.16 database where I’d to enable FLASHBACK on a database, but immediately kicked out with an error “ORA-38706: Cannot turn on FLASHBACK DATABASE logging. ORA-38708: not enough space for first flashback database log file”. So, I’d tried to expand the FRA size, but thought to check what there inside the FRA, it was 99.9% full with 270 archive log files occupying 99.39% of the total allocated space. So, everything was good till that point.

[oracle@fatdba ~]$ sqlplus / as sysdba

SQL*Plus: Release 19.0.0.0.0 - Production on Mon Sep 5 19:07:28 2022
Version 19.16.0.0.0

Copyright (c) 1982, 2022, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.16.0.0.0

SQL>
SQL> show parameter db_recovery_file_dest_size

NAME                                 TYPE        VALUE
------------------------------------ ----------- ------------------------------
db_recovery_file_dest_size           big integer 251G


NAME         SPACE_LIMIT_GB SPACE_AVAILABLE_GB PERCENT_FULL
------------ -------------- ------------------ ------------
+RECO                   251         .240234375         99.9


FILE_TYPE               PERCENT_SPACE_USED PERCENT_SPACE_RECLAIMABLE NUMBER_OF_FILES     CON_ID
----------------------- ------------------ ------------------------- --------------- ----------
CONTROL FILE                             0                         0               1          0
REDO LOG                                 0                         0               0          0
ARCHIVED LOG                         99.39                         0             270          0
BACKUP PIECE                           .01                         0               2          0
IMAGE COPY                               0                         0               0          0
FLASHBACK LOG                            0                         0               0          0
FOREIGN ARCHIVED LOG                     0                         0               0          0
AUXILIARY DATAFILE COPY                  0                         0               0          0

But I thought to check space at the ASM Level. I queried v$asm_diskgroup and results were totally opposite with what I saw with V$RECOVERY_FILE_DEST and v$flash_recovery_area_usage. RECO Disk Group (FRA location) was almost 100% free and only 0.54% was consumed. Same results were there when I’d queried RECO DG via asmcmd.

-- results from v$asm_diskgroup view
Disk Group            Sector   Block   Allocation
Name                    Size    Size    Unit Size State       Type   Total Size (MB) Used Size (MB) Pct. Used
-------------------- ------- ------- ------------ ----------- ------ --------------- -------------- ---------
DATA                     512   4,096    1,048,576 CONNECTED   EXTERN         691,197        356,322     51.55
OCRVFDG                  512   4,096    4,194,304 MOUNTED     EXTERN          25,596            100       .39
RECO                     512   4,096    1,048,576 CONNECTED   EXTERN       1,048,575          5,645       .54
                                                                     --------------- --------------
Grand Total:                                                               1,765,368        362,067



ASMCMD> lsdg
State    Type    Rebal  Sector  Logical_Sector  Block       AU  Total_MB  Free_MB  Req_mir_free_MB  Usable_file_MB  Offline_disks  Voting_files  Name
MOUNTED  EXTERN  N         512             512   4096  1048576    691197   334875                0          334875              0             N  DATA/
MOUNTED  EXTERN  N         512             512   4096  4194304     25596    25496                0           25496              0             N  OCRVFDG/
MOUNTED  EXTERN  N         512             512   4096  1048576   1048575  1043233                0         1043233              0             N  RECO/
ASMCMD>

At this point I’d started thinking about some kind of a BUG in the database, I know about few FRA related bugs in earlier Oracle versions. Just before I’d tried anything else, I thought to execute dbms_backup_restore.refreshagedfiles which refreshes the view. At the same time tried kra_options event which resets v$recovery_file_dest, but no luck ๐Ÿ˜ฆ

SQL>
SQL> alter session set events 'immediate trace name kra_options level 1';

Session altered.

SQL>  execute dbms_backup_restore.refreshagedfiles;

PL/SQL procedure successfully completed.

SQL>

And right at that point I was very sure it was happening all due to a bug and was thinking to contact Oracle support. But just before that, that proud little DBA in me thought, Am I missing something ? Any other possible areas I should have explored before connecting with OCS ?

I’d checked RMAN to see if it still has any expired archivelog details and ran ‘crosscheck archivelog all’, and it identified exactly 270 older archivelogs which were non existent. So, that proud little DBA was wrong ๐Ÿ™‚ .. When the count was matched exactly with the v$flash_recovery_area_usage, I’d deleted all of those expired archivelogs from catalog.

-- To Crosscheck all archivelog files present in the RMAN catalog.
RMAN> crosscheck archivelog all;

using target database control file instead of recovery catalog
allocated channel: ORA_DISK_1
channel ORA_DISK_1: SID=258 device type=DISK
validation failed for archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_1.261.1109109619 RECID=1 STAMP=1109109620
validation failed for archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_2.264.1109401205 RECID=2 STAMP=1109401206
validation failed for archived log
.....
........
..........
..............
validation failed for archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_268.463.1114203831 RECID=268 STAMP=1114203829
validation failed for archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_269.469.1114207455 RECID=269 STAMP=1114207454
validation succeeded for archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_321.531.1114624193 RECID=270 STAMP=1114624193
Crosschecked 270 objects


-- Delete expired archivelog files
RMAN>
RMAN>
RMAN> delete expired archivelog all;
...
.......
270     1    270     X 31-AUG-22
        Name: +RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_268.463.1114203831 RECID=268 STAMP=1114203829
..
.......
Do you really want to delete the above objects (enter YES or NO)? YES
deleted archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_1.261.1109109619 RECID=1 STAMP=1109109620
deleted archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_2.264.1109401205 RECID=2 STAMP=1109401206
deleted archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_3.265.1109671797 RECID=3 STAMP=1109671799
deleted archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_4.266.1109955617 RECID=4 STAMP=1109955618
deleted archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_5.267.1110233333 RECID=5 STAMP=1110233334
deleted archived log
archived log file name=+RECO/FATDBA/ARCHIVELOG/2022_07_02/thread_1_seq_6.268.1110485231 RECID=6 STAMP=1110485232
deleted archived log
Deleted 270 EXPIRED objects

RMAN>
RMAN>

And immediately I saw the change in FRA related dynamic views (V$RECOVERY_FILE_DEST and v$flash_recovery_area_usage) and matched the genuine utilization at the ASM level.

[oracle@fatdba ~]$ sqlplus / as sysdba

SQL*Plus: Release 19.0.0.0.0 - Production on Mon Sep 5 19:07:28 2022
Version 19.16.0.0.0

Copyright (c) 1982, 2022, Oracle.  All rights reserved.


Connected to:
Oracle Database 19c Enterprise Edition Release 19.0.0.0.0 - Production
Version 19.16.0.0.0

SQL>
SQL>
SQL> SELECT NAME,
       (SPACE_LIMIT / 1024 / 1024 / 1024) SPACE_LIMIT_GB,
         ((SPACE_LIMIT - SPACE_USED + SPACE_RECLAIMABLE) / 1024 / 1024 / 1024) AS SPACE_AVAILABLE_GB,
       ROUND((SPACE_USED - SPACE_RECLAIMABLE) / SPACE_LIMIT * 100, 1) AS PERCENT_FULL
  FROM V$RECOVERY_FILE_DEST;  

NAME         SPACE_LIMIT_GB SPACE_AVAILABLE_GB PERCENT_FULL
------------ -------------- ------------------ ------------
+RECO                   200          197.59082          1.2

SQL> select * from v$flash_recovery_area_usage;

FILE_TYPE               PERCENT_SPACE_USED PERCENT_SPACE_RECLAIMABLE NUMBER_OF_FILES     CON_ID
----------------------- ------------------ ------------------------- --------------- ----------
CONTROL FILE                           .01                         0               1          0
REDO LOG                                 0                         0               0          0
ARCHIVED LOG                           .57                         0               2          0
BACKUP PIECE                           .01                       .01               2          0
IMAGE COPY                               0                         0               0          0
FLASHBACK LOG                            0                         0               0          0
FOREIGN ARCHIVED LOG                     0                         0               0          0
AUXILIARY DATAFILE COPY                  0                         0               0          0

8 rows selected.

Hope It Helped!
Prashant Dixit

Posted in Uncategorized | Tagged: , , | Leave a Comment »