Re: BUG #5121: Segmentation Fault when using pam w/ krb5 - Mailing list pgsql-bugs

From Douglas, Ryan
Subject Re: BUG #5121: Segmentation Fault when using pam w/ krb5
Date
Msg-id 706C25916A1ADD489F69906EC24FC07E026FDFB6@vamail02.TheXchange.com
Whole thread Raw
In response to Re: BUG #5121: Segmentation Fault when using pam w/ krb5  (Tom Lane <tgl@sss.pgh.pa.us>)
List pgsql-bugs
Any tips on using gdb to step through the code?


[postgres@va-mp-db02 ~]$ file /usr/local/pgsql/bin/postgres
/usr/local/pgsql/bin/postgres: ELF 64-bit LSB executable, x86-64,
version 1 (SYSV), dynamically linked (uses shared libs), for GNU/Linux
2.6.18, not stripped

---- Pg Log ---

<[unknown]@[unknown]  2009-10-16 12:33:33.600 EDT>LOG:  00000:
connection received: host=3D10.0.20.38 port=3D57014
<[unknown]@[unknown]  2009-10-16 12:33:33.600 EDT>LOCATION:
BackendInitialize, postmaster.c:3259
<[unknown]@[unknown] 10.0.20.38(57014) 2009-10-16 12:33:33.629
EDT>DEBUG:  00000: SSL connection from "(anonymous)"
<[unknown]@[unknown] 10.0.20.38(57014) 2009-10-16 12:33:33.629
EDT>LOCATION:  open_server_SSL, be-secure.c:961
<rdouglas@tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>DEBUG:
00000: SSL: read alert (0x0100)
<rdouglas@tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOCATION:
info_cb, be-secure.c:699
<rdouglas@tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOG:
08006: could not receive data from client: Connection reset by peer
<rdouglas@tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOCATION:
pq_recvbuf, pqcomm.c:769
<rdouglas@tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOG:
00000: RD - passwd is NULL... returning PAM_CONV_ERR
<rdouglas@tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOCATION:
pam_passwd_conv_proc, auth.c:1906
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: reaping dead processes
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  reaper, postmaster.c:2236
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: server process (PID 2257)
was terminated by signal 11: Segmentation fault
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  LogChildExit,
postmaster.c:2725
<@  2009-10-16 12:33:33.641 EDT>LOG:  00000: server process (PID 2257)
was terminated by signal 11: Segmentation fault
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  LogChildExit,
postmaster.c:2725
<@  2009-10-16 12:33:33.641 EDT>LOG:  00000: terminating any other
active server processes
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  HandleChildCrash,
postmaster.c:2552
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: sending SIGQUIT to
process 2251
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  HandleChildCrash,
postmaster.c:2621
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: sending SIGQUIT to
process 2252
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  HandleChildCrash,
postmaster.c:2633
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: shmem_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  shmem_exit, ipc.c:197
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: proc_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  proc_exit_prepare, ipc.c:169
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: shmem_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  shmem_exit, ipc.c:197
<@  2009-10-16 12:33:33.641 EDT>DEBUG:  00000: proc_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.641 EDT>LOCATION:  proc_exit_prepare, ipc.c:169
<@  2009-10-16 12:33:33.643 EDT>DEBUG:  00000: sending SIGQUIT to
process 2253
<@  2009-10-16 12:33:33.643 EDT>LOCATION:  HandleChildCrash,
postmaster.c:2645
<@  2009-10-16 12:33:33.643 EDT>DEBUG:  00000: sending SIGQUIT to
process 2254
<@  2009-10-16 12:33:33.643 EDT>LOCATION:  HandleChildCrash,
postmaster.c:2675
<@  2009-10-16 12:33:33.643 EDT>DEBUG:  00000: shmem_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.643 EDT>LOCATION:  shmem_exit, ipc.c:197
<@  2009-10-16 12:33:33.643 EDT>DEBUG:  00000: proc_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.643 EDT>LOCATION:  proc_exit_prepare, ipc.c:169
<@  2009-10-16 12:33:33.643 EDT>DEBUG:  00000: shmem_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.643 EDT>LOCATION:  shmem_exit, ipc.c:197
<@  2009-10-16 12:33:33.643 EDT>DEBUG:  00000: proc_exit(-1): 0
callbacks to make
<@  2009-10-16 12:33:33.643 EDT>LOCATION:  proc_exit_prepare, ipc.c:169
<@  2009-10-16 12:33:33.644 EDT>DEBUG:  00000: reaping dead processes
<@  2009-10-16 12:33:33.644 EDT>LOCATION:  reaper, postmaster.c:2236
<@  2009-10-16 12:33:33.644 EDT>DEBUG:  00000: reaping dead processes
<@  2009-10-16 12:33:33.644 EDT>LOCATION:  reaper, postmaster.c:2236
<@  2009-10-16 12:33:33.644 EDT>LOG:  00000: all server processes
terminated; reinitializing




-----Original Message-----
From: Tom Lane [mailto:tgl@sss.pgh.pa.us]=20
Sent: Friday, October 16, 2009 12:19 PM
To: Douglas, Ryan
Cc: pgsql-bugs@postgreSQL.org
Subject: Re: [BUGS] BUG #5121: Segmentation Fault when using pam w/ krb5


"Douglas, Ryan" <RDouglas@arbinet.com> writes:
> Program terminated with signal 11, Segmentation fault.
> #0  0x0000000000559624 in pam_passwd_conv_proc ()
> Missing separate debuginfos, use: debuginfo-install
audit-libs-1.7.13-1.fc11.x86_64
> (gdb) bt
> #0  0x0000000000559624 in pam_passwd_conv_proc ()
> #1  0x00007f738dfeedd8 in _pam_krb5_conv_call (pamh=3D<value optimized
out>, messages=3D0xb51780, n_prompts=3D0, responses=3D0x7fff2e356668) at
conv.c:99
> #2  0x00007f738dfefb38 in _pam_krb5_generic_prompter (context=3D<value
optimized out>, data=3D0x7fff2e357fe0, name=3D<value optimized out>,
banner=3D<value optimized out>, num_prompts=3D1,
>     prompts=3D<value optimized out>, suppress_password_prompts=3D1) at
prompter.c:330

Actually, now that I look more closely at that stack trace,
pam_passwd_conv_proc *is* a Postgres function --- so the core dump
is happening when libpam calls us back.  (I wonder why gdb failed
to present any information about it?  Are you using a stripped
postgres executable?)

In a quick look at the source for pam_passwd_conv_proc, the only
very plausible explanation for why it would segfault in isolated
cases seems to be that the initial sanity check on the passed-in
message status might be assuming more than it should --- in particular
it would obviously dump core if msg is null or msg[0] is null.

I am thinking that maybe, when the KDC is Active Directory and there's
no password supplied already, libpam makes additional calls to the
conv_proc with parameter values that we're not prepared to handle.
Can you add additional debug printouts or step through the code
and verify what's happening there?

            regards, tom lane

pgsql-bugs by date:

Previous
From: "Douglas, Ryan"
Date:
Subject: Re: BUG #5121: Segmentation Fault when using pam w/ krb5
Next
From: Robert Haas
Date:
Subject: Re: BUG #5118: start-status-insert-fatal