I am able to login as postgres with password from the same machine. So it is not an expiry issue (as you too concluded). Output from strace is about 500 lines. I am pasting what I feel may be relevant. I hope this will be useful.
execve("/usr/pgsql-9.3/bin/psql", ["psql", "-h", "localhost"], [/* 24 vars */]) = 0
brk(0) = 0x1962000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb252e42000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=40284, ...}) = 0
mmap(NULL, 40284, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb252e38000
close(3) = 0
open("/usr/pgsql-9.3/lib/libpq.so.5", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\225\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=188904, ...}) = 0
mmap(NULL, 2284256, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb2529f6000
mprotect(0x7fb252a21000, 2097152, PROT_NONE) = 0
....
munmap(0x7fb252e41000, 4096) = 0
open("/usr/pgsql-9.3/share/locale/en_IN/LC_MESSAGES/psql-9.3.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/pgsql-9.3/share/locale/en/LC_MESSAGES/psql-9.3.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
geteuid() = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
....
stat("/root/.pgpass", 0x7fffc631e030) = -1 ENOENT (No such file or directory)
socket(PF_NETLINK, SOCK_RAW, 0) = 3
bind(3, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
.....
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
open("/etc/host.conf", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=9, ...}) = 0
....
sendto(3, "\0\0\0T\0\3\0\0user\0postgres\0database\0p"..., 84, MSG_NOSIGNAL, NULL, 0) = 84
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "R\0\0\0\f\0\0\0\5:\314\261\264", 16384, 0, NULL, NULL) = 13
close(3) = 0
open("/dev/tty", O_RDONLY) = 3
open("/dev/tty", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4
ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fffc631e550) = -1 ENOTTY (Inappropriate ioctl for device)
ioctl(3, SNDCTL_TMR_CONTINUE or TCSETSF, {B0 -opost -isig icanon -echo ...}) = -1 ENOTTY (Inappropriate ioctl for device)
fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb252e41000
write(4, "Password: ", 10) = 10
fstat(3, {st_mode=S_IFREG|0644, st_size=10, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb252e40000
read(3, "Password: ", 4096) = 10
read(3, "", 4096) = 0
read(3, "", 4096) = 0
ioctl(3, SNDCTL_TMR_CONTINUE or TCSETSF, {B0 -opost -isig icanon -echo ...}) = -1 ENOTTY (Inappropriate ioctl for device)
write(4, "\n", 1) = 1
close(3) = 0
munmap(0x7fb252e40000, 4096) = 0
close(4) = 0
munmap(0x7fb252e41000, 4096) = 0
socket(PF_NETLINK, SOCK_RAW, 0) = 3
....
connect(3, {sa_family=AF_INET, sin_port=htons(1234), sin_addr=inet_addr("212.71.253.117")}, 16) = 0
getsockname(3, {sa_family=AF_INET6, sin6_port=htons(49998), inet_pton(AF_INET6, "::ffff:212.71.253.117", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
close(3) = 0
socket(PF_NETLINK, SOCK_RAW, 0) = 3
bind(3, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(3, {sa_family=AF_NETLINK, pid=3632, groups=00000000}, [12]) = 0
sendto(3, "\24\0\0\0\22\0\1\3m4\312R\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"0\4\0\0\20\0\2\0m4\312R0\16\0\0\0\0\4\3\1\0\0\0I\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 3244
close(3) = 0
socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 3
setsockopt(3, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
fcntl(3, F_SETFD, FD_CLOEXEC) = 0
setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
connect(3, {sa_family=AF_INET6, sin6_port=htons(1234), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}])
getsockopt(3, SOL_SOCKET, SO_ERROR, [5972663263635177472], [4]) = 0
getsockname(3, {sa_family=AF_INET6, sin6_port=htons(49516), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}])
sendto(3, "\0\0\0\10\4\322\26/", 8, MSG_NOSIGNAL, NULL, 0) = 8
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "N", 16384, 0, NULL, NULL) = 1
poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}])
sendto(3, "\0\0\0T\0\3\0\0user\0postgres\0database\0p"..., 84, MSG_NOSIGNAL, NULL, 0) = 84
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "R\0\0\0\f\0\0\0\5\245}\301\263", 16384, 0, NULL, NULL) = 13
sendto(3, "p\0\0\0(md5db443609787c21b3171e5eed"..., 41, MSG_NOSIGNAL, NULL, 0) = 41
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "E\0\0\0aSFATAL\0C28P01\0Mpassword aut"..., 16384, 0, NULL, NULL) = 98
write(2, "psql: FATAL: password authentic"..., 65) = 65
execve("/usr/pgsql-9.3/bin/psql", ["psql", "-h", "localhost"], [/* 24 vars */]) = 0
brk(0) = 0x1962000
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb252e42000
access("/etc/ld.so.preload", R_OK) = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=40284, ...}) = 0
mmap(NULL, 40284, PROT_READ, MAP_PRIVATE, 3, 0) = 0x7fb252e38000
close(3) = 0
open("/usr/pgsql-9.3/lib/libpq.so.5", O_RDONLY) = 3
read(3, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0>\0\1\0\0\0\240\225\0\0\0\0\0\0"..., 832) = 832
fstat(3, {st_mode=S_IFREG|0755, st_size=188904, ...}) = 0
mmap(NULL, 2284256, PROT_READ|PROT_EXEC, MAP_PRIVATE|MAP_DENYWRITE, 3, 0) = 0x7fb2529f6000
mprotect(0x7fb252a21000, 2097152, PROT_NONE) = 0
....
munmap(0x7fb252e41000, 4096) = 0
open("/usr/pgsql-9.3/share/locale/en_IN/LC_MESSAGES/psql-9.3.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
open("/usr/pgsql-9.3/share/locale/en/LC_MESSAGES/psql-9.3.mo", O_RDONLY) = -1 ENOENT (No such file or directory)
geteuid() = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
....
stat("/root/.pgpass", 0x7fffc631e030) = -1 ENOENT (No such file or directory)
socket(PF_NETLINK, SOCK_RAW, 0) = 3
bind(3, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
.....
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
socket(PF_FILE, SOCK_STREAM|SOCK_CLOEXEC|SOCK_NONBLOCK, 0) = 3
connect(3, {sa_family=AF_FILE, path="/var/run/nscd/socket"}, 110) = -1 ENOENT (No such file or directory)
close(3) = 0
open("/etc/host.conf", O_RDONLY) = 3
fstat(3, {st_mode=S_IFREG|0644, st_size=9, ...}) = 0
....
sendto(3, "\0\0\0T\0\3\0\0user\0postgres\0database\0p"..., 84, MSG_NOSIGNAL, NULL, 0) = 84
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "R\0\0\0\f\0\0\0\5:\314\261\264", 16384, 0, NULL, NULL) = 13
close(3) = 0
open("/dev/tty", O_RDONLY) = 3
open("/dev/tty", O_WRONLY|O_CREAT|O_TRUNC, 0666) = 4
ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0x7fffc631e550) = -1 ENOTTY (Inappropriate ioctl for device)
ioctl(3, SNDCTL_TMR_CONTINUE or TCSETSF, {B0 -opost -isig icanon -echo ...}) = -1 ENOTTY (Inappropriate ioctl for device)
fstat(4, {st_mode=S_IFREG|0644, st_size=0, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb252e41000
write(4, "Password: ", 10) = 10
fstat(3, {st_mode=S_IFREG|0644, st_size=10, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x7fb252e40000
read(3, "Password: ", 4096) = 10
read(3, "", 4096) = 0
read(3, "", 4096) = 0
ioctl(3, SNDCTL_TMR_CONTINUE or TCSETSF, {B0 -opost -isig icanon -echo ...}) = -1 ENOTTY (Inappropriate ioctl for device)
write(4, "\n", 1) = 1
close(3) = 0
munmap(0x7fb252e40000, 4096) = 0
close(4) = 0
munmap(0x7fb252e41000, 4096) = 0
socket(PF_NETLINK, SOCK_RAW, 0) = 3
....
connect(3, {sa_family=AF_INET, sin_port=htons(1234), sin_addr=inet_addr("212.71.253.117")}, 16) = 0
getsockname(3, {sa_family=AF_INET6, sin6_port=htons(49998), inet_pton(AF_INET6, "::ffff:212.71.253.117", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
close(3) = 0
socket(PF_NETLINK, SOCK_RAW, 0) = 3
bind(3, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 0
getsockname(3, {sa_family=AF_NETLINK, pid=3632, groups=00000000}, [12]) = 0
sendto(3, "\24\0\0\0\22\0\1\3m4\312R\0\0\0\0\0\0\0\0", 20, 0, {sa_family=AF_NETLINK, pid=0, groups=00000000}, 12) = 20
recvmsg(3, {msg_name(12)={sa_family=AF_NETLINK, pid=0, groups=00000000}, msg_iov(1)=[{"0\4\0\0\20\0\2\0m4\312R0\16\0\0\0\0\4\3\1\0\0\0I\0\1\0\0\0\0\0"..., 4096}], msg_controllen=0, msg_flags=0}, 0) = 3244
close(3) = 0
socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 3
setsockopt(3, SOL_TCP, TCP_NODELAY, [1], 4) = 0
fcntl(3, F_SETFL, O_RDONLY|O_NONBLOCK) = 0
fcntl(3, F_SETFD, FD_CLOEXEC) = 0
setsockopt(3, SOL_SOCKET, SO_KEEPALIVE, [1], 4) = 0
connect(3, {sa_family=AF_INET6, sin6_port=htons(1234), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}])
getsockopt(3, SOL_SOCKET, SO_ERROR, [5972663263635177472], [4]) = 0
getsockname(3, {sa_family=AF_INET6, sin6_port=htons(49516), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}])
sendto(3, "\0\0\0\10\4\322\26/", 8, MSG_NOSIGNAL, NULL, 0) = 8
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "N", 16384, 0, NULL, NULL) = 1
poll([{fd=3, events=POLLOUT|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLOUT}])
sendto(3, "\0\0\0T\0\3\0\0user\0postgres\0database\0p"..., 84, MSG_NOSIGNAL, NULL, 0) = 84
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "R\0\0\0\f\0\0\0\5\245}\301\263", 16384, 0, NULL, NULL) = 13
sendto(3, "p\0\0\0(md5db443609787c21b3171e5eed"..., 41, MSG_NOSIGNAL, NULL, 0) = 41
poll([{fd=3, events=POLLIN|POLLERR}], 1, -1) = 1 ([{fd=3, revents=POLLIN}])
recvfrom(3, "E\0\0\0aSFATAL\0C28P01\0Mpassword aut"..., 16384, 0, NULL, NULL) = 98
write(2, "psql: FATAL: password authentic"..., 65) = 65
On Sun, Jan 5, 2014 at 11:18 PM, Tom Lane <tgl@xxxxxxxxxxxxx> wrote:
I wrote:Ah, no, scratch that: a look at the code shows the backend doesn't
> Perhaps the postgres user has a password that's marked as expired
> in pg_authid.rolvaliduntil?
check rolvaliduntil until after the client has given a valid password.
Seems like psql *must* be getting a password from someplace.
Perhaps it's time to strace psql and see what files it accesses.
regards, tom lane
