Small query performance analysis / Pequena an�lise de performance de querys

This article is written in English and Portuguese
Este artigo est� escrito em Ingl�s e Portugu�s

English version:

The need...

The end of the year is typically a critical time for IT people. Following up on last article's I'm still working with performance issues. "Performance issues on Informix?!" I hear you say... Well yes, but to give you an idea of the kind of system I'm talking about I can say that recently we noticed three small tables (between 3 and 60 rows) that between mid-night and 11AM were scanned 33M times. To save you the math, that's around 833 scans/queries for each of these tables per second. And this started to happen recently, on top of the normal load that nearly 3000 sessions can generate...
So, the point is: every bit of performance matters. And in most cases, on this system there are no long running queries. It's mostly very short requests made an incredible number of times. And yes, this makes the DBA life harder... If you have long running queries with bad query plans they're usually easy to spot. But if you have a large number of very quick queries, but with questionable query plans, than it's much more difficult to find.

Just recently I had one of this situations. I've found a query with a questionable query plan. The query plan varies with the arguments and both possible options have immediate response times (fraction of a second). That's not the first time I've found something similar, and most of the times I face the same situation twice I usually decide I need to have some tool to help me on that.

The idea!

The purpose was to see the difference in the work the engine does between two query plans. And when I say "tool" I'm thinking about a script. Last time I remember having this situation, I used a trick in dbaccess to obtain the performance counters for both the session, and the tables involved. Some of you probably know, others may not, but when dbaccess parses an SQL script file it can recognize a line starting with "!" as an instruction to execute the rest of the line as a SHELL command. So basically what I did previously was to customize the SQL script containing the query like this:

!onstat -z
SELECT .... FROM .... WHERE ...
!some_shell_scritpt

where some_shell_script had the ability to find the session and run an onstat -g tpf and also an onstat -g ppf. These two onstat commands show us a lot of performance counters respectively from the threads (tpf) and from the partitions (ppf). The output looks like:


IBM Informix Dynamic Server Version 11.70.UC4 -- On-Line -- Up 7 days 23:42:15 -- 411500 Kbytes

Thread profiles
tid lkreqs lkw dl to lgrs isrd iswr isrw isdl isct isrb lx bfr bfw lsus lsmx seq
24 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
26 0 0 0 0 0 0 0 0 0 0 0 0 95 95 0 0 0
51 32917 0 0 0 21101 13060 3512 57 532 3795 0 0 91215 29964 0 125008 4226
52 39036 0 0 0 9099 11356 2648 80 1372 265 0 0 45549 9312 0 244900 21
49 705 0 0 0 574 8938 0 139 0 139 0 0 22252 148 0 5656 541
2444 706 0 0 0 14 344 0 4 0 0 3 0 819 7 136 224 0

This tells us the thread Id, lock requests, lock waits, deadlocks, timeouts, logical log records, isam calls (read, write, rewrite, delete, commit and rollback), long transactions, buffer reads and writes, logical log space used, logical log space maximum and sequential scans.
And this:

panther@pacman.onlinedomus.com:informix-> onstat -g ppf | grep -v "0     0     0     0     0     0     0     0     0     0     0     0"

IBM Informix Dynamic Server Version 11.70.UC4 -- On-Line -- Up 7 days 23:43:41 -- 411500 Kbytes

Partition profiles
partnum lkrqs lkwts dlks touts isrd iswrt isrwt isdel bfrd bfwrt seqsc rhitratio
0x100001 0 0 0 0 0 0 0 0 13697 0 0 100
0x100002 993 0 0 0 445 0 0 0 1460 0 2 100
0x10002d 6769 0 0 0 2379 34 340 34 9094 581 2 100
0x10002e 164 0 0 0 166 0 0 0 472 0 2 100
0x10002f 2122 0 0 0 2750 0 0 0 5288 0 0 100
0x100030 0 0 0 0 4 0 0 0 700 0 4 100
0x100034 14192 0 0 0 5922 192 80 192 15566 1274 0 100
0x100035 2260 0 0 0 188 80 0 80 2766 655 4 100
0x100036 1350 0 0 0 548 34 0 34 1872 249 0 100
0x100037 80 0 0 0 16 4 0 4 346 28 0 100
0x100038 4720 0 0 0 738 360 0 360 3734 1557 0 100

