pgCenter’s wait events profiler
As you might know, in the last pgCenter release the new tool has been added — wait events profiler. In this post, I’d like to explore this tool and propose some use-cases for it.
First of all, what are “wait events”? PostgreSQL official documentation doesn’t give an explanation for wait events (it just provides a list of all wait events). In short, wait events are points in time where backends have to wait until a particular event occurs. This may be waiting for obtaining locks, IO, inter-process communication, interacting with client or something else. Stats about wait events are provided by pg_stat_activity view in wait_event_type and wait_event columns.
Using EXPLAIN we always can understand what query does. But EXPLAIN is aimed to work with query planner and doesn’t show time when query got stuck in waitings. For this, you can use pgCenter’s wait events profiler.
How does it work? First, you need to know PID of profiled backend. It can be found using pg_stat_activity, or, if you’re connected to Postgres directly, with pg_backend_pid(). Next, in the second terminal, run ‘pgcenter profile‘ and pass backend PID as an argument. That’s it. pgCenter connects to Postgres and using wait events stats from pg_stat_activity will start collecting data. When query finishes, pgCenter shows you distribution of wait events, like this:
In this example, a massive UPDATE is profiled. The query took around 40 seconds, and most of the time has been spent on reading data from data files. The ‘Running’ entry shows length of the time when query was active doing “real” work. The remaining time was spent doing things related to writing WAL and data files.
Let’s look at the example with VACUUM FULL. Obviously, the majority of the time would be spent on IO blocking.
Another example is parallel query. As you can see 14% of the time is spent on communication between master process and its children. Unfortunately, profile tool doesn’t account wait events of parallel workers because there is no guaranteed way to associate background parallel workers with their master process.
Let me summarize some key points about pgCcenter’s profiler:
- it is there for profiling long queries, completion of which takes seconds;
- it doesn’t count the waiting time of parallel workers.
- internally, it works with pg_stat_activity;
- the texts of long queries may be truncated in the output, because it might break wait events table;
- profiler is configurable, see built-in for help.
This post gave you an overview of the new pgCenter’s wait events profiler that can be used for observing long queries and understanding what they spent their time on. If you haven’t tried it yet, I’d suggest you download pgCenter and try it on your long queries. Let me know what you think!
