Re: Inconsistency between pg_stat_activity and log_duration - Mailing list pgsql-hackers

From Amit Kapila
Subject Re: Inconsistency between pg_stat_activity and log_duration
Date
Msg-id CAA4eK1+5TysPa-pdoVKkjRJHajVZ0wd6WZfPDQH46SdF9VhNRQ@mail.gmail.com
Whole thread Raw
In response to Re: Inconsistency between pg_stat_activity and log_duration  (Amit Kapila <amit.kapila16@gmail.com>)
List pgsql-hackers
On Fri, Feb 7, 2014 at 10:43 AM, Amit Kapila <amit.kapila16@gmail.com> wrote:
> On Tue, Feb 4, 2014 at 9:36 AM, Tatsuo Ishii <ishii@postgresql.org> wrote:
>> As you can see, at 2014-02-04 12:47:27.210981+09 the query "SELECT
>> count(*) FROM pg_catalog.pg_class..." is "active" and it seems still
>> running.
>>
>> On the other side, Here is an excerpt from PostgreSQL log:
>>
>> 21850 2014-02-04 12:47:11.241 JST LOG:  execute pgpool21805/pgpool21805: SELECT count(*) FROM pg_catalog.pg_class AS
cWHERE c.oid = pgpool_regclass('pgbench_accounts') AND c.relpersistence = 'u'
 
>> 21850 2014-02-04 12:47:11.241 JST LOG:  duration: 0.078 ms
>>
>> The duration was shown as "0.078 ms" thus it seems the query has been
>> already finished.
>>
>> The reason why pg_stat_activity thinks that the query in question is,
>> "sync" message has not been sent to the backend yet (at least from
>> what I read from postgres.c).
>
> I think that is the probable reason for the above mentioned behaviour.

One more catch is that I think it can happen for simple query statements
as well, because we first logs the query end duration and then updates
the state and both are not related in code, so there is always a small
window during which this can happen.

With Regards,
Amit Kapila.
EnterpriseDB: http://www.enterprisedb.com



pgsql-hackers by date:

Previous
From: Amit Kapila
Date:
Subject: Re: Inconsistency between pg_stat_activity and log_duration
Next
From: Hiroshi Inoue
Date:
Subject: Re: narwhal and PGDLLIMPORT