<div dir="ltr">Hi everyone,<br><br>I have a repeatable core dump when running dovecot on FreeBSD in the specific scenario described below.<br><br>Dovecot is linked against MIT kerberos in /usr/local/lib/, whilst PAM is linked against Heimdal in /usr/lib/.<br>My expectation was that dovecot authentication using GSSAPI would use MIT kerberos in /usr/local/lib, whereas PAM authentication is independent from dovecot and would therefore use Herimdal in /usr/lib/.<br><br>What actually seems to occur during PAM authentication is the Heimdal code in /usr/lib/ is initially being used, but part way through it switches to using the MIT kerberos code in /usr/local/lib/.<br><br>I have reported this bug on the FreeBSD bug tracker here:<br><a href="https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=225818">https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=225818</a><br><br>Any help troubleshooting this issue would be much appreciated. I suspect it has something to do with the CFLAGS and LDFLAGS being used during the build, so I have attached the build log to the FreeBSD bug report.<br><br>Thanks in advance,<br>Ben<br><br><br>SCENARIO:<br>- Build mail/dovecot with option GSSAPI_MIT (link against MIT kerberos from ports rather than Heimdal in base)<br>- Configure dovecot for PAM authentication, using PAM service "imap":<br>  $ cat /usr/local/etc/dovecot/conf.d/10-auth.conf<br>  auth_mechanisms = plain<br>  passdb {<br>    driver = pam<br>    args = %s<br>  }<br>  userdb {<br>    driver = passwd<br>  }<br>- Configure imap pam to authenticate against kerberos (and enable debugging):<br>  $ cat /etc/pam.d/imap<br>  auth            sufficient      pam_krb5.so             debug<br>  account         required        pam_krb5.so             debug<br><br><br>RESULT:<br>This results in a crash of the dovecot authentication worker before any kerberos messages are even exchanged.<br><br><br>DIAGNOSIS:<br>Reviewing the log output below, my explanation of the backtrace is below (cronological order / newest item last):<br><br>- Dovecot had successfully performed pam_start(), the necessary pam_set_item(), and called pam_authenticate(pamh, 0)<br><a href="https://github.com/dovecot/core/blob/2.2.33.2/src/auth/passdb-pam.c#L158">https://github.com/dovecot/core/blob/2.2.33.2/src/auth/passdb-pam.c#L158</a><br><br>- PAM called pam_sm_authenticate() in /usr/lib/libpam/modules/pam_krb5/pam_krb5.c which successfully got the user, ruser, service, principal, password, checked local user, and then ran krb5_get_init_creds_opt_set_default_flags<br><a href="https://github.com/freebsd/freebsd/blob/master/lib/libpam/modules/pam_krb5/pam_krb5.c#L242">https://github.com/freebsd/freebsd/blob/master/lib/libpam/modules/pam_krb5/pam_krb5.c#L242</a><br><br>- Heimdal krb5_get_init_creds_opt_set_default_flags ran the Heimdal version of krb5_appdefault_time:<br><a href="https://github.com/freebsd/freebsd/blob/master/crypto/heimdal/lib/krb5/init_creds.c#L171">https://github.com/freebsd/freebsd/blob/master/crypto/heimdal/lib/krb5/init_creds.c#L171</a><br><br>- Heimdal function krb5_appdefault_time ran the MIT kerberos version of krb5_appdefault_string:<br><a href="https://github.com/freebsd/freebsd/blob/master/crypto/heimdal/lib/krb5/appdefault.c#L130">https://github.com/freebsd/freebsd/blob/master/crypto/heimdal/lib/krb5/appdefault.c#L130</a><br><br>This is where the code path cross from using the Heimdal code to the MIT kerberos code, which it should not do. I know this, because the GDB backtrace shows the krb5_appdefault_string function called strdup in file appdefault.c:165, but the Heimdal appdefault.c file only has 140 lines. Reviewing the MIT kerberos code, the strdup function is indeed called at appdefault.c:165.<br><br>Why did the Heimdal appdefault.c code call the MIT kerberos version of krb5_appdefault_string, when the Heimdal version was only 50 lines higher in the same appdefault.c file?<br><br><br>ENVIRONMENT:<br>$ dovecot -n<br># 2.2.33.2 (d6601f4ec): /usr/local/etc/dovecot/dovecot.conf<br># OS: FreeBSD 12.0-CURRENT amd64  zfs<br>auth_debug = yes<br>auth_debug_passwords = yes<br>auth_krb5_keytab = /usr/local/etc/dovecot/dovecot.keytab<br>auth_mechanisms = plain login gssapi<br>auth_realms = <a href="http://WOODS.AM">WOODS.AM</a><br>auth_verbose = yes<br>mail_location = mdbox:/var/mail/%u<br>namespace inbox {<br>  inbox = yes<br>  location =<br>  mailbox Drafts {<br>    special_use = \Drafts<br>  }<br>  mailbox Junk {<br>    special_use = \Junk<br>  }<br>  mailbox Sent {<br>    special_use = \Sent<br>  }<br>  mailbox "Sent Messages" {<br>    special_use = \Sent<br>  }<br>  mailbox Trash {<br>    special_use = \Trash<br>  }<br>  prefix =<br>}<br>passdb {<br>  args = failure_show_msg=yes %s<br>  driver = pam<br>}<br>service auth-worker {<br>  drop_priv_before_exec = yes<br>}<br>ssl_cert = </usr/local/etc/ssl/<a href="http://mail.woods.am/fullchain.pem">mail.woods.am/fullchain.pem</a><br>ssl_key =  # hidden, use -P to show it<br>userdb {<br>  driver = passwd<br>}<br><br>GDB BACKTRACE OF COREDUMP:<br>$ gdb /usr/local/libexec/dovecot/auth<br>GNU gdb (GDB) 8.0.1 [GDB v8.0.1 for FreeBSD]<br>Copyright (C) 2017 Free Software Foundation, Inc.<br>License GPLv3+: GNU GPL version 3 or later <<a href="http://gnu.org/licenses/gpl.html">http://gnu.org/licenses/gpl.html</a>><br>This is free software: you are free to change and redistribute it.<br>There is NO WARRANTY, to the extent permitted by law.  Type "show copying"<br>and "show warranty" for details.<br>This GDB was configured as "x86_64-portbld-freebsd12.0".<br>Type "show configuration" for configuration details.<br>For bug reporting instructions, please see:<br><<a href="http://www.gnu.org/software/gdb/bugs/">http://www.gnu.org/software/gdb/bugs/</a>>.<br>Find the GDB manual and other documentation resources online at:<br><<a href="http://www.gnu.org/software/gdb/documentation/">http://www.gnu.org/software/gdb/documentation/</a>>.<br>For help, type "help".<br>Type "apropos word" to search for commands related to "word"...<br>Reading symbols from /usr/local/libexec/dovecot/auth...done.<br>(gdb) core /tmp/auth.core<br>[New LWP 102627]<br>warning: Can't read pathname for load map: Unknown error: -1.<br>warning: Can't read pathname for load map: Unknown error: -1.<br>warning: Can't read pathname for load map: Unknown error: -1.<br>warning: Can't read pathname for load map: Unknown error: -1.<br>Core was generated by `dovecot/auth -w'.<br>Program terminated with signal SIGSEGV, Segmentation fault.<br>#0  strlen (str=0x0) at /usr/src/lib/libc/string/strlen.c:100<br>warning: Source file is more recent than executable.<br>100              */<br>(gdb) bt<br>#0  strlen (str=0x0) at /usr/src/lib/libc/string/strlen.c:100<br>#1  0x0000000012130022 in strdup (str=0x0) at /usr/src/lib/libc/string/strdup.c:46<br>#2  0x0000000011b65e9d in krb5_appdefault_string (context=0x10777000, appname=0x106f0018 "imap", realm=0x0, option=0x13b1f403 "ticket_lifetime", default_value=0x0, ret_value=0x7fffffffe088)<br>    at appdefault.c:165<br>#3  0x0000000013af4a80 in krb5_appdefault_time (context=0x0, appname=0xffffffffaaca6003 <error: Cannot access memory at address 0xffffffffaaca6003>, <br>    realm=0x50 <error: Cannot access memory at address 0x50>, option=0x0, def_val=0, ret_val=0x7fffffffe0e0) at /usr/src/crypto/heimdal/lib/krb5/appdefault.c:130<br>#4  0x0000000013ae3e79 in krb5_get_init_creds_opt_set_default_flags (context=0x10777000, appname=0x106f0018 "imap", realm=0x0, opt=0x1070f3c0)<br>    at /usr/src/crypto/heimdal/lib/krb5/init_creds.c:171<br>#5  0x00000000138b738f in ?? ()<br>#6  0x0000000000000000 in ?? ()<br><br><br>LOG OUTPUT:<br>$ cat /var/log/maillog:<br>Feb 11 09:20:40 mail dovecot: auth: Error: auth worker: Aborted PASSV request for woodsb02: Worker process died unexpectedly<br>Feb 11 09:20:40 mail dovecot: auth-worker(34874): Fatal: master: service(auth-worker): child 34874 killed with signal 11 (core dumped)<br>Feb 11 09:20:47 mail dovecot: imap-login: Disconnected (auth failed, 1 attempts in 7 secs): user=<woodsb02>, method=PLAIN, rip=192.168.1.13, lip=192.168.1.13, TLS, session=<GRJsRuxkf17AqAEN><br><br>$ cat /var/log/debug.log:<br>Feb 11 09:20:35 mail dovecot: auth: Debug: auth client connected (pid=34853)                                                                                                         [34/1991]<br>Feb 11 09:20:40 mail dovecot: auth: Debug: client in: AUTH      1       PLAIN   service=imap    secured session=GRJsRuxkf17AqAEN        lip=192.168.1.13        rip=192.168.1.13        lport=<br>993     rport=24191     resp=AHdvb2RzYjAyAHRlc3Q= (previous base64 data may contain sensitive data)<br>Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: Loading modules from directory: /usr/local/lib/dovecot/auth<br>Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: Module loaded: /usr/local/lib/dovecot/auth/lib20_auth_var_expand_crypt.so<br>Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: pam(woodsb02,192.168.1.13,<GRJsRuxkf17AqAEN>): lookup service=imap<br>Feb 11 09:20:40 mail auth: in openpam_dispatch(): calling pam_sm_authenticate() in /usr/lib/pam_krb5.so.6<br>Feb 11 09:20:40 mail auth: in pam_get_user(): entering             <br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_USER   <br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS   <br>Feb 11 09:20:40 mail auth: in pam_get_user(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got user: woodsb02      <br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_RUSER <br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS          <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got ruser: woodsb02<br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_SERVICE <br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS                                                 <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got service: imap                                                            <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Context initialised                            <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Done krb5_cc_register()<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'auth_as_self'                          <br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL                                                  <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Created principal: woodsb02                             <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Done krb5_parse_name() <br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got principal: <a href="mailto:woodsb02@WOODS.AM">woodsb02@WOODS.AM</a><br>Feb 11 09:20:40 mail auth: in pam_get_authtok(): entering                                             <br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_RHOST                                                   <br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS                                          <br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_HOST            <br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS         <br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_OLDAUTHTOK                                                                                                                       <br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'try_first_pass'<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'use_first_pass'<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'authtok_prompt'<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL<br>Feb 11 09:20:40 mail auth: in openpam_subst(): entering: 'Password:'<br>Feb 11 09:20:40 mail auth: in openpam_subst(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'echo_pass'<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL<br>Feb 11 09:20:40 mail auth: in pam_vprompt(): entering<br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_CONV<br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in pam_vprompt(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in pam_set_item(): entering: PAM_AUTHTOK<br>Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: pam(woodsb02,192.168.1.13,<GRJsRuxkf17AqAEN>): #1/1 style=1 msg=Password:<br>Feb 11 09:20:40 mail auth: in pam_set_item(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_AUTHTOK<br>Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in pam_get_authtok(): returning PAM_SUCCESS<br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got password<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'no_user_check'<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'no_user_check'<br>Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL<br>Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Done getpwnam()<br>Feb 11 09:20:40 mail dovecot: auth-worker(34875): Debug: Loading modules from directory: /usr/local/lib/dovecot/auth<br>Feb 11 09:20:40 mail dovecot: auth-worker(34875): Debug: Module loaded: /usr/local/lib/dovecot/auth/lib20_auth_var_expand_crypt.so<br><br><br><br>$ ldd /usr/local/libexec/dovecot/auth<br>/usr/local/libexec/dovecot/auth:<br>        libstats_auth.so => /usr/local/lib/dovecot/stats/libstats_auth.so (0x80089a000)<br>        libdovecot.so.0 => /usr/local/lib/dovecot/libdovecot.so.0 (0x800a9c000)<br>        libcrypt.so.5 => /lib/libcrypt.so.5 (0x800e3a000)<br>        libpam.so.6 => /usr/lib/libpam.so.6 (0x801058000)<br>        libk5crypto.so.3.1 => /usr/local/lib/libk5crypto.so.3.1 (0x801265000)<br>        libcom_err.so.3.0 => /usr/local/lib/libcom_err.so.3.0 (0x8014b3000)<br>        libldap-2.4.so.2 => /usr/local/lib/libldap-2.4.so.2 (0x8016b6000)<br>        liblber-2.4.so.2 => /usr/local/lib/liblber-2.4.so.2 (0x8018fc000)<br>        libkrb5.so.3.3 => /usr/local/lib/libkrb5.so.3.3 (0x801b0b000)<br>        libgssapi_krb5.so.2.2 => /usr/local/lib/libgssapi_krb5.so.2.2 (0x801e27000)<br>        libc.so.7 => /lib/libc.so.7 (0x802090000)<br>        libkrb5support.so.0.1 => /usr/local/lib/libkrb5support.so.0.1 (0x802679000)<br>        libintl.so.8 => /usr/local/lib/libintl.so.8 (0x802888000)<br>        libssl.so.44 => /usr/local/lib/libssl.so.44 (0x802a93000)<br>        libcrypto.so.42 => /usr/local/lib/libcrypto.so.42 (0x802ce7000)<br><br>$ ldd /usr/lib/pam_krb5.so.6<br>/usr/lib/pam_krb5.so.6:<br>        libkrb5.so.11 => /usr/lib/libkrb5.so.11 (0x801614000)<br>        libpam.so.6 => /usr/lib/libpam.so.6 (0x801892000)<br>        libc.so.7 => /lib/libc.so.7 (0x800826000)<br>        libasn1.so.11 => /usr/lib/libasn1.so.11 (0x801a9f000)<br>        libcom_err.so.5 => /usr/lib/libcom_err.so.5 (0x801d40000)<br>        libcrypt.so.5 => /lib/libcrypt.so.5 (0x801f42000)<br>        libcrypto.so.8 => /lib/libcrypto.so.8 (0x802200000)<br>        libhx509.so.11 => /usr/lib/libhx509.so.11 (0x80266e000)<br>        libroken.so.11 => /usr/lib/libroken.so.11 (0x8028bb000)<br>        libwind.so.11 => /usr/lib/libwind.so.11 (0x802ace000)<br>        libheimbase.so.11 => /usr/lib/libheimbase.so.11 (0x802cf6000)<br>        libprivateheimipcc.so.11 => /usr/lib/libprivateheimipcc.so.11 (0x802efa000)<br>        libthr.so.3 => /lib/libthr.so.3 (0x8030fc000)<br clear="all"><div><div class="gmail_signature"><br>--<br>From: Benjamin Woods<br><a href="mailto:woodsb02@gmail.com" target="_blank">woodsb02@gmail.com</a></div></div>
</div>