IBM AIX POWER7 CPU Usage and Throughput

This Blog summaries author's observation and understanding on CPU usage of AIX POWER7 SMT4 Architecture.
POWER8 content is added in Section "8 Power8".

1. POWER7 Execution Units

 POWER7 Core is made of 12 execution units [1]:

   2 fixed-point units
   2 load/store units
   4 double-precision floating-point units
   1 vector unit supporting VSX
   1 decimal floating-point unit
   1 branch unit
   1 condition register unit

2. CPU Usage and Throughput

When setting SMT=4, each Core provides 4 Hardware Thread Contexts(HTC, logic CPU) and can simultaneously executes 4 Software Threads (Processes, Tasks).

For example, if more then 2 threads want to run concurrently floating point at the same time (cycle), then the 3rd and 4th thread would have to wait CPU cycles for access to the two FP units to be free. Therefore, with SMT=4, number of instructions executed by a single HTC slows down, but overall throughput goes up per core. IBM claims 60% boost of throughput. That means when 4 processes run on a core (smt=4), it delivers 1.6 times throughput than a a single process per core ([2], [3]). In case of smt=2, the boost is 40%, or 1.4 times throughput (note that we use lower case "smt=4" to differ it from POWER SMT configuration of SMT=4).

Mathematically, with smt=4, one could think that 25% Core usage provide 40% CPU power. The response time is increased from 1 to 2.5 (= 1/0.4) instead of 4.

Now it comes puzzle, how much should we show the CPU usage for each HTC and each process ? 25% or 40% in the above example ? In general, measuring and modelling SMT cpu usage is an on-going research subjects ([5]).

POWER7 is advanced with a new Model of CPU usage. The general intent of POWER7 is to provide a measure of CPU utilization wherein there is a linear relationship between the current throughput (e.g., transactions per second) and the CPU utilization being measured for that level of throughput [2].

In smt=4, 4 Threads running per core, each Thread shares 25% of a whole core, and provides 40% throughput in comparing to smt=1. To build up the linear relation of throughput to CPU usage, the CPU usage of smt=1, 2, 3, 4 can be computed as:

 CPU%(smt=1) = (1.0/0.4) * 25% = 62.50%

 CPU%(smt=2) = (0.7/0.4) * 25% = 43.75%

 CPU%(smt=3) = (0.5/0.4) * 25% = 31.25%

  CPU%(smt=4) = (0.4/0.4) * 25% = 25.00%

Note that for smt=3, boost of 50%, or 1.5 times throughput, stems from this Blog's test, and can be inaccurate.

Expressed in linear equation, it looks like:

  t = f(s) * u

where t for Throughput, s for smt (with possible value of 1, 2, 3, 4), u for CPU Usage.

Putting all together, we can draw a table:

smt	Throughput/core	Throughput/HTC	CPU%
1	1.0	1.0	62.50
2	1.4	0.7	43.75
3	1.5	0.5	31.25
4	1.6	0.4	25.00

Table-1

Therefore, maximum CPU usage of HTC (logic CPU) and Software Thread (Process or Task) is 62.5%. In POWER7 SMT=4, it would be astonishing if it were possible to observe a Process CPU usage more than 65%,  or a HTC's CPU usage more than 65% (mpstat -s).

Picking performance test data out of Blog [6] Table-1 (tested on POWER7, 4 Core, SMT=4, Oracle 11.2.0.3.0), and verifying against above linear relations:

JOB_CNT	HTC/Core	C2_RUN_CNT	Throughtput/HTC	Throughput_Based_CPU%	Throughput_Ratio_to_Min	Theory_Throughput/HTC
1	1	119	119 (119/1)	64.67	2.59 (119/46)	115.00
8	2	580	73 (580/8)	39.40	1.58 (73/46)	80.50
12	3	654	55 (654/12)	29.89	1.20 (55/46)	57.50
16	4	730	46 (730/16)	25.00	1.00 (46/46)	46.00

Table-2

where Throughput_Based_CPU%:

   (119/46)*25% = 64.67%
   (73/46)*25%  = 39.40%
   (55/46)*25%  = 29.89%

and Theory_Throughput/HTC based on linear interpolation:

   46*(0.6250/0.25) = 115.00
   46*(0.4375/0.25) = 80.50
   46*(0.3125/0.25) = 57.50

Table-2 shows that the Theory_Throughput is close to tested Throughput. Thus the designated CPU usage is a calibrated, scalable metric (notice: "S" in POWER8 servers signifies Scale-out.).

Usually applications with a lot of transaction are benchmarked in terms of Throughput, hence binding Throughput linearly to CPU usage is a practical approach to assess application performance.

In principle, CPU usage represents the throughput, and its complement (1 - Usage) stands for the remaining available capacity. One process running in one core with CPU usage of 62.5% on first HTC stands for that there is still 37.5% available capacity on other 3 HTCs, each of which can share a portion of 12.5%.

In practice, CPU utilization can be applied as metric for charging back of computing resources used, and its complement can be used for predication of capacity planning.

This model of SMT CPU accounting is not widely acknowledged, and therefore caused confusion. For example, Oracle Note 1963791.1:

 Unaccounted Time in 10046 File on AIX SMT4 Platform when Comparing Elapsed and CPU Time (Doc ID 1963791.1) [8]

where session trace records:
 cpu time = 86.86   waited time = 7.06  elapsed time = 142.64

and the difference:
 142.64 - (86.86 + 7.06) = 48.72 seconds,
is interpreted as "Unaccounted Time".

In fact,
   86.86/142.64 = 60.90%,
indicates that almost a single Oracle session alone occupies one full core.

Blog [9] also reported the similar observation on AIX POWER7 and trying to explain the unaccounted time.

Probably people working in other UNIX (Solaris, HP-UX, Linux) gets used to intuitive interpretation of CPU time and elapsed time, but with the advancing of multi-threaded processors like AIX, an inception of rethinking would help disperse the confusion so that CPU resource can be efficiently allocated and accurately assessed.

3. POWER PURR

According to [2][4],

 POWER5 includes a per-thread processor utilization of resources register (PURR), which increments at the timebase frequency multiplied by the fraction of cycles on which the thread can dispatch instructions.

 Beginning with IBM® POWER5 TM processor architecture, a new register, PURR, is introduced to assist in computing the utilization.
 The PURR stands for Processor Utilization of Resources Register and its available per Hardware Thread Context.

 The PURR counts in proportion to the real time clock (timebase)
 The SPURR stands for Scaled Processor Utilization of Resources Register.
 The SPURR is similar to PURR except that it increments proportionally to the processor core frequency.
 The AIX® lparstat, sar & mpstat utilities are modified to report the PURR-SPURR ratio via a new column, named "nsp".

and it demonstrates the enhanced command: time (timex), sar -P ALL, mpstat -s, lpstat -E

AIX provides command pprof with flag: -r PURR to report CPU usage in PURR time instead of TimeBase.

For example, start one CPU intensive Oracle session (process) in one core for a duration of 120 seconds:

  exec xpp_test.run_job(p_case => 2, p_job_cnt => 1, p_dur_seconds => 120);
 (see TestCase in Blog [7], POWER7, 4 Core, SMT=4)

in this case, single Core runs in smt=1, then tracking its PURR time for 100 seconds by:
 pprof 100 -r PURR

and displaying the report by:
 head -n 50 pprof.cpu

The output shows (irrelevant lines removed):

                    Pprof CPU Report
        E = Exec'd      F = Forked
        X = Exited      A = Alive (when traced started or stopped)
        C = Thread Created
        * = Purr based values
               Pname      PID     PPID  BE      TID     PTID ACC_time*  STT_time  STP_time   STP-STT
               =====    =====    ===== ===    =====    ===== =========  ========  ========  ========
     ora_j000_testdb 42598406  7864540  AA 21299317        0    62.930     0.037    99.805    99.768

