[20250222]利用lcm.sh脚本测试软软解析(21c).txt

[20250222]利用lcm.sh脚本测试软软解析(21c).txt

--//利用自己写的lsm.sh脚本测试软软解析(21c).

1.环境：
SCOTT@book01p> @ver2
==============================
PORT_STRING                   : x86_64/Linux 2.4.xx
VERSION                       : 21.0.0.0.0
BANNER                        : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
BANNER_FULL                   : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
Version 21.3.0.0.0
BANNER_LEGACY                 : Oracle Database 21c Enterprise Edition Release 21.0.0.0.0 - Production
CON_ID                        : 0
PL/SQL procedure successfully completed.

$ cat loop3.txt
set verify off
DECLARE
   l_count PLS_INTEGER;
BEGIN
    FOR i IN 1..&&1
    LOOP
       EXECUTE IMMEDIATE 'select /*+ 9 */ count(*) from dept where deptno = 93834' INTO l_count ;
    END LOOP;
END;
/

$ cat record.txt
set verify off
variable v_method varchar2(20)
exec :v_method := '&&2';

define t=&&1;

column 3 new_value 3;
select decode('&3',null,'loop.txt','&&3') "3" from dual;

@@ &&3 5 &&2

insert into job_times values ( sys_context ('userenv', 'sid') ,dbms_utility.get_time ,'&&2') ;
commit ;

@@ &&3 &&t &&2

update job_times set time_ela = dbms_utility.get_time - time_ela where sid=sys_context ('userenv', 'sid') and method= :v_method;
commit;
quit

$ cat lcm.sh
#!/bin/bash

# arg1=mutex_address arg2=offset arg3=monitor_times

offset=${2:-4}
sleeps=${3:-20}
v_addr="0x${1}+${offset}"

echo "begin mutex value :"
gdb -q -batch -p $(pgrep -f ora_mmon_${ORACLE_SID}) -ex "x/8wx 0x${1}" -ex "quit" |  grep "^0x" | grep -v "^0x0"

gdb -q -batch -p $(pgrep -f ora_mmon_${ORACLE_SID}) -ex "set *(  int *)(${v_addr})=0x7777"  -ex "quit" >/dev/null

echo "modify mutex value :"
gdb -q -batch -p $(pgrep -f ora_mmon_${ORACLE_SID}) -ex "x/8wx 0x${1}" -ex "quit" |  grep "^0x" | grep -v "^0x0"

echo sleep $sleeps seconds
(sleep $sleeps ;gdb -q -batch -p $(pgrep -f ora_mmon_${ORACLE_SID}) -ex "set *(  int *)(${v_addr})=0x0"  -ex "quit" > /dev/null) &

sqlplus -s -l scott/book@book01p <<EOF
set echo off head off verify off feedback off define #
variable my_sid number
column spid new_value v_spid noprint
exec  :my_sid :=  userenv('sid');
select p.spid from v\$session s,v\$process p where s.sid = :my_sid and s.paddr=p.addr;
host strace -Ttt -y -f -p #v_spid -o laji.txt > /dev/null 2>&1 &
host echo "running at background : strace -Ttt -y -f -p #v_spid -o laji.txt >/dev/null 2>&1 &"
host sleep 1
set define &
@ loop3.txt  1 AAAA
quit
EOF

echo "end mutex value :"
gdb -q -batch -p $(pgrep -f ora_mmon_${ORACLE_SID}) -ex "x/8wx 0x${1}" -ex "quit" |  grep "^0x" | grep -v "^0x0"

mv -iv laji.txt mutex$(date +"%Y%m%d%H%M%S").txt
--//注意在执行loop3.txt脚本前要设置set define &，在这里浪费一点点时间。

2.测试出现阻塞的mutex地址：
$ zzdate;seq 10 | xargs -P 10 -IQ sqlplus -s -l scott/book@book01p @record.txt 1e5 AAAA loop3.txt > /dev/null;zzdate
trunc(sysdate)+09/24+33/1440+07/86400 1740274387.729109828
trunc(sysdate)+09/24+33/1440+12/86400 1740274392.528387235

