Subject: Re: New Object Access Type hooks

From: Tom Lane <[email-masked]>
Date: Mon, 04 Apr 2022 13:51:13 -0400

I wrote:
> Is our CI setup failing to capture stderr from TAP tests??

Oh, I'm barking up the wrong tree.  This test must have been run
against HEAD between 6da65a3f9 (23 Feb) and 2beb4acff (31 Mar), when
pump_until indeed didn't print this essential information :-(

If you just got this failure, could you look in the log to
see if there's a pump_until report?

			regards, tom lane

---

From: Mark Dilger <[email-masked]>
Date: Mon, 4 Apr 2022 10:56:11 -0700

> On Apr 4, 2022, at 10:51 AM, Tom Lane <[email-masked]> wrote:
> 

I was running `make -j12 check-world` against my local patched version of master:

commit 80399fa5f208c4acd4ec194c47e534ba8dd3ae7c (HEAD -> 0001)
Author: Mark Dilger <[email-masked]>
Date:   Mon Mar 28 13:35:11 2022 -0700

    Allow grant and revoke of privileges on parameters
    
    Add new SET and ALTER SYSTEM privileges for configuration parameters
    (GUCs), and a new catalog, pg_parameter_acl, for tracking grants of
    these privileges.
    
    The privilege to SET a parameter marked USERSET is inherent in that
    parameter's marking and cannot be revoked.  This saves cycles when
    performing SET operations, as looking up privileges in the catalog
    can be skipped.  If we find that administrators need to revoke SET
    privilege on a particular variable from public, that variable can be
    redefined in future releases as SUSET with a default grant of SET to
    PUBLIC issued.

commit 4eb9798879680dcc0e3ebb301cf6f925dfa69422 (origin/master, origin/HEAD, master)
Author: Andrew Dunstan <[email-masked]>
Date:   Mon Apr 4 10:12:30 2022 -0400

    Avoid freeing objects during json aggregate finalization
    
    Commit f4fb45d15c tried to free memory during aggregate finalization.
    This cause issues, particularly when used as a window function, so stop
    doing that.
    
    Per complaint by Jaime Casanova and diagnosis by Andres Freund
    
    Discussion: https://postgr.es/m/YkfeMNYRCGhySKyg@ahch-to

The test logs are attached.

—
Mark Dilger
EnterpriseDB: http://www.enterprisedb.com
The Enterprise PostgreSQL Company

---

From: Tom Lane <[email-masked]>
Date: Mon, 04 Apr 2022 14:07:06 -0400

> The test logs are attached.

Server log looks as-expected:

2022-04-04 09:11:51.087 PDT [2084] 013_crash_restart.pl LOG:  statement: SELECT pg_sleep(3600);
2022-04-04 09:11:51.094 PDT [2083] 013_crash_restart.pl WARNING:  terminating connection because of unexpected SIGQUIT signal
2022-04-04 09:11:51.095 PDT [2070] LOG:  server process (PID 2083) exited with exit code 2
2022-04-04 09:11:51.095 PDT [2070] DETAIL:  Failed process was running: INSERT INTO alive VALUES($$in-progress-before-sigquit$$) RETURNING status;
2022-04-04 09:11:51.095 PDT [2070] LOG:  terminating any other active server processes

I was hoping to see regress_log_013_crash_restart, though.

			regards, tom lane

---

From: Mark Dilger <[email-masked]>
Date: Mon, 4 Apr 2022 11:09:45 -0700

> On Apr 4, 2022, at 11:07 AM, Tom Lane <[email-masked]> wrote:
> 

—
Mark Dilger

---

From: Tom Lane <[email-masked]>
Date: Mon, 04 Apr 2022 15:01:15 -0400

Mark Dilger <[email-masked]> writes:

> # Running: pg_ctl kill QUIT 2083
> ok 4 - killed process with SIGQUIT
> # pump_until: process terminated unexpectedly when searching for "(?^m:WARNING:  terminating connection because of crash of another server process|server closed the connection unexpectedly|connection to server was lost)" with stream: "psql:<stdin>:9: WARNING:  terminating connection because of unexpected SIGQUIT signal
> # psql:<stdin>:9: could not send data to server: Socket is not connected
> # "
> not ok 5 - psql query died successfully after SIGQUIT

And there we have it: the test wasn't updated for the new backend message
spelling, and we're seeing a different frontend behavior.  Evidently the
backend is dying before we're able to send the "SELECT 1;" to it.

I'm not quite sure whether it's a libpq bug that it doesn't produce the
"connection to server was lost" message here, but in any case I suspect
that we shouldn't be checking for the second and third regex alternatives.
The "terminating connection" warning absolutely should get through, and
if it doesn't we want to know about it.  So my proposal for a fix is
to change the regex to be just "WARNING:  terminating connection because
of unexpected SIGQUIT signal".

			regards, tom lane

---

From: Tom Lane <[email-masked]>
Date: Mon, 04 Apr 2022 15:05:10 -0400

I wrote:
> The "terminating connection" warning absolutely should get through,

... oh, no, that's not guaranteed at all, since it's sent from quickdie().
So scratch that.  Maybe we'd better add "could not send data to server"
to the regex?

			regards, tom lane

---

From: Mark Dilger <[email-masked]>
Date: Mon, 4 Apr 2022 13:28:17 -0700

> On Apr 4, 2022, at 12:05 PM, Tom Lane <[email-masked]> wrote:
> 
> I wrote:

If it fails in pqsecure_raw_write(), you get either "server closed the connection unexpectedly" or "could not send data to server".  Do we need to support pgtls_write() or pg_GSS_write(), which have different error messages?  Can anybody run the tests with TLS or GSS enabled?  I assume the test framework prevents this, but I didn't check too closely....

Is it possible that pgFlush will call pqSendSome which calls pqReadData before trying to write anything, and get back a "could not receive data from server" from pqsecure_raw_read()?

It's a bit hard to prove to myself which paths might be followed through this code.  Thoughts?

—
Mark Dilger

---

From: Tom Lane <[email-masked]>
Date: Mon, 04 Apr 2022 16:47:04 -0400

> If it fails in pqsecure_raw_write(), you get either "server closed the connection unexpectedly" or "could not send data to server".  Do we need to support pgtls_write() or pg_GSS_write(), which have different error messages?

Don't see why, since this test sets up a new cluster in which neither
is enabled.

> Is it possible that pgFlush will call pqSendSome which calls pqReadData before trying to write anything, and get back a "could not receive data from server" from pqsecure_raw_read()?

Yeah, it's plausible to get a failure on either the write or read side
depending on timing.

Perhaps libpq should be trying harder to make those cases look alike, but
this test is about server behavior not libpq behavior, so I'm inclined
to just make it lax.

			regards, tom lane

---

From: Mark Dilger <[email-masked]>
Date: Mon, 4 Apr 2022 13:50:40 -0700

> On Apr 4, 2022, at 1:47 PM, Tom Lane <[email-masked]> wrote:
> 

+1.

I've gotten this test failure only a few times in perhaps the last six months, so if we narrow the opportunity for test failure without closing it entirely, we're just making the test failures that much harder to diagnose.

—
Mark Dilger

---

From: Tom Lane <[email-masked]>
Date: Mon, 04 Apr 2022 22:10:50 -0400

> I've gotten this test failure only a few times in perhaps the last six months, so if we narrow the opportunity for test failure without closing it entirely, we're just making the test failures that…

Done that way.

			regards, tom lane