[20200223] optimization of latch and mutext.txt

Time:2021-2-25

[20200223] optimization of latch and mutext.txt

–//I have been testing DBMS for some time_ SHARED_ POOL.MARKHOT Identify hot objects and optimize SQL statements.
–//Some people asked me that I spent a lot of energy on meaningless work. In fact, I used to optimize SQL statements more on Io and reduce logical reading of SQL statements.
–//Little attention is paid to why developers need to execute these SQL statements, and more third-party ways are involved in the optimization of the database.
–//For example, our production system 1 hour AWR report:

            Snap Id  Snap Time               Sessions  Cursors/Session         Instances
Begin Snap: 43914    01-Nov-19 10:00:32      4283      2.2                     2
End Snap:   43915    01-Nov-19 11:00:53      4522      2.2                     2
Elapsed:             60.36 (mins)
DB Time:             404.88 (mins)
–//db_ Time = 404.88, equivalent to 404.88 * 60 = 24292.8 seconds
….

SQL ordered by Executions

    %CPU – CPU Time as a percentage of Elapsed Time
    %IO – User I/O Time as a percentage of Elapsed Time
    Total Executions: 29,779,711
    Captured SQL account for 29.9% of Total

Executions Rows Processed  Rows per Exec   Elapsed Time (s) %CPU  %IO   SQL Id          SQL Module      SQL Text
10,279,442 10,276,526      1.00            2,671.78         97.1  0     190q1sz3ywrd7   PPPQQQ.EXE      begin :con := “XXXXXXACL”.”QUE…”
2,469,226  2,469,184       1.00            990.07           96.1  0     g7ytdh9mxt1s0   PPPQQQ.EXE      select count ( :”SYS_B_0″ ) fr…
2,003,509  2,003,261       1.00            69.14            99.8  0     f8733rs2f3bng   PPPQQQ.EXE      SELECT sysdate FROM Dual

–//The first sentence is the so-called waterproof wall product. 10279442 / 3600 = 2855.4 times per second.
–//The second statement determines whether to connect to the database. 2469226 / 3600 per second = 685.89
–//The third statement takes the current date, 2003509 / 3600 = 556.53 per second.

Report Summary
Load Profile
                                Per Second       Per Transaction  Per Exec   Per Call
DB Time(s):                     6.7              0.1              0.00      0.00
DB CPU(s):                      6.1              0.1              0.00      0.00
Redo size (bytes):              259,680.1        2,047.8
Logical read (blocks):          539,587.6        4,255.0
Block changes:                  1,322.0          10.4
Physical read (blocks):         47,972.4         378.3
Physical write (blocks):        548.1            4.3
Read IO requests:               565.7            4.5
Write IO requests:              58.8             0.5
Read IO (MB):                   374.8            3.0
Write IO (MB):                  4.3              0.0
Global Cache blocks received:   12.1             0.1
Global Cache blocks served:     0.8              0.0
User calls:                     8,826.6          69.6
Parses (SQL):                   7,458.3          58.8
Hard parses (SQL):              16.8             0.1
SQL Work Area (MB):             158.8            1.3
Logons:                         7.6              0.1
Executes (SQL):                 8,222.7          64.8
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
Rollbacks:                      2.7              0.0
Transactions:                   126.8
–//The execution times of the above three statements account for (2855 + 686 + 557) / 8223 = 0.498, almost 1.5%.

