Russian Version

Part 1. Single queries.

Chapter 1. Query.

I think most of you know what any difficult problem can be devided into set of easy problems. Same method is applicable to SQL applications.

For first lets see example with easy query. It is elementary to find error in this case.

select * fro t1 where f1 in (1,2,1);

I think most of readers noticed where is the problem. If run this query in mysql cli error become clear:

mysql> select * fro t1 where f1 in (1,2,1);
ERROR 1064 (42000): You have an error in your SQL syntax;
check the manual that corresponds to your MySQL server version
for the right syntax to use near 'fro t1 where f1 in (1,2,1)' at line 1

This means this is syntax error: last letter in predicate from missed. It is easy, isn't it?

Let's take harder example. This is PHP code. (Code was firstly prepared for PHP conference in Moscow. Same style of coding can be made with use of any other programming alnguage.)

$query = 'SELECT * FROM t4 WHERE f1 IN(';
for ($i = 1; $i < 101; $i ++)
$query .= "'row$i,";
$query = rtrim($query, ',');
$query .= ')';
$result = mysql_query($query);

In this case is harder to find error. And what to do with more complicated query?

In case of PHP operator echo, which outputs its operands, will help us:

$query = 'SELECT * FROM t4 WHERE f1 IN(';
for ($i = 1; $i < 101; $i ++)
$query .= "'row$i,";
$query = rtrim($query, ',');
$query .= ')';
echo $query;
//$result = mysql_query($query);

Lets run the script:

$php phpconf2009_1.php
SELECT * FROM t4 WHERE f1 IN('row1,'row2,'row3,'row4,'row5,'row6,'row7,'row8,'row9,'row10,'row11,
'row12,'row13,'row14,'row15,'row16,'row17,'row18,'row19,'row20)

And now we can clearly see the error: closing apostrof is missed

$query .= "'row$i,";

It is enough to replace above code with

$query .= "'row$i',";

and query will be proceed in proper way.

Please pay attention, what we printed query exactly same as RDBMS gets it. It is much more easy to find an error in final query, than in a row, which combined from different parts or contains variables.

Using output operator for finding problem query – easiest, but effective method.

Method #1: use output operator to output query in exactly same way in which RDBMS gets it.

Unfortunately we can not use echo everytime. For example when support complicated application running for years.

Lets examine next example.

There is a problem at web-странице with following interface:

Existent systems

    * System 1
    * Test
    * test2
    * test2
    * test2
    * test2
    * test2

Enter name of new system:

<>

Description:

<>

<Go!>

Problem is we have several systems with same "unique" name.

Let's look in the code:

$system = System::factory()
->setName($this->form->get(Field::NAME))
->setDescription(
$this->form->get(Field::DESCRIPTION)
);
DAO::system()->take($system);

Can you get something? I think experienced person can guess where is the problem, but in any case this is just a hypothesis, which we have to confirm or reject. Even more puzzling is to find place where to add output operator and what to output: we have no database connection information, no query.

In PHP quite easy to change code of library, which is responsible for compilation of a query, so it will print the query to a file or to stderr before to send to RDBMS, but in case of compiling languages, for example Java, you have to recompile the library even if code of the library is open.

But what to do? With MySQL we can use general query log:

mysql> set global log_output='table';
Query OK, 0 rows affected (0.00 sec)

mysql> select * from mysql.general_log;
Empty set (0.09 sec)

mysql> set global general_log='on';
Query OK, 0 rows affected (0.00 sec)

Let's run the application.

mysql> select * from mysql.general_log order by event_time desc limit 25\G
*************************** 1. row ***************************
  event_time: 2009-10-19 13:00:00
   user_host: root[root] @ localhost []
   thread_id: 10323
   server_id: 60
command_type: Query
    argument: select * from mysql.general_log order by event_time desc limit 25
...
*************************** 22. row ***************************
  event_time: 2009-10-19 12:58:20
   user_host: root[root] @ localhost [127.0.0.1]
   thread_id: 10332
   server_id: 60
command_type: Query
    argument: INSERT INTO `system` (`id`, `name`, `description`) VALUES ('', 'test2', '')
...
mysql> set global general_log='off';
Query OK, 0 rows affected (0.08 sec)

In row 22 we can see our query. It doesn't look problematic: regular INSERT.

Let's see what we have in table named system:

mysql> select * from system;
+----+----------+------------------------------------------+
| id | name     | description                              |
+----+----------+------------------------------------------+
|  1 | System 1 | Man and woman clothing construction      |
|  2 | Test     | Testing Geometric set                    |
|  3 | test2    | New test                                 |
|  4 | test2    | foobar                                   |
|  8 | test2    |                                          |
+----+----------+------------------------------------------+
5 rows in set (0.00 sec)

Let's look at its definition:

mysql> show create table system\G
*************************** 1. row ***************************
       Table: system
Create Table: CREATE TABLE `system` (
  `id` int(11) NOT NULL AUTO_INCREMENT,
  `name` varchar(255) NOT NULL,
  `description` tinytext NOT NULL,
  PRIMARY KEY (`id`)
) ENGINE=InnoDB AUTO_INCREMENT=9 DEFAULT CHARSET=utf8
1 row in set (0.09 sec)

field name is not unique. Therefore we have at least 2 ways to solve the problem: make this field unique using query

(alter table system add unique(name))

or change application in such a way what this problem can be handled on not SQL level.

We just learned next method: use general query log for finding a query which causes wrong behavior.

Method #2: use general query log if you need to find which exact query causes wrong behavior of your application.

Please pay attention for following feature of general query log: query goes there right after mysqld gets it, but before started to execute it. Therefore don't expect to see return code or error message there.

We just learned what practically always is possible to find a query which causes a problem in the application. In most cases this is enough for finding and solving the problem. And describes why I devoted for this most part of the text. Of course exist situations when finding single query could not help you. We will examine such situations later.

I'd like to bring your attention for following queries:

mysql> select * from mysql.general_log;
Empty set (0.09 sec)

mysql> set global general_log='on';
Query OK, 0 rows affected (0.00 sec)
...
mysql> set global general_log='off';
Query OK, 0 rows affected (0.08 sec)

Why do we need to change value of global variable if we can turn general query log to ON in the configuration file?

General query log itself costs resources: it increases load for the server and you have to watch disk space as it contains every query sent to the server. But since MySQL version 5.1 you can turn it on/off online decreasing additional load on MySQL server to necessary minimum.

Next query turns output to the table, not to the file. Such output into the table is good for queries similar to described inlast 2 examples, because you can easily sort the table: you can use it in the same way as any other SQL table.

mysql> set global log_output='table';
Query OK, 0 rows affected (0.00 sec)

Back Content Forward  



Author 2010 Sveta Smirnova
COPYRIGHT © 2010 S.Smirnova and S. Lasunov
sveta_at_js-client_dot_com