Consider lines without timestamp as part of the previous message

elastic · Oct 18, 2019 · 79e9b6f · 79e9b6f
1 parent 1370919
commit 79e9b6f
Show file tree

Hide file tree

Showing 7 changed files with 284 additions and 218 deletions.
diff --git a/filebeat/module/mysql/error/config/error.yml b/filebeat/module/mysql/error/config/error.yml
@@ -5,5 +5,11 @@ paths:
 {{ end }}
 exclude_files: [".gz$"]
 
+multiline:
+  # Consider lines without timestamp part of the previous message
+  pattern: '^([0-9]{4}-[0-9]{2}-[0-9]{2}|[0-9]{6})'
+  negate: true
+  match: after
+
 processors:
 - add_locale: ~
diff --git a/filebeat/module/mysql/error/ingest/pipeline.json b/filebeat/module/mysql/error/ingest/pipeline.json
@@ -4,13 +4,14 @@
     "grok": {
         "field": "message",
         "patterns": [
-          "%{MYSQLDATETIME}%{SPACE}(%{NUMBER:mysql.thread_id:long}%{SPACE})?(\\[%{DATA:log.level}\\]%{SPACE})?%{GREEDYDATA:message}",
+          "%{MYSQLDATETIME}%{SPACE}(%{NUMBER:mysql.thread_id:long}%{SPACE})?(\\[%{DATA:log.level}\\]%{SPACE})?%{GREEDYMULTILINE:message}",
           "%{GREEDYDATA:message}"
         ],
         "ignore_missing": true,
         "pattern_definitions": {
           "LOCALDATETIME": "(?:%{YEAR}-%{MONTHNUM}-%{MONTHDAY}|%{NUMBER})%{SPACE}%{TIME}",
-          "MYSQLDATETIME": "(?:%{LOCALDATETIME:_tmp.local_timestamp}|%{TIMESTAMP_ISO8601:_tmp.timestamp})"
+          "MYSQLDATETIME": "(?:%{LOCALDATETIME:_tmp.local_timestamp}|%{TIMESTAMP_ISO8601:_tmp.timestamp})",
+          "GREEDYMULTILINE": "(.|\n)+"
         }
       }
     }, {

diff --git a/filebeat/module/mysql/error/test/error.log-expected.json b/filebeat/module/mysql/error/test/error.log-expected.json
@@ -82,22 +82,15 @@
         "event.timezone": "-02:00",
         "fileset.name": "error",
         "input.type": "log",
+        "log.flags": [
+            "multiline"
+        ],
         "log.level": "Note",
         "log.offset": 832,
-        "message": "/usr/local/Cellar/mysql/5.7.10/bin/mysqld: ready for connections.",
+        "message": "/usr/local/Cellar/mysql/5.7.10/bin/mysqld: ready for connections.\nVersion: '5.7.10'  socket: '/tmp/mysql.sock'  port: 3306  Homebrew",
         "mysql.thread_id": 0,
         "service.type": "mysql"
     },
-    {
-        "event.dataset": "mysql.error",
-        "event.module": "mysql",
-        "event.timezone": "-02:00",
-        "fileset.name": "error",
-        "input.type": "log",
-        "log.offset": 935,
-        "message": "Version: '5.7.10'  socket: '/tmp/mysql.sock'  port: 3306  Homebrew",
-        "service.type": "mysql"
-    },
     {
         "@timestamp": "2016-12-09T22:21:02.443Z",
         "event.dataset": "mysql.error",

diff --git a/filebeat/module/mysql/error/test/mariadb-10.4.8.log-expected.json b/filebeat/module/mysql/error/test/mariadb-10.4.8.log-expected.json
@@ -291,22 +291,15 @@
         "event.timezone": "-02:00",
         "fileset.name": "error",
         "input.type": "log",
+        "log.flags": [
+            "multiline"
+        ],
         "log.level": "Note",
         "log.offset": 1788,
-        "message": "/usr/sbin/mysqld: ready for connections.",
+        "message": "/usr/sbin/mysqld: ready for connections.\nVersion: '10.4.8-MariaDB-log'  socket: '/data/mysqldata/mysql.sock'  port: 3306  MariaDB Server",
         "mysql.thread_id": 0,
         "service.type": "mysql"
     },
