filebeat/module/mysql: add authentication message parsing and related.ip & related.user fields

CHANGELOG.next.asciidoc

@@ -241,6 +241,7 @@ automatic splitting at root level, if root level element is an array. {pull}3415
 - Improve CEL input documentation {pull}34831[34831]
 - Add metrics documentation for CEL and AWS CloudWatch inputs. {issue}34887[34887] {pull}34889[34889]
 - Register MIME handlers for CSV types in CEL input. {pull}34934[34934]
+- Add MySQL authentication message parsing and `related.ip` and `related.user` fields {pull}34810[34810]
 
 *Auditbeat*
 

filebeat/module/mysql/error/ingest/pipeline.yml

@@ -18,11 +18,17 @@ processors:
 - grok:
     field: message
     patterns:
+    - '(\[%{DATA:event.code}\])%{SPACE}(\[%{DATA:event.provider}\])%{SPACE}%{NOTSPACE}: Forcing close of thread %{INT}  user: ''%{USERNAME:user.name}'''
     - '(\[%{DATA:event.code}\])%{SPACE}(\[%{DATA:event.provider}\])%{SPACE}%{GREEDYMULTILINE}'
+    - "%{ACCESS:_tmp.auth_failed} for user '%{USERNAME:user.name}'(@'%{IP:source.ip}')?"
+    - '%{IP_RESOLVE_ERROR:_tmp.ip_resolve_error}'
+    - "Server socket created on IP: '%{IP:source.ip}'"
     - '%{GREEDYDATA}'
     ignore_missing: true
     ignore_failure: true
     pattern_definitions:
+      ACCESS: "Access denied" 
+      IP_RESOLVE_ERROR: "IP address '%{IP:source.ip}' could not be resolved: Name or service not known"
       GREEDYMULTILINE: |-
         (.|
         )+
@@ -51,9 +57,6 @@ processors:
     field: _tmp.timestamp
     formats:
     - ISO8601
-- remove:
-    field: _tmp
-    ignore_missing: true
 - set:
     field: event.kind
     value: event
@@ -67,6 +70,53 @@ processors:
     field: event.type
     value: error
     if: "ctx?.log?.level != null && ctx.log.level.toLowerCase() == 'error'"
+- geoip:
+    field: source.ip
+    target_field: source.geo
+    ignore_missing: true
+- geoip:
+    database_file: GeoLite2-ASN.mmdb
+    field: source.ip
+    target_field: source.as
+    properties:
+      - asn
+      - organization_name
+    ignore_missing: true
+- rename:
+    field: source.as.asn
+    target_field: source.as.number
+    ignore_missing: true
+- rename:
+    field: source.as.organization_name
+    target_field: source.as.organization.name
+    ignore_missing: true
+- append:
+    field: related.ip
+    value: "{{source.ip}}"
+    if: ctx.source?.ip != null
+- append:
+    field: related.user
+    value: "{{user.name}}"
+    if: ctx.user?.name != null
+- append:
+    field: event.category
+    value: authentication
+    if: ctx._tmp?.auth_failed != null
+- append:
+    field: event.category
+    value: network
+    if: ctx?._tmp?.ip_resolve_error != null
+- append:
+    field: event.action
+    value: logon-failed
+    if: ctx._tmp?.auth_failed != null
+- set:
+    field: event.outcome
+    value: failure
+    if: ctx._tmp?.auth_failed != null
+- remove:
+    field: _tmp
+    ignore_missing: true
 on_failure:
 - set:
     field: error.message

filebeat/module/mysql/error/test/mariadb-10.4.8.log

@@ -27,4 +27,5 @@ Version: '10.4.8-MariaDB-log'  socket: '/data/mysqldata/mysql.sock'  port: 3306
 2019-10-16 17:25:43 12 [Note] Event Scheduler: Dropping test.test_error_log
 2019-10-16 17:25:43 12 [ERROR] Event Scheduler: [root@localhost][test.test_error_log] hi from the error log
 2019-10-16 17:25:43 12 [Note] Event Scheduler: [root@localhost][test.test_error_log] At line 1 in test.test_error_log
-
+2023-03-02 17:00:06 200 [Warning] Access denied for user 'sherlock'@'localhost' (using password: NO)
+2023-03-02 17:00:06 200 [Warning] Access denied for user 'sherlock'@'10.10.10.10' (using password: NO)

filebeat/module/mysql/error/test/mariadb-10.4.8.log-expected.json

@@ -396,7 +396,11 @@
         "log.offset": 1582,
         "message": "Server socket created on IP: '::'.",
         "mysql.thread_id": 0,
-        "service.type": "mysql"
+        "related.ip": [
+            "::"
+        ],
+        "service.type": "mysql",
+        "source.ip": "::"
     },
     {
         "@timestamp": "2019-10-16T17:24:15.000-02:00",
@@ -556,13 +560,72 @@
         ],
         "fileset.name": "error",
         "input.type": "log",
