Thread: authentication failure

Hi there

I have a process in place which runs several queries from one host to another one


All of a sudden I started noticing authentication failures

Like below

.009 ms  statement: COPY  NACDS.tf_show_code_response_person FROM STDIN with csv;",,,,,,,,,"psql"
2018-04-12 00:10:48.765 CDT,"csidba","birstdb",7553,"172.16.20.4:40330",5aceea2e.1d81,1,"UPDATE",2018-04-12 00:10:06
CDT,24/0,0,LOG,00000,"duration:425 
90.993 ms  statement: UPDATE
    csischema.tf_transaction_person
SET
    is_deleted = 'TRUE',
    birst_is_deleted = 'TRUE',
    update_datetime = now()::timestamp(0)
WHERE
    show_id = '984BIOWC18' AND
    birst_is_deleted = 'FALSE' AND
    person_transaction_id IN (
        SELECT a.person_transaction_id
        FROM csischema.tf_transaction_person a
             LEFT JOIN BIOWC.tf_transaction_person b
             ON a.person_transaction_id=b.person_transaction_id
        WHERE a.show_id = '984BIOWC18' AND b.person_transaction_id IS NULL
    )
;",,,,,,,,,"psql"
2018-04-12 00:10:48.823 CDT,"csidba","birstdb",7755,"172.16.20.4:40455",5aceea58.1e4b,1,"authentication",2018-04-12
00:10:48CDT,3/20320168,0,FATAL,28P0 
1,"password authentication failed for user ""csidba""","Connection matched pg_hba.conf line 84: ""host all all
0.0.0.0/0md5""",,,,,,,,"" 
2018-04-12 00:10:48.841 CDT,"csidba","birstdb",7756,"172.16.20.4:40456",5aceea58.1e4c,1,"authentication",2018-04-12
00:10:48CDT,3/20320169,0,FATAL,28P0 
1,"password authentication failed for user ""csidba""","Connection matched pg_hba.conf line 84: ""host all all
0.0.0.0/0md5""",,,,,,,,"" 
2018-04-12 00:10:48.957 CDT,"csidba","birstdb",7759,"172.16.20.4:40459",5aceea58.1e4f,1,"authentication",2018-04-12
00:10:48CDT,3/20320172,0,FATAL,28P0 


pg_hba.conf

# "local" is for Unix domain socket connections only
#local   all             all                                     peer
local   all             all                                     md5
# IPv4 local connections:
#host    all             all             127.0.0.1/32            ident
host all all 0.0.0.0/0 md5
# IPv6 local connections:
host    all             all             ::1/128                 ident
# Allow replication connections from localhost, by a user with the
# replication privilege.
#local   replication     postgres                                peer
#host    replication     postgres        127.0.0.1/32            ident
#host    replication     postgres        ::1/128                 ident
local  replication  csidba  md5
host   replication  csidba  127.0.0.1/32  md5
host   replication  csidba  0.0.0.0/0     md5
local  replication  repuser  md5
host   replication  repuser  127.0.0.1/32  md5
host   replication  repuser  0.0.0.0/0     md5
local  all         repuser  md5
host   all         repuser  127.0.0.1/32  md5
host   all         repuser  0.0.0.0/0     md5



Did I run in somthing similar to a racong condition ?


Any ideas ?



Many thanks

— Armand

On 04/12/2018 06:51 AM, armand pirvu wrote:
> Hi there
> 
> I have a process in place which runs several queries from one host to another one
> 
> 
> All of a sudden I started noticing authentication failures
> 
> Like below
> 
> .009 ms  statement: COPY  NACDS.tf_show_code_response_person FROM STDIN with csv;",,,,,,,,,"psql"
> 2018-04-12 00:10:48.765 CDT,"csidba","birstdb",7553,"172.16.20.4:40330",5aceea2e.1d81,1,"UPDATE",2018-04-12 00:10:06
CDT,24/0,0,LOG,00000,"duration:425
 
> 90.993 ms  statement: UPDATE
>      csischema.tf_transaction_person
> SET
>      is_deleted = 'TRUE',
>      birst_is_deleted = 'TRUE',
>      update_datetime = now()::timestamp(0)
> WHERE
>      show_id = '984BIOWC18' AND
>      birst_is_deleted = 'FALSE' AND
>      person_transaction_id IN (
>          SELECT a.person_transaction_id
>          FROM csischema.tf_transaction_person a
>               LEFT JOIN BIOWC.tf_transaction_person b
>               ON a.person_transaction_id=b.person_transaction_id
>          WHERE a.show_id = '984BIOWC18' AND b.person_transaction_id IS NULL
>      )
> ;",,,,,,,,,"psql"
> 2018-04-12 00:10:48.823 CDT,"csidba","birstdb",7755,"172.16.20.4:40455",5aceea58.1e4b,1,"authentication",2018-04-12
00:10:48CDT,3/20320168,0,FATAL,28P0
 
> 1,"password authentication failed for user ""csidba""","Connection matched pg_hba.conf line 84: ""host all all
0.0.0.0/0md5""",,,,,,,,""
 
> 2018-04-12 00:10:48.841 CDT,"csidba","birstdb",7756,"172.16.20.4:40456",5aceea58.1e4c,1,"authentication",2018-04-12
00:10:48CDT,3/20320169,0,FATAL,28P0
 
> 1,"password authentication failed for user ""csidba""","Connection matched pg_hba.conf line 84: ""host all all
0.0.0.0/0md5""",,,,,,,,""
 
> 2018-04-12 00:10:48.957 CDT,"csidba","birstdb",7759,"172.16.20.4:40459",5aceea58.1e4f,1,"authentication",2018-04-12
00:10:48CDT,3/20320172,0,FATAL,28P0
 
> 
> 
> pg_hba.conf
> 
> # "local" is for Unix domain socket connections only
> #local   all             all                                     peer
> local   all             all                                     md5
> # IPv4 local connections:
> #host    all             all             127.0.0.1/32            ident
> host all all 0.0.0.0/0 md5
> # IPv6 local connections:
> host    all             all             ::1/128                 ident
> # Allow replication connections from localhost, by a user with the
> # replication privilege.
> #local   replication     postgres                                peer
> #host    replication     postgres        127.0.0.1/32            ident
> #host    replication     postgres        ::1/128                 ident
> local  replication  csidba  md5
> host   replication  csidba  127.0.0.1/32  md5
> host   replication  csidba  0.0.0.0/0     md5
> local  replication  repuser  md5
> host   replication  repuser  127.0.0.1/32  md5
> host   replication  repuser  0.0.0.0/0     md5
> local  all         repuser  md5
> host   all         repuser  127.0.0.1/32  md5
> host   all         repuser  0.0.0.0/0     md5
> 
> 
> 
> Did I run in somthing similar to a racong condition ?
> 
> 
> Any ideas ?

Is the process using the correct password?

> 
> 
> 
> Many thanks
> 
> — Armand
> 
> 
> 
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

On 04/12/2018 06:59 AM, armand pirvu wrote:

Please reply to list also.
Ccing list.
> Yes and worked fine until two days ago
> I use .pgpass

So can you connect from wherever the process is run to the server 
manually? Something like:


psql -d birstab -U csidba -h some_server


> I will also check and see if there are not too many hands in the cookie jar so to speak and things happen without
beingcommunicated
 
> 
> 
>> On Apr 12, 2018, at 8:56 AM, Adrian Klaver <adrian.klaver@aklaver.com> wrote:
>>
>> On 04/12/2018 06:51 AM, armand pirvu wrote:
>>> Hi there
>>> I have a process in place which runs several queries from one host to another one
>>> All of a sudden I started noticing authentication failures
>>> Like below
>>> .009 ms  statement: COPY  NACDS.tf_show_code_response_person FROM STDIN with csv;",,,,,,,,,"psql"
>>> 2018-04-12 00:10:48.765 CDT,"csidba","birstdb",7553,"172.16.20.4:40330",5aceea2e.1d81,1,"UPDATE",2018-04-12
00:10:06CDT,24/0,0,LOG,00000,"duration: 425
 
>>> 90.993 ms  statement: UPDATE
>>>      csischema.tf_transaction_person
>>> SET
>>>      is_deleted = 'TRUE',
>>>      birst_is_deleted = 'TRUE',
>>>      update_datetime = now()::timestamp(0)
>>> WHERE
>>>      show_id = '984BIOWC18' AND
>>>      birst_is_deleted = 'FALSE' AND
>>>      person_transaction_id IN (
>>>          SELECT a.person_transaction_id
>>>          FROM csischema.tf_transaction_person a
>>>               LEFT JOIN BIOWC.tf_transaction_person b
>>>               ON a.person_transaction_id=b.person_transaction_id
>>>          WHERE a.show_id = '984BIOWC18' AND b.person_transaction_id IS NULL
>>>      )
>>> ;",,,,,,,,,"psql"
>>> 2018-04-12 00:10:48.823 CDT,"csidba","birstdb",7755,"172.16.20.4:40455",5aceea58.1e4b,1,"authentication",2018-04-12
00:10:48CDT,3/20320168,0,FATAL,28P0
 
>>> 1,"password authentication failed for user ""csidba""","Connection matched pg_hba.conf line 84: ""host all all
0.0.0.0/0md5""",,,,,,,,""
 
>>> 2018-04-12 00:10:48.841 CDT,"csidba","birstdb",7756,"172.16.20.4:40456",5aceea58.1e4c,1,"authentication",2018-04-12
00:10:48CDT,3/20320169,0,FATAL,28P0
 
>>> 1,"password authentication failed for user ""csidba""","Connection matched pg_hba.conf line 84: ""host all all
0.0.0.0/0md5""",,,,,,,,""
 
>>> 2018-04-12 00:10:48.957 CDT,"csidba","birstdb",7759,"172.16.20.4:40459",5aceea58.1e4f,1,"authentication",2018-04-12
00:10:48CDT,3/20320172,0,FATAL,28P0
 
>>> pg_hba.conf
>>> # "local" is for Unix domain socket connections only
>>> #local   all             all                                     peer
>>> local   all             all                                     md5
>>> # IPv4 local connections:
>>> #host    all             all             127.0.0.1/32            ident
>>> host all all 0.0.0.0/0 md5
>>> # IPv6 local connections:
>>> host    all             all             ::1/128                 ident
>>> # Allow replication connections from localhost, by a user with the
>>> # replication privilege.
>>> #local   replication     postgres                                peer
>>> #host    replication     postgres        127.0.0.1/32            ident
>>> #host    replication     postgres        ::1/128                 ident
>>> local  replication  csidba  md5
>>> host   replication  csidba  127.0.0.1/32  md5
>>> host   replication  csidba  0.0.0.0/0     md5
>>> local  replication  repuser  md5
>>> host   replication  repuser  127.0.0.1/32  md5
>>> host   replication  repuser  0.0.0.0/0     md5
>>> local  all         repuser  md5
>>> host   all         repuser  127.0.0.1/32  md5
>>> host   all         repuser  0.0.0.0/0     md5
>>> Did I run in somthing similar to a racong condition ?
>>> Any ideas ?
>>
>> Is the process using the correct password?
>>
>>> Many thanks
>>> — Armand
>>
>>
>> -- 
>> Adrian Klaver
>> adrian.klaver@aklaver.com
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

On 04/12/2018 07:15 AM, armand pirvu wrote:
> 

>>
>>
> 
> Sorry for the double posting but could it be from
> 
> #authentication_timeout = 1min# 1s-600s

 From you previous post:

"It is almost like the authnetication stops working for whatever reason"

So to be clear the initial connections in the process go through, but at 
some point they start failing. Is that correct?

The timeout could be an issue. It would helpful to also see what 
max_connections setting is.

> 
> So if the server gets a bit oveloaded this could play a role ?
> 
> 
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

> On Apr 12, 2018, at 9:28 AM, Adrian Klaver <adrian.klaver@aklaver.com> wrote:
>
> On 04/12/2018 07:15 AM, armand pirvu wrote:
>
>>>
>>>
>> Sorry for the double posting but could it be from
>> #authentication_timeout = 1min# 1s-600s
>
> From you previous post:
>
> "It is almost like the authnetication stops working for whatever reason"
>
> So to be clear the initial connections in the process go through, but at some point they start failing. Is that
correct?
>
> The timeout could be an issue. It would helpful to also see what max_connections setting is.
>
>> So if the server gets a bit oveloaded this could play a role ?
>
>
> --
> Adrian Klaver
> adrian.klaver@aklaver.com


Yes correct initially they go through but at some point they start failing
Max_connections is set to 200 on the postgres server, but I did not notice any message about being maxed out
connectionswise 
As a workaround for this very specific set of processes, until things get back in line so to speak, do you think from
thedevweb2004 (where processing is done) to devdb2004 (where the postgres database resides), should I just go from md5
totrusted ? 

On 04/12/2018 07:37 AM, armand pirvu wrote:
> 
>> On Apr 12, 2018, at 9:28 AM, Adrian Klaver <adrian.klaver@aklaver.com> wrote:
>>
>> On 04/12/2018 07:15 AM, armand pirvu wrote:
>>
>>>>
>>>>
>>> Sorry for the double posting but could it be from
>>> #authentication_timeout = 1min# 1s-600s
>>
>>  From you previous post:
>>
>> "It is almost like the authnetication stops working for whatever reason"
>>
>> So to be clear the initial connections in the process go through, but at some point they start failing. Is that
correct?
>>
>> The timeout could be an issue. It would helpful to also see what max_connections setting is.
>>
>>> So if the server gets a bit oveloaded this could play a role ?
>>
>>
>> -- 
>> Adrian Klaver
>> adrian.klaver@aklaver.com
> 
> 
> Yes correct initially they go through but at some point they start failing
> Max_connections is set to 200 on the postgres server, but I did not notice any message about being maxed out
connectionswise
 
> As a workaround for this very specific set of processes, until things get back in line so to speak, do you think from
thedevweb2004 (where processing is done) to devdb2004 (where the postgres database resides), should I just go from md5
totrusted ?
 

I would be inclined to raise the authentication_timeout first before 
setting the auth method to trust.

I would also set the below.:

https://www.postgresql.org/docs/10/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHAT

log_connections (boolean)
Causes each attempted connection to the server to be logged, as well as 
successful completion of client authentication. Only superusers can 
change this parameter at session start, and it cannot be changed at all 
within a session. The default is off.

log_disconnections (boolean)

That will give you a better idea of what is going on connection wise.

> 
> 
> 
> 
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

> On Apr 12, 2018, at 9:48 AM, Adrian Klaver <adrian.klaver@aklaver.com> wrote:
>
> On 04/12/2018 07:37 AM, armand pirvu wrote:
>>> On Apr 12, 2018, at 9:28 AM, Adrian Klaver <adrian.klaver@aklaver.com> wrote:
>>>
>>> On 04/12/2018 07:15 AM, armand pirvu wrote:
>>>
>>>>>
>>>>>
>>>> Sorry for the double posting but could it be from
>>>> #authentication_timeout = 1min# 1s-600s
>>>
>>> From you previous post:
>>>
>>> "It is almost like the authnetication stops working for whatever reason"
>>>
>>> So to be clear the initial connections in the process go through, but at some point they start failing. Is that
correct?
>>>
>>> The timeout could be an issue. It would helpful to also see what max_connections setting is.
>>>
>>>> So if the server gets a bit oveloaded this could play a role ?
>>>
>>>
>>> --
>>> Adrian Klaver
>>> adrian.klaver@aklaver.com
>> Yes correct initially they go through but at some point they start failing
>> Max_connections is set to 200 on the postgres server, but I did not notice any message about being maxed out
connectionswise 
>> As a workaround for this very specific set of processes, until things get back in line so to speak, do you think
fromthe devweb2004 (where processing is done) to devdb2004 (where the postgres database resides), should I just go from
md5to trusted ? 
>
> I would be inclined to raise the authentication_timeout first before setting the auth method to trust.
>
> I would also set the below.:
>
> https://www.postgresql.org/docs/10/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHAT
>
> log_connections (boolean)
> Causes each attempted connection to the server to be logged, as well as successful completion of client
authentication.Only superusers can change this parameter at session start, and it cannot be changed at all within a
session.The default is off. 
>
> log_disconnections (boolean)
>
> That will give you a better idea of what is going on connection wise.
>
>
>
> --
> Adrian Klaver
> adrian.klaver@aklaver.com


Will do so and report back

Many thanks
Armand

On 04/12/2018 07:50 AM, armand pirvu wrote:
> 

>> I would be inclined to raise the authentication_timeout first before setting the auth method to trust.
>>
>> I would also set the below.:
>>
>> https://www.postgresql.org/docs/10/static/runtime-config-logging.html#RUNTIME-CONFIG-LOGGING-WHAT
>>
>> log_connections (boolean)
>> Causes each attempted connection to the server to be logged, as well as successful completion of client
authentication.Only superusers can change this parameter at session start, and it cannot be changed at all within a
session.The default is off.
 
>>
>> log_disconnections (boolean)
>>
>> That will give you a better idea of what is going on connection wise.
>>
>>
>>
>> -- 
>> Adrian Klaver
>> adrian.klaver@aklaver.com
> 
> 
> Will do so and report back

Also, in a previous post you mentioned:

"Yes and worked fine until two days ago"

Is the code under version control so you can see if anything changed two 
days ago?

If not, any recollections of significant events from that time period?

> 
> Many thanks
> Armand
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com

On 04/15/2018 06:22 PM, armand pirvu wrote:
> 

>>
> 
> 
> Sorry for the late reply. In and out sll sorts of things which do 
> distract me.
> I raised the authentication_timeout and seems okay for now

I would take the 'for now' as a heads up that there is underlying issue 
that will need to be resolved eventually. Namely that the procedure is 
using enough resources to impact the authentication process.

> 
> Thank you for the help
> 
> Armand
> 
> 
> 


-- 
Adrian Klaver
adrian.klaver@aklaver.com