2. Test:
$ seq 100 |  xargs -IQ -P 100 bash -c “echo 2^1000000 | bc > /dev/null “
$ vmstat -w 1 100 | tw.awk
[2020-02-24 10:20:51] procs ——————-memory—————— —swap– —–io—- –system– —–cpu——-
[2020-02-24 10:20:51]  r  b       swpd       free       buff      cache   si   so    bi    bo   in   cs  us sy  id wa st
[2020-02-24 10:20:51]  0  0          0  118995152     417284   10254324    0    0     0     0  112  130   0  0 100  0  0
[2020-02-24 10:20:52] 100  0          0  118939296     417284   10254324    0    0     0     0 2664 1075   4  1  96  0  0
[2020-02-24 10:20:53] 100  0          0  118925288     417284   10254324    0    0     0     0 24176 3785  100  0   0  0  0
[2020-02-24 10:20:54] 100  0          0  118913328     417284   10254324    0    0     0     0 24114 3737  100  0   0  0  0
[2020-02-24 10:20:55] 100  0          0  118894976     417284   10254324    0    0     0     0 24118 3718  100  0   0  0  0
[2020-02-24 10:20:56] 100  0          0  118892728     417284   10254324    0    0     0     0 24111 3729  100  0   0  0  0
[2020-02-24 10:20:57] 100  0          0  118888264     417284   10254324    0    0     0     0 24133 3764  100  0   0  0  0
[2020-02-24 10:20:58] 100  0          0  118884768     417284   10254324    0    0     0     0 24109 3737  100  0   0  0  0
[2020-02-24 10:20:59] 100  0          0  118879528     417284   10254324    0    0     0     0 24096 3714  100  0   0  0  0
[2020-02-24 10:21:00] 100  0          0  118873224     417284   10254324    0    0     0     0 24112 3727  100  0   0  0  0
[2020-02-24 10:21:01] 100  0          0  118865984     417284   10254324    0    0     0     0 24133 3774  100  0   0  0  0
[2020-02-24 10:21:02] 100  0          0  118866032     417284   10254328    0    0     0     0 24109 3711  100  0   0  0  0
[2020-02-24 10:21:03] 100  0          0  118864464     417284   10254328    0    0     0     0 24121 3677  100  0   0  0  0
[2020-02-24 10:21:04] 100  0          0  118862608     417284   10254328    0    0     0     0 24116 3699  100  0   0  0  0
[2020-02-24 10:21:05] 100  0          0  118861008     417284   10254328    0    0     0     0 24158 3795  100  0   0  0  0
[2020-02-24 10:21:06] 100  0          0  118860608     417284   10254328    0    0     0    16 24120 3767  100  0   0  0  0
[2020-02-24 10:21:07] 100  0          0  118855024     417284   10254328    0    0     0    32 24104 3764  100  0   0  0  0
[2020-02-24 10:21:08] 100  0          0  118849600     417284   10254328    0    0     0     0 24121 3743  100  0   0  0  0
[2020-02-24 10:21:09] 100  0          0  118844696     417284   10254328    0    0     0     0 24139 3727  100  0   0  0  0
[2020-02-24 10:21:10] 100  0          0  118842544     417284   10254328    0    0     0     0 24128 3749  100  0   0  0  0
[2020-02-24 10:21:11] 100  0          0  118838200     417284   10254328    0    0     0     0 24093 3732  100  0   0  0  0
[2020-02-24 10:21:12] procs ——————-memory—————— —swap– —–io—- –system– —–cpu——-
[2020-02-24 10:21:12]  r  b       swpd       free       buff      cache   si   so    bi    bo   in   cs  us sy  id wa st
[2020-02-24 10:21:12] 101  0          0  118830832     417284   10254328    0    0     0    24 24129 3747  100  0   0  0  0
[2020-02-24 10:21:13] 100  0          0  118826608     417284   10254328    0    0     0     0 24159 3764  100  0   0  0  0
[2020-02-24 10:21:14] 100  0          0  118822136     417284   10254328    0    0     0     0 24098 3763  100  0   0  0  0
[2020-02-24 10:21:15] 100  0          0  118821040     417284   10254328    0    0     0     0 24112 3709  100  0   0  0  0
[2020-02-24 10:21:16] 94  0          0  118825536     417284   10254328    0    0     0     0 24165 3695  100  0   0  0  0
[2020-02-24 10:21:17] 67  0          0  118864688     417284   10254328    0    0     0     0 24209 3283  100  0   0  0  0
[2020-02-24 10:21:18]  0  0          0  118967936     417284   10254328    0    0     0     0 17636 1150  82  1  18  0  0
[2020-02-24 10:21:19]  0  0          0  118969400     417284   10254328    0    0     0     0   92   38   0  0 100  0  0
–//About 26 seconds up and down.
–//In fact, if it is only executed once, it will take a little more than 4 seconds. I think the number of logical CPUs (hyper threading on) = 24, and if you look at the output of vmstat.
$ time echo 2^1000000 | bc > /dev/null
real    0m4.058s
user    0m4.048s
sys     0m0.001s

