Re: Does export operation cancel SQLs?

[Siraj G <tosiraj.g@xxxxxxxxx>]

Hello Everyone!

I did a little bit of digging in the logs. Here is the observation:

Export start timestamp:

"2025-02-19 05:29:16.911 UTC [675181]: [2-1] db=postgres,user=cloudsqladmin LOG: connection authorized: user=cloudsqladmin database=postgres application_name=pg_dump SSL enabled (protocol=TLSv1.3, cipher=TLS_AES_128_GCM_SHA256, bits=128)"

The process is: 675181

Locks observed:

Soon after I started noticing:

"2025-02-19 05:31:38.856 UTC [663355]: [483-1] db=postgres,user=postgres DETAIL: Process holding the lock: 675181. Wait queue: 663355."

timestamp: "2025-02-19T05:31:38.857111Z"

"2025-02-19 05:32:04.030 UTC [675442]: [22-1] db=postgres,user=postgres DETAIL: Process holding the lock: 675181. Wait queue: 675442, 675407."

timestamp: "2025-02-19T05:32:04.030807Z"

  

Waiting processes get cancelled:

In the case, all the waiting pid (663355, 675442, 675407) got cancelled and the messages are:

textPayload: "2025-02-19 05:32:33.040 UTC [675442]: [30-1] db=postgres,user=postgres ERROR: canceling statement due to user request"

timestamp: "2025-02-19T05:32:33.040612Z"

"2025-02-19 05:32:33.040 UTC [675442]: [31-1] db=postgres,user=postgres STATEMENT: truncate "gcp_dms_fc129ac2e00c01c5"."t_e136e66f7f9bab10_8""

timestamp: "2025-02-19T05:32:33.040645Z"

"2025-02-19 05:32:33.042 UTC [675442]: [32-1] db=postgres,user=postgres LOG: disconnection: session time: 0:00:30.074 user=postgres database=postgres host=[local]"

timestamp: "2025-02-19T05:32:33.042884Z"

On Wed, Feb 19, 2025 at 9:38 PM Jeff Janes <jeff.janes@xxxxxxxxx> wrote:

On Wed, Feb 19, 2025 at 10:43 AM Ron Johnson <ronljohnsonjr@xxxxxxxxx> wrote:

On Wed, Feb 19, 2025 at 10:00 AM Laurenz Albe <laurenz.albe@xxxxxxxxxxx> wrote:

No, that message is from a cancel request, like when you interrupt your
currently running query with Ctrl+C in "psql" or invoke pg_cancel_backend().
PostgreSQL doesn't do that by itself.

The Linux oom killer?  I don't remember the exact error message that PG gives to the user, but ISTR that it's "user request”.  Had to search through /var/log/messages to see that oomkiller was the culprit.

OOM killer kills a process with sig 9.  This reboots the entire cluster, and you would get some variant of "server closed the connection unexpectedly" or "terminating connection because of crash of another server process".  So not a "user request".

Most likely some client (or client library) has an internal timer and cancels its own query after a certain amount of time.  

I know that JDBC's setQueryTimeout operates this way, it sets a client side timeout which then kicks in to cancel the query by "user request".

The server load caused by an export could cause the other queries to run long enough for this logic to kick in, when they otherwise would not.

Cheers,

Jeff