[Freeipa-users] HBAC rules don't work with PAM - problem

Sumit Bose sbose at redhat.com
Mon May 11 15:15:31 UTC 2015 

On Mon, May 11, 2015 at 04:47:01PM +0200, Lukas Slebodnik wrote:
> On (11/05/15 14:57), Vangass wrote:
> >Hi,
> >
> >I try to access Cisco switch via ssh. Cisco has tacacs login configured.
> >
> ># tail /var/log/secure
> >May 11 14:18:46 freeipa tac_plus[29096]: pam_sss(tac_plus:auth):
> >authentication success; logname=bartosz uid=0 euid=0 tty= ruser= rhost=
> >user=bartosz
> >May 11 14:18:53 freeipa tac_plus[29096]: pam_sss(tac_plus:auth):
> >authentication success; logname=bartosz uid=0 euid=0 tty= ruser= rhost=
> >user=test
> >
> >User bartosz is added in HBAC rule as Specified Users and Groups.
> >User test exist in FreeIPA but isn't in HBAC rule and shouldn't be
> >autheniticated.
> >
> ># cat /etc/sssd/sssd.conf
> >[domain/test.example.com]
> >debug_level = 6
> >cache_credentials = True
> >krb5_store_password_if_offline = True
> >ipa_domain = test.example.com
> >id_provider = ipa
> >auth_provider = ipa
> >access_provider = ipa
> >ipa_hostname = freeipa.test.example.com
> >chpass_provider = ipa
> >ipa_server = freeipa.test.example.com
> >ipa_server_mode = True
> >ldap_tls_cacert = /etc/ipa/ca.crt
> >
> >[sssd]
> >services = nss, sudo, pam, ssh
> >config_file_version = 2
> >domains = test.example.com
> >
> >[nss]
> >homedir_substring = /home
> >
> >[pam]
> >debug_level = 6
> >domains = test.example.com
> >
> >[sudo]
> >
> >[autofs]
> >
> >[ssh]
> >
> >[pac]
> >
> >[ifp]
> >
> >
> >#cat /var/log/sssd/sssd_pam.log
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [accept_fd_handler] (0x0400): Client
> >connected to privileged pipe!
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_cmd_get_version] (0x0200):
> >Received client version [3].
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_cmd_get_version] (0x0200):
> >Offered version [3].
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_cmd_authenticate] (0x0100):
> >entering pam_cmd_authenticate
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_parse_name_for_domains]
> >(0x0200): name 'test' matched without domain, user is test
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): command:
> >PAM_AUTHENTICATE
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): domain:
> >not set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): user: test
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): service:
> >tac_plus
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: not
> >set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser:
> >not set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost:
> >not set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok
> >type: 1
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100):
> >newauthtok type: 0
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
> >29218
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): logon
> >name: test
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_dp_issue_request] (0x0400):
> >Issuing request for [0x7f4f20215ed0:3:test at test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_dp_get_account_msg] (0x0400):
> >Creating request for [test.example.com][3][1][name=test]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_dp_internal_get_send] (0x0400):
> >Entering request [0x7f4f20215ed0:3:test at test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_check_user_search] (0x0100):
> >Requesting info for [test at test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_check_user_search] (0x0400):
> >Returning info for user [test at test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_dp_send_req] (0x0100): Sending
> >request with the following data:
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): command:
> >PAM_AUTHENTICATE
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): domain:
> >test.example.com
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): user: test
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): service:
> >tac_plus
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): tty: not
> >set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): ruser:
> >not set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): rhost:
> >not set
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): authtok
> >type: 1
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100):
> >newauthtok type: 0
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): priv: 1
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): cli_pid:
> >29218
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_print_data] (0x0100): logon
> >name: test
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_dom_forwarder] (0x0100):
> >pam_dp_send_req returned 0
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [sss_dp_req_destructor] (0x0400):
> >Deleting request: [0x7f4f20215ed0:3:test at test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_dp_process_reply] (0x0100):
> >received: [0][test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply
> >called with result [0].
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_reply] (0x0200): pam_reply
> >called with result [0].
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [pam_reply] (0x0200): blen: 81
> >(Mon May 11 14:40:28 2015) [sssd[pam]] [client_recv] (0x0200): Client
> >disconnected!
> >
> ># cat /var/log/sssd/sssd_test.example.com.log
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[be_get_account_info] (0x0200): Got request for [0x3][1][name=test]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [be_req_set_domain]
> >(0x0400): Changing request domain from [test.example.com] to [
> >test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> >domain SID from [(null)]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> >domain SID from [(null)]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_initgr_next_base] (0x0400): Searching for users with base
> >[cn=accounts,dc=test,dc=example,dc=com]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
> >[(&(uid=test)(objectclass=posixAccount)(&(uidNumber=*)(!(uidNumber=0))))][cn=accounts,dc=test,dc=example,dc=com].
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
> >errmsg set
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_user]
> >(0x0400): Save user
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_primary_name] (0x0400): Processing object test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_user]
> >(0x0400): Processing user test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> >domain SID from [(null)]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_user]
> >(0x0400): Adding original memberOf attributes to [test].
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_user]
> >(0x0400): Adding user principal [test at TEST.EXAMPLE.COM] to attributes of
> >[test].
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_user]
> >(0x0400): Storing info for user test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_primary_name] (0x0400): Processing object test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
> >[(&(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*))][cn=ipausers,cn=groups,cn=accounts,dc=test,dc=example,dc=com].
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
> >errmsg set
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_primary_name] (0x0400): Processing object ipausers
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> >domain SID from [(null)]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_groups_next_base] (0x0400): Searching for groups with base
> >[cn=accounts,dc=test,dc=example,dc=com]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
> >[(&(gidNumber=732000003)(|(objectClass=ipaUserGroup)(objectClass=posixGroup))(cn=*)(&(gidNumber=*)(!(gidNumber=0))))][cn=accounts,dc=test,dc=example,dc=com].
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_op_finished] (0x0400): Search result: Success(0), no
> >errmsg set
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_groups_process] (0x0400): Search for groups, returned 1 results.
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_has_deref_support] (0x0400): The server supports deref method OpenLDAP
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> >domain SID from [(null)]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_nested_group_recv] (0x0400): 0 users found in the hash table
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_nested_group_recv] (0x0400): 1 groups found in the hash table
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_primary_name] (0x0400): Processing object test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_group]
> >(0x0400): Processing group test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_idmap_domain_has_algorithmic_mapping] (0x0080): Could not parse
> >domain SID from [(null)]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_process_ghost_members] (0x0400): The group has 0 members
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_process_ghost_members] (0x0400): Group has 0 members
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_group]
> >(0x0400): Storing info for group test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_primary_name] (0x0400): Processing object test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_grpmem]
> >(0x0400): Processing group test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_grpmem]
> >(0x0400): Failed to get group sid
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [sdap_save_grpmem]
> >(0x0400): No members for group [test]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_ext_step] (0x0400): calling ldap_search_ext with
> >[(&(objectClass=ipaOverrideAnchor)(ipaAnchorUUID=:IPA:test.example.com:b8e22526-f4c0-11e4-8865-005056a8f368))][cn=Default
> >Trust View,cn=views,cn=accounts,dc=test,dc=example,dc=com].
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[sdap_get_generic_op_finished] (0x0400): Search result: No such object(32),
> >no errmsg set
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [acctinfo_callback]
> >(0x0100): Request processed. Returned 0,0,Success
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [be_req_set_domain]
> >(0x0400): Changing request domain from [test.example.com] to [
> >test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [be_pam_handler]
> >(0x0100): Got request with the following data
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): command: PAM_AUTHENTICATE
> Here just authentication was performed.
>    It coresponds to the line "auth required pam_sss.so" in your pam stack.
> 
> 
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): domain: test.example.com
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): user: test
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): service: tac_plus
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): tty:
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): ruser:
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): rhost:
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): authtok type: 1
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): newauthtok type: 0
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): priv: 1
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): cli_pid: 29218
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [pam_print_data]
> >(0x0100): logon name: not set
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[fo_resolve_service_send] (0x0100): Trying to resolve service 'IPA'
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[be_resolve_server_process] (0x0200): Found address for server
> >freeipa.test.example.com: [172.21.0.20] TTL 7200
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[write_pipe_handler] (0x0400): All data has been sent!
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [child_sig_handler]
> >(0x0100): child [29226] finished successfully.
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]] [read_pipe_handler]
> >(0x0400): EOF received, client finished
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[fo_set_port_status] (0x0100): Marking port 0 of server '
> >freeipa.test.example.com' as 'working'
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[set_server_common_status] (0x0100): Marking server '
> >freeipa.test.example.com' as 'working'
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[fo_set_port_status] (0x0400): Marking port 0 of duplicate server '
> >freeipa.test.example.com' as 'working'
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[be_pam_handler_callback] (0x0100): Backend returned: (0, 0, <NULL>)
> >[Success]
>  ^^^^^^^^
> Result of authentication is "Success" which means that password is correct.
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[be_pam_handler_callback] (0x0100): Sending result [0][test.example.com]
> >(Mon May 11 14:40:28 2015) [sssd[be[test.example.com]]]
> >[be_pam_handler_callback] (0x0100): Sent result [0][test.example.com]
> >
> 
> I could not see authorisation phase; neither in sssd_pam log nor in
> sssd_$domain.log.
> 
> It means that you either shared just part of log file or that
> your application did not reach/try line "account" in pam stack
>   "account required pam_sss.so"
> In this case you would able to see PAM_ACCT_MGMT in log files.
> 
> sssd seems to work as expected.

I found the following on
http://www.shrubbery.net/tac_plus/PAM_guide.txt:

"Currently, tac_plus only allows authentication using pam (since pam is
only used for authentication anyway). Authorizations are still
configured within the conf file, no ldap groups allowed :("

So it is not expected that tac_plus does only authentication and not
access control via PAM.

HTH

bye,
Sumit

> 
> LS
> 
> -- 
> Manage your subscription for the Freeipa-users mailing list:
> https://www.redhat.com/mailman/listinfo/freeipa-users
> Go to http://freeipa.org for more info on the project

More information about the Freeipa-users mailing list