Oracle database internals by Riyaj

Discussions about Oracle performance tuning, RAC, Oracle internal & E-business suite.

Posts Tagged ‘oracle performance’

CPU profiling using perf utility in Linux

Posted by Riyaj Shamsudeen on June 9, 2016

After reading my blog entry about a performance issue due to excessive HCC decompression ( Accessing HCC compressed objects using index access path, a reader asked me about the CPU profiling method I mentioned in that blog entry. I started responding to that comment, and realized that the response was too big for a comment. So, in this blog entry, I will cover basics of the CPU profiling in Linux. Other platform provides similar utilities, for example, Solaris provides an utility dtrace.

Tool Box

There are many ways to do CPU profiling, and a few techniques are:
(a) Using Linux perf utility.
(b) Using pstack output and grouping the output by top functions in the call stack. Tanel has a great blog entry about the variant of this method: Tanel’s blog entry

I will discuss the perf utility briefly in this entry.

perf utility

There are two parts to perf utility usage: perf record to sample the function calls executed by a process or processes. perf record command writes the output to a file perf.data, by default, in the current directory. perf report reads the perf.data file and prints a human readable output of top function calls. Think of the functionality of the perf report command as “group by function_call, order by count desc” operation.

You can use perf utility to watch the server, a process, or a subset of processes. In this example, I recreated the issue in my database session and so we will use the command: perf record -p to record the function call samples on the dedicated server process associated with my session.

  -- Login to the database using your favorite tool.
  -- Find the pid of the Oracle dedicated server process. (You could skip this step if you know the pid of the process that you want to probe. Note that, you can use this method to probe an application performance issue also, not just database performance issue.)
  select spid from v$process where addr=(select paddr from v$session where sid=(select sid from v$mystat where rownum=1));
  
  -- In another window, login to the server and become root (sudo, direct login etc)
  cd /tmp; perf report -p 

  -- Recreate the issue in the first window.
  @lu.sql
  exit;

  -- Control+c the perf record command also.

perf report

So, perf record command mentioned above would have written the file perf.data. We can use perf report command to identify the function calls frequently seen executed by the process. ( Partial output shown to improve brevity)

# Events: 427K cycles
#
# Overhead          Command                 Shared Object                               Symbol
# ........  ...............  ............................  ...................................
#
    34.84%  oracle_76112_ua  oracle                        [.] BZ2_decompress
    25.52%  oracle_76112_ua  oracle                        [.] unRLE_obuf_to_output_FAST
     5.44%  oracle_76112_ua  oracle                        [.] kxhrPUcompare
     4.03%  oracle_76112_ua  oracle                        [.] qerhjWalkHashBucket
     4.00%  oracle_76112_ua  oracle                        [.] qerhjSplitProbe
     3.24%  oracle_76112_ua  oracle                        [.] qeruaRowProcedure
     3.18%  oracle_76112_ua  oracle                        [.] qerhjInnerProbeHashTable
     2.20%  oracle_76112_ua  oracle                        [.] kdzdcol_get_vals_rle_one
     2.05%  oracle_76112_ua  oracle                        [.] qervwRowProcedure
     2.03%  oracle_76112_ua  oracle                        [.] kdzt_acmp_project
     1.61%  oracle_76112_ua  oracle                        [.] evareo
     1.13%  oracle_76112_ua  oracle                        [.] kxhrHash
..

Analysis

From the output of perf report command, you can infer that the process was seen executing the BZ2_decompress function calls in ~35% of samples. That BZ2_decompress function call is executed to decompress the segments, compressed with HCC archive compression. Next function call in the list(25% of samples) unRLE_obuf_to_output_FAST is also associated with bzip2 decompression function (Refer unRLE_obuf_to_output_FAST ).

We were able to identify the function calls consuming the CPU cycles quickly using perf tool. In this case, it is HCC archive high decompression. So, we can correlate this data with the SQL Monitor output, identify the line number spending time, and understand the reasoning behind high CPU usage (and high elapsed time).

perf tool has many options. Read the wiki for further details: perf wiki

Posted in Oracle database internals, Performance tuning | Tagged: , , , , , , | 1 Comment »

Accessing HCC compressed objects using an index

Posted by Riyaj Shamsudeen on June 7, 2016

Problem

I came across another strange SQL performance issue: Problem was that a SQL statement was running for about 3+ hours in an User Acceptance (UA) database, compared to 1 hour in a development database. I ruled out usual culprits such as statistics, degree of parallelism etc. Reviewing the SQL Monitor output posted below, you can see that the SQL statement has already done 6 Billion buffer gets and steps 21 through 27 were executed 3 Billion times so far.

Statistics and execution plan

Please refer to the execution plan. Due to the functionality of the SQL statement, the execution plan seems acceptable. 3 Billion executions in to the view (at step 21) is also expected, however, why would the SQL statement runs much slower in the UA database ? [ Table names are changed for security reasons. ].
continue reading

Posted in 12c, Oracle database internals, Performance tuning | Tagged: , , , | 3 Comments »

library cache lock on BUILD$ object

Posted by Riyaj Shamsudeen on May 21, 2016

I was testing an application performance in 12c, and one job was constantly running slower than 11g. This post is to detail the steps. I hope the steps would be useful if you encounter similar issue.

Problem

In an one hour period, over 90% of the DB time spent on waiting for library cache lock waits. Upon investigation, one statement was suffering from excessive waits for ‘library cache lock’ event. We recreated the problem and investigated it further to understand the issue.

Following is the output of wait_details_rac.sql script (that I will upload here) and there are many PX query servers are waiting for ‘library cache lock’ wait event.

   SID PID        EVENT                          USERNAME   OSUSER     STATE               WAIT_TIME   WIS P1_P2_P3_TEXT
------ ---------- ------------------------------ ---------- ---------- ------------------- --------- ----- ----------------------------------------
                                                                                                            2163

   276  12445     library cache lock             TST_USR    test       WAITING                     0     1 handle address 399021346904-lock address
                                                                                                            2147

   288  12449     library cache lock             TST_USR    test       WAITING                     0     4 handle address 399021346904-lock address
                                                                                                            2136

   303  12453     library cache lock             TST_USR    test       WAITING                     0     4 handle address 399021346904-lock address
                                                                                                            2136

   315  12457     library cache lock             TST_USR    test       WAITING                     0     4 handle address 399021346904-lock address
 ...Snipped..                                                                                                           2152

continue reading

Posted in 12c, inmemory, Oracle database internals, Performance tuning, RAC | Tagged: , , , , , , , | 2 Comments »

OTNYathra2016

Posted by Riyaj Shamsudeen on March 24, 2016

Over the last many years, some of you have invited me to attend conferences in India, and talk about Oracle RAC and performance. I have not had an opportunity to make it to conferences in India, until now:)

