darold / pgbadger

A fast PostgreSQL Log Analyzer
http://pgbadger.darold.net/
PostgreSQL License
3.49k stars 349 forks source link

postgresql-11.11 and pgbadger 11.8 produces empty html report #736

Closed Reewz closed 2 years ago

Reewz commented 2 years ago

Hi ! Pgbadger (11.8 version) produces empty html report from logs of our postgres (11.11) cluster. Our postgres.conf file has following log line prefix: log_line_prefix: 'timestamp: %m user: %u host: %h db: %d app: [%a] '

We execute pgbadger as: pgbadger /data/pg_log/postgresql-Fri.log -o report.html --prefix='timestamp: %m user: %u host: %h db: %d app: [%a] ' -f stderr

Here is example of logs in file:

timestamp: 2022-06-23 00:00:15.639 MSK user: sentry host: [local] db: sentry app: [[unknown]] STATEMENT: INSERT INTO "sentry_eventuser" ("project_id", "hash", "ident", "email", "username", "name", "ip_address", "date_added") VALUES (152, 'a30d004660658a2b2e14cd489a21f480', NULL, NULL, NULL, NULL, '95.153.161.250', '2022-06-22 21:00:15.636023+00:00') RETURNING "sentry_eventuser"."id" timestamp: 2022-06-23 00:00:15.681 MSK user: sentry host: [local] db: sentry app: [[unknown]] ERROR: duplicate key value violates unique constraint "sentry_environmentproject_project_id_29250c1307d3722b_uniq" timestamp: 2022-06-23 00:00:15.681 MSK user: sentry host: [local] db: sentry app: [[unknown]] DETAIL: Key (project_id, environment_id)=(152, 2) already exists. timestamp: 2022-06-23 00:00:15.681 MSK user: sentry host: [local] db: sentry app: [[unknown]] STATEMENT: INSERT INTO "sentry_environmentproject" ("project_id", "environment_id", "is_hidden") VALUES (152, 2, NULL) RETURNING "sentry_environmentproject"."id" timestamp: 2022-06-23 00:00:19.051 MSK user: host: db: app: [] LOG: automatic analyze of table "esx_site_backend_api.public.shedlock" system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.02 s timestamp: 2022-06-23 00:00:19.440 MSK user: host: db: app: [] LOG: automatic vacuum of table "esx_site_backend_api.public.registered_client": index scans: 1 pages: 0 removed, 1790 remain, 0 skipped due to pins, 271 skipped frozen tuples: 15158 removed, 19250 remain, 0 are dead but not yet removable, oldest xmin: 650513400 buffer usage: 3777 hits, 0 misses, 0 dirtied avg read rate: 0.000 MB/s, avg write rate: 0.000 MB/s system usage: CPU: user: 0.01 s, system: 0.00 s, elapsed: 0.37 s timestamp: 2022-06-23 00:00:19.833 MSK user: host: db: app: [] LOG: automatic analyze of table "esx_site_backend_api.public.registered_client" system usage: CPU: user: 0.17 s, system: 0.00 s, elapsed: 0.39 s

Here is result of pgbadger's execution: [========================>] Parsed 125439235 bytes of 125439235 (100.00%), queries: 0, events: 1 LOG: Ok, generating html report...

And finally it is empty inside after opening in browser. By the way overall size of .html file is 5.5 Mb.

We've tried to run verbose and found following messages:

DEBUG: Start parsing postgresql log at offset 0 of file "/data/pg_log/postgresql-Fri.log" to 119253976 DEBUG: Unknown stderr log line format: pages: 0 removed, 174 remain, 0 skipped due to pins, 103 skipped frozen DEBUG: Unknown stderr log line format: tuples: 180 removed, 96 remain, 0 are dead but not yet removable, oldest xmin: 656129919 DEBUG: Unknown stderr log line format: buffer usage: 244 hits, 3 misses, 0 dirtied DEBUG: Unknown stderr log line format: avg read rate: 0.495 MB/s, avg write rate: 0.000 MB/s DEBUG: Unknown stderr log line format: system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.04 s DEBUG: Unknown stderr log line format: pages: 0 removed, 1 remain, 0 skipped due to pins, 0 skipped frozen DEBUG: Unknown stderr log line format: tuples: 56 removed, 1 remain, 0 are dead but not yet removable, oldest xmin: 656129964 ... DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING DEBUG: Unknown stderr log line format: RETURNING

Seems we are experiencing some troubles with prefix, but can't understand how to fix it.

darold commented 2 years ago

The documentation says:

pgBadger supports any custom format set into the log_line_prefix directive of
your postgresql.conf file as long as it at least specify the %t and %p patterns.

the pid is not present in your log_line_prefix

Reewz commented 2 years ago

Thanks ! My bad. May be you could add a line about it in '--help' ? Or throw an according exception if supplied --prefix doesn't contain mandatory values ?

darold commented 2 years ago

Or read the doc :-)