If tracking with TimeBase by:
 pprof 100

The output (head -n 50 pprof.cpu) looks like:

               Pname      PID     PPID  BE      TID     PTID  ACC_time  STT_time  STP_time   STP-STT
               =====    =====    ===== ===    =====    =====  ========  ========  ========  ========
     ora_j000_testdb  1835064        0  AA  2687059        0    99.899     0.016    99.916    99.900

Continues with our example by starting 8 CPU intensive Oracle sessions (each Core runs in smt=2):

  exec xpp_test.run_job(p_case => 2, p_job_cnt => 8, p_dur_seconds => 120);

and look PURR report for one Oracle process:

               Pname      PID     PPID  BE      TID     PTID ACC_time*  STT_time  STP_time   STP-STT
               =====    =====    ===== ===    =====    ===== =========  ========  ========  ========
     ora_j007_testdb 17760298  7864540  AA 57475195        0    42.910     0.340    99.210    98.870
    
then starting 12 CPU intensive Oracle sessions (each Core runs in smt=3):

  exec xpp_test.run_job(p_case => 2, p_job_cnt => 12, p_dur_seconds => 120);

and look PURR report for one Oracle process:
   
               Pname      PID     PPID  BE      TID     PTID ACC_time*  STT_time  STP_time   STP-STT
               =====    =====    ===== ===    =====    ===== =========  ========  ========  ========
     ora_j007_testdb 33095898  7864540  AA 50135123        0    30.658     0.017   100.008    99.990

And finally starting 16 CPU intensive Oracle sessions (each Core runs in smt=4):

  exec xpp_test.run_job(p_case => 2, p_job_cnt => 16, p_dur_seconds => 120);

and look PURR report for one Oracle process:

               Pname      PID     PPID  BE      TID     PTID ACC_time*  STT_time  STP_time   STP-STT
               =====    =====    ===== ===    =====    ===== =========  ========  ========  ========
     ora_j014_testdb 33488964  7864540  AA 73531621        0    24.673     0.143    99.145    99.002

We can see that ACC_time* correlates well with CPU% of Table-1. The little difference is probably due to single point of contention on Oracle latch: row cache objects - child: dc_users [7].

The study[4] shows that PURR limits its inaccuracy to 26% in the single core POWER5 configuration (CMP+SMT).

Additionally, in AIX, the number of physical processors consumed is reported by sar.physc and vmstat.pc, percentage of entitled capacity consumed is reported by sar.%entc and vmstat.ec.

By the way, Linux on POWER machine reads PURR at regular intervals and make the values available through a file in the procfs [4].

3.1 PURR APIs

AIX perfstat_cpu APIs include:

  perfstat_cpu_total(), perfstat_partition_total(), and perfstat_cpu_total_wpar(), perfstat_cpu_util().

perfstat_partition_total Subroutine retrieves global Micro-Partitioning® usage statistics into:

  perfstat_partition_total_t lparstats;  

In libperfstat.h File[12], perfstat_partition_total_t contains the following PURR members:

  purr_counter            Number of purr cycles spent in user and kernel mode.
  u_longlong_t puser  Raw number of physical processor ticks in user mode.
  u_longlong_t psys   Raw number of physical processor ticks in system mode.
  u_longlong_t pidle  Raw number of physical processor ticks idle.
  u_longlong_t pwait  Raw number of physical processor ticks waiting for I/O.    

perfstat_cpu_total Subroutine fills perfstat_cpu_total_t, which contains the following members:

  u_longlong_t user  Raw total number of clock ticks spent in user mode.
  u_longlong_t sys   Raw total number of clock ticks spent in system mode.
  u_longlong_t idle  Raw total number of clock ticks spent idle.
  u_longlong_t wait  Raw total number of clock ticks spent waiting for I/O.

(see File: libperfstat.h)

perfstat_partition_total Interface demonstrates emulating the lparstat command including PCPU:

  /* calculate physcial processor tics during the last interval in user, system, idle and wait mode  */
  delta_pcpu_user  = lparstats.puser - last_pcpu_user; 
  delta_pcpu_sys   = lparstats.psys  - last_pcpu_sys;
  delta_pcpu_idle  = lparstats.pidle - last_pcpu_idle;
  delta_pcpu_wait  = lparstats.pwait - last_pcpu_wait; 

Oracle'link to AIX perfstat_cpu_total is visible by:

$ nm -Xany $ORACLE_HOME/bin/oracle |grep perfstat_cpu_total

Name                 Type  Value       Size
-------------------  ----  ----------  ----
.perfstat_cpu_total  T     4580969124
.perfstat_cpu_total  t     4580969124   44
perfstat_cpu_total   U              -
perfstat_cpu_total   d     4861786384    8

 Type:
   T Global text symbol
   t Local text symbol
   U Undefined symbol
   d Local data symbol

but it is not clear how Oracle calls perfstat_partition_total.

4. Thread Scheduling and Throughput

Picking performance test data out of Blog [6] Table-3, and adding smt per Core, we got:

JOB_CNT	C1_RUN_CNT(Throughput)	MIN	MAX	Core_1_smt	Core_2_smt	Core_3_smt	Core_4_smt	Theory_Throughput
1	118	118	118	1	0	0	0	118.00
2	240	120	120	1	1	0	0	236.00
3	360	120	120	1	1	1	0	354.00
4	461	109	120	1	1	1	1	472.00
5	476	74	119	2	1	1	1	519.20
6	515	75	97	2	2	1	1	566.40
7	551	66	100	2	2	2	1	613.60
8	569	63	77	2	2	2	2	660.80
9	597	58	76	3	2	2	2	672.60
10	601	56	73	3	3	2	2	684.40
11	613	48	67	3	3	3	2	696.20
12	646	49	64	3	3	3	3	708.00
13	683	47	66	4	3	3	3	719.80
14	696	46	65	4	4	3	3	731.60
15	714	45	51	4	4	4	3	731.60
16	733	44	47	4	4	4	4	755.20

Table-3

where Theory_Throughput is calculated based on above Table-1 and smt per Core, for example:

 JOB_CNT=5,  118*1.4*1+118*3     = 519.2
 JOB_CNT=11, 118*1.5*3+118*1.4*1 = 696.2
 JOB_CNT=15, 118*1.6*2+118*1.5*2 = 731.6

Blog [3] reveals the particularity on non-existence of smt=3 mode, which said: when starting 9 processes (Oracle sessions) on a POWER7 4 Cores SMT=4, there will be 1 Cores running with 4 HTCs, and 1 Core having only 1 HTC, and 2 Cores with 2 HTCs  in total, 9 HTCs for 9 Oracle sessions.

As we tested by running:

  exec xpp_test.run_job(p_case => 2, p_job_cnt => 9, p_dur_seconds => 120);
 
"pprof 100 -r PURR" shows:

            Pname      PID     PPID  BE      TID     PTID ACC_time*  STT_time  STP_time   STP-STT
            =====    =====    ===== ===    =====    ===== =========  ========  ========  ========
  ora_j000_testdb 43646996  7864540  AA 65273961        0    43.578     0.008    97.823    97.815
  ora_j001_testdb 14090250  7864540  AA 45744377        0    43.314     1.621   100.010    98.389
  ora_j002_testdb 38338754  7864540  AA 28442745        0    40.696     0.007   100.000    99.993
  ora_j003_testdb 33095926  7864540  AA 78119153        0    36.575     0.010    99.922    99.912
  ora_j004_testdb 39583756  7864540  AA 35258545        0    36.204     2.242    97.824    95.582
  ora_j005_testdb 42401958  7864540  AA 73662611        0    36.020     1.131    99.731    98.600
  ora_j006_testdb 12976182  7864540  AA 68681805        0    35.944     2.212    99.912    97.700
  ora_j007_testdb 49086646  7864540  AA 75563151        0    32.372     1.893    97.823    95.930
  ora_j008_testdb  7602206  7864540  AA 32112699        0    31.676     1.893    97.823    95.930

