mysql log_queries_not_using_indexes works wrong?

Question

I have following procedure:

CREATE PROCEDURE getProjectTeams(IN p_idProject INTEGER)
BEGIN
 SELECT idTeam, name, workersCount, confirmersCount, isConfirm 
 FROM Teams JOIN team_project USING (idTeam)
 WHERE idProject = p_idProject;
END $$

And here are CREATE TABLE script for tables Teams and team_project:

CREATE TABLE Teams (
 idTeam INT PRIMARY KEY auto_increment,
 name CHAR(20) NOT NULL UNIQUE,
 isConfirm BOOL DEFAULT 0,
 workersCount SMALLINT DEFAULT 0,
 confirmersCount SMALLINT DEFAULT 0 
) engine = innodb DEFAULT CHARACTER SET=utf8 COLLATE=utf8_polish_ci;

CREATE TABLE team_project (
idTeam INT NOT NULL,
idProject INT NOT NULL,
FOREIGN KEY(idTeam) REFERENCES Teams(idTeam)
    ON DELETE CASCADE
    ON UPDATE CASCADE,
FOREIGN KEY (idProject) REFERENCES Projects(idProject)
    ON DELETE CASCADE
    ON UPDATE CASCADE,
PRIMARY KEY(idTeam, idProject)
) engine = innodb DEFAULT CHARACTER SET=utf8 COLLATE=utf8_polish_ci;

I have few databases with identical schema on the server, but this procedure is being logged only if it is called by one database. Calles done by those othere databases are not being logged. It's not a question of being slow or not slow query (it always takes about 0.0001s). It's about why it is logged as not using indexes. How is that possible?

As Zagor23 suggested I run that EXPLAIN an and here are the results. a) in database where procedure is logged:

| id | select_type | table        | type | possible_keys     | key       | key_len | ref   | rows | Extra                          |
|  1 | SIMPLE      | team_project | ref  | PRIMARY,idProject | idProject | 4       | const |    3 | Using index                    |
|  1 | SIMPLE      | Teams        | ALL  | PRIMARY           | NULL      | NULL    | NULL  |    4 | Using where; Using join buffer |

b) database, where procedure is not logged:

| id | select_type | table        | type   | possible_keys     | key       | key_len | ref                              | rows | Extra       |
|  1 | SIMPLE      | team_project | ref    | PRIMARY,idProject | idProject | 4       | const                            |    1 | Using index |
|  1 | SIMPLE      | Teams        | eq_ref | PRIMARY           | PRIMARY   | 4       | ecovbase.team_project.idTeam |    1 |             |

The fact is - the data are a bit different, but not that much. The GoodDB (the one that is not logging proc) has 11 rows in Teams and 420 rows in team_project, the BadDB - 4 rows in Teams and about 800 in team_project. It doesn't seem like a bid difference. Is there a way to avoid logging that procedure?

Answer 1

Maybe it's not being logged because it uses indexes in those cases. Try running

EXPLAIN SELECT idTeam, name, workersCount, confirmersCount, isConfirm 
FROM Teams JOIN team_project USING (idTeam)
WHERE idProject = p_idProject;

on database where you feel it shouldn't use index and see if it really does. MySql will use index if there is one available and suitable for the query, and if the returning result set is up to about 7-8% of the entire result set.

You say that information_schema is identical, but if the data isn't, that could be a reason for different behavior.

Answer 2

@Zagor23 explains why this can happen. Your tables are probbaly much bigger in this database and you haven't the appropriate indices.

My advice would be to add a UNIQUE index on table team_project, at (idProject, idTeam)

---

After the added EXPLAIN outputs, it seems that in the logged case, MySQL optimizer chooses a plan that doesn't need to use any index from the Team table and just scans that whole (4 rows!) table. Which is most probably faster as the table has only 4 rows.

Now, slow-log has some default settings, if I remember well, that adds in the log any query that doesn't use an index, even if the query takes 0.0001 sec to finish.

You can simply ignore this logging or change the slow-log settings to ignore queries that don't use an index. See the MySQL documenation: The Slow Query Log