Bug #46679 setting @@global.log_queries_not_using_indexes=1 does not log queries
Submitted: 12 Aug 2009 18:08 Modified: 19 May 2011 4:30
Reporter: N P Email Updates:
Status: Not a Bug Impact on me:
None 
Category:MySQL Server: Logging Severity:S3 (Non-critical)
Version:5.0.27, 5.0, 5.1, azalea bzr OS:Any
Assigned to: Tatiana Azundris Nuernberg CPU Architecture:Any
Tags: log_queries_not_using_indexes
Triage: Triaged: D3 (Medium)

[12 Aug 2009 18:08] N P
Description:
We have:  slow query log enabled with the following:

log-slow=/mysql/admin/db/log/db.log
long-query = 15

We tried to change below server variable: log_queries_not_using_indexes for additional logging.

mysql> show global variables like 'log_queries_not_using_indexes';
------------------------------------------
|  Vairable_name                 |  Value |
-------------------------------------------
|  log-queries_not_using_indexes | OFF |
------------------------------------------

mysql> set @@global.log_queries_not_using_indexes = 1;

------------------------------------------
|  Vairable_name                 |  Value |
-------------------------------------------
|  log-queries_not_using_indexes | ON |
------------------------------------------

1.  mysql> create table t1(id int);
2.  insert into t1 values (1);
3.  select * from t1;

Note:  the query in #3 does not show up in the slow-query log.

How to repeat:
see description

Suggested fix:
n/a
[12 Aug 2009 22:02] Sveta Smirnova
Thank you for the report.

According to http://dev.mysql.com/doc/refman/5.0/en/server-options.html#option_mysqld_log-queries-not-u...:

If you are using this option with the slow query log enabled, queries that are expected to retrieve all rows are logged. See Section 5.2.4, “The Slow Query Log”. This option does not necessarily mean that no index is used.

So this option does not promise to log queries which don't use indexes if no index in the table. But you are right, this is not very clear from documentation, so report is verified as documentation bug.
[13 Aug 2009 13:16] N P
I am still not clear, when we tried to set this variable "GLOBALLY" instead of in the my.cnf file, it did not take effect, however, same parameter takes effect if the MySQL version is 5.1.32.
[13 Aug 2009 13:52] N P
>>
So this option does not promise to log queries which don't use indexes if no index in the table. 
>>

When setting this on 5.1 version, it does log queries if the table does not have an index.

What is the correct behavior of this parameter?
[13 Aug 2009 19:00] Sveta Smirnova
Thank you for the feedback.

According to your feedback and internal discussion set category to "Logging" although I have not this query logged even in version 5.1 or azalea:

=====mysql-azalea=====
=====bug46679=====
create table t1(id int);
insert into t1 values (1);
select * from t1;
id
1
/Users/apple/bzr/mysql-azalea/sql/mysqld, Version: 5.4.4-alpha-debug-log (Source distribution). started with:
Tcp port: 13000  Unix socket: /Users/apple/bzr/mysql-azalea/mysql-test/var/tmp/mysqld.1.sock
Time                 Id Command    Argument
# Time: 090813 21:57:51
# User@Host: root[root] @ localhost []
# Query_time: 0.032294  Lock_time: 0.031458 Rows_sent: 539  Rows_examined: 1074
SET timestamp=1250189871;
call mtr.check_testcase();

Test for the testsuite:

create table t1(id int);
insert into t1 values (1);
select * from t1;

--let $MYSQLD_DATADIR=`select @@datadir`
--exec cat $MYSQLD_DATADIR/../mysqld-slow.log
[14 Aug 2009 3:48] Paul Dubois
Unassigning from myself.
[14 Aug 2009 13:09] N P
I guess the question was, why does the parameter work when set dynamically on version 5.1 and does not work on version 5.0?
[14 Aug 2009 13:09] N P
-is that the intended behavior?
[17 Aug 2009 22:49] Omer Barnir
Addressed in 5.1
[18 Aug 2009 7:50] Sveta Smirnova
Omer, why this issue is 5.0 only? Queries to tables which have not indexes are not logged in all trees.
[18 Aug 2009 7:51] Sveta Smirnova
Main problem is not dynamic or static variable, but query not logged independently where you specified option log-queries-not-using-indexes
[20 Aug 2009 19:31] Omer Barnir
Hi Sveta,

