[SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

hjheins · 2024-11-21 14:56:04

OK, this is going to be a fairly long and tricky one....

I have a server with Postfix and Courier-imap and Courier-Authdaemon installed
In order for the user to get to his/her mail, he should authenticate. This is where, when using imap, the Authdaemon comes into play.

In the Courier-Authdaemon config, you can define your " authmodulelist"
In there, authshadow seems to work without issue.

However, I would like to use authpam as it is seemingly more secure.
In order to use authpam, a config should be defined for imap -> /etc/pam.d/imap
You can not use the config as suggested by the Courier-Authdaemon, as that is too old.
(https://www.courier-mta.org/authlib/REA … ml#authpam)

When you " update" what is suggested there and include system-auth in your pam config, you run into this error:
(all users actually exist, and the passwords are correct)

authdaemond[]: pam_unix(imap:auth): authentication failure; logname= uid=<uid>.....
authdaemond[]: pam_unix(imap:auth): received for user <username>:7 (Authentication failure)

Apparently this issue has to do with the fact that courier-imap and courier-authdaemon run under their own user " courier" , and not under user root.
It seems that pam_unix can only verify logins when the service user is root (which it is clearly not in this case). source

In order to work around this, I found pam_sssd (arch package sssd).
Apparently this can be used as an authentication proxy for services that run under a non-root user.

So I set this up, and connected as per the documentation (https://wiki.archlinux.org/title/SSSD)

I also added a new /etc/pam.d/imap file with the contents as per the mentioned wiki,
Next I started the new sssd service and restarted the courier authdaemon.
However the logs still seem to give exactly the same errors; only with the sssd layer in between?

authdaemond[]: pam_sss(imap:auth): authentication failure; logname= uid=<uid> euid=<euid> tty= ....
authdaemond[]: pam_sss(imap:auth): received for user <username>: 7 (Authentication failure)

what' s going on here, and how can I solve this one?

thanks

*****UPDATE*****
I once more checked the sssd settings, and made some changes so that the whole service runs under the root user (inc. logs and pid).
Now I seem to be a step further: sssd seems to run and be available with no errors in the logs.
However, it seems that for some reason the courier-authdaemon has no access to the pam_sss socket?
What does this mean, and how can I solve this. Logs:

authdaemond[1]: pam_sss(imap:auth): Request to sssd failed. Socket has wrong ownership or permissions.
authdaemond[1]: pam_sss(imap:auth): Request to sssd failed. Socket has wrong ownership or permissions.
authdaemond[2]: pam_authenticate failed, result 9
authdaemond[2]: authpam: REJECT - try next module

Last edited by hjheins (2024-12-08 11:01:29)

hjheins · 2024-11-22 13:48:36

Right, I reverted to running everything as user and group sssd, as it seems that running as root only resulted in more issues.

The full log I get when using sssd according to Archwiki (minus running as root) now gives:

imapd[1]: Connection, ip=[:<someip>], port=[<someport>]
proxy_child[2]: Starting up
proxy_child[2]: pam_unix(sssd-shadowutils:auth): authentication failure; logname= uid=<uid> euid=<euid> tty= rus>
authdaemond[3]: pam_sss(imap:auth): authentication failure; logname= uid=<uid> euid=<euid> tty= ruser= rhost=::fff>
authdaemond[3]: pam_sss(imap:auth): received for user <username>: 7 (Authentication failure)

anyone?

hjheins · 2024-11-22 15:36:43

Right, I have the feeling that I am making headway, but only slowly.
From what I can gather, the Archwiki for sssd is not that accurate.
I now have the following config:

[sssd]
services = pam
domains = imap
debug_level=6

[domain/imap]
id_provider = files 
proxy_lib_name = files
proxy_pam_target = sssd-shadowutils
enable_files_domain = False

this gets me in the right direction as now the log at /var/log/sssd_imap.log just outputs on starting the service.
All the other info is in the log /var/log/sssd_pam.log.
When I try to connect to IMAP I now get:

   *  (2024-11-22 15:25:08): [pam] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x8c49f8][18]
   *  (2024-11-22 15:25:08): [pam] [accept_fd_handler] (0x0400): [CID#1] Client [cmd /usr/lib/courier-authlib/authdaemond][uid 72][0x8c49f8][18] connected!
   *  (2024-11-22 15:25:08): [pam] [sss_cmd_get_version] (0x0200): [CID#1] Received client version [3].
   *  (2024-11-22 15:25:08): [pam] [sss_cmd_get_version] (0x0200): [CID#1] Offered version [3].
   *  (2024-11-22 15:25:08): [pam] [pam_cmd_preauth] (0x0100): [CID#1] entering pam_cmd_preauth
   *  (2024-11-22 15:25:08): [pam] [sss_parse_name] (0x0200): [CID#1] Domain not provided!
   *  (2024-11-22 15:25:08): [pam] [sss_parse_name_for_domains] (0x0200): [CID#1] name '<username>' matched without domain, user is <username>
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] command: SSS_PAM_PREAUTH
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] domain: not set
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] user: <username>
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] service: imap
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] tty: not set
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] ruser: not set
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] rhost: 2a02:8071:6141:e2e0:2f73:1bcc:c771:8d4f
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] authtok type: 0 (No authentication token available)
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] newauthtok type: 0 (No authentication token available)
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] priv: 0
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] cli_pid: 24512
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] child_pid: 0
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] logon name: <username>
   *  (2024-11-22 15:25:08): [pam] [pam_print_data] (0x0100): [CID#1] flags: 0
   *  (2024-11-22 15:25:08): [pam] [cache_req_set_plugin] (0x2000): [CID#1] CR #0: Setting "Initgroups by name" plugin
   *  (2024-11-22 15:25:08): [pam] [cache_req_send] (0x0400): [CID#1] CR #0: REQ_TRACE: New request [CID #1] '(null)'
   *  (2024-11-22 15:25:08): [pam] [cache_req_process_input] (0x0400): [CID#1] CR #0: Parsing input name [<username>]
   *  (2024-11-22 15:25:08): [pam] [sss_parse_name] (0x0200): [CID#1] Domain not provided!
   *  (2024-11-22 15:25:08): [pam] [sss_parse_name_for_domains] (0x0200): [CID#1] name '<username>' matched without domain, user is <username>
   *  (2024-11-22 15:25:08): [pam] [cache_req_set_name] (0x0400): [CID#1] CR #0: Setting name [<username>]
   *  (2024-11-22 15:25:08): [pam] [cache_req_select_domains] (0x0400): [CID#1] CR #0: Performing a multi-domain search
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_domains] (0x0400): [CID#1] CR #0: Search will check the cache and bypass the data provider
   *  (2024-11-22 15:25:08): [pam] [cache_req_validate_domain_type] (0x2000): [CID#1] Request type POSIX-only for domain imap type POSIX is valid
   *  (2024-11-22 15:25:08): [pam] [cache_req_set_domain] (0x0400): [CID#1] CR #0: Using domain [imap]
   *  (2024-11-22 15:25:08): [pam] [cache_req_prepare_domain_data] (0x0400): [CID#1] CR #0: Preparing input data for domain [imap] rules
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_send] (0x0400): [CID#1] CR #0: Looking up <username>@imap
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #0: Checking negative cache for [<username>@imap]
   *  (2024-11-22 15:25:08): [pam] [sss_ncache_check_str] (0x2000): [CID#1] Checking negative cache for [NCE/USER/imap/<username>@imap]
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #0: [<username>@imap] is not present in negative cache
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_cache] (0x0400): [CID#1] CR #0: Looking up [<username>@imap] in cache
   *  (2024-11-22 15:25:08): [pam] [cache_req_process_result] (0x0400): [CID#1] CR #0: Finished: Not found
   *  (2024-11-22 15:25:08): [pam] [pam_check_user_search_next] (0x4000): [CID#1] PAM initgroups scheme [no_session].
   *  (2024-11-22 15:25:08): [pam] [cache_req_set_plugin] (0x2000): [CID#1] CR #1: Setting "Initgroups by name" plugin
   *  (2024-11-22 15:25:08): [pam] [cache_req_send] (0x0400): [CID#1] CR #1: REQ_TRACE: New request [CID #1] '(null)'
   *  (2024-11-22 15:25:08): [pam] [cache_req_process_input] (0x0400): [CID#1] CR #1: Parsing input name [<username>]
   *  (2024-11-22 15:25:08): [pam] [sss_parse_name] (0x0200): [CID#1] Domain not provided!
   *  (2024-11-22 15:25:08): [pam] [sss_parse_name_for_domains] (0x0200): [CID#1] name '<username>' matched without domain, user is <username>
   *  (2024-11-22 15:25:08): [pam] [cache_req_set_name] (0x0400): [CID#1] CR #1: Setting name [<username>]
   *  (2024-11-22 15:25:08): [pam] [cache_req_select_domains] (0x0400): [CID#1] CR #1: Performing a multi-domain search
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_domains] (0x0400): [CID#1] CR #1: Search will bypass the cache and check the data provider
   *  (2024-11-22 15:25:08): [pam] [cache_req_validate_domain_type] (0x2000): [CID#1] Request type POSIX-only for domain imap type POSIX is valid
   *  (2024-11-22 15:25:08): [pam] [cache_req_set_domain] (0x0400): [CID#1] CR #1: Using domain [imap]
   *  (2024-11-22 15:25:08): [pam] [cache_req_prepare_domain_data] (0x0400): [CID#1] CR #1: Preparing input data for domain [imap] rules
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_send] (0x0400): [CID#1] CR #1: Looking up <username>@imap
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #1: Checking negative cache for [<username>@imap]
   *  (2024-11-22 15:25:08): [pam] [sss_ncache_check_str] (0x2000): [CID#1] Checking negative cache for [NCE/USER/imap/<username>@imap]
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #1: [<username>@imap] is not present in negative cache
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_dp] (0x0400): [CID#1] CR #1: Looking up [<username>@imap] in data provider
   *  (2024-11-22 15:25:08): [pam] [sss_domain_get_state] (0x1000): [CID#1] Domain imap is Active
   *  (2024-11-22 15:25:08): [pam] [sss_dp_account_files_params] (0x2000): [CID#1] The entries in the files domain are up-to-date
   *  (2024-11-22 15:25:08): [pam] [sss_domain_get_state] (0x1000): [CID#1] Domain imap is Active
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_cache] (0x0400): [CID#1] CR #1: Looking up [<username>@imap] in cache
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_ncache_filter] (0x0400): [CID#1] CR #1: This request type does not support filtering result by negative cache
   *  (2024-11-22 15:25:08): [pam] [cache_req_search_done] (0x0400): [CID#1] CR #1: Returning updated object [<username>@imap]
   *  (2024-11-22 15:25:08): [pam] [cache_req_create_and_add_result] (0x0400): [CID#1] CR #1: Found 2 entries in domain imap
   *  (2024-11-22 15:25:08): [pam] [cache_req_done] (0x0400): [CID#1] CR #1: Finished: Success
   *  (2024-11-22 15:25:08): [pam] [pd_set_primary_name] (0x0400): [CID#1] User's primary name is <username>@imap
   *  (2024-11-22 15:25:08): [pam] [pam_initgr_check_timeout] (0x4000): [CID#1] User [<username>] not found in PAM cache.
   *  (2024-11-22 15:25:08): [pam] [pam_initgr_cache_set] (0x2000): [CID#1] [<username>] added to PAM initgroup cache
   *  (2024-11-22 15:25:08): [pam] [pam_dom_forwarder] (0x0100): [CID#1] pam_dp_send_req returned 0
   *  (2024-11-22 15:25:08): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-22 15:25:08): [pam] [pam_dp_send_req_done] (0x0200): [CID#1] received: [9 (Authentication service cannot retrieve authentication info)][imap]
   *  (2024-11-22 15:25:08): [pam] [pam_reply] (0x4000): [CID#1] pam_reply initially called with result [9]: Authentication service cannot retrieve authentication info. this result might be changed during processing
   *  (2024-11-22 15:25:08): [pam] [pam_reply] (0x0400): [CID#1] Local auth policy allowed: smartcard [True], passkey [False]
   *  (2024-11-22 15:25:08): [pam] [pam_reply] (0x0040): [CID#1] Assuming offline authentication setting status for pam call 249 to PAM_SUCCESS.

This seems very successful, unfortunately this still delivers an error:

imapd[31562]: Connection, ip=[<ip>], port=[<port>]
authdaemond[24536]: pam_sss(imap:auth): authentication failure; logname= uid=<uid> euid=<euid> tty= ruser= rhost=<ip> user=<username>
authdaemond[24536]: pam_sss(imap:auth): received for user <username>: 9 (Authentication service cannot retrieve authentication info)

sooow: what is going on here?

Strike0 · 2024-11-22 23:07:27

In the doc you linked, I see https://www.courier-mta.org/authlib/REA … l#authtest
Did you try that, or is it obsolete with your changed method? It also leads to debug instructions.

hjheins · 2024-11-22 23:35:21

Hi @strike0,

thanks a lot for your suggestion; I actually did not do that yet.
I did now, but the response seems similar (if not the same):

$ authtest <username> <password>

authdaemond[18933]: pam_systemd_home(login:auth): New sd-bus connection (system-bus-pam-systemd-home-18933) opened.
unix_chkpwd[18934]: check pass; user unknown
unix_chkpwd[18935]: check pass; user unknown
unix_chkpwd[18935]: password check failed for user (<username>)
authdaemond[18933]: pam_unix(login:auth): authentication failure; logname= uid=<uid> euid=<euid> tty= ruser= rhost=::1  user=<username>

this is however not the same output as I get from an imap login?
For the imap login, I also have a sssd log. This is more detailed, but also actually without error?
Can that be? looks like this actually authorises, but authdaemon doesn't "accept" it as correct?

   *  (2024-11-22 23:22:55): [pam] [cache_req_set_domain] (0x0400): [CID#1] CR #1: Using domain [files]
   *  (2024-11-22 23:22:55): [pam] [cache_req_prepare_domain_data] (0x0400): [CID#1] CR #1: Preparing input data for domain [files] rules
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_send] (0x0400): [CID#1] CR #1: Looking up <username>@files
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #1: Checking negative cache for [<username>@files]
   *  (2024-11-22 23:22:55): [pam] [sss_ncache_check_str] (0x2000): [CID#1] Checking negative cache for [NCE/USER/files/<username>@files]
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #1: [<username>@files] is not present in negative cache
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_dp] (0x0400): [CID#1] CR #1: Looking up [<username>@files] in data provider
   *  (2024-11-22 23:22:55): [pam] [sss_domain_get_state] (0x1000): [CID#1] Domain files is Active
   *  (2024-11-22 23:22:55): [pam] [sss_dp_account_files_params] (0x2000): [CID#1] The entries in the files domain are up-to-date
   *  (2024-11-22 23:22:55): [pam] [sss_domain_get_state] (0x1000): [CID#1] Domain files is Active
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_cache] (0x0400): [CID#1] CR #1: Looking up [<username>@files] in cache
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_ncache_filter] (0x0400): [CID#1] CR #1: This request type does not support filtering result by negative cache
   *  (2024-11-22 23:22:55): [pam] [cache_req_search_done] (0x0400): [CID#1] CR #1: Returning updated object [<username>@files]
   *  (2024-11-22 23:22:55): [pam] [cache_req_create_and_add_result] (0x0400): [CID#1] CR #1: Found 1 entries in domain files
   *  (2024-11-22 23:22:55): [pam] [cache_req_done] (0x0400): [CID#1] CR #1: Finished: Success
   *  (2024-11-22 23:22:55): [pam] [pd_set_primary_name] (0x0400): [CID#1] User's primary name is <username>@files
   *  (2024-11-22 23:22:55): [pam] [pam_initgr_check_timeout] (0x4000): [CID#1] User [<username>] not found in PAM cache.
   *  (2024-11-22 23:22:55): [pam] [pam_initgr_cache_set] (0x2000): [CID#1] [<username>] added to PAM initgroup cache
   *  (2024-11-22 23:22:55): [pam] [pam_dom_forwarder] (0x0100): [CID#1] pam_dp_send_req returned 0
   *  (2024-11-22 23:22:55): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-22 23:22:55): [pam] [pam_dp_send_req_done] (0x0200): [CID#1] received: [9 (Authentication service cannot retrieve authentication info)][files]
   *  (2024-11-22 23:22:55): [pam] [pam_reply] (0x4000): [CID#1] pam_reply initially called with result [9]: Authentication service cannot retrieve authentication info. this result might be changed during processing
   *  (2024-11-22 23:22:55): [pam] [pam_reply] (0x0400): [CID#1] Local auth policy allowed: smartcard [True], passkey [False]
   *  (2024-11-22 23:22:55): [pam] [pam_reply] (0x0040): [CID#1] Assuming offline authentication setting status for pam call 249 to PAM_SUCCESS.

Strike0 · 2024-11-23 23:03:26

Yes, all output points to /etc/pam.d/imap failing it. I've neither used sssd nor courier with any of the authlibs, but what I'd do is
1. rollback to the working authshadow module to check that still works,
2. decide on either authpam or sssd to set it up again. For authpam: The pam_stack.so you reference your post #1 in courier's doc is 15+ years deprecated, so if you used that it is bound to fail. Have a look at /etc/pam.d/sshd, copy that as /etc/pam.d/imap and
3. create a fresh testuser and run the authtest and your regular test again. If it fails, both with debug log.

hjheins · 2024-11-24 11:45:12

Right, I have made some progress:

To your questions.
1) yes, authshadow does still work
2) no, I never used that; I went for the "modern" version of that
here's /etc/pam.d/imap for courier-authdaemon as I "updated" what was available on the courier-authd website:

auth       required    pam_nologin.so
auth       include     system-auth
account    include     system-auth
session    include     system-auth

I actually also was in contact with the developer of courier-authd and he told me to compile according to standard whereby courier-authd is ran as root.
I did, used the above config, and that actually worked see conversation

3) as for the test: I set up with sssd. see pam imap setup below.
here' s my /etc/pam.d/imap for sssd:

auth      required  pam_sss.so
account   required  pam_sss.so
password  required  pam_sss.so
session   required  pam_sss.so

this still fails. The error logs:
journal:

imapd[28757]: Connection, ip=[<ip>], port=[<port>]
authdaemond[28769]: pam_sss(imap:auth): authentication failure; logname= uid=<uid> euid=<euid> tty= ruser= rhost=<host> user>
authdaemond[28769]: pam_sss(imap:auth): received for user <testuser>: 9 (Authentication service cannot retrieve authentication info)
imapd[28757]: LOGIN FAILED, method=PLAIN, ip=[<ip>], port=[<port>]

sssd_files.log

(): [be[files]] [server_setup] (0x3f7c0): Starting with debug level = 0x0070
(): [be[files]] [server_loop] (0x3f7c0): Entering main loop under uid=964 (euid=964) : gid=964 (egid=964) with SECBIT_KEEP_CAPS = 0 and following capabilities:
   (nothing)

sssd_pam.log:

(2024-11-24 11:32:11): [pam] [server_setup] (0x3f7c0): Starting with debug level = 0x0070
(2024-11-24 11:32:11): [pam] [server_loop] (0x3f7c0): Entering main loop under uid=964 (euid=964) : gid=964 (egid=964) with SECBIT_KEEP_CAPS = 0 and following capabilities:
         CAP_DAC_READ_SEARCH: effective =  0 , permitted = *1*, inheritable =  0 , bounding = *1*
(2024-11-24 11:35:53): [pam] [pam_reply] (0x0040): [CID#1] Assuming offline authentication setting status for pam call 249 to PAM_SUCCESS.
********************** PREVIOUS MESSAGE WAS TRIGGERED BY THE FOLLOWING BACKTRACE:
   *  [pam] [ldb] (0x0400): server_sort:Unable to register control with rootdse!
   *  (2024-11-24 11:32:11): [pam] [server_setup] (0x0400): CONFDB: /var/lib/sss/db/config.ldb
   *  (2024-11-24 11:32:11): [pam] [confdb_init_domain_provider_and_enum] (0x0400): No enumeration for [files]
   *  (2024-11-24 11:32:11): [pam] [confdb_init_domain_pwd_expire] (0x1000): pwd_expiration_warning is -1
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /bin/sh in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /bin/bash in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /usr/bin/git-shell in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /usr/bin/bash in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /bin/rbash in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /usr/bin/rbash in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /usr/bin/sh in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_get_etc_shells] (0x0400): Found shell /usr/bin/systemd-home-fallback-shell in /etc/shells
   *  (2024-11-24 11:32:11): [pam] [sss_names_init_from_args] (0x0100): Using re [^((?P<name>.+)@(?P<domain>[^@]+)|(?P<name>[^@]+))$].
   *  (2024-11-24 11:32:11): [pam] [sss_fqnames_init] (0x0100): Using fq format [%1$s@%2$s].
   *  (2024-11-24 11:32:11): [pam] [sysdb_domain_init_internal] (0x0200): DB File for files: /var/lib/sss/db/cache_files.ldb
   *  (2024-11-24 11:32:11): [pam] [sysdb_domain_init_internal] (0x0200): Timestamp file for files: /var/lib/sss/db/timestamps_files.ldb
   *  (2024-11-24 11:32:11): [pam] [sysdb_ldb_connect] (0x4000): No ldb module path set in env
   *  (2024-11-24 11:32:11): [pam] [ldb] (0x0400): asq: Unable to register control with rootdse!
   *  (2024-11-24 11:32:11): [pam] [sysdb_ldb_connect] (0x4000): No ldb module path set in env
   *  (2024-11-24 11:32:11): [pam] [sss_names_init_from_args] (0x0100): Using re [^(((?P<domain>[^\\]+)\\(?P<name>.+))|((?P<name>.+)@(?P<domain>[^@]+))|((?P<name>[^@\\]+)))$].
   *  (2024-11-24 11:32:11): [pam] [sss_fqnames_init] (0x0100): Using fq format [%1$s@%2$s].
   *  (2024-11-24 11:32:11): [pam] [sbus_dbus_connect_address] (0x0400): Connected to unix:path=/var/lib/sss/pipes/private/sbus-master bus as sssd.pam
   *  (2024-11-24 11:32:11): [pam] [sbus_router_add_path] (0x0400): Registering interface org.freedesktop.DBus.Introspectable on path /
   *  (2024-11-24 11:32:11): [pam] [sbus_router_add_path] (0x0400): Registering interface org.freedesktop.DBus.Introspectable on path /*
   *  (2024-11-24 11:32:11): [pam] [sbus_router_add_path] (0x0400): Registering interface org.freedesktop.DBus.Properties on path /
   *  (2024-11-24 11:32:11): [pam] [sbus_router_add_path] (0x0400): Registering interface org.freedesktop.DBus.Properties on path /*
   *  (2024-11-24 11:32:11): [pam] [sbus_watch_add] (0x2000): Created a disabled -/W watch on 17
   *  (2024-11-24 11:32:11): [pam] [sbus_watch_toggle] (0x4000): Toggle to enabled R/- watch on 17
   *  (2024-11-24 11:32:11): [pam] [sbus_router_listen] (0x0400): Registering signal listener org.freedesktop.DBus.NameOwnerChanged on path /org/freedesktop/DBus
   *  (2024-11-24 11:32:11): [pam] [sbus_router_listen] (0x0400): Registering signal listener org.freedesktop.DBus.NameAcquired on path /org/freedesktop/DBus
   *  (2024-11-24 11:32:11): [pam] [sbus_router_listen] (0x0400): Registering signal listener sssd.Responder.Domain.SetActive on path /sssd
   *  (2024-11-24 11:32:11): [pam] [sbus_router_listen] (0x0400): Registering signal listener sssd.Responder.Domain.SetInconsistent on path /sssd
   *  (2024-11-24 11:32:11): [pam] [sbus_router_listen] (0x0400): Registering signal listener sssd.Responder.NegativeCache.ResetUsers on path /sssd
   *  (2024-11-24 11:32:11): [pam] [sbus_router_listen] (0x0400): Registering signal listener sssd.Responder.NegativeCache.ResetGroups on path /sssd
   *  (2024-11-24 11:32:11): [pam] [sss_process_init] (0x0400): Responder initialization complete (explicitly configured)
   *  (2024-11-24 11:32:11): [pam] [get_trusted_uids] (0x0400): All UIDs are allowed.
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/files/root@files] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/GROUP/files/root@files] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/UID/0] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/GID/0] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [responder_set_fd_limit] (0x0100): Maximum file descriptors set to [8192]
   *  (2024-11-24 11:32:11): [pam] [pam_process_init] (0x2000): Found value [no_session] for option [pam_initgroups_scheme].
   *  (2024-11-24 11:32:11): [pam] [pam_process_init] (0x2000): Found value [-] for option [pam_gssapi_services].
   *  (2024-11-24 11:32:11): [pam] [pam_process_init] (0x2000): Found value [-] for option [pam_gssapi_indicators_map].
   *  (2024-11-24 11:32:11): [pam] [sbus_router_add_path] (0x0400): Registering interface sssd.service on path /sssd
   *  (2024-11-24 11:32:11): [pam] [cache_req_domain_new_list_from_domain_resolution_order] (0x0400): Domain resolution order list: not set
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/USER/files/root@files] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/GROUP/files/root@files] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/UID/0] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_ncache_set_str] (0x0400): Adding [NCE/GID/0] to negative cache permanently
   *  (2024-11-24 11:32:11): [pam] [sss_domain_get_state] (0x1000): Domain files is Active
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_signal_handler] (0x2000): Received D-Bus signal org.freedesktop.DBus.NameAcquired on /org/freedesktop/DBus from org.freedesktop.DBus
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_signal_handler] (0x2000): Received D-Bus signal org.freedesktop.DBus.NameAcquired on /org/freedesktop/DBus from org.freedesktop.DBus
   *  (2024-11-24 11:32:11): [pam] [sbus_name_acquired] (0x0400): D-Bus name acquired: :1.3
   *  (2024-11-24 11:32:11): [pam] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.NameAcquired on /org/freedesktop/DBus from org.freedesktop.DBus: Success
   *  (2024-11-24 11:32:11): [pam] [sbus_name_acquired] (0x0400): D-Bus name acquired: sssd.pam
   *  (2024-11-24 11:32:11): [pam] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.NameAcquired on /org/freedesktop/DBus from org.freedesktop.DBus: Success
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:32:11): [pam] [sss_monitor_register_service_done] (0x0100): Got id ack and version (1) from Monitor
   *  (2024-11-24 11:35:53): [pam] [get_client_cred] (0x4000): Client [0x133ab98][18] creds: euid[72] egid[72] pid[28769] cmd_line['/usr/lib/courier-authlib/authdaemond'].
   *  (2024-11-24 11:35:53): [pam] [get_client_cred] (0x0080): The following failure is expected to happen in case SELinux is disabled:
SELINUX_getpeercon failed [95][Operation not supported].
Please, consider enabling SELinux in your system.
   *  (2024-11-24 11:35:53): [pam] [setup_client_idle_timer] (0x4000): Idle timer re-set for client [0x133ab98][18]
   *  (2024-11-24 11:35:53): [pam] [accept_fd_handler] (0x0400): [CID#1] Client [cmd /usr/lib/courier-authlib/authdaemond][uid 72][0x133ab98][18] connected!
   *  (2024-11-24 11:35:53): [pam] [sss_cmd_get_version] (0x0200): [CID#1] Received client version [3].
   *  (2024-11-24 11:35:53): [pam] [sss_cmd_get_version] (0x0200): [CID#1] Offered version [3].
   *  (2024-11-24 11:35:53): [pam] [pam_cmd_preauth] (0x0100): [CID#1] entering pam_cmd_preauth
   *  (2024-11-24 11:35:53): [pam] [sss_parse_name] (0x0200): [CID#1] Domain not provided!
   *  (2024-11-24 11:35:53): [pam] [sss_parse_name_for_domains] (0x0200): [CID#1] name '<username>' matched without domain, user is <username>
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] command: SSS_PAM_PREAUTH
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] domain: not set
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] user: <username>
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] service: imap
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] tty: not set
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] ruser: not set
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] rhost: 2a02:8071:6141:e2e0::6fe
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] authtok type: 0 (No authentication token available)
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] newauthtok type: 0 (No authentication token available)
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] priv: 0
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] cli_pid: 28769
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] child_pid: 0
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] logon name: <username>
   *  (2024-11-24 11:35:53): [pam] [pam_print_data] (0x0100): [CID#1] flags: 0
   *  (2024-11-24 11:35:53): [pam] [cache_req_set_plugin] (0x2000): [CID#1] CR #0: Setting "Initgroups by name" plugin
   *  (2024-11-24 11:35:53): [pam] [cache_req_send] (0x0400): [CID#1] CR #0: REQ_TRACE: New request [CID #1] '(null)'
   *  (2024-11-24 11:35:53): [pam] [cache_req_process_input] (0x0400): [CID#1] CR #0: Parsing input name [<username>]
   *  (2024-11-24 11:35:53): [pam] [sss_parse_name] (0x0200): [CID#1] Domain not provided!
   *  (2024-11-24 11:35:53): [pam] [sss_parse_name_for_domains] (0x0200): [CID#1] name '<username>' matched without domain, user is <username>
   *  (2024-11-24 11:35:53): [pam] [cache_req_set_name] (0x0400): [CID#1] CR #0: Setting name [<username>]
   *  (2024-11-24 11:35:53): [pam] [cache_req_select_domains] (0x0400): [CID#1] CR #0: Performing a multi-domain search
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_domains] (0x0400): [CID#1] CR #0: Search will check the cache and bypass the data provider
   *  (2024-11-24 11:35:53): [pam] [cache_req_validate_domain_type] (0x2000): [CID#1] Request type POSIX-only for domain files type POSIX is valid
   *  (2024-11-24 11:35:53): [pam] [cache_req_set_domain] (0x0400): [CID#1] CR #0: Using domain [files]
   *  (2024-11-24 11:35:53): [pam] [cache_req_prepare_domain_data] (0x0400): [CID#1] CR #0: Preparing input data for domain [files] rules
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_send] (0x0400): [CID#1] CR #0: Looking up <username>@files
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #0: Checking negative cache for [<username>@files]
   *  (2024-11-24 11:35:53): [pam] [sss_ncache_check_str] (0x2000): [CID#1] Checking negative cache for [NCE/USER/files/<username>@files]
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #0: [<username>@files] is not present in negative cache
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_cache] (0x0400): [CID#1] CR #0: Looking up [<username>@files] in cache
   *  (2024-11-24 11:35:53): [pam] [cache_req_process_result] (0x0400): [CID#1] CR #0: Finished: Not found
   *  (2024-11-24 11:35:53): [pam] [pam_check_user_search_next] (0x4000): [CID#1] PAM initgroups scheme [no_session].
   *  (2024-11-24 11:35:53): [pam] [cache_req_set_plugin] (0x2000): [CID#1] CR #1: Setting "Initgroups by name" plugin
   *  (2024-11-24 11:35:53): [pam] [cache_req_send] (0x0400): [CID#1] CR #1: REQ_TRACE: New request [CID #1] '(null)'
   *  (2024-11-24 11:35:53): [pam] [cache_req_process_input] (0x0400): [CID#1] CR #1: Parsing input name [<username>]
   *  (2024-11-24 11:35:53): [pam] [sss_parse_name] (0x0200): [CID#1] Domain not provided!
   *  (2024-11-24 11:35:53): [pam] [sss_parse_name_for_domains] (0x0200): [CID#1] name '<username>' matched without domain, user is <username>
   *  (2024-11-24 11:35:53): [pam] [cache_req_set_name] (0x0400): [CID#1] CR #1: Setting name [<username>]
   *  (2024-11-24 11:35:53): [pam] [cache_req_select_domains] (0x0400): [CID#1] CR #1: Performing a multi-domain search
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_domains] (0x0400): [CID#1] CR #1: Search will bypass the cache and check the data provider
   *  (2024-11-24 11:35:53): [pam] [cache_req_validate_domain_type] (0x2000): [CID#1] Request type POSIX-only for domain files type POSIX is valid
   *  (2024-11-24 11:35:53): [pam] [cache_req_set_domain] (0x0400): [CID#1] CR #1: Using domain [files]
   *  (2024-11-24 11:35:53): [pam] [cache_req_prepare_domain_data] (0x0400): [CID#1] CR #1: Preparing input data for domain [files] rules
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_send] (0x0400): [CID#1] CR #1: Looking up <username>@files
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #1: Checking negative cache for [<username>@files]
   *  (2024-11-24 11:35:53): [pam] [sss_ncache_check_str] (0x2000): [CID#1] Checking negative cache for [NCE/USER/files/<username>@files]
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_ncache] (0x0400): [CID#1] CR #1: [<username>@files] is not present in negative cache
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_dp] (0x0400): [CID#1] CR #1: Looking up [<username>@files] in data provider
   *  (2024-11-24 11:35:53): [pam] [sss_domain_get_state] (0x1000): [CID#1] Domain files is Active
   *  (2024-11-24 11:35:53): [pam] [sss_dp_account_files_params] (0x2000): [CID#1] The entries in the files domain are up-to-date
   *  (2024-11-24 11:35:53): [pam] [sss_domain_get_state] (0x1000): [CID#1] Domain files is Active
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_cache] (0x0400): [CID#1] CR #1: Looking up [<username>@files] in cache
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_ncache_filter] (0x0400): [CID#1] CR #1: This request type does not support filtering result by negative cache
   *  (2024-11-24 11:35:53): [pam] [cache_req_search_done] (0x0400): [CID#1] CR #1: Returning updated object [<username>@files]
   *  (2024-11-24 11:35:53): [pam] [cache_req_create_and_add_result] (0x0400): [CID#1] CR #1: Found 1 entries in domain files
   *  (2024-11-24 11:35:53): [pam] [cache_req_done] (0x0400): [CID#1] CR #1: Finished: Success
   *  (2024-11-24 11:35:53): [pam] [pd_set_primary_name] (0x0400): [CID#1] User's primary name is <username>@files
   *  (2024-11-24 11:35:53): [pam] [pam_initgr_check_timeout] (0x4000): [CID#1] User [<username>] not found in PAM cache.
   *  (2024-11-24 11:35:53): [pam] [pam_initgr_cache_set] (0x2000): [CID#1] [<username>] added to PAM initgroup cache
   *  (2024-11-24 11:35:53): [pam] [pam_dom_forwarder] (0x0100): [CID#1] pam_dp_send_req returned 0
   *  (2024-11-24 11:35:53): [pam] [sbus_dispatch] (0x4000): Dispatching.
   *  (2024-11-24 11:35:53): [pam] [pam_dp_send_req_done] (0x0200): [CID#1] received: [9 (Authentication service cannot retrieve authentication info)][files]
   *  (2024-11-24 11:35:53): [pam] [pam_reply] (0x4000): [CID#1] pam_reply initially called with result [9]: Authentication service cannot retrieve authentication info. this result might be changed during processing
   *  (2024-11-24 11:35:53): [pam] [pam_reply] (0x0400): [CID#1] Local auth policy allowed: smartcard [True], passkey [False]
   *  (2024-11-24 11:35:53): [pam] [pam_reply] (0x0040): [CID#1] Assuming offline authentication setting status for pam call 249 to PAM_SUCCESS.
********************** BACKTRACE DUMP ENDS HERE *********************************

sssd.conf:

[sssd]
services = pam
domains = files
debug_level=9


[domain/files]
id_provider = files
proxy_lib_name = files
proxy_pam_target = sssd-shadowutils

Strike0 · 2024-11-24 18:56:51

Ok, great, so you got 2) done.
For your 3) test with sssd, I see you changed its sssd.conf settings. I would start with "domains = all" and see if that changes the "[9 (Authentication service cannot retrieve authentication info)" error.see here
I'm unsure what services sssd actually proxies, because it's main application is ldap/ad/freeipa - I'd assume you need any of them running for it to proxy against. Do you have ldap setup for it?

hjheins · 2024-11-25 10:20:20

As far as I understand sssd, it seems to act as sort of a proxy:
According to the PAM documentation the user or service that contacts PAM, should always be root. Requests from any other entity are now acknowledged.

The link you refer to, is documentation from 2022. Apparently currently it is not allowed to run sssd without specifying a domain.
I have however tried with setting a trust on the requesting user. unfortunatly I still get the same error message as before.

the modified sssd.conf:

[sssd]
services = pam
domains = files
debug_level=9

[pam]
pam_trusted_users = courier

[domain/files]
id_provider = files
proxy_lib_name = files
proxy_pam_target = sssd-shadowutils

Strike0 · 2024-11-26 22:41:55

Ok, yes, my bad with the "all" reference.
Yet, arch SSSD setup instructions start with LDAP, that's why I asked if you have done that.

hjheins · 2024-11-27 06:13:59

hmm, i see what you mean. apparently you can "daisy chain" authorization services/modules by comma separating them. I also tried pam,nss for services, which seems to be related to your remark, however also that made no difference

-thc · 2024-11-27 06:31:20

Did you ever consider switching to dovecot? It uses PAM, most of the daemons (including dovecot-auth) run as non-root users, the authentication just works and dovecot even provides it's authentication as a mechanism for postfix.

hjheins · 2024-11-27 07:27:30

hi @-thc,

Actually I have a working solution already: the problem is that the aur package for courier-authlib for some reason runs as user courier.
As soon as I change this to the default (=root) everything works.

However: I went down this sssd rabit hole, and from what I understand, sssd should provide some type of proxy service to enable services that are running as non-root to still use the pam authentication mechanisms. That should apply to the courier-athlib package as in aur. And I would like to get this working even if that means it is just an example solution of how to make sssd work, as I guess that would benefit a lot of other uses as well.

hjheins · 2024-11-28 20:52:20

Right, I ended up scratching my own itch:

This will work, but you need to get the settings right.
See the arch wiki on sssd

or if you need the long and arduous version, check out the ticket at the sssd git hub

I'll mark this one as solved

Arch Linux

#1 2024-11-21 14:56:04

[SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#2 2024-11-22 13:48:36

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#3 2024-11-22 15:36:43

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#4 2024-11-22 23:07:27

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#5 2024-11-22 23:35:21

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#6 2024-11-23 23:03:26

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#7 2024-11-24 11:45:12

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#8 2024-11-24 18:56:51

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#9 2024-11-25 10:20:20

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#10 2024-11-26 22:41:55

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#11 2024-11-27 06:13:59

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#12 2024-11-27 06:31:20

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#13 2024-11-27 07:27:30

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

#14 2024-11-28 20:52:20

Re: [SOLVED] SSSD User Authentication with PAM on Courier-Authlib Fails

Board footer