Re: Cannot reach pg server using -h localhost - Mailing list pgsql-general

From Fritz Meissner
Subject Re: Cannot reach pg server using -h localhost
Date
Msg-id CAGUYmUYKm767jBH2UcSCgNvz3GDtiHRMdX=bFS1hpydi30BAgQ@mail.gmail.com
Whole thread Raw
In response to Re: Cannot reach pg server using -h localhost  (Adrian Klaver <adrian.klaver@aklaver.com>)
List pgsql-general
Logging at debug5, hopefully it will mean more to you than to me.
Local connection connects and I quit in a few seconds. -h localhost
takes 90+ seconds to be closed by the server. In the longer duration
there is a lot more logged, seems like unrelated auto chatter.

I turned autovacuum off in postgresql.conf in the hope that it would
reduce the chatter, seems unsuccesful.

psql -Umyuser -dmydb

2015-07-22 12:00:51.175 CEST  DEBUG:  forked new backend, pid=5923 socket=12
2015-07-22 12:00:51.175 CEST [unknown] LOG:  connection received: host=[local]
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:  postgres
child[5923]: starting with (
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:        postgres
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:  )
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:  InitPostgres
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:  my backend ID is 2
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:  StartTransaction
2015-07-22 12:00:51.175 CEST myuser [local]DEBUG:  name: unnamed;
blockState:       DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0,
nestlvl: 1, children:
2015-07-22 12:00:51.176 CEST myuser [local]LOG:  connection
authorized: user=myuser database=mydb
2015-07-22 12:00:51.179 CEST myuser [local]DEBUG:  CommitTransaction
2015-07-22 12:00:51.179 CEST myuser [local]DEBUG:  name: unnamed;
blockState:       STARTED; state: INPROGR, xid/subid/cid: 0/1/0,
nestlvl: 1, children:
2015-07-22 12:00:59.896 CEST myuser [local]DEBUG:  shmem_exit(0): 1
before_shmem_exit callbacks to make
2015-07-22 12:00:59.896 CEST myuser [local]DEBUG:  shmem_exit(0): 6
on_shmem_exit callbacks to make
2015-07-22 12:00:59.896 CEST myuser [local]DEBUG:  proc_exit(0): 4
callbacks to make
2015-07-22 12:00:59.897 CEST myuser [local]LOG:  disconnection:
session time: 0:00:08.721 user=myuser database=mydb host=[local]
2015-07-22 12:00:59.897 CEST myuser [local]DEBUG:  exit(0)
2015-07-22 12:00:59.897 CEST myuser [local]DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2015-07-22 12:00:59.897 CEST myuser [local]DEBUG:  shmem_exit(-1): 0
on_shmem_exit callbacks to make
2015-07-22 12:00:59.897 CEST myuser [local]DEBUG:  proc_exit(-1): 0
callbacks to make
2015-07-22 12:00:59.898 CEST  DEBUG:  reaping dead processes
2015-07-22 12:00:59.898 CEST  DEBUG:  server process (PID 5923) exited
with exit code 0

****************************************************************************

psql -Umyuser -dmyuser -h localhost