$ man vmstat
..
Procs
  r: The number of processes waiting for run time.
  b: The number of processes in uninterruptible sleep.
–//The number of B is always 0, that is, all BC computing programs are running without any blocking, but the CPU can not be scheduled, and the execution time required becomes about six times.

3. Continue to Test Oracle Application:
[email protected]> @ 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

[email protected]> @ hide _kgl_hot_object_copies
NAME                   DESCRIPTION                         DEFAULT_VALUE SESSION_VALUE SYSTEM_VALUE ISSES ISSYS_MOD
———————- ———————————– ————- ————- ———— —– ———
_kgl_hot_object_copies Number of copies for the hot object TRUE          0             0            FALSE FALSE

–//rename job_times to job_times_20200224;
create table job_times (sid number, sessionid number,time_ela number,method varchar2(20));

–//Create script bb.txt :
$ cat bb.txt
SELECT owner
      ,name
      ,hash_value
      ,full_hash_value
      ,namespace
      ,child_latch
      ,property hot_flag
      ,executions
      ,invalidations
  FROM v$db_object_cache
 WHERE name = ‘DBMS_APPLICATION_INFO’ AND owner = ‘SYS’
 order by executions desc ;

–//Create test script m3.txt
set verify off
–//host sleep $(echo &&3/50 | bc -l )
insert into job_times values ( sys_context (‘userenv’, ‘sid’) ,sys_context (‘userenv’, ‘sessionid’),dbms_utility.get_time ,’&&2′) ;
commit ;
declare
v_id number;
v_d date;
begin
    for i in 1 .. &&1 loop
        execute immediate ‘begin dbms_application_info.set_client_info(”mutex”);end;’;
    end loop;
end ;
/
update job_times set time_ela = dbms_utility.get_time – time_ela where sid=sys_context (‘userenv’, ‘sid’) and sessionid=sys_context (‘userenv’, ‘sessionid’) and method=’&&2′;
commit;
quit

$ seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book @m3.txt 1e5 p=50 {} >/dev/null