SYS@book> @ mutexprofz idn,hash,loc,maddr "ts>=trunc(sysdate)+09/24+33/1440+07/86400"
-- MutexProf by Tanel Poder (http://www.tanelpoder.com)
-- Showing profile of top 50 sleeps...
-- column info : id idn hash hash_value=>hash_value ts=>sleep_timestamp
--               req=>requesting_session blk=>blocking_session val=>mutex_value maddr=>mutex_addr
SUM_SLEEPS      GETS_DIFF MUTEX_TYPE             IDN       HASH GET_LOCATION                      mutex_addr           OBJECT_NAME
---------- -------------- --------------- ---------- ---------- --------------------------------- -------------------- --------------------------------------------------------------------------------
         6         209507 Cursor Pin      3403546624 3403546624 kksLockDelete [KKSCHLPIN6]        000000006470C768     select /*+ 9 */ count(*) from dept where deptno = 93834
         4         101357 Cursor Pin      3403546624 3403546624 kksfbc [KKSCHLFSP2]               000000006470C768     select /*+ 9 */ count(*) from dept where deptno = 93834

--//mutex_addr=000000006470C768

$ ./lcm.sh 000000006470C768 4 20
begin mutex value :
0x6470c768:     0x00000000      0x00000000      0x003d0ab0      0x00011082
0x6470c778:     0xcade0000      0x00000000      0x00000000      0x00000000
modify mutex value :
0x6470c768:     0x00000000      0x00007777      0x003d0ab0      0x00011082
0x6470c778:     0xcade0000      0x00000000      0x00000000      0x00000000
sleep 20 seconds

running at background : strace -Ttt -y -f -p 5534 -o laji.txt >/dev/null 2>&1 &

end mutex value :
0x6470c768:     0x00000000      0x00000000      0x003d0ab2      0x00012240
0x6470c778:     0xcade0000      0x00000000      0x00000000      0x00000000
'laji.txt' -> 'mutex20250223100352.txt'
--//gets 0x003d0ab2-0x003d0ab0 = 0x2,增加2次，很好理解出现在2个GET_LOCATION:kksLockDelete [KKSCHLPIN6],kksfbc [KKSCHLFSP2]
--//sleeps 0x00012240-0x00011082 = 0x11be = 4542.

$ egrep "semtimedop|sched_yield|select" mutex20250223100352.txt|wc
   4542   54504  363360
--//sleeps 数量完成一致。

$ egrep "getrusage" mutex20250223100352.txt
5534  10:03:31.741740 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 22306}, ru_stime={0, 12914}, ...}) = 0 <0.000114>
5534  10:03:31.742017 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 22343}, ru_stime={0, 12935}, ...}) = 0 <0.000013>
5534  10:03:31.742156 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 22394}, ru_stime={0, 12964}, ...}) = 0 <0.000012>
5534  10:03:33.130828 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 25130}, ru_stime={0, 15078}, ...}) = 0 <0.000015>
5534  10:03:35.154824 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 37851}, ru_stime={0, 24603}, ...}) = 0 <0.000014>
5534  10:03:37.159906 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 46371}, ru_stime={0, 36290}, ...}) = 0 <0.000013>
5534  10:03:39.265663 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 52974}, ru_stime={0, 44145}, ...}) = 0 <0.000010>
5534  10:03:41.329461 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 67789}, ru_stime={0, 62366}, ...}) = 0 <0.000010>
5534  10:03:43.352760 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 77030}, ru_stime={0, 74067}, ...}) = 0 <0.000012>
5534  10:03:45.354729 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 93344}, ru_stime={0, 83688}, ...}) = 0 <0.000012>
5534  10:03:47.357422 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 96057}, ru_stime={0, 99155}, ...}) = 0 <0.000013>
5534  10:03:49.364437 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 108739}, ru_stime={0, 108739}, ...}) = 0 <0.000014>
5534  10:03:51.366873 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 129227}, ru_stime={0, 132379}, ...}) = 0 <0.000007>
5534  10:03:51.519412 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 130947}, ru_stime={0, 134065}, ...}) = 0 <0.000007>
5534  10:03:51.524268 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 132742}, ru_stime={0, 134065}, ...}) = 0 <0.000048>
5534  10:03:51.525429 getrusage(0x1 /* RUSAGE_??? */, {ru_utime={0, 132742}, ru_stime={0, 134065}, ...}) = 0 <0.000048>
--//间隔2秒。

$ awk '{print $3}' mutex20250223100352.txt | egrep "semtimedop|getrusage|sched_yield|select" | uniq -c| head -10
      3 getrusage(0x1
     92 select(0,
      1 getrusage(0x1
    437 select(0,
      1 getrusage(0x1
    337 select(0,
      1 getrusage(0x1
    290 select(0,
      1 getrusage(0x1
    662 select(0,
--//注意采用mutex wait scheme=1，但是开头并没有出现sched_yield.

$ egrep "semtimedop|sched_yield|select" mutex20250223100352.txt|head -4
5534  10:03:31.742412 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.040249>
5534  10:03:31.782774 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.121680>
5534  10:03:31.904552 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.080899>
5534  10:03:31.985592 select(0, [], [], [], {0, 1000}) = 0 (Timeout) <0.029052>
--//sleeps 1毫秒。