Finn Fysj via FreeIPA-users wrote:
If SSSD doesn't have the rules it can't grant access.
You might try enabling replication debugging on your misbehaving server. It could tell you what is wrong.
rob
I tried to setup a another test IPA server just to verify. Here I created a dummy user "test_alice" I added a public key to this user, added a hbac rule: Rule name: allow_alice Host category: all Service category: all Enabled: True Users: test_alice accessruletype: allow
systemctl status sssd Oct 25 15:18:10 ipa-test.example.com sssd_be[34484]: dereference processing failed : Invalid argument
systemctl status sshd Oct 25 15:18:10 ipa-test.example.com sshd[34496]: pam_sss(sshd:account): Access denied for user test_alice: 4 (System error) Oct 25 15:18:10 ipa-test.example.com sshd[34496]: fatal: Access denied for user test_alice by PAM account configuration [preauth]
/var/log/sssd/sssd_example.com.log (2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#4] commit ldb transaction (nesting: 0) (2023-10-25 15:18:10): [be[example.com]] [sysdb_set_entry_attr] (0x0200): [RID#4] Entry [name=test_alice@example.com,cn=users,cn=example.com,cn=sysdb] has set [ts_cache] attrs. (2023-10-25 15:18:10): [be[example.com]] [dp_get_account_info_initgroups_resolv_done] (0x0400): [RID#4] Ordering NSS responder to update memory cache (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: sh[0x5632f31d8560], connected[1], ops[(nil)], ldap[0x5632f31da1c0] (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [sbus_method_handler] (0x2000): Received D-Bus method org.freedesktop.DBus.GetConnectionUnixUser on /org/freedesktop/DBus (2023-10-25 15:18:10): [be[example.com]] [sbus_issue_request_done] (0x0400): org.freedesktop.DBus.GetConnectionUnixUser: Success (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [dp_req_reply_std] (0x1000): [RID#4] DP Request [Initgroups #4]: Returning [Success]: 0,0,Success (2023-10-25 15:18:10): [be[example.com]] [sbus_issue_request_done] (0x0400): sssd.dataprovider.getAccountInfo: Success (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [sbus_dispatch] (0x4000): Dispatching. (2023-10-25 15:18:10): [be[example.com]] [sbus_method_handler] (0x2000): Received D-Bus method sssd.dataprovider.pamHandler on /sssd (2023-10-25 15:18:10): [be[example.com]] [sbus_senders_lookup] (0x2000): Looking for identity of sender [sssd.pam] (2023-10-25 15:18:10): [be[example.com]] [dp_pam_handler_send] (0x0100): Got request with the following data (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): command: SSS_PAM_ACCT_MGMT (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): domain: example.com (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): user: test_alice@example.com (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): service: sshd (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): tty: ssh (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): ruser: (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): rhost: 192.168.10.66 (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): authtok type: 0 (No authentication token available) (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): newauthtok type: 0 (No authentication token available) (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): priv: 1 (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): cli_pid: 34496 (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): child_pid: 0 (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): logon name: not set (2023-10-25 15:18:10): [be[example.com]] [pam_print_data] (0x0100): flags: 0 (2023-10-25 15:18:10): [be[example.com]] [dp_attach_req] (0x0400): [RID#5] DP Request [PAM Account #5]: REQ_TRACE: New request. [sssd.pam CID #1] Flags [0000]. (2023-10-25 15:18:10): [be[example.com]] [dp_attach_req] (0x0400): [RID#5] Number of active DP request: 1 (2023-10-25 15:18:10): [be[example.com]] [sss_domain_get_state] (0x1000): [RID#5] Domain example.com is Active (2023-10-25 15:18:10): [be[example.com]] [sdap_access_send] (0x0400): [RID#5] Performing access check for user [test_alice@example.com] (2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Added timed event "ldb_kv_callback": 0x5632f31b7100
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Added timed event "ldb_kv_timeout": 0x5632f3202bf0
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Running timer event 0x5632f31b7100 "ldb_kv_callback"
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Destroying timer event 0x5632f3202bf0 "ldb_kv_timeout"
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Destroying timer event 0x5632f31b7100 "ldb_kv_callback"
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Added timed event "ldb_kv_callback": 0x5632f32579f0
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Added timed event "ldb_kv_timeout": 0x5632f3202bf0
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Running timer event 0x5632f32579f0 "ldb_kv_callback"
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Destroying timer event 0x5632f3202bf0 "ldb_kv_timeout"
(2023-10-25 15:18:10): [be[example.com]] [ldb] (0x10000): [RID#5] Destroying timer event 0x5632f32579f0 "ldb_kv_callback"
(2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_rhds] (0x0400): [RID#5] Performing RHDS access check for user [test_alice@example.com] (2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_rhds] (0x4000): [RID#5] Account for user [test_alice@example.com] is not locked. (2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired] (0x0400): [RID#5] IPA access control succeeded, checking AD access control (2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_ad] (0x0400): [RID#5] Performing AD access check for user [test_alice@example.com] (2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_ad] (0x4000): [RID#5] User account control for user [test_alice@example.com] is [0]. (2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_ad] (0x4000): [RID#5] Expiration time for user [test_alice@example.com] is [0]. (2023-10-25 15:18:10): [be[example.com]] [ipa_fetch_hbac_send] (0x4000): [RID#5] Connection status is [online]. (2023-10-25 15:18:10): [be[example.com]] [sdap_id_op_connect_step] (0x4000): [RID#5] reusing cached connection (2023-10-25 15:18:10): [be[example.com]] [sdap_id_conn_data_not_idle] (0x4000): [RID#5] Marking connection as not idle (2023-10-25 15:18:10): [be[example.com]] [sdap_print_server] (0x2000): [RID#5] Searching 10.141.4.21:389 (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x0400): [RID#5] calling ldap_search_ext with [(&(objectClass=ipaHost)(fqdn=ipa-test.example.com))][cn=accounts,dc=example,dc=com]. (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [objectClass] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [cn] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [fqdn] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [serverHostname] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [memberOf] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [ipaSshPubKey] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [ipaUniqueID] (2023-10-25 15:18:10): [be[example.com]] [sdap_op_add] (0x2000): [RID#5] New operation 18 timeout 60 (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: sh[0x5632f31d8560], connected[1], ops[0x5632f312ec50], ldap[0x5632f31da1c0] (2023-10-25 15:18:10): [be[example.com]] [sdap_process_message] (0x4000): [RID#5] Message type: [LDAP_RES_SEARCH_ENTRY] (2023-10-25 15:18:10): [be[example.com]] [sdap_call_op_callback] (0x20000): [RID#5] Handling LDAP operation [18][server: [10.141.4.21:389] filter: [(&(objectClass=ipaHost)(fqdn=ipa-test.example.com))] base: [cn=accounts,dc=example,dc=com]] took [0.412] milliseconds. (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_entry] (0x1000): [RID#5] OriginalDN: [fqdn=ipa-test.example.com,cn=computers,cn=accounts,dc=example,dc=com]. (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [objectClass] (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [cn] (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [fqdn] (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [serverHostname] (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [memberOf] (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [ipaSshPubKey] (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_range] (0x2000): [RID#5] No sub-attributes for [ipaUniqueID] (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: sh[0x5632f31d8560], connected[1], ops[0x5632f312ec50], ldap[0x5632f31da1c0] (2023-10-25 15:18:10): [be[example.com]] [sdap_process_message] (0x4000): [RID#5] Message type: [LDAP_RES_SEARCH_RESULT] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_op_finished] (0x0400): [RID#5] Search result: Success(0), no errmsg set (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_op_finished] (0x2000): [RID#5] Total count [0] (2023-10-25 15:18:10): [be[example.com]] [sdap_op_destructor] (0x2000): [RID#5] Operation 18 finished (2023-10-25 15:18:10): [be[example.com]] [sdap_has_deref_support_ex] (0x0400): [RID#5] The server supports deref method OpenLDAP (2023-10-25 15:18:10): [be[example.com]] [sdap_deref_search_send] (0x2000): [RID#5] Server supports OpenLDAP deref (2023-10-25 15:18:10): [be[example.com]] [sdap_x_deref_search_send] (0x0400): [RID#5] Dereferencing entry [fqdn=ipa-test.example.com,cn=computers,cn=accounts,dc=example,dc=com] using OpenLDAP deref (2023-10-25 15:18:10): [be[example.com]] [sdap_print_server] (0x2000): [RID#5] Searching 10.141.4.21:389 (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_send] (0x0400): [RID#5] WARNING: Disabling paging because scope is set to base. (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x0400): [RID#5] calling ldap_search_ext with [no filter][fqdn=ipa-test.example.com,cn=computers,cn=accounts,dc=example,dc=com]. (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [objectClass] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [cn] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [memberOf] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x1000): [RID#5] Requesting attrs: [ipaUniqueID] (2023-10-25 15:18:10): [be[example.com]] [sdap_get_generic_ext_step] (0x2000): [RID#5] ldap_search_ext called, msgid = 19 (2023-10-25 15:18:10): [be[example.com]] [sdap_op_add] (0x2000): [RID#5] New operation 19 timeout 60 (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: sh[0x5632f31d8560], connected[1], ops[0x5632f312ec50], ldap[0x5632f31da1c0] (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: end of ldap_result list (2023-10-25 15:18:10): [be[example.com]] [sdap_process_result] (0x2000): Trace: sh[0x5632f31d8560], connected[1], ops[0x5632f312ec50], ldap[0x5632f31da1c0] (2023-10-25 15:18:10): [be[example.com]] [sdap_process_message] (0x4000): [RID#5] Message type: [LDAP_RES_SEARCH_ENTRY] (2023-10-25 15:18:10): [be[example.com]] [sdap_call_op_callback] (0x20000): [RID#5] Handling LDAP operation [19][server: [10.141.4.21:389] filter: [(null)] base: [fqdn=ipa-test.example.com,cn=computers,cn=accounts,dc=example,dc=com]] took [1.636] milliseconds. (2023-10-25 15:18:10): [be[example.com]] [sdap_x_deref_parse_entry] (0x0400): [RID#5] Got deref control (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x1000): [RID#5] Dereferenced DN: cn=ipaservers,cn=hostgroups,cn=accounts,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced objectClass value: top (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced objectClass value: groupOfNames (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced objectClass value: nestedGroup (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced objectClass value: ipaobject (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced objectClass value: ipahostgroup (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Found map for objectclass 'ipahostgroup' (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x2000): [RID#5] Dereferenced attribute: objectClass (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x2000): [RID#5] Dereferenced attribute: cn (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: ipaservers (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x2000): [RID#5] Dereferenced attribute: memberOf (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Replication Administrators,cn=privileges,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Add Replication Agreements,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Modify Replication Agreements,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Read Replication Agreements,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Remove Replication Agreements,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Modify DNA Range,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Read PassSync Managers Configuration,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Read Replication Changelog Configuration,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Write Replication Changelog Configuration,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Modify PassSync Managers Configuration,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Read LDBM Database Configuration,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Add Configuration Sub-Entries,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: cn=Read DNA Range,cn=permissions,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x2000): [RID#5] Dereferenced attribute: ipaUniqueID (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x4000): [RID#5] Dereferenced attribute value: d2694b3c-7347-11ee-bd25-000017024d7a (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x1000): [RID#5] Dereferenced DN: cn=Replication Administrators,cn=privileges,cn=pbac,dc=example,dc=com (2023-10-25 15:18:10): [be[example.com]] [sdap_parse_deref] (0x0020): [RID#5] Unknown entry type, no objectClasses found! (2023-10-25 15:18:10): [be[example.com]] [sdap_x_deref_parse_entry] (0x0040): [RID#5] sdap_parse_deref failed [22]: Invalid argument
Is it considered a practice to always restart sssd when a HBAC rule is added and to empty the cache?