Some features in this post require a Diagnostics Pack license.
No sooner had I finished part 3 with some conclusions than I thought of another example I should have included and then someone else made a comment in an email which suggested another. (Thanks, JB!)
“It’s probably worth pointing out that NO TOOL can claim to identify the blocking SID->SQL in such a case as there is no relationship kept in Oracle between locks acquired by users and the SQL that acquired the locks”
I’ll try to deal with that point and some other thoughts I had here in a further example. For this example, I decided to suggest how to create a quick table so that you can test this out for yourself.
SQL> create user testuser identified by testuser 2 default tablespace USERS 3 temporary tablespace TEMP; User created. SQL> grant create session, create table to testuser; Grant succeeded. SQL> connect testuser/testuser Connected. SQL> create table test_tab1 as select object_id pk_id, object_name from all_objects; Table created.
As easy as that.
In the last part I showed that the SQL_ID for the last sample of a blocking session immediately before it went idle might not be the SQL statement holding the lock. In that case, it was fairly obvious that it wasn’t because it was a simple query that couldn’t have been responsible. However, it’s likely to be even more confusing if the SQL_ID captured by the ASH sample *looks* like it’s responsible, but isn’t, and the previous example didn’t illustrate that clearly.
Session 1 – Connected as TESTUSER
SQL> select pk_id, object_name from test_tab1 order by pk_id desc for update; <Trimmed> 890 DBMS_STANDARD 889 DBMS_STANDARD PK_ID OBJECT_NAME ---------- ------------------------------ 887 STANDARD 886 RE$NV_LIST 605 MAP_OBJECT 319 STMT_AUDIT_OPTION_MAP 317 STMT_AUDIT_OPTION_MAP 316 TABLE_PRIVILEGE_MAP 314 TABLE_PRIVILEGE_MAP 313 SYSTEM_PRIVILEGE_MAP 311 SYSTEM_PRIVILEGE_MAP 259 DUAL 258 DUAL 4477 rows selected. SQL> rollback; Rollback complete. SQL> select pk_id from test_tab1 where object_name='SYSTEM_PRIVILEGE_MAP' for update; PK_ID ---------- 311 313 SQL> rollback; Rollback complete. SQL> select pk_id from test_tab1 where pk_id=313 for update; PK_ID ---------- 313 SQL>
So session 1 has executed three different queries, all of which lock one or more rows including the row with PK_ID=313, has rolled back the first two (releasing the locks) and has just that row locked now.
Session 2 – Connected as TESTUSER
SQL> select pk_id from test_tab1 where pk_id=313 for update;
Session 2 hangs, waiting for the lock.
Session 1 – Connected as TESTUSER
SQL> rollback; Rollback complete.
So the lock is released and session 2 acquires the lock and then releases it
Session 2 – Connected as Testuser
PK_ID ---------- 313 SQL> rollback; Rollback complete.
OK, time to look at the ASH data for the last two minutes for TESTUSER sessions. (Note that I have added each session’s serial# to the query. Graham Wood corrected a statement I made in the last post …
“who is to say that that session 148 is the same session as the blocking session 148 and not an earlier session that has disconnected?”
… by pointing out that session_serial# would allow me to differentiate between different sessions where SID=148. I’ve updated the previous post to that effect.)
break on MY_TIME
column my_sid format 999
column my_ser format 99999
column my_state format a30
column my_blkr format 999
select to_char(a.sample_time, 'HH24:MI:SS') MY_TIME,a.session_id MY_SID,a.session_serial# MY_SER,
DECODE(a.session_state, 'WAITING' ,a.event, a.session_state) MY_STATE,a.xid, a.sql_id,
a.blocking_session MY_BLKR
from v$active_session_history a, dba_users u
where u.user_id = a.user_id
and u.username = 'TESTUSER'
and a.sample_time > SYSTIMESTAMP-(2/1440);
MY_TIME MY_SID MY_SER MY_STATE XID SQL_ID MY_BLKR
-------- ------ ------ ------------------------------ ---------------- ------------- -------
12:53:01 300 2739 enq: TX - row lock contention 2pa7rnqf65gj3 304
12:53:00 300 2739 enq: TX - row lock contention 2pa7rnqf65gj3 304
12:52:59 300 2739 enq: TX - row lock contention 2pa7rnqf65gj3 304
12:52:50 304 1445 ON CPU 0006000E0000884D 95k0s60jznz76
So what statement is SQL_ID ‘95k0s60jznz76’?
SQL> select sql_text from v$sql where sql_id='95k0s60jznz76'; SQL_TEXT ----------------------------------------------------------------------------- select pk_id, object_name from test_tab1 order by pk_id desc for update
Let’s face it, if you were to look at this data, how likely is it that you would think that that statement was responsible for blocking session 2, when it wasn’t?