From dfe4f27fa15e887bdd93366d738a9f96b8bea27c Mon Sep 17 00:00:00 2001 From: Mario Castro Date: Fri, 9 Aug 2019 14:56:45 +0200 Subject: [PATCH] [Filebeat] Upgrade Postgres module to work with version 11 (#13053) --- filebeat/docs/fields.asciidoc | 9 + filebeat/module/postgresql/fields.go | 2 +- .../module/postgresql/log/_meta/fields.yml | 4 + .../postgresql/log/ingest/pipeline.json | 2 +- .../postgresql/log/test/postgresql-11.4.log | 29 ++ .../test/postgresql-11.4.log-expected.json | 422 ++++++++++++++++++ 6 files changed, 466 insertions(+), 2 deletions(-) create mode 100644 filebeat/module/postgresql/log/test/postgresql-11.4.log create mode 100644 filebeat/module/postgresql/log/test/postgresql-11.4.log-expected.json diff --git a/filebeat/docs/fields.asciidoc b/filebeat/docs/fields.asciidoc index 3b0f91db1564..3bb356626b7b 100644 --- a/filebeat/docs/fields.asciidoc +++ b/filebeat/docs/fields.asciidoc @@ -12670,6 +12670,15 @@ example: SELECT * FROM users; -- +*`postgresql.log.error.code`*:: ++ +-- +Error code returned by Postgres (if any) + +type: long + +-- + *`postgresql.log.timezone`*:: + -- diff --git a/filebeat/module/postgresql/fields.go b/filebeat/module/postgresql/fields.go index 9d799833aa64..0490b489779a 100644 --- a/filebeat/module/postgresql/fields.go +++ b/filebeat/module/postgresql/fields.go @@ -32,5 +32,5 @@ func init() { // AssetPostgresql returns asset data. // This is the base64 encoded gzipped contents of module/postgresql. func AssetPostgresql() string { - return "eJyck0Fr3DAQhe/+FY89FmIKPRRc6CUkp6RtmtyDYo9lUUmjaOTQ7a8vWmfZjdZe4sxRw3vf4419gT+0bRBYko4kz7YCkkmWGmx+TY/3dzebCuhI2mhCMuwbfK8A4Ja70RJ6jggqivEaaSAcdLCs0RtLUleADBzTY8u+N7pBiiNVQG/IdtLs/C7glaMiTZ60DdRARx7D68tMmmmud37oI7siyC5DnmPkMdayPjI6ZZ7lviWfq2E/ZYzjKMk4kqRceLPN+BCpVYm6Bl/rL/Xnk/1ivDwPAx2sD0lzPGs81bNZWo70aLrCbKrHstfrIlxyJBRue1KnknpSQoWI/ioXdl+k23ZPmzO8E9oP5Qjczzvvsc8jxe0i8/7q5uryAZ9w/fvnLUahKN9WZbjL9pCkEjny6VDy4uX/sS87mOpW1igpNkGloQG9ZOsFsTM6qukgr3/dDHeIpLqlOy+DQ+SWROpwonwPNde5EpgldVZ/AGfphexKnmVdz+new3MkovTaW86rSt7/AAAA//+nmXd6" + return "eJyck0FrGzEQhe/+FQ+f2kKWQg+FLfQSnFPSNk3uQV7NyqKSRhlpQ7e/vsiOsbPeNd7MccV73+eRfIU/1NeInLIRSs9uAWSbHdVY/tp9fLi/XS4ATakRG7PlUOP7AgDuWHeO0LIgKkk2GOQN4ZCDY4PWOkrVAkgblvzUcGitqZGlowXQWnI61du+KwTlaWBTJveRahjhLr5+GbHZzc22D62wH4hsHcocI4+xjs1R0SnzLPct+dwa9jPUOFbJ1lPKysc3pwUfhRqVSdf4Wn2pPp+cT+qVedzQofpgWvScDVSNujQs9GT1oGy3HsfBzFO4ZiEM2vYkrbJaq0SDEP1VPm5fpO/1enmGd0L7oTyB2/HmPfa5I+knmQ+r29X1Iz7h5vfPO3SJJH2b5XBf6pGyyuQp5MOSR2VIhKVqWA+3cNnCVyWOEodQ7iSQxrrfv8WED7aFCv3H8xLljfzjMK6gnFVpcBJV3tSgl/L7JsLeGlE7yde//gh3I6T01GObBkfhhlKq4knyEmq505nAEqlK+h04Ry/kZvIcm2osdwnPU0rKzL3L8dSQ9z8AAP//UU6bDw==" } diff --git a/filebeat/module/postgresql/log/_meta/fields.yml b/filebeat/module/postgresql/log/_meta/fields.yml index dd2ce0b6465d..834c38596780 100644 --- a/filebeat/module/postgresql/log/_meta/fields.yml +++ b/filebeat/module/postgresql/log/_meta/fields.yml @@ -20,6 +20,10 @@ description: Query statement. + - name: error.code + type: long + description: Error code returned by Postgres (if any) + - name: timezone type: alias path: event.timezone diff --git a/filebeat/module/postgresql/log/ingest/pipeline.json b/filebeat/module/postgresql/log/ingest/pipeline.json index c0d83f38065b..f698fac4ac28 100644 --- a/filebeat/module/postgresql/log/ingest/pipeline.json +++ b/filebeat/module/postgresql/log/ingest/pipeline.json @@ -6,7 +6,7 @@ "field": "message", "ignore_missing": true, "patterns": [ - "^%{DATETIME:postgresql.log.timestamp} \\[%{NUMBER:process.pid:long}(-%{BASE16FLOAT:postgresql.log.core_id:long})?\\] ((\\[%{USERNAME:user.name}\\]@\\[%{POSTGRESQL_DB_NAME:postgresql.log.database}\\]|%{USERNAME:user.name}@%{POSTGRESQL_DB_NAME:postgresql.log.database}) )?%{WORD:log.level}: (duration: %{NUMBER:temp.duration:float} ms statement: %{GREEDYDATA:postgresql.log.query}|%{GREEDYDATA:message})" + "^%{DATETIME:postgresql.log.timestamp} \\[%{NUMBER:process.pid:long}(-%{BASE16FLOAT:postgresql.log.core_id:long})?\\] ((\\[%{USERNAME:user.name}\\]@\\[%{POSTGRESQL_DB_NAME:postgresql.log.database}\\]|%{USERNAME:user.name}@%{POSTGRESQL_DB_NAME:postgresql.log.database}) )?%{WORD:log.level}: (?:%{NUMBER:postgresql.log.error.code:long}|%{SPACE})(duration: %{NUMBER:temp.duration:float} ms statement: %{GREEDYDATA:postgresql.log.query}|: %{GREEDYDATA:message}|%{GREEDYDATA:message})" ], "pattern_definitions": { "DATETIME": "[-0-9]+ %{TIME} %{WORD:event.timezone}", diff --git a/filebeat/module/postgresql/log/test/postgresql-11.4.log b/filebeat/module/postgresql/log/test/postgresql-11.4.log new file mode 100644 index 000000000000..dedc3285aa3c --- /dev/null +++ b/filebeat/module/postgresql/log/test/postgresql-11.4.log @@ -0,0 +1,29 @@ +2019-07-23 12:06:24.406 UTC [25] LOG: 00000: database system was interrupted; last known up at 2019-07-23 12:03:20 UTC +2019-07-23 12:06:24.406 UTC [25] LOCATION: StartupXLOG, xlog.c:6388 +2019-07-23 12:06:24.478 UTC [25] LOG: 00000: database system was not properly shut down; automatic recovery in progress +2019-07-23 12:06:24.478 UTC [25] LOCATION: StartupXLOG, xlog.c:6879 +2019-07-23 12:06:24.485 UTC [25] LOG: 00000: redo starts at 0/1651398 +2019-07-23 12:06:24.485 UTC [25] LOCATION: StartupXLOG, xlog.c:7150 +2019-07-23 12:06:24.485 UTC [25] LOG: 00000: invalid record length at 0/16513D0: wanted 24, got 0 +2019-07-23 12:06:24.485 UTC [25] LOCATION: ReadRecord, xlog.c:4233 +2019-07-23 12:06:24.485 UTC [25] LOG: 00000: redo done at 0/1651398 +2019-07-23 12:06:24.485 UTC [25] LOCATION: StartupXLOG, xlog.c:7422 +2019-07-23 12:06:24.507 UTC [1] LOG: 00000: database system is ready to accept connections +2019-07-23 12:06:24.507 UTC [1] LOCATION: reaper, postmaster.c:2889 +2019-07-23 12:06:30.536 UTC [44] LOG: 00000: connection received: host=[local] +2019-07-23 12:06:30.536 UTC [44] LOCATION: BackendInitialize, postmaster.c:4206 +2019-07-23 12:06:30.537 UTC [44] LOG: 00000: connection authorized: user=postgres database=postgres +2019-07-23 12:06:30.537 UTC [44] LOCATION: PerformAuthentication, postinit.c:279 +2019-07-23 12:06:33.732 UTC [44] LOG: 00000: statement: show config_filel; +2019-07-23 12:06:33.732 UTC [44] LOCATION: exec_simple_query, postgres.c:975 +2019-07-23 12:06:33.732 UTC [44] ERROR: 42704: unrecognized configuration parameter "config_filel" +2019-07-23 12:06:33.732 UTC [44] LOCATION: GetConfigOptionByName, guc.c:8342 +2019-07-23 12:06:33.732 UTC [44] STATEMENT: show config_filel; +2019-07-23 12:06:34.877 UTC [44] LOG: 00000: statement: show config_file; +2019-07-23 12:06:34.877 UTC [44] LOCATION: exec_simple_query, postgres.c:975 +2019-07-23 12:06:34.878 UTC [44] LOG: 00000: duration: 0.524 ms +2019-07-23 12:06:34.878 UTC [44] LOCATION: exec_simple_query, postgres.c:1219 +2019-07-23 12:09:57.563 UTC [44] LOG: 00000: statement: SELECT * FROM pg_catalog.pg_tables; +2019-07-23 12:09:57.563 UTC [44] LOCATION: exec_simple_query, postgres.c:975 +2019-07-23 12:09:57.565 UTC [44] LOG: 00000: duration: 2.139 ms +2019-07-23 12:09:57.565 UTC [44] LOCATION: exec_simple_query, postgres.c:1219 diff --git a/filebeat/module/postgresql/log/test/postgresql-11.4.log-expected.json b/filebeat/module/postgresql/log/test/postgresql-11.4.log-expected.json new file mode 100644 index 000000000000..2c347c87c6ad --- /dev/null +++ b/filebeat/module/postgresql/log/test/postgresql-11.4.log-expected.json @@ -0,0 +1,422 @@ +[ + { + "@timestamp": "2019-07-23T12:06:24.406Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 0, + "message": "database system was interrupted; last known up at 2019-07-23 12:03:20 UTC", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:24.406 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.406Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 120, + "message": "StartupXLOG, xlog.c:6388", + "postgresql.log.timestamp": "2019-07-23 12:06:24.406 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.478Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 189, + "message": "database system was not properly shut down; automatic recovery in progress", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:24.478 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.478Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 310, + "message": "StartupXLOG, xlog.c:6879", + "postgresql.log.timestamp": "2019-07-23 12:06:24.478 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.485Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 379, + "message": "redo starts at 0/1651398", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:24.485 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.485Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 450, + "message": "StartupXLOG, xlog.c:7150", + "postgresql.log.timestamp": "2019-07-23 12:06:24.485 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.485Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 519, + "message": "invalid record length at 0/16513D0: wanted 24, got 0", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:24.485 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.485Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 618, + "message": "ReadRecord, xlog.c:4233", + "postgresql.log.timestamp": "2019-07-23 12:06:24.485 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.485Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 686, + "message": "redo done at 0/1651398", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:24.485 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.485Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 755, + "message": "StartupXLOG, xlog.c:7422", + "postgresql.log.timestamp": "2019-07-23 12:06:24.485 UTC", + "process.pid": 25, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.507Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 824, + "message": "database system is ready to accept connections", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:24.507 UTC", + "process.pid": 1, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:24.507Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 916, + "message": "reaper, postmaster.c:2889", + "postgresql.log.timestamp": "2019-07-23 12:06:24.507 UTC", + "process.pid": 1, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:30.536Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 985, + "message": "connection received: host=[local]", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:30.536 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:30.536Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 1065, + "message": "BackendInitialize, postmaster.c:4206", + "postgresql.log.timestamp": "2019-07-23 12:06:30.536 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:30.537Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 1146, + "message": "connection authorized: user=postgres database=postgres", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:30.537 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:30.537Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 1247, + "message": "PerformAuthentication, postinit.c:279", + "postgresql.log.timestamp": "2019-07-23 12:06:30.537 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:33.732Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 1329, + "message": "statement: show config_filel;", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:33.732 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:33.732Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 1405, + "message": "exec_simple_query, postgres.c:975", + "postgresql.log.timestamp": "2019-07-23 12:06:33.732 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:33.732Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "ERROR", + "log.offset": 1483, + "message": "unrecognized configuration parameter \"config_filel\"", + "postgresql.log.error.code": 42704, + "postgresql.log.timestamp": "2019-07-23 12:06:33.732 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:33.732Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 1583, + "message": "GetConfigOptionByName, guc.c:8342", + "postgresql.log.timestamp": "2019-07-23 12:06:33.732 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:33.732Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "STATEMENT", + "log.offset": 1661, + "message": "show config_filel;", + "postgresql.log.timestamp": "2019-07-23 12:06:33.732 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:34.877Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 1725, + "message": "statement: show config_file;", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:34.877 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:34.877Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 1800, + "message": "exec_simple_query, postgres.c:975", + "postgresql.log.timestamp": "2019-07-23 12:06:34.877 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:34.878Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 1878, + "message": "duration: 0.524 ms", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:06:34.878 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:06:34.878Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 1943, + "message": "exec_simple_query, postgres.c:1219", + "postgresql.log.timestamp": "2019-07-23 12:06:34.878 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:09:57.563Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 2022, + "message": "statement: SELECT * FROM pg_catalog.pg_tables;", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:09:57.563 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:09:57.563Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 2115, + "message": "exec_simple_query, postgres.c:975", + "postgresql.log.timestamp": "2019-07-23 12:09:57.563 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:09:57.565Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOG", + "log.offset": 2193, + "message": "duration: 2.139 ms", + "postgresql.log.error.code": 0, + "postgresql.log.timestamp": "2019-07-23 12:09:57.565 UTC", + "process.pid": 44, + "service.type": "postgresql" + }, + { + "@timestamp": "2019-07-23T12:09:57.565Z", + "event.dataset": "postgresql.log", + "event.module": "postgresql", + "event.timezone": "UTC", + "fileset.name": "log", + "input.type": "log", + "log.level": "LOCATION", + "log.offset": 2258, + "message": "exec_simple_query, postgres.c:1219", + "postgresql.log.timestamp": "2019-07-23 12:09:57.565 UTC", + "process.pid": 44, + "service.type": "postgresql" + } +] \ No newline at end of file