$ vmstat  -w 1 100 | ts.awk
[2020-02-24 10:32:31] procs ——————-memory—————— —swap– —–io—- –system– —–cpu——-
[2020-02-24 10:32:31]  r  b       swpd       free       buff      cache   si   so    bi    bo   in   cs  us sy  id wa st
[2020-02-24 10:32:31]  1  0          0  118890760     417300   10255360    0    0     0     0    0    0   0  0 100  0  0
[2020-02-24 10:32:32]  0  0          0  118888768     417300   10255360    0    0     0     0 1254 2110   0  0 100  0  0
[2020-02-24 10:32:33]  0  0          0  118889032     417300   10255360    0    0     0     0 1111 2026   0  0 100  0  0
[2020-02-24 10:32:34]  0  0          0  118889032     417300   10255360    0    0     0     0 1054 2003   0  0 100  0  0
[2020-02-24 10:32:35] 17  0          0  118534208     417300   10255360    0    0     0     0 18130 14789  22  6  72  0  0
[2020-02-24 10:32:36] 15  0          0  118530112     417300   10255388    0    0     0    12 17428 12406  53  7  40  0  0
[2020-02-24 10:32:37] 18  0          0  118530112     417300   10255388    0    0     0     0 17481 12502  54  6  40  0  0
[2020-02-24 10:32:38] 16  0          0  118528264     417300   10255388    0    0     0     0 17684 12112  54  7  39  0  0
[2020-02-24 10:32:39] 17  0          0  118528448     417300   10255388    0    0     0     0 17777 12436  54  7  39  0  0
[2020-02-24 10:32:40] 15  0          0  118528576     417300   10255388    0    0     0     0 17650 11967  54  6  39  0  0
[2020-02-24 10:32:41] 21  0          0  118528584     417300   10255388    0    0     0    32 17776 12917  55  6  38  0  0
[2020-02-24 10:32:42] 21  0          0  118529824     417300   10255388    0    0     0     0 17640 13795  54  7  39  0  0
[2020-02-24 10:32:43] 15  0          0  118529920     417300   10255388    0    0     0     0 17631 11054  54  7  39  0  0
[2020-02-24 10:32:44] 16  0          0  118529936     417300   10255388    0    0     0     0 17705 12744  54  7  39  0  0
[2020-02-24 10:32:45] 19  0          0  118530448     417300   10255388    0    0     0     0 17915 13821  55  6  39  0  0
[2020-02-24 10:32:46] 18  0          0  118530464     417300   10255388    0    0     0     0 17670 11483  54  7  39  0  0
[2020-02-24 10:32:47] 23  0          0  118530464     417300   10255388    0    0     0    12 18050 13022  55  7  38  0  0
[2020-02-24 10:32:48] 20  0          0  118530760     417300   10255388    0    0     0     0 17829 12484  55  7  38  0  0
[2020-02-24 10:32:49] 16  0          0  118530760     417300   10255388    0    0     0     0 17682 13121  55  7  38  0  0
[2020-02-24 10:32:50] 18  0          0  118530792     417300   10255388    0    0     0     0 17866 12203  55  7  38  0  0
[2020-02-24 10:32:51] 16  0          0  118530992     417300   10255388    0    0     0     0 17410 11298  54  7  39  0  0
[2020-02-24 10:32:52] procs ——————-memory—————— —swap– —–io—- –system– —–cpu——-
[2020-02-24 10:32:52]  r  b       swpd       free       buff      cache   si   so    bi    bo   in   cs  us sy  id wa st
[2020-02-24 10:32:52] 15  0          0  118530992     417300   10255388    0    0     0     0 17880 11685  55  7  38  0  0
[2020-02-24 10:32:53] 22  0          0  118530992     417300   10255388    0    0     0     0 17547 11065  54  7  40  0  0
[2020-02-24 10:32:54] 16  0          0  118531072     417300   10255388    0    0     0     0 17727 11844  54  7  39  0  0
[2020-02-24 10:32:55] 11  0          0  118531072     417300   10255388    0    0     0     0 17781 11598  55  7  39  0  0
[2020-02-24 10:32:56] 17  0          0  118531072     417300   10255388    0    0     0     0 17756 11906  54  7  39  0  0
[2020-02-24 10:32:57] 21  0          0  118531072     417300   10255388    0    0     0     0 17685 13743  55  6  39  0  0
[2020-02-24 10:32:58] 23  0          0  118531104     417300   10255388    0    0     0     0 17969 12060  56  6  37  0  0
[2020-02-24 10:32:59]  5  0          0  118531104     417300   10255388    0    0     0     8 17948 11292  55  7  38  0  0
[2020-02-24 10:33:00] 17  0          0  118531104     417300   10255388    0    0     0    16 17791 12828  55  7  38  0  0
[2020-02-24 10:33:01] 17  0          0  118531088     417300   10255388    0    0     0     0 17634 12162  54  7  39  0  0
[2020-02-24 10:33:02] 16  0          0  118531088     417300   10255388    0    0     0     0 18026 13306  56  7  37  0  0
[2020-02-24 10:33:03] 17  0          0  118531088     417300   10255388    0    0     0     0 17766 11976  55  7  38  0  0
[2020-02-24 10:33:04]  7  0          0  118530968     417300   10255388    0    0     0     0 17951 11757  56  7  37  0  0
[2020-02-24 10:33:05] 18  0          0  118530952     417300   10255388    0    0     0     0 17921 11570  55  7  38  0  0
[2020-02-24 10:33:06] 21  0          0  118530976     417300   10255388    0    0     0     0 17241 12085  52  6  42  0  0
[2020-02-24 10:33:07] 11  0          0  118530976     417300   10255388    0    0     0     0 17623 11839  54  6  39  0  0
[2020-02-24 10:33:08] 23  0          0  118530976     417300   10255388    0    0     0     0 17609 11634  55  6  39  0  0
[2020-02-24 10:33:09] 17  0          0  118530976     417300   10255388    0    0     0     0 17609 11607  54  7  39  0  0
[2020-02-24 10:33:10] 16  0          0  118530992     417300   10255388    0    0     0    32 17803 12065  55  7  38  0  0
[2020-02-24 10:33:11]  6  0          0  118530976     417300   10255388    0    0     0     0 17912 11454  56  7  37  0  0
[2020-02-24 10:33:12] 17  0          0  118531112     417300   10255388    0    0     0     0 17869 11916  55  7  39  0  0
[2020-02-24 10:33:13] procs ——————-memory—————— —swap– —–io—- –system– —–cpu——-
[2020-02-24 10:33:13]  r  b       swpd       free       buff      cache   si   so    bi    bo   in   cs  us sy  id wa st
[2020-02-24 10:33:13] 19  0          0  118531112     417300   10255388    0    0     0     0 17746 11633  54  6  39  0  0
[2020-02-24 10:33:14] 18  0          0  118531112     417300   10255388    0    0     0     0 17887 11629  56  7  37  0  0
[2020-02-24 10:33:15] 18  0          0  118531112     417300   10255388    0    0     0     0 17715 12068  55  7  39  0  0
[2020-02-24 10:33:16] 17  0          0  118537576     417300   10255388    0    0     0    12 17589 11460  54  7  39  0  0
[2020-02-24 10:33:17] 16  0          0  118675928     417300   10255392    0    0     0     0 18894 9604  55  7  38  0  0
[2020-02-24 10:33:18]  1  0          0  118857304     417300   10255392    0    0     0     0 10522 3468  33  5  62  0  0
[2020-02-24 10:33:19]  0  0          0  118859728     417300   10255392    0    0     0     0 1092 1997   0  0 100  0  0
[2020-02-24 10:33:20]  0  0          0  118860720     417300   10255392    0    0     0     0 1121 2066   0  0 100  0  0
[2020-02-24 10:33:21]  0  0          0  118861048     417300   10255392    0    0     0     0 1173 2034   0  0 100  0  0
[2020-02-24 10:33:22]  1  0          0  118861712     417300   10255392    0    0     0     0 1082 2004   0  0 100  0  0
^C
–//You can see that the number of vmstat r does not reach 50, although B is still 0 all the time. However, it is obvious that blocking causes the number of concurrency to not reach 50

