From: Jacob Champion <pchampion@vmware.com>
To: michael@paquier.xyz <michael@paquier.xyz>
Cc: magnus@hagander.net <magnus@hagander.net>
Cc: stark@mit.edu <stark@mit.edu>
Cc: pgsql-hackers@postgresql.org <pgsql-hackers@postgresql.org>
Cc: sfrost@snowman.net <sfrost@snowman.net>
Cc: tgl@sss.pgh.pa.us <tgl@sss.pgh.pa.us>
Subject: Re: Proposal: Save user's original authenticated identity for logging
Date: Mon, 29 Mar 2021 23:53:03 +0000
Message-ID: <4a87886f034c713c056c43850f55e6e0ba50d8b5.camel@vmware.com> (raw)
In-Reply-To: <YGGG1jJkkqCvI5pg@paquier.xyz>
References: <65354d28ec024d610ee7fe0128a69075d2092043.camel@vmware.com>
<d88b52ac2539caa7eb28bde6db589926e187ab76.camel@vmware.com>
<YFg2QJolwvV7K33B@paquier.xyz>
<3d0e903ae67cf27240f1c392534951e86c939cb7.camel@vmware.com>
<YFl68dieZi3F4q/N@paquier.xyz>
<4c90814d2f0018ba835c3d8e2eb67b99e6a45578.camel@vmware.com>
<YFwip2On8XmGlfIA@paquier.xyz>
<9f222bb07e711f6f1ffcfcb4fe162d9e84054a1f.camel@vmware.com>
<YF0m4M7Tt4buCNSD@paquier.xyz>
<ce72fb588e21a283fb20789faa4da750fea2975a.camel@vmware.com>
<YGGG1jJkkqCvI5pg@paquier.xyz>
On Mon, 2021-03-29 at 16:50 +0900, Michael Paquier wrote:
> On Fri, Mar 26, 2021 at 10:41:03PM +0000, Jacob Champion wrote:
> > For a few of the bugs I was tracking down, it was imperative. The tests
> > aren't isolated enough (or at all) to keep one from affecting the
> > others.
>
> If the output of the log file is redirected to stderr and truncated,
> while the connection attempts are isolated according to the position
> where the file is truncated, I am not quite sure to follow this line
> of thoughts. What actually happened? Should we make the tests more
> stable instead?
It's not a matter of the tests being stable, but of the tests needing
to change and evolve as the implementation changes. A big part of that
is visibility into what the tests are doing, so that you can debug
them.
I'm sorry I don't have any explicit examples; the NSS work is pretty
broad.
> The kerberos have been running for one week now with
> 11e1577a on HEAD, and look stable so it would be good to be consistent
> on all fronts.
I agree that it would be good in general, as long as the consistency
isn't at the expense of usefulness.
Keep in mind that the rotate-restart-slurp method comes from an
existing test. I assume Andrew chose that method for the same reasons I
did -- it works with what we currently have.
> Hmm, okay. However, I still see a noticeable difference in the tests
> without the additional restarts done so I would rather avoid this
> cost. For example, on my laptop, the restarts make
> authentication/t/001_password.pl last 7s. Truncating the logs without
> any restarts bring the test down to 5.3s so that's 20% faster without
> impacting its coverage.
I agree that it'd be ideal not to have to restart the server. But 20%
of less than ten seconds is less than two seconds, and the test suite
has to run thousands of times to make up a single hour of debugging
time that would be (hypothetically) lost by missing log files. (These
are not easy tests for me to debug and maintain, personally -- maybe
others have a different experience.)
> If you want to keep this information around
> for debugging, I guess that we could just print the contents of the
> backend logs to regress_log_001_password instead? This could be done
> with a simple wrapper routine that prints the past contents of the log
> file before truncating them. I am not sure that we need to stop the
> server while checking for the logs contents either, to start it again
> a bit later in the test while the configuration does not change. that
> costs in speed.
Is the additional effort to create (and maintain) that new system worth
two seconds per run? I feel like it's not -- but if you feel strongly
then I can definitely look into it.
Personally, I'd rather spend time making it easy for tests to get the
log entries associated with a given connection or query. It seems like
every suite has had to cobble together its own method of checking the
log files, with varying levels of success/correctness. Maybe something
with session_preload_libraries and the emit_log_hook? But that would be
a job for a different changeset.
> Causes each attempted connection to the server to be logged,
> - as well as successful completion of client authentication.
> + as well as successful completion of client authentication and authorization.
> I am wondering if this paragraph can be confusing for the end-user
> without more explanation and a link to the "User Name Maps" section,
> and if we actually need this addition at all. The difference is that
> the authenticated log is logged before the authorized log, with user
> name map checks in-between for some of the auth methods. HEAD refers
> to the existing authorized log as "authentication" in the logs, while
> you correct that.
Which parts would you consider confusing/in need of change? I'm happy
to expand where needed. Would an inline sample be more helpful than a
textual explanation?
Thanks again for all the feedback!
--Jacob
Reply instructions:
You may reply publicly to this message via plain-text email
using any one of the following methods:
* Reply to all the recipients using the --to and --cc options:
reply via email
To: pgsql-hackers@postgresql.org
Cc: pchampion@vmware.com, michael@paquier.xyz, magnus@hagander.net, stark@mit.edu, sfrost@snowman.net, tgl@sss.pgh.pa.us
Subject: Re: Proposal: Save user's original authenticated identity for logging
In-Reply-To: <4a87886f034c713c056c43850f55e6e0ba50d8b5.camel@vmware.com>
* Save the following mbox file, import it into your mail client,
and reply-to-all from there: mbox
This inbox is served by DDX for PostgreSQL; see mirroring instructions
for how to clone and mirror all data and code used for this inbox