2015-07-22 12:02:20.422 CEST  DEBUG:  forked new backend, pid=5941 socket=12
2015-07-22 12:02:20.422 CEST [unknown] LOG:  connection received:
host=::1 port=51255
2015-07-22 12:02:27.393 CEST  DEBUG:  StartTransaction
2015-07-22 12:02:27.393 CEST  DEBUG:  name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:02:27.393 CEST  DEBUG:  CommitTransaction
2015-07-22 12:02:27.393 CEST  DEBUG:  name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:02:27.393 CEST  DEBUG:  received inquiry for database 0
2015-07-22 12:02:27.393 CEST  DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2015-07-22 12:02:27.394 CEST  DEBUG:  writing stats file "pg_stat_tmp/db_0.stat"
2015-07-22 12:02:27.406 CEST  DEBUG:  InitPostgres
2015-07-22 12:02:27.406 CEST  DEBUG:  my backend ID is 2
2015-07-22 12:02:27.407 CEST  DEBUG:  StartTransaction
2015-07-22 12:02:27.407 CEST  DEBUG:  name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:02:27.411 CEST  DEBUG:  CommitTransaction
2015-07-22 12:02:27.411 CEST  DEBUG:  name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:02:27.411 CEST  DEBUG:  autovacuum: processing database “mydb”
2015-07-22 12:02:27.411 CEST  DEBUG:  received inquiry for database 16384
2015-07-22 12:02:27.411 CEST  DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2015-07-22 12:02:27.411 CEST  DEBUG:  writing stats file
"pg_stat_tmp/db_16384.stat"
2015-07-22 12:02:27.422 CEST  DEBUG:  StartTransaction
2015-07-22 12:02:27.423 CEST  DEBUG:  name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_statistic: vac: 0 (threshold
130), anl: 0 (threshold 90)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_type: vac: 0 (threshold 118),
anl: 0 (threshold 84)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_authid: vac: 0 (threshold
50), anl: 0 (threshold 50)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_attribute: vac: 0 (threshold
512), anl: 0 (threshold 281)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_proc: vac: 0 (threshold 587),
anl: 0 (threshold 318)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_index: vac: 0 (threshold 73),
anl: 0 (threshold 61)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_opclass: vac: 0 (threshold
76), anl: 0 (threshold 63)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_am: vac: 0 (threshold 51),
anl: 0 (threshold 50)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_amop: vac: 0 (threshold 137),
anl: 0 (threshold 94)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_amproc: vac: 0 (threshold
119), anl: 0 (threshold 84)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_database: vac: 0 (threshold
50), anl: 0 (threshold 50)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_cast: vac: 0 (threshold 90),
anl: 0 (threshold 70)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_namespace: vac: 0 (threshold
51), anl: 0 (threshold 51)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_tablespace: vac: 0 (threshold
50), anl: 0 (threshold 50)
2015-07-22 12:02:27.423 CEST  DEBUG:  pg_class: vac: 0 (threshold
109), anl: 0 (threshold 80)
2015-07-22 12:02:27.423 CEST  DEBUG:  CommitTransaction
2015-07-22 12:02:27.423 CEST  DEBUG:  name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:02:27.423 CEST  DEBUG:  shmem_exit(0): 1
before_shmem_exit callbacks to make
2015-07-22 12:02:27.423 CEST  DEBUG:  shmem_exit(0): 7 on_shmem_exit
callbacks to make
2015-07-22 12:02:27.423 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2015-07-22 12:02:27.423 CEST  DEBUG:  exit(0)
2015-07-22 12:02:27.423 CEST  DEBUG:  shmem_exit(-1): 0
before_shmem_exit callbacks to make
2015-07-22 12:02:27.423 CEST  DEBUG:  shmem_exit(-1): 0 on_shmem_exit
callbacks to make
2015-07-22 12:02:27.423 CEST  DEBUG:  proc_exit(-1): 0 callbacks to make
2015-07-22 12:02:27.424 CEST  DEBUG:  reaping dead processes
2015-07-22 12:02:27.424 CEST  DEBUG:  server process (PID 5943) exited
with exit code 0
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:
shmem_exit(1): 0 before_shmem_exit callbacks to make
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:
shmem_exit(1): 0 on_shmem_exit callbacks to make
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:  proc_exit(1):
1 callbacks to make
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:  exit(1)
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:
shmem_exit(-1): 0 before_shmem_exit callbacks to make
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:
shmem_exit(-1): 0 on_shmem_exit callbacks to make
2015-07-22 12:03:20.426 CEST [unknown] ::1(51255)DEBUG:
proc_exit(-1): 0 callbacks to make
2015-07-22 12:03:20.426 CEST  DEBUG:  reaping dead processes
2015-07-22 12:03:20.426 CEST  DEBUG:  server process (PID 5941) exited
with exit code 1
2015-07-22 12:03:27.395 CEST  DEBUG:  StartTransaction
2015-07-22 12:03:27.396 CEST  DEBUG:  name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:03:27.396 CEST  DEBUG:  CommitTransaction
2015-07-22 12:03:27.396 CEST  DEBUG:  name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:03:27.396 CEST  DEBUG:  received inquiry for database 0
2015-07-22 12:03:27.396 CEST  DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2015-07-22 12:03:27.396 CEST  DEBUG:  writing stats file "pg_stat_tmp/db_0.stat"
2015-07-22 12:03:27.409 CEST  DEBUG:  InitPostgres
2015-07-22 12:03:27.409 CEST  DEBUG:  my backend ID is 2
2015-07-22 12:03:27.409 CEST  DEBUG:  StartTransaction
2015-07-22 12:03:27.409 CEST  DEBUG:  name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:03:27.413 CEST  DEBUG:  CommitTransaction
2015-07-22 12:03:27.413 CEST  DEBUG:  name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:03:27.413 CEST  DEBUG:  autovacuum: processing database "mydb"
2015-07-22 12:03:27.413 CEST  DEBUG:  received inquiry for database 16384
2015-07-22 12:03:27.413 CEST  DEBUG:  writing stats file
"pg_stat_tmp/global.stat"
2015-07-22 12:03:27.413 CEST  DEBUG:  writing stats file
"pg_stat_tmp/db_16384.stat"
2015-07-22 12:03:27.424 CEST  DEBUG:  StartTransaction
2015-07-22 12:03:27.424 CEST  DEBUG:  name: unnamed; blockState:
DEFAULT; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_statistic: vac: 0 (threshold
130), anl: 0 (threshold 90)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_type: vac: 0 (threshold 118),
anl: 0 (threshold 84)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_authid: vac: 0 (threshold
50), anl: 0 (threshold 50)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_attribute: vac: 0 (threshold
512), anl: 0 (threshold 281)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_proc: vac: 0 (threshold 587),
anl: 0 (threshold 318)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_index: vac: 0 (threshold 73),
anl: 0 (threshold 61)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_opclass: vac: 0 (threshold
76), anl: 0 (threshold 63)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_am: vac: 0 (threshold 51),
anl: 0 (threshold 50)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_amop: vac: 0 (threshold 137),
anl: 0 (threshold 94)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_amproc: vac: 0 (threshold
119), anl: 0 (threshold 84)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_database: vac: 0 (threshold
50), anl: 0 (threshold 50)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_cast: vac: 0 (threshold 90),
anl: 0 (threshold 70)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_namespace: vac: 0 (threshold
51), anl: 0 (threshold 51)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_tablespace: vac: 0 (threshold
50), anl: 0 (threshold 50)
2015-07-22 12:03:27.425 CEST  DEBUG:  pg_class: vac: 0 (threshold
109), anl: 0 (threshold 80)
2015-07-22 12:03:27.425 CEST  DEBUG:  CommitTransaction
2015-07-22 12:03:27.425 CEST  DEBUG:  name: unnamed; blockState:
STARTED; state: INPROGR, xid/subid/cid: 0/1/0, nestlvl: 1, children:
2015-07-22 12:03:27.425 CEST  DEBUG:  shmem_exit(0): 1
before_shmem_exit callbacks to make
2015-07-22 12:03:27.425 CEST  DEBUG:  shmem_exit(0): 7 on_shmem_exit
callbacks to make
2015-07-22 12:03:27.425 CEST  DEBUG:  proc_exit(0): 2 callbacks to make
2015-07-22 12:03:27.425 CEST  DEBUG:  exit(0)

