Add support to MySQL 8 extra fields in slow log (#11417)

Add test files for MySQL 8, Percona 8 and MariaDB 10.3 to filebeat
mysql module.

Add support for MySQL 8 extra fields in slow log.

Update compatibility notes.

Closes #10257

CHANGELOG.next.asciidoc

@@ -308,6 +308,7 @@ https://github.com/elastic/beats/compare/v7.0.0-alpha2...master[Check the HEAD d
 - Add the `network.community_id` flow identifier to field to the IPTables, Suricata, and Zeek modules. {pull}11005[11005]
 - Add support for loading custom NetFlow and IPFIX field definitions to netflow input. {pull}10945[10945]
 - Added categorization fields for SSH login events in the system/auth fileset. {pull}11334[11334]
+- Add support for MySQL 8.0 slow logs and tests also for Percona 8.0 and MariaDB 10.3. {pull}11417[11417]
 
 *Heartbeat*
 

filebeat/docs/fields.asciidoc

@@ -7273,7 +7273,19 @@ type: long
 
 format: bytes
 
-The size of the query result.
+The number of bytes sent to client.
+
+
+--
+
+*`mysql.slowlog.bytes_received`*::
++
+--
+type: long
+
+format: bytes
+
+The number of bytes received from client.
 
 
 --
@@ -7454,6 +7466,46 @@ type: long
 Number of merge passes executed for the query.
 
 
+--
+
+*`mysql.slowlog.sort_merge_passes`*::
++
+--
+type: long
+
+Number of merge passes that the sort algorithm has had to do.
+
+
+--
+
+*`mysql.slowlog.sort_range_count`*::
++
+--
+type: long
+
+Number of sorts that were done using ranges. 
+
+
+--
+
+*`mysql.slowlog.sort_rows`*::
++
+--
+type: long
+
+Number of sorted rows.
+
+
+--
+
+*`mysql.slowlog.sort_scan_count`*::
++
+--
+type: long
+
+Number of sorts that were done by scanning the table.
+
+
 --
 
 *`mysql.slowlog.log_slow_rate_type`*::
@@ -7474,6 +7526,76 @@ type: keyword
 Slow log rate limit, a value of 100 means that one in a hundred queries or sessions are being logged.
 
 
+--
+
+*`mysql.slowlog.read_first`*::
++
+--
+type: long
+
+The number of times the first entry in an index was read.
+
+
+--
+
+*`mysql.slowlog.read_last`*::
++
+--
+type: long
+
+The number of times the last key in an index was read.
+
+
+--
+
+*`mysql.slowlog.read_key`*::
++
+--
+type: long
+
+The number of requests to read a row based on a key.
+
+
+--
+
+*`mysql.slowlog.read_next`*::
++
+--
+type: long
+
+The number of requests to read the next row in key order.
+
+
+--
+
+*`mysql.slowlog.read_prev`*::
++
+--
+type: long
+
+The number of requests to read the previous row in key order.
+
+
+--
+
+*`mysql.slowlog.read_rnd`*::
++
+--
+type: long
+
+The number of requests to read a row based on a fixed position. 
+
+
+--
+
+*`mysql.slowlog.read_rnd_next`*::
++
+--
+type: long
+
+The number of requests to read the next row in the data file.
+
+
 --
 
 [float]

filebeat/docs/modules/mysql.asciidoc

@@ -16,8 +16,8 @@ include::../include/what-happens.asciidoc[]
 [float]
 === Compatibility
 
-The  +{modulename}+ module was tested with logs from MySQL 5.5 and 5.7,
-MariaDB 10.1 and 10.2, and Percona 5.7.
+The  +{modulename}+ module was tested with logs from MySQL 5.5, 5.7 and 8.0,
+MariaDB 10.1, 10.2 and 10.3, and Percona 5.7 and 8.0.
 
 On Windows, the module was tested with MySQL installed from the Chocolatey
 repository.

filebeat/module/mysql/_meta/docs.asciidoc

@@ -11,8 +11,8 @@ include::../include/what-happens.asciidoc[]
 [float]
 === Compatibility
 
-The  +{modulename}+ module was tested with logs from MySQL 5.5 and 5.7,
-MariaDB 10.1 and 10.2, and Percona 5.7.
+The  +{modulename}+ module was tested with logs from MySQL 5.5, 5.7 and 8.0,
+MariaDB 10.1, 10.2 and 10.3, and Percona 5.7 and 8.0.
 
 On Windows, the module was tested with MySQL installed from the Chocolatey
 repository.

filebeat/module/mysql/error/test/mysql-ubuntu-8.0.15.log

@@ -0,0 +1,12 @@
+2019-03-24T13:44:25.484123Z 0 [System] [MY-013169] [Server] /usr/sbin/mysqld (mysqld 8.0.15) initializing of server in progress as process 1640
+2019-03-24T13:44:27.924508Z 5 [Warning] [MY-010453] [Server] root@localhost is created with an empty password ! Please consider switching off the --initialize-insecure option.
+2019-03-24T13:44:29.065309Z 0 [System] [MY-013170] [Server] /usr/sbin/mysqld (mysqld 8.0.15) initializing of server has completed
+2019-03-24T13:44:31.085670Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.15) starting as process 1688
+2019-03-24T13:44:31.533096Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
+2019-03-24T13:44:31.534587Z 0 [Warning] [MY-011810] [Server] Insecure configuration for --pid-file: Location '/tmp' in the path is accessible to all OS users. Consider choosing a different directory.
+2019-03-24T13:44:31.555406Z 6 [System] [MY-013172] [Server] Received SHUTDOWN from user boot. Shutting down mysqld (Version: 8.0.15).
+2019-03-24T13:44:33.236624Z 0 [System] [MY-010910] [Server] /usr/sbin/mysqld: Shutdown complete (mysqld 8.0.15)  MySQL Community Server - GPL.
+2019-03-24T13:44:34.072713Z 0 [System] [MY-010116] [Server] /usr/sbin/mysqld (mysqld 8.0.15) starting as process 1834
+2019-03-24T13:44:34.406962Z 0 [Warning] [MY-010068] [Server] CA certificate ca.pem is self signed.
+2019-03-24T13:44:34.420123Z 0 [System] [MY-010931] [Server] /usr/sbin/mysqld: ready for connections. Version: '8.0.15'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  MySQL Community Server - GPL.
+2019-03-24T13:44:34.572158Z 0 [System] [MY-011323] [Server] X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060

