Tag Archives: query plan

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 engi...

Leave a comment Continue Reading →

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 eng...

Leave a comment Continue Reading →

Objective: Performance!

Hi all, This is a message received today from IS management: “Your mission today, should you accept it, is to implement a new table in the database, perform an initial data load with an execution time of less than 10 minutes, and provide the team of developers with a way to best manage the response […]

1 Comment Continue Reading →