MySQL Forums
Forum List  »  Performance

slow-query-log
Posted by: harry sheng
Date: October 15, 2018 09:22AM

Environment:

Server version: 5.7.20-log MySQL Community Server (GPL)
Linux sp-177-46 2.6.32-504.8.1.el6.x86_64 #1 SMP Fri Dec 19 12:09:25 EST 2014 x86_64 x86_64 x86_64 GNU/Linux

mysql> show variables like 'slow%';
+---------------------+--------------------------------------+
| Variable_name | Value |
+---------------------+--------------------------------------+
| slow_launch_time | 2 |
| slow_query_log | ON |
| slow_query_log_file | /opt/mysql/mysql/data/mysql-slow.log |
+---------------------+--------------------------------------+

mysql> show variables like 'long%';
+-----------------+-----------+
| Variable_name | Value |
+-----------------+-----------+
| long_query_time | 10.000000 |
+-----------------+-----------+
1 row in set (0.00 sec)


querys in mysql-slow.log:

# Time: 2018-10-15T15:05:00.019949Z
# User@Host: xxxx[xxxx] @ localhost [127.0.0.1] Id: 36
# Query_time: 0.005734 Lock_time: 0.000885 Rows_sent: 48 Rows_examined: 1572
SET timestamp=1539615900;
select monitoredo0_.id as id35_, monitoredo0_.active as active35_, monitoredo0_.alarmActive as alarmAct3_35_, monitoredo0_.cachedSamObject_id as cachedS12_35_, monitoredo0_.createdBy as createdBy35_, monitoredo0_.monitoredByUser as monitore5_35_, monitoredo0_.monitoredObjectId as monitore6_35_, monitoredo0_.monitoredObjectType as monitore7_35_, monitoredo0_.oamTestActive as oamTestA8_35_, monitoredo0_.slaReferenceNumber as slaRefer9_35_, monitoredo0_.tag as tag35_, monitoredo0_.timeCreated as timeCre11_35_, monitoredo0_2_.dateSamExpired as dateSamE1_40_, monitoredo0_2_.serviceId as serviceId40_, monitoredo0_2_.subscriberId as subscrib3_40_, monitoredo0_3_.partOfComposite as partOfCo1_43_, case when monitoredo0_2_.id is not null then 2 when monitoredo0_1_.id is not null then 1 when monitoredo0_3_.id is not null then 3 when monitoredo0_4_.id is not null then 4 when monitoredo0_.id is not null then 0 end as clazz_ from MonitoredObject monitoredo0_ left outer join CompositeMonitoredObject monitoredo0_1_ on monitoredo0_.id=monitoredo0_1_.id left outer join MonitoredService monitoredo0_2_ on monitoredo0_.id=monitoredo0_2_.id left outer join SimpleMonitoredObject monitoredo0_3_ on monitoredo0_.id=monitoredo0_3_.id left outer join MonitoredAlarmObject monitoredo0_4_ on monitoredo0_.id=monitoredo0_4_.id, CachedSamObject cachedsamo1_ where monitoredo0_.cachedSamObject_id=cachedsamo1_.id and monitoredo0_.alarmActive=1 and cachedsamo1_.objectType='service';