filebeat/module/mysql/slowlog/_meta/fields.yml

@@ -24,7 +24,12 @@
       type: long
       format: bytes
       description: >
-        The size of the query result.
+        The number of bytes sent to client.
+    - name: bytes_received
+      type: long
+      format: bytes
+      description: >
+        The number of bytes received from client.
     - name: query
       description: >
         The slow query.
@@ -98,6 +103,22 @@
       type: long
       description: >
         Number of merge passes executed for the query.
+    - name: sort_merge_passes
+      type: long
+      description: >
+        Number of merge passes that the sort algorithm has had to do.
+    - name: sort_range_count
+      type: long
+      description: >
+        Number of sorts that were done using ranges. 
+    - name: sort_rows
+      type: long
+      description: >
+        Number of sorted rows.
+    - name: sort_scan_count
+      type: long
+      description: >
+        Number of sorts that were done by scanning the table.
     - name: log_slow_rate_type
       type: keyword
       description: >
@@ -108,6 +129,34 @@
       description: >
         Slow log rate limit, a value of 100 means that one in a hundred queries
         or sessions are being logged.
+    - name: read_first
+      type: long
+      description: >
+        The number of times the first entry in an index was read.
+    - name: read_last
+      type: long
+      description: >
+        The number of times the last key in an index was read.
+    - name: read_key
+      type: long
+      description: >
+        The number of requests to read a row based on a key.
+    - name: read_next
+      type: long
+      description: >
+        The number of requests to read the next row in key order.
+    - name: read_prev
+      type: long
+      description: >
+        The number of requests to read the previous row in key order.
+    - name: read_rnd
+      type: long
+      description: >
+        The number of requests to read a row based on a fixed position. 
+    - name: read_rnd_next
+      type: long
+      description: >
+        The number of requests to read the next row in the data file.
 
     # https://www.percona.com/doc/percona-server/5.7/diagnostics/slow_extended.html
     - name: innodb

filebeat/module/mysql/slowlog/ingest/pipeline.json

