SCENARIO: - Build mail/dovecot with option GSSAPI_MIT - Configure dovecot for PAM authentication, using PAM service "imap": $ cat /usr/local/etc/dovecot/conf.d/10-auth.conf auth_mechanisms = plain passdb { driver = pam args = %s } userdb { driver = passwd } - Configure imap pam to authenticate against kerberos (and enable debugging): $ cat /etc/pam.d/imap auth sufficient pam_krb5.so debug account required pam_krb5.so debug RESULT: This results in a crash of the dovecot authentication worker before any kerberos messages are even exchanged. GDB BACKTRACE OF COREDUMP: $ gdb /usr/local/libexec/dovecot/auth GNU gdb (GDB) 8.0.1 [GDB v8.0.1 for FreeBSD] Copyright (C) 2017 Free Software Foundation, Inc. License GPLv3+: GNU GPL version 3 or later <http://gnu.org/licenses/gpl.html> This is free software: you are free to change and redistribute it. There is NO WARRANTY, to the extent permitted by law. Type "show copying" and "show warranty" for details. This GDB was configured as "x86_64-portbld-freebsd12.0". Type "show configuration" for configuration details. For bug reporting instructions, please see: <http://www.gnu.org/software/gdb/bugs/>. Find the GDB manual and other documentation resources online at: <http://www.gnu.org/software/gdb/documentation/>. For help, type "help". Type "apropos word" to search for commands related to "word"... Reading symbols from /usr/local/libexec/dovecot/auth...done. (gdb) core /tmp/auth.core [New LWP 102627] warning: Can't read pathname for load map: Unknown error: -1. warning: Can't read pathname for load map: Unknown error: -1. warning: Can't read pathname for load map: Unknown error: -1. warning: Can't read pathname for load map: Unknown error: -1. Core was generated by `dovecot/auth -w'. Program terminated with signal SIGSEGV, Segmentation fault. #0 strlen (str=0x0) at /usr/src/lib/libc/string/strlen.c:100 warning: Source file is more recent than executable. 100 */ (gdb) bt #0 strlen (str=0x0) at /usr/src/lib/libc/string/strlen.c:100 #1 0x0000000012130022 in strdup (str=0x0) at /usr/src/lib/libc/string/strdup.c:46 #2 0x0000000011b65e9d in krb5_appdefault_string (context=0x10777000, appname=0x106f0018 "imap", realm=0x0, option=0x13b1f403 "ticket_lifetime", default_value=0x0, ret_value=0x7fffffffe088) at appdefault.c:165 #3 0x0000000013af4a80 in krb5_appdefault_time (context=0x0, appname=0xffffffffaaca6003 <error: Cannot access memory at address 0xffffffffaaca6003>, 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 #4 0x0000000013ae3e79 in krb5_get_init_creds_opt_set_default_flags (context=0x10777000, appname=0x106f0018 "imap", realm=0x0, opt=0x1070f3c0) at /usr/src/crypto/heimdal/lib/krb5/init_creds.c:171 #5 0x00000000138b738f in ?? () #6 0x0000000000000000 in ?? () LOG OUTPUT: $ cat /var/log/maillog: Feb 11 09:20:40 mail dovecot: auth: Error: auth worker: Aborted PASSV request for woodsb02: Worker process died unexpectedly Feb 11 09:20:40 mail dovecot: auth-worker(34874): Fatal: master: service(auth-worker): child 34874 killed with signal 11 (core dumped) 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> $ cat /var/log/debug.log: Feb 11 09:20:35 mail dovecot: auth: Debug: auth client connected (pid=34853) [34/1991] 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= 993 rport=24191 resp=AHdvb2RzYjAyAHRlc3Q= (previous base64 data may contain sensitive data) Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: Loading modules from directory: /usr/local/lib/dovecot/auth Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: Module loaded: /usr/local/lib/dovecot/auth/lib20_auth_var_expand_crypt.so Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: pam(woodsb02,192.168.1.13,<GRJsRuxkf17AqAEN>): lookup service=imap Feb 11 09:20:40 mail auth: in openpam_dispatch(): calling pam_sm_authenticate() in /usr/lib/pam_krb5.so.6 Feb 11 09:20:40 mail auth: in pam_get_user(): entering Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_USER Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_get_user(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got user: woodsb02 Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_RUSER Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got ruser: woodsb02 Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_SERVICE Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got service: imap Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Context initialised Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Done krb5_cc_register() Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'auth_as_self' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Created principal: woodsb02 Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Done krb5_parse_name() Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got principal: woodsb02@WOODS.AM Feb 11 09:20:40 mail auth: in pam_get_authtok(): entering Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_RHOST Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_HOST Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_OLDAUTHTOK Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'try_first_pass' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'use_first_pass' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'authtok_prompt' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in openpam_subst(): entering: 'Password:' Feb 11 09:20:40 mail auth: in openpam_subst(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'echo_pass' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in pam_vprompt(): entering Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_CONV Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_vprompt(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_set_item(): entering: PAM_AUTHTOK Feb 11 09:20:40 mail dovecot: auth-worker(34874): Debug: pam(woodsb02,192.168.1.13,<GRJsRuxkf17AqAEN>): #1/1 style=1 msg=Password: Feb 11 09:20:40 mail auth: in pam_set_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_get_item(): entering: PAM_AUTHTOK Feb 11 09:20:40 mail auth: in pam_get_item(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_get_authtok(): returning PAM_SUCCESS Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Got password Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'no_user_check' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in openpam_get_option(): entering: 'no_user_check' Feb 11 09:20:40 mail auth: in openpam_get_option(): returning NULL Feb 11 09:20:40 mail auth: in pam_sm_authenticate(): Done getpwnam() Feb 11 09:20:40 mail dovecot: auth-worker(34875): Debug: Loading modules from directory: /usr/local/lib/dovecot/auth Feb 11 09:20:40 mail dovecot: auth-worker(34875): Debug: Module loaded: /usr/local/lib/dovecot/auth/lib20_auth_var_expand_crypt.so
Reviewing the log output, my explanation of the backtrace is below (cronological order / newest item last): - Dovecot had successfully performed pam_start(), the necessary pam_set_item(), and called pam_authenticate(pamh, 0) https://github.com/dovecot/core/blob/2.2.33.2/src/auth/passdb-pam.c#L158 - 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 https://github.com/freebsd/freebsd/blob/master/lib/libpam/modules/pam_krb5/pam_krb5.c#L242 - Heimdal krb5_get_init_creds_opt_set_default_flags ran the Heimdal version of krb5_appdefault_time: https://github.com/freebsd/freebsd/blob/master/crypto/heimdal/lib/krb5/init_creds.c#L171 - Heimdal function krb5_appdefault_time ran the MIT kerberos version of krb5_appdefault_string: https://github.com/freebsd/freebsd/blob/master/crypto/heimdal/lib/krb5/appdefault.c#L130 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. 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?
Ben, you should report this upstream at https://dovecot.org/bugreport.html They're very responsive, and I know very little about Kerberos. Please also check whether this has been fixed already. 2.3.0 was released in December, but I'm waiting for 2.3.1 before I commit the update. I'm happy to backport a fix now if it's available though.
Created attachment 190543 [details] Poudriere build log of mail/dovecot with option GSSAPI_MIT enabled (gzipped) ENVIRONMENT DETAILS: $ dovecot -n # 2.2.33.2 (d6601f4ec): /usr/local/etc/dovecot/dovecot.conf # OS: FreeBSD 12.0-CURRENT amd64 zfs auth_debug = yes auth_debug_passwords = yes auth_krb5_keytab = /usr/local/etc/dovecot/dovecot.keytab auth_mechanisms = plain login gssapi auth_realms = WOODS.AM auth_verbose = yes mail_location = mdbox:/var/mail/%u namespace inbox { inbox = yes location = mailbox Drafts { special_use = \Drafts } mailbox Junk { special_use = \Junk } mailbox Sent { special_use = \Sent } mailbox "Sent Messages" { special_use = \Sent } mailbox Trash { special_use = \Trash } prefix = } passdb { args = failure_show_msg=yes %s driver = pam } service auth-worker { drop_priv_before_exec = yes } ssl_cert = </usr/local/etc/ssl/mail.woods.am/fullchain.pem ssl_key = # hidden, use -P to show it userdb { driver = passwd }
I have posted this bug report to the dovecot mailing list here: https://dovecot.org/pipermail/dovecot/2018-February/110897.html
Dovecot wraps all of the possible authentication methods into a single library libauth.so, so it is not possible to separate the PAM authentication libraries from the GSSAPI authentication libraries. If dovecot is compiled to dynamically link against the ports MIT kerberos libraries for GSSAPI authentication, it will break PAM authentication using kerberos credentials. This is because the system PAM libraries are linked against the base heimdal libraries, and when PAM is dynamically loaded by dovecot's libauth.so, both the base heimdal libraries and ports MIT kerberos libraries will be loaded. It is unlikely this can be resolved unless libauth.so is split out into separate libraries for each authentication method.
What happens if you install security/pam_krb5? If it works that way, I can definitely add GSSAPI_MIT_RUN_DEPENDS+= security/pam_krb5
Ah... that's a very good idea, and probably the right answer. I have just spent the entire day re-working my mail setup to avoid linking to MIT kerberos... so it may take me a while to test this. I am 95% confident it is the right answer though.
Over to new maintainer
I am not going to get the time to look into this further, but I think adamw's recommendation to use the port security/pam_krb5 is likely the right solution.