Re: BUG #5121: Segmentation Fault when using pam w/ krb5

Any tips on using gdb to step through the code?

[postgres(at)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](at)[unknown] 2009-10-16 12:33:33.600 EDT>LOG: 00000:
connection received: host=10.0.20.38 port=57014
<[unknown](at)[unknown] 2009-10-16 12:33:33.600 EDT>LOCATION:
BackendInitialize, postmaster.c:3259
<[unknown](at)[unknown] 10.0.20.38(57014) 2009-10-16 12:33:33.629
EDT>DEBUG: 00000: SSL connection from "(anonymous)"
<[unknown](at)[unknown] 10.0.20.38(57014) 2009-10-16 12:33:33.629
EDT>LOCATION: open_server_SSL, be-secure.c:961
<rdouglas(at)tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>DEBUG:
00000: SSL: read alert (0x0100)
<rdouglas(at)tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOCATION:
info_cb, be-secure.c:699
<rdouglas(at)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(at)tacacs 10.0.20.38(57014) 2009-10-16 12:33:33.634 EDT>LOCATION:
pq_recvbuf, pqcomm.c:769
<rdouglas(at)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(at)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(at)sss(dot)pgh(dot)pa(dot)us]
Sent: Friday, October 16, 2009 12:19 PM
To: Douglas, Ryan
Cc: pgsql-bugs(at)postgreSQL(dot)org
Subject: Re: [BUGS] BUG #5121: Segmentation Fault when using pam w/ krb5

"Douglas, Ryan" <RDouglas(at)arbinet(dot)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=<value optimized
out>, messages=0xb51780, n_prompts=0, responses=0x7fff2e356668) at
conv.c:99
> #2 0x00007f738dfefb38 in _pam_krb5_generic_prompter (context=<value
optimized out>, data=0x7fff2e357fe0, name=<value optimized out>,
banner=<value optimized out>, num_prompts=1,
> prompts=<value optimized out>, suppress_password_prompts=1) 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