Fritz


On Wed, Jul 22, 2015 at 12:05 AM, Adrian Klaver
<adrian.klaver@aklaver.com> wrote:
> On 07/21/2015 01:58 PM, Fritz Meissner wrote:
>>>
>>> 2) I know in your original post you did a which on psql, but is there
>>> more
>>> then one instance/install of Postgres on this machine?
>>>
>>> The reason I ask is this from the original post:
>>>
>>> psql -Umyuser -d mydb
>>> sql (9.3.5)
>>> Type "help" for help.
>>>
>>> myuser=#
>>>
>>
>> Yeah sorry, that's a copy/paste from before I upgraded out of
>> desperation. Same thing was happening on 9.3.5 and 9.4.4. Currently:
>>
>> psql (9.4.4)
>> Type "help" for help.
>>
>> myuser=#
>>
>
> Well that would have been too easy.
>
> Have you tried Tom's suggestion?:
>
>
> "However, assuming that that's not your problem, I'd suggest cranking up
> log_min_messages to DEBUG5 and seeing if anything more gets reported
> in the postmaster log.
> "
>
> --
> Adrian Klaver
> adrian.klaver@aklaver.com


pgsql-general by date:

Previous
From: Chris Mair
Date:
Subject: Re: Cannot reach pg server using -h localhost
Next
From: Marc Mamin
Date:
Subject: Drop down in connect time between 9.3.6 and 9.3.9 ?