which tells us some of the above, but for each partition.
Note that I reset the counters, run the query and then obtain the profile counters. Ideally, nothing else should be running on the instance (better to do it on a test instance)

Sharing it

But I decided to make this a bit easier and I created a script for doing it. I'm also using this article to announce that starting today, I'll try to keep my collection of scripts on a publicly available site:

http://onlinedomus.com/informix/viewvc.cgi

This repository contains a reasonable amount of scripts for several purposes. Ideally I should create proper documentation and use cases for each one of them, but I currently don't have that. It's possible I'll cover some of them here in the blog, but probably only integrated in a wider article (like this one).

These scripts were created by me (with one exception - setinfx was created by Eric Vercelleto when we were colleagues in Informix Portugal and we should thank him for allowing the distribution), during my free time and should all contain license info (GPL 2.0). This means you can use them, copy them, change them etc. Some of them are very old and may not contain this info.
Some fixes and improvements were done during project engagements. Many of them were based on ideas I got from some scripts available in IIUG's software repository or from colleagues ideas, problems and suggestions (Thanks specially to Ant�nio Lima and Adelino Silva)

It's important to notice that the scripts are available "as-is", no guarantees are made and I cannot be held responsible for any problem that it's use may cause.
Having said that, I've been using most of them on several customers for years without problems.
Any comments and/or suggestions are very welcome, and if I find the suggestions interesting and they don't break the script's ideas and usage, I'll be glad to incorporate them on future versions.

Many of the scripts have two option switches that provide basic help (-h) and version info (-V).
If by any chance you are using any of these scripts I suggest you check the site periodically to find any updates. I try my best to maintain retro-compatibility and old behavior when I make changes on them.

Back to the problem

So, this article focus on analyzing and comparing the effects of running a query with two (or more) different query plans. The script created for this was ixprofiling. If you run it with -h (help) option it will print:


panther@pacman.onlinedomus.com:fnunes-> ./ixprofiling -h
ixprofiling [ -h | -V ]
-s SID database
[-z|-Z|-n] database sql_script
-h : Get this help
-V : Get script version
-s SID database: Get stats for session (SID) and database
-n : Do NOT reset engine stats
-z : Reset engine stats using onstat (default - needs local database)
-Z : Reset engine stats using SQL Admin API (can work remotely )

Let's see what the options do:
  • -s SID database
    Shows the info similar to onstat -g tpf (for the specified session id) and onstat -g ppf (for the specified database)
    It will show information for all the partition objects in the specified database for which any of the profile counters is different from zero. Note that when I write partition, it can be a table, a table's partition or a table's index.
  • database sql_script
    Runs the specified SQL script after making some changes that will (by default) reset the engine profile counters (-z option). See more information about the SQL script below
  • -n
    Prevents the reset of profile counters (if you're not a system database administrator you'll need to specify this to avoid errors)
  • -z
    Resets the profile counters using onstat -z. This is the quickest and most simple way to do it but will need local database access.
  • -Z
    Resets the counters using SQL admin API, so it can be used on remote databases


And now let's see an usage example. The script has some particularities that need to be detailed.
First, since the idea is to compare two or more query plans we can put all the variations inside the SQL script, separating them by a line like:

-- QUERY

when the script finds these lines, it will automatically get the stats (from the previous query) and reset the counters to prepare for the next query. If you use just one query you don't need this, since by default it will reset the counters at the beginning and show the stats at the end.
If you put two or more queries on the script don't forget to end each query with ";" or it will break the functionality.
Let's see a practical example. I have a table with the following structure:

create table ibm_test_case 
(
col1 integer,
col2 smallint not null ,
col3 integer,
col4 integer,
[... irrelevant bits... ]
col13 datetime year to second,
[... more irrelevant bits... ]
);

create index ix_col3_col13 on ibm_test_case (col3,col13) using btree ;
create index ix_col4 on ibm_test_case (col4) using btree ;