-    {
-        "event.dataset": "mysql.error",
-        "event.module": "mysql",
-        "event.timezone": "-02:00",
-        "fileset.name": "error",
-        "input.type": "log",
-        "log.offset": 1858,
-        "message": "Version: '10.4.8-MariaDB-log'  socket: '/data/mysqldata/mysql.sock'  port: 3306  MariaDB Server",
-        "service.type": "mysql"
-    },
     {
         "@timestamp": "2019-10-16T17:25:43.000-02:00",
         "event.dataset": "mysql.error",
@@ -366,9 +359,12 @@
         "event.timezone": "-02:00",
         "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",
+        "message": "Event Scheduler: [root@localhost][test.test_error_log] At line 1 in test.test_error_log\n",
         "mysql.thread_id": 12,
         "service.type": "mysql"
     }

diff --git a/filebeat/module/mysql/error/test/mysql-darwin-brew-5.7.10.log-expected.json b/filebeat/module/mysql/error/test/mysql-darwin-brew-5.7.10.log-expected.json
@@ -524,22 +524,15 @@
         "event.timezone": "-02:00",
         "fileset.name": "error",
         "input.type": "log",
+        "log.flags": [
+            "multiline"
+        ],
         "log.level": "Note",
         "log.offset": 3888,
-        "message": "/usr/local/Cellar/mysql/5.7.10/bin/mysqld: ready for connections.",
+        "message": "/usr/local/Cellar/mysql/5.7.10/bin/mysqld: ready for connections.\nVersion: '5.7.10'  socket: '/tmp/mysql.sock'  port: 3306  Homebrew",
         "mysql.thread_id": 0,
         "service.type": "mysql"
     },
-    {
-        "event.dataset": "mysql.error",
-        "event.module": "mysql",
-        "event.timezone": "-02:00",
-        "fileset.name": "error",
-        "input.type": "log",
-        "log.offset": 3991,
-        "message": "Version: '5.7.10'  socket: '/tmp/mysql.sock'  port: 3306  Homebrew",
-        "service.type": "mysql"
-    },
     {
         "@timestamp": "2016-12-09T22:21:02.443Z",
         "event.dataset": "mysql.error",
@@ -1293,5 +1286,18 @@
         "message": "InnoDB: page_cleaner: 1000ms intended loop took 515624ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)",
         "mysql.thread_id": 0,
         "service.type": "mysql"
+    },
+    {
+        "@timestamp": "2016-12-11T06:36:50.017Z",
+        "event.dataset": "mysql.error",
+        "event.module": "mysql",
+        "event.timezone": "-02:00",
+        "fileset.name": "error",
+        "input.type": "log",
+        "log.level": "Note",
+        "log.offset": 14182,
+        "message": "InnoDB: page_cleaner: 1000ms intended loop took 3598619ms. The settings might not be optimal. (flushed=0 and evicted=0, during the time.)",
+        "mysql.thread_id": 0,
+        "service.type": "mysql"
     }
 ]
diff --git a/filebeat/module/mysql/error/test/mysql-ubuntu-5.5.53.log b/filebeat/module/mysql/error/test/mysql-ubuntu-5.5.53.log
@@ -97,19 +97,6 @@ Version: '5.5.53-0ubuntu0.12.04.1'  socket: '/var/run/mysqld/mysqld.sock'  port:
 161209 14:37:58 [Note] Event Scheduler: Loaded 0 events
 161209 14:37:58 [Note] /usr/sbin/mysqld: ready for connections.
 Version: '5.5.53-0ubuntu0.12.04.1-log'  socket: '/var/run/mysqld/mysqld.sock'  port: 3306  (Ubuntu)
-vagrant@precise32:~$ cat /var/log/mysql.log | grep phisically
-vagrant@precise32:~$ cat /var/log/mysql.log | grep physi
-vagrant@precise32:~$ cat /var/log/mysql.log | physically
-physically: command not found
-vagrant@precise32:~$ cat /var/log/mysql.log | grep physically
-vagrant@precise32:~$ less /var/log/mysql.
-mysql.err  mysql.log
-vagrant@precise32:~$ less /var/log/mysql.err
-vagrant@precise32:~$ less /var/log/mysql.log
-vagrant@precise32:~$ less /var/log/mysql/
-error.log       mysql-slow.log
-vagrant@precise32:~$ less /var/log/mysql/error.log
-vagrant@precise32:~$ cat /var/log/mysql/error.log
 161209 14:18:50 [Warning] Using unique option prefix myisam-recover instead of myisam-recover-options is deprecated and will be removed in a future release. Please use the full name instead.
 161209 14:18:50 [Note] Plugin 'FEDERATED' is disabled.
 161209 14:18:50 InnoDB: The InnoDB memory heap is disabled