How to Analyze PostgreSQL Performance with Logging and pgBadger
Introduction
Configuring Logging Settings
Configuring auto_explain
Restarting/Reloading PostgreSQL
Log Compression
Installing pgBadger
Generating pgBadger Report
Understanding PostgreSQL Log Entries
Conclusion
Introduction
Efficient logging and performance analysis are critical for maintaining optimal PostgreSQL database operations. By configuring logging settings and using pgBadger for analysis, administrators can gain valuable insights into SQL performance, auto vacuum operations, checkpoints, connections, disconnections, locking, and temporary files.
Configuring Logging Settings
By default, PostgreSQL logs are generated within the cluster's data directory, which can increase the size of backups.
It's recommended to place logs in a dedicated directory outside of the data directory. Update the log_directory setting with an absolute path.
log_autovacuum_min_duration = 0
log_checkpoints = on
log_connections = on
log_destination = 'stderr'
log_directory = '/var/lib/pgsql/15/pg_logs'
log_disconnections = on
log_duration = off
log_filename = 'postgresql_%w_%a_%H.log'
log_line_prefix = '%t [%p]: [%l] %quser=%u,db=%d,app=%a,client=%h '
log_lock_waits = on
log_min_duration_statement = 0
log_rotation_age = 60
log_rotation_size = 0
log_statement = 'none'
log_temp_files = 0
log_truncate_on_rotation = 'on'
logging_collector = 'on'
Configuring auto_explain
Enable the auto_explain module in the postgresql.conf by adding it to the shared_preload_libraries setting, and configure the related settings as shown below:
shared_preload_libraries = 'auto_explain'
auto_explain.log_analyze = 1
auto_explain.log_buffers = 1
auto_explain.log_timing = 1
auto_explain.log_triggers = 1
auto_explain.log_verbose = 1
auto_explain.log_format = text
auto_explain.log_min_duration = 3000
auto_explain.log_nested_statements = 1
auto_explain.sample_rate = 1
Restarting/Reloading PostgreSQL
Most logging settings can be reloaded, except for logging_collector, which requires a restart. Use the following commands:
Reload:
pg_ctl -D /var/lib/pgsql/15/data reload
Restart:
pg_ctl -D /var/lib/pgsql/15/data stop
pg_ctl -D /var/lib/pgsql/15/data start
Log Compression
To manage log file size, you can set up a cron job to compress log files older than one day:
0 0 * * * for f in $(find /path_to_logs/ -mtime +0 -name "postgresql_*.log"); do gzip -9 -f $f; done
Installing pgBadger
Follow these steps to install pgBadger:
sudo yum install perl-devel- Download the latest tar ball from pgBadger Releases.
tar xzf v11.x.tar.gzcd pgbadger-11.x/perl Makefile.PLmake && sudo make install
Generating pgBadger Report
Generate a pgBadger report using the following command:
pgbadger --dbname dbdocs --top 50 --title dbdocs --outdir /var/lib/pgsql/15/pg_reports --outfile pgBadger_dbdocs_20240203.html /var/lib/pgsql/15/pg_logs/postgresql-2024-02-03_104631.log
Understanding PostgreSQL Log Entries
Query Times
2024-02-12 16:24:14 CET [7926]: [539] user=dbdocs_user,db=dbdocs,app=[unknown],client=10.XX.102.XXX LOG: duration: 0.104 ms bind PGCursor_0x7f27049e8570: UPDATE Auditlog SET JobType = $1, LastUpdate = $2, LastStatus = $3, StatusStr = $4, Counter = $5 WHERE AuditID = $6
Query Plan
2024-02-12 16:24:14 CET [7926]: [541] user=dbdocs,db=dbdocs,app=[unknown],client=10.XX.102.XXX LOG: duration: 0.052 ms plan:
Query Text: UPDATE Auditlog SET JobType = $1, LastUpdate = $2, LastStatus = $3, StatusStr = $4, Counter = $5 WHERE AuditID = $6
Update on public.Auditlog (cost=20.26..24.28 rows=1 width=571) (actual time=0.043..0.044 rows=0 loops=1)
Buffers: shared hit=5
-> Bitmap Heap Scan on public.Auditlog (cost=20.26..24.28 rows=1 width=571) (actual time=0.026..0.029 rows=1 loops=1)
Output: AuditID, '0'::smallint, '2024-02-12 16:24:14'::timestamp(3) without time zone, 0, 'Sleeping for 0.5 seconds...'::character varying(255), '-1'::integer, ctid
Recheck Cond: ((Auditlog.AuditID)::text = 'Worker_monitoringagent_3099_002'::text)
Heap Blocks: exact=1
Buffers: shared hit=4
-> Bitmap Index Scan on Auditlog_1 (cost=0.00..20.26 rows=1 width=0) (actual time=0.019..0.019 rows=1 loops=1)
Index Cond: ((Auditlog.AuditID)::text = 'Worker_monitoringagent_3099_002'::text)
Buffers: shared hit=3
Autovacuum
2024-03-24 13:00:27 CET [11144]: [2] LOG: automatic vacuum of table "dbdocs.public.employee": index scans: 1
pages: 0 removed, 2 remain, 0 skipped due to pins, 0 skipped frozen
tuples: 60 removed, 20 remain, 0 are dead but not yet removable, oldest xmin: 1100844226
buffer usage: 104 hits, 0 misses, 2 dirtied
avg read rate: 0.000 MB/s, avg write rate: 22.877 MB/s
system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.00 s
2024-03-24 13:00:27 CET [11144]: [3] LOG: automatic analyze of table "dbdocs.public.employee" system usage: CPU: user: 0.00 s, system: 0.00 s, elapsed: 0.02 s
Lock Waits
2024-02-12 16:36:26 CET [9501]: [26] user=dbdocs,db=dbdocs,app=DBeaver 7.3.2 - SQLEditor ,client=10.XX.72.XXX LOG: process 9501 still waiting for ShareLock on transaction 1013253691 after 1000.116 ms
Checkpoint
2024-03-24 13:07:20 CET [1822]: [7247] LOG: checkpoint starting: time
2024-03-24 13:07:40 CET [1822]: [7248] LOG: checkpoint complete: wrote 200 buffers (0.1%); 0 WAL file(s) added, 0 removed, 0 recycled; write=20.050 s, sync=0.001 s, total=20.057 s; sync files=125, longest=0.000 s, average=0.000 s; distance=2513 kB, estimate=3055 kB
Connect/Disconnect
2024-03-24 13:10:06 CET [12615]: [1] user=[unknown],db=[unknown],app=[unknown],client=10.XX.102.XX LOG: connection received: host=10.XX.102.XX port=5432
2024-03-24 13:10:06 CET [12615]: [2] user=pgdbdocs,db=postgres,app=[unknown],client=10.XX.102.XX LOG: connection authorized: user=pgdbdocs database=postgres
2024-03-24 13:10:06 CET [12614]: [28] user=pgdbdocs,db=postgres,app=bin/rake,client=10.XX.102.XX LOG: disconnection: session time: 0:00:00.091 user=pgdbdocs database=postgres host=10.XX.102.XX port=5432
Conclusion
By configuring PostgreSQL logging and utilizing pgBadger for analysis, database administrators can significantly improve the performance and reliability of their systems. Proper logging allows for proactive monitoring and troubleshooting, ensuring that the database runs smoothly and efficiently.
Related content