and a query like:

select c.col1
from ibm_test_case c
where
c.col3 = 123456789 and
c.col4 = 1234567 and
c.col13 = ( select max ( c2.col13 ) from ibm_test_case c2
where
c2.col3 = c.col3 and
c2.col4 = c.col4
);


The problem is the query plan for the sub-query. It can choose between an index headed by col3 and another on col4. So I create a test_case.sql with:


unload to /dev/null select c.col1
from ibm_test_case c
where
c.col3 = 123456789 and
c.col4 = 1234567 and
c.col13 = ( select max ( c2.col13 ) from ibm_test_case c2
where
c2.col3 = c.col3 and
c2.col4 = c.col4
);

-- QUERY
unload to /dev/null select c.col1
from ibm_test_case c
where
c.col3 = 123456789 and
c.col4 = 1234567 and
c.col13 = ( select --+ INDEX ( c2 ix_col3_col13 )
max ( c2.col13 ) from ibm_test_case c2
where
c2.col3 = c.col3 and
c2.col4 = c.col4
);

Note that on the second query I'm forcing the use of a particular index.
Then we run:

ixprofiling stores test_case.sql


and we get the following output:


Database selected.

Engine statistics RESETed. Query results:

Explain set.


1 row(s) unloaded.


Thread profiles (SID: 2690)
LkReq LkWai DLks TOuts LgRec IsRd IsWrt IsRWr IsDel BfRd BfWrt LgUse LgMax SeqSc Srts DskSr SrtMx Sched CPU Time Name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----------- ------------
5224 0 0 0 0 2611 0 0 0 2646 0 0 0 0 0 0 0 2170 0.051671256 sqlexec

Partitions profiles (Database: stores)
LkReq LkWai DLks TOuts DskRd DskWr IsRd IsWrt IsRWr IsDel BfRd BfWrt SeqSc Object name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ------------------------------------------------------
6 0 0 0 0 0 2 0 0 0 10 0 0 systables
2609 0 0 0 1933 0 2607 0 0 0 2609 0 0 ibm_test_case
1 0 0 0 2 0 1 0 0 0 6 0 0 ibm_test_case#ix_col3_col13
2608 0 0 0 3 0 1 0 0 0 21 0 0 ibm_test_case#ix_col4
Engine statistics RESETed. Query results:

1 row(s) unloaded.


Thread profiles (SID: 2690)
LkReq LkWai DLks TOuts LgRec IsRd IsWrt IsRWr IsDel BfRd BfWrt LgUse LgMax SeqSc Srts DskSr SrtMx Sched CPU Time Name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----------- ------------
17 0 0 0 0 6 0 0 0 31 0 0 0 0 0 0 0 188 0.003161049 sqlexec

Partitions profiles (Database: stores)
LkReq LkWai DLks TOuts DskRd DskWr IsRd IsWrt IsRWr IsDel BfRd BfWrt SeqSc Object name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ------------------------------------------------------
6 0 0 0 0 0 2 0 0 0 10 0 0 systables
4 0 0 0 2 0 1 0 0 0 4 0 0 ibm_test_case
7 0 0 0 0 0 6 0 0 0 17 0 0 ibm_test_case#ix_col3_col13

So, we can now analyze the differences. As you can see the output is more friendly than the output from onstat. On the session section we can see the usual counters, plus the number of times the engine scheduled the thread(s) to run, the CPU time consumed and the name of the threads.
On the tables/partitions section, we can find the partition, table or index name in a friendly nomenclature (instead of the partnum).
As for the comparison, you can spot a big difference. Much more buffer reads and ISAM reads for the first query plan and also a bigger CPU time. Be aware however that for very fast queries the CPU times may show very big variance so don't assume a lower CPU time is always associated with the better query plan. You should repeat the test many times to see the oscillations.
Also note that the meaning of ISAM calls is many times misunderstood. Some people think it's the number of "SELECTs", others the number of rows returned... In reality it's the number of internal functions calls. Some engine settings like BATCHEDREAD_TABLE and BATCHEDREAD_INDEX may influence the number of calls for the same query and query result.

