Thread: Proposal: Save user's original authenticated identity for logging

Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
Hello all,

First, the context: recently I've been digging into the use of third-
party authentication systems with Postgres. One sticking point is the
need to have a Postgres role corresponding to the third-party user
identity, which becomes less manageable at scale. I've been trying to
come up with ways to make that less painful, and to start peeling off
smaller feature requests.

= Problem =

For auth methods that allow pg_ident mapping, there's a way around the
one-role-per-user problem, which is to have all users that match some
pattern map to a single role. For Kerberos, you might specify that all
user principals under @EXAMPLE.COM are allowed to connect as some
generic user role, and that everyone matching */admin@EXAMPLE.COM is
additionally allowed to connect as an admin role.

Unfortunately, once you've been assigned a role, Postgres either makes
the original identity difficult to retrieve, or forgets who you were
entirely:

- for GSS, the original principal is saved in the Port struct, and you
need to either pull it out of pg_stat_gssapi, or enable log_connections
and piece the log line together with later log entries;
- for LDAP, the bind DN is discarded entirely;
- for TLS client certs, the DN has to be pulled from pg_stat_ssl or the
sslinfo extension (and it's truncated to 64 characters, so good luck if
you have a particularly verbose PKI tree);
- for peer auth, the username of the peereid is discarded;
- etc.

= Proposal =

I propose that every auth method should store the string it uses to
identify a user -- what I'll call an "authenticated identity" -- into
one central location in Port, after authentication succeeds but before
any pg_ident authorization occurs. This field can then be exposed in
log_line_prefix. (It could additionally be exposed through a catalog
table or SQL function, if that were deemed useful.) This would let a
DBA more easily audit user activity when using more complicated
pg_ident setups.

Attached is a proof of concept that implements this for a handful of
auth methods:

- ldap uses the final bind DN as its authenticated identity
- gss uses the user principal
- cert uses the client's Subject DN
- scram-sha-256 just uses the Postgres username

With this patch, the authenticated identity can be inserted into
log_line_prefix using the placeholder %Z.

= Implementation Notes =

- Client certificates can be combined with other authentication methods
using the clientcert option, but that doesn't provide an authenticated
identity in my proposal. *Only* the cert auth method populates the
authenticated identity from a client certificate. This keeps the patch
from having to deal with two simultaneous identity sources.

- The trust auth method has an authenticated identity of NULL, logged
as [unknown]. I kept this property even when clientcert=verify-full is
in use (which would otherwise be identical to the cert auth method), to
hammer home that 1) trust is not an authentication method and 2) the
clientcert option does not provide an authenticated identity. Whether
this is a useful property, or just overly pedantic, is probably
something that could be debated.

- The cert method's Subject DN string formatting needs the same
considerations that are currently under discussion in Andrew's DN patch
[1].

- I'm not crazy about the testing method -- it leads to a lot of log
file proliferation in the tests -- but I wanted to make sure that we
had test coverage for the log lines themselves. The ability to
correctly audit user behavior depends on us logging the correct
identity after authentication, but not a moment before.

Would this be generally useful for those of you using pg_ident in
production? Have I missed something that already provides this
functionality?

Thanks,
--Jacob

[1] 
https://www.postgresql.org/message-id/flat/92e70110-9273-d93c-5913-0bccb6562740@dunslane.net




Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Jacob Champion (pchampion@vmware.com) wrote:
> First, the context: recently I've been digging into the use of third-
> party authentication systems with Postgres. One sticking point is the
> need to have a Postgres role corresponding to the third-party user
> identity, which becomes less manageable at scale. I've been trying to
> come up with ways to make that less painful, and to start peeling off
> smaller feature requests.

Yeah, it'd be nice to improve things in this area.

> = Problem =
>
> For auth methods that allow pg_ident mapping, there's a way around the
> one-role-per-user problem, which is to have all users that match some
> pattern map to a single role. For Kerberos, you might specify that all
> user principals under @EXAMPLE.COM are allowed to connect as some
> generic user role, and that everyone matching */admin@EXAMPLE.COM is
> additionally allowed to connect as an admin role.
>
> Unfortunately, once you've been assigned a role, Postgres either makes
> the original identity difficult to retrieve, or forgets who you were
> entirely:
>
> - for GSS, the original principal is saved in the Port struct, and you
> need to either pull it out of pg_stat_gssapi, or enable log_connections
> and piece the log line together with later log entries;

This has been improved on of late, but it's been done piece-meal.

> - for LDAP, the bind DN is discarded entirely;

We don't support pg_ident.conf-style entries for LDAP, meaning that the
user provided has to match what we check, so I'm not sure what would be
improved with this change..?  I'm also just generally not thrilled with
putting much effort into LDAP as it's a demonstrably insecure
authentication mechanism.

> - for TLS client certs, the DN has to be pulled from pg_stat_ssl or the
> sslinfo extension (and it's truncated to 64 characters, so good luck if
> you have a particularly verbose PKI tree);

Yeah, it'd be nice to improve on this.

> - for peer auth, the username of the peereid is discarded;

Would be good to improve this too.

> = Proposal =
>
> I propose that every auth method should store the string it uses to
> identify a user -- what I'll call an "authenticated identity" -- into
> one central location in Port, after authentication succeeds but before
> any pg_ident authorization occurs. This field can then be exposed in
> log_line_prefix. (It could additionally be exposed through a catalog
> table or SQL function, if that were deemed useful.) This would let a
> DBA more easily audit user activity when using more complicated
> pg_ident setups.

This seems like it would be good to include the CSV format log files
also.

> Would this be generally useful for those of you using pg_ident in
> production? Have I missed something that already provides this
> functionality?

For some auth methods, eg: GSS, we've recently added information into
the authentication method which logs what the authenticated identity
was.  The advantage with that approach is that it avoids bloating the
log by only logging that information once upon connection rather than
on every log line...  I wonder if we should be focusing on a similar
approach for other pg_ident.conf use-cases instead of having it via
log_line_prefix, as the latter means we'd be logging the same value over
and over again on every log line.

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Tom Lane
Date:
Stephen Frost <sfrost@snowman.net> writes:
> * Jacob Champion (pchampion@vmware.com) wrote:
>> I propose that every auth method should store the string it uses to
>> identify a user -- what I'll call an "authenticated identity" -- into
>> one central location in Port, after authentication succeeds but before
>> any pg_ident authorization occurs. This field can then be exposed in
>> log_line_prefix. (It could additionally be exposed through a catalog
>> table or SQL function, if that were deemed useful.) This would let a
>> DBA more easily audit user activity when using more complicated
>> pg_ident setups.

> This seems like it would be good to include the CSV format log files
> also.

What happens if ALTER USER RENAME is done while the session is still
alive?

More generally, exposing this in log_line_prefix seems like an awfully
narrow-minded view of what people will want it for.  I'd personally
think pg_stat_activity a better place to look, for example.

> on every log line...  I wonder if we should be focusing on a similar
> approach for other pg_ident.conf use-cases instead of having it via
> log_line_prefix, as the latter means we'd be logging the same value over
> and over again on every log line.

Yeah, this seems like about the most expensive way that we could possibly
choose to make the info available.

            regards, tom lane



Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-01-29 at 17:01 -0500, Stephen Frost wrote:
> > - for LDAP, the bind DN is discarded entirely;
> 
> We don't support pg_ident.conf-style entries for LDAP, meaning that the
> user provided has to match what we check, so I'm not sure what would be
> improved with this change..?

For simple binds, this gives you almost nothing. For bind+search,
logging the actual bind DN is still important, in my opinion, since the
mechanism for determining it is more opaque (and may change over time).

But as Tom noted -- for both cases, if the role name changes, this
mechanism can still help you audit who the user _actually_ bound as,
not who you think they should have bound as based on their current role
name.

(There's also the fact that I think pg_ident mapping for LDAP would be
just as useful as it is for GSS or certs. That's for a different
conversation.)

> I'm also just generally not thrilled with
> putting much effort into LDAP as it's a demonstrably insecure
> authentication mechanism.

Because Postgres has to proxy the password? Or is there something else?

> > I propose that every auth method should store the string it uses to
> > identify a user -- what I'll call an "authenticated identity" -- into
> > one central location in Port, after authentication succeeds but before
> > any pg_ident authorization occurs. This field can then be exposed in
> > log_line_prefix. (It could additionally be exposed through a catalog
> > table or SQL function, if that were deemed useful.) This would let a
> > DBA more easily audit user activity when using more complicated
> > pg_ident setups.
> 
> This seems like it would be good to include the CSV format log files
> also.

Agreed in principle... Is the CSV format configurable? Forcing it into
CSV logs by default seems like it'd be a hard sell, especially for
people not using pg_ident.

> For some auth methods, eg: GSS, we've recently added information into
> the authentication method which logs what the authenticated identity
> was.  The advantage with that approach is that it avoids bloating the
> log by only logging that information once upon connection rather than
> on every log line...  I wonder if we should be focusing on a similar
> approach for other pg_ident.conf use-cases instead of having it via
> log_line_prefix, as the latter means we'd be logging the same value over
> and over again on every log line.

As long as the identity can be easily logged and reviewed by DBAs, I'm
happy.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-01-29 at 17:30 -0500, Tom Lane wrote:
> What happens if ALTER USER RENAME is done while the session is still
> alive?

IMO the authenticated identity should be write-once. Especially since
one of my goals is to have greater auditability into events as they've
actually happened. So ALTER USER RENAME should have no effect.

This also doesn't really affect third-party auth methods. If I'm bound
as pchampion@EXAMPLE.COM and a superuser changes my username to tlane,
you _definitely_ don't want to see my authenticated identity change to 
tlane@EXAMPLE.COM. That's not who I am.

So the potential confusion would come into play with first-party authn.
From an audit perspective, I think it's worth it. I did authenticate as
pchampion, not tlane.

> More generally, exposing this in log_line_prefix seems like an awfully
> narrow-minded view of what people will want it for.  I'd personally
> think pg_stat_activity a better place to look, for example.
> [...]
> Yeah, this seems like about the most expensive way that we could possibly
> choose to make the info available.

I'm happy as long as it's _somewhere_. :D It's relatively easy to
expose a single location through multiple avenues, but currently there
is no single location.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Tom Lane
Date:
Jacob Champion <pchampion@vmware.com> writes:
> On Fri, 2021-01-29 at 17:30 -0500, Tom Lane wrote:
>> What happens if ALTER USER RENAME is done while the session is still
>> alive?

> IMO the authenticated identity should be write-once. Especially since
> one of my goals is to have greater auditability into events as they've
> actually happened. So ALTER USER RENAME should have no effect.

> This also doesn't really affect third-party auth methods. If I'm bound
> as pchampion@EXAMPLE.COM and a superuser changes my username to tlane,
> you _definitely_ don't want to see my authenticated identity change to 
> tlane@EXAMPLE.COM. That's not who I am.

Ah.  So basically, this comes into play when you consider that some
outside-the-database entity is your "real" authenticated identity.
That seems reasonable when using Kerberos or the like, though it's
not real meaningful for traditional password-type authentication.
I'd misunderstood your point before.

So, if we store this "real" identity, is there any security issue
involved in exposing it to other users (via pg_stat_activity or
whatever)?

I remain concerned about the cost and inconvenience of exposing
it via log_line_prefix, but at least that shouldn't be visible
to anyone who's not entitled to know who's logged in ...

            regards, tom lane



Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-01-29 at 18:40 -0500, Tom Lane wrote:
> Ah.  So basically, this comes into play when you consider that some
> outside-the-database entity is your "real" authenticated identity.
> That seems reasonable when using Kerberos or the like, though it's
> not real meaningful for traditional password-type authentication.

Right.

> So, if we store this "real" identity, is there any security issue
> involved in exposing it to other users (via pg_stat_activity or
> whatever)?

I think that could be a concern for some, yeah. Besides being able to
get information on other logged-in users, the ability to connect an
authenticated identity to a username also gives you some insight into
the pg_hba configuration.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Magnus Hagander
Date:
On Sat, Jan 30, 2021 at 12:40 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Jacob Champion <pchampion@vmware.com> writes:
> > On Fri, 2021-01-29 at 17:30 -0500, Tom Lane wrote:
> >> What happens if ALTER USER RENAME is done while the session is still
> >> alive?
>
> > IMO the authenticated identity should be write-once. Especially since
> > one of my goals is to have greater auditability into events as they've
> > actually happened. So ALTER USER RENAME should have no effect.
>
> > This also doesn't really affect third-party auth methods. If I'm bound
> > as pchampion@EXAMPLE.COM and a superuser changes my username to tlane,
> > you _definitely_ don't want to see my authenticated identity change to
> > tlane@EXAMPLE.COM. That's not who I am.
>
> Ah.  So basically, this comes into play when you consider that some
> outside-the-database entity is your "real" authenticated identity.
> That seems reasonable when using Kerberos or the like, though it's
> not real meaningful for traditional password-type authentication.

