2

I am trying to parse the mysql slow log with logstash so it's important that the format is consistent. I have noticed that if statements execute at the same time, the line # Time: yymmdd is only logged once (see example below). I looked at the setting mysqld_log-long-format however this setting is deprecated and supposedily the default. I have not enabled the log-short-format option.

Is there any setting that can enforce the Time field to either always show, or always not show? I don't actually need the information since there is also a timestamp, I just need the output to be consistent.

# Time: 150419  6:00:43
# User@Host: web[web] @ localhost []
# Query_time: 7.730519  Lock_time: 0.000070 Rows_sent: 167620  Rows_examined: 167620
SET timestamp=1429416043;
SELECT /*!40001 SQL_NO_CACHE */ * FROM `messages`;
# Time: 150419  6:00:45
# User@Host: web[web] @ localhost []
# Query_time: 3.480173  Lock_time: 0.000101 Rows_sent: 0  Rows_examined: 0
SET timestamp=1429416045;
INSERT INTO user (lastupdated, fk_id, user_id) ..
# User@Host: web[web] @ localhost []
# Query_time: 3.388204  Lock_time: 0.000133 Rows_sent: 0  Rows_examined: 0
SET timestamp=1429416045;
INSERT INTO user (lastupdated, fk_id, user_id) ..

The logstash config I'm using looks like this - see logstash multiline codec 

input { 
  file {
     path => "mysql-slow.log"
     codec => multiline {
        pattern => "^# Time" 
        negate => true
        what => previous
     }
  }
}
Improve this question
4
  • Not hard to keep a running variable in your parser with the current value of time. I guess it depends on what your parser is written in.
    – Philᵀᴹ
    Commented Apr 26, 2015 at 11:38
  • Logstash is mainly using regex - elastic.co/guide/en/logstash/current/…
    – aland
    Commented Apr 26, 2015 at 11:44
  • 1
    @aland Have you tried tutorials like phase2technology.com/blog/… already? The idea is to use the timestamp, and not the time the query was logged.
    – jynus
    Commented Apr 26, 2015 at 11:48
  • @jynus yes I had based my config from that blog and I'm using timestamp for a timestamp, I'm using the line 'Time' as an anchor to mark the start of a new log event - but it seems he has recently edited it so that the pattern is based on the 'User' line rather than 'Time'.
    – aland
    Commented Apr 26, 2015 at 12:18

2 Answers 2

Reset to default
1

A lot of things have changed in the slowlog over the versions. Discover the inconsistencies and code to them!

# Time (and maybe some other things) are specified only when they change.

In 5.7.2 Time will include microseconds. This is one of many syntax changes that have happened over the years -- be careful. Percona and MariaDB also have different things that can show in the SlowLog.

Query time used to be just an integer.

Improve this answer
2
  • Is the format of the slow query log documented for each version?
    – aland
    Commented Apr 26, 2015 at 21:07
  • 1
    Ha ha. Not that I have ever seen. In my previous job, I devised a parser that worked for hundreds of machines, dozens of versions. Every few months, I would need to tweak it for a new change. It was a custom Perl script, based on mysqldumpslow
    – Rick James
    Commented Apr 26, 2015 at 22:10
0

Well this answer doesn't make much sense when I can't add a logstash tag, but I've changed the multiline input codec to anchor each pattern to a # User line as the # Time line is not always present.

I can't find any way to change this setting in MySQL but I'll leave this question open for a while in case it is possible and someone knows.

Improve this answer

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service and acknowledge you have read our privacy policy.

Not the answer you're looking for? Browse other questions tagged or ask your own question.