I am excited to announce that I will be participating in OTN sponsored Oracle ACE Director’s tour in India (April 23rd to May 2nd 2016), and presenting ( with deep dive demos ) about RAC, performance, and in-memory. This is a golden opportunity for you to learn some of the internal stuff that I talk about in my class too.

Refer http://otnyathra.com for further details.

I am also excited to be in the tour with Connor McDonald, Biju Thomas, Sai, and many others. Don’t forget to send an email to Sai, the conference rooms will fill out quickly.

Did I mention deep dive demos?:)

Update 1: Updating the presentation slides and scripts. Do ask if I miss any script that you are looking for:)

india_2016_files_v1

Posted in 12c, Performance tuning, Presentations, RAC | Tagged: , | 5 Comments »

OOUG RAC day presentation files and scripts

Posted by Riyaj Shamsudeen on November 18, 2015

Thanks for coming to my presentations in RAC day at Dublin, Ohio. Please find the presentation files below. Hopefully, I will get video files and upload that here too.

OOUG presentation files and scripts

md5 checksum of the zip file is:

$md5sum ooug_2015_pdf.zip
df8bdcbc02926e5bbd721514b473bf16  ooug_2015_pdf.zip

Posted in Oracle database internals, Performance tuning, Presentations, RAC | Tagged: , , | 3 Comments »

RAC day with Ohio Oracle User Group

Posted by Riyaj Shamsudeen on October 22, 2015

I will be talking about RAC and performance in-depth, with lots of demos, in a RAC day training with Ohio Oracle User group on Nov 16,2015 Monday. Venue for the presentation is Dublin, Ohio.

Agenda for the day:

08:00a – 09:00: Registration / Breakfast

09:00a – 09:15: Announcements -Introduction of the speaker

09:15a – 10:30: Underpinning for Oracle RAC and Clusterware

10:30a – 10:45: Break

10:45a – 11:45: RAC cache fusion internals

11:45a – 01:00: Lunch

01:00p – 02:00: RAC Performance tuning Part 1 – Wait events and object tuning

02:00p – 02:15: Break

02:15p – 03:30: RAC performance tuning Part 2 – locks, library cache locks etc.

03:30p – 03:45: Member Announcements, Gift Drawings

Please RSVP to the co-ordinators so that you will have a seat:)

OOUG RAC day

Posted in Oracle database internals, Performance tuning, Presentations, RAC | Tagged: , , , | 1 Comment »

Demos do fail.

Posted by Riyaj Shamsudeen on April 15, 2015