I think the usecases where it's relevant is a relatively close match
to the usecases where we support user mapping in pg_ident.conf. There
is a small exception in the ldap search+bind since it's a two-step
operation and the interesting part would be in the mid-step, but I'm
not sure there is any other case than those where it adds a lot of
value.


> I'd misunderstood your point before.
>
> So, if we store this "real" identity, is there any security issue
> involved in exposing it to other users (via pg_stat_activity or
> whatever)?

I'd say it might. It might for example reveal where in a hierarchical
authentication setup your "real identity" lives. I think it'd at least
have to be limited to superusers.


> I remain concerned about the cost and inconvenience of exposing
> it via log_line_prefix, but at least that shouldn't be visible
> to anyone who's not entitled to know who's logged in ...

What if we logged it as part of log_connection=on, but only there and
only once? It could still be traced through the rest of that sessions
logging using the fields identifying the session, and we'd only end up
logging it once.

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/



Re: Proposal: Save user's original authenticated identity for logging

From
Magnus Hagander
Date:
On Sat, Jan 30, 2021 at 12:21 AM Jacob Champion <pchampion@vmware.com> wrote:
>
> On Fri, 2021-01-29 at 17:01 -0500, Stephen Frost wrote:
> > > - for LDAP, the bind DN is discarded entirely;
> >
> > We don't support pg_ident.conf-style entries for LDAP, meaning that the
> > user provided has to match what we check, so I'm not sure what would be
> > improved with this change..?
>
> For simple binds, this gives you almost nothing. For bind+search,
> logging the actual bind DN is still important, in my opinion, since the
> mechanism for determining it is more opaque (and may change over time).

Yeah, that's definitely a piece of information that can be hard to get at today.


> (There's also the fact that I think pg_ident mapping for LDAP would be
> just as useful as it is for GSS or certs. That's for a different
> conversation.)

Specifically for search+bind, I would assume?


> > I'm also just generally not thrilled with
> > putting much effort into LDAP as it's a demonstrably insecure
> > authentication mechanism.
>
> Because Postgres has to proxy the password? Or is there something else?

Stephen is on a bit of a crusade against ldap :) Mostly for good
reasons of course. A large amount of those who choose ldap also have a
kerberos system (because, say, active directory) and the pick ldap
only because they think it's good, not because it is...

But yes, I think the enforced cleartext password proxying is at the
core of the problem. LDAP also encourages the idea of centralized
password-reuse, which is not exactly a great thing for security.

That said, I don't think either of those are reasons not to improve on
LDAP. It can certainly be a reason for somebody not to want to spend
their own time on it, but there's no reason it should prevent
improvements.


> > > I propose that every auth method should store the string it uses to
> > > identify a user -- what I'll call an "authenticated identity" -- into
> > > one central location in Port, after authentication succeeds but before
> > > any pg_ident authorization occurs. This field can then be exposed in
> > > log_line_prefix. (It could additionally be exposed through a catalog
> > > table or SQL function, if that were deemed useful.) This would let a
> > > DBA more easily audit user activity when using more complicated
> > > pg_ident setups.
> >
> > This seems like it would be good to include the CSV format log files
> > also.
>
> Agreed in principle... Is the CSV format configurable? Forcing it into
> CSV logs by default seems like it'd be a hard sell, especially for
> people not using pg_ident.

For CVS, all columns are always included, and that's a feature -- it
makes it predictable.

To make it optional it would have to be a configuration parameter that
turns the field into an empty one. but it should still be there.


> > For some auth methods, eg: GSS, we've recently added information into
> > the authentication method which logs what the authenticated identity
> > was.  The advantage with that approach is that it avoids bloating the
> > log by only logging that information once upon connection rather than
> > on every log line...  I wonder if we should be focusing on a similar
> > approach for other pg_ident.conf use-cases instead of having it via
> > log_line_prefix, as the latter means we'd be logging the same value over
> > and over again on every log line.
>
> As long as the identity can be easily logged and reviewed by DBAs, I'm
> happy.

Yeah, per my previous mail, I think this is a better way - make it
part of log_connections. But it would be good to find a way that we
can log it the same way for all of them -- rather than slightly
different ways depending on authentication method.

With that I think it would also be useful to have it available in the
system as well -- either as a column in pg_stat_activity or maybe just
as a function like pg_get_authenticated_identity() since it might be
something that's interesting to a smallish subset of users (but very
interesting to those).

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/



Re: Proposal: Save user's original authenticated identity for logging

From
Greg Stark
Date:
On Fri, 29 Jan 2021 at 18:41, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Ah.  So basically, this comes into play when you consider that some
> outside-the-database entity is your "real" authenticated identity.
> That seems reasonable when using Kerberos or the like, though it's
> not real meaningful for traditional password-type authentication.
> I'd misunderstood your point before.

I wonder if there isn't room to handle this the other way around. To
configure Postgres to not need a CREATE ROLE for every role but
delegate the user management to the external authentication service.

So Postgres would consider the actual role to be the one kerberos said
it was even if that role didn't exist in pg_role. Presumably you would
want to delegate to a corresponding authorization system as well so if
the role was absent from pg_role (or more likely fit some pattern)
Postgres would ignore pg_role and consult the authorization system
configured like AD or whatever people use with Kerberos these days.


-- 
greg



Re: Proposal: Save user's original authenticated identity for logging

From
Tom Lane
Date:
Magnus Hagander <magnus@hagander.net> writes:
> On Sat, Jan 30, 2021 at 12:40 AM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> I remain concerned about the cost and inconvenience of exposing
>> it via log_line_prefix, but at least that shouldn't be visible
>> to anyone who's not entitled to know who's logged in ...

> What if we logged it as part of log_connection=on, but only there and
> only once? It could still be traced through the rest of that sessions
> logging using the fields identifying the session, and we'd only end up
> logging it once.

I'm certainly fine with including this info in the log_connection output.
Perhaps it'd also be good to have a superuser-only column in
pg_stat_activity, or some other restricted way to get the info from an
existing session.  I doubt we really want a log_line_prefix option.

            regards, tom lane



Re: Proposal: Save user's original authenticated identity for logging

From
Tom Lane
Date:
Greg Stark <stark@mit.edu> writes:
> I wonder if there isn't room to handle this the other way around. To
> configure Postgres to not need a CREATE ROLE for every role but
> delegate the user management to the external authentication service.

> So Postgres would consider the actual role to be the one kerberos said
> it was even if that role didn't exist in pg_role. Presumably you would
> want to delegate to a corresponding authorization system as well so if
> the role was absent from pg_role (or more likely fit some pattern)
> Postgres would ignore pg_role and consult the authorization system
> configured like AD or whatever people use with Kerberos these days.

This doesn't sound particularly workable: how would you manage
inside-the-database permissions?  Kerberos isn't going to know
what "view foo" is, let alone know whether you should be allowed
to read or write it.  So ISTM there has to be a role to hold
those permissions.  Certainly, you could allow multiple external
identities to share a role ... but that works today.

            regards, tom lane



Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Magnus Hagander (magnus@hagander.net) wrote:
> On Sat, Jan 30, 2021 at 12:21 AM Jacob Champion <pchampion@vmware.com> wrote:
> > > I'm also just generally not thrilled with
> > > putting much effort into LDAP as it's a demonstrably insecure
> > > authentication mechanism.
> >
> > Because Postgres has to proxy the password? Or is there something else?

Yes.

> Stephen is on a bit of a crusade against ldap :) Mostly for good
> reasons of course. A large amount of those who choose ldap also have a
> kerberos system (because, say, active directory) and the pick ldap
> only because they think it's good, not because it is...

This is certainly one area of frustration, but even if Kerberos isn't
available, it doesn't make it a good idea to use LDAP.

> But yes, I think the enforced cleartext password proxying is at the
> core of the problem. LDAP also encourages the idea of centralized
> password-reuse, which is not exactly a great thing for security.

Right- passing around a user's password in the clear (or even through an
encrypted tunnel) has been strongly discouraged for a very long time,
for very good reason.  LDAP does double-down on that by being a
centralized password, meaning that someone's entire identity (for all
the services that share that LDAP system, at least) are compromised if
any one system in the environment is.

Ideally, we'd have a 'PasswordAuthentication' option which would
disallow cleartext passwords, as has been discussed elsewhere, which
would make things like ldap and pam auth methods disallowed.

> That said, I don't think either of those are reasons not to improve on
> LDAP. It can certainly be a reason for somebody not to want to spend
> their own time on it, but there's no reason it should prevent
> improvements.

I realize that this isn't a popular opinion, but I'd much rather we
actively move in the direction of deprecating auth methods which use
cleartext passwords.  The one auth method we have that works that way
and isn't terrible is radius, though it also isn't great since the pin
doesn't change and would be compromised, not to mention that it likely
depends on the specific system as to if an attacker might be able to use
the exact same code provided to log into other systems if done fast
enough.

> > > > I propose that every auth method should store the string it uses to
> > > > identify a user -- what I'll call an "authenticated identity" -- into
> > > > one central location in Port, after authentication succeeds but before
> > > > any pg_ident authorization occurs. This field can then be exposed in
> > > > log_line_prefix. (It could additionally be exposed through a catalog
> > > > table or SQL function, if that were deemed useful.) This would let a
> > > > DBA more easily audit user activity when using more complicated
> > > > pg_ident setups.
> > >
> > > This seems like it would be good to include the CSV format log files
> > > also.
> >
> > Agreed in principle... Is the CSV format configurable? Forcing it into
> > CSV logs by default seems like it'd be a hard sell, especially for
> > people not using pg_ident.
>
> For CVS, all columns are always included, and that's a feature -- it
> makes it predictable.
>
> To make it optional it would have to be a configuration parameter that
> turns the field into an empty one. but it should still be there.

Yeah, we've been around this before and, as I recall anyway, there was
actually a prior patch proposed to add this information to the CSV log.
There is the question about if it's valuable enough to repeat on every
line or not.  These days, I think I lean in the same direction as the
majority on this thread that it's sufficient to log as part of the
connection authorized message.

> > > For some auth methods, eg: GSS, we've recently added information into
> > > the authentication method which logs what the authenticated identity
> > > was.  The advantage with that approach is that it avoids bloating the
> > > log by only logging that information once upon connection rather than
> > > on every log line...  I wonder if we should be focusing on a similar
> > > approach for other pg_ident.conf use-cases instead of having it via
> > > log_line_prefix, as the latter means we'd be logging the same value over
> > > and over again on every log line.
> >
> > As long as the identity can be easily logged and reviewed by DBAs, I'm
> > happy.
>
> Yeah, per my previous mail, I think this is a better way - make it
> part of log_connections. But it would be good to find a way that we
> can log it the same way for all of them -- rather than slightly
> different ways depending on authentication method.

+1.

> With that I think it would also be useful to have it available in the
> system as well -- either as a column in pg_stat_activity or maybe just
> as a function like pg_get_authenticated_identity() since it might be
> something that's interesting to a smallish subset of users (but very
> interesting to those).

We've been trending in the direction of having separate functions/views
for the different types of auth, as the specific information you'd want
varies (SSL has a different set than GSS, for example).  Maybe it makes
sense to have the one string that's used to match against in pg_ident
included in pg_stat_activity also but I'm not completely sure- after
all, there's a reason we have the separate views.  Also, if we do add
it, I would think we'd have it under the same check as the other
sensitive pg_stat_activity fields and not be superuser-only.

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Tom Lane (tgl@sss.pgh.pa.us) wrote:
> Greg Stark <stark@mit.edu> writes:
> > I wonder if there isn't room to handle this the other way around. To
> > configure Postgres to not need a CREATE ROLE for every role but
> > delegate the user management to the external authentication service.
>
> > So Postgres would consider the actual role to be the one kerberos said
> > it was even if that role didn't exist in pg_role. Presumably you would
> > want to delegate to a corresponding authorization system as well so if
> > the role was absent from pg_role (or more likely fit some pattern)
> > Postgres would ignore pg_role and consult the authorization system
> > configured like AD or whatever people use with Kerberos these days.
>
> This doesn't sound particularly workable: how would you manage
> inside-the-database permissions?  Kerberos isn't going to know
> what "view foo" is, let alone know whether you should be allowed
> to read or write it.  So ISTM there has to be a role to hold
> those permissions.  Certainly, you could allow multiple external
> identities to share a role ... but that works today.

