Filebeat does not parse postgresql logs properly

Elastic Stack Beats
1

Hello,

I recently installed filebeat and followed the documentation to enable the postgresql module, in order to use kibana dashboards for psql. When checking ES filebeat index mappings i can see the postgres.log.(*) fields. When i review kibana postgresql dashboards the fields are empty and i get an error.message "Provided Grok expressions do not match field value: [2019-01-09 15:18:55 UTC [2527-1] root@template1 FATAL: role "root" does not exist]" .

Please guide on what config files/logs are needed in order to find whats the problem

Thanks.

Here is an example of filebeat logs.
019-01-09T15:30:31.676Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":70,"time":{"ms":4}},"total":{"ticks":290,"time":{"ms":4},"value":290},"user":{"ticks":220}},"handles":{"limit":{"hard":4096,"soft":1024},"open":8},"info":{"ephemeral_id":"c15e6814-019f-43cb-ae43-0706bccd3eb4","uptime":{"ms":2040018}},"memstats":{"gc_next":4194304,"memory_alloc":3032864,"memory_total":28327576}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":5}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}
2019-01-09T15:31:01.676Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":70},"total":{"ticks":300,"time":{"ms":4},"value":300},"user":{"ticks":230,"time":{"ms":4}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":8},"info":{"ephemeral_id":"c15e6814-019f-43cb-ae43-0706bccd3eb4","uptime":{"ms":2070017}},"memstats":{"gc_next":4194304,"memory_alloc":1898760,"memory_total":28512648}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":5}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}
2019-01-09T15:31:31.676Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":70},"total":{"ticks":300,"time":{"ms":4},"value":300},"user":{"ticks":230,"time":{"ms":4}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":8},"info":{"ephemeral_id":"c15e6814-019f-43cb-ae43-0706bccd3eb4","uptime":{"ms":2100017}},"memstats":{"gc_next":4194304,"memory_alloc":2231088,"memory_total":28844976}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":5}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}
2019-01-09T15:32:01.676Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":70},"total":{"ticks":310,"time":{"ms":4},"value":310},"user":{"ticks":240,"time":{"ms":4}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":8},"info":{"ephemeral_id":"c15e6814-019f-43cb-ae43-0706bccd3eb4","uptime":{"ms":2130018}},"memstats":{"gc_next":4194304,"memory_alloc":2559536,"memory_total":29173424}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":5}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}
2019-01-09T15:32:31.676Z INFO [monitoring] log/log.go:144 Non-zero metrics in the last 30s {"monitoring": {"metrics": {"beat":{"cpu":{"system":{"ticks":70},"total":{"ticks":310,"time":{"ms":4},"value":310},"user":{"ticks":240,"time":{"ms":4}}},"handles":{"limit":{"hard":4096,"soft":1024},"open":8},"info":{"ephemeral_id":"c15e6814-019f-43cb-ae43-0706bccd3eb4","uptime":{"ms":2160018}},"memstats":{"gc_next":4194304,"memory_alloc":2962400,"memory_total":29576288}},"filebeat":{"harvester":{"open_files":0,"running":0}},"libbeat":{"config":{"module":{"running":0}},"pipeline":{"clients":3,"events":{"active":0}}},"registrar":{"states":{"current":5}},"system":{"load":{"1":0,"15":0,"5":0,"norm":{"1":0,"15":0,"5":0}}}}}}

Summary

This text will be hidden

2

@Alexandros_Aristopan I think you are hitting the following bug https://github.com/elastic/beats/issues/7438 , We will need to fix the ingest pipeline to correctly parse the log.

3

Thank you for replying! I looked at the reported issue and i did some silly tests by myself. What i noticed and I believe it is strange is that when i test the pattern:

"%{LOCALDATE:postgres.log.timestamp} %{WORD:postgres.log.timezone} \\[%{NUMBER_PID:postgres.log.pid}\\] (%{USERNAME:postgresql.log.user}@%{POSTGRESQL_DB_NAME:postgresql.log.database}) ?%{WORD:postgresql.log.level}: (duration: %{NUMBER:postgresql.log.duration} ms  statement: %{GREEDYDATA:postgresql.log.query}|%{GREEDYDATA:postgresql.log.message})"

on some grok tester it matches my logs but when adjusting for filebeat it still fails to parse. Is there anywhere explaining in detail the process between filebeat and kibana? How can a grok tester like http://grokconstructor.appspot.com/do/match#result can match the result and filebeat psotgresql module can not with the same patterns?

Kind Regards,
Alex

P.S NUMBER_PID = NUMBER_PID": "%{NUMBER}-[a-zA-Z0-9_]+[a-zA-Z0-9_\$]*" to match pids in the form of [1234-56]

4

This topic was automatically closed 28 days after the last reply. New replies are no longer allowed.