"mpstat -ws" shows:

              Proc0                           Proc4            
              94.56%                          99.92%           
  cpu0    cpu1    cpu2    cpu3    cpu4    cpu5    cpu6    cpu7 
  22.43%  24.13%  36.16%  11.84%  30.39%  20.72%  30.08%  18.72%
 
              Proc8                          Proc12            
             100.00%                         100.00%           
  cpu8    cpu9    cpu10   cpu11   cpu12   cpu13   cpu14   cpu15
  25.72%  24.80%  16.14%  33.35%  48.67%  46.49%   2.35%   2.49%

"sar -P ALL" shows:

  cpu    %usr    %sys    %wio   %idle   physc   %entc
    0      47       6       0      47    0.20     5.1
    1      60       0       0      40    0.24     5.9
    2      92       0       0       8    0.38     9.4
    3      14       0       0      86    0.13     3.2
    4      99       0       0       1    0.32     8.1
    5      87       0       0      13    0.19     4.7
    6      89       0       0      11    0.30     7.6
    7      73       0       0      27    0.19     4.6
    8     100       0       0       0    0.26     6.4
    9     100       0       0       0    0.25     6.2
    10     43       0       0      57    0.15     3.8
    11    100       0       0       0    0.34     8.6
    12    100       0       0       0    0.48    12.0
    13    100       0       0       0    0.48    12.0
    14      0       0       0     100    0.02     0.5
    15     11       0       0      89    0.02     0.5
    U       -       -       0       2    0.05     1.3
    -      84       0       0      16    3.95    98.7

However, the above outputs shows that 2 HTCs (cpu14, cpu15) are almost idle, one (cpu3) has low workload, and the other 13 HTCs are more or less busy, probably only top 9 busy HTCs are for 9 running Oracle sessions.

Two idle HTCs (cpu14, cpu15) in Core 4 could also signify that 3 Cores running in smt=4 and one Core in smt=2.

Applying it to 15 processes (Oracle sessions), there will be 3 Cores running with 4 HTCs, and one Core having only 2 HTCs, in total, 14 HTCs for 15 Oracle sessions.

Let's test it by:

  exec xpp_test.run_job(p_case => 2, p_job_cnt => 15, p_dur_seconds => 120);

"pprof 100 -r PURR" shows:

               Pname      PID     PPID  BE      TID     PTID ACC_time*  STT_time  STP_time   STP-STT
               =====    =====    ===== ===    =====    ===== =========  ========  ========  ========
     ora_j000_testdb 40108192  7864540  AA 15859877        0    27.389     0.020   100.003    99.983
     ora_j001_testdb 11927686  7864540  AA 40697939        0    27.277     0.023   100.020    99.997
     ora_j002_testdb 43647120  7864540  AA 30867661        0    26.892     0.657   100.003    99.346
     ora_j003_testdb 17760278  7864540  AA 73531567        0    26.695     0.009    99.040    99.031
     ora_j004_testdb  8388634  7864540  AA 60424235        0    26.576     0.003   100.013   100.011
     ora_j005_testdb 33095868  7864540  AA 30801969        0    25.437     0.657    98.956    98.300
     ora_j006_testdb 37290002  7864540  AA 26411087        0    25.278     0.656    97.135    96.478
     ora_j007_testdb 44105940  7864540  AA 39190655        0    24.977     0.003   100.009   100.006
     ora_j008_testdb 45285388  7864540  AA 72482871        0    24.773     0.735   100.013    99.279
     ora_j009_testdb 33488948  7864540  AA 75628593        0    24.262     0.015    96.875    96.860
     ora_j010_testdb 13828318  7864540  AA 67240145        0    24.256     0.016    96.876    96.860
     ora_j011_testdb 42926108  7864540  AA 64421997        0    24.233     0.024    96.874    96.850
     ora_j012_testdb 42336484  7864540  AA 32112833        0    24.180     0.016    96.876    96.860
     ora_j013_testdb 38600812  7864540  AA 47972531        0    24.049     0.734    96.874    96.140
     ora_j014_testdb 46727262  7864540  AA 25690295        0    24.047     0.734    96.874    96.140

"mpstat -s" shows:

              Proc0                           Proc4            
              99.99%                         100.00%           
  cpu0    cpu1    cpu2    cpu3    cpu4    cpu5    cpu6    cpu7 
  21.33%  28.15%  24.69%  25.81%  25.00%  25.03%  24.98%  24.99%
 
              Proc8                          Proc12            
             100.00%                         100.00%           
  cpu8    cpu9    cpu10   cpu11   cpu12   cpu13   cpu14   cpu15
  25.03%  25.02%  24.66%  25.29%  25.92%  24.12%  24.95%  25.02%

"sar -P ALL" shows:

  cpu    %usr    %sys    %wio   %idle   physc   %entc
   0       72       5       0      23    0.21     5.3
   1       94       0       0       6    0.28     7.1
   2       91       0       0       9    0.24     6.1
   3       95       0       0       5    0.26     6.5
   4       99       0       0       1    0.25     6.2
   5      100       0       0       0    0.25     6.3
   6      100       0       0       0    0.25     6.3
   7      100       0       0       0    0.25     6.2
   8      100       0       0       0    0.25     6.3
   9      100       0       0       0    0.25     6.3
   10      99       0       0       1    0.25     6.2
   11     100       0       0       0    0.25     6.3
   12     100       0       0       0    0.25     6.4
   13      98       0       0       2    0.25     6.1
   14     100       0       0       0    0.25     6.2
   15     100       0       0       0    0.25     6.3
   -       97       0       0       3    4.00   100.0

The above outputs deliver no evidence of non-existence of smt=3 mode. It could be possible that I missed some points here. It will be interesting to see how to demonstrate it.

5. AIX Internal Code

