Manual:Usage examples

From Pinba.org

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;

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):

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):

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