Sunday, April 8, 2018

TM lock and no transaction commit

Oracle Document wrote:
COMMIT
  Use the COMMIT statement to end your current transaction and make permanent all changes performed in the transaction. 
  A transaction is a sequence of SQL statements that Oracle Database treats as a single unit. 
  This statement also erases all savepoints in the transaction and releases transaction locks.

ROLLBACK
  Use the ROLLBACK statement to undo work done in the current transaction or to manually undo the work done by an in-doubt distributed transaction.
It looks like that COMMIT / ROLLBACK are for transactions.

This Blog will show that COMMIT / ROLLBACK has to be executed even without any transactions.

The test code is also trying to reproduce and study MOS:
    Bug 26965236 : DELETE FROM TSDP_SENSITIVE_DATA$ CAUSING ENQ: TM - CONTENTION WAITS

Note: All tests are done in Oracle 12.1.0.2.

------------------ T0: Test SetUp ------------------ 
drop table tt1;

create table tt1 (x number, c1 number, c2 number);

------------------ T1: Session_1------------------ 
SQL(sid 190) > delete from sys.tsdp_sensitive_data$ where 1=2; 
  0 rows deleted.

------------------ T2: Session_2 ------------------ 
SQL(sid 290) > alter table tt1 drop column c2;

-- Session 290 hanging, blocked by 190.
-- same for   alter table k.tt1 set unused (c1);

------------------ T3: Monitor Session_3 ------------------ 
SQL(sid 390) > select o.object_name, k.* from v$lock k, dba_objects o where k.type in ('TM') and k.ID1 = o.object_id;
 
  OBJECT_NAME                    SID  TYPE  ID1      ID2  LMODE  REQUEST  CTIME  BLOCK
  -----------------------------  ---  ----  -------  ---  -----  -------  -----  -----
  TSDP_SENSITIVE_DATA$           190  TM    1576498  0    3      0        14     0    
  TSDP_SUBPOL$                   190  TM    1578689  0    3      0        14     0    
  TSDP_PROTECTION$               190  TM    1578695  0    3      0        14     1    
  TT1                            290  TM    2321087  0    6      0        9      0    
  WRI$_OPTSTAT_HISTHEAD_HISTORY  290  TM    601844   0    3      0        9      0    
  WRI$_OPTSTAT_HISTGRM_HISTORY   290  TM    601856   0    3      0        9      0    
  COM$                           290  TM    136      0    3      0        9      0    
  COL_USAGE$                     290  TM    456      0    3      0        9      0    
  OBJAUTH$                       290  TM    61       0    3      0        9      0    
  TSDP_SENSITIVE_DATA$           290  TM    1576498  0    3      0        9      0    
  TSDP_SUBPOL$                   290  TM    1578689  0    3      0        9      0    
  TSDP_PROTECTION$               290  TM    1578695  0    0      5        9      0    

--TSDP_PROTECTION$  REQUEST = 5
--Session_2 blocked by Session_1 in 'enq: TM - contention' Lock Mode 5 (SSX/SRX)

SQL(sid 390) > select * from v$transaction;
  0 rows selected.
  
  -- no TRX

SQL(sid 390) > select chain_signature, sid, blocker_sid, wait_event_text, p1, p1_text, p2, p2_text, p3, p3_text from v$wait_chains;

  CHAIN_SIGNATURE                                        SID  BLOCKER_SID  WAIT_EVENT_TEXT              P1          P1_TEXT    P2       P2_TEXT   P3  P3_TEXT
  -----------------------------------------------------  ---  -----------  ---------------------------  ----------  ---------  -------  --------  --  ---------------
  'SQL*Net message from client'<='enq: TM - contention'  290  190          enq: TM - contention         1414332421  name|mode  1578695  object #  0   table/partition
  'SQL*Net message from client'<='enq: TM - contention'  190               SQL*Net message from client  1413697536  driver id  1        #bytes    0


SQL(sid 390) > select * from dba_constraints where constraint_name = 'TSDP_PROTECTION$FKSD';

  OWNER  CONSTRAINT_NAME       CONSTRAINT_TYPE  TABLE_NAME        R_CONSTRAINT_NAME       DELETE_RULE  STATUS
  -----  --------------------  ---------------  ----------------  ----------------------  -----------  ------
  SYS    TSDP_PROTECTION$FKSD  R                TSDP_PROTECTION$  TSDP_SENSITIVE_DATA$PK  CASCADE      ENABLED


-- Suspending LGWR will not block commit in Session_1
--SQL> oradebug setorapid 13
--  Oracle pid: 13, Unix process pid: 18482, image: oracle@testdb (LGWR)
--SQL> oradebug suspend
--SQL> oradebug resume

------------------ T4: Session_1, Release TM Locks to deblock ------------------ 
SQL(sid 290) > commit;
One quick workaround is to disable the foreign key constraint if Transparent Sensitive Data Protection is not used.

  alter table sys.tsdp_protection$ disable constraint tsdp_protection$fksd;
If we suspend LGWR in Session_3 (see commented-out code), and repeat the whole test, the "commit" in Session_1 will not be blocked. It indicates no "commit record" written to redo log for this "commit" execution, in other words, not every "commit" generates a "commit record".

With event 10704, we can list all triggered TM Locks. (see Blog: Investigating Oracle lock issues with event 10704 )

SQL(sid 290) > alter session set events='10046 trace name context forever, level 1 : 10704 trace name context forever, level 3' tracefile_identifier='ksun_10704_1';

SQL(sid 290) > alter table tt1 drop column c1;

SQL(sid 290) > alter session set events='10046 trace name context off : 10704 trace name context off ';


ksqgtl *** TM-00236ABF-00000000-00000000-00000000 mode=6 flags=0x400 timeout=5 ***
...
ksqgtl *** TM-001816C7-00000000-00000000-00000000 mode=5 flags=0x400 timeout=21474836 ***
ksqcnv: TM-001816C7-00000000-00000000-00000000 mode=3 timeout=21474836
ksqcmi: TM-001816C7-00000000-00000000-00000000 mode=3 timeout=21474836
ksqrcl: TM-001816C7-00000000-00000000-00000000
...
ksqrcl: TM-00236ABF-00000000-00000000-00000000

  -- 00236ABF (2321087) = TT1
  -- 001816C7 (1578695) = SYS.TSDP_PROTECTION$
  
  -- ksqgtl: get lock 
  -- ksqcnv: convert lock
  -- ksqcmi: 
  -- ksqrcl: release lock
We can see that DDL_LOCK_TIMEOUT = 5 seconds has no effect in this case (line with "TM-00236ABF" for TT1). TM lock on SYS.TSDP_PROTECTION$ ("TM-001816C7") is first obtained in MODE 5 (SRX), then converted to 3 (RX).