[20211115]12c以上版本Last Login Time 引发的故障.txt

--//昨天看了链接www.modb.pro/db/152906=>Oracle 12c New Feature: Last Login Time 引发的故障.
--//我一直认为oracle这个功能是不好的设计，大量密集的用户登陆会导致buffer busy waits。
--//对方遇到的问题就是登陆出现阻塞，原因是某个用户登陆后修改user$表，但是机器挂了，导致后续的用户无法登陆，出现library
--//cache lock。我在测试环境模拟看看，顺便测试wcx.sql脚本。

1.环境：
XXXXX> @ ver1
XXXXX> @ prxx
==============================
PORT_STRING                   : x86_64/Linux 2.4.xx
VERSION                       : 18.0.0.0.0
BANNER                        : Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
BANNER_FULL                   : Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
Version 18.3.0.0.0
BANNER_LEGACY                 : Oracle Database 18c Enterprise Edition Release 18.0.0.0.0 - Production
CON_ID                        : 0
PL/SQL procedure successfully completed.

2.测试：
--//注意修改后不提交：
XXXXX> select user#,name,SPARE6 from user$ where  name='TTT';
     USER# NAME                 SPARE6
---------- -------------------- --------------------
       105 TTT                  2021-11-11 09:01:59
--//9zg9qd9bm4spu

XXXXX> @ tpt/sql_id 9zg9qd9bm4spu %
Show SQL text, child cursors and execution stats for SQLID 9zg9qd9bm4spu child %
HASH_VALUE  CH# SQL_TEXT
---------- ---- ------------------------------------------------------------------------------------------------------------------------------------------------------
1462919866    0 update user$ set spare6=DECODE(to_char(:2, 'YYYY-MM-DD'), '0000-00-00', to_date(NULL), :2) where user#=:1

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 0000000069ABDA38 0000000108D6A758 2447725225          2          2          2          0              2      5.534     16.897         13          1          0               0

XXXXX> update user$ set spare6=DECODE(to_char(sysdate, 'YYYY-MM-DD'), '0000-00-00', to_date(NULL), sysdate) where user#=105;
1 row updated.   

--//其他用户登陆:
$ seq 10 | xargs -P 10 -IQ bash -c "sqlplus -s -l ttt/oracle@orcl <<<exit"

XXXXXcdb> @ wcx sysdate-1/1440 sysdate

-- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com )
%This     SECONDS  AAS #Blkrs WAIT_CHAIN                                                                                                                                               FIRST_SEEN           LAST_SEEN
------ ---------- ---- ------ -------------------------------------------------------------------------------------------------------------------------------------------------------- -------------------- --------------------
  10%           9    0      1 -> 38,20451,@1=>294,10284,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)] 2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>35,46402,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)]  2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)]                                                  2021-11-15 09:43:57  2021-11-15 09:44:05
  ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
  10%           9    0      1 -> 38,20451,@1=>285,21962,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)] 2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>409,35152,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)] 2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>286,53111,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)] 2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>164,47506,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)] 2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>27,25128,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)]  2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>151,9063,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)]  2021-11-15 09:43:57  2021-11-15 09:44:05
  10%           9    0      1 -> 38,20451,@1=>282,44344,@1=>library cache lock -> 276,37682,@1=>38,20451,@1=>enq: TX - row lock contention -> [idle blocker 1,276,37682 (sqlplus.exe)] 2021-11-15 09:43:57  2021-11-15 09:44:05
   2%           2    0      1 -> ,,@=>421,12408,@1=>                                                                                                                                   2021-11-15 09:43:09  2021-11-15 09:43:24
   1%           1    0      1 -> ,,@=>131,65094,@1=>control file parallel write                                                                                                        2021-11-15 09:43:51  2021-11-15 09:43:51
12 rows selected.
--//一样可以看见library cache lock。阻塞是sid＝276.

XXXXXcdb> @ sid 276
sid = 276
SPID       PID        SID    SERIAL# CLIENT_INFO          PNAME  TRACEFILE                                                         PROGRAM     TERMINAL     SQL_ID STATUS           C50
------ ------- ---------- ---------- -------------------- ------ ----------------------------------------------------------------- ----------- ------------ ------ ---------------- --------------------------------------------------
14690       70        276      37682                             /u01/app/oracle/diag/rdbms/orclcdb/orclcdb/trace/orclcdb_ora_1469 sqlplus.exe XXXXXBXX            INACTIVE         alter system kill session '276,37682' immediate;
                                                                 0.trc

XXXXXcdb> alter system kill session '276,37682' immediate;
System altered.

XXXXXcdb> @ wcx sysdate-0.1/1440 sysdate
-- Display ASH Wait Chain Signatures script v0.6 BETA by Tanel Poder ( http://blog.tanelpoder.com )
no rows selected

--//问题解决。

XXXXXcdb> @ tpt/sql_id 9zg9qd9bm4spu %
Show SQL text, child cursors and execution stats for SQLID 9zg9qd9bm4spu child %
HASH_VALUE  CH# SQL_TEXT
---------- ---- ------------------------------------------------------------------------------------------------------------------------------------------------------
1462919866    0 update user$ set spare6=DECODE(to_char(:2, 'YYYY-MM-DD'), '0000-00-00', to_date(NULL), :2) where user#=:1
1462919866    1 update user$ set spare6=DECODE(to_char(:2, 'YYYY-MM-DD'), '0000-00-00', to_date(NULL), :2) where user#=:1

 CH# PARENT_HANDLE    OBJECT_HANDLE     PLAN_HASH     PARSES   H_PARSES EXECUTIONS    FETCHES ROWS_PROCESSED     CPU_MS     ELA_MS       LIOS       PIOS      SORTS USERS_EXECUTING
---- ---------------- ---------------- ---------- ---------- ---------- ---------- ---------- -------------- ---------- ---------- ---------- ---------- ---------- ---------------
   0 0000000069ABDA38 0000000108D6A758 2447725225          4          2          4          0              4      8.374     18.955         21          1          0               0
   1 0000000069ABDA38 0000000101C7AD80 2447725225         21          1         21          0             21     28.689 298151.332         88          0          0               0

$ seq 10 | xargs -P 10 -IQ bash -c "sqlplus -s -l ttt/oracle@orcl <<<exit"
--//OK，问题消失。