I am an ardent believer of “show me how it works” principle and usually, I have demos in my presentation. So, I was presenting “Tools for advanced debugging in Solaris and Linux” with demos in IOUG Collaborate 2015 in Las Vegas on April 13 and my souped-up laptop (with 32G of memory, SSD drives, and an high end video processor etc ) was not responding when I tried to access folder to open my presentation files.

Sometimes, demos do fail. At least, I managed to complete the demos with zero slides:-) Apologies to the audience for my R-rated rants about laptop issues.

You can download presentations files from the links below.

Session_145_advanced_debugging_using_UNIX_tools

Session_189_Riyaj_Inmemory_internals_files

Posted in in-memory, inmemory, Performance tuning, Presentations | Tagged: , , , , , | Leave a Comment »

Visualizing AWR data using python

Posted by Riyaj Shamsudeen on August 1, 2014

In my earlier post, I talked about, how tableau can be used to visualize the data. In some cases, I find it useful to query AWR base tables directly using Python and graph it using matplotlib package quickly. Since python is preinstalled in almost all computers, I think, this method will be useful for almost everyone. Of course, you may not have all necessary packages installed in your computer, you can install the packages using install python packages . Of course, if you improve the script, please send it to me, I will share it in this blog entry.

Script is available as a zip file: plotdb.py

Usage:

Script usage is straight forward. Unzip the zip file and you will have a .py script in the current directory. Execute the script (after adjusting permissions of the script) using the format described below:

# To graph the events for the past 60 days, for inst_id=1, connecting to PROD, with username system. 
./plotdb.py -d PROD -u system -n 'latch free' -t e -i 1
# To graph the statistics for the past 60 days, for inst_id=2, connecting to PROD
./plotdb.py -d PRD -u system  -n 'physical reads' -t s -i 2

A typical graph from the above script is:

physical_reads

physical_reads

Posted in 11g, 12c | Tagged: , | 1 Comment »

inmemory area is another sub-heap of the top-level SGA heap

Posted by Riyaj Shamsudeen on July 30, 2014

I blogged earlier about heap dump shared pool heap duration and was curious to see how the inmemory – 12.1.0.2 new feature – is implemented. This is a short blog entry to discuss the inmemory area heap.

Parameters

I have set the initialization parameters sga_target=32G and inmemory_size=16G, meaning, out of 32GB SGA, 16GB will be allocated to inmemory area and the remaining 16GB will be allocated to the traditional areas such as buffer_cache, shared_pool etc. I was expecting v$sgastat view to show the memory allocated for inmemory area, unfortunately, there are no rows marked for inmemory area (Command “show sga” shows the inmemory area though). However, dumping heapdump at level 2 shows that the inmemory area is defined as a sub-heap of the top level SGA heap. Following are the commands to take an heap dump.

oradebug setmypid
oradebug heapdump 2 -- this command creates an heap dump trace file.
oradebug tracefile_name

Reviewing trace file

Trace file shows that the inmemory area is implemented as two sub-heaps namely IMCA_RO and IMCA_RW. Split is not equal between these two sub-heaps and I am not exactly sure about the algorithm for this split, about 12.75GB is allocated for IMCA_RO and the remaining 3.25GB is allocated for IMCA_RW area [ That’s about 80-20:) split ].

$ grep "heap name" *ora_56235*.trc
HEAP DUMP heap name="sga heap"  desc=0x600013d0
HEAP DUMP heap name="sga heap(1,0)"  desc=0x60063740
HEAP DUMP heap name="sga heap(1,3)"  desc=0x60068048
HEAP DUMP heap name="sga heap(2,0)"  desc=0x6006d490
HEAP DUMP heap name="sga heap(2,3)"  desc=0x60071d98
HEAP DUMP heap name="sga heap(3,0)"  desc=0x600771e0
...
HEAP DUMP heap name="sga heap(7,0)"  desc=0x6009e720
HEAP DUMP heap name="sga heap(7,3)"  desc=0x600a3028
HEAP DUMP heap name="IMCA_RO"  desc=0x60001130 <--- In memory Read only area?
HEAP DUMP heap name="IMCA_RW"  desc=0x60001278 <--- In memory Read write area?

You can learn all about SGA heap duration here , only last two lines are interesting to this blog entry and shows that two sub-heaps were allocated for Inmemory area.

The inmemory sub-heaps are split in to memory extents, similar to traditional SGA heap allocations. Each extent has numerous 64MB chunks allocated to it. These chunks are tagged as “cimadrv”. Total heap size is about 12.5GB.

HEAP DUMP heap name="IMCA_RO"  desc=0x60001130
 extent sz=0x1040 alt=288 het=32767 rec=0 flg=2 opc=2
 parent=(nil) owner=(nil) nex=(nil) xsz=0x30600000 heap=(nil)
 fl2=0x20, nex=(nil), dsxvers=1, dsxflg=0x0
 dsx first ext=0x64000000
 dsx empty ext bytes=0  subheap rc link=0x64000070,0x64000070
 pdb id=0
