Skip to content

Usage examples

Jump to bottom Edit New page
Antony Dovgal edited this page Jan 14, 2013 · 1 revision

Table of Contents

Raw data and simple reports

Most requested scripts 

SELECT * FROM report_by_script_name ORDER BY req_per_sec LIMIT 100

Script distribution by execution time 

SELECT
   script_name,
   count(*) AS n,
   avg(req_time) AS avg_req_time,
   sum(req_time<0.2) AS n02, 
   sum(req_time<0.5) AS n05, 
   sum(req_time<1) AS n1, 
   sum(req_time<2) AS n2, 
   sum(req_time>=2) AS ng2
FROM request
GROUP BY script_name
HAVING ng2>0
ORDER BY n DESC
LIMIT 100;

We use HAVING param here to get stats for possibly slow scripts only (here: scripts that were executing over 2 seconds at least once).

Requests with "slow" timers 

SELECT r.id, r.script_name, t.value AS timer_value, hit_count, tag.value
FROM request r, timer t, timertag tag
WHERE t.value>1 AND r.id = t.request_id AND tag.timer_id = t.id
ORDER BY t.value DESC
LIMIT 100;

Get top 100 slowest timers (here: slower than 1 sec) with corresponding script name.

Request details 

SELECT t.*, tag.* FROM timer t, timertag tag WHERE t.request_id = 42 AND tag.timer_id = t.id;

Request time distribution for a certain script 

$pinba_host = "host";
$pinba_user = "user";
$pinba_pswd = "pswd";
$pinba_db = "pinba";
$script_name = "/script.php";
$precision = 0.05;
$show_threshold = 0.5;

$c = mysql_connect($pinba_host, $pinba_user, $pinba_pswd);
mysql_select_db($pinba_db, $c);

$r = mysql_query("SELECT req_count FROM report_by_script_name WHERE script_name = '".$script_name."'");
$row = mysql_fetch_row($r);
$count = $row[0];