@@ -4,7 +4,7 @@
     "grok": {
       "field": "message",
       "patterns":[
-        "^# User@Host: %{USER:user.name}(\\[%{USER:mysql.slowlog.current_user}\\])? @ %{HOSTNAME:source.domain}? \\[%{IP:source.ip}?\\]%{METRICSPACE}(Id:%{SPACE}%{NUMBER:mysql.thread_id:long}%{METRICSPACE})?(Thread_id:%{SPACE}%{NUMBER:mysql.thread_id}%{METRICSPACE})?(Schema:%{SPACE}%{WORD:mysql.slowlog.schema}?%{METRICSPACE})?(Last_errno: %{NUMBER:mysql.slowlog.last_errno:long}%{METRICSPACE})?(Killed: %{NUMBER:mysql.slowlog.killed:long}%{METRICSPACE})?(QC_hit: %{WORD:mysql.slowlog.query_cache_hit}%{METRICSPACE})?(Query_time: %{NUMBER:temp.duration: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})?(Bytes_sent: %{NUMBER:mysql.slowlog.bytes_sent:long}%{METRICSPACE})?(Tmp_tables: %{NUMBER:mysql.slowlog.tmp_tables:long}%{METRICSPACE})?(Tmp_disk_tables: %{NUMBER:mysql.slowlog.tmp_disk_tables}%{METRICSPACE})?(Tmp_table_sizes: %{NUMBER:mysql.slowlog.tmp_table_sizes:long}%{METRICSPACE})?(InnoDB_trx_id: %{WORD:mysql.slowlog.innodb.trx_id}%{METRICSPACE})?(QC_Hit: %{WORD:mysql.slowlog.query_cache_hit}%{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:long}%{METRICSPACE})?(Priority_queue: %{WORD:mysql.slowlog.priority_queue}%{METRICSPACE})?(No InnoDB statistics available for this query%{METRICSPACE})?(InnoDB_IO_r_ops: %{NUMBER:mysql.slowlog.innodb.io_r_ops:long}%{METRICSPACE})?(InnoDB_IO_r_bytes: %{NUMBER:mysql.slowlog.innodb.io_r_bytes:long}%{METRICSPACE})?(InnoDB_IO_r_wait: %{NUMBER:mysql.slowlog.innodb.io_r_wait.sec:float}%{METRICSPACE})?(InnoDB_rec_lock_wait: %{NUMBER:mysql.slowlog.innodb.rec_lock_wait.sec:float}%{METRICSPACE})?(InnoDB_queue_wait: %{NUMBER:mysql.slowlog.innodb.queue_wait.sec:float}%{METRICSPACE})?(InnoDB_pages_distinct: %{NUMBER:mysql.slowlog.innodb.pages_distinct:long}%{METRICSPACE})?(Log_slow_rate_type: %{WORD:mysql.slowlog.log_slow_rate_type}%{METRICSPACE})?(Log_slow_rate_limit: %{NUMBER:mysql.slowlog.log_slow_rate_limit:long}%{METRICSPACE})?%{EXPLAIN}?(use %{WORD:mysql.slowlog.schema};\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}?\\]%{METRICSPACE}(Id:%{SPACE}%{NUMBER:mysql.thread_id:long}%{METRICSPACE})?(Thread_id:%{SPACE}%{NUMBER:mysql.thread_id}%{METRICSPACE})?(Schema:%{SPACE}%{WORD:mysql.slowlog.schema}?%{METRICSPACE})?(Last_errno: %{NUMBER:mysql.slowlog.last_errno:long}%{METRICSPACE})?(Killed: %{NUMBER:mysql.slowlog.killed:long}%{METRICSPACE})?(QC_hit: %{WORD:mysql.slowlog.query_cache_hit}%{METRICSPACE})?(Query_time: %{NUMBER:temp.duration: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})?(Thread_id: %{NUMBER:mysql.thread_id}%{METRICSPACE})?(Errno: %{NUMBER:mysql.slowlog.last_errno:long}%{METRICSPACE})?(Killed: %{NUMBER:mysql.slowlog.killed:long}%{METRICSPACE})?(Bytes_received: %{NUMBER:mysql.slowlog.bytes_received:long}%{METRICSPACE})?(Bytes_sent: %{NUMBER:mysql.slowlog.bytes_sent:long}%{METRICSPACE})?(Read_first: %{NUMBER:mysql.slowlog.read_first:long}%{METRICSPACE})?(Read_last: %{NUMBER:mysql.slowlog.read_last:long}%{METRICSPACE})?(Read_key: %{NUMBER:mysql.slowlog.read_key:long}%{METRICSPACE})?(Read_next: %{NUMBER:mysql.slowlog.read_next:long}%{METRICSPACE})?(Read_prev: %{NUMBER:mysql.slowlog.read_prev:long}%{METRICSPACE})?(Read_rnd: %{NUMBER:mysql.slowlog.read_rnd:long}%{METRICSPACE})?(Read_rnd_next: %{NUMBER:mysql.slowlog.read_rnd_next:long}%{METRICSPACE})?(Sort_merge_passes: %{NUMBER:mysql.slowlog.sort_merge_passes:long}%{METRICSPACE})?(Sort_range_count: %{NUMBER:mysql.slowlog.sort_range_count:long}%{METRICSPACE})?(Sort_rows: %{NUMBER:mysql.slowlog.sort_rows:long}%{METRICSPACE})?(Sort_scan_count: %{NUMBER:mysql.slowlog.sort_scan_count:long}%{METRICSPACE})?(Created_tmp_disk_tables: %{NUMBER:mysql.slowlog.tmp_disk_tables:long}%{METRICSPACE})?(Created_tmp_tables: %{NUMBER:mysql.slowlog.tmp_tables:long}%{METRICSPACE})?(Tmp_tables: %{NUMBER:mysql.slowlog.tmp_tables:long}%{METRICSPACE})?(Tmp_disk_tables: %{NUMBER:mysql.slowlog.tmp_disk_tables}%{METRICSPACE})?(Tmp_table_sizes: %{NUMBER:mysql.slowlog.tmp_table_sizes:long}%{METRICSPACE})?(Start: %{TIMESTAMP_ISO8601:event.start}%{METRICSPACE})?(End: %{TIMESTAMP_ISO8601:event.end}%{METRICSPACE})?(InnoDB_trx_id: %{WORD:mysql.slowlog.innodb.trx_id}%{METRICSPACE})?(QC_Hit: %{WORD:mysql.slowlog.query_cache_hit}%{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:long}%{METRICSPACE})?(Priority_queue: %{WORD:mysql.slowlog.priority_queue}%{METRICSPACE})?(No InnoDB statistics available for this query%{METRICSPACE})?(InnoDB_IO_r_ops: %{NUMBER:mysql.slowlog.innodb.io_r_ops:long}%{METRICSPACE})?(InnoDB_IO_r_bytes: %{NUMBER:mysql.slowlog.innodb.io_r_bytes:long}%{METRICSPACE})?(InnoDB_IO_r_wait: %{NUMBER:mysql.slowlog.innodb.io_r_wait.sec:float}%{METRICSPACE})?(InnoDB_rec_lock_wait: %{NUMBER:mysql.slowlog.innodb.rec_lock_wait.sec:float}%{METRICSPACE})?(InnoDB_queue_wait: %{NUMBER:mysql.slowlog.innodb.queue_wait.sec:float}%{METRICSPACE})?(InnoDB_pages_distinct: %{NUMBER:mysql.slowlog.innodb.pages_distinct:long}%{METRICSPACE})?(Log_slow_rate_type: %{WORD:mysql.slowlog.log_slow_rate_type}%{METRICSPACE})?(Log_slow_rate_limit: %{NUMBER:mysql.slowlog.log_slow_rate_limit:long}%{METRICSPACE})?%{EXPLAIN}?(use %{WORD:mysql.slowlog.schema};\n)?SET timestamp=%{NUMBER:mysql.slowlog.timestamp:long};\n%{GREEDYMULTILINE:mysql.slowlog.query}"
         ],
       "pattern_definitions" : {
         "GREEDYMULTILINE": "(.|\n)*",

filebeat/module/mysql/slowlog/test/mariadb-10.3.13.log

@@ -0,0 +1,18 @@
+/usr/sbin/mysqld, Version: 10.3.13-MariaDB-1:10.3.13+maria~bionic-log (mariadb.org binary distribution). started with:
+Tcp port: 3306  Unix socket: /var/run/mysqld/mysqld.sock
+Time		    Id Command	Argument
+# Time: 190324 16:03:00
+# User@Host: root[root] @ localhost []
+# Thread_id: 37  Schema: employees  QC_hit: No
+# Query_time: 2.461578  Lock_time: 0.000196  Rows_sent: 10  Rows_examined: 3145718
+# Rows_affected: 0  Bytes_sent: 319
+# Tmp_tables: 1  Tmp_disk_tables: 0  Tmp_table_sizes: 4026528
+# 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: Yes
+use employees;
+SET timestamp=1553443380;
+SELECT last_name, MAX(salary) AS salary FROM employees
+    INNER JOIN salaries ON employees.emp_no = salaries.emp_no
+    GROUP BY last_name
+    ORDER BY salary DESC
+    LIMIT 10;