Understanding Slow Query Log

2012-09-01 Thread Adarsh Sharma
Hi all,

I am using Mysql Ver 14.14 Distrib 5.1.58 in which i enabled slow query log
by setting below parameters in my.cnf :

log-slow-queries=/usr/local/mysql/slow-query.log
long_query_time=100
log-queries-not-using-indexes

I am assuming from the inf. from the internet that long_query_time is in
seconds , but i see the slow query log ,  there are lots of statements (
queries ) :

# User@Host: user1[user1] @ abc.dd.aa.com [192.112.111.111]
# Query_time: 0.052784  Lock_time: 0.43 Rows_sent: 1  Rows_examined:
141145
SET timestamp=1346409734;
select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
ENTITY_NAME='FETL-ImpressionRC-conversion';
# Time: 120831 10:43:14
# User@Host: user1[user1] @ abc.dd.aa.com [192.112.111.111]
# Query_time: 0.053599  Lock_time: 0.79 Rows_sent: 1  Rows_examined:
141145
SET timestamp=1346409794;
select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
ENTITY_NAME='FETL-click-enhancer-deferred';
# User@Host: user1[user2] @ abc.dd.aa.com [192.112.111.111]
# Query_time: 0.054185  Lock_time: 0.86 Rows_sent: 1  Rows_examined:
141145
SET timestamp=1346409794;
select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
ENTITY_NAME='FETL-ImpressionRC-conversion';
# Time: 120831 10:43:22
# User@Host: user2[user2] @ abc.dd.aa.com [192.112.111.111]
# Query_time: 0.000163  Lock_time: 0.45 Rows_sent: 1  Rows_examined: 13



I don't  understand the query time unit in slow query log because i expect
queries to be logged that takes  100 s. I tested with sleep command for
60s , it doesn't logged in slow query log and when i sleep for 120 s it
logged but i don't why the other queries are logging in slow log.

# Query_time: 120.000259  Lock_time: 0.00 Rows_sent: 1  Rows_examined: 0
SET timestamp=1346443103;
SELECT SLEEP(120);

And also my slow log is increasing and decided to purge thorogh below
command :

cat /dev/null  /var/lib/mysql/slow-queries.log


Anyone any ideas about this.


Thanks


Re: Understanding Slow Query Log

2012-09-01 Thread yoku ts
Hi

Because of that, those queries don't use index.
log-queries-not-using-indexes works even if query time less than
long-query-time.

http://dev.mysql.com/doc/refman/5.5/en/server-options.html#option_mysqld_log-queries-not-using-indexes

regards,

yoku

2012/9/1 Adarsh Sharma eddy.ada...@gmail.com:
 Hi all,

 I am using Mysql Ver 14.14 Distrib 5.1.58 in which i enabled slow query log
 by setting below parameters in my.cnf :

 log-slow-queries=/usr/local/mysql/slow-query.log
 long_query_time=100
 log-queries-not-using-indexes

 I am assuming from the inf. from the internet that long_query_time is in
 seconds , but i see the slow query log ,  there are lots of statements (
 queries ) :

 # User@Host: user1[user1] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.052784  Lock_time: 0.43 Rows_sent: 1  Rows_examined:
 141145
 SET timestamp=1346409734;
 select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
 date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
 ENTITY_NAME='FETL-ImpressionRC-conversion';
 # Time: 120831 10:43:14
 # User@Host: user1[user1] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.053599  Lock_time: 0.79 Rows_sent: 1  Rows_examined:
 141145
 SET timestamp=1346409794;
 select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
 date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
 ENTITY_NAME='FETL-click-enhancer-deferred';
 # User@Host: user1[user2] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.054185  Lock_time: 0.86 Rows_sent: 1  Rows_examined:
 141145
 SET timestamp=1346409794;
 select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
 date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
 ENTITY_NAME='FETL-ImpressionRC-conversion';
 # Time: 120831 10:43:22
 # User@Host: user2[user2] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.000163  Lock_time: 0.45 Rows_sent: 1  Rows_examined: 13



 I don't  understand the query time unit in slow query log because i expect
 queries to be logged that takes  100 s. I tested with sleep command for
 60s , it doesn't logged in slow query log and when i sleep for 120 s it
 logged but i don't why the other queries are logging in slow log.

 # Query_time: 120.000259  Lock_time: 0.00 Rows_sent: 1  Rows_examined: 0
 SET timestamp=1346443103;
 SELECT SLEEP(120);

 And also my slow log is increasing and decided to purge thorogh below
 command :

 cat /dev/null  /var/lib/mysql/slow-queries.log


 Anyone any ideas about this.


 Thanks

-- 
MySQL General Mailing List
For list archives: http://lists.mysql.com/mysql
To unsubscribe:http://lists.mysql.com/mysql



Re: Understanding Slow Query Log

2012-09-01 Thread Suresh Kuna
Disable log-queries-not-using-indexes to log only queries  100 sec.

Just do  /var/lib/mysql/slow-queries.log it will clear the log.

On Sat, Sep 1, 2012 at 12:34 PM, Adarsh Sharma eddy.ada...@gmail.comwrote:

 Hi all,

 I am using Mysql Ver 14.14 Distrib 5.1.58 in which i enabled slow query log
 by setting below parameters in my.cnf :

 log-slow-queries=/usr/local/mysql/slow-query.log
 long_query_time=100
 log-queries-not-using-indexes

 I am assuming from the inf. from the internet that long_query_time is in
 seconds , but i see the slow query log ,  there are lots of statements (
 queries ) :

 # User@Host: user1[user1] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.052784  Lock_time: 0.43 Rows_sent: 1  Rows_examined:
 141145
 SET timestamp=1346409734;
 select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
 date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
 ENTITY_NAME='FETL-ImpressionRC-conversion';
 # Time: 120831 10:43:14
 # User@Host: user1[user1] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.053599  Lock_time: 0.79 Rows_sent: 1  Rows_examined:
 141145
 SET timestamp=1346409794;
 select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
 date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
 ENTITY_NAME='FETL-click-enhancer-deferred';
 # User@Host: user1[user2] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.054185  Lock_time: 0.86 Rows_sent: 1  Rows_examined:
 141145
 SET timestamp=1346409794;
 select count(ENTITY_NAME) from ALERT_EVENTS where EVENT_TIME 
 date_sub(now(),INTERVAL 60 MINUTE) and status=upper('failed') and
 ENTITY_NAME='FETL-ImpressionRC-conversion';
 # Time: 120831 10:43:22
 # User@Host: user2[user2] @ abc.dd.aa.com [192.112.111.111]
 # Query_time: 0.000163  Lock_time: 0.45 Rows_sent: 1  Rows_examined: 13



 I don't  understand the query time unit in slow query log because i expect
 queries to be logged that takes  100 s. I tested with sleep command for
 60s , it doesn't logged in slow query log and when i sleep for 120 s it
 logged but i don't why the other queries are logging in slow log.

 # Query_time: 120.000259  Lock_time: 0.00 Rows_sent: 1  Rows_examined:
 0
 SET timestamp=1346443103;
 SELECT SLEEP(120);

 And also my slow log is increasing and decided to purge thorogh below
 command :

 cat /dev/null  /var/lib/mysql/slow-queries.log


 Anyone any ideas about this.


 Thanks




-- 
Thanks
Suresh Kuna
MySQL DBA