$precision_arg = round($precision * 100, 2);
$r = mysql_query("SELECT COUNT(*) as num, ROUND(req_time/".$precision_arg.", 2) * ".$precision_arg." as req_time_zone
                  FROM request
                  WHERE script_name = '".$script_name."'
                  GROUP BY ROUND(req_time/".$precision_arg.", 2)
                  ORDER BY req_time_zone ASC");

while($row = mysql_fetch_row($r)) {
    $percent = ($row[0] / $count) * 100;
    if ($percent < $show_threshold) continue;
    printf("%0.2f: %-50s (%d, %0.2f%%)\n", $row[1], str_repeat("*",$percent), $row[0], $percent);
}

And here is what the result looks like: 

0.00:                                                    (612, 0.99%)
0.05: ***                                                (2239, 3.62%)
0.10: *****                                              (3401, 5.51%)
0.15: *****************************************          (25431, 41.17%)
0.20: ************                                       (7806, 12.64%)
0.25: *********                                          (5823, 9.43%)
0.30: *****                                              (3347, 5.42%)
0.35: **                                                 (1505, 2.44%)
0.40: *                                                  (1091, 1.77%)
0.45: ****                                               (2951, 4.78%)
0.50: **                                                 (1238, 2.00%)
0.55: *                                                  (1019, 1.65%)
0.60: *                                                  (746, 1.21%)
0.65: *                                                  (662, 1.07%)
0.70:                                                    (575, 0.93%)
0.75:                                                    (486, 0.79%)
0.80:                                                    (381, 0.62%)

Complex reports

This page explains how to get several basic reports. We used the following tags:

  • group is a group-operation tag: db::update, memcached::get etc
  • server is a remote host
Thus having a delete SQL statement executed by host db42 tags will be: 
 group = db::delete
 server = db42

Having a set command passed to memcached42 tags will be: 

 group = memcached::set
 server = memcached42

Corresponding report tables are:

  • tag_info_group - group stats
  • tag_info_group_server - group+server stats
Here comes DDL for these tables: 
CREATE TABLE `tag_info_group` (
  `tag_value` varchar(32) DEFAULT NULL,
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
  `hit_count` int(11) DEFAULT NULL,
  `hit_per_sec` float DEFAULT NULL,
  `timer_value` float DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag_info:group'
CREATE TABLE `tag_info_group_server` (
  `group_value` varchar(32) DEFAULT NULL,
  `server_value` varchar(32) DEFAULT NULL,
  `req_count` int(11) DEFAULT NULL,
  `req_per_sec` float DEFAULT NULL,
  `hit_count` int(11) DEFAULT NULL,
  `hit_per_sec` float DEFAULT NULL,
  `timer_value` float DEFAULT NULL
) ENGINE=PINBA DEFAULT CHARSET=latin1 COMMENT='tag2_info:group,server'

Basically there are just four parameters most important for performance analysis:

  • timer_value is total time the system spent in current operation (timer)
  • req_count is total count of requests with this operation (timer)
  • hit_count is total count of operations (timer measures) for this operation (timer)
  • avg_op_value is average time for a single operation (avg_op_value = timer_value/hit_count)

Basic group stats 

SELECT 
    tag_value, timer_value, 
    tag_value, 
    timer_value/req_count AS avg_timer_value, 
    timer_value/hit_count AS avg_op_value, 
    req_count, hit_count,
    hit_count/req_count AS avg_op_count
FROM tag_info_group
ORDER BY timer_value DESC

Here timer_value is sum for all the timers within one group. Groups are sorted by the total time spent by our system executing this group timers. Use "avg_op_value" to sort by an average operation value, or "avg_op_count" to sort by an average operation count. The difference between req_count and hit_count is the following: when we have 100 requests and each requests has exactly 2 same operations (timers with equal group), we have req_count=100 and hit_count=200 for this timer.

Script stats 

SELECT tag_value, timer_value, 
    timer_value/req_count AS avg_timer_value, 
    hit_count/req_count AS avg_op_count,
    timer_value/hit_count AS avg_op_value, 
    hit_count, req_count
FROM tag_report_group
WHERE script_name = '/index.phtml'
ORDER BY timer_value DESC

This report shows the "internal structure" for "/index.phtml".

Scripts with many timers 

SELECT script_name, tag_value, hit_count/req_count AS avg_hit_count
FROM tag_report_group
ORDER BY avg_hit_count DESC
LIMIT 100;

You may use this report to find scripts which do too much remote requests to memcached or database or whatever you measure.

Slowest db-servers 

SELECT group_value, server_value, 
    timer_value/req_count AS avg_timer_value, timer_value/hit_count AS avg_op_value, 
    timer_value, req_count, hit_count
FROM tag_info_group_server
WHERE group_value LIKE 'db::%'
ORDER BY avg_timer_value DESC
LIMIT 100;

This report shows servers with slowest average time for each database operation. Use timer_value for sorting if you want to get the most "important" servers (servers with maximal total time your system spent talking to). Or just hit_count to get the most loaded.

Examples with graphs

Average request time for certain scripts 

SELECT
      script_name,
      req_per_sec,
      req_time_total/req_count AS req_time_avg
  FROM
      report_by_server_and_script
 WHERE
      server_name = 'pinba.org'
   AND
      script_name IN ('/index.php', '/w/index.php', '/wiki')

Resulting graph (using RRDTool, updated every minute):
http://pinba.org/rrd/pinba-scripts-time-1d.png

You can find example scripts I use to generate this particular graph here: http://pinba.org/files/scripts/

Requests per second to certain scripts 

SELECT 
      script_name,
      req_per_sec,
      req_time_total/req_count 
  FROM 
      report_by_script_name
 WHERE 
      script_name IN (....)';

Resulting graph (using RRDTool):
http://pinba.org/img/top-cnt-1d.png

Operations in certain script (using timer tags to group timers) 

SELECT 
      tag_value, 
      timer_value 
  FROM 
      tag_report_group
 WHERE 
      script_name = "..."
ORDER BY 
      time DESC

Resulting graph (using RRDTool):
http://pinba.org/img/index-1d.png

Add a custom footer
Add a custom sidebar
Clone this wiki locally