query that canceled isnt logged

From: Mariel Cherkassky <mariel(dot)cherkassky(at)gmail(dot)com>
To: pgsql-performance(at)lists(dot)postgresql(dot)org
Subject: query that canceled isnt logged
Date: 2019-12-08 13:08:27
Message-ID: CA+t6e1nYocLRyELmm6VM81JjfwTz_QbkiSJgyUkyDHGd-DFt8A@mail.gmail.com
Views: Raw Message | Whole Thread | Download mbox | Resend email
Thread:
Lists: pgsql-performance

Hey all,
I'm trying to analyze a weird situation that I have seen in my db.
Sometimes my app fails to start because of the following msg :
SQL State : null
Error Code : 0
Message : Cannot create PoolableConnectionFactory (ERROR: canceling
statement due to user request)

In the db at the same time I saw the same msg :
2019-12-08 00:04:56 IST DB 10035 ERROR: canceling statement due to user
request
2019-12-08 00:04:56 IST DB 10035 STATEMENT: select 1 as test

I thought that it might be related to the validation query that is set to 2
seconds (when I change the validation query from "select 1 as test" to
"select pg_sleep(10)" ) the same behavior was reproduced .

Therefore, my theory was that the validation query is taking more than 2
seconds. I decided to log all the statements(log_statements=all) that are
running in order to see for how long the validation query is running in the
db (log_min_duration_statement wont be helpful here because the query is
canceled and I wont be able to see its duration..).

The weird thing is that I dont see before that error any log message that
indicate that the query was running. I hoped to see the following msg in
the db log :
2019-12-08 00:04:55 IST DB 2695 LOG: *execute *<unnamed>: select 1 as test

but I dont see any execute msg of this query , I just see the ERROR msg :
2019-12-08 00:04:56 IST DB 10035 ERROR: canceling statement due to user
request
2019-12-08 00:04:56 IST DB 10035 STATEMENT: select 1 as test

Any idea why I the query isnt logged but I still get the ERROR msg ?

Responses

Browse pgsql-performance by date

  From Date Subject
Next Message Tom Lane 2019-12-08 15:05:02 Re: query that canceled isnt logged
Previous Message Fahiz Mohamed 2019-12-07 20:05:59 Specific query taking time to process