query that canceled isnt logged
Mariel Cherkassky <[email protected]> Sun, 8 Dec 2019 15:08:27 +0200
| Newsgroups | gmane.comp.db.postgresql.performance |
|---|---|
| Message-ID | <CA+t6e1nYocLRyELmm6VM81JjfwTz_QbkiSJgyUkyDHGd-DFt8A@mail.gmail.com> |
--000000000000313f9c059930fae8 Content-Type: text/plain; charset="UTF-8" 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 ? --000000000000313f9c059930fae8 Content-Type: text/html; charset="UTF-8" Content-Transfer-Encoding: quoted-printable <div dir=3D"rtl"><div dir=3D"ltr">Hey all,</div><div dir=3D"ltr">I'm tr= ying to analyze a weird situation that I have seen in my db.</div><div dir= =3D"ltr">Sometimes my app fails to start because of the following msg :=C2= =A0</div><div dir=3D"ltr">SQL State =C2=A0: null<br>Error Code : 0<br>Messa= ge =C2=A0 =C2=A0: Cannot create PoolableConnectionFactory (ERROR: canceling= statement due to user request)<br></div><div dir=3D"ltr"><br></div><div di= r=3D"ltr">In the db at the same time I saw the same msg :=C2=A0</div><div d= ir=3D"ltr">2019-12-08 00:04:56 IST DB 10035 =C2=A0ERROR: =C2=A0canceling st= atement due to user request<br>2019-12-08 00:04:56 IST DB 10035 =C2=A0STATE= MENT: =C2=A0select 1 as test<br></div><div dir=3D"ltr"><br></div><div dir= =3D"ltr">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 a= s test" to "select pg_sleep(10)" ) the same behavior was rep= roduced .</div><div dir=3D"ltr"><br></div><div dir=3D"ltr"></div><div dir= =3D"ltr">Therefore, my theory was that the validation query is taking more = than 2 seconds.=C2=A0 I decided to log all the statements(log_statements=3D= 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=C2=A0here bec= ause the query is canceled and I wont be able to see its duration..). </div><div dir=3D"ltr"><br></div><div dir=3D"ltr">The weird=C2=A0thing is t= hat I dont see before that error any log message that indicate that the que= ry was running. I hoped to see the following msg in the db log :=C2=A0</div= ><div dir=3D"ltr">2019-12-08 00:04:55 IST DB 2695 =C2=A0LOG: =C2=A0<b>execu= te </b><unnamed>: select 1 as test<br></div><div dir=3D"ltr"><br></di= v><div dir=3D"ltr">but I dont see any execute msg of this query , I just se= e the ERROR msg :=C2=A0</div><div dir=3D"ltr">=C2=A0 2019-12-08 00:04:56 IS= T DB 10035 =C2=A0ERROR: =C2=A0canceling statement due to user request<br>20= 19-12-08 00:04:56 IST DB 10035 =C2=A0STATEMENT: =C2=A0select 1 as test=C2= =A0=C2=A0<br></div><div dir=3D"ltr"><br></div><div dir=3D"ltr">Any idea why= I the query isnt logged but I still get the ERROR msg ?=C2=A0</div></div> --000000000000313f9c059930fae8--