That's all for now. I leave you with the repository and hopefully future articles will focus on some of these scripts. Feel free to use them and send me you suggestions.

Vers�o Portuguesa:


A necessidade...

O fina do ano � tipicamente uma altura critica para os inform�ticos. Continuando no mesmo tema do �ltimo artigo, continuo a trabalhar com problemas de performance. "Problemas de performance em Informix?!" poder�o estar a pensar... Bem, sim, mas para vos dar uma ideia do sistema sobre o qual estou a falar, posso dizer que recentemente not�mos tr�s pequenas tabelas (entre 3 e 60 linhas) que entre a meia-noite e as onze da manh� eram varridas (sequential scan) 33M de vezes. Para poupar nas contas posso j� dizer que d� cerca de 833 scans/queries por segundo para cada uma das tabelas. E isto come�ou a acontecer recentemente sobre a carga "normal" que perto de 3000 sess�es podem criar.
Portanto, a ideia � que cada bocadinho de performance tem impacto. Na maioria dos casos, este sistema n�o tem queries longas. Na maior parte das vezes os problemas s�o pedidos com curta dura��o mas feitos um imenso n�mero de vezes. E sim, isto torna a vida dos DBAs mais dicf�cil... Se tivermos queries longas com maus planos de execu��o s�o normalmente f�ceis de identificar. Mas se tivermos um grande n�mero de queries muito curtas, com um plano de execu��o question�vel, isso � muito mais dif�cil de encontrar.

Ainda recentemente tive uma dessas situa��es. Detectei uma query com um plano de execu��o duvidoso. O plano de execu��o varia com os par�metros usados e ambas as alternativas t�m um tempo de resposta "imediato" (frac��o de segundo). N�o foi a primeira vez que encontrei algo semelhante, e na maioria dos casos em que enfrento uma situa��o duas vezes, normalmente decido que preciso de alguma ferramenta que me ajude no futuro.

A ideia!


O objectivo era evidenciar a diferen�a no trabalho feito pelo motor entre dois planos de execu��o. E quando refiro "ferramenta" estou a pensar num script. A �ltima vez que me lembro de ter tido uma situa��o destas  usei um truque no dbaccess para obter os indicadores de performance tanto para a sess�o como para as tabelas envolvidas.
Alguns de v�s saber�o, outros n�o, mas quando o dbaccess l� um scritpt SQL pode reconhecer uma linha come�ada com "!" como uma instru��o para executar o resto da linha como um comando SHELL. Assim, o que fiz em situa��es anteriores foi alterar o script SQL que continha a query para algo do g�nero:

!onstat -z
SELECT .... FROM .... WHERE ...
!um_shell_scritpt

onde um_shell_script tem a capacidade de encontrar a sess�o e correr um onstat -g tpf e tamb�m um onstat -g ppf. Ests dois comandos mostram-nos uma s�rie de contadores de performance respectivamente da sess�o/thread (tpf) e das parti��es (ppf). O output � semelhante a isto:

IBM Informix Dynamic Server Version 11.70.UC4 -- On-Line -- Up 7 days 23:42:15 -- 411500 Kbytes

Thread profiles
tid lkreqs lkw dl to lgrs isrd iswr isrw isdl isct isrb lx bfr bfw lsus lsmx seq
24 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0 0
26 0 0 0 0 0 0 0 0 0 0 0 0 95 95 0 0 0
51 32917 0 0 0 21101 13060 3512 57 532 3795 0 0 91215 29964 0 125008 4226
52 39036 0 0 0 9099 11356 2648 80 1372 265 0 0 45549 9312 0 244900 21
49 705 0 0 0 574 8938 0 139 0 139 0 0 22252 148 0 5656 541
2444 706 0 0 0 14 344 0 4 0 0 3 0 819 7 136 224 0

�-nos mostrado o ID da thread, n�mero de pedidos de lock, esperas em locks, deadlocks, lock timeouts, chamadas ISAM (leitura, escrita, re-escrita, apagar, commit e rollback), transac��es longas, leituras e escritas de buffers, espa�o usado em logical logs e m�ximo espa�o usado em logical logs e n�mero de sequential scans. E isto:

