[20210916]探究mutex的值 8.txt

[20210916]探究mutex的值 8.txt --//昨天做了mutex相关sleep的测试,我前面提到隐含参数 SYS@book> @ hide mutex NAME               DESCRIPTION       DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD ------------------ ----------------- ------------- ------------- ------------ ----- --------- _mutex_spin_count  Mutex spin count  TRUE          255           255          FALSE IMMEDIATE _mutex_wait_scheme Mutex wait scheme TRUE          2             2            FALSE IMMEDIATE _mutex_wait_time   Mutex wait time   TRUE          1             1            FALSE IMMEDIATE --//缺省_mutex_wait_time=1,单位厘秒. 当大于1时sleeps的时间会出现指数回退,看看这样的情况如下. --//网上找了一段资料: * _mutex_spin_count (Integer) - This sets the number of times to spin before yielding/waiting. * _mutex_wait_scheme (Integer) - In 11.2 this controls which wait scheme to use. It can be set to one of the three wait schemes described above thus: _mutex_wait_scheme = 0                        – Always YIELD _mutex_wait_scheme = 1 & _mutex_wait_time = t – Always SLEEP for t milli-seconds (default) _mutex_wait_scheme = 2 & _mutex_wait_time = t – EXP BACKOFF with maximum sleep 1.环境: SYS@book> @ ver1 PORT_STRING                    VERSION        BANNER ------------------------------ -------------- -------------------------------------------------------------------------------- x86_64/Linux 2.4.xx            11.2.0.4.0     Oracle Database 11g Enterprise Edition Release 11.2.0.4.0 - 64bit Production SYS@book> alter system set session_cached_cursors=0 scope=spfile; System altered. --//重启略,设置目的主要保证每次都是软解析,这样都会访问library cache mutex. --//session 1: SCOTT@book> @ spid        SID    SERIAL# PROCESS                  SERVER    SPID       PID  P_SERIAL# C50 ---------- ---------- ------------------------ --------- ------ ------- ---------- --------------------------------------------------        295          5 9539                     DEDICATED 9540        21          3 alter system kill session '295,5' immediate; --//sid=295 = 0x127. SCOTT@book> select * from dept where deptno=20;     DEPTNO DNAME          LOC ---------- -------------- -------------         20 RESEARCH       DALLAS --//执行5次以上。 SCOTT@book> @ hash HASH_VALUE SQL_ID        CHILD_NUMBER HASH_HEX ---------- ------------- ------------ ---------   95129850 80baj2c2ur47u            0   5ab90fa --//95129850%131072 = 102650,确定library cache mutex 地址如下,通过转储library cache,过程略. oradebug setmypid oradebug dump library_cache 10; --//检查转储,搜索Bucket: #=102650,发现如下: Bucket: #=102650 Mutex=0x80528f40(0, 6, 0, 6) SYS@book> alter system set "_mutex_wait_time"=500 scope=memory; System altered. --//相当于5秒. 2.建立测试脚本: $ cat mutex_sleeps.sh #! /bin/bash # test mutix sleep change # # argv1=mutex_address # argv2=poke mutex_address1 value # argv3=poke mutex_address2 value # argv4=sleep seconds # vdate=$(date '+%Y%m%d%H%M%S') echo $vdate offset4=`printf "%x" $(( 0x${1} + 0x4  )) ` #echo $offset4 sqlplus -s -l / as sysdba <<EOF | ts.awk oradebug setmypid oradebug poke 0x${1}       4 0x${2} oradebug poke 0x${offset4}   4 0x${3} oradebug peek 0x${1} 24 quit EOF sqlplus -s -l scott/book <<<"select * from dept where deptno=20;"  & strace -Ttt -f -p $! -o /tmp/mutex_${vdate}.txt -e select,sched_yield,semtimedop,getrusage & sqlplus -s -l / as sysdba <<EOF | ts.awk oradebug setmypid $(seq ${4} | xargs -IQ echo -e "oradebug peek 0x${1} 24\nhost sleep 1\n") oradebug poke 0x${1}       8 0x0000000000000000 $(seq 5    | xargs -IQ echo -e "oradebug peek 0x${1} 24\nhost sleep 1\n") --oradebug peek 0x${1} 24 quit EOF --//简单说明:开始设置值非0,执行sqlplus语句放在后台,这时会挂起,通过$!获得前面sqlplus的进程号,通过strace监测,等待一定时间后, --//修改设置值为0,sqlplus正常执行后退出,strace跟踪也停止.通过前后sleep的差值就可以知道次数,同时看看strace跟踪的调用次数 --//是否基本一致. 3.测试: $ . mutex_sleeps.sh 80528f40 00000000 00009999 15 | grep "080528F40," [2021-09-16 09:43:36] BEFORE: [080528F40, 080528F44) = 00000000 [2021-09-16 09:43:36] AFTER:  [080528F40, 080528F44) = 00000000 [2021-09-16 09:43:36] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 Process 23609 attached - interrupt to quit Process 23640 attached Process 23609 detached Process 23640 detached [2021-09-16 09:43:36] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:37] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:38] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:39] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:40] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:41] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:42] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:43] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:44] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:45] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:46] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:47] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:48] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:49] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:50] [080528F40, 080528F58) = 00000000 00009999 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:51] BEFORE: [080528F40, 080528F48) = 00000000 00009999 [2021-09-16 09:43:51] AFTER:  [080528F40, 080528F48) = 00000000 00000000 [2021-09-16 09:43:51] [080528F40, 080528F58) = 00000000 00000000 000000C7 000AAC48 000190FA 00000000 [2021-09-16 09:43:52] [080528F40, 080528F58) = 00000000 00000000 000000C8 000AAC5B 000190FA 00000000 ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ [2021-09-16 09:43:53] [080528F40, 080528F58) = 00000000 00000000 000000C8 000AAC5B 000190FA 00000000 [2021-09-16 09:43:54] [080528F40, 080528F58) = 00000000 00000000 000000C8 000AAC5B 000190FA 00000000 [2021-09-16 09:43:55] [080528F40, 080528F58) = 00000000 00000000 000000C8 000AAC5B 000190FA 00000000 --//0x5b-0x48 = 19 --//5b = 91   48 = 72   91-72 = 19 $ grep semtimedop /tmp/mutex_20210916094335.txt 23640 09:43:36.258247 semtimedop(43581440, 0x7fff24813d80, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010610> 23640 09:43:36.268982 semtimedop(43581440, 0x7fff24813d80, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010943> 23640 09:43:36.280047 semtimedop(43581440, 0x7fff24813d80, 1, {0, 30000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.030853> 23640 09:43:36.311030 semtimedop(43581440, 0x7fff24813d80, 1, {0, 30000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.030873> 23640 09:43:36.342035 semtimedop(43581440, 0x7fff24813d80, 1, {0, 80000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.080866> 23640 09:43:36.423035 semtimedop(43581440, 0x7fff24813d80, 1, {0, 90000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.090863> 23640 09:43:36.514031 semtimedop(43581440, 0x7fff24813d80, 1, {0, 180000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.180894> 23640 09:43:36.695056 semtimedop(43581440, 0x7fff24813d80, 1, {0, 230000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.230866> 23640 09:43:36.926053 semtimedop(43581440, 0x7fff24813d80, 1, {0, 400000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.400880> 23640 09:43:37.327071 semtimedop(43581440, 0x7fff24813d80, 1, {0, 410000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.410827> 23640 09:43:37.738030 semtimedop(43581440, 0x7fff24813d80, 1, {0, 740000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.740943> 23640 09:43:38.479359 semtimedop(43581440, 0x7fff24813d80, 1, {0, 710000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.710692> 23640 09:43:39.190173 semtimedop(43581440, 0x7fff24813d80, 1, {1, 360000000}) = -1 EAGAIN (Resource temporarily unavailable) <1.360780> 23640 09:43:40.551330 semtimedop(43581440, 0x7fff24813d80, 1, {1, 370000000}) = -1 EAGAIN (Resource temporarily unavailable) <1.370597> 23640 09:43:41.922297 semtimedop(43581440, 0x7fff24813d80, 1, {2, 660000000}) = -1 EAGAIN (Resource temporarily unavailable) <2.660649> 23640 09:43:44.583363 semtimedop(43581440, 0x7fff24813d80, 1, {2, 710000000}) = -1 EAGAIN (Resource temporarily unavailable) <2.710690> 23640 09:43:47.315069 semtimedop(43581440, 0x7fff24813d80, 1, {5, 0}) = -1 EAGAIN (Resource temporarily unavailable) <5.000956> --//注意看最后一行开始时间09:43:47.315069到9:43:52.XXXXX结束.更新mutex结构里面的第12-15字节sleeps信息. --//注意看里面的参数{0, 10000000},参数1表示0秒 ,参数2 10000000/10^9 = .01秒. --//可以看出semtimedop的参数时间变化逐步增加.1,1,3,3,8,9,18,23,40,41,64,71,136,137,266,271,500,单位cs. $ grep semtimedop /tmp/mutex_20210916094335.txt |wc      17     238    2298 --//奇怪总是相差2. $ egrep "semtimedop|getrusage" /tmp/mutex_20210916094335.txt 23640 09:43:36.257760 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 29995}, ...}) = 0 <0.000025> 23640 09:43:36.257922 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 29995}, ...}) = 0 <0.000023> ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ 23640 09:43:36.258247 semtimedop(43581440, 0x7fff24813d80, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010610> 23640 09:43:36.268982 semtimedop(43581440, 0x7fff24813d80, 1, {0, 10000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.010943> 23640 09:43:36.280047 semtimedop(43581440, 0x7fff24813d80, 1, {0, 30000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.030853> 23640 09:43:36.311030 semtimedop(43581440, 0x7fff24813d80, 1, {0, 30000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.030873> 23640 09:43:36.342035 semtimedop(43581440, 0x7fff24813d80, 1, {0, 80000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.080866> 23640 09:43:36.423035 semtimedop(43581440, 0x7fff24813d80, 1, {0, 90000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.090863> 23640 09:43:36.514031 semtimedop(43581440, 0x7fff24813d80, 1, {0, 180000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.180894> 23640 09:43:36.695056 semtimedop(43581440, 0x7fff24813d80, 1, {0, 230000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.230866> 23640 09:43:36.926053 semtimedop(43581440, 0x7fff24813d80, 1, {0, 400000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.400880> 23640 09:43:37.327071 semtimedop(43581440, 0x7fff24813d80, 1, {0, 410000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.410827> 23640 09:43:37.738030 semtimedop(43581440, 0x7fff24813d80, 1, {0, 740000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.740943> 23640 09:43:38.479102 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 30995}, ...}) = 0 <0.000029> ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ --//间隔2秒上下调用getrusage. 23640 09:43:38.479233 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 30995}, ...}) = 0 <0.000025> 23640 09:43:38.479359 semtimedop(43581440, 0x7fff24813d80, 1, {0, 710000000}) = -1 EAGAIN (Resource temporarily unavailable) <0.710692> 23640 09:43:39.190173 semtimedop(43581440, 0x7fff24813d80, 1, {1, 360000000}) = -1 EAGAIN (Resource temporarily unavailable) <1.360780> 23640 09:43:40.551075 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 30995}, ...}) = 0 <0.000028> 23640 09:43:40.551204 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 30995}, ...}) = 0 <0.000025> 23640 09:43:40.551330 semtimedop(43581440, 0x7fff24813d80, 1, {1, 370000000}) = -1 EAGAIN (Resource temporarily unavailable) <1.370597> 23640 09:43:41.922044 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 30995}, ...}) = 0 <0.000028> 23640 09:43:41.922172 getrusage(RUSAGE_SELF, {ru_utime={0, 21996}, ru_stime={0, 30995}, ...}) = 0 <0.000026> 23640 09:43:41.922297 semtimedop(43581440, 0x7fff24813d80, 1, {2, 660000000}) = -1 EAGAIN (Resource temporarily unavailable) <2.660649> 23640 09:43:44.583103 getrusage(RUSAGE_SELF, {ru_utime={0, 22996}, ru_stime={0, 30995}, ...}) = 0 <0.000033> 23640 09:43:44.583236 getrusage(RUSAGE_SELF, {ru_utime={0, 22996}, ru_stime={0, 30995}, ...}) = 0 <0.000026> 23640 09:43:44.583363 semtimedop(43581440, 0x7fff24813d80, 1, {2, 710000000}) = -1 EAGAIN (Resource temporarily unavailable) <2.710690> 23640 09:43:47.294166 getrusage(RUSAGE_SELF, {ru_utime={0, 22996}, ru_stime={0, 30995}, ...}) = 0 <0.000061> 23640 09:43:47.314943 getrusage(RUSAGE_SELF, {ru_utime={0, 22996}, ru_stime={0, 30995}, ...}) = 0 <0.000020> 23640 09:43:47.315069 semtimedop(43581440, 0x7fff24813d80, 1, {5, 0}) = -1 EAGAIN (Resource temporarily unavailable) <5.000956> 23640 09:43:52.316151 getrusage(RUSAGE_SELF, {ru_utime={0, 22996}, ru_stime={0, 30995}, ...}) = 0 <0.000060>