Fwd: weird long time query

Previous Topic Next Topic
 
classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

Fwd: weird long time query

Kaijiang Chen

I'm using postgres 9.4.17 on centos 7.
I check the running queries with the following SQL:
SELECT
    procpid,  
    start,  
    now() - start AS lap,  
    current_query  
FROM
    (SELECT
        backendid,  
        pg_stat_get_backend_pid(S.backendid) AS procpid,  
        pg_stat_get_backend_activity_start(S.backendid) AS start,  
        pg_stat_get_backend_activity(S.backendid) AS current_query  
    FROM
        (SELECT pg_stat_get_backend_idset() AS backendid) AS S  
    ) AS S  
WHERE
    current_query <> '<IDLE>'
ORDER BY
    lap DESC;

Then, I found a SQL that has run for some days (and still running):
procpid       | 32638
start         | 2019-11-25 16:29:29.529318+08
lap           | 21 days 18:24:54.707369
current_query | DEALLOCATE pdo_stmt_00000388

I tried to kill it with: SELECT pg_cancel_backend(32638) but it takes no effects.

What's this query and what shall I do for it?

I think it is a bug since logically, this query should be gone.

Best Wishes
Kaijiang

Reply | Threaded
Open this post in threaded view
|

Re: Fwd: weird long time query

hubert depesz lubaczewski-2
On Wed, Dec 18, 2019 at 11:25:32AM +0800, Kaijiang Chen wrote:

> I'm using postgres 9.4.17 on centos 7.
> I check the running queries with the following SQL:
> SELECT
>     procpid,
>     start,
>     now() - start AS lap,
>     current_query
> FROM
>     (SELECT
>         backendid,
>         pg_stat_get_backend_pid(S.backendid) AS procpid,
>         pg_stat_get_backend_activity_start(S.backendid) AS start,
>         pg_stat_get_backend_activity(S.backendid) AS current_query
>     FROM
>         (SELECT pg_stat_get_backend_idset() AS backendid) AS S
>     ) AS S
> WHERE
>     current_query <> '<IDLE>'
> ORDER BY
>     lap DESC;
>
> Then, I found a SQL that has run for some days (and still running):
> procpid       | 32638
> start         | 2019-11-25 16:29:29.529318+08
> lap           | 21 days 18:24:54.707369
> current_query | DEALLOCATE pdo_stmt_00000388
>
> I tried to kill it with: SELECT pg_cancel_backend(32638) but it takes no
> effects.
>
> What's this query and what shall I do for it?
>
> I think it is a bug since logically, this query should be gone.

It's not a bug. Most likely this backend is not doing anything.

You're using old way to check if backend is working - current_query <>
'<IDLE>';

Check: select * from pg_stat_activity where pid = 32638

Most likely you'll see state = 'idle'

In such cases, query just shows last executed query, not currently
running one.

Also - WHY are you calling internal pg* functions directly, instead of
using pg_stat_activity view?

Best regards,

depesz



Reply | Threaded
Open this post in threaded view
|

Re: Fwd: weird long time query

Kaijiang Chen
Thanks!
I learn the SQL from the web. pg views should be better.
BTW, I got the similar result (still see that proc) with "select * from pg_stat_activity":

backend_start    | 2019-11-25 16:27:05.103901+08
xact_start       |
query_start      | 2019-11-25 16:29:29.529318+08
state_change     | 2019-11-25 16:29:29.529344+08
waiting          | f
state            | idle
backend_xid      |
backend_xmin     |
query            | DEALLOCATE pdo_stmt_00000388

Looks not very nice :-)

On Wed, Dec 18, 2019 at 10:06 PM hubert depesz lubaczewski <[hidden email]> wrote:
On Wed, Dec 18, 2019 at 11:25:32AM +0800, Kaijiang Chen wrote:
> I'm using postgres 9.4.17 on centos 7.
> I check the running queries with the following SQL:
> SELECT
>     procpid,
>     start,
>     now() - start AS lap,
>     current_query
> FROM
>     (SELECT
>         backendid,
>         pg_stat_get_backend_pid(S.backendid) AS procpid,
>         pg_stat_get_backend_activity_start(S.backendid) AS start,
>         pg_stat_get_backend_activity(S.backendid) AS current_query
>     FROM
>         (SELECT pg_stat_get_backend_idset() AS backendid) AS S
>     ) AS S
> WHERE
>     current_query <> '<IDLE>'
> ORDER BY
>     lap DESC;
>
> Then, I found a SQL that has run for some days (and still running):
> procpid       | 32638
> start         | 2019-11-25 16:29:29.529318+08
> lap           | 21 days 18:24:54.707369
> current_query | DEALLOCATE pdo_stmt_00000388
>
> I tried to kill it with: SELECT pg_cancel_backend(32638) but it takes no
> effects.
>
> What's this query and what shall I do for it?
>
> I think it is a bug since logically, this query should be gone.

It's not a bug. Most likely this backend is not doing anything.

You're using old way to check if backend is working - current_query <>
'<IDLE>';

Check: select * from pg_stat_activity where pid = 32638

Most likely you'll see state = 'idle'

In such cases, query just shows last executed query, not currently
running one.

Also - WHY are you calling internal pg* functions directly, instead of
using pg_stat_activity view?

Best regards,

depesz

Reply | Threaded
Open this post in threaded view
|

Re: Fwd: weird long time query

hubert depesz lubaczewski-2
On Thu, Dec 19, 2019 at 12:14:26AM +0800, Kaijiang Chen wrote:

> Thanks!
> I learn the SQL from the web. pg views should be better.
> BTW, I got the similar result (still see that proc) with "select * from
> pg_stat_activity":
>
> backend_start    | 2019-11-25 16:27:05.103901+08
> xact_start       |
> query_start      | 2019-11-25 16:29:29.529318+08
> state_change     | 2019-11-25 16:29:29.529344+08
> waiting          | f
> state            | idle
> backend_xid      |
> backend_xmin     |
> query            | DEALLOCATE pdo_stmt_00000388
>
> Looks not very nice :-)

not sure what you mean by not nice.

As you can clearly see the backend is *NOT* running anything (state is
idle).

Value in "query" column is simply last query that it ran. It *finished*
running this query at 2019-11-25 16:29:29.529344+08.

So your app is keeping connection open. It's not Pg problem or a bug.

Best regards,

depesz



Reply | Threaded
Open this post in threaded view
|

Re: Fwd: weird long time query

Tom Lane-2
hubert depesz lubaczewski <[hidden email]> writes:
> On Thu, Dec 19, 2019 at 12:14:26AM +0800, Kaijiang Chen wrote:
>> BTW, I got the similar result (still see that proc) with "select * from
>> pg_stat_activity":
>> ...
>> state            | idle
>> ...
>> query            | DEALLOCATE pdo_stmt_00000388
>>
>> Looks not very nice :-)

> not sure what you mean by not nice.

That's a feature not a bug (and yes, the behavior is documented).
People requested that the view continue to display the last query
of an idle session.  IIRC, the main argument was that otherwise
it's hard to tell apart a bunch of idle sessions.

If you don't like it, you can always do something like

case when state = idle then null else query end

                        regards, tom lane