EXTENT 0 addr=0x363a00000
  Chunk        363a00010 sz=  8388304    free      "               "
  Chunk        3641ffee0 sz= 65011736    freeable  "cimadrv        "
  Chunk        367fffef8 sz= 67108888    freeable  "cimadrv        " <-- 64MB chunks
  Chunk        36bffff10 sz= 67108888    freeable  "cimadrv        "
  Chunk        36fffff28 sz= 67108888    freeable  "cimadrv        "
  Chunk        373ffff40 sz= 67108888    freeable  "cimadrv        "
...
EXTENT 1 addr=0x2e3b00000
  Chunk        2e3b00010 sz= 66059528    freeable  "cimadrv        "
  Chunk        2e79ffd18 sz= 67108888    freeable  "cimadrv        "
  Chunk        2eb9ffd30 sz= 67108888    freeable  "cimadrv        "
…
Total heap size    =13690208144 <-- Total heap size.

Next heap IMCA_RW is more interesting. This sub-heap also has extents with 64MB of chunks allocated it, however, I see that there are also smaller chunks in the heap. (I am still researching meaning of these chunks and trying to avoid guess work at this time.)

EAP DUMP heap name="IMCA_RW"  desc=0x60001278
 extent sz=0x1040 alt=304 het=32767 rec=0 flg=2 opc=2
 parent=(nil) owner=(nil) nex=(nil) xsz=0x50100000 heap=(nil)
 fl2=0x20, nex=(nil), dsxvers=1, dsxflg=0x0
 dsx first ext=0x790000030
 dsx empty ext bytes=0  subheap rc link=0x7900000a0,0x7900000a0
 pdb id=0
EXTENT 0 addr=0x80ff00000
  Chunk        80ff00010 sz= 17825296    free      "               "
  Chunk        810fffe20 sz= 50331672    freeable  "cimadrv        "
  Chunk        813fffe38 sz= 67108888    freeable  "cimadrv        "
  Chunk        817fffe50 sz= 67108888    freeable  "cimadrv        "
…
  Chunk        80f8d5ef8 sz=     8296    freeable  "cimcadrv-sb    " <-- smaller chunks. Most are about 8k or 16k.
  Chunk        80f8d7f60 sz=       48    freeable  "cimcadrv-sbrcv "
  Chunk        80f8d7f90 sz=      184    freeable  "cimcadrv-sblatc"
  Chunk        80f8d8048 sz=     8296    freeable  "cimcadrv-sb    "
  Chunk        80f8da0b0 sz=       48    freeable  "cimcadrv-sbrcv "
  Chunk        80f8da0e0 sz=      184    freeable  "cimcadrv-sblatc"
…
Total heap size    =3489660848

So, if this is similar to shared pool heap, is it possible to get an out-of-space error such as ORA-4031 for the shared pool heap?. There is such an error associated with inmemory option:).

 oerr ora 64356
64356, 00000, "in-memory area out of space"
// *Document: NO
// *Cause:    The in-memory area had no free space.
// *Action:   Drop the in-memory segments to make space.

In summary, I was expecting inmemory area to be allocated as integral part of buffer_cache buffers, however, that is not the case. Inmemory area size is allocated as sub-heaps very similar to the shared pool sub-heaps (but, NOT part of shared pool heaps though). As the software was released just recently, I need to research further to understand the intricate details.

Posted in 12c, Oracle database internals, Performance tuning | Tagged: , , , , | Leave a Comment »

Data visualization, px qref waits, and a kernel bug!

Posted by Riyaj Shamsudeen on July 2, 2014

Data visualization is a useful method to identify performance patterns. In most cases, I pull custom performance metrics from AWR repository and use tableau to visualize the data. Of course, you can do the visualization using excel spreadsheet too.

Problem definition
We had huge amount of PX qref waits in a database:

                                            Tota    Wait   % DB
Event                                 Waits Time Avg(ms)   time Wait Class
------------------------------ ------------ ---- ------- ------ ----------
PX qref latch                    63,669,198 3341       0   34.2 Other
DB CPU                                      3031           31.1
direct path read temp                92,996 199.       2    2.0 User I/O
direct path write temp               12,029 109.       9    1.1 User I/O
direct path read                      5,454 61.1      11     .6 User I/O

Read the rest of this entry »

Posted in 11g, 12c, Oracle database internals, Performance tuning, weird stuff | Tagged: , , , , , , , | 5 Comments »

 
Follow

Get every new post delivered to your Inbox.

Join 288 other followers