panther@pacman.onlinedomus.com:informix-> onstat -g ppf | grep -v "0     0     0     0     0     0     0     0     0     0     0     0"

IBM Informix Dynamic Server Version 11.70.UC4 -- On-Line -- Up 7 days 23:43:41 -- 411500 Kbytes

Partition profiles
partnum lkrqs lkwts dlks touts isrd iswrt isrwt isdel bfrd bfwrt seqsc rhitratio
0x100001 0 0 0 0 0 0 0 0 13697 0 0 100
0x100002 993 0 0 0 445 0 0 0 1460 0 2 100
0x10002d 6769 0 0 0 2379 34 340 34 9094 581 2 100
0x10002e 164 0 0 0 166 0 0 0 472 0 2 100
0x10002f 2122 0 0 0 2750 0 0 0 5288 0 0 100
0x100030 0 0 0 0 4 0 0 0 700 0 4 100
0x100034 14192 0 0 0 5922 192 80 192 15566 1274 0 100
0x100035 2260 0 0 0 188 80 0 80 2766 655 4 100
0x100036 1350 0 0 0 548 34 0 34 1872 249 0 100
0x100037 80 0 0 0 16 4 0 4 346 28 0 100
0x100038 4720 0 0 0 738 360 0 360 3734 1557 0 100

que nos mostra alguns dos contadores anteriores, mas por parti��o.
Note-se que re-inicializo os contadores, corro a query e depois obtenho os outputs. Idealmente n�o dever� estar mais nada a correr na inst�ncia (� prefer�vel usar uma inst�ncia de teste).

Partilha


Mas decidi tornar isto um pouco mais f�cil e criei um script para o fazer. Estou tamb�m a usar este artigo para anunciar que a partir de hoje, tentarei manter a minha colec��o de scripts dispon�vel num site p�blico:

http://onlinedomus.com/informix/viewvc.cgi

Este reposit�rio cont�m uma quantidade razo�vel de scripts e outras ferramentas �teis para v�rias tareafas. Idealmente eu deveria criar documenta��o e casos de uso para cada um deles, mas de momento isso n�o est� feito. � poss�vel que v� descrevendo alguns destes scripts em futuros artigos, mas sempre integrados em assuntos mais vastos (como este)

Estes scripts foram criados por mim (com uma excep��o - setinfx foi criado por Eric Vercelletto quando �ramos colegas na Informix Portugal e devemos agradecer-lhe por permitir a distribui��o), durante os meus tempos livres e devem conter informa��o de licenciamento (GPL 2.0). Isto quer dizer que podem ser usados, distribuidos, alterados etc.). Alguns podem n�o ter esta informa��o por serem muito antigos.
Naturalmente algumas correc��es e melhorias foram feitas durante projectos em clientes, sempre que detecto algum erro ou hip�tese de melhoria no seu uso. Muitos deles foram baseados em ideias que obtive de scripts existents no reposit�rio do IIUG, ou de ideias, problemas e sugest�es de colegas (agradecimento especial ao Ant�nio Lima e ao Adelino Silva)

� importante avisar que os scripts s�o disponiblizados "como s�o", sem qualquer tipo de garantia implicita ou explicita e eu n�o posso ser responsabilizado por qualquer problema que advenha do seu uso. Posto isto, conv�m tamb�m dizer que a maioria dos scripts t�m sido usados por mim em clientes ao longo de anos, sem problemas.

Quaisquer coment�rios e/ou sugest�es s�o bem vindas, e se os achar interessantes terei todo o prazer em os incorportar em futuras vers�es (desde que n�o fujam � l�gica e utiliza��o do script)
Muitos destes scripts disponibilizam duas op��es que fornecem ajuda b�sica (-h) e informa��o sobre a vers�o (-V).
Se utilizar algum destes scripts no seu ambiente, sugiro que verifique periodicamente se houve correc��es ou melhorias, consultando o site com alguma regularidade. Sempre que poss�vel evito que novas funcionalidades alterem o comportamento do script.

De volta ao problema

