Date: Sat, 2 Feb 2019 13:40:32 -0800 From: Patrick Mahan <plmahan@gmail.com> To: User Questions <freebsd-questions@freebsd.org> Subject: Help debugging pam authentication for dovecot Message-ID: <CAFDHx1%2BE8_NoftRyKazJWN4XkBRDuCFT9r5qX5zk_n_gnU%2B=DQ@mail.gmail.com>
next in thread | raw e-mail | index | archive | help
FreeBSD 11.2-RELEASE-p7 Dovecot 2.3.4 Postfix 3.3.2 I recently upgraded my domain server (mahan.org) from FBSD 9.2 to FBSD 11.2. Due to some configuration issues with my sendmail due to the upgrade, I was suddenly relaying spam. I decided it was time to switch to something newer and after a little research installed postfix. I then modified the dovecot config to support postfix instead of sendmail. This has shutdown the spam relaying. However a new issue has cropped up. I cannot access mail via IMAP through dovecot. The failure seems to be with the user authentication, which is configured to use PAM. My imap client (both thunderbird and iOS mail) report that the password is invalid. Looking at both maillog, auth.log and debug.log I see that PAM is refusing authentication. My /usr/local/pam.d/dovecot file contains - # # ns.mahan.org - dovecot pam config # Use pam to access standard user passwd # # PAM configuration for the "dovecot" service # # auth auth required pam_unix.so debug nullok local_pass # account account required pam_unix.so debug try_first_pass local_pass I have testing using the pamtester-0.1.2 and the user authentication passes. I cannot understand what the failure mode code be with dovecot. The command I used was 'pamtester -v dovecot mahan authenticate' As you can see I have enabled PAM debugging and have that output, but it is rather involved so I was going to wait until it was requested. Based on the debug output I see some differences (1 minor, 1 major): Both ways cause the following log message - Feb 2 12:43:24 ns pamtester: in pam_sm_authenticate(): Got user: mahan Feb 2 12:43:24 ns pamtester: in pam_sm_authenticate(): Doing real authentication The minor difference I see is - with pamtester Feb 2 12:43:24 ns pamtester: in pam_get_authtok(): entering Feb 2 12:43:24 ns pamtester: in pam_get_item(): entering: PAM_RHOST Feb 2 12:43:24 ns pamtester: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:43:24 ns pamtester: in pam_get_item(): entering: PAM_OLDAUTHTOK Feb 2 12:43:24 ns pamtester: in pam_get_item(): returning PAM_SUCCESS with dovecot Feb 2 12:46:19 ns auth: in pam_get_authtok(): entering Feb 2 12:46:19 ns auth: in pam_get_item(): entering: PAM_RHOST Feb 2 12:46:19 ns auth: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:46:19 ns auth: in pam_get_item(): entering: PAM_HOST Feb 2 12:46:19 ns auth: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:46:19 ns auth: in pam_get_item(): entering: PAM_OLDAUTHTOK Feb 2 12:46:19 ns auth: in pam_get_item(): returning PAM_SUCCESS Dovecot causes PAM_HOST get item. This may be something that can be included with the '-I' option of pamtester, so I do think it is really an issue. The major difference I see is - with pamtester Feb 2 12:43:24 ns pamtester: in openpam_get_option(): entering: 'authtok_prompt' Feb 2 12:43:24 ns pamtester: in openpam_get_option(): returning NULL Feb 2 12:43:24 ns pamtester: in pam_get_item(): entering: PAM_AUTHTOK_PROMPT Feb 2 12:43:24 ns pamtester: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:43:24 ns pamtester: in openpam_subst(): entering: 'Password:' Feb 2 12:43:24 ns pamtester: in openpam_subst(): returning PAM_SUCCESS with dovecot Feb 2 12:46:19 ns auth: in openpam_get_option(): entering: 'authtok_prompt' Feb 2 12:46:19 ns auth: in openpam_get_option(): returning NULL Feb 2 12:46:19 ns auth: in pam_get_item(): entering: PAM_AUTHTOK_PROMPT Feb 2 12:46:19 ns auth: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:46:19 ns auth: in openpam_subst(): entering: 'Password for %u@%h:' Feb 2 12:46:19 ns auth: in pam_get_item(): entering: PAM_USER Feb 2 12:46:19 ns auth: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:46:19 ns auth: in pam_get_item(): entering: PAM_HOST Feb 2 12:46:19 ns auth: in pam_get_item(): returning PAM_SUCCESS Feb 2 12:46:19 ns auth: in openpam_subst(): returning PAM_SUCCESS I don't know if this is the problem. I am unsure how this works differently between pamtester and dovecot so I am looking for some help here. After these lines, I see for pamtester - Feb 2 12:43:27 ns pamtester: in pam_sm_authenticate(): Got password Feb 2 12:43:27 ns pamtester: in openpam_dispatch(): /usr/lib/pam_unix.so.6: pam_sm_authenticate(): success while with dovecot Feb 2 12:46:19 ns auth: in pam_vprompt(): returning PAM_SUCCESS Feb 2 12:46:19 ns auth: in openpam_dispatch(): /usr/lib/pam_unix.so.6: pam_sm_authenticate(): authentication error I'm sure I have something odd configured in dovecot, but after working through a couple of examples on the web, I don't see what I have done incorrectly. Corrections, pointers, help is welcomed. Thanks Patrick
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?CAFDHx1%2BE8_NoftRyKazJWN4XkBRDuCFT9r5qX5zk_n_gnU%2B=DQ>