Waiting for 9.2 – split of current_query in pg_stat_activity

On 19t of January, Magnus Hagander committed patch:

Separate state from query string in pg_stat_activity
 
This separates the state (running/idle/idleintransaction etc) into
it's own field ("state"), and leaves the query field containing just
query text.
 
The query text will now mean "current query" when a query is running
and "last query" in other states. Accordingly,the field has been
renamed from current_query to query.
 
Since backwards compatibility was broken anyway to make that, the procpid
field has also been renamed to pid - along with the same field in
pg_stat_replication for consistency.
 
Scott Mead and Magnus Hagander, review work from Greg Smith

This patch is great. And I mean it. The dreaded “<IDLE> in transaction"
connections are constant pain in most applications (of non-trivial size) that
I've seen.

I wrote about them earlier, and I spent countless hours finding clues on what could be the path that lead to it.

And now, thanks to Scott, Magnus and Greg the problem has real possibility to be fixable.

Let's see how it worked previously, and how it works now.

Since I don't have 9.2devel without this patch, I will use 9.1.2 – which should be good enough, as it's the latest released version of PostgreSQL.

I will start two connections. Get their pids, change prompts to show the pids, and run some queries. Let's start:

$ SELECT pg_backend_pid();
 pg_backend_pid
----------------
          16326
(1 ROW)
 
$ \SET PROMPT1 '16326 > '
16326 >

and second connection:

$ SELECT pg_backend_pid();
 pg_backend_pid
----------------
          16966
(1 ROW)
 
$ \SET PROMPT1 '16966 > '
16966 >

Now, I can show the IIT problem in itself:

16326 > BEGIN;
BEGIN
16326 > SELECT pg_sleep(10);

before it stops, I run in second psql:

16966 > SELECT current_query FROM pg_stat_activity WHERE procpid = 16326;
    current_query
----------------------
 SELECT pg_sleep(10);
(1 ROW)

which is great, but when pg_sleep will finish, and first query will end:

 pg_sleep
----------
 
(1 ROW)
 
16326 >

pg_stat_activity value is useless:

16966 > SELECT current_query FROM pg_stat_activity WHERE procpid = 16326;
     current_query
-----------------------
 <IDLE> IN TRANSACTION
(1 ROW)

But, with this new patch, situation is very different:

$ SELECT pg_backend_pid();
 pg_backend_pid
────────────────
           3245
(1 ROW)
 
$ \SET PROMPT1 '3245 > '
3245 > BEGIN;
BEGIN
3245 > SELECT pg_sleep(10);

while it runs, I get from pg_stat_activity:

2340 > SELECT * FROM pg_stat_activity WHERE pid = 3245;
─[ RECORD 1 ]────┬──────────────────────────────
datid            │ 16388
datname          │ depesz
pid              │ 3245
usesysid         │ 16384
usename          │ depesz
application_name │ psql
client_addr      │ [NULL]
client_hostname  │ [NULL]
client_port      │ -1
backend_start    │ 2012-01-22 17:05:30.495627+01
xact_start       │ 2012-01-22 17:06:39.208258+01
query_start      │ 2012-01-22 17:06:42.535464+01
state_change     │ 2012-01-22 17:06:42.535467+01
waiting          │ f
state            │ active
query            │ SELECT pg_sleep(10);

And when it finished:

2340 > SELECT * FROM pg_stat_activity WHERE pid = 3245;
─[ RECORD 1 ]────┬──────────────────────────────
datid            │ 16388
datname          │ depesz
pid              │ 3245
usesysid         │ 16384
usename          │ depesz
application_name │ psql
client_addr      │ [NULL]
client_hostname  │ [NULL]
client_port      │ -1
backend_start    │ 2012-01-22 17:05:30.495627+01
xact_start       │ 2012-01-22 17:06:39.208258+01
query_start      │ 2012-01-22 17:06:42.535464+01
state_change     │ 2012-01-22 17:06:52.537057+01
waiting          │ f
state            │ idle IN TRANSACTION
query            │ SELECT pg_sleep(10);

In the new column, state – i see that connection is in “idle in transaction" state.

But. I also see that last ran query was select pg_sleep(10);. I have also information when the query started ( 17:06:42.535464+01 ) and when it ended ( 17:06:52.537057+01 ).

This also works for normal idle connections:

3245 > SELECT * FROM pg_stat_activity WHERE pid = 2340;
─[ RECORD 1 ]────┬─────────────────────────────────────────────────
datid            │ 16388
datname          │ depesz
pid              │ 2340
usesysid         │ 16384
usename          │ depesz
application_name │ psql
client_addr      │ [NULL]
client_hostname  │ [NULL]
client_port      │ -1
backend_start    │ 2012-01-22 16:53:34.846465+01
xact_start       │ [NULL]
query_start      │ 2012-01-22 17:06:55.396182+01
state_change     │ 2012-01-22 17:06:55.396862+01
waiting          │ f
state            │ idle
query            │ SELECT * FROM pg_stat_activity WHERE pid = 3245;

We see what was the last query, when it started, when it finished.

It is absolutely great. It would be better only if we could have a list/array of all previous queries in transaction, but that can be expensive. Anyway – this patch is a huge help for IIT hunters.

3 thoughts on “Waiting for 9.2 – split of current_query in pg_stat_activity”

  1. yes it is great. its good progress. however i’d like to see more done. the thing that i would really like improving is the waiting column. it would be great to look at this and find out more about what its waiting for rather than getting a t or f. its kinda annoying to go to pg_locks and join with pg_class to get the relation name and get more info. i know i can create a view which would join all these 3 tables to get the kind of output i want, but would be really nice if it would be done in pg_stat_activity itself. just a thought, i dont know what the pg community feels about this.

  2. Since the information about what the query is waiting for can require navigating an entire tree structure to figure out–pg_locks can grow quite complicated in some cases–I don’t see that sort of change ever happening within the pg_stat_activity code. The best we might do is ship with the sort of view you’re describing as a built-in one.

Comments are closed.