Tales From A Lazy Fat DBA

Hi Guys,

Now after my last two posts on Perf tool/profiler, i guess this the right time to move ahead with interpretation on stack trace data.
Back with another post, this time as promised about ‘Flame Graphs’!
So, would like to first start with the very standard question – Why, what this Flame Graphs are ?

Flame Graphs is tool developed by Kernel/System Performance maestro Brendan Gregg to project or visualize strack traces for both user/all processes and kernel-level stacks for CPU, Off-CPU etc. You can use it on stacks/traces collected by various profiler i.e. perf, Dtrace, SystemTap etc.

In this post we will be using PERF for statistics collection and project them using Flame Graphs and will understand the complexity and the code paths of many Oracle’s internal functions. This being the very first edition for this subject we will start with basics and will first discuss about CPU graphs and try to understand why and where CPUs are busy using stack traces and identify hot code-paths.This can be a really helpful tool for fast identification of performance problems where conventional oracle performance tools failed.

Okay, let’s jump on how you will do it. First you have to download the toolkit (Download Link)
This tool generates results in SVG format using below three steps.

• Stats Collection using any of the profiler e.g. Perf, Dtrace, Systemtap etc.
• Compress or Fold your stats
• Finally use the core (flamegraph.pl) script to generate the SVG file.

Okay, so now after enough description on tool, let’s start out first case – “CPU Flame Graphs for an expensive SQL Statement”.

Scenario: We have a resource intensive query “COUNT on one of the big table “ running from session with SPID 19280
So, we will be collecting process strack traces while the SQL statement was in run.

SQL> explain plan for select count(*) from dwh.**********_*** where ****TIMESTAMP > '23-JUN-16' and ******KEY > 789999999;

Explained.

SQL> SELECT * FROM TABLE(dbms_xplan.display);

PLAN_TABLE_OUTPUT
------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------
Plan hash value: 1112565023

------------------------------------------------------------------------------------------
| Id  | Operation          | Name                | Rows  | Bytes | Cost (%CPU)| Time     |
------------------------------------------------------------------------------------------
|   0 | SELECT STATEMENT   |                     |     1 |    14 |  2604K  (1)| 08:40:53 |
|   1 |  SORT AGGREGATE    |                     |     1 |    14 |            |          |
|*  2 |   TABLE ACCESS FULL| **************_**** |    39M|   524M|  2604K  (1)| 08:40:53 |
------------------------------------------------------------------------------------------

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

   2 - filter("*****KEY">789999999 AND "*****TIMESTAMP">'23-JUN-16')

14 rows selected.

SQL>

Now collecting perf statistics for the process at low-frequency of 997 Hertz.

[root@dselimw5862 perftest]# perf record -a -g -F997 -p 19280 

perf record: Woken up 3926 times to write data ]
[ perf record: Captured and wrote 981.809 MB perf.data (9751081 samples) ]

This will create perf data file under the same directory.

[root@dselimw5862 perftest]# ls -ltrh
-rw-------. 1 root root 982M Jan 12 14:58 perf.data

Next, collapse the stacks using below

[root@dselimw5862 perftest]# /root/perftest/FlameGraph-master/stackcollapse-perf.pl 

Finally, time to render the SVG file.

[root@dselimw5862 perftest]# /root/perftest/FlameGraph-master/flamegraph.pl --title "Flame Graph: Selective data search on dwh.W6AUDITHISTORY_FULL Table" > ImageAuditHistory.svg 

Let’s open the SVG file in browser and see what’s it’s got!

Important Note: The x-axis reflects stack profile population, and the y-axis represents the stack depth

Here you will see many of the familiar Oracle specific functions/processes opiodr, opitsk, opiino, opidrv etc.
Okay so, If you take a look at the map, you will see few of the Linux processes spawned first which called Oracle Internal functions next which moved to the query execution (i.e SELECT FETCH -> GROUP BY SORT -> TABLE ACCESS) and then to other functions. For example you can see the execution time during the sampling was spent in kdstf0100101000km functions which was called by kdsttgr which is Kernel Data Scan Table Get Row.

So, now question ‘Which function is on CPU the most ??‘
The top edge shows who is on CPU directly, copy_user_generic_unrolled function which is used when there is no optimization on CPU level.
Remember Flame Graphs follows ancestry, means copy_user_generic_unrolled was called by __pread_nocancel and __pread_nocancel was called by ksfd_skgfqio and which called … and then it points to …

Next look little above from the bottom of the graph with three functions __libc_start_main, __pread_nocancel and kaf4reasrp1km. If we visually compare them it is clear that __pread_nocancel function was running more often than other two. We see one of the linux function __pread_nocancel() was sampled a lot during the query execution and found repeated 2 times in the graph. This is used by libc when a cancellation point (a POSIX threads concept) is not permitted.

In Short: So, the Flame Graphs might help you when you have a problem in hand ‘My Production Database had poor performance”.
It was a heavy CPU consumer, so i used to CPU profiler to see WHY ? – But do you thing reading those lengthy, messy, long, raw traces that easy. So, here at this point there is a need of some data representation tool to capture the problems and sources and to visualize them. Here comes Flame Graphs to picture, The hero! It also gives you flexibility to move your cursor to any of the object to understand how much percent the object was present during the sample time.

Well, in later editions for this subject i will try to cover more scenarios. The sole purpose of this post is to give audience an idea, a gist of the topic.

Hope It Helps
Prashant Dixit