40.4 log_min_duration_statement: Capturing Slow Queries
Right, let’s talk about finding the slowpokes in your database. You can’t fix what you can’t see, and log_min_duration_statement is your primary spotlight for illuminating the queries that are gumming up the works. It’s a brilliantly simple, brutally effective PostgreSQL setting.
Here’s the deal: you tell PostgreSQL, “Hey, if any query takes longer than this many milliseconds to run, I want you to write the entire thing, plus some crucial details, to the log file.” You’re not sampling; you’re getting a perfect record of every single query that crosses your pain threshold. This is your first and most important line of defense against sluggish performance.
The beauty is in its directness. You’re not asking the database to do expensive profiling on every query; you’re just asking it to note the egregious offenders. The overhead is negligible, which is why you can (and often should) run this in production.
Setting It Up: No Magic, Just Configuration
You don’t need to restart your database for this, which is a godsend. You can set it at the system level, but you can also dial it in for a specific user or database. This is incredibly useful. Maybe you want to log anything over 1 second for your main app database but crank it down to 100ms for your reporting user because those queries should be highly optimized.
You’ll typically set this in postgresql.conf. Let’s say you want to start by catching anything that takes over 2 seconds:
# In postgresql.conf
log_min_duration_statement = 2000
But let’s be real, you’re not restarting your production database right now. Use ALTER SYSTEM to change the config file and then reload.
-- Change the setting in the config file and schedule a reload
ALTER SYSTEM SET log_min_duration_statement = '2000';
-- Then tell the server to reload its configuration (SIGHUP)
SELECT pg_reload_conf();
For more surgical strikes, use ALTER DATABASE or ALTER ROLE:
-- Only log slow queries for the "reporting_user"
ALTER ROLE reporting_user SET log_min_duration_statement = '100';
-- Only log slow queries in the "analytics_db" database
ALTER DATABASE analytics_db SET log_min_duration_statement = '5000';
Reading the Output: It’s Not Just the Query
This is where people often gloss over the details. You set this, see a query in the logs, and think “Aha! I found it!” Slow down. The log entry is a treasure trove of information. It’s not just the SQL.
A typical entry will look something like this (I’ve added line breaks for clarity):
2023-10-27 14:22:01.345 UTC [12345] LOG: duration: 3247.512 ms execute <unnamed>:
SELECT * FROM giant_table WHERE some_column ILIKE '%a very vague search term%';
Let’s break down the clues we get for free:
duration: 3247.512 ms: The exact execution time. This is gold.[12345]: The process ID of the backend that ran this. Useful for connecting it to other diagnostics.execute <unnamed>: This tells you how the query was sent.execute <unnamed>often points to a prepared statement from a client library. If it just shows the SQL directly, it was a simple query.
To get even more information, pair this setting with log_line_prefix to add things like the application name, user, and database. A robust log_line_prefix is like putting a GPS tracker on every query. My preferred setup is:
log_line_prefix = '%t [%p] %u@%d app=%a '
Now your log entry might tell you it was user api_user on database app_db from application puma_5—immediately telling you which part of your stack to go bother.
Choosing Your Threshold: Start Aggressive
The biggest mistake is setting the threshold too high. “Oh, I’ll set it to 10 seconds to start.” No. You’re blind to everything between 0 and 10 seconds. Start aggressively low and dial it up if you get too much log spam.
- Initial Investigation: Set it to
100or250(ms). You’ll be shocked at what you find. Many “fast” applications are riddled with 200ms queries that add up to a terrible user experience. - Production Baseline: Once you’ve squashed the obvious offenders, you might raise it to
1000or2000for ongoing monitoring. The goal is to have your logs be a quiet place, only chirping when something truly bad happens. - The Nuclear Option: Set it to
0. This will log every… single… query. It will crush your disk I/O and is only usable on a low-traffic dev/staging environment for short periods. But when you’re desperate to find that one weird query a specific page is making, it’s a blunt instrument that works.
The Pitfalls: What It Doesn’t Tell You
This setting is brilliant, but it’s not omniscient. You must know its blind spots.
- It Only Logs After Completion: A query that’s stuck in a deadlock and has been running for 10 hours won’t appear here until it finishes. For finding active problems, you need to query
pg_locksandpg_stat_activity. - It Misses Fast Queries Called a Million Times: A 10ms query is “fast.” But if your app calls it 1,000 times per request, that’s 10 seconds of database time. This log won’t flag it. That’s what
pg_stat_statementsis for—it aggregates total time, not individual execution time. - The Parameter Sniffing Problem: The logged query shows the literal text. If you use prepared statements with parameters, you’ll see
$1,$2, etc. This is useless. To fix this, enablelog_parameter_max_lengthorlog_parameter_max_length_on_errorto capture the parameter values that actually caused the slow down. It’s a game-changer for debugging.
So, set it, reload, and start tailing those logs. It’s the closest thing to a free performance audit you’ll ever get. Just remember, the goal isn’t to have a cool log file; it’s to make the log file so boring you forget it’s there.