This bug as reported by 'N P' is about the variable and as such it is a 5.0 issue only. As it is fixed in 5.1 and has a workaround (use the cnf file) it was set to 'Won't Fix'.

For the logging bug - you mentioned - it should be opened as a separate bug.

Thanks
[20 Aug 2009 19:38] Peter Laursen
My God, what formalism!

So 'formalistic correct description in report synopisis' is more important than fixing bugs with the server I understand!  What about simply changing the synopsis to reflect the *real* issue here?
[20 Aug 2009 21:13] Sveta Smirnova
Omer,

in the initial description N P writes:

> We tried to change below server variable: log_queries_not_using_indexes *for additional
logging.*
...
> Note:  the query in #3 does not show up in the slow-query log.

Name of this bug is "setting @@global.log_queries_not_using_indexes=1 *does not log queries*"

Where did you read N P complains about if this variable can be set dinamically or not?

N P, please confirm or reject this bug report is about queries are not logged and not about variable behavior.
[20 Aug 2009 22:57] Omer Barnir
The way I see it there are *two* issues here
 - The scenario reported by 'N P' that relates to the variable behaving 
   differently in 5.0 and 5.1
 - The scenario mentioned by Sveta that seems to not work in either 5.0 and 5.1

Two problems - need to have two bugs - this is not a matter of formalism.
[20 Aug 2009 23:01] Peter Laursen
Could I propose then, that you create one more and update both with information about what issues are considered in each?

Not impressive!
[21 Aug 2009 13:17] Omer Barnir
My comment above was simply to clarify why this is not a matter of "formalistic correct description in report synopisis" as suggested. 
It was not intended to impress anyone.
[22 Aug 2009 11:40] Peter Laursen
I did not imply you were trying to impress anyone (and you definitely don't!).  But as a QA team member I would expect that you act *proactively* to improve the quality of MySQL products.

What has been identified here in my understanding is

1) problems with dynamically setting 'queries_not_using_indexes' on specific server versions for slow log.  That is a marked as a 'Wont fix'. OK so far.

2) setting 'queries_not_using_indexes' works inconsistently across server versions with tables having no indexes. The behaviour is not documented (nad is probably a bug).

But instead of acting *proactively* to get things described, verified and fixed you just lean back and wait for somebody else to satisfy your formalistic requirements.

It very much looks like the QA system at Sun/MySQL needs a review!
[24 Aug 2009 14:23] Omer Barnir
Peter, Thanks for your feedback.

Unfortunately, your knowledge about my specific job description and responsibilities are a bit off.
[24 Aug 2009 14:33] Peter Laursen
So 'specific job description's and a 'requirement for 2 reports' simply deadlocks here? Nobody can do progress because it is not their 'specific job description' to do what is required - such as create one more report? And nobody can go ahead with this unless there are 2 reports.

Everybody seems to be waiting for everybody else to do something .. and as a consequence nobody will ever do anything! 

This is not a matter of 'specific job description' but only plain common sense and a matter of proactive attitude. If not I cannot understand!
[24 Aug 2009 17:04] Omer Barnir
Peter,
The bug is not in 'deadlock' and no one is just 'waiting for others".

We are working to understand with the reporter exactly what the issue is. Until we will get clarifications the bug is in 'Verified' state.
When we have the information the bug will be updated accordingly.
[24 Aug 2009 20:47] Sveta Smirnova
In another internal discussion we agreed about main problem is not dynamic or static variable, but query not logged independently where you specified option log-queries-not-using-indexes.

So this is logging problem, not variable behavior.
[19 May 2011 4:30] Tatiana Azundris Nuernberg
Thank you for taking the time to write to us, but this is not a bug.

Table in example has 1 row. This makes it, in the parlance of our times, a "constant"; it would not benefit from an index. As this behavior might be considered slightly surprising, it has been documented in 2005 for Bug#7939

http://bugs.mysql.com/bug.php?id=7939

so the documentation at

http://dev.mysql.com/doc/mysql/en/slow-query-log.html

now explicitly points out that this is expected behavior:

"Queries handled by the query cache are not added to the slow query log, nor are queries that would not benefit from the presence of an index because the table has zero rows or one row."

This works as expected in 5.0.94 and 5.1.58.