-        "log.flags": [
-            "multiline"
-        ],
         "log.level": "Note",
         "log.offset": 2317,
-        "message": "Event Scheduler: [root@localhost][test.test_error_log] At line 1 in test.test_error_log\n",
+        "message": "Event Scheduler: [root@localhost][test.test_error_log] At line 1 in test.test_error_log",
         "mysql.thread_id": 12,
         "service.type": "mysql"
+    },
+    {
+        "@timestamp": "2023-03-02T17:00:06.000-02:00",
+        "event.action": [
+            "logon-failed"
+        ],
+        "event.category": [
+            "authentication",
+            "database"
+        ],
+        "event.dataset": "mysql.error",
+        "event.kind": "event",
+        "event.module": "mysql",
+        "event.outcome": "failure",
+        "event.timezone": "-02:00",
+        "event.type": [
+            "info"
+        ],
+        "fileset.name": "error",
+        "input.type": "log",
+        "log.level": "Warning",
+        "log.offset": 2435,
+        "message": "Access denied for user 'sherlock'@'localhost' (using password: NO)",
+        "mysql.thread_id": 200,
+        "related.user": [
+            "sherlock"
+        ],
+        "service.type": "mysql",
+        "user.name": "sherlock"
+    },
+    {
+        "@timestamp": "2023-03-02T17:00:06.000-02:00",
+        "event.action": [
+            "logon-failed"
+        ],
+        "event.category": [
+            "authentication",
+            "database"
+        ],
+        "event.dataset": "mysql.error",
+        "event.kind": "event",
+        "event.module": "mysql",
+        "event.outcome": "failure",
+        "event.timezone": "-02:00",
+        "event.type": [
+            "info"
+        ],
+        "fileset.name": "error",
+        "input.type": "log",
+        "log.level": "Warning",
+        "log.offset": 2536,
+        "message": "Access denied for user 'sherlock'@'10.10.10.10' (using password: NO)",
+        "mysql.thread_id": 200,
+        "related.ip": [
+            "10.10.10.10"
+        ],
+        "related.user": [
+            "sherlock"
+        ],
+        "service.type": "mysql",
+        "source.ip": "10.10.10.10",
+        "user.name": "sherlock"
     }
 ]

filebeat/module/mysql/error/test/mysql-darwin-brew-5.7.10.log-expected.json

@@ -775,7 +775,11 @@
         "log.offset": 3746,
         "message": "Server socket created on IP: '::'.",
         "mysql.thread_id": 0,
-        "service.type": "mysql"
+        "related.ip": [
+            "::"
+        ],
+        "service.type": "mysql",
+        "source.ip": "::"
     },
     {
         "@timestamp": "2016-12-09T12:08:33.784Z",

filebeat/module/mysql/error/test/mysql-ubuntu-5.5.53-extented.log

@@ -0,0 +1 @@
+230312 19:26:00 [Warning] IP address '10.10.10.10' could not be resolved: Name or service not known

filebeat/module/mysql/error/test/mysql-ubuntu-5.5.53-extented.log-expected.json

@@ -0,0 +1,26 @@
+[
+    {
+        "@timestamp": "2023-03-12T19:26:00.000-02:00",
+        "event.category": [
+            "database",
+            "network"
+        ],
+        "event.dataset": "mysql.error",
+        "event.kind": "event",
+        "event.module": "mysql",
+        "event.timezone": "-02:00",
+        "event.type": [
+            "info"
+        ],
+        "fileset.name": "error",
+        "input.type": "log",
+        "log.level": "Warning",
+        "log.offset": 0,
+        "message": "IP address '10.10.10.10' could not be resolved: Name or service not known",
+        "related.ip": [
+            "10.10.10.10"
+        ],
+        "service.type": "mysql",
+        "source.ip": "10.10.10.10"
+    }
+]

filebeat/module/mysql/error/test/mysql-ubuntu-5.5.53.log-expected.json

@@ -1049,7 +1049,11 @@
         "log.level": "Note",
         "log.offset": 4808,
         "message": "Server socket created on IP: '127.0.0.1'.",
-        "service.type": "mysql"
+        "related.ip": [
+            "127.0.0.1"
+        ],
+        "service.type": "mysql",
+        "source.ip": "127.0.0.1"
     },
     {
         "@timestamp": "2016-12-09T14:18:58.000-02:00",
@@ -1428,7 +1432,11 @@
         "log.level": "Note",
         "log.offset": 6305,
         "message": "Server socket created on IP: '127.0.0.1'.",
-        "service.type": "mysql"
+        "related.ip": [
+            "127.0.0.1"
+        ],
+        "service.type": "mysql",
+        "source.ip": "127.0.0.1"
     },
     {
         "@timestamp": "2016-12-09T14:37:58.000-02:00",

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

@@ -10,3 +10,5 @@
 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
+2023-03-12T15:30:16.866015Z 4016575 [Note] Aborted connection 4016575 to db: 'testdb' user: 'sherlock' host: 'localhost' (Got an error reading communication packets)
+2023-03-07T09:34:58.461438Z 0 [Warning] [MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 14  user: 'sherlock'.

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

@@ -262,5 +262,51 @@
         "message": "[MY-011323] [Server] X Plugin ready for connections. Socket: '/var/run/mysqld/mysqlx.sock' bind-address: '::' port: 33060",
         "mysql.thread_id": 0,
         "service.type": "mysql"
+    },
+    {
+        "@timestamp": "2023-03-12T15:30:16.866Z",
+        "event.category": [
+            "database"
+        ],
+        "event.dataset": "mysql.error",
+        "event.kind": "event",
+        "event.module": "mysql",
+        "event.timezone": "-02:00",
+        "event.type": [
+            "info"
+        ],
+        "fileset.name": "error",
+        "input.type": "log",
+        "log.level": "Note",
+        "log.offset": 1723,
+        "message": "Aborted connection 4016575 to db: 'testdb' user: 'sherlock' host: 'localhost' (Got an error reading communication packets)",
+        "mysql.thread_id": 4016575,
+        "service.type": "mysql"
+    },
+    {
+        "@timestamp": "2023-03-07T09:34:58.461Z",
+        "event.category": [
+            "database"
+        ],
+        "event.code": "MY-010909",
+        "event.dataset": "mysql.error",
+        "event.kind": "event",
+        "event.module": "mysql",
+        "event.provider": "Server",
+        "event.timezone": "-02:00",
+        "event.type": [
+            "info"
+        ],
+        "fileset.name": "error",
+        "input.type": "log",
+        "log.level": "Warning",
+        "log.offset": 1889,
+        "message": "[MY-010909] [Server] /usr/sbin/mysqld: Forcing close of thread 14  user: 'sherlock'.",
+        "mysql.thread_id": 0,
+        "related.user": [
+            "sherlock"
+        ],
+        "service.type": "mysql",
+        "user.name": "sherlock"
     }
 ]

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