# Time: 2018-10-15T15:05:00.695292Z
# User@Host: xxxx[xxxx] @ localhost [127.0.0.1] Id: 36
# Query_time: 0.023212 Lock_time: 0.000171 Rows_sent: 2 Rows_examined: 10563
SET timestamp=1539615900;
select alarmobjec0_.id as id51_, alarmobjec0_.affectedObjectFullName as affected2_51_, alarmobjec0_.alarmClassName as alarmCla3_51_, alarmobjec0_.alarmName as alarmName51_, alarmobjec0_.dateLogged as dateLogged51_, alarmobjec0_.firstTimeDetected as firstTim6_51_, alarmobjec0_.frequency as frequency51_, alarmobjec0_.highestSeverity as highestS8_51_, alarmobjec0_.isServiceAffecting as isServic9_51_, alarmobjec0_.lastTimeCleared as lastTim10_51_, alarmobjec0_.lastTimeDetected as lastTim11_51_, alarmobjec0_.nodeId as nodeId51_, alarmobjec0_.numberOfOccurences as numberO13_51_, alarmobjec0_.objectFullName as objectF14_51_, alarmobjec0_.probableCause as probabl15_51_, alarmobjec0_.processed as processed51_, alarmobjec0_.severity as severity51_, alarmobjec0_.timeLogged as timeLogged51_, alarmobjec0_.type as type51_ from AlarmObjectEntity alarmobjec0_ where alarmobjec0_.lastTimeCleared=0 and (alarmobjec0_.affectedObjectFullName like 'svc-mgr:service-2709%');

# Time: 2018-10-15T15:05:00.791417Z
# User@Host: xxxx[xxxx] @ localhost [127.0.0.1] Id: 36
# Query_time: 0.012545 Lock_time: 0.000371 Rows_sent: 4 Rows_examined: 10567
SET timestamp=1539615900;
select alarmobjec0_.id as id51_, alarmobjec0_.affectedObjectFullName as affected2_51_, alarmobjec0_.alarmClassName as alarmCla3_51_, alarmobjec0_.alarmName as alarmName51_, alarmobjec0_.dateLogged as dateLogged51_, alarmobjec0_.firstTimeDetected as firstTim6_51_, alarmobjec0_.frequency as frequency51_, alarmobjec0_.highestSeverity as highestS8_51_, alarmobjec0_.isServiceAffecting as isServic9_51_, alarmobjec0_.lastTimeCleared as lastTim10_51_, alarmobjec0_.lastTimeDetected as lastTim11_51_, alarmobjec0_.nodeId as nodeId51_, alarmobjec0_.numberOfOccurences as numberO13_51_, alarmobjec0_.objectFullName as objectF14_51_, alarmobjec0_.probableCause as probabl15_51_, alarmobjec0_.processed as processed51_, alarmobjec0_.severity as severity51_, alarmobjec0_.timeLogged as timeLogged51_, alarmobjec0_.type as type51_ from AlarmObjectEntity alarmobjec0_ where alarmobjec0_.processed=0 order by alarmobjec0_.timeLogged;

# Time: 2018-10-15T15:05:01.453702Z
# User@Host: xxxx[xxxx] @ localhost [127.0.0.1] Id: 36
# Query_time: 0.653920 Lock_time: 0.000619 Rows_sent: 77 Rows_examined: 612995
SET timestamp=1539615901;
select alarmoutag0_.id as id37_, alarmoutag0_.affectedObjectOfn as affected3_37_, alarmoutag0_.alarmType as alarmType37_, alarmoutag0_.dateLogged as dateLogged37_, alarmoutag0_.endTime as endTime37_, alarmoutag0_.nodeId as nodeId37_, alarmoutag0_.startTime as startTime37_, alarmoutag0_.alarmName as alarmName37_, alarmoutag0_.probableCause as probabl10_37_, alarmoutag0_.type as type37_ from OutagePeriod alarmoutag0_ where alarmoutag0_.DTYPE='AlarmOutagePeriod' and endtime=9223372036854775807;
~

Question:
If the long-query-time in my.cnf is the query's real time in seconds; what is the query_time in the slow-query log file? What is included in the query_time and what is included in the long-query-time? How to relate them?
My server in the lab has quite reasonable hardware, I do not have much data in my database, and there's only moderate access to the server, but the mysql-slow.log grows very fast. Almost every single SQL statement ever sent from client to server is logged.

Options: ReplyQuote


Subject
Views
Written By
Posted
slow-query-log
959
October 15, 2018 09:22AM


Sorry, you can't reply to this topic. It has been closed.

Content reproduced on this site is the property of the respective copyright holders. It is not reviewed in advance by Oracle and does not necessarily represent the opinion of Oracle or any other party.