Thread: BUG #9518: temporary login failure - "missing pg_hba entry"
The following bug has been logged on the website:
Bug reference: 9518
Logged by: Mike Blackwell
Email address: mike.blackwell@rrd.com
PostgreSQL version: 9.3.3
Operating system: RHEL 6
Description:
The following sequence showed up in the error log recently:
2014-03-09 19:53:18 CDT [30632]: [2-1] username@databasename
10.17.x.y(53454)LOCATION: ClientAuthentication, auth.c:486
2014-03-09 19:53:18 CDT [30633]: [1-1] username@databasename
10.17.x.y(53455)FATAL: 28000: no pg_hba.conf entry for host "10.17.x.y",
user "username", database "databasename", SSL off
2014-03-09 19:53:18 CDT [30633]: [2-1] username@databasename
10.17.x.y(53455)LOCATION: ClientAuthentication, auth.c:486
2014-03-09 20:05:15 CDT [32505]: [1-1] username@databasename
10.17.x.y(54134)LOG: 00000: duration: 13641.600 ms execute dbdpg_p28498_2:
select ...;
2014-03-09 20:05:15 CDT [32505]: [2-1] username@databasename
10.17.x.y(54134)LOCATION: exec_execute_message, postgres.c:1991
The auth failure shows up seven times over a span of approximately six
seconds, with the one above being the last of the sequence.
This is on a server that has been running for quite a while. The last conf
reload was at the last Postgres restart on 3/1. The pg_hba.conf file
timestamps indicate no recent change as well.
This may not be a PostgreSQL bug but I'm running out of other explanations.
mike.blackwell@rrd.com wrote: > 2014-03-09 19:53:18 CDT [30633]: [1-1] username@databasename 10.17.x.y(53455)FATAL: 28000: no pg_hba.conf entry for host"10.17.x.y", user "username", database "databasename", SSL off > 2014-03-09 19:53:18 CDT [30633]: [2-1] username@databasename 10.17.x.y(53455)LOCATION: ClientAuthentication, auth.c:486 > 2014-03-09 20:05:15 CDT [32505]: [1-1] username@databasename 10.17.x.y(54134)LOG: 00000: duration: 13641.600 ms executedbdpg_p28498_2: > > select ...; > > 2014-03-09 20:05:15 CDT [32505]: [2-1] username@databasename 10.17.x.y(54134)LOCATION: exec_execute_message, postgres.c:1991 > > The auth failure shows up seven times over a span of approximately six > seconds, with the one above being the last of the sequence. So the connection that actually executes queries, is using SSL? I'm betting it's first trying one without SSL, failing, then trying with SSL and succeeding. -- Álvaro Herrera http://www.2ndQuadrant.com/ PostgreSQL Development, 24x7 Support, Training & Services
Hmm... Interesting thought. The server is built with SSL, but there's nothing on the app side that's explicitly enabling SSL, nor is the user account in question set up for SSL. That's on the TODO list at the moment. :) So, looks like that's not it. Thanks, though. I'd missed that possibility= . ___________________________________________________________________________= _______ *Mike Blackwell | Technical Analyst, Distribution Services/Rollout Management | RR Donnelley* 1750 Wallace Ave | St Charles, IL 60174-3401 Office: 630.313.7818 Mike.Blackwell@rrd.com http://www.rrdonnelley.com <http://www.rrdonnelley.com/> * <Mike.Blackwell@rrd.com>* On Mon, Mar 10, 2014 at 9:58 AM, Alvaro Herrera <alvherre@2ndquadrant.com>w= rote: > mike.blackwell@rrd.com wrote: > > > 2014-03-09 19:53:18 CDT [30633]: [1-1] username@databasename10.17.x.y(5= 3455)FATAL: 28000: no pg_hba.conf entry for host "10.17.x.y", > user "username", database "databasename", SSL off > > 2014-03-09 19:53:18 CDT [30633]: [2-1] username@databasename10.17.x.y(5= 3455)LOCATION: ClientAuthentication, auth.c:486 > > > 2014-03-09 20:05:15 CDT [32505]: [1-1] username@databasename10.17.x.y(5= 4134)LOG: 00000: duration: 13641.600 ms execute dbdpg_p28498_2: > > > > select ...; > > > > 2014-03-09 20:05:15 CDT [32505]: [2-1] username@databasename10.17.x.y(5= 4134)LOCATION: exec_execute_message, postgres.c:1991 > > > > The auth failure shows up seven times over a span of approximately six > > seconds, with the one above being the last of the sequence. > > So the connection that actually executes queries, is using SSL? I'm > betting it's first trying one without SSL, failing, then trying with > SSL and succeeding. > > -- > =C3=81lvaro Herrera http://www.2ndQuadrant.com/ > PostgreSQL Development, 24x7 Support, Training & Services >
=E2=80=8BThis particular host is listed in pg_hba.conf by host name rather = than by IP address. Is it possible this error is due to an intermittent DNS failure?=E2=80=8B ___________________________________________________________________________= _______ *Mike Blackwell | Technical Analyst, Distribution Services/Rollout Management | RR Donnelley* 1750 Wallace Ave | St Charles, IL 60174-3401 Office: 630.313.7818 Mike.Blackwell@rrd.com http://www.rrdonnelley.com <http://www.rrdonnelley.com/> * <Mike.Blackwell@rrd.com>* On Mon, Mar 10, 2014 at 10:06 AM, Mike Blackwell <mike.blackwell@rrd.com>wr= ote: > Hmm... Interesting thought. The server is built with SSL, but there's > nothing on the app side that's explicitly enabling SSL, nor is the user > account in question set up for SSL. That's on the TODO list at the momen= t. > :) > > So, looks like that's not it. Thanks, though. I'd missed that > possibility. > > > _________________________________________________________________________= _________ > *Mike Blackwell | Technical Analyst, Distribution Services/Rollout > Management | RR Donnelley* > 1750 Wallace Ave | St Charles, IL 60174-3401 > Office: 630.313.7818 > Mike.Blackwell@rrd.com > http://www.rrdonnelley.com > > > <http://www.rrdonnelley.com/> > * <Mike.Blackwell@rrd.com>* > > > On Mon, Mar 10, 2014 at 9:58 AM, Alvaro Herrera <alvherre@2ndquadrant.com= >wrote: > >> mike.blackwell@rrd.com wrote: >> >> > 2014-03-09 19:53:18 CDT [30633]: [1-1] username@databasename10.17.x.y(= 53455)FATAL: 28000: no pg_hba.conf entry for host "10.17.x.y", >> user "username", database "databasename", SSL off >> > 2014-03-09 19:53:18 CDT [30633]: [2-1] username@databasename10.17.x.y(= 53455)LOCATION: ClientAuthentication, auth.c:486 >> >> > 2014-03-09 20:05:15 CDT [32505]: [1-1] username@databasename10.17.x.y(= 54134)LOG: 00000: duration: 13641.600 ms execute dbdpg_p28498_2: >> > >> > select ...; >> > >> > 2014-03-09 20:05:15 CDT [32505]: [2-1] username@databasename10.17.x.y(= 54134)LOCATION: exec_execute_message, postgres.c:1991 >> > >> > The auth failure shows up seven times over a span of approximately six >> > seconds, with the one above being the last of the sequence. >> >> So the connection that actually executes queries, is using SSL? I'm >> betting it's first trying one without SSL, failing, then trying with >> SSL and succeeding. >> >> -- >> =C3=81lvaro Herrera http://www.2ndQuadrant.com/ >> PostgreSQL Development, 24x7 Support, Training & Services >> > >
On Sat, Mar 29, 2014 at 8:36 AM, Mike Blackwell <mike.blackwell@rrd.com>wrote: This particular host is listed in pg_hba.conf by host name rather than by > IP address. Is it possible this error is due to an intermittent DNS > failure? > Not sure, if this issue still persists - We had the similar situation in the past - If the host is listed in the pg_hba.conf file - the reloading of the configuration was successful ? Any unnecessary blank spaces or the entries which are in-correct format will not let the pg_hba.conf reload be successful. In our case - some other host's entry was troubling us, it worked fine, when we commented it out. OR May be you need to re-check the DNS configuration and see if you are able to ping the DB server host ( using DNS name and IP address both ). May be DB server is not recognizing the DNS hostname ( check /etc/hosts ). Regards, Venkata Balaji N Fujitsu Australia
Mike Blackwell wrote:
> âThis particular host is listed in pg_hba.conf by host name rather than by
> IP address. Is it possible this error is due to an intermittent DNS
> failure?â
Doesn't look like it; that code has this:
ret = getaddrinfo(port->remote_hostname, NULL, NULL, &gai_result);
if (ret != 0)
ereport(ERROR,
(errmsg("could not translate host name \"%s\" to address: %s",
port->remote_hostname, gai_strerror(ret))));
so unless I'm misreading it, you should see an error message in your
server log.
--
Ãlvaro Herrera http://www.2ndQuadrant.com/
PostgreSQL Development, 24x7 Support, Training & Services
Alvaro Herrera <alvherre@2ndquadrant.com> writes:
> Mike Blackwell wrote:
>>âThis particular host is listed in pg_hba.conf by host name rather than by
>> IP address. Is it possible this error is due to an intermittent DNS
>> failure?â
> Doesn't look like it; that code has this:
> ret = getaddrinfo(port->remote_hostname, NULL, NULL, &gai_result);
> if (ret != 0)
> ereport(ERROR,
> (errmsg("could not translate host name \"%s\" to address: %s",
> port->remote_hostname, gai_strerror(ret))));
Don't think that proves a lot. Before we do that, we attempt to do a
reverse IP-to-name lookup, and AFAICS if that fails we just return
silently. The code you're quoting complains if the later cross-check
on the name's forward DNS resolution fails --- but we might never get
to that.
IOW, it looks to me like intermittent failures in the reverse DNS lookup
could disable matching by hostname, and nothing would be said in the
postmaster log. Why is there no complaint if check_hostname's call to
pg_getnameinfo_all (line 600 in HEAD) fails?
regards, tom lane
I wrote:
> IOW, it looks to me like intermittent failures in the reverse DNS lookup
> could disable matching by hostname, and nothing would be said in the
> postmaster log. Why is there no complaint if check_hostname's call to
> pg_getnameinfo_all (line 600 in HEAD) fails?
After sleeping on it, I think probably the reason it is like that is a
desire to not clutter the postmaster log if there are some legitimate
clients without rDNS entries. That is, suppose pg_hba.conf has
host foo.bar.com ...
host 192.168.168.1 ...
and you've not bothered to create a reverse-DNS entry for 192.168.168.1.
We will try (and fail) to look up the rDNS entry while considering the
foo.bar.com line. We certainly don't want a failure there to prevent us
from reaching the 192.168.168.1 line, and we don't really want to clutter
the postmaster log with a bleat about it, either. Hence the lack of any
error logging in the existing code. (The later cross-check on whether
the forward DNS matches does have an error report, which maybe isn't such
a great thing either from this standpoint.)
The problem of course is that if the rDNS failure prevents us from
matching to *any* line, we exit with no error more helpful than
"missing pg_hba entry", which is not very desirable in this case.
I guess we could do something like remember the fact that we tried and
failed to do an rDNS lookup, and report it as DETAIL in the eventual
"missing pg_hba entry" report. Not quite sure if it's worth the trouble
--- any thoughts?
Another objection to the code as it stands is that if there are multiple
pg_hba lines containing hostnames, we'll repeat the failing rDNS lookup
at each one. This is at best a huge waste of cycles (multiple network
roundtrips, if the DNS server isn't local), and at worst inconsistent
if things actually are intermittent and a later lookup attempt succeeds.
I think we want to fix it to be sure that there's exactly one rDNS lookup
attempt, occurring at the first line with a hostname.
regards, tom lane
=E2=80=8B On Tue, Apr 1, 2014 at 10:13 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > I guess we could do something like remember the fact that we tried and > failed to do an rDNS lookup, and report it as DETAIL in the eventual > "missing pg_hba entry" report. Not quite sure if it's worth the trouble > --- any thoughts? > That certainly would have saved some head scratching here, so +1 from me. I'll take a look at this part if no one else is interested, but my C skills are rather rusty. =E2=80=8BThanks for tracking this down, Tom.=E2=80=8B =E2=80=8BMike=E2=80=8B
Mike Blackwell <mike.blackwell@rrd.com> writes:
> On Tue, Apr 1, 2014 at 10:13 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote:
>> I guess we could do something like remember the fact that we tried and
>> failed to do an rDNS lookup, and report it as DETAIL in the eventual
>> "missing pg_hba entry" report. Not quite sure if it's worth the trouble
>> --- any thoughts?
> That certainly would have saved some head scratching here, so +1 from me.
> I'll take a look at this part if no one else is interested, but my C
> skills are rather rusty.
This was messier than it looked, because there were multiple interacting
bugs, but I've committed a fix now.
regards, tom lane
Thanks Tom! Mike __________________________________________________________________________________ *Mike Blackwell | Technical Analyst, Distribution Services/Rollout Management | RR Donnelley* 1750 Wallace Ave | St Charles, IL 60174-3401 Office: 630.313.7818 Mike.Blackwell@rrd.com http://www.rrdonnelley.com <http://www.rrdonnelley.com/> * <Mike.Blackwell@rrd.com>* On Wed, Apr 2, 2014 at 4:13 PM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > Mike Blackwell <mike.blackwell@rrd.com> writes: > > On Tue, Apr 1, 2014 at 10:13 AM, Tom Lane <tgl@sss.pgh.pa.us> wrote: > >> I guess we could do something like remember the fact that we tried and > >> failed to do an rDNS lookup, and report it as DETAIL in the eventual > >> "missing pg_hba entry" report. Not quite sure if it's worth the trouble > >> --- any thoughts? > > > That certainly would have saved some head scratching here, so +1 from me. > > I'll take a look at this part if no one else is interested, but my C > > skills are rather rusty. > > This was messier than it looked, because there were multiple interacting > bugs, but I've committed a fix now. > > regards, tom lane >