Profiling

MySQL Simple Query Builder provides profiling [1] automation and status variable [2] collection for a query or series of queries. Specifically what it does is:

  1. Turn off query cache
  2. Fetch status variables before the target queries
  3. Wrap target queries in SET profiling = 1 and SET profiling = 0
  4. Fetch status variables after the target queries and calculate a difference

myquerybuilder.profiler.QueryProfiler only collects profiles and status changes. If you need to profile a method or a query subclass myquerybuilder.test.ProfilerTestCase. It is a subclass of unittest.TestCase and is intended to be used with compatible test runner.

Note

myquerybuilder.profiler.QueryProfiler overrides cursorType with aliases to profilable cursors. Thus if you use non-alias or None type argument for cursor(), the queries won’t be handled.

By default, myquerybuilder.test.ProfilerTestCase prints only non-zero changes in status variables and performance entries which are greater than or equal to 5% of the query total execution time. You can adjust these by changing its skipZeroStatus and durationThreshold attributes, respectively. Also it prints queries, query arguments and their execution plans.

QueryProfiler.groups defines status groups which should be collected. By default it is ('select', 'sort', 'handler', 'created', 'innodb_buffer'). See MySQL server status variable description [3].

Note

MySQL variable profiling_history_size [4] defines the number of statements for which to maintain profiling information if profiling is enabled, which by default is 15. If you need to profile a group of more than 15 queries, you need to increase it.

Example

from myquerybuilder import test, profiler


class TestExample(test.ProfilerTestCase):

  def setUp(self):
    test.ProfilerTestCase.profiler = profiler.QueryProfiler(**config)

    super(TestQueryProfiler, self).setUp()

  @test.ProfilerTestCase.profile
  def testProfile(self):
    sql = '''
      SELECT country_id, city_id,  city
      FROM city
      JOIN country USING(country_id )
      {where}
    '''
    self.profiler.query(sql, {'country': 'Japan'})

The output for this test case looks like this:

********* profile **********
  #1 0.000717 - 100.0%
    starting        0.000072
    sending data    0.000389
    freeing items   0.000075

    *********** plan ***********
      ***************** id:1 *****************
      select_type     SIMPLE
      table           country
      type            ALL
      possible_keys   PRIMARY
      key
      key_len
      ref
      rows            109
      extra           Using where
      ***************** id:1 *****************
      select_type     SIMPLE
      table           city
      type            ref
      possible_keys   idx_fk_country_id
      key             idx_fk_country_id
      key_len         2
      ref             sakila.country.country_id
      rows            3
      extra

    ********** query ***********

      SELECT country_id, city_id,  city
      FROM city
      JOIN country USING(country_id )
      WHERE (`country` = %(country)s)


    ******** arguments *********
    {'country': 'Japan'}


****** status handler ******
  handler_commit                        1.0
  handler_read_first                    1.0
  handler_read_key                      2.0
  handler_read_next                     31.0
  handler_read_rnd_next                 110.0
*** status innodb_buffer ***
  innodb_buffer_pool_read_requests      116.0
****** status select *******
  select_scan                           1.0

For more examples you can look at the profiler test module [5].

[1]http://dev.mysql.com/doc/refman/5.5/en/show-profile.html
[2]http://dev.mysql.com/doc/refman/5.5/en/show-status.html
[3]http://dev.mysql.com/doc/refman/5.5/en/server-status-variables.html
[4]http://dev.mysql.com/doc/refman/5.5/en/server-system-variables.html#sysvar_profiling_history_size
[5]https://bitbucket.org/saaj/mysql-simple-query-builder/src/tip/myquerybuilder/test/profiler.py