Este artigo foca a an�lise e compara��o dos efeitos de executar uma query com dois (ou mais) planos de execu��o. O script criado para isso chama-se ixprofiling. Se corrido com a op��o -h (help) mostra-nos:

panther@pacman.onlinedomus.com:fnunes-> ./ixprofiling -h
ixprofiling [ -h | -V ]
-s SID database
[-z|-Z|-n] database sql_script
-h : Get this help
-V : Get script version
-s SID database: Get stats for session (SID) and database
-n : Do NOT reset engine stats
-z : Reset engine stats using onstat (default - needs local database)
-Z : Reset engine stats using SQL Admin API (can work remotely )

Vejamos o que fazem as op��es:
  • -s SID base_dados
    Mostra informa��o semelhante ao onstat -g tpf (para a sess�o indicada por SID) e onstat -g ppf (para a base de dados indicada)
    Ir� mostrar informa��o para todas as parti��es na base de dados escolhida, para as quais exista pelo menos um dos contadores com valor diferente de zero. Note-se que quando refiro parti��o estou a referir-me a uma tabela, a um fragmento de tabela fragmentada (ou se preferir particionada) ou a um ind�ce.
  • base_dados script_sql
    Corre o script SQL indicado, fazendo altera��es que ir�o (por omiss�o), re-inicializar os contadores de performance do motor (op��o -z). Veja mais informa��o sobre o script SQL abaixo
  • -n
    Evita a re-inicializa��o dos contadores de performance (se n�o f�r administrador do sistema de base de dados ter� de usar esta op��o para evitar erros)
  • -z
    Faz a re-inicializa��o dos contadores do motor usando o comando onstat -z. Esta � a forma mais simples e r�pida de o fazer, mas requer que a base de dados seja local
  • -Z
    Faz a re-inicializa��o dos contadores utilizando a SQL Admin API, de forma que possa ser feito com bases de dados remotas

E agora vejamos um exemplo de uso. O script tem algumas particularidades que merecem ser datalhadas.
Primeiro e porque a ideia � comparar dois ou mais planos de execu��o, podemos colocar todas as variantes de plano de execu��o  dentro do mesmo script SQL usando uma linha como esta para separar as queries:

-- QUERY

Estas linhas s�o automaticamente substitu�das por comandos que obt�m os contadores actuais (da query anterior) e que re-inicializam os mesmos contadores preparando a execu��o seguinte. Se usar apenas uma query n�o � necess�rio isto, pois por omiss�o a re-inicializa��o dos contadores � feita no in�cio, e ap�s a �ltima query s�o automaticamente mostrados os contadores.
Se colocar duas ou mais queries no script n�o se esque�a de terminar cada uma com ";" ou o script n�o funcionar� como esperado.
Vamos ver um exemplo pr�tico. Tenho uma tabela com a seguinte estrutura:

create table ibm_test_case 
(
col1 integer,
col2 smallint not null ,
col3 integer,
col4 integer,
[... parte irrelevante ... ]
col13 datetime year to second,
[... mais colunas irrelevantes ... ]
);

create index ix_col3_col13 on ibm_test_case (col3,col13) using btree ;
create index ix_col4 on ibm_test_case (col4) using btree ;

e uma query com:

select c.col1
from ibm_test_case c
where
c.col3 = 123456789 and
c.col4 = 1234567 and
c.col13 = ( select max ( c2.col13 ) from ibm_test_case c2
where
c2.col3 = c.col3 and
c2.col4 = c.col4
);


O problem � o plano de execu��o da sub-query. Pode  escolher entre um �ndice come�ado pela coluna col3 e outro pela coluna col4. Por isso crio um ficheiro, caso_teste.sql com:


unload to /dev/null select c.col1
from ibm_test_case c
where
c.col3 = 123456789 and
c.col4 = 1234567 and
c.col13 = ( select max ( c2.col13 ) from ibm_test_case c2
where
c2.col3 = c.col3 and
c2.col4 = c.col4
);

