> 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 [[email protected],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: 
[email protected]
(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 [[email protected]]
(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 [[email protected]]
(2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_rhds] (0x4000): 
[RID#5] Account for user [[email protected]] 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 [[email protected]]
(2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_ad] (0x4000): 
[RID#5] User account control for user [[email protected]] is [0].
(2023-10-25 15:18:10): [be[example.com]] [sdap_account_expired_ad] (0x4000): 
[RID#5] Expiration time for user [[email protected]] 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?
_______________________________________________
FreeIPA-users mailing list -- [email protected]
To unsubscribe send an email to [email protected]
Fedora Code of Conduct: 
https://docs.fedoraproject.org/en-US/project/code-of-conduct/
List Guidelines: https://fedoraproject.org/wiki/Mailing_list_guidelines
List Archives: 
https://lists.fedorahosted.org/archives/list/[email protected]
Do not reply to spam, report it: 
https://pagure.io/fedora-infrastructure/new_issue

Reply via email to