Support mariadb slowlog (#9731)

Add support for MariaDB in the Filebeat module for MySQL. slowlog grok pattern is modified to support more versions of this log file and to make it easier to support more in the future. More example files are added to test this. Co-authored-by: Rodrigo Floriano de Souza <rodrigochurrops@gmail.com>
elastic · Jan 18, 2019 · 4140305 · 4140305
1 parent 31fec4f
commit 4140305
Show file tree

Hide file tree

Showing 14 changed files with 369 additions and 7 deletions.
diff --git a/CHANGELOG.next.asciidoc b/CHANGELOG.next.asciidoc
@@ -135,6 +135,7 @@ https://github.com/elastic/beats/compare/v7.0.0-alpha2...master[Check the HEAD d
 - Add support for ssl_request_log in apache2 module. {issue}8088[8088] {pull}9833[9833]
 - Add support for iis 7.5 log format. {issue}9753[9753] {pull}9967[9967]
 - Add service.type field to all Modules. By default the field is set with the module name. It can be overwritten with `service.type` config. {pull}10042[10042]
+- Add support for MariaDB in the `slowlog` fileset of `mysql` module. {pull}9731[9731]
 - Elasticsearch module's slowlog now populates `event.duration` (ECS). {pull}9293[9293]
 - HAProxy module now populates `event.duration` and `http.response.bytes` (ECS). {pull}10143[10143]
 

diff --git a/filebeat/docs/fields.asciidoc b/filebeat/docs/fields.asciidoc
@@ -6409,6 +6409,16 @@ type: long
 The number of rows scanned by the query.
 
 
+--
+
+*`mysql.slowlog.rows_affected`*::
++
+--
+type: long
+
+The number of rows modified by the query.
+
+
 --
 
 *`mysql.slowlog.timestamp`*::
@@ -6434,7 +6444,117 @@ The slow query.
 --
 type: long
 
-The connection ID for the query.
+The connection or thread ID for the query.
+
+
+--
+
+*`mysql.slowlog.schema`*::
++
+--
+type: keyword
+
+The schema where the slow query was executed.
+
+
+--
+
+*`mysql.slowlog.current_user`*::
++
+--
+type: keyword
+
+Current authenticated user, used to determine access privileges. Can differ from the value for user.
+
+
+--
+
+*`mysql.slowlog.query_cache_hit`*::
++
+--
+type: boolean
+
+Whether the query cache was hit.
+
+
+--
+
+*`mysql.slowlog.tmp_table`*::
++
+--
+type: boolean
+
+Whether a temporary table was used to resolve the query.
+
+
+--
+
+*`mysql.slowlog.tmp_table_on_disk`*::
++
+--
+type: boolean
+
+Whether the query needed temporary tables on disk.
+
+
+--
+
+*`mysql.slowlog.filesort`*::
++
+--
+type: boolean
+
+Whether filesort optimization was used.
+
+
+--
+
+*`mysql.slowlog.filesort_on_disk`*::
++
+--
+type: boolean
+
+Whether filesort optimization was used and it needed temporary tables on disk.
+
+
+--
+
+*`mysql.slowlog.priority_queue`*::
++
+--
+type: boolean
+
+Whether a priority queue was used for filesort.
+
+
+--
+
+*`mysql.slowlog.full_scan`*::
++
+--
+type: boolean
+
+Whether a full table scan was needed for the slow query.
+
+
+--
+
+*`mysql.slowlog.full_join`*::
++
+--
+type: boolean
+
+Whether a full join was needed for the slow query (no indexes were used for joins).
+
+
+--
+
+*`mysql.slowlog.merge_passes`*::
++
+--
+type: long
+
+Number of merge passes executed for the query.
 
 
 --

diff --git a/filebeat/docs/modules/mysql.asciidoc b/filebeat/docs/modules/mysql.asciidoc
@@ -16,7 +16,8 @@ include::../include/what-happens.asciidoc[]
 [float]
 === Compatibility
 
-The  +{modulename}+ module was tested with logs from versions 5.5 and 5.7.
+The  +{modulename}+ module was tested with logs from MySQL 5.5 and 5.7 and
+MariaDB 10.1 and 10.2.
 
 On Windows, the module was tested with MySQL installed from the Chocolatey
 repository.

diff --git a/filebeat/module/mysql/_meta/docs.asciidoc b/filebeat/module/mysql/_meta/docs.asciidoc
@@ -11,7 +11,8 @@ include::../include/what-happens.asciidoc[]
 [float]
 === Compatibility
 
-The  +{modulename}+ module was tested with logs from versions 5.5 and 5.7.
+The  +{modulename}+ module was tested with logs from MySQL 5.5 and 5.7 and
+MariaDB 10.1 and 10.2.
 
 On Windows, the module was tested with MySQL installed from the Chocolatey
 repository.

diff --git a/filebeat/module/mysql/fields.go b/filebeat/module/mysql/fields.go
diff --git a/filebeat/module/mysql/slowlog/_meta/fields.yml b/filebeat/module/mysql/slowlog/_meta/fields.yml
@@ -20,6 +20,10 @@
       type: long
       description: >
         The number of rows scanned by the query.
+    - name: rows_affected
+      type: long
+      description: >
+        The number of rows modified by the query.
     - name: timestamp
       type: long
       description: >
@@ -30,7 +34,52 @@
     - name: id
       type: long
       description: >
-        The connection ID for the query.
+        The connection or thread ID for the query.
+    - name: schema
+      type: keyword
+      description: >
+        The schema where the slow query was executed.
+    - name: current_user
+      type: keyword
+      description: >
+        Current authenticated user, used to determine access privileges. Can differ from the value for user.
+
+    - name: query_cache_hit
+      type: boolean
+      description: >
+        Whether the query cache was hit.
+    - name: tmp_table
+      type: boolean
+      description: >
+        Whether a temporary table was used to resolve the query.
+    - name: tmp_table_on_disk
+      type: boolean
+      description: >
+        Whether the query needed temporary tables on disk.
+    - name: filesort
+      type: boolean
+      description: >
+        Whether filesort optimization was used.
+    - name: filesort_on_disk
+      type: boolean
+      description: >
+        Whether filesort optimization was used and it needed temporary tables on disk.
+    - name: priority_queue
+      type: boolean
+      description: >
+        Whether a priority queue was used for filesort.
+    - name: full_scan
+      type: boolean
+      description: >
+        Whether a full table scan was needed for the slow query.
+    - name: full_join
+      type: boolean
+      description: >
+        Whether a full join was needed for the slow query (no indexes were used for joins).
+    - name: merge_passes
+      type: long
+      description: >
+        Number of merge passes executed for the query.
 
     - name: user
       type: alias

diff --git a/filebeat/module/mysql/slowlog/ingest/pipeline.json b/filebeat/module/mysql/slowlog/ingest/pipeline.json
@@ -4,17 +4,40 @@
     "grok": {
       "field": "message",
       "patterns":[
-        "^# User@Host: %{USER:user.name}(\\[[^\\]]+\\])? @ (%{HOSTNAME:source.domain})? \\[(%{IP:source.ip})?\\](\\s*Id:\\s* %{NUMBER:mysql.slowlog.id:long})?\n# Query_time: %{NUMBER:mysql.slowlog.query_time.sec:float}\\s* Lock_time: %{NUMBER:mysql.slowlog.lock_time.sec:float}\\s* Rows_sent: %{NUMBER:mysql.slowlog.rows_sent:long}\\s* Rows_examined: %{NUMBER:mysql.slowlog.rows_examined:long}\n(SET timestamp=%{NUMBER:mysql.slowlog.timestamp:long};\n)?%{GREEDYMULTILINE:mysql.slowlog.query}"
+        "^# User@Host: %{USER:user.name}(\\[%{USER:mysql.slowlog.current_user}\\])? @ %{HOSTNAME:source.domain}? \\[%{IP:source.ip}?\\](\\s*Id:\\s* %{NUMBER:mysql.slowlog.id:long})?\n(# Thread_id:%{SPACE}%{NUMBER:mysql.slowlog.id}%{METRICSPACE}Schema: %{WORD:mysql.slowlog.schema}?%{METRICSPACE}QC_hit: %{WORD:mysql.slowlog.query_cache_hit}\n)?%{METRICSPACE}Query_time: %{NUMBER:mysql.slowlog.query_time.sec:float}%{METRICSPACE}Lock_time: %{NUMBER:mysql.slowlog.lock_time.sec:float}%{METRICSPACE}Rows_sent: %{NUMBER:mysql.slowlog.rows_sent:long}%{METRICSPACE}Rows_examined: %{NUMBER:mysql.slowlog.rows_examined:long}%{METRICSPACE}(Rows_affected: %{NUMBER:mysql.slowlog.rows_affected:long}%{METRICSPACE})?(Full_scan: %{WORD:mysql.slowlog.full_scan}%{METRICSPACE})?(Full_join: %{WORD:mysql.slowlog.full_join}%{METRICSPACE})?(Tmp_table: %{WORD:mysql.slowlog.tmp_table}%{METRICSPACE})?(Tmp_table_on_disk: %{WORD:mysql.slowlog.tmp_table_on_disk}%{METRICSPACE})?(Filesort: %{WORD:mysql.slowlog.filesort}%{METRICSPACE})?(Filesort_on_disk: %{WORD:mysql.slowlog.filesort_on_disk}%{METRICSPACE})?(Merge_passes: %{NUMBER:mysql.slowlog.merge_passes}%{METRICSPACE})?(Priority_queue: %{WORD:mysql.slowlog.priority_queue}%{METRICSPACE})?%{EXPLAIN}?(use %{WORD:mysql.slowlog.schema};\n)?SET timestamp=%{NUMBER:mysql.slowlog.timestamp:long};\n%{GREEDYMULTILINE:mysql.slowlog.query}"
         ],
       "pattern_definitions" : {
-        "GREEDYMULTILINE" : "(.|\n)*"
+        "GREEDYMULTILINE": "(.|\n)*",
+        "METRICSPACE": "([ #\n]*)",
+        "EXPLAIN": "(# explain:.*\n|#\\s*\n)*"
       },
       "ignore_missing": true
     }
   }, {
     "remove":{
       "field": "message"
     }
+  }, {
+    "script": {
+      "lang": "painless",
+      "source": "for (field in params.fields) { def v = ctx.mysql.slowlog.get(field); if (v != null) { ctx.mysql.slowlog.put(field, params.mapping.get(v)) } }",
+      "params": {
+         "mapping": {
+           "Yes": true,
+           "No": false
+         },
+         "fields": [
+           "query_cache_hit",
+           "tmp_table",
+           "tmp_table_on_disk",
+           "filesort",
+           "filesort_on_disk",
+           "priority_queue",
+           "full_scan",
+           "full_join"
+         ]
+      }
+    }
   }, {
     "script":{
       "lang": "painless",

diff --git a/filebeat/module/mysql/slowlog/test/mariadb-10.1.21.log b/filebeat/module/mysql/slowlog/test/mariadb-10.1.21.log
@@ -0,0 +1,6 @@
+# Time: 180613 11:04:36
+# User@Host: root[root] @ localhost [121.0.0.1]
+# Thread_id: 5  Schema:   QC_hit: No
+# Query_time: 2.000652  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
+SET timestamp=1528898676;
+select sleep(2);
diff --git a/filebeat/module/mysql/slowlog/test/mariadb-10.1.21.log-expected.json b/filebeat/module/mysql/slowlog/test/mariadb-10.1.21.log-expected.json
@@ -0,0 +1,28 @@
+[
+    {
+        "@timestamp": "2018-06-13T14:04:36.000Z",
+        "ecs.version": "1.0.0-beta2",
+        "event.dataset": "mysql.slowlog",
+        "event.duration": 2000652000,
+        "event.module": "mysql",
+        "fileset.name": "slowlog",
+        "input.type": "log",
+        "log.flags": [
+            "multiline"
+        ],
+        "log.offset": 24,
+        "mysql.slowlog.current_user": "root",
+        "mysql.slowlog.id": "5",
+        "mysql.slowlog.lock_time.sec": 0.0,
+        "mysql.slowlog.query": "select sleep(2);",
+        "mysql.slowlog.query_cache_hit": false,
+        "mysql.slowlog.query_time.sec": 2.000652,
+        "mysql.slowlog.rows_examined": 0,
+        "mysql.slowlog.rows_sent": 1,
+        "mysql.slowlog.timestamp": 1528898676,
+        "service.type": "mysql",
+        "source.domain": "localhost",
+        "source.ip": "121.0.0.1",
+        "user.name": "root"
+    }
+]
diff --git a/filebeat/module/mysql/slowlog/test/mariadb-10.2.12.log b/filebeat/module/mysql/slowlog/test/mariadb-10.2.12.log
@@ -0,0 +1,23 @@
+mysqld, Version: 10.2.12-MariaDB-10.2.12+maria~jessie-log (mariadb.org binary distribution). started with:
+Tcp port: 0  Unix socket: /var/run/mysqld/mysqld.sock
+Time                 Id Command    Argument
+mysqld, Version: 10.2.12-MariaDB-10.2.12+maria~jessie-log (mariadb.org binary distribution). started with:
+Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
+Time                 Id Command    Argument
+# Time: 190117 16:04:03
+# User@Host: root[root] @ localhost []
+# Thread_id: 8  Schema:   QC_hit: No
+# Query_time: 2.000227  Lock_time: 0.000000  Rows_sent: 1  Rows_examined: 0
+# Rows_affected: 0
+SET timestamp=1547741043;
+select sleep(2)
+AS foo;
+# Time: 190117 16:04:18
+# User@Host: root[root] @  [192.168.0.10]
+# Thread_id: 25844  Schema: blah  QC_hit: No
+# Query_time: 178.306017  Lock_time: 0.000000  Rows_sent: 0  Rows_examined: 53022772
+# Rows_affected: 3062
+# Full_scan: Yes  Full_join: No  Tmp_table: Yes  Tmp_table_on_disk: No
+# Filesort: Yes  Filesort_on_disk: No  Merge_passes: 0  Priority_queue: No
+SET timestamp=1547741058;
+call PROC('blah');