@@ -94,6 +94,20 @@
         "field": "event.type",
         "value": "info"
       }
+    },
+    {
+      "append": {
+        "field": "related.user",
+        "value": "{{user.name}}",
+        "if": "ctx.user?.name != null"
+      }
+    },
+    {
+      "append": {
+        "field": "related.ip",
+        "value": "{{source.ip}}",
+        "if": "ctx.source?.ip != null"
+      }
     }
   ],
   "on_failure": [
@@ -104,4 +118,4 @@
       }
     }
   ]
-}
+}

filebeat/module/mysql/slowlog/test/mariadb-10.1.21.log-expected.json

@@ -24,6 +24,12 @@
         "mysql.slowlog.rows_examined": 0,
         "mysql.slowlog.rows_sent": 1,
         "mysql.thread_id": "5",
+        "related.ip": [
+            "121.0.0.1"
+        ],
+        "related.user": [
+            "root"
+        ],
         "service.type": "mysql",
         "source.domain": "localhost",
         "source.ip": "121.0.0.1",

filebeat/module/mysql/slowlog/test/mariadb-10.2.12.log-expected.json

@@ -25,6 +25,9 @@
         "mysql.slowlog.rows_examined": 0,
         "mysql.slowlog.rows_sent": 1,
         "mysql.thread_id": "8",
+        "related.user": [
+            "root"
+        ],
         "service.type": "mysql",
         "source.domain": "localhost",
         "user.name": "root"
@@ -64,6 +67,12 @@
         "mysql.slowlog.tmp_table": true,
         "mysql.slowlog.tmp_table_on_disk": false,
         "mysql.thread_id": "25844",
+        "related.ip": [
+            "192.168.0.10"
+        ],
+        "related.user": [
+            "root"
+        ],
         "service.type": "mysql",
         "source.ip": "192.168.0.10",
         "user.name": "root"

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

@@ -38,6 +38,9 @@
         "mysql.slowlog.tmp_table_sizes": 4026528,
         "mysql.slowlog.tmp_tables": 1,
         "mysql.thread_id": "37",
+        "related.user": [
+            "root"
+        ],
         "service.type": "mysql",
         "source.domain": "localhost",
         "user.name": "root"

filebeat/module/mysql/slowlog/test/mariadb-explain.log-expected.json

@@ -25,6 +25,9 @@
         "mysql.slowlog.rows_sent": 1,
         "mysql.slowlog.schema": "dbt3sf1",
         "mysql.thread_id": "2",
+        "related.user": [
+            "root"
+        ],
         "service.type": "mysql",
         "source.domain": "localhost",
         "user.name": "root"