How to understand the MySQL Slow Query Log

How to understand the MySQL Slow Query Log

root@server#tail -f /var/log/mysql_slow_query.log
# Time: 2017-04-09T20:10:09.472872Z
# User@Host: db_user[db_name] @  [x.x.x.125]
# Query_time: 3.776369  Lock_time: 0.000269 Rows_sent: 0  Rows_examined: 308448
SET timestamp=1491768609;
insert into tempo_table select * from tempo_table_tmp;

Let us understand what each line means:

• The first line shows the time the query was logged. The format is YYMMDD H:M:S. We can see the query above was logged at 2017 April 9th at 20:10 - NOTE: This is server time, which may be different from your local time
• Next, we'll see the MySQL user, database, and hostname/ip address
• The third line shows the total query time, the Lock time, the number of Rows "sent" or returned, and the number of rows examined during the query.
• Below that you'll see SET timestamp=UNIXTIME; < this is the time the query actually happened. It is good to check that you're not looking at a problem that happened months ago if you're trying to figure out why something is slow right now. I'll explain how to turn that into a usable time below
• The final line shows the full query.

To get a human-readable timestamp from the Unix Epoch,

root@server# date -d @1491768609
Mon Apr 10 01:40:09 IST 2017