4. Continue testing:
–//Using DBMS_ shared_ pool.markhot After hot object identification:
[email protected]> exec dbms_shared_pool.markhot(‘SYS’,’DBMS_APPLICATION_INFO’,1);
PL/SQL procedure successfully completed.

[email protected]> exec dbms_shared_pool.markhot(‘SYS’,’DBMS_APPLICATION_INFO’,2);
PL/SQL procedure successfully completed.

$ seq 50 | xargs -I{} -P 50 sqlplus -s -l scott/book @m3.txt 1e5 mp=50 {} >/dev/null

$ vmstat  -w 1 100 | ts.awk
[2020-02-24 10:37:10] procs ——————-memory—————— —swap– —–io—- –system– —–cpu——-
[2020-02-24 10:37:10]  r  b       swpd       free       buff      cache   si   so    bi    bo   in   cs  us sy  id wa st
[2020-02-24 10:37:10]  1  0          0  118873072     417300   10255404    0    0     0     0    0    0   0  0 100  0  0
[2020-02-24 10:37:11]  0  0          0  118870936     417300   10255404    0    0     0     0 1233 2056   0  0 100  0  0
[2020-02-24 10:37:12] 47  0          0  118521648     417300   10255404    0    0     0     8 21133 8990  30  7  63  0  0
[2020-02-24 10:37:13] 50  0          0  118518544     417300   10255404    0    0     0     0 24557 4843  86 11   3  0  0
[2020-02-24 10:37:14] 48  0          0  118518424     417300   10255404    0    0     0     0 24649 4801  87 11   2  0  0
[2020-02-24 10:37:15] 50  0          0  118518672     417300   10255404    0    0     0     0 24765 4696  87 11   2  0  0
[2020-02-24 10:37:16] 47  0          0  118519896     417300   10255404    0    0     0     0 24773 4860  87 11   2  0  0
[2020-02-24 10:37:17] 22  0          0  118520016     417300   10255404    0    0     0     0 24476 5224  86 11   3  0  0
[2020-02-24 10:37:18] 50  0          0  118520408     417300   10255404    0    0     0    16 24638 4950  87 11   2  0  0
[2020-02-24 10:37:19] 49  0          0  118521280     417300   10255404    0    0     0     0 24770 4946  88 11   2  0  0
[2020-02-24 10:37:20] 45  0          0  118521376     417300   10255404    0    0     0     0 24936 4901  88 11   1  0  0
[2020-02-24 10:37:21] 46  0          0  118521552     417300   10255404    0    0     0     0 24884 4875  88 11   1  0  0
[2020-02-24 10:37:22] 48  0          0  118521992     417300   10255404    0    0     0     0 24634 5066  86 11   3  0  0
[2020-02-24 10:37:23] 42  0          0  118538432     417300   10255404    0    0     0     4 24639 4868  86 11   3  0  0
[2020-02-24 10:37:24]  0  0          0  118847888     417300   10255404    0    0     0     0 18070 3752  66  9  26  0  0
[2020-02-24 10:37:25]  0  0          0  118849808     417300   10255404    0    0     0     0 1142 2047   0  0 100  0  0
[2020-02-24 10:37:26]  0  0          0  118849808     417300   10255404    0    0     0     0 1098 1993   0  0 100  0  0
[2020-02-24 10:37:27]  0  0          0  118851008     417300   10255404    0    0     0     0 1127 2049   0  0 100  0  0
[2020-02-24 10:37:28]  0  0          0  118851312     417300   10255404    0    0     0     0 1085 1994   0  0 100  0  0
[2020-02-24 10:37:29]  0  0          0  118851632     417300   10255404    0    0     0     0 1214 2078   0  0 100  0  0
[2020-02-24 10:37:30]  0  0          0  118852688     417300   10255404    0    0     0    16 1216 2024   0  0 100  0  0
^C
–//You can see that the number of R is close to the number of concurrent 50. So the same amount of work is done in 12 seconds.

[email protected]> Select method,count(*),round(avg(TIME_ELA),0),sum(TIME_ELA) from scott.job_times group by method order by 3 ;
METHOD                 COUNT(*) ROUND(AVG(TIME_ELA),0) SUM(TIME_ELA)
——————– ———- ———————- ————-
mp=50                        50                   1197         59852
p=50                         50                   4270        213485

–//I just use this example to show that optimizing latch is as important as mutex. Many developers and even DBAs don’t have this kind of awareness, which is really terrible.
–//In other words, this kind of work is not meaningless. You can learn a lot about OS and Oracle through a simple example.

Recommended Today

Practice analysis of rust built-in trait: partialeq and EQ

Abstract:Rust uses traits in many places, from simple operator overloading to subtle features like send and sync. This article is shared from Huawei cloud community《Analysis of rust built-in trait: partialeq and EQ》Author: debugzhang Rust uses traits in many places, from simple operator overloading to subtle features like send and sync. Some traits can be automatically […]