【20180417】ELK日志管理之filebeat收集分析mysql慢日志

环境版本

filebeat: 6.2.3
mysql: 5.6.38

错误信息

{
  "_index": "mysql-slow-2018.04.17",
  "_type": "doc",
  "_id": "AWLRiDqYhjFMCbqrK5ez",
  "_version": 1,
  "_score": null,
  "_source": {
    "@timestamp": "2018-04-17T02:56:22.823Z",
    "offset": 100619865,
    "beat": {
      "hostname": "test-db1",
      "name": "test-db1",
      "version": "6.2.3"
    },
    "prospector": {
      "type": "log"
    },
    "source": "/var/log/mysql_3306/mysql-slow.log",
    "fileset": {
      "module": "mysql",
      "name": "slowlog"
    },
    "message": "# User@Host: test_db[test_table] @  [10.10.10.10]  Id: 1874266\n# Query_time: 2.088465  Lock_time: 0.000086 Rows_sent: 67  Rows_examined: 18862\nSET timestamp=1523933781;\nselect id, dct, mh, topcolor, bit_count(dct^1144174128272565460) as dist from image_feature where topcolor=\"278522176103c518c774fe2a73b20569\" and created_at<\"2018-04-17 10:54:16\" and id not in (120251270,120251181,120251202,120251209,120251221,120251229,120251240,120251252,120251259,120251270,120251278) having dist<=20 order by dist;",
    "error": {
      "message": "Provided Grok expressions do not match field value: [# User@Host: test_db[test_table] @  [10.10.10.10]  Id: 1874266\\n# Query_time: 2.088465  Lock_time: 0.000086 Rows_sent: 67  Rows_examined: 18862\\nSET timestamp=1523933781;\\nselect id, dct, mh, topcolor, bit_count(dct^1144174128272565460) as dist from image_feature where topcolor=\\\"278522176103c518c774fe2a73b20569\\\" and created_at<\\\"2018-04-17 10:54:16\\\" and id not in (120251270,120251181,120251202,120251209,120251221,120251229,120251240,120251252,120251259,120251270,120251278) having dist<=20 order by dist;]"
    }
  },
  "fields": {
    "@timestamp": [
      1523933782823
    ]
  },
  "highlight": {
    "beat.name": [
      "@kibana-highlighted-field@test-db1@/kibana-highlighted-field@"
    ]
  },
  "sort": [
    1523933782823
  ]
}

{
  "_index": "mysql-slow-2018.04.17",
  "_type": "doc",
  "_id": "AWLRb2nl6-SuKroP98i-",
  "_version": 1,
  "_score": null,
  "_source": {
    "@timestamp": "2018-04-17T02:29:21.535Z",
    "offset": 100614853,
    "beat": {
      "hostname": "test-db1",
      "name": "test-db1",
      "version": "6.2.3"
    },
    "prospector": {
      "type": "log"
    },
    "source": "/var/log/mysql_3306/mysql-slow.log",
    "message": "# Time: 180417 10:29:18",
    "fileset": {
      "module": "mysql",
      "name": "slowlog"
    },
    "error": {
      "message": "Provided Grok expressions do not match field value: [# Time: 180417 10:29:18]"
    }
  },
  "fields": {
    "@timestamp": [
      1523932161535
    ]
  },
  "highlight": {
    "error.message": [
      "Provided Grok expressions do not match field value: [# @kibana-highlighted-field@Time@/kibana-highlighted-field@: 180417 10:29:18]"
    ]
  },
  "sort": [
    1523932161535
  ]
}

上面的这些信息可以在Kibana的Discover中可以查询得到。

1. 从上面的JSON信息我们可以很明确的获取得到俩个信息:

   • 一个就是Kibana无法解析MySQL实例的slow日志。
   • 另外一个就是类似 "# Time: 180417 10:26:11"这样子的时间信息也被当作了MySQL的SQL信息发送给Kibana。
2. 其实主要问题就是在于pipeline，

问题解决

1. 修改module/mysql/slowlog/config/slowlog.yml

   修改之前：
   exclude_lines: [‘^[\/\w\.]+, Version: .* started with:.*‘]   # Exclude the header
   修改之后：
   exclude_lines: [‘^[\/\w\.]+, Version: .* started with:.*‘,‘^# Time.*‘]   # Exclude the header

2. 修改module/mysql/slowlog/ingest/pipeline.json

   修改之前：
   "patterns":[
       "^# User@Host: %{USER:mysql.slowlog.user}(\\[[^\\]]+\\])? @ %{HOSTNAME:mysql.slowlog.host} \\[(%{IP:mysql.slowlog.ip})?\\](\\s*Id:\\s* %{NUMBER:mysql.slowlog.id})?\n# Query_time: %{NUMBER:mysql.slowlog.query_time.sec}\\s* Lock_time: %{NUMBER:mysql.slowlog.lock_time.sec}\\s* Rows_sent: %{NUMBER:mysql.slowlog.rows_sent}\\s* Rows_examined: %{NUMBER:mysql.slowlog.rows_examined}\n(SET timestamp=%{NUMBER:mysql.slowlog.timestamp};\n)?%{GREEDYMULTILINE:mysql.slowlog.query}"
               ]
   修改之后：
     "patterns":[
       "^# User@Host: %{USER:mysql.slowlog.user}(\\[[^\\]]+\\])? @ %{HOSTNAME:mysql.slowlog.host} \\[(IP:mysql.slowlog.ip)?\\](\\s*Id:\\s* %{NUMBER:mysql.slowlog.id})?\n# Query_time: %{NUMBER:mysql.slowlog.query_time.sec}\\s* Lock_time: %{NUMBER:mysql.slowlog.lock_time.sec}\\s* Rows_sent: %{NUMBER:mysql.slowlog.rows_sent}\\s* Rows_examined: %{NUMBER:mysql.slowlog.rows_examined}\n(SET timestamp=%{NUMBER:mysql.slowlog.timestamp};\n)?%{GREEDYMULTILINE:mysql.slowlog.query}"
               ],