AIX "struct procinfo" used in getprocs Subroutine (/usr/include/procinfo.h) contains a comment on pi_cpu:

  struct  procinfo
  {
    /* scheduler information */
    unsigned long   pi_pri;         /* priority, 0 high, 31 low */
    unsigned long   pi_nice;        /* nice for priority, 0 to 39 */
    unsigned long   pi_cpu;         /* processor usage, 0 to 80 */ 

Probably in the mind of AIX developers, process processor usage is not allowed to be over 80.

In fact, in one POWER8 with SMT=2, maximum CPU Utilization of 76% is observed.

All fields in Oracle procsinfo (not AIX struct "procinfo") can be listed by:

$ nm -Xany $ORACLE_HOME/bin/oracle |grep -i procsinfo

  procsinfo:T153=s1568
  pi_pid:121,0,32;
  pi_ppid:121,32,32;
  ...
  pi_cpu:123,448,32;
  ...
  pi_utime:123,864,32;
  ...
  pi_stime:123,928,32;
  ...

6. vpm_throughput_mode

This AIX scheduler tunable parameter specifies the desired level of SMT exploitation for scaled throughput mode.

A value of 0 gives default behavior (raw throughput mode).
A value of 1, 2, or 4 selects the scaled throughput mode and the desired level of SMT exploitation. It is the number of threads used by one core before using next core.

schedo –p –o vpm_throughput_mode=
  0 Legacy Raw mode (default)
  1 Enhanced Raw mode with a higher threshold than legacy
  2 Scaled mode, use primary and secondary SMT threads
  4 Scaled mode, use all four SMT threads

Raw Mode (0, 1)

provides the highest per-thread throughput and best response times at the expense of activating more physical core. For example, Legacy Raw mode (default) dispatches workload to all primary threads before using any secondary threads.

Secondary threads are activated when the load of all primary threads is over certain utilization, probably 50%, and new workload (process) comes to be dispatched for running.

3rd and 4th threads are activated when the load of secondary threads is over certain utilization, probably 20%, and new workload (process) comes to be dispatched for running.

Scaled Mode (2, 4)

intends the highest per-core throughput (in the specified mode: 2 or 4) at the expense of per-thread response times and throughput. For example, Scaled mode 2 dispatches workload to both primary and secondary threads of one core before using those of next core. Scaled mode 4 dispatches workload to all 4 threads of one core before using those of next core.

In Scaled mode 2, 1st and 2nd threads of each core are bound together, thus both have the similar workload (CPU Usage). 3rd and 4th threads are activated when the load of 1st and 2nd threads is over certain utilization, probably 30%, and new workload (process) comes to be dispatched for running.

Note that this tuning intention is per active core, not all cores in the LPAR. In fact, it is aimed at activating less cores. It would be a setting conceived for a test system with a few LPARs.

Referring to Table-1, vpm_throughput_mode = 2 is corresponding to smt = 2, two threads are running per core, Throughput/HTC = 0.7, CPU% = 43.75. In real applications with Scaled mode 2, we also observed that CPU% is constrained under 43% even if runqueue is shorter than number of cores. That means even though workload is low, CPU% can not score up to its maximum of 62.50, and applications can not benefit from the maximum Throughput/HTC. For the performance critical application, Scaled mode is questionable. On the contrary, Raw Mode automatically tunes the CPU% based on workload. That is probably why vpm_throughput_mode is in default set to 0.

We can see there is no vpm_throughput_mode=3. Probably it is related to Blog [3] mentioned the particularity on non-existence of smt=3 mode.

There is also a naming confusion. In default, POWER7 runs in "Legacy Raw mode", and POWER6 behaves like "scaled throughput mode". Normally "Legacy" means it was used in some previous model or release,  but here POWER6 uses something like "Scaled mode, and a later model (POWER7) introduced a "Legacy" mode 0.

7. NMON Report

NMON report contains three aspects of worksheets on CPU usage: PCPU_ALL (PCPUnnn), SCPU_ALL (SCPUnnn), CPU_ALL (CPUnnn).

AIXpert Blog[10] said:

   If I had to guess then the Utilisation numbers in our PCPU_ALL graph (above) have been scaled from 75 cores to roughly 62 cores so "show" some SMT threads are unused so the CPU cores are not fully used (and given enough threads it could give you more performance). Roughly 10 - 15% more. Now, in my humble opinion, this is totally the wrong way of doing this as it is just plain confusing.

   The PCPU and SCPU stats where (in my humble opinion) a confusing mistake and only useful if you have the CPUs in Power saving mode i.e. its changing the CPU GHz to save electrical power.

and IBM developerWorks Forum[11] described:

   PCPU_ALL is the actual physical resource consumption. It would be in units of cores.
   SCPU_ALL is the scaled physical resource consumption. Differs from PCPU_ALL if running at non-nominal frequency.
          Again in units of cores. SCPU, PCPU do not differ when the system runs in the nominal frequency.
   CPU_ALL: PhysicalCPU tag (0.376) denotes the fraction of core used by this partition.
          The distribution of the 0.376 across various modes (user, sys, wait, idle) is proportional to the CPU_ALL% in all modes. 
         Applying this % would give the PCPU_ALL.

In short, PCPU_ALL represents PURR, SCPU_ALL for SPURR; and CPU_ALL denotes PCPU_ALL modes (user, sys, wait, idle) in percentage, and sum of them should be around 100%.

PCPUnnn represents CPU% of one single HTC (logical CPU, see Table-1), PCPU_ALL is sum of all PCPUnnn across various modes (user, sys, wait, idle).

In case of smt=2 (only two HTCs per core are activated), at each time instance, sum of user and sys in PCPUnnn should be under 43.75%; for each core, sum of user and sys should be under 87.5% (2*43.75); whereas for whole LPAR, sum of user and sys in PCPU_ALL should be under number_of_core * 87.50%.

In case of smt=4 (all 4 HTCs per core are activated), at each time instance, sum of user and sys in PCPUnnn should be under 25.00%; for each core, sum of user and sys should be under 100.00% (4*25.00); whereas for whole LPAR, sum of user and sys in PCPU_ALL should be under number_of_core * 100.00%.

In TOP worksheet, %CPU, %Usr, %Sys also represent PURR. Note that if Threads > 1, they are the sum of all Threads aggregated by PID, hence can be more than 80%.

In Oracle AWR report, %CPU is in PURR too.

8. Power8

(a). SMT=4, for single HTC (smt=1), CPU% = 60.00% instead of 62.50% in Power7 (see Table-1).
       The Throughput Ratio of smt=1 vs. smt=4 is 60.00/25.00 = 2.4 instead of 2.5 in Power7,
       that means about 4% (2.5/62.5 = 0.1/2.5 = 0.04) less than Power7.
  
(b). SMT=8, for single HTC (smt=1), CPU% = 56.00%
       The Throughput Ratio of smt=1 vs. smt=8 is 56.00/12.50 = 4.48.

The above preliminary figures needs to be further verified.

POWER8 Each core has 16 execution pipelines[13]:

 2  fixed-point pipelines
 2  load-store pipelines
 2* load pipelines (no results to store)
 4* double-precision floating-point pipelines, which can also act as eight single-precision pipelines
 2* fully symmetric vector pipelines with support for VMX and VSX AltiVec instructions.
 1  decimal floating-point pipeline
 1* cryptographic pipeline (AES, Galois Counter Mode, SHA-2)
 1  branch execution pipeline
 1  condition register logical pipeline
 
  Note: All units different from POWER7 are marked by "*". 
        POWER7 Core has 12 execution units, POWER8 16.

9. Conclusion

This Blog presented the POWER7 model of CPU usage and throughput, and examined with real cases. Accurately modelling leads to not only fruitful system tuning and trustful performance assessment, but also fairly charging back and economically resource utilizing (e.g. Power Saver Mode). As coming study, we will investigate the applicability and eventually adaptation of the model on new POWER8 (SMT=8), and the future POWER9.

References

1. POWER7

2. Understanding CPU Utilization on AIX

3. Local, Near & Far Memory part 3 - Scheduling processes to SMT & Virtual Processors

4. P. Mackerras, T. S. Mathews, and R. C. Swanberg. Operating System Exploitation of the POWER5 System.
    IBM J. Res. Dev., 49(4/5):533–539, July 2005.

5. CPU accounting in multi-threaded processors

6. java stored procedure calls and latch: row cache objects, and performance

7. java stored procedure calls and latch: row cache objects

8. Unaccounted Time in 10046 File on AIX SMT4 Platform when Comparing Elapsed and CPU Time (Doc ID 1963791.1)

    Bug 13354348 : UNACCOUNTED GAP BETWEEN ELAPSED TO CPU TIME ON 11.2 IN AIX
    Bug 16044824 - UNACCOUNTED GAP BETWEEN ELAPSED AND CPU TIME FOR DB 11.2 ON PLATFORM AIX POWER7
    Bug 18599013 : NEED TO CALCULATE THE UNACCOUNTED TIME FOR A TRACE FILE
    Bug 7410881 : HOW CPU% UTILIZATION COLLECTED ON AIX VIA EM
    Bug 15925194 : AIX COMPUTING METRICS INCORRECTLY

9. Oracle on AIX - where's my cpu time ?

10. nmon CPU graphs - Why are the PCPU_ALL graphs lower?

11. dW:AIX and UNIX:Performance Tools Forum:Nmon - PCPU_ALL

12. libperfstat.h

13. POWER8

Oracle 11.2.0.4.0 AWR "Tablespace IO Stats" Column Names Shifted

Oracle 11.2.0.4.0 added two new columns in Section "Tablespace IO Stats" and "File IO Stats":

 1-bk Rds/s
 Av 1-bk Rd(ms)

but in "Tablespace IO Stats", both Column Names do not match the content in the table.

Running the appended TestCase, we got the AWR report for "Tablespace IO Stats":

Tablespace	Reads	Av Rds/s	Av Rd(ms)	Av Blks/Rd	1-bk Rds/s	Av 1-bk Rd(ms)	Writes	Writes avg/s	Buffer Waits	Av Buf Wt(ms)
TEST_TBS	25	6	0	7.6	87	1.54	0	22	0	0

and "File IO Stats":

Tablespace	Filename	Reads	Av Rds/s	Av Rd(ms)	Av Blks/Rd	1-bk Rds/s	Av 1-bk Rd(ms)	Writes	Writes avg/s	Buffer Waits	Av Buf Wt(ms)
TEST_TBS	test_tbs.dbf	25	6	0	7.6	2	0	87	22	0	0

In "Tablespace IO Stats", "1-bk Rds/s" and "Av 1-bk Rd(ms)" have to be switched with Column "Writes" so that Names are in sync with Content.

Tablespace	Reads	Av Rds/s	Av Rd(ms)	Av Blks/Rd	Writes	1-bk Rds/s	Av 1-bk Rd(ms)	Writes avg/s	Buffer Waits	Av Buf Wt(ms)
TEST_TBS	25	6	0	7.6	87	1.54	0	22	0	0

Another difference noticed is that both "Tablespace IO Stats" and "File IO Stats" report Read statistics:
     Av Rd(ms)
  Av Blks/Rd
but there are no symmetrical figures on Write like:
   *Av Wr(ms)
 *Av Blks/Wr

With following query, we can fulfil these statistics:

select filename, file#, snap_id, end_interval_time
      ,round(phyrds_d)                             "Reads"
      ,round(phyrds_d/interval_seconds)            "Av Reads/s"      
      ,round(readtim_d*10/nullif(phyrds_d, 0))     "Av Rd(ms)"       
      ,round(phyblkrd_d/nullif(phyrds_d, 0))       "Av Blks/Rd"  
      ,round(singleblkrds_d/interval_seconds)      "1-bk Rds/s"  
      ,round(singleblkrdtim_d*10/nullif(singleblkrds_d, 0))     "Av 1-bk Rd(ms)"
      ,round(phywrts_d)                            "Writes"  
      ,round(phywrts_d/interval_seconds)           "Av Writes/s"  
      ,round(writetim_d*10/nullif(phywrts_d, 0))   "*Av Wr(ms)"      -- * Not in AWR
      ,round(phyblkwrt_d/nullif(phywrts_d, 0))     "*Av Blks/Wr"     -- * Not in AWR
      ,round(wait_count_d)                         "Buffer Waits"  
      ,round(time_d*10/nullif(wait_count_d, 0))    "Av Buf Wt(ms)"   -- in CentiSeconds
from (
  select 
     phyrds - lag(phyrds) over(partition by file# order by snap_id) phyrds_d
    ,phywrts - lag(phywrts) over(partition by file# order by snap_id) phywrts_d
    ,singleblkrds - lag(singleblkrds) over(partition by file# order by snap_id) singleblkrds_d
    ,readtim - lag(readtim) over(partition by file# order by snap_id) readtim_d
    ,writetim - lag(writetim) over(partition by file# order by snap_id) writetim_d
    ,singleblkrdtim - lag(singleblkrdtim) over(partition by file# order by snap_id) singleblkrdtim_d
    ,phyblkrd - lag(phyblkrd) over(partition by file# order by snap_id) phyblkrd_d
    ,phyblkwrt - lag(phyblkwrt) over(partition by file# order by snap_id) phyblkwrt_d
    ,wait_count - lag(wait_count) over(partition by file# order by snap_id) wait_count_d   
    ,time - lag(time) over(partition by file# order by snap_id) time_d
    ,end_interval_time   
    ,interval_seconds
    ,t.*
from dba_hist_filestatxs t
   ,(select snap_id s_snap_id, end_interval_time 
           ,((sysdate + (end_interval_time - begin_interval_time)) - sysdate)*86400 interval_seconds 
       from dba_hist_snapshot)
where t.snap_id = s_snap_id
  and tsname = 'TEST_TBS'
  and snap_id >= (select max(snap_id) from dba_hist_snapshot) - 6
--  and end_interval_time > timestamp'2015-04-22 06:00:00'
);

TestCode

Run code block:

 drop tablespace test_tbs including contents;
 
 create tablespace test_tbs datafile 'test_tbs.dbf' size 100m reuse online;
 
 drop table testt;
 
 create table testt(x number, y varchar2(1000)) tablespace test_tbs;
 
 exec sys.dbms_workload_repository.create_snapshot('ALL'); 
 
 insert into testt select level x, rpad('abc', 1000, 'x') y from dual connect by level <= 1000;
 
 commit;
 
 alter system flush buffer_cache; 
 
 select count(*) from testt;
 
 exec dbms_lock.sleep(3);
 
 exec sys.dbms_workload_repository.create_snapshot('ALL'); 
 
 select bytes, blocks from dba_segments where segment_name = 'TESTT';

And get AWR report by:

select * from table(SYS.DBMS_WORKLOAD_REPOSITORY.awr_report_html(
  (select dbid from v$database), 1, 
  (select max(snap_id) from dba_hist_snapshot) - 1, 
  (select max(snap_id) from dba_hist_snapshot)));

There could exist other misleading information in AWR report. Recently we were puzzled by a high Session UGA and PGA memory reported in AWR, where UGA is much larger than PGA in a dedicated server:

  session pga memory max    308,253,725,520    302,308,652,008
  session uga memory max  5,614,577,384,552  5,666,238,828,552

At the end, we found one MOS Note:
    High Session UGA & PGA Memory Reported in AWR (Doc ID 1483177.1)
which said:

    These statistics will be removed from AWR report in future versions, could be 12.1 
    so you should not depend on these fake numbers for investigations of performance issues.

open_cursors, session_cached_cursors: cursordump

1. Parse

Oracle (11.2.0.3.0) document wrote:

OPEN_CURSORS specifies the maximum number of open cursors (handles to private SQL areas) a session can have at once (Oracle® Database Reference 11g Release 2 (11.2)).

SESSION_CACHED_CURSORS specifies the number of session cursors to cache. Repeated parse calls of the same SQL (including recursive SQL)  or PL/SQL statement cause the session cursor for that statement to be moved into the session cursor cache. Subsequent parse calls will find the cursor in the cache and do not need to reopen the cursor (Oracle® Database Reference 11g Release 2 (11.2)).

Popular Oracle books invested a large paragraph on both subjects:

•  Effective Oracle by Design (Thomas Kyte): Page 287-302
•  Oracle Core: Essential Internals for DBAs and Developers (Jonathan Lewis): Page 173-178
•  Oracle Performance Firefighting (Craig Shallahamer): Page 261
•  Troubleshooting Oracle Performance (Christian Antognini) (2nd Edition): Page 436-438

In summary, one cursor experiences:

1. hard parse:   not yet existed in SGA
2. soft parse:    globally available in SGA's shared pool (library cache)
3. softer parse: locally available in PGA's Session Cached Cursor (controlled by SESSION_CACHED_CURSORS)
4. no parse:      executed in PL/SQL and found in PL/SQL cached type (specially optimized for PL/SQL)

and its life stage undergoes from one phase to next.

Classifying by its locality (similar to NUMA memory):

1. hard parse:   first-time creating(or re-creating)
2. soft parse:    global shared_pool cache
3. softer parse: local session UGA cache
4. no parse:      running thread heap

If we model them in 3 dimensional Qualitative Physics, each phase can be represented as:

1. hard parse:   parse_count_hard(+), parse_count_total(+), lock_count(+), pin_count(+)
2. soft parse:    parse_count_hard(0), parse_count_total(+), lock_count(+), pin_count(+)
3. softer parse: parse_count_hard(0), parse_count_total(+), lock_count(0), pin_count(+)
4. no parse:      parse_count_hard(0), parse_count_total(0), lock_count(0), pin_count(0)

where + for increase, 0 for no change(or little change).
(Note:lock_count: library cache lock; pin_count: library cache pin)

So we can use 4 metrics to determine a cursor's parse stage (see queries of next sesction).

2. Parse Identifying

With following example queries, we can determine the types of parsing: (Note: 'parse count (total)' is same as 'parse_calls').

select n.name, s.value 
  from v$statname n, V$SESSTAT s 
 where n.statistic# = s.statistic# 
   and n.name in ('execute count', 'parse count (hard)', 'parse count (total)', 'session cursor cache hits')
   and s.sid in (:sid);
 
select executions, parse_calls, locked_total, pinned_total, loads, invalidations, child_number, last_load_time, v.* 
  from V$SQL v 
 where sql_id in (':SQL_ID') or lower(sql_text) like '%:sql_text%'
  order by v.last_load_time desc;

select timestamp, locked_total, pinned_total, loads, invalidations, v.* 
  from V$DB_OBJECT_CACHE v 
 where lower(name) like '%:name%' 
 order by v.timestamp desc;

select cursor_type, v.* 
  from V$OPEN_CURSOR v 
 where v.cursor_type in ('SESSION CURSOR CACHED', 'PL/SQL CURSOR CACHED') 
   and v.sid in (:sid) and sql_id in (':sql_id')
   --and lower(sql_text) like '%:sql_text%'
 order by v.sid, v.cursor_type;

The difference among them are signified by the columns' values of those views:

1. hard parse:   
     V$SESSTAT 'parse count (hard)' value
     V$SQL.invalidations and loads
     V$DB_OBJECT_CACHE.invalidations and loads
2. soft parse:  
     V$SQL.locked_total 
     V$DB_OBJECT_CACHE.locked_total     
3. softer parse: 
     V$SESSTAT 'session cursor cache hits' value
     V$SQL.pinned_total 
     V$DB_OBJECT_CACHE.pinned_total    
     V$OPEN_CURSOR 'SESSION CURSOR CACHED'
4. no parse:
     V$OPEN_CURSOR 'PL/SQL CURSOR CACHED'
     V$SQL.parse_calls (not increasing)
     V$DB_OBJECT_CACHE.parse_calls (not increasing)      

Only in case of "no parse", 'parse count (total)' or parse_calls are not increased.

3. Cusrordump

A cusrordump by:

 alter session set open_cursors=400;
 alter session set session_cached_cursors=600;
 alter session set tracefile_identifier = "cursordump_4";
 alter session set events 'immediate trace name cursordump level 4';

reveals certain aspects of internal implementation (irrelevant details are removed):

 ----- Session Cursor Dump -----
 Current cursor: 4, pgadep=0

 Open cursors(pls, sys, hwm, max): 4(0, 2, 64, 400)
  NULL=3 SYNTAX=0 PARSE=0 BOUND=1 FETCH=0 ROW=0
 Cached frame pages(total, free):
  4k(50, 50), 8k(1, 1), 16k(1, 1), 32k(0, 0)
 ----- Session Open Cursors -----
 ----------------------------------------
 Cursor#1(0x1108e1b38) state=NULL curiob=0x110906698
  ......
 Cursor#6(0x1108e1e08) state=NULL curiob=0x110e38c70
  ......
 Cursor#5(0x1108e1d78) state=NULL curiob=0x11090a528
  ......
 Cursor#4(0x1108e1ce8) state=BOUND curiob=0x110908068
  ......

 ----- Session Cached Cursor Dump -----
 ----- Generic Session Cached Cursor Dump -----
 -----------------------------------------------------------
 hash table=1108e4100 cnt=539 LRU=1108d5168 cnt=536 hit=2263 max=600 NumberOfTypes=6
 type#0 name=DICTION count=0
 type#1 name=BUNDLE  count=13
 type#2 name=SESSION count=38
 type#3 name=PL/SQL  count=485
 type#4 name=CONSTRA count=0
 type#5 name=REPLICA count=0
  Bucket#001 seg=1108e4128 nit=8 nal=8 ips=8 sz=56 flg=3 ucnt=0
  Bucket#008 seg=1108e4278 nit=8 nal=8 ips=8 sz=56 flg=3 ucnt=1
    0 cob=110caaa28 idx=8 flg=0 typ=3 cur=110e27f90 lru=1 fl=15
  ......
  Bucket#109 seg=1108e5568 nit=8 nal=8 ips=8 sz=56 flg=3 ucnt=2
    0 cob=110907140 idx=6d flg=0 typ=2 cur=11092ac40 lru=1 fl=1
    1 cob=110907178 idx=1006d flg=0 typ=2 cur=110c796f0 lru=1 fl=1
  ......
  Bucket#256 seg=1108e70f8 nit=8 nal=8 ips=8 sz=56 flg=3 ucnt=0

In the above dump, max number of Open cursors is noted with 400 due to open_cursors=400;
and indicated with state info:

 NULL=3 SYNTAX=0 PARSE=0 BOUND=1 FETCH=0 ROW=0

Max number of Session Cached Cursor is 600 because of session_cached_cursors=600.

Internally Session Cached Cursor is a hash table consisting of 256 Buckets, classified into 6 types, and located in PGA. Since Session Cached Cursor is limited with 256 Buckets, setting session_cached_cursors bigger than 256 incurs more chance of hash collision (Bucket#109 in above example).

Open cursors and Session Cached Cursors by each session are exposed by V$OPEN_CURSOR which lists cursors that each user session currently has opened and parsed, or cached. Internally they are the kgl locks (x$kgllk) imposed by the session.

Joining v$open_cursor with v$libcache_locks (or dba_kgllock)  displays information (LOCK_HELD, REFCOUNT, MODE_HELD, MODE_REQUESTED) about the locks:

   select * from v$open_cursor c, v$libcache_locks l
  where c.saddr = l.holding_user_session
    and c.address = l.object_handle;

Local prefixed vs. nonprefixed indexes: Column Null Values

According to Oracle Doc, Oracle does not index table rows in which all key columns are null except in the case of bitmap indexes (Database SQL Language Reference).

Therefore, in a composite B-tree index, if there exists one column which contains a non-null value, the row will be indexed. Since local prefixed indexes is a composite index which includes partition keys on the leading edge of the index definition, and partition keys are never all null, all rows are always indexed.

For applications, it means that local prefixed indexes is always usable, but not local nonprefixed indexes. In the performance point of view, Column Null Values is a torque on Local prefixed vs. nonprefixed indexes (Number_of_Null_Columns x Number_of_Rows).

Taking the same example from Expert Oracle Database Architecture Page 593, but updating Column b of one row in PART_1 as NULL.

 create table partitioned_table
 ( a int,
   b int,
   data char(20)
 )
 partition by range (a)
 (
 partition part_1 values less than(2) tablespace p1,
 partition part_2  values less than(3) tablespace p2
 )
 /

 create index local_prefixed on partitioned_table (a,b) local;

 create index local_nonprefixed on partitioned_table (b) local;

 insert into partitioned_table
  select mod(rownum-1,2)+1, rownum, 'x' from all_objects where rownum <= 1000;

 update partitioned_table set b=null where a=1 and b=99;
  
 begin
    dbms_stats.gather_table_stats
    ( user,
     'PARTITIONED_TABLE',
      cascade=>TRUE );
 end;
 /

we can see PART_1 having one row with Column b being NULL:

 select a, count(*), count(a), count(b)
  from partitioned_table group by a;

           A   COUNT(*)   COUNT(A)   COUNT(B)
  ---------- ---------- ---------- ----------
           1        500        500        499
           2        500        500        500

 select index_name, partition_name, num_rows
   from dba_ind_partitions
  where index_name in ('LOCAL_PREFIXED', 'LOCAL_NONPREFIXED');

 INDEX_NAME                     PARTITION_NAME                   NUM_ROWS
 ------------------------------ ------------------------------ ----------
 LOCAL_NONPREFIXED              PART_1                                499
 LOCAL_NONPREFIXED              PART_2                                500
 LOCAL_PREFIXED                 PART_1                                500
 LOCAL_PREFIXED                 PART_2                                500

Now if we run following queries, all of them will use LOCAL_PREFIXED index.

 select /*+ index(t local_prefixed) */ count(a) from partitioned_table t where a = 1 and b is null;

 select /*+ index(t local_nonprefixed) */ count(a) from partitioned_table t where a = 1 and b is null;

 select /*+ index(t local_prefixed) */ count(a) from partitioned_table t where b is null;

 select /*+ index(t local_nonprefixed) */ count(a) from partitioned_table t where b is null;

 select /*+ index(t local_prefixed) */ count(a) from partitioned_table t where a is null and b is null;

 select /*+ index(t local_nonprefixed) */ count(a)
   from partitioned_table t where a is null and b is null;

  -----------------------------------------------------------------------------------------------
  | Id  | Operation               | Name           | Rows  | Bytes | Cost (%CPU)| Pstart| Pstop |
  -----------------------------------------------------------------------------------------------
  |   0 | SELECT STATEMENT        |                |     1 |     7 |     1   (0)|       |       |
  |   1 |  SORT AGGREGATE         |                |     1 |     7 |            |       |       |
  |   2 |   PARTITION RANGE SINGLE|                |     1 |     7 |     1   (0)|     1 |     1 |
  |*  3 |    INDEX RANGE SCAN     | LOCAL_PREFIXED |     1 |     7 |     1   (0)|     1 |     1 |
  -----------------------------------------------------------------------------------------------

  Predicate Information (identified by operation id):
  ---------------------------------------------------

     3 - access("A"=1 AND "B" IS NULL)

For the queries with partition key being NULL, PARTITION RANGE EMPTY elimination is used.

Even though PART_2 does not contain any rows whose Column b being NULL, LOCAL_NONPREFIXED index can neither be used in the following queries.

 select /*+ index(t local_prefixed) */ count(a) from partitioned_table t where a = 2 and b is null;

 select /*+ index(t local_nonprefixed) */ count(a) from partitioned_table t where a = 2 and b is null;

 select /*+ index(t local_nonprefixed) */ count(a)
   from partitioned_table partition (part_2) t where b is null;

reverse key index: the remedy is worse than the symptoms

In general, reverse key index mitigates data block contention (buffer busy waits) when inserting monotonically increasing key into right-most index by multiple concurrent sessions. The disadvantage is its inability to support range scan.

Based on AWR report, this Blog will try to list the main checking points when using reverse key index, and shows how to find the acceptable trade-off between benefits and drawbacks. The whole discussion stems from author's experience in single instance DB (non-RAC).

1.Top 5 Timed Foreground Events

When some events like:
 enq: TX - index contention
 buffer busy waits
 read by other session
appear in Top Events, reverse key index is hastily resorted.

However "db file sequential read" should be checked after experimenting reverse key index since all the original inserts of right-most single index block are now spread over many blocks. One should try to balance the fast logical buffer activity against slow physical disk access.

2. Time Model Statistics

Since more blocks are involved with reverse key index, DBWR is more active, and therefore:
 background elapsed time
 background cpu time
are augmented.

Higher "db file parallel write" and "DBWR checkpoint buffers written" can also be observed,

3. SQL ordered by Gets

The insert statement generates a lower "Buffer Gets" in case of reverse key index.

4. SQL ordered by Reads

Reverse key index incurs a higher "Physical Reads" for the insert statement, almost 1 "Reads per Exec" since each insert touches a single different block.

Moreover, the queries using the index also cause higher "Physical Reads" due to the wide spreading of conceptually adjacent indexes, but physically isolated.

5. Segment Statistics

The absolute figures of buffer contentions and physical activities can be extracted by looking:
 Segments by Logical Reads
 Segments by Row Lock Waits
 Segments by Buffer Busy Waits

 Segments by Physical Reads
 Segments by Physical Writes
Based on them, a quick magnitude comparison of IO and Memory associated with system statistics can give an approximate assessment of reverse key index.

Discussion

D-1. Expert Oracle Database Architecture said:

 One way to improve the performance of the PL/SQL implementation with a regular index would be to introduce a small wait. That would reduce the contention on the right-hand side of the index and increase overall performance (Page 439)

 reverse key index (designed for Oracle RAC) (Page 491)

Usually, sequence insert in OLTP system is inherently operated with a slight delay due to the interactive nature of OLTP, whereas Batch processing can be impeded by heavy buffer contention of index blocks.

D-2. Introduction To Reverse Key Indexes: Part III (A Space Oddity) and
        Oracle B-Tree Index Internals:Rebuilding The Truth wrote:

If the "right-most" block is filled by the maximum current value in the index, Oracle performs 90-10 block splits meaning that full index blocks are left behind in the index structure.

I prefer to call them 99-1 block splits as 90-10 is misleading.

Generally reverse key index tends to use 50-50 Split, which costs more block creates and touches.
In principle, it shifts single block buffer contention to multiple accesses of separate blocks.

D-3. Oracle MOS has a cautious Doc:
        Using Reverse Key Indexes For Oracle 11.2.0.2 (Doc ID 1352477.1)

 However, it must be noted that : Now the entire index had better be in the buffer cache whereas before - only the hot right hand side needed to be in the cache for efficient inserts. If the index cannot fit into the cache we might well have turned a buffer busy wait into a physical IO wait which could be even worse (the remedy is worse than the symptoms).

The reminiscent last remark is voted as the title of this Blog.

D-4. Oracle MOS Doc:
 Troubleshooting 'enq: TX - index contention' Waits in a RAC Environment. (Doc ID 873243.1)
explains "enq: TX - index contention":

 The reason for this is the index block splits while inserting a new row into the index. The transactions will have to wait for TX lock in mode 4, until the session that is doing the block splits completes the operations.

and suggests to look Instance Activity Stats:  
  root node splits
 branch node splits
 leaf node splits
 leaf node 90-10 splits

In a DB, reverse key index can be found by:
 select * from dba_indexes where index_type = 'NORMAL/REV';

Low High Water Mark, High High Water Mark, and Parallel Query

Recently we saw a 4 hours running parallel SELECT:

 select /*+  parallel(t,2) parallel_index(t,2) dbms_stats cursor_sharing_exact
   use_weak_name_resl dynamic_sampling(0) no_monitoring no_substrb_pad 
   */count(*), count("ID"), count(distinct "ID"),
   sum(sys_op_opnsize("ID")), substrb(dump(min("ID"),16,0,32),1,120),
   substrb(dump(max("ID"),16,0,32),1,120),
   ...
 from "X"."TABLE_1" sample (  5.0000000000)  t;

which is generated when executing:
 dbms_stats.gather_table_stats('X', 'TABLE_1', estimate_percent=>5, degree=>2);
on both Oracle 11.2.0.3.0 and 11.2.0.4.0.

The table is about 160GB and contains 20m blocks (8K per block) in ASSM LMT Managed Tablespaces, all the columns are number or varchar2.

AWR report shows the SELECT statement statistics:
   Buffer Gets          14,805,983,166
 Physical Reads           40,474,817
 UnOptimized Read Reqs     1,881,624

TABLE_1 Segment Statistics:
 Segments by Logical Reads        16,312,997,632
 Segments by Physical Reads           38,580,663
 Segments by Direct Physical Reads    38,557,265
 Segments by Table Scans                 263,660
 Segments by Buffer Busy Waits            53,492

At first, one surprising big "Table Scans" indicates certainly abnormal behavior.

Huge number of "Buffer Gets" and double "Physical Reads" also explain the slow running.

"Table Scans" for Parallel Query is the Execs of "TABLE ACCESS FULL" below "PX BLOCK ITERATOR" in xplan, since "PX BLOCK ITERATOR" at first breaks up the table into granules which are then dispatched to each PX slaves. In the case of SAMPLE select, it is the Execs of "TABLE ACCESS SAMPLE BY ROWID RANGE".

The number of granules processed by each PX slave is controlled by two hidden parameters:
 _px_min_granules_per_slave: minimum number of rowid range granules to generate per slave default  13
 _px_max_granules_per_slave: maximum number of rowid range granules to generate per slave default 100

For instance, parallel(t,2) contributes minimum 26 (2*13) "Table Scans", and maximum 200 (2*100);
and parallel(t,16) generates minimum 208 (16*13) "Table Scans", and maximum 1600 (16*100);

Therefore when increasing degree from 2 to 16,
 dbms_stats.gather_table_stats(null, 'TABLE_1', estimate_percent=>5, degree=>16);
will take 32 (8*4) hours. That is a counterintuitive behavior when using parallel query.

The "Table Scans" can be monitored by:
     select * from V$segment_statistics
   where object_name = 'TABLE_1' and statistic_name = 'segment scans';
 
The hidden parameters can be changed by, for example:
 alter system set "_px_min_granules_per_slave"=19;
 
 
Searching MOS, we found:

 Bug 6474009 - On ASSM tablespaces Scans using Parallel Query can be slower than in 9.2 (Doc ID 6474009.8)

which says:

 Scans using Parallel Query on ASSM tablespaces on 10.2 can be slower compared to 9.2 when there is a wide separation between the High and Low High Water Mark.  There can be High contention and/or a large number of accesses to bitmap blocks in PQ slaves during extent-based scans
 of table/index segments.

 AWR reports may show "read by other session" as one of the top wait events and Section "Buffer Wait Statistics" may report "1st level bmb" as the most important wait class.

 The difference between the High and Low High Water Mark can be identified by running procedure DBMS_SPACE_ADMIN.ASSM_SEGMENT_SYNCHWM with parameter check_only=1.

The AWR report confirms the above notice:
 read by other session  Waits=11,302,432
 1st level bmb          Waits=98,112

and calling:
 DBMS_SPACE_ADMIN.ASSM_SEGMENT_SYNCHWM('X','TABLE_1','TABLE',NULL,1) returns 1.

MOS also gives a Workaround:
   Execute procedure DBMS_SPACE_ADMIN.ASSM_SEGMENT_SYNCHWM with check_only=0 to synchronize the gap between the High and Low High Water Mark.
   IMPORTANT: A patch for bug 6493013 must be installed before running that procedure.
  
DBMS_SPACE_ADMIN.ASSM_SEGMENT_SYNCHWM only signals the existence of the gap,
but does not report the size of the gap. However, the width between low HWM and the HWM
determines the performance of full table scan (see Section "Segment Space and the High Water Mark" later in this Blog).

To find the exact gap size, we can dump segment header by:
 alter system dump datafile 94 block 2246443; 

Here the output:
  -----------------------------------------------------------------
  Extent Header:: spare1: 0      spare2: 0      #extents: 1242809 #blocks: 19884944
                  last map  0x9d178f31  #maps: 2446   offset: 2720 
      Highwater::  0x9d179f90  ext#: 1242808 blk#: 16     ext size: 16   
  #blocks in seg. hdr's freelists: 0    
  #blocks below: 19804642
  mapblk  0x9d178f31  offset: 441  
                   Unlocked
  --------------------------------------------------------
  Low HighWater Mark :
      Highwater::  0x1e243af9  ext#: 448588 blk#: 16     ext size: 16   
  #blocks in seg. hdr's freelists: 0    
  #blocks below: 7177417
  mapblk  0x1e242fd9  offset: 225  
  Level 1 BMB for High HWM block: 0x9d179910
  Level 1 BMB for Low HWM block: 0x1aace0d9
  --------------------------------------------------------

We can see there are 19,804,642 blocks below Highwater: 0x9d179f90, but only 7,177,417 below Low HighWater Mark: 0x1e243af9. So 12,627,225 (19804642-7177417) are between (64%).

The distance between Level 1 BMB High HWM block and Low HWM block is 2,188,032,055
(0x9d179910 - 0x1aace0d9 = 2635569424 - 447537369 = 2188032055).

After synchronizing by:
  DBMS_SPACE_ADMIN.ASSM_SEGMENT_SYNCHWM('X','TABLE_1','TABLE',NULL,0)
the gap is gotten closed as showed by anew header dump:
  
  -----------------------------------------------------------------
  Extent Header:: spare1: 0      spare2: 0      #extents: 1242809 #blocks: 19884944
                  last map  0x9d178f31  #maps: 2446   offset: 2720 
      Highwater::  0x9d179f90  ext#: 1242808 blk#: 16     ext size: 16   
  #blocks in seg. hdr's freelists: 0    
  #blocks below: 19804642
  mapblk  0x9d178f31  offset: 441  
                   Unlocked
  --------------------------------------------------------
  Low HighWater Mark :
      Highwater::  0x9d179f90  ext#: 1242808 blk#: 16     ext size: 16   
  #blocks in seg. hdr's freelists: 0    
  #blocks below: 19884944
  mapblk  0x9d178f31  offset: 441  
  Level 1 BMB for High HWM block: 0x9d179910
  Level 1 BMB for Low HWM block: 0x9d179910
  --------------------------------------------------------  
 
In "Low HighWater Mark" section:
     -. "#blocks below: 7177417" is updated to "#blocks below: 19884944" (even bigger than 19804642).
     -. "Level 1 BMB for Low HWM block: 0x1aace0d9" is changed to "Level 1 BMB for Low HWM block: 0x9d179910",
               which got the same block id (0x9d179910) as "Level 1 BMB for High HWM block: 0x9d179910".

by chance, we also notice that the gap between the High and Low High Water Mark can be synchronized by:
 select /*+ parallel(t, 2) */ count(*) from TABLE_1 t;

Segment Space and the High Water Mark

Oracle has a detail description about High HWM (or simply HWM) and Low HWM
(see Segment Space and the High Water Mark):

 Suppose that a transaction inserts rows into the segment. The database must allocate a group of blocks to hold the rows. The allocated blocks fall below the HWM. The database formats a bitmap block in this group to hold the metadata,  but does not preformat the remaining blocks in the group. 

 The low HWM is important in a full table scan. Because blocks below the HWM are formatted only when used, some blocks could be unformatted, as in Figure 12-25. For this reason, the database reads the bitmap block to obtain the location of the low HWM. The database reads all blocks up to the low HWM because they are known to be formatted, and then carefully reads only the formatted blocks between the low HWM and the HWM.

We can see that ASSM uses bitmap to track the state of blocks in the segment, and introduces LHWM and HHWM to manage segment space.

Low High-Water Mark (LHWM): Like the old High Water Mark.
    All blocks below this block have been formatted for the table.

High High-Water Mark (HHWM)
    All blocks above this block have not been formatted.

The LHWM and the HHWM may not be the same value depending on how the bitmap tree was traversed. If different the blocks between them may or may not be formatted for use. The HHWM is necessary so that direct load operation can guarantee contiguous unformatted blocks.

During parallel query, a select on v$bh shows more than 100 CR versions of TABLE_1 segment header block. It could be triggered by bitmap block(BMB) checking.

When looking v$session.event, we saw a heavy activity on:
 "db file parallel read"

AWR report also shows:
 db file parallel read:  202,467

Oracle says that this event happens during recovery or buffer prefetching. But in this case, it could be the multiple BMB blocks' reads from different files in which BMB blocks are located for each group.