-- QUERY
unload to /dev/null select c.col1
from ibm_test_case c
where
c.col3 = 123456789 and
c.col4 = 1234567 and
c.col13 = ( select --+ INDEX ( c2 ix_col3_col13 )
max ( c2.col13 ) from ibm_test_case c2
where
c2.col3 = c.col3 and
c2.col4 = c.col4
);

Repare  que na segunda query estou a for�ar o uso de um determinado �ndice:
Depois corro:

ixprofiling stores caso_teste.sql


e obtemos o seguinte:


Database selected.

Engine statistics RESETed. Query results:

Explain set.


1 row(s) unloaded.


Thread profiles (SID: 2690)
LkReq LkWai DLks TOuts LgRec IsRd IsWrt IsRWr IsDel BfRd BfWrt LgUse LgMax SeqSc Srts DskSr SrtMx Sched CPU Time Name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----------- ------------
5224 0 0 0 0 2611 0 0 0 2646 0 0 0 0 0 0 0 2170 0.051671256 sqlexec

Partitions profiles (Database: stores)
LkReq LkWai DLks TOuts DskRd DskWr IsRd IsWrt IsRWr IsDel BfRd BfWrt SeqSc Object name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ------------------------------------------------------
6 0 0 0 0 0 2 0 0 0 10 0 0 systables
2609 0 0 0 1933 0 2607 0 0 0 2609 0 0 ibm_test_case
1 0 0 0 2 0 1 0 0 0 6 0 0 ibm_test_case#ix_col3_col13
2608 0 0 0 3 0 1 0 0 0 21 0 0 ibm_test_case#ix_col4
Engine statistics RESETed. Query results:

1 row(s) unloaded.


Thread profiles (SID: 2690)
LkReq LkWai DLks TOuts LgRec IsRd IsWrt IsRWr IsDel BfRd BfWrt LgUse LgMax SeqSc Srts DskSr SrtMx Sched CPU Time Name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----------- ------------
17 0 0 0 0 6 0 0 0 31 0 0 0 0 0 0 0 188 0.003161049 sqlexec

Partitions profiles (Database: stores)
LkReq LkWai DLks TOuts DskRd DskWr IsRd IsWrt IsRWr IsDel BfRd BfWrt SeqSc Object name
----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ----- ------------------------------------------------------
6 0 0 0 0 0 2 0 0 0 10 0 0 systables
4 0 0 0 2 0 1 0 0 0 4 0 0 ibm_test_case
7 0 0 0 0 0 6 0 0 0 17 0 0 ibm_test_case#ix_col3_col13

Ent�o, podemos agora analisar as diferen�as. Como se pode ver o resultado � mais simp�tico que o do onstat. Na sec��o relativa � sess�o, podemos ver os contadores habituais, mais o n�mero de vezes que o motor escalonou a thread para correr, e o tempo de CPU consumido, bem como o nome das threads
Na sec��o destinada �s parti��es podemos encontrar os nomes das tabelas, parti��es ou ind�ces numa nomenclatura f�cil de entender (em vez do partnum).
Sobre a compara��o, podemos ver uma grande diferen�a. Muitos mais leituras de buffers e chamadas ISAM para o primeiro plano de execu��o e tamb�m mais consumo de CPU. Mas aten��o que para queries muito r�pidas os tempos de CPU podem apresentar uma varia��o muito grande. Por isso conv�m n�o assumir imediatamente que um plano de execu��o � melhor porque se v� um tempo de CPU menor na primeira intera��o. Deve repetir-se o teste muitas vezes para se verificar as oscila��es.
Chamo tamb�m a aten��o para o significado das chamadas ISAM. Muitas vezes vejo confus�es sobre este tema. Algumas pessoas pensam que s�o o n�mero de SELECTs (para os ISAM reads), ou que ser�o o n�mero de linhas retornadas... Na realidade � o n�mero de chamadas a fun��es internas. Algumas configura��es do motor como BATCHEDREAD_TABLE e BATCHEDREAD_INDEX podem influenciar o n�mero destas chamadas, para a mesma query e mesmo conjunto de resultados.


� tudo por agora. Deixo-lhe o reposit�rio e a esperan�a que artigos futuros se foquem em alguns destes scripts. Use-os � vontade e envie quaisquer sugest�es.