Scaling the Wall of Text: Best Practices for Logging in PostgreSQL

Something that many PostgreSQL users take for granted is the powerful logging features that it provides. With the right configuration, DBAs and sysadmins can quickly diagnose performance, security, and configuration issues, saving precious seconds of application uptime. This talk will cover the major logging parameters in `postgresql.conf`, as well as provide some tips and wisdom gleaned over years of parsing through gigabytes of logs.

Presented at POSETTE on June 11, 2024

Transcript

1. © EnterpriseDB Corporation 2024 - All Rights Reserved Scaling the Wall of Text POSETTE 2024.06.11 Richard Yen Best Practices for Logging in PostgreSQL 1
2. © EnterpriseDB Corporation 2024 - All Rights Reserved 2 • Software Developer/Support Engineer @ EDB since 2015 • Using Postgres to back Golang and Python apps • Perl web developer before getting thrust into a DBA role • Been working with PostgreSQL since 2002 About Me
3. © EnterpriseDB Corporation 2024 - All Rights Reserved Why Logging? 3
4. © EnterpriseDB Corporation 2024 - All Rights Reserved Bad Stuff Happens 4
5. © EnterpriseDB Corporation 2024 - All Rights Reserved Bad Stuff Happens • Who caused it? • What happened? • When did it happen? • Why did it happen? • How did it happen? • How can we prevent it from happening again? 5
6. © EnterpriseDB Corporation 2024 - All Rights Reserved Bad Stuff Happens Configure logging well, and recover quickly 6
7. © EnterpriseDB Corporation 2024 - All Rights Reserved Bad Stuff Happens Configure logging well, and recover quickly 7
8. © EnterpriseDB Corporation 2024 - All Rights Reserved 8 • Query performance is poor • The database crashed • Replication is broken • Some tool or extension is not working • Database is failing to upgrade • and more... Situations Encountered in Support
9. © EnterpriseDB Corporation 2024 - All Rights Reserved 9 • Query timing statistics • Data corruption • Query errors • Maintenance activity • Performance bottlenecks • Access attempts • Cause of a crash • And more! What the log can tell you
10. © EnterpriseDB Corporation 2024 - All Rights Reserved 10 • Where to Log • When to Log • What to Log PostgreSQL Logging Parameters
11. © EnterpriseDB Corporation 2024 - All Rights Reserved 11 • log_destination (stderr, syslog, csvlog, eventlog) • logging_collector (on/off) • log_directory # use a custom partition • log_filename # postgresql-%Y-%m-%d_%H%M%S.log • log_file_mode (0600) • log_rotation_age (1 day) • log_rotation_size (10 MB) • log_truncate_on_rotation (on/off) Where to Log
12. © EnterpriseDB Corporation 2024 - All Rights Reserved 12 • log_min_messages • log_min_error_statement • log_min_duration_statement • Logs queries that are considered "slow" in your application • log_min_duration_sample • log_statement_sample_rate • log_transaction_sample_rate What to Log
13. © EnterpriseDB Corporation 2024 - All Rights Reserved 13 • log_min_messages • log_min_error_statement • DEBUG{5,4,3,2,1} • INFO • NOTICE • WARNING • ERROR • LOG • FATAL • PANIC When to Log 2024-05-23 09:51:51.779 PDT [223363] someuser@my_database FATAL: role "someuser" does not exist 2024-05-23 09:54:50.804 PDT [223395] postgres@postgres WARNING: there is no transaction in progress
14. © EnterpriseDB Corporation 2024 - All Rights Reserved 14 • log_duration • log_statement • Do not confuse with log_min_duration_statement • log_replication_commands • log_line_prefix What to Log
15. © EnterpriseDB Corporation 2024 - All Rights Reserved 15 • log_min_duration_statement • logs the statement and duration AFTER the query has finished • does not log parameters • log_statement • logs the statement BEFORE the query is executed • logs parameters log_min_duration_statement v. log_statement
16. © EnterpriseDB Corporation 2024 - All Rights Reserved log_line_prefix '%m [%p]: [%l] [txid=%x] user=%u,db=%d,app%a,client=%r ' 16
17. © EnterpriseDB Corporation 2024 - All Rights Reserved 17 • Gives greater clarity • Gives you control over filtering, sorting, grouping log_line_prefix
18. © EnterpriseDB Corporation 2024 - All Rights Reserved 18 • As of v.10, defaults to %m [%p] (timestamp + backend PID) • Before v.10, default is blank • ~40% of users keep default • Don't neglect this parameter! log_line_prefix
19. © EnterpriseDB Corporation 2024 - All Rights Reserved 19 2024-02-29 00:11:15.337 UTC [658] LOG: statement: drop table pgbench_accounts; 2024-02-29 00:37:42.796 UTC [5193]: [2] [txid=0] user=bad_user,db=my_database,app[unknown],client=172.17.0.3(44698) LOG: connection authorized: user=bad_user database=my_database 2024-02-29 00:37:42.797 UTC [5193]: [3] [txid=0] user=bad_user,db=my_database,apppsql,client=172.17.0.3(44698) LOG: statement: drop table pgbench_accounts log_line_prefix
20. © EnterpriseDB Corporation 2024 - All Rights Reserved 20 • Logging Levels • Filter by FATAL/WARN/ERROR/ etc. • Hints • Often related to Autovacuum performance issues • Patterns • Unix tools (grep/sed/awk/etc) • Application Bugs • Broken Replication • Replication Slots • wal_keep_segments • Autovacuum • "dead but not yet removable" • Temp Files • work_mem • Lock Waits & Deadlocks • pg_stat_activity What to Look For
21. © EnterpriseDB Corporation 2024 - All Rights Reserved 21 • Be sure to set your log_line_prefix • '%m [%p]: [%l] [txid=%x] user=%u,db=%d,app%a,client=%r ' • Log as much as you can, and use a separate partition if you have to • Monitor for spikes in FATAL/ERROR/WARNING messages • Pay attention to patterns in your logs • Tools like pgbadger and auto_explain can be helpful Summary
22. © EnterpriseDB Corporation 2024 - All Rights Reserved 22 THANK YOU 6