Agreed- we would need something in the database to tie it to and I don't
see it making much sense to try to invent something else for that when
that's what roles are.  What's been discussed before and would certainly
be nice, however, would be a way to have roles automatically created.
There's pg_ldap_sync for that today but it'd be nice to have something
built-in and which happens at connection/authentication time, or maybe a
background worker that connects to an ldap server and listens for
changes and creates appropriate roles when they're created.  Considering
we've got the LDAP code already, that'd be a really nice capability.

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Tom Lane
Date:
Stephen Frost <sfrost@snowman.net> writes:
> * Tom Lane (tgl@sss.pgh.pa.us) wrote:
>> This doesn't sound particularly workable: how would you manage
>> inside-the-database permissions?  Kerberos isn't going to know
>> what "view foo" is, let alone know whether you should be allowed
>> to read or write it.  So ISTM there has to be a role to hold
>> those permissions.  Certainly, you could allow multiple external
>> identities to share a role ... but that works today.

> Agreed- we would need something in the database to tie it to and I don't
> see it making much sense to try to invent something else for that when
> that's what roles are.  What's been discussed before and would certainly
> be nice, however, would be a way to have roles automatically created.
> There's pg_ldap_sync for that today but it'd be nice to have something
> built-in and which happens at connection/authentication time, or maybe a
> background worker that connects to an ldap server and listens for
> changes and creates appropriate roles when they're created.  Considering
> we've got the LDAP code already, that'd be a really nice capability.

That's still got the same issue though: where does the role get any
permissions from?

I suppose you could say "allow auto-creation of new roles and make them
members of group X", where X holds the permissions that "everybody"
should have.  But I'm not sure how much that buys compared to just
letting everyone log in as X.

            regards, tom lane



Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Tom Lane (tgl@sss.pgh.pa.us) wrote:
> Stephen Frost <sfrost@snowman.net> writes:
> > * Tom Lane (tgl@sss.pgh.pa.us) wrote:
> >> This doesn't sound particularly workable: how would you manage
> >> inside-the-database permissions?  Kerberos isn't going to know
> >> what "view foo" is, let alone know whether you should be allowed
> >> to read or write it.  So ISTM there has to be a role to hold
> >> those permissions.  Certainly, you could allow multiple external
> >> identities to share a role ... but that works today.
>
> > Agreed- we would need something in the database to tie it to and I don't
> > see it making much sense to try to invent something else for that when
> > that's what roles are.  What's been discussed before and would certainly
> > be nice, however, would be a way to have roles automatically created.
> > There's pg_ldap_sync for that today but it'd be nice to have something
> > built-in and which happens at connection/authentication time, or maybe a
> > background worker that connects to an ldap server and listens for
> > changes and creates appropriate roles when they're created.  Considering
> > we've got the LDAP code already, that'd be a really nice capability.
>
> That's still got the same issue though: where does the role get any
> permissions from?
>
> I suppose you could say "allow auto-creation of new roles and make them
> members of group X", where X holds the permissions that "everybody"
> should have.  But I'm not sure how much that buys compared to just
> letting everyone log in as X.

Right, pg_ldap_sync already supports making new roles a member of
another role in PG such as a group role, we'd want to do something
similar.  Also- once the role exists, then permissions could be assigned
directly as well, of course, which would be the advantage of a
background worker that's keeping the set of roles in sync, as the role
would be created at nearly the same time in both the authentication
system itself (eg: AD) and in PG.  That kind of integration exists in
other products and would go a long way to making PG easier to use and
administer.

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Magnus Hagander
Date:
On Mon, Feb 1, 2021 at 6:32 PM Tom Lane <tgl@sss.pgh.pa.us> wrote:
>
> Stephen Frost <sfrost@snowman.net> writes:
> > * Tom Lane (tgl@sss.pgh.pa.us) wrote:
> >> This doesn't sound particularly workable: how would you manage
> >> inside-the-database permissions?  Kerberos isn't going to know
> >> what "view foo" is, let alone know whether you should be allowed
> >> to read or write it.  So ISTM there has to be a role to hold
> >> those permissions.  Certainly, you could allow multiple external
> >> identities to share a role ... but that works today.
>
> > Agreed- we would need something in the database to tie it to and I don't
> > see it making much sense to try to invent something else for that when
> > that's what roles are.  What's been discussed before and would certainly
> > be nice, however, would be a way to have roles automatically created.
> > There's pg_ldap_sync for that today but it'd be nice to have something
> > built-in and which happens at connection/authentication time, or maybe a
> > background worker that connects to an ldap server and listens for
> > changes and creates appropriate roles when they're created.  Considering
> > we've got the LDAP code already, that'd be a really nice capability.
>
> That's still got the same issue though: where does the role get any
> permissions from?
>
> I suppose you could say "allow auto-creation of new roles and make them
> members of group X", where X holds the permissions that "everybody"
> should have.  But I'm not sure how much that buys compared to just
> letting everyone log in as X.

What people would *really* want I think is "alow auto-creation of new
roles, and then look up which other roles they should be members of
using ldap" (or "using this script over here" for a more flexible
approach). Which is of course a whole different thing to do in the
process of authentication.

The main thing you'd gain by auto-creating users rather than just
letting them log in is the ability to know exactly which user did
something, and view who it really is through pg_stat_activity. Adding
the "original auth id" as a field or available method would provide
that information in the mapped user case -- making the difference even
smaller. It's really the auto-membership that's the killer feature of
that one, I think.

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/



Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Sun, 2021-01-31 at 12:27 +0100, Magnus Hagander wrote:
> > (There's also the fact that I think pg_ident mapping for LDAP would be
> > just as useful as it is for GSS or certs. That's for a different
> > conversation.)
> 
> Specifically for search+bind, I would assume?

Even for the simple bind case, I think it'd be useful to be able to
perform a pg_ident mapping of

    ldapmap    /.*    ldapuser

so that anyone who is able to authenticate against the LDAP server is
allowed to assume the ldapuser role. (For this to work, you'd need to
be able to specify your LDAP username as a connection option, similar
to how you can specify a client certificate, so that you could set
PGUSER=ldapuser.)

But again, that's orthogonal to the current discussion.

> With that I think it would also be useful to have it available in the
> system as well -- either as a column in pg_stat_activity or maybe just
> as a function like pg_get_authenticated_identity() since it might be
> something that's interesting to a smallish subset of users (but very
> interesting to those).

Agreed, it would slot in nicely with the other per-backend stats functions.
--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-02-01 at 11:49 -0500, Stephen Frost wrote:
> * Magnus Hagander (magnus@hagander.net) wrote:
> > But yes, I think the enforced cleartext password proxying is at the
> > core of the problem. LDAP also encourages the idea of centralized
> > password-reuse, which is not exactly a great thing for security.
> 
> Right- passing around a user's password in the clear (or even through an
> encrypted tunnel) has been strongly discouraged for a very long time,
> for very good reason.  LDAP does double-down on that by being a
> centralized password, meaning that someone's entire identity (for all
> the services that share that LDAP system, at least) are compromised if
> any one system in the environment is.

Sure. I don't disagree with anything you've said in that paragraph, but
as someone who's implementing solutions for other people who are
actually deploying, I don't have a lot of control over whether a
customer's IT department wants to use LDAP or not. And I'm not holding
my breath for LDAP servers to start implementing federated identity,
though that would be nice.

> Also, if we do add
> it, I would think we'd have it under the same check as the other
> sensitive pg_stat_activity fields and not be superuser-only.

Just the standard HAS_PGSTAT_PERMISSIONS(), then?

To double-check -- since giving this ability to the pg_read_all_stats
role would expand its scope -- could that be dangerous for anyone?

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Jacob Champion (pchampion@vmware.com) wrote:
> On Mon, 2021-02-01 at 11:49 -0500, Stephen Frost wrote:
> > * Magnus Hagander (magnus@hagander.net) wrote:
> > > But yes, I think the enforced cleartext password proxying is at the
> > > core of the problem. LDAP also encourages the idea of centralized
> > > password-reuse, which is not exactly a great thing for security.
> >
> > Right- passing around a user's password in the clear (or even through an
> > encrypted tunnel) has been strongly discouraged for a very long time,
> > for very good reason.  LDAP does double-down on that by being a
> > centralized password, meaning that someone's entire identity (for all
> > the services that share that LDAP system, at least) are compromised if
> > any one system in the environment is.
>
> Sure. I don't disagree with anything you've said in that paragraph, but
> as someone who's implementing solutions for other people who are
> actually deploying, I don't have a lot of control over whether a
> customer's IT department wants to use LDAP or not. And I'm not holding
> my breath for LDAP servers to start implementing federated identity,
> though that would be nice.

Not sure exactly what you're referring to here but AD already provides
Kerberos with cross-domain trusts (aka forests).  The future is here..?
:)

> > Also, if we do add
> > it, I would think we'd have it under the same check as the other
> > sensitive pg_stat_activity fields and not be superuser-only.
>
> Just the standard HAS_PGSTAT_PERMISSIONS(), then?
>
> To double-check -- since giving this ability to the pg_read_all_stats
> role would expand its scope -- could that be dangerous for anyone?

I don't agree that this really expands its scope- in fact, you'll see
that the GSSAPI and SSL user authentication information is already
allowed under HAS_PGSTAT_PERMISSIONS().

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Magnus Hagander
Date:
On Mon, Feb 1, 2021 at 10:36 PM Jacob Champion <pchampion@vmware.com> wrote:
>
> On Sun, 2021-01-31 at 12:27 +0100, Magnus Hagander wrote:
> > > (There's also the fact that I think pg_ident mapping for LDAP would be
> > > just as useful as it is for GSS or certs. That's for a different
> > > conversation.)
> >
> > Specifically for search+bind, I would assume?
>
> Even for the simple bind case, I think it'd be useful to be able to
> perform a pg_ident mapping of
>
>     ldapmap    /.*    ldapuser
>
> so that anyone who is able to authenticate against the LDAP server is
> allowed to assume the ldapuser role. (For this to work, you'd need to
> be able to specify your LDAP username as a connection option, similar
> to how you can specify a client certificate, so that you could set
> PGUSER=ldapuser.)
>
> But again, that's orthogonal to the current discussion.

Right. I guess that's what I mean -- *just* adding support for user
mapping wouldn't be helpful. You'd have to change how the actual
authentication is done. The way that it's done now, mapping makes no
sense.

--
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/



Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-02-01 at 18:44 +0100, Magnus Hagander wrote:
> What people would *really* want I think is "alow auto-creation of new
> roles, and then look up which other roles they should be members of
> using ldap" (or "using this script over here" for a more flexible
> approach). Which is of course a whole different thing to do in the
> process of authentication.

Yep. I think there are at least three separate things:

1) third-party authentication ("tell me who this user is"), which I
think Postgres currently has a fairly good handle on;

2) third-party authorization ("tell me what roles this user can
assume"), which Postgres doesn't do, unless you have a script
automatically update pg_ident -- and even then you can't do it for
every authentication type; and

3) third-party role administration ("tell me what roles should exist in
the database, and what permissions they have"), which currently exists
in a limited handful of third-party tools.

Many users will want all three of these questions to be answered by the
same system, which is fine, but for more advanced use cases I think
it'd be really useful if you could answer them fully independently.

For really gigantic deployments, the overhead of hundreds of Postgres
instances randomly pinging a central server just to see if there have
been any new users can be a concern. Having a solid system for
authorization could potentially decrease the need for a role auto-
creation system, and reduce the number of moving parts. If you have a
small number of core roles (relative to the number of users), it might
not be as important to constantly keep role lists up to date, so long
as the central authority can tell you which of your existing roles a
user is authorized to become.

> The main thing you'd gain by auto-creating users rather than just
> letting them log in is the ability to know exactly which user did
> something, and view who it really is through pg_stat_activity. Adding
> the "original auth id" as a field or available method would provide
> that information in the mapped user case -- making the difference even
> smaller. It's really the auto-membership that's the killer feature of
> that one, I think.

Agreed. As long as it's possible for multiple user identities to assume
the same role, storing the original authenticated identity is still
important, regardless of how you administer the roles themselves.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-02-01 at 17:01 -0500, Stephen Frost wrote:
> * Jacob Champion (pchampion@vmware.com) wrote:
> > And I'm not holding
> > my breath for LDAP servers to start implementing federated identity,
> > though that would be nice.
> 
> Not sure exactly what you're referring to here but AD already provides
> Kerberos with cross-domain trusts (aka forests).  The future is here..?
> :)

If the end user is actually using LDAP-on-top-of-AD, and comfortable
administering the Kerberos-related pieces of AD so that their *nix
servers and users can speak it instead, then sure. But I continue to
hear about customers who don't fit into that mold. :D Enough that I
have to keep an eye on the "pure" LDAP side of things, at least.

> > To double-check -- since giving this ability to the pg_read_all_stats
> > role would expand its scope -- could that be dangerous for anyone?
> 
> I don't agree that this really expands its scope- in fact, you'll see
> that the GSSAPI and SSL user authentication information is already
> allowed under HAS_PGSTAT_PERMISSIONS().

Ah, so they are. :) I think that's the way to go, then.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Jacob Champion (pchampion@vmware.com) wrote:
> On Mon, 2021-02-01 at 17:01 -0500, Stephen Frost wrote:
> > * Jacob Champion (pchampion@vmware.com) wrote:
> > > And I'm not holding
> > > my breath for LDAP servers to start implementing federated identity,
> > > though that would be nice.
> >
> > Not sure exactly what you're referring to here but AD already provides
> > Kerberos with cross-domain trusts (aka forests).  The future is here..?
> > :)
>
> If the end user is actually using LDAP-on-top-of-AD, and comfortable
> administering the Kerberos-related pieces of AD so that their *nix
> servers and users can speak it instead, then sure. But I continue to
> hear about customers who don't fit into that mold. :D Enough that I
> have to keep an eye on the "pure" LDAP side of things, at least.

I suppose it's likely that I'll continue to run into people who are
horrified to learn that they've been using pass-the-password auth thanks
to using ldap.

> > > To double-check -- since giving this ability to the pg_read_all_stats
> > > role would expand its scope -- could that be dangerous for anyone?
> >
> > I don't agree that this really expands its scope- in fact, you'll see
> > that the GSSAPI and SSL user authentication information is already
> > allowed under HAS_PGSTAT_PERMISSIONS().
>
> Ah, so they are. :) I think that's the way to go, then.

Ok..  but what's 'go' mean here?  We already have views and such for GSS
and SSL, is the idea to add another view for LDAP and add in columns
that are returned by pg_stat_get_activity() which are then pulled out by
that view?  Or did you have something else in mind?

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-02-01 at 18:01 -0500, Stephen Frost wrote:
> Ok..  but what's 'go' mean here?  We already have views and such for GSS
> and SSL, is the idea to add another view for LDAP and add in columns
> that are returned by pg_stat_get_activity() which are then pulled out by
> that view?  Or did you have something else in mind?

Magnus suggested a function like pg_get_authenticated_identity(), which
is what I was thinking of when I said that. I'm not too interested in
an LDAP-specific view, and I don't think anyone so far has asked for
that.

My goal is to get this one single point of reference, for all of the
auth backends. The LDAP mapping conversation is separate.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Stephen Frost
Date:
Greetings,

* Jacob Champion (pchampion@vmware.com) wrote:
> On Mon, 2021-02-01 at 18:01 -0500, Stephen Frost wrote:
> > Ok..  but what's 'go' mean here?  We already have views and such for GSS
> > and SSL, is the idea to add another view for LDAP and add in columns
> > that are returned by pg_stat_get_activity() which are then pulled out by
> > that view?  Or did you have something else in mind?
>
> Magnus suggested a function like pg_get_authenticated_identity(), which
> is what I was thinking of when I said that. I'm not too interested in
> an LDAP-specific view, and I don't think anyone so far has asked for
> that.
>
> My goal is to get this one single point of reference, for all of the
> auth backends. The LDAP mapping conversation is separate.

Presumably this would be the DN for SSL then..?  Not just the CN?  How
would the issuer DN be included?  And the serial?

Thanks,

Stephen

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-02-01 at 18:40 -0500, Stephen Frost wrote:
> * Jacob Champion (pchampion@vmware.com) wrote:
> > My goal is to get this one single point of reference, for all of the
> > auth backends. The LDAP mapping conversation is separate.
> 
> Presumably this would be the DN for SSL then..?  Not just the CN?

Correct.

> How would the issuer DN be included?  And the serial?

In the current proposal, they're not. Seems like only the Subject
should be considered when determining the "identity of the user" --
knowing the issuer or the certificate fingerprint might be useful in
general, and perhaps they should be logged somewhere, but they're not
part of the user's identity.

If there were a feature that considered the issuer or serial number
when making role mappings, I think it'd be easier to make a case for
that. As of right now I don't think they should be incorporated into
this *particular* identifier.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Thu, 2021-01-28 at 18:22 +0000, Jacob Champion wrote:
> = Proposal =
> 
> I propose that every auth method should store the string it uses to
> identify a user -- what I'll call an "authenticated identity" -- into
> one central location in Port, after authentication succeeds but before
> any pg_ident authorization occurs.

Thanks everyone for all of the feedback! Here's my summary of the
conversation so far:

- The idea of storing the user's original identity consistently across
all auth methods seemed to be positively received.

- Exposing this identity through log_line_prefix was not as well-
received, landing somewhere between "meh" and "no thanks". The main
concern was log bloat/expense.

- Exposing it through the CSV log got the same reception: if we expose
it through log_line_prefix, we should expose it through CSV, but no one
seemed particularly excited about either.

- The idea of logging this information once per session, as part of
log_connection, got a more positive response. That way the information
can still be obtained, but it doesn't clutter every log line.

- There was also some interest in exposing this through the statistics
collector, either as a superuser-only feature or via the
pg_read_all_stats role.

- There was some discussion around *which* string to choose as the
identifer for more complicated cases, such as TLS client certificates.

- Other improvements around third-party authorization and role
management were discussed, including the ability to auto-create
nonexistent roles, to sync role definitions as a first-party feature,
and to query an external system for role authorization.

(Let me know if there's something else I've missed.)

== My Plans ==

Given the feedback above, I'll continue to flesh out the PoC patch,
focusing on 1) storing the identity in a single place for all auth
methods and 2) exposing it consistently in the logs as part of
log_connections. I'll drop the log_line_prefix format specifier from
the patch and see what that does to the testing side of things. I also
plan to write a follow-up patch to add the authenticated identity to
the statistics collector, with pg_get_authenticated_identity() to
retrieve it.

I'm excited to see where the third-party authz and role management
conversations go, but I won't focus on those for my initial patchset. I
think this patch has use even if those ideas are implemented too.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Tue, 2021-02-02 at 22:22 +0000, Jacob Champion wrote:
> Given the feedback above, I'll continue to flesh out the PoC patch,
> focusing on 1) storing the identity in a single place for all auth
> methods and 2) exposing it consistently in the logs as part of
> log_connections.

Attached is a v1 patchset. Note that I haven't compiled or tested on
Windows and BSD yet, so the SSPI and BSD auth changes are eyeballed for
now.

The first two patches are preparatory, pulled from other threads on the
mailing list: 0001 comes from my Kerberos test fix thread [1], and 0002
is extracted from Andrew Dunstan's patch [2] to store the subject DN
from a client cert. 0003 has the actual implementation, which now fills
in port->authn_id for all auth methods.

Now that we're using log_connections instead of log_line_prefix,
there's more helpful information we can put into the log when
authentication succeeds. For now, I include the identity of the user,
the auth method in use, and the pg_hba.conf file and line number. E.g.

    LOG:  connection received: host=[local]
    LOG:  connection authenticated: identity="pchampion" method=peer (/data/pg_hba.conf:88)
    LOG:  connection authorized: user=admin database=postgres application_name=psql

If the overall direction seems good, then I have two questions:

- Since the authenticated identity is more or less an opaque string
that may come from a third party, should I be escaping it in some way
before it goes into the logs? Or is it generally accepted that log
files can contain arbitrary blobs in unspecified encodings?

- For the SSPI auth method, I pick the format of the identity string
based on the compatibility mode: "DOMAIN\user" when using compat_realm,
and "user@DOMAIN" otherwise. For Windows DBAs, is this a helpful way to
visualize the identity, or should I just stick to one format?

> I also
> plan to write a follow-up patch to add the authenticated identity to
> the statistics collector, with pg_get_authenticated_identity() to
> retrieve it.

This part turned out to be more work than I'd thought! Now I understand
why pg_stat_ssl truncates several fields to NAMEDATALEN.

Has there been any prior discussion on lifting that restriction for the
statistics collector as a whole, before I go down my own path? I can't
imagine taking up another 64 bytes per connection for a field that
won't be useful for the most common use cases -- and yet it still won't
be long enough for other users...

Thanks,
--Jacob

[1] https://www.postgresql.org/message-id/fe7a46f8d46ebb074ba1572d4b5e4af72dc95420.camel%40vmware.com
[2] https://www.postgresql.org/message-id/fd96ae76-a8e3-ef8e-a642-a592f5b76771%40dunslane.net

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-02-08 at 23:35 +0000, Jacob Champion wrote:
> Note that I haven't compiled or tested on
> Windows and BSD yet, so the SSPI and BSD auth changes are eyeballed for
> now.

I've now tested on both.

> - For the SSPI auth method, I pick the format of the identity string
> based on the compatibility mode: "DOMAIN\user" when using compat_realm,
> and "user@DOMAIN" otherwise. For Windows DBAs, is this a helpful way to
> visualize the identity, or should I just stick to one format?

After testing on Windows, I think switching formats based on
compat_realm is a good approach. For users not on a domain, the
MACHINE\user format is probably more familiar than user@MACHINE.
Inversely, users on a domain probably want to see the modern 
user@DOMAIN instead.

v2 just updates the patchset to remove the Windows TODO and fill in the
patch notes; no functional changes. The question about escaping log
contents remains.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Mon, Mar 15, 2021 at 03:50:48PM +0000, Jacob Champion wrote:
>          # might need to retry if logging collector process is slow...
>          my $max_attempts = 180 * 10;
>          my $first_logfile;
>          for (my $attempts = 0; $attempts < $max_attempts; $attempts++)
>          {
>              $first_logfile = slurp_file($node->data_dir . '/' . $lfname);
> -            last if $first_logfile =~ m/\Q$expect_log_msg\E/;
> +
> +            # Don't include previously matched text in the search.
> +            $first_logfile = substr $first_logfile, $current_log_position;
> +            if ($first_logfile =~ m/\Q$expect_log_msg\E/g)
> +            {
> +                $current_log_position += pos($first_logfile);
> +                last;
> +            }
> +
>              usleep(100_000);

Looking at 0001, I am not much a fan of relying on the position of the
matching pattern in the log file.  Instead of relying on the logging
collector and one single file, why not just changing the generation of
the logfile and rely on the output of stderr by restarting the server?
That means less tests, no need to wait for the logging collector to do
its business, and it solves your problem.  Please see the idea with
the patch attached.  Thoughts?
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Thu, Mar 18, 2021 at 05:14:24PM +0900, Michael Paquier wrote:
> Looking at 0001, I am not much a fan of relying on the position of the
> matching pattern in the log file.  Instead of relying on the logging
> collector and one single file, why not just changing the generation of
> the logfile and rely on the output of stderr by restarting the server?
> That means less tests, no need to wait for the logging collector to do
> its business, and it solves your problem.  Please see the idea with
> the patch attached.  Thoughts?

While looking at 0003, I have noticed that the new kerberos tests
actually switch from a logic where one message pattern matches, to a
logic where multiple message patterns match, but I don't see a problem
with what I sent previously, as long as one consume once a log file
and matches all the patterns once, say like the following in
test_access():
    my $first_logfile = slurp_file($node->logfile);

    # Verify specified log messages are logged in the log file.
    while (my $expect_log_msg = shift @expect_log_msgs)
    {
            like($first_logfile, qr/\Q$expect_log_msg\E/,
                 'found expected log file content');
    }

    # Rotate to a new file, for any next check.
    $node->rotate_logfile;
    $node->restart;

A second solution would be a logrotate, relying on the contents of
current_logfiles to know what is the current file, with an extra wait
after $node->logrotate to check if the contents of current_logfiles
have changed.  That's slower for me as this requires a small sleep to
make sure that the new log file name has changed, and I find the
restart solution simpler and more elegant.  Please see the attached
based on HEAD for this logrotate idea.

Jacob, what do you think?
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-03-19 at 17:21 +0900, Michael Paquier wrote:
> On Thu, Mar 18, 2021 at 05:14:24PM +0900, Michael Paquier wrote:
> > Looking at 0001, I am not much a fan of relying on the position of the
> > matching pattern in the log file.  Instead of relying on the logging
> > collector and one single file, why not just changing the generation of
> > the logfile and rely on the output of stderr by restarting the server?

For getting rid of the logging collector logic, this is definitely an
improvement. It was briefly discussed in [1] but I never got around to
trying it; thanks!

One additional improvement I would suggest, now that the rotation logic
is simpler than it was in my original patch, is to rotate the logfile
regardless of whether the test is checking the logs or not. (Similarly,
we can manually rotate after the block of test_query() calls.) That way
it's harder to match the last test's output.

> While looking at 0003, I have noticed that the new kerberos tests
> actually switch from a logic where one message pattern matches, to a
> logic where multiple message patterns match, but I don't see a problem
> with what I sent previously, as long as one consume once a log file
> and matches all the patterns once, say like the following in
> test_access():

The tradeoff is that if you need to check for log message order, or for
multiple instances of overlapping patterns, you still need some sort of
search-forward functionality. But looking over the tests, I don't see
any that truly *need* that yet. It's nice that the current patchset
enforces an "authenticated" line before an "authorized" line, but I
think it's nicer to not have the extra code.

I'll incorporate this approach into the patchset. Thanks!

--Jacob

[1] https://www.postgresql.org/message-id/f1fd9ccaf7ffb2327bf3c06120afeadd50c1db97.camel%40vmware.com

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-03-19 at 16:54 +0000, Jacob Champion wrote:
> One additional improvement I would suggest, now that the rotation logic
> is simpler than it was in my original patch, is to rotate the logfile
> regardless of whether the test is checking the logs or not. (Similarly,
> we can manually rotate after the block of test_query() calls.) That way
> it's harder to match the last test's output.

The same effect can be had by moving the log rotation to the top of the
test that needs it, so I've done it that way in v7.

> The tradeoff is that if you need to check for log message order, or for
> multiple instances of overlapping patterns, you still need some sort of
> search-forward functionality.

Turns out it's easy now to have our cake and eat it too; a single if
statement can implement the same search-forward functionality that was
spread across multiple places before. So I've done that too.

Much nicer, thank you for the suggestion!

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Fri, Mar 19, 2021 at 06:37:05PM +0000, Jacob Champion wrote:
> The same effect can be had by moving the log rotation to the top of the
> test that needs it, so I've done it that way in v7.

After thinking more about 0001, I have come up with an even simpler
solution that has resulted in 11e1577.  That's similar to what
PostgresNode::issues_sql_like() does.  This also makes 0003 simpler
with its changes as this requires to change two lines in test_access.

> Turns out it's easy now to have our cake and eat it too; a single if
> statement can implement the same search-forward functionality that was
> spread across multiple places before. So I've done that too.

I have briefly looked at 0002 (0001 in the attached set), and it seems
sane to me.  I still need to look at 0003 (well, now 0002) in details,
which is very sensible as one mistake would likely be a CVE-class
bug.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Magnus Hagander
Date:
On Mon, Mar 22, 2021 at 7:16 AM Michael Paquier <michael@paquier.xyz> wrote:
>
> On Fri, Mar 19, 2021 at 06:37:05PM +0000, Jacob Champion wrote:
> > The same effect can be had by moving the log rotation to the top of the
> > test that needs it, so I've done it that way in v7.
>
> After thinking more about 0001, I have come up with an even simpler
> solution that has resulted in 11e1577.  That's similar to what
> PostgresNode::issues_sql_like() does.  This also makes 0003 simpler
> with its changes as this requires to change two lines in test_access.

Man that renumbering threw me off :)


> > Turns out it's easy now to have our cake and eat it too; a single if
> > statement can implement the same search-forward functionality that was
> > spread across multiple places before. So I've done that too.
>
> I have briefly looked at 0002 (0001 in the attached set), and it seems
> sane to me.  I still need to look at 0003 (well, now 0002) in details,
> which is very sensible as one mistake would likely be a CVE-class
> bug.

The 0002/0001/whateveritisaftertherebase is tracked over at
https://www.postgresql.org/message-id/flat/92e70110-9273-d93c-5913-0bccb6562740@dunslane.net
isn't it? I've assumed the expectation is to have that one committed
from that thread, and then rebase using that.

-- 
 Magnus Hagander
 Me: https://www.hagander.net/
 Work: https://www.redpill-linpro.com/



Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-03-22 at 18:22 +0100, Magnus Hagander wrote:
> On Mon, Mar 22, 2021 at 7:16 AM Michael Paquier <michael@paquier.xyz> wrote:
> > 
> > I have briefly looked at 0002 (0001 in the attached set), and it seems
> > sane to me.  I still need to look at 0003 (well, now 0002) in details,
> > which is very sensible as one mistake would likely be a CVE-class
> > bug.
> 
> The 0002/0001/whateveritisaftertherebase is tracked over at
>
https://nam04.safelinks.protection.outlook.com/?url=https%3A%2F%2Fwww.postgresql.org%2Fmessage-id%2Fflat%2F92e70110-9273-d93c-5913-0bccb6562740%40dunslane.net&data=04%7C01%7Cpchampion%40vmware.com%7Cd085c1e56ff045c7af3308d8ed57279a%7Cb39138ca3cee4b4aa4d6cd83d9dd62f0%7C0%7C0%7C637520305878415422%7CUnknown%7CTWFpbGZsb3d8eyJWIjoiMC4wLjAwMDAiLCJQIjoiV2luMzIiLCJBTiI6Ik1haWwiLCJXVCI6Mn0%3D%7C1000&sdata=kyW9O1jD0z14z0rC%2BYY9UhIKb7D6bg0nCWoVBJkF8oQ%3D&reserved=0
> isn't it? I've assumed the expectation is to have that one committed
> from that thread, and then rebase using that.

I think the primary thing that needs to be greenlit for both is the
idea of using the RFC 2253/4514 format for Subject DNs.

Other than that, the version here should only contain the changes
necessary for both features (that is, port->peer_dn), so there's no
hard dependency between the two. It's just on me to make sure my
version is up-to-date. Which I believe it is, as of today.

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-03-22 at 15:16 +0900, Michael Paquier wrote:
> On Fri, Mar 19, 2021 at 06:37:05PM +0000, Jacob Champion wrote:
> > The same effect can be had by moving the log rotation to the top of the
> > test that needs it, so I've done it that way in v7.
> 
> After thinking more about 0001, I have come up with an even simpler
> solution that has resulted in 11e1577.  That's similar to what
> PostgresNode::issues_sql_like() does.  This also makes 0003 simpler
> with its changes as this requires to change two lines in test_access.
v8's test_access lost the in-order log search from v7; I've added it
back in v9. The increased resistance to entropy seems worth the few
extra lines. Thoughts?

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Mon, Mar 22, 2021 at 07:17:26PM +0000, Jacob Champion wrote:
> v8's test_access lost the in-order log search from v7; I've added it
> back in v9. The increased resistance to entropy seems worth the few
> extra lines. Thoughts?

I am not really sure that we need to bother about the ordering of the
entries here, as long as we check for all of them within the same
fragment of the log file, so I would just go down to the simplest
solution that I posted upthread that is enough to make sure that the
verbosity is protected.  That's what we do elsewhere, like with
command_checks_all() and such.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Mon, Mar 22, 2021 at 06:22:52PM +0100, Magnus Hagander wrote:
> The 0002/0001/whateveritisaftertherebase is tracked over at
> https://www.postgresql.org/message-id/flat/92e70110-9273-d93c-5913-0bccb6562740@dunslane.net
> isn't it? I've assumed the expectation is to have that one committed
> from that thread, and then rebase using that.

Independent and useful pieces could just be extracted and applied
separately where it makes sense.  I am not sure if that's the case
here, so I'll do a patch_to_review++.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Tue, 2021-03-23 at 14:21 +0900, Michael Paquier wrote:
> I am not really sure that we need to bother about the ordering of the
> entries here, as long as we check for all of them within the same
> fragment of the log file, so I would just go down to the simplest
> solution that I posted upthread that is enough to make sure that the
> verbosity is protected.  That's what we do elsewhere, like with
> command_checks_all() and such.
With low-coverage test suites, I think it's useful to allow as little
strange behavior as possible -- in this case, printing authorization
before authentication could signal a serious bug -- but I don't feel
too strongly about it.

v10 attached, which reverts to v8 test behavior, with minor updates to
the commit message and test comment.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Wed, Mar 24, 2021 at 04:45:35PM +0000, Jacob Champion wrote:
> With low-coverage test suites, I think it's useful to allow as little
> strange behavior as possible -- in this case, printing authorization
> before authentication could signal a serious bug -- but I don't feel
> too strongly about it.

I got to look at the DN patch yesterday, so now's the turn of this
one.  Nice work.

+ * Sets the authenticated identity for the current user. The provided string
+ * will be copied into the TopMemoryContext. The ID will be logged if
+ * log_connections is enabled.
[...]
+   port->authn_id = MemoryContextStrdup(TopMemoryContext, id);
It may not be obvious that all the field is copied to TopMemoryContext
because the Port requires that.

+$node->stop('fast');
+my $log_contents = slurp_file($log);
Like 11e1577, let's just truncate the log files in all those tests.

+   if (auth_method < 0 || USER_AUTH_LAST < auth_method)
+   {
+       Assert((0 <= auth_method) && (auth_method <= USER_AUTH_LAST));
What's the point of having the check and the assertion?  NULL does not
really seem like a good default here as this should never really
happen.  Wouldn't a FATAL be actually safer?

+like(
+   $log_contents,
+   qr/connection authenticated: identity="ssltestuser"
method=scram-sha-256/,
+   "Basic SCRAM sets the username as the authenticated identity");
+
+$node->start;
It looks wrong to me to include in the SSL tests some checks related
to SCRAM authentication.  This should remain in 001_password.pl, as of
src/test/authentication/.

    port->gss->princ = MemoryContextStrdup(TopMemoryContext, port->gbuf.value);
+   set_authn_id(port, gbuf.value);
I don't think that this position is right for GSSAPI.  Shouldn't this
be placed at the end of pg_GSS_checkauth() and only if the status is
OK?

-   ret = check_usermap(port->hba->usermap, port->user_name, peer_user, false);
-
-   pfree(peer_user);
+   ret = check_usermap(port->hba->usermap, port->user_name, port->authn_id, false);
I would also put this one after checking the usermap for peer.

+   /*
+    * We have all of the information necessary to construct the authenticated
+    * identity.
+    */
+   if (port->hba->compat_realm)
+   {
+       /* SAM-compatible format. */
+       authn_id = psprintf("%s\\%s", domainname, accountname);
+   }
+   else
+   {
+       /* Kerberos principal format. */
+       authn_id = psprintf("%s@%s", accountname, domainname);
+   }
+
+   set_authn_id(port, authn_id);
+   pfree(authn_id);
For SSPI, I think that this should be moved down once we are sure that
there is no error and that pg_SSPI_recvauth() reports STATUS_OK to the
caller.  There is a similar issue with CheckCertAuth(), and
set_authn_id() is documented so as it should be called only when we
are sure that authentication succeeded.

Reading through the thread, the consensus is to add the identity
information with log_connections.  One question I have is that if we
just log the information with log_connectoins, there is no real reason
to add this information to the Port, except the potential addition of
some system function, a superuser-only column in pg_stat_activity or
to allow extensions to access this information.  I am actually in
favor of keeping this information in the Port with those pluggability
reasons.  How do others feel about that?
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Thu, 2021-03-25 at 14:41 +0900, Michael Paquier wrote:
> I got to look at the DN patch yesterday, so now's the turn of this
> one.  Nice work.

Thanks!

> +   port->authn_id = MemoryContextStrdup(TopMemoryContext, id);
> It may not be obvious that all the field is copied to TopMemoryContext
> because the Port requires that.

I've expanded the comment. (v11 attached, with incremental changes over
v10 in since-v10.diff.txt.)

> +$node->stop('fast');
> +my $log_contents = slurp_file($log);
> Like 11e1577, let's just truncate the log files in all those tests.

Hmm... having the full log file contents for the SSL tests has been
incredibly helpful for me with the NSS work. I'd hate to lose them; it
can be very hard to recreate the test conditions exactly.

> +   if (auth_method < 0 || USER_AUTH_LAST < auth_method)
> +   {
> +       Assert((0 <= auth_method) && (auth_method <= USER_AUTH_LAST));
> What's the point of having the check and the assertion?  NULL does not
> really seem like a good default here as this should never really
> happen.  Wouldn't a FATAL be actually safer?

I think FATAL makes more sense. Changed, thanks.

> It looks wrong to me to include in the SSL tests some checks related
> to SCRAM authentication.  This should remain in 001_password.pl, as of
> src/test/authentication/.

Agreed. Moved the bad-password SCRAM tests over, and removed the
duplicates. The last SCRAM test in that file, which tests the
interaction between client certificates and SCRAM auth, remains.

>     port->gss->princ = MemoryContextStrdup(TopMemoryContext, port->gbuf.value);
> +   set_authn_id(port, gbuf.value);
> I don't think that this position is right for GSSAPI.  Shouldn't this
> be placed at the end of pg_GSS_checkauth() and only if the status is
> OK?

No, and the tests will catch you if you try. Authentication happens
before authorization (user mapping), and can succeed independently even
if authz doesn't. See below.

> For SSPI, I think that this should be moved down once we are sure that
> there is no error and that pg_SSPI_recvauth() reports STATUS_OK to the
> caller.  There is a similar issue with CheckCertAuth(), and
> set_authn_id() is documented so as it should be called only when we
> are sure that authentication succeeded.

Authentication *has* succeeded already; that's what the SSPI machinery
has done above. Likewise for CheckCertAuth, which relies on the TLS
subsystem to validate the client signature before setting the peer_cn.
The user mapping is an authorization concern: it answers the question,
"is an authenticated user allowed to use a particular Postgres user
name?"

Postgres currently conflates authn and authz in many places, and in my
experience, that'll make it difficult to maintain new authorization
features like the ones in the wishlist upthread. This patch is only one
step towards a clearer distinction.

> I am actually in
> favor of keeping this information in the Port with those pluggability
> reasons.

That was my intent, yeah. Getting this into the stats framework was
more than I could bite off for this first patchset, but having it
stored in a central location will hopefully help people do more with
it.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Thu, Mar 25, 2021 at 06:51:22PM +0000, Jacob Champion wrote:
> On Thu, 2021-03-25 at 14:41 +0900, Michael Paquier wrote:
>> +   port->authn_id = MemoryContextStrdup(TopMemoryContext, id);
>> It may not be obvious that all the field is copied to TopMemoryContext
>> because the Port requires that.
>
> I've expanded the comment. (v11 attached, with incremental changes over
> v10 in since-v10.diff.txt.)

That's the addition of "to match the lifetime of the Port".  Looks
good.

>> +$node->stop('fast');
>> +my $log_contents = slurp_file($log);
>> Like 11e1577, let's just truncate the log files in all those tests.
>
> Hmm... having the full log file contents for the SSL tests has been
> incredibly helpful for me with the NSS work. I'd hate to lose them; it
> can be very hard to recreate the test conditions exactly.

Does it really matter to have the full contents of the file from the
previous tests though?  like() would report the contents of
slurp_file() when it fails if the generated output does not match the
expected one, so you actually get less noise this way.

>> +   if (auth_method < 0 || USER_AUTH_LAST < auth_method)
>> +   {
>> +       Assert((0 <= auth_method) && (auth_method <= USER_AUTH_LAST));
>> What's the point of having the check and the assertion?  NULL does not
>> really seem like a good default here as this should never really
>> happen.  Wouldn't a FATAL be actually safer?
>
> I think FATAL makes more sense. Changed, thanks.

Thanks.  FWIW, one worry I had here was a corrupted stack that calls
this code path that would remain undetected.

>> For SSPI, I think that this should be moved down once we are sure that
>> there is no error and that pg_SSPI_recvauth() reports STATUS_OK to the
>> caller.  There is a similar issue with CheckCertAuth(), and
>> set_authn_id() is documented so as it should be called only when we
>> are sure that authentication succeeded.
>
> Authentication *has* succeeded already; that's what the SSPI machinery
> has done above. Likewise for CheckCertAuth, which relies on the TLS
> subsystem to validate the client signature before setting the peer_cn.
> The user mapping is an authorization concern: it answers the question,
> "is an authenticated user allowed to use a particular Postgres user
> name?"

Okay.  Could you make the comments in those various areas more
explicit about the difference and that it is intentional to register
the auth ID before checking the user map?  Anybody reading this code
in the future may get confused with the differences in handling all
that according to the auth type involved if that's not clearly
stated.

> That was my intent, yeah. Getting this into the stats framework was
> more than I could bite off for this first patchset, but having it
> stored in a central location will hopefully help people do more with
> it.

No problem with that.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-03-26 at 09:12 +0900, Michael Paquier wrote:
> Does it really matter to have the full contents of the file from the
> previous tests though?

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. And if the test is written incorrectly, or becomes incorrect
due to implementation changes, then the log files are really the only
way to debug after a false positive -- with truncation, the bad test
succeeds incorrectly and then swallows the evidence. :)

> Could you make the comments in those various areas more
> explicit about the difference and that it is intentional to register
> the auth ID before checking the user map?  Anybody reading this code
> in the future may get confused with the differences in handling all
> that according to the auth type involved if that's not clearly
> stated.

I took a stab at this in v12, attached.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
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?  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.

> And if the test is written incorrectly, or becomes incorrect
> due to implementation changes, then the log files are really the only
> way to debug after a false positive -- with truncation, the bad test
> succeeds incorrectly and then swallows the evidence. :)

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.  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.

>> Could you make the comments in those various areas more
>> explicit about the difference and that it is intentional to register
>> the auth ID before checking the user map?  Anybody reading this code
>> in the future may get confused with the differences in handling all
>> that according to the auth type involved if that's not clearly
>> stated.
>
> I took a stab at this in v12, attached.

This part looks good, thanks!

         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.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
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

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Mon, Mar 29, 2021 at 11:53:03PM +0000, Jacob Champion wrote:
> 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.

Sure, but I still don't quite see why this applies here?  At the point
of any test, like() or unlink() print the contents of the comparison
if there is a failure, so there is no actual loss of data.  That's
what issues_sql_like() does, for one.

> I'm sorry I don't have any explicit examples; the NSS work is pretty
> broad.

Yeah, I saw that..

> 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.

PostgresNode::rotate_logfile got introduced in c098509, and it is just
used in t/017_shm.pl on HEAD.  There could be more simplifications
with 019_replslot_limit.pl, I certainly agree with that.

> 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.)
>
> 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.

I fear that heavily parallelized runs could feel the difference.  Ask
Andres about that, he has been able to trigger in parallel a failure
with pg_upgrade wiping out testtablespace while the main regression
test suite just began :)

> 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.

Maybe.

>>          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?

That's with the use of "authentication and authorization".  How can
users make the difference between what one or this other is without
some explanation with the name maps?  It seems that there is no place
in the existing docs where this difference is explained.  I am
wondering if it would be better to not change this paragraph, or
reword it slightly to outline that this may cause more than one log
entry, say:
"Causes each attempted connection to the server, and each
authentication activity to be logged."
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Tue, 2021-03-30 at 09:55 +0900, Michael Paquier wrote:
> On Mon, Mar 29, 2021 at 11:53:03PM +0000, Jacob Champion wrote:
> > 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.
> 
> Sure, but I still don't quite see why this applies here?  At the point
> of any test, like() or unlink() print the contents of the comparison
> if there is a failure, so there is no actual loss of data.  That's
> what issues_sql_like() does, for one.

The key there is "if there is a failure" -- false positives need to be
debugged too. Tests I've worked with recently for the NSS work were
succeeding for the wrong reasons. Overly generic logfile matches ("SSL
error"), for example.

> > 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.
> 
> PostgresNode::rotate_logfile got introduced in c098509, and it is just
> used in t/017_shm.pl on HEAD.  There could be more simplifications
> with 019_replslot_limit.pl, I certainly agree with that.

modules/ssl_passphrase_callback/t/001_testfunc.pl is where I pulled
this pattern from.

> > 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.
> 
> I fear that heavily parallelized runs could feel the difference.  Ask
> Andres about that, he has been able to trigger in parallel a failure
> with pg_upgrade wiping out testtablespace while the main regression
> test suite just began :) 

Does unilateral log truncation play any nicer with parallel test runs?
I understand not wanting to make an existing problem worse, but it
doesn't seem like the existing tests were written for general
parallelism.

Would it be acceptable to adjust the tests for live rotation using the
logging collector, rather than a full restart? It would unfortunately
mean that we have to somehow wait for the rotation to complete, since
that's asynchronous.

(Speaking of asynchronous: how does the existing check-and-truncate
code make sure that the log entries it's looking for have been flushed
to disk? Shutting down the server guarantees it.)

> > 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?
> 
> That's with the use of "authentication and authorization".  How can
> users make the difference between what one or this other is without
> some explanation with the name maps?  It seems that there is no place
> in the existing docs where this difference is explained.  I am
> wondering if it would be better to not change this paragraph, or
> reword it slightly to outline that this may cause more than one log
> entry, say:
> "Causes each attempted connection to the server, and each
> authentication activity to be logged."

I took a stab at this in v13: "Causes each attempted connection to the
server to be logged, as well as successful completion of both client
authentication (if necessary) and authorization." (IMO any further in-
depth explanation of authn/z and user mapping probably belongs in the
auth method documentation, and this patch doesn't change any authn/z
behavior.)

v13 also incorporates the latest SSL cert changes, so it's just a
single patch now. Tests now cover the CN and DN clientname modes. I
have not changed the log capture method yet; I'll take a look at it
next.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Tue, 2021-03-30 at 17:06 +0000, Jacob Champion wrote:
> Would it be acceptable to adjust the tests for live rotation using the
> logging collector, rather than a full restart? It would unfortunately
> mean that we have to somehow wait for the rotation to complete, since
> that's asynchronous.

I wasn't able to make live rotation work in a sane way. So, v14 tries
to thread the needle with a riff on your earlier idea:

> 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.

Rather than putting Postgres log data into the Perl logs, I rotate the
logs exactly once at the beginning -- so that there's an
old 001_ssltests_primary.log, and a new 001_ssltests_primary_1.log --
and then every time we truncate the logfile, I shuffle the bits from
the new logfile into the old one. So no one has to learn to find the
log entries in a new place, we don't get an explosion of rotated logs,
we don't lose the log data, we don't match incorrect portions of the
logs, and we only pay the restart price once. This is wrapped into a
small Perl module, LogCollector.

WDYT?

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Tue, Mar 30, 2021 at 05:06:51PM +0000, Jacob Champion wrote:
> The key there is "if there is a failure" -- false positives need to be
> debugged too. Tests I've worked with recently for the NSS work were
> succeeding for the wrong reasons. Overly generic logfile matches ("SSL
> error"), for example.

Indeed, so that's a test stability issue.  It looks like a good idea
to make those tests more picky with the sub-errors they expect.  I see
most "certificate verify failed" a lot, two "sslv3 alert certificate
revoked" and one "tlsv1 alert unknown ca" with 1.1.1, but it is not
something that this patch has to address IMO.

> modules/ssl_passphrase_callback/t/001_testfunc.pl is where I pulled
> this pattern from.

I see.  For this case, I see no issue as the input caught is from
_PG_init() so that seems better than a wait on the logs generated.

> Does unilateral log truncation play any nicer with parallel test runs?
> I understand not wanting to make an existing problem worse, but it
> doesn't seem like the existing tests were written for general
> parallelism.

TAP tests running in parallel use their own isolated backend, wiht
dedicated paths and ports.

> Would it be acceptable to adjust the tests for live rotation using the
> logging collector, rather than a full restart? It would unfortunately
> mean that we have to somehow wait for the rotation to complete, since
> that's asynchronous.
>
> (Speaking of asynchronous: how does the existing check-and-truncate
> code make sure that the log entries it's looking for have been flushed
> to disk? Shutting down the server guarantees it.)

stderr redirection looks to be working pretty well with
issues_sql_like().

> I took a stab at this in v13: "Causes each attempted connection to the
> server to be logged, as well as successful completion of both client
> authentication (if necessary) and authorization." (IMO any further in-
> depth explanation of authn/z and user mapping probably belongs in the
> auth method documentation, and this patch doesn't change any authn/z
> behavior.)
>
> v13 also incorporates the latest SSL cert changes, so it's just a
> single patch now. Tests now cover the CN and DN clientname modes. I
> have not changed the log capture method yet; I'll take a look at it
> next.

Thanks, I am looking into that and I am digging into the code now.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Tue, Mar 30, 2021 at 11:15:48PM +0000, Jacob Champion wrote:
> Rather than putting Postgres log data into the Perl logs, I rotate the
> logs exactly once at the beginning -- so that there's an
> old 001_ssltests_primary.log, and a new 001_ssltests_primary_1.log --
> and then every time we truncate the logfile, I shuffle the bits from
> the new logfile into the old one. So no one has to learn to find the
> log entries in a new place, we don't get an explosion of rotated logs,
> we don't lose the log data, we don't match incorrect portions of the
> logs, and we only pay the restart price once. This is wrapped into a
> small Perl module, LogCollector.

Hmm.  I have dug today into that and I am really not convinced that
this is necessary, as a connection attempt combined with the output
sent to stderr gives you the stability needed.  If we were to have
anything like that, perhaps a sub-class of PostgresNode would be
adapted instead, with an internal log integration.

After thinking about it, the new wording in config.sgml looks fine
as-is.

Anyway, I have not been able to convince myself that we need those
slowdowns and that many server restarts as there is no
reload-dependent timing here, and things have been stable on
everything I have tested (including a slow RPI).  I have found a
couple of things that can be simplified in the tests:
- In src/test/authentication/, except for the trust method where there
is no auth ID, all the other tests wrap a like() if $res == 0, or
unlike() otherwise.  I think that it is cleaner to make the matching
pattern an argument of test_role(), and adapt the tests to that.
- src/test/ldap/ can also embed a single logic within test_access().
- src/test/ssl/ is a different beast, but I think that there is more
refactoring possible here in parallel of the recent work I have sent
to have equivalents of test_connect_ok() and test_connect_fails() in
PostgresNode.pm.  For now, I think that we should just live in this
set with a small routine able to check for pattern matches in the
logs.

Attached is an updated patch, with a couple of comments tweaks, the
reworked tests and an indentation done.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Wed, Mar 31, 2021 at 04:42:32PM +0900, Michael Paquier wrote:
> Attached is an updated patch, with a couple of comments tweaks, the
> reworked tests and an indentation done.

Jacob has mentioned me that v15 has some false positives in the SSL
tests, as we may catch in the backend logs patterns that come from
a previous test.  We should really make that stuff more robust by
design, or it will bite hard with some bugs remaining undetected while
the tests pass.  This stuff can take advantage of 0d1a3343, and I
think that we should make the kerberos, ldap, authentication and SSL
test suites just use connect_ok() and connect_fails() from
PostgresNode.pm.  They just need to be extended a bit with a new
argument for the log pattern check.  This has the advantage to
centralize in a single code path the log file truncation (or some log
file rotation if the logging collector is used).
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Thu, 2021-04-01 at 10:21 +0900, Michael Paquier wrote:
> This stuff can take advantage of 0d1a3343, and I
> think that we should make the kerberos, ldap, authentication and SSL
> test suites just use connect_ok() and connect_fails() from
> PostgresNode.pm.  They just need to be extended a bit with a new
> argument for the log pattern check.

v16, attached, migrates all tests in those suites to connect_ok/fails
(in the first two patches), and also adds the log pattern matching (in
the final feature patch).

A since-v15 diff is attached, but it should be viewed with suspicion
since I've rebased on top of the new SSL tests at the same time.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Fri, Apr 02, 2021 at 12:03:21AM +0000, Jacob Champion wrote:
> On Thu, 2021-04-01 at 10:21 +0900, Michael Paquier wrote:
> > This stuff can take advantage of 0d1a3343, and I
> > think that we should make the kerberos, ldap, authentication and SSL
> > test suites just use connect_ok() and connect_fails() from
> > PostgresNode.pm.  They just need to be extended a bit with a new
> > argument for the log pattern check.
>
> v16, attached, migrates all tests in those suites to connect_ok/fails
> (in the first two patches), and also adds the log pattern matching (in
> the final feature patch).

Thanks.  I have been looking at 0001 and 0002, and found the addition
of %params to connect_ok() and connect_fails() confusing first, as
this is only required for the 12th test of 001_password.pl (failure to
grab a password for md5_role not located in a pgpass file with
PGPASSWORD not set).  Instead of falling into a trap where the tests
could remain stuck, I think that we could just pass down -w from
connect_ok() and connect_fails() to PostgresNode::psql.

This change made also the parameter handling of the kerberos tests
more confusing on two points:
- PostgresNode::psql uses a query as an argument, so there was a mix
between the query passed down within the set of parameters, but then
removed from the list.
- PostgresNode::psql uses already -XAt so there is no need to define
it again.

> A since-v15 diff is attached, but it should be viewed with suspicion
> since I've rebased on top of the new SSL tests at the same time.

That did not seem that suspicious to me ;)

Anyway, after looking at 0003, the main patch, it becomes quite clear
that the need to match logs depending on like() or unlike() is much
more elegant once we have use of parameters in connect_ok() and
connect_fails(), but I think that it is a mistake to pass down blindly
the parameters to psql and delete some of them on the way while
keeping the others.  The existing code of HEAD only requires a SQL
query or some expected stderr or stdout output, so let's make all
that parameterized first.

Attached is what I have come up with as the first building piece,
which is basically a combination of 0001 and 0002, except that I
modified things so as the number of arguments remains minimal for all
the routines.  This avoids the manipulation of the list of parameters
passed down to PostgresNode::psql. The arguments for the optional
query, the expected stdout and stderr are part of the parameter set
(0001 was not doing that).  For the main patch, this will need to be
extended with two more parameters in each routine: log_like and
log_unlike to match for the log patterns, handled as arrays of
regexes.  That's what 0003 is basically doing already.

As a whole, this is a consolidation of its own, so let's apply this
part first.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Fri, 2021-04-02 at 13:45 +0900, Michael Paquier wrote:
> Attached is what I have come up with as the first building piece,
> which is basically a combination of 0001 and 0002, except that I
> modified things so as the number of arguments remains minimal for all
> the routines.  This avoids the manipulation of the list of parameters
> passed down to PostgresNode::psql. The arguments for the optional
> query, the expected stdout and stderr are part of the parameter set
> (0001 was not doing that).

I made a few changes, highlighted in the since-v18 diff:

> +        # The result is assumed to match "true", or "t", here.
> +        $node->connect_ok($connstr, $test_name, sql => $query,
> +                  expected_stdout => qr/t/);

I've anchored this as qr/^t$/ so we don't accidentally match a stray
"t" in some larger string.

> -    is($res, 0, $test_name);
> -    like($stdoutres, $expected, $test_name);
> -    is($stderrres, "", $test_name);
> +    my ($stdoutres, $stderrres);
> +
> +    $node->connect_ok($connstr, $test_name, $query, $expected);

$query and $expected need to be given as named parameters. We also lost
the stderr check from the previous version of the test, so I added
expected_stderr to connect_ok().

> @@ -446,14 +446,14 @@ TODO:
>      # correct client cert in encrypted PEM with empty password
>      $node->connect_fails(
>          "$common_connstr user=ssltestuser sslcert=ssl/client.crt sslkey=ssl/client-encrypted-pem_tmp.key
sslpassword=''",
> -        qr!\Qprivate key file "ssl/client-encrypted-pem_tmp.key": processing error\E!,
> +        expected_stderr => qr!\Qprivate key file "ssl/client-encrypted-pem_tmp.key": processing error\E!,
>          "certificate authorization fails with correct client cert and empty password in encrypted PEM format"
>      );

These tests don't run yet inside the TODO block, but I've put the
expected_stderr parameter at the end of the list for them.

> For the main patch, this will need to be
> extended with two more parameters in each routine: log_like and
> log_unlike to match for the log patterns, handled as arrays of
> regexes.  That's what 0003 is basically doing already.

Rebased on top of your patch as v19, attached. (v17 disappeared into
the ether somewhere, I think. :D)

Now that it's easy to add log_like to existing tests, I fleshed out the
LDAP tests with a few more cases. They don't add code coverage, but
they pin the desired behavior for a few more types of LDAP auth.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Fri, Apr 02, 2021 at 01:45:31PM +0900, Michael Paquier wrote:
> As a whole, this is a consolidation of its own, so let's apply this
> part first.

Slight rebase for this one to take care of the updates with the SSL
error messages.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Sat, Apr 03, 2021 at 09:30:25PM +0900, Michael Paquier wrote:
> Slight rebase for this one to take care of the updates with the SSL
> error messages.

I have been looking again at that and applied it as c50624cd after
some slight modifications.  Attached is the main, refactored, patch
that plugs on top of the existing infrastructure.  connect_ok() and
connect_fails() gain two parameters each to match or to not match the
logs of the backend, with a truncation of the logs done before any
connection attempt.

I have spent more time reviewing the backend code while on it and
there was one thing that stood out:
+       ereport(FATAL,
+               (errmsg("connection was re-authenticated"),
+                errdetail_log("previous ID: \"%s\"; new ID: \"%s\"",
+                              port->authn_id, id)));
This message would not actually trigger because auth_failed() is the
code path in charge of showing an error here, so this could just be
replaced by an assertion on authn_id being NULL?  The contents of this
log were a bit in contradiction with the comments a couple of lines
above anyway.  Jacob, what do you think?
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Mon, 2021-04-05 at 14:47 +0900, Michael Paquier wrote:
> On Sat, Apr 03, 2021 at 09:30:25PM +0900, Michael Paquier wrote:
> > Slight rebase for this one to take care of the updates with the SSL
> > error messages.
> 
> I have been looking again at that and applied it as c50624cd after
> some slight modifications.

This loses the test fixes I made in my v19 [1]; some of the tests on
HEAD aren't testing anything anymore. I've put those fixups into 0001,
attached.

> Attached is the main, refactored, patch
> that plugs on top of the existing infrastructure.  connect_ok() and
> connect_fails() gain two parameters each to match or to not match the
> logs of the backend, with a truncation of the logs done before any
> connection attempt.

It looks like this is a reimplementation of v19, but it loses the
additional tests I wrote? Not sure. Maybe my v19 was sent to spam?

In any case I have attached my Friday patch as 0002.

> I have spent more time reviewing the backend code while on it and
> there was one thing that stood out:
> +       ereport(FATAL,
> +               (errmsg("connection was re-authenticated"),
> +                errdetail_log("previous ID: \"%s\"; new ID: \"%s\"",
> +                              port->authn_id, id)));
> This message would not actually trigger because auth_failed() is the
> code path in charge of showing an error here

It triggers just fine for me (you can duplicate one of the
set_authn_id() calls to see):

    FATAL:  connection was re-authenticated
    DETAIL:  previous ID: "uid=test2,dc=example,dc=net"; new ID: "uid=test2,dc=example,dc=net"

> so this could just be
> replaced by an assertion on authn_id being NULL?

An assertion seems like the wrong way to go; in the event that a future
code path accidentally performs a duplicated authentication, the FATAL
will just kill off an attacker's connection, while an assertion will
DoS the server.

> The contents of this
> log were a bit in contradiction with the comments a couple of lines
> above anyway.

What do you mean by this? I took another look at the comment and it
seems to match the implementation.

v21 attached, which is just a rebase of my original v19.

--Jacob

[1] https://www.postgresql.org/message-id/8c08c6402051b5348d599c0e07bbd83f8614fa16.camel%40vmware.com

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Mon, Apr 05, 2021 at 04:40:41PM +0000, Jacob Champion wrote:
> This loses the test fixes I made in my v19 [1]; some of the tests on
> HEAD aren't testing anything anymore. I've put those fixups into 0001,
> attached.

Argh, Thanks.  The part about not checking after the error output when
the connection should pass is wanted to be more consistent with the
other test suites.  So I have removed this part and applied the rest
of 0001.

> It looks like this is a reimplementation of v19, but it loses the
> additional tests I wrote? Not sure.

So, what you have here are three extra tests for ldap with
search+bind and search filters.  This looks like a good idea.

> Maybe my v19 was sent to spam?

Indeed.  All those messages are finishing in my spam folder.  I am
wondering why actually.  That's a bit surprising.

> It triggers just fine for me (you can duplicate one of the
> set_authn_id() calls to see):
>
>     FATAL:  connection was re-authenticated
>     DETAIL:  previous ID: "uid=test2,dc=example,dc=net"; new ID: "uid=test2,dc=example,dc=net"

Hmm.  It looks like I did something wrong here.

> An assertion seems like the wrong way to go; in the event that a future
> code path accidentally performs a duplicated authentication, the FATAL
> will just kill off an attacker's connection, while an assertion will
> DoS the server.

Hmm.  You are making a good point here, but is that really the best
thing we can do?  We lose the context of the authentication type being
done with this implementation, and the client would know that it did a
re-authentication even if the logdetail goes only to the backend's
logs.  Wouldn't it be better, for instance, to generate a LOG message
in this code path, switch to STATUS_ERROR to let auth_failed()
generate the FATAL message?  set_authn_id() could just return a
boolean to tell if it was OK with the change in authn_id or not.

> v21 attached, which is just a rebase of my original v19.

This requires a perltidy run from what I can see, but that's no big
deal.

+   my (@log_like, @log_unlike);
+   if (defined($params{log_like}))
+   {
+       @log_like = @{ delete $params{log_like} };
+   }
+   if (defined($params{log_unlike}))
+   {
+       @log_unlike = @{ delete $params{log_unlike} };
+   }
There is no need for that?  This removal was done as %params was
passed down directly as-is to PostgresNode::psql, but that's not the
case anymore.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Tue, 2021-04-06 at 14:15 +0900, Michael Paquier wrote:
> On Mon, Apr 05, 2021 at 04:40:41PM +0000, Jacob Champion wrote:
> > This loses the test fixes I made in my v19 [1]; some of the tests on
> > HEAD aren't testing anything anymore. I've put those fixups into 0001,
> > attached.
> 
> Argh, Thanks.  The part about not checking after the error output when
> the connection should pass is wanted to be more consistent with the
> other test suites.  So I have removed this part and applied the rest
> of 0001.

I assumed Tom added those checks to catch a particular failure mode for
the GSS encryption case. (I guess Tom would know for sure.)

> > An assertion seems like the wrong way to go; in the event that a future
> > code path accidentally performs a duplicated authentication, the FATAL
> > will just kill off an attacker's connection, while an assertion will
> > DoS the server.
> 
> Hmm.  You are making a good point here, but is that really the best
> thing we can do?  We lose the context of the authentication type being
> done with this implementation, and the client would know that it did a
> re-authentication even if the logdetail goes only to the backend's
> logs.  Wouldn't it be better, for instance, to generate a LOG message
> in this code path, switch to STATUS_ERROR to let auth_failed()
> generate the FATAL message?  set_authn_id() could just return a
> boolean to tell if it was OK with the change in authn_id or not. 

My concern there is that we already know the code is wrong in this
(hypothetical future) case, and then we'd be relying on that wrong code
to correctly bubble up an error status. I think that, once you hit this
code path, the program flow should be interrupted immediately -- do not
pass Go, collect $200, or let the bad implementation continue to do
more damage.

I agree that losing the context is not ideal. To avoid that, I thought
it might be nice to add errbacktrace() to the ereport() call -- but
since the functions we're interested in are static, the backtrace
doesn't help. (I should check to see whether libbacktrace is better in
this situation. Later.)

As for the client knowing: an active attacker is probably going to know
that they're triggering the reauthentication anyway. So the primary
disadvantage I see is that a more passive attacker could scan for some
vulnerability by looking for that error message.

If that's a major concern, we could call auth_failed() directly from
this code. But that means that the auth_failed() logic must not give
them more ammunition, in this hypothetical scenario where the authn
system is already messed up. Obscuring the failure mode helps buy
people time to update Postgres, which definitely has value, but it
won't prevent any actual exploit by the time we get to this check. A
tricky trade-off.

> > v21 attached, which is just a rebase of my original v19.
> 
> This requires a perltidy run from what I can see, but that's no big
> deal.

Is that done per-patch? It looks like there's a large amount of
untidied code in src/test in general, and in the files being touched.

> +   my (@log_like, @log_unlike);
> +   if (defined($params{log_like}))
> +   {
> +       @log_like = @{ delete $params{log_like} };
> +   }
> +   if (defined($params{log_unlike}))
> +   {
> +       @log_unlike = @{ delete $params{log_unlike} };
> +   }
> There is no need for that?  This removal was done as %params was
> passed down directly as-is to PostgresNode::psql, but that's not the
> case anymore.

Fixed in v22, thanks.

--Jacob

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Tue, Apr 06, 2021 at 06:31:16PM +0000, Jacob Champion wrote:
> On Tue, 2021-04-06 at 14:15 +0900, Michael Paquier wrote:
> > Hmm.  You are making a good point here, but is that really the best
> > thing we can do?  We lose the context of the authentication type being
> > done with this implementation, and the client would know that it did a
> > re-authentication even if the logdetail goes only to the backend's
> > logs.  Wouldn't it be better, for instance, to generate a LOG message
> > in this code path, switch to STATUS_ERROR to let auth_failed()
> > generate the FATAL message?  set_authn_id() could just return a
> > boolean to tell if it was OK with the change in authn_id or not.
>
> My concern there is that we already know the code is wrong in this
> (hypothetical future) case, and then we'd be relying on that wrong code
> to correctly bubble up an error status. I think that, once you hit this
> code path, the program flow should be interrupted immediately -- do not
> pass Go, collect $200, or let the bad implementation continue to do
> more damage.

Sounds fair to me.

> I agree that losing the context is not ideal. To avoid that, I thought
> it might be nice to add errbacktrace() to the ereport() call -- but
> since the functions we're interested in are static, the backtrace
> doesn't help. (I should check to see whether libbacktrace is better in
> this situation. Later.)

Perhaps, but that does not seem strongly necessary to me either here.

> If that's a major concern, we could call auth_failed() directly from
> this code. But that means that the auth_failed() logic must not give
> them more ammunition, in this hypothetical scenario where the authn
> system is already messed up. Obscuring the failure mode helps buy
> people time to update Postgres, which definitely has value, but it
> won't prevent any actual exploit by the time we get to this check. A
> tricky trade-off.

Nah.  I don't like much a solution that involves calling auth_failed()
in more code paths than now.

>> This requires a perltidy run from what I can see, but that's no big
>> deal.
>
> Is that done per-patch? It looks like there's a large amount of
> untidied code in src/test in general, and in the files being touched.

Committers take care of that usually, but if you can do it that
helps :)

From what I can see, most of the indent diffs are coming from the
tests added with the addition of the log_(un)like parameters.  See
pgindent's README for all the details related to the version of
perltidy, for example.  The trick is that some previous patches may
not have been indented, causing the apparitions of extra diffs
unrelated to a patch.  Usually that's easy enough to fix on a
file-basis.

Anyway, using a FATAL in this code path is fine by me at the end, so I
have applied the patch.  Let's see now what the buildfarm thinks about
it.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Wed, 2021-04-07 at 10:20 +0900, Michael Paquier wrote:
> Anyway, using a FATAL in this code path is fine by me at the end, so I
> have applied the patch.  Let's see now what the buildfarm thinks about
> it.

Looks like the farm has gone green, after some test fixups. Thanks for
all the reviews!

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Tue, Apr 13, 2021 at 03:47:21PM +0000, Jacob Champion wrote:
> Looks like the farm has gone green, after some test fixups. Thanks for
> all the reviews!

You may want to follow this thread as well, as the topic is related to
what has been discussed on this thread as there is an impact in a
different code path for the TAP tests, and not only the connection
tests:
https://www.postgresql.org/message-id/YHajnhcMAI3++pJL@paquier.xyz
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Peter Eisentraut
Date:
On 03.04.21 14:30, Michael Paquier wrote:
> On Fri, Apr 02, 2021 at 01:45:31PM +0900, Michael Paquier wrote:
>> As a whole, this is a consolidation of its own, so let's apply this
>> part first.
> 
> Slight rebase for this one to take care of the updates with the SSL
> error messages.

I noticed this patch eliminated one $Test::Builder::Level assignment. 
Was there a reason for this?

I think we should add it back, and also add a few missing ones in 
similar places.  See attached patch.

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Wed, Sep 22, 2021 at 08:59:38AM +0200, Peter Eisentraut wrote:
> I noticed this patch eliminated one $Test::Builder::Level assignment. Was
> there a reason for this?
>
> I think we should add it back, and also add a few missing ones in similar
> places.  See attached patch.
>
> [...]
>
>  {
> +    local $Test::Builder::Level = $Test::Builder::Level + 1;
> +

So you are referring to this one removed in c50624c.  In what does
this addition change things compared to what has been added in
connect_ok() and connect_fails()?  I am pretty sure that I have
removed this one because this logic got refactored in
PostgresNode.pm.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Peter Eisentraut
Date:
On 22.09.21 09:39, Michael Paquier wrote:
> On Wed, Sep 22, 2021 at 08:59:38AM +0200, Peter Eisentraut wrote:
>> I noticed this patch eliminated one $Test::Builder::Level assignment. Was
>> there a reason for this?
>>
>> I think we should add it back, and also add a few missing ones in similar
>> places.  See attached patch.
>>
>> [...]
>>
>>   {
>> +    local $Test::Builder::Level = $Test::Builder::Level + 1;
>> +
> 
> So you are referring to this one removed in c50624c.  In what does
> this addition change things compared to what has been added in
> connect_ok() and connect_fails()?  I am pretty sure that I have
> removed this one because this logic got refactored in
> PostgresNode.pm.

This should be added to each level of a function call that represents a 
test.  This ensures that when a test fails, the line number points to 
the top-level location of the test_role() call.  Otherwise it would 
point to the connect_ok() call inside test_role().



Re: Proposal: Save user's original authenticated identity for logging

From
Jacob Champion
Date:
On Wed, 2021-09-22 at 10:20 +0200, Peter Eisentraut wrote:
> This should be added to each level of a function call that represents a 
> test.  This ensures that when a test fails, the line number points to 
> the top-level location of the test_role() call.  Otherwise it would 
> point to the connect_ok() call inside test_role().

Patch LGTM, sorry about that. Thanks!

--Jacob

Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Wed, Sep 22, 2021 at 03:18:43PM +0000, Jacob Champion wrote:
> On Wed, 2021-09-22 at 10:20 +0200, Peter Eisentraut wrote:
>> This should be added to each level of a function call that represents a
>> test.  This ensures that when a test fails, the line number points to
>> the top-level location of the test_role() call.  Otherwise it would
>> point to the connect_ok() call inside test_role().
>
> Patch LGTM, sorry about that. Thanks!

For the places of the patch, that seems fine then.  Thanks!

Do we need to care about that in other places?  We have tests in
src/bin/ using subroutines that call things from PostgresNode.pm or
TestLib.pm, like pg_checksums, pg_ctl or pg_verifybackup, just to name
three.
--
Michael

Attachment

Re: Proposal: Save user's original authenticated identity for logging

From
Peter Eisentraut
Date:
On 23.09.21 12:34, Michael Paquier wrote:
> On Wed, Sep 22, 2021 at 03:18:43PM +0000, Jacob Champion wrote:
>> On Wed, 2021-09-22 at 10:20 +0200, Peter Eisentraut wrote:
>>> This should be added to each level of a function call that represents a
>>> test.  This ensures that when a test fails, the line number points to
>>> the top-level location of the test_role() call.  Otherwise it would
>>> point to the connect_ok() call inside test_role().
>>
>> Patch LGTM, sorry about that. Thanks!
> 
> For the places of the patch, that seems fine then.  Thanks!

committed

> Do we need to care about that in other places?  We have tests in
> src/bin/ using subroutines that call things from PostgresNode.pm or
> TestLib.pm, like pg_checksums, pg_ctl or pg_verifybackup, just to name
> three.

Yeah, at first glance, there is probably more that could be done.  Here, 
I was just looking at a place where it was already and was accidentally 
removed.



Re: Proposal: Save user's original authenticated identity for logging

From
Andrew Dunstan
Date:
On 9/23/21 5:20 PM, Peter Eisentraut wrote:
> On 23.09.21 12:34, Michael Paquier wrote:
>> On Wed, Sep 22, 2021 at 03:18:43PM +0000, Jacob Champion wrote:
>>> On Wed, 2021-09-22 at 10:20 +0200, Peter Eisentraut wrote:
>>>> This should be added to each level of a function call that
>>>> represents a
>>>> test.  This ensures that when a test fails, the line number points to
>>>> the top-level location of the test_role() call.  Otherwise it would
>>>> point to the connect_ok() call inside test_role().
>>>
>>> Patch LGTM, sorry about that. Thanks!
>>
>> For the places of the patch, that seems fine then.  Thanks!
>
> committed
>
>> Do we need to care about that in other places?  We have tests in
>> src/bin/ using subroutines that call things from PostgresNode.pm or
>> TestLib.pm, like pg_checksums, pg_ctl or pg_verifybackup, just to name
>> three.
>
> Yeah, at first glance, there is probably more that could be done. 
> Here, I was just looking at a place where it was already and was
> accidentally removed.



It probably wouldn't be a bad thing to have something somewhere
(src/test/perl/README ?) that explains when and why we need to bump
$Test::Builder::Level.


cheers


andrew

--
Andrew Dunstan
EDB: https://www.enterprisedb.com




Re: Proposal: Save user's original authenticated identity for logging

From
Michael Paquier
Date:
On Fri, Sep 24, 2021 at 05:37:48PM -0400, Andrew Dunstan wrote:
> It probably wouldn't be a bad thing to have something somewhere
> (src/test/perl/README ?) that explains when and why we need to bump
> $Test::Builder::Level.

I have some ideas about that.  So I propose to move the discussion to
a new thread.
--
Michael

Attachment