Bug 1664974

Summary: ipa hbacrule-add-service --hbacsvcs=sshd is not applied successfully.
Product: Red Hat Enterprise Linux 8 Reporter: anuja <amore>
Component: ipaAssignee: IPA Maintainers <ipa-maint>
Status: CLOSED CURRENTRELEASE QA Contact: Kaleem <ksiddiqu>
Severity: unspecified Docs Contact:
Priority: unspecified    
Version: 8.0CC: abokovoy, cheimes, jwboyer, ksiddiqu, lpoetter, mkosek, myusuf, ndehadra, pvoborni, rcritten, tscherf
Target Milestone: rcKeywords: Regression
Target Release: 8.0   
Hardware: Unspecified   
OS: Unspecified   
Whiteboard:
Fixed In Version: ipa-server-4.7.1-10 Doc Type: If docs needed, set a value
Doc Text:
Story Points: ---
Clone Of: Environment:
Last Closed: 2019-06-14 01:36:25 UTC Type: Bug
Regression: --- Mount Type: ---
Documentation: --- CRM:
Verified Versions: Category: ---
oVirt Team: --- RHEL 7.3 requirements from Atomic Host:
Cloudforms Team: --- Target Upstream Version:
Embargoed:

Description anuja 2019-01-10 07:57:23 UTC 
Description of problem:
ipa hbacrule-add-service --hbacsvcs=sshd is not applied successfully.

Version-Release number of selected component (if applicable):
ipa-server-4.7.1-7.module+el8+2555+b334d87b.x86_64
sssd-ipa-2.0.0-32.el8.x86_64

How reproducible:
Always

Steps to Reproduce:
Establish trust with :
ipa trust-add ad2016.test --admin --range-type=ipa-ad-trust --password --two-way=True

Then :
1. ipa group-add --desc=0 hbacgroup_external --external
2. ipa group-add --desc=0 hbacgroup
3. ipa group-add-member hbacgroup --groups=hbacgroup_external
4. ipa group-add-member hbacgroup_external             --external='aduser1' --users='' --groups=''
5. ipa hbacrule-add hbacrule_005 --hostcat=all
6. ipa hbacrule-add-service hbacrule_005 --hbacsvcs=sshd
7. ipa hbacrule-add-user hbacrule_005 --groups=hbacgroup
8. ipa hbacrule-disable allow_all

On client :
1. ssh -l aduser1 <hostname>
Actual results:
[root@kvm-01-guest21 ~]# ssh -l aduser1 <hostname>
Password: 
Connection closed by UNKNOWN port 65535

Expected results:
ssh login should be successful.
Or hbacrule should be applied successfully.
Comment 2 Alexander Bokovoy 2019-01-10 08:56:23 UTC 
Upon inspection of the provided machines, I can see that SSSD works as configured. However, When logging in via ssh, pam_systemd attempts to launch user session and that requires pam_sss to allow a session for systemd-user PAM service:

Jan 10 03:34:32 kvm-01-guest10 sshd[1425]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=some-IP user=aduser1
Jan 10 03:34:32 kvm-01-guest10 sshd[1422]: Accepted keyboard-interactive/pam for aduser1 from some-IP port 57756 ssh2
Jan 10 03:34:32 kvm-01-guest10 systemd[1431]: pam_sss(systemd-user:account): Access denied for user aduser1: 6 (Permission denied)
Jan 10 03:34:32 kvm-01-guest10 sshd[1422]: pam_systemd(sshd:session): Failed to create session: Start job for unit user failed with 'failed'
Jan 10 03:34:32 kvm-01-guest10 sshd[1422]: pam_unix(sshd:session): session opened for user aduser1 by (uid=0)

(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_evaluate] (0x0100): [< hbac_evaluate()
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_req_debug_print] (0x2000):     REQUEST:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 service [systemd-user]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 service_group (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 user [aduser1]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 user_group:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                         [hbacgroup]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 targethost [kvm-01-guest10.janhb1.test]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 targethost_group:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                         [ipaservers]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_request_element_debug_print] (0x2000):                 srchost_group (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_req_debug_print] (0x2000):             request time 2019-01-10 03:34:32
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    RULE [hbacrule_02] [ENABLED]:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    services:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0] [NONE]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            services_names:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):                    [sshd]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            services_groups (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    users:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0] [NONE]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            users_names:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):                    [admin]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            users_groups (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    targethosts:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0x1] [ALL]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    srchosts:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0x1] [ALL]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_evaluate] (0x0100): The rule [hbacrule_02] did not match.
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    RULE [hbacrule_002] [ENABLED]:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    services:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0] [NONE]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            services_names:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):                    [sshd]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            services_groups (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    users:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0] [NONE]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            users_names (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            users_groups (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    targethosts:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0x1] [ALL]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    srchosts:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0x1] [ALL]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_evaluate] (0x0100): The rule [hbacrule_002] did not match.
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    RULE [hbacrule_005] [ENABLED]:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    services:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0] [NONE]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            services_names:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):                    [sshd]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            services_groups (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    users:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0] [NONE]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            users_names (none)
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            users_groups:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):                    [hbacgroup]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    targethosts:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0x1] [ALL]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_debug_print] (0x2000):    srchosts:
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_rule_element_debug_print] (0x2000):            category [0x1] [ALL]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_evaluate] (0x0100): The rule [hbacrule_005] did not match.
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [hbac_evaluate] (0x0100): hbac_evaluate() >]
(Thu Jan 10 03:34:32 2019) [sssd[be[janhb1.test]]] [ipa_hbac_evaluate_rules] (0x0080): Access denied by HBAC rules

So I think we should repurpose this bug to add systemd-user HBAC service to FreeIPA by default, create an HBAC service group that includes both ssh and systemd-user service and suggest admins to modify their rules to use this group instead of alone sshd service. It also needs an update to the documentation and release notes.

One last question is to systemd folks. Lennart, in which systemd version the behavior for pam_systemd changed to run user@.unit by default? It is certainly not a default in RHEL 7.
Comment 5 Alexander Bokovoy 2019-01-10 09:25:40 UTC 
I verified that with the following changes everything works:

# ipa hbacsvc-show systemd-user
  Service name: systemd-user
  Member of HBAC service groups: interactive-login
# ipa hbacsvcgroup-show interactive-login
  Service group name: interactive-login
  Member HBAC service: sshd, systemd-user
# ipa hbacrule-show hbacrule_005
  Rule name: hbacrule_005
  Host category: all
  Enabled: TRUE
  User Groups: hbacgroup
  Services: sshd
  Service Groups: interactive-login

When HBAC rule references HBAC services for both sshd and systemd-user (either directly or via HBAC service group), the rule is correctly allowing users to login and create a systemd user session.
Comment 7 Christian Heimes 2019-01-11 08:55:37 UTC 
The issue was introduced when pam_systemd in system-auth was changed from optional to required.

https://bugzilla.redhat.com/show_bug.cgi?id=1643928
https://github.com/pbrezina/authselect/issues/118
Comment 8 Alexander Bokovoy 2019-01-11 15:15:49 UTC 
Pull request: https://github.com/freeipa/freeipa/pull/2746 (ACKed, needs to be committed)
Comment 9 Alexander Bokovoy 2019-01-11 15:16:16 UTC 
Clear needinfo now that we know what is the reason.
Comment 10 Alexander Bokovoy 2019-01-11 15:42:54 UTC 
Here is the difference between broken and fixed versions:

-- Logs begin at Wed 2018-12-05 13:34:40 CET. --
Jan 11 16:36:02 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[29738]: user: Failed at step PAM spawning /usr/lib/systemd/systemd: Operation not permitted
Jan 11 16:36:02 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: user: Failed with result 'protocol'.
Jan 11 16:36:02 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: Failed to start User Manager for UID 487600001.
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: Starting User Manager for UID 487600001...
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73239]: pam_sss(systemd-user:account): Access denied for user testuser1: 6 (Permission denied)
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73239]: PAM failed: Permission denied
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73239]: user: Failed to set up PAM session: Operation not permitted
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73239]: user: Failed at step PAM spawning /usr/lib/systemd/systemd: Operation not permitted
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: user: Failed with result 'protocol'.
Jan 11 16:38:40 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: Failed to start User Manager for UID 487600001.

Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: Starting User Manager for UID 487600001...
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: pam_unix(systemd-user:session): session opened for user testuser1 by (uid=0)
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Starting D-Bus User Message Bus Socket.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Reached target Paths.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Started Mark boot as successful after the user session has run 2 minutes.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Reached target Timers.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Listening on D-Bus User Message Bus Socket.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Reached target Sockets.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Reached target Basic System.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Reached target Default.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[73297]: Startup finished in 78ms.
Jan 11 16:39:07 vm-171-211.abc.idm.lab.eng.brq.redhat.com systemd[1]: Started User Manager for UID 487600001.
Comment 11 Christian Heimes 2019-01-11 15:46:36 UTC 
Fixed upstream
master:
https://pagure.io/freeipa/c/2ef6e14c5a87724a3b37dd5f0817af48c4411e03
Comment 12 Christian Heimes 2019-01-11 17:33:07 UTC 
Fixed upstream
ipa-4-7:
https://pagure.io/freeipa/c/c5cfac3188f2b4c35d3e5aff1828cc2773e7c9ef
Comment 14 Christian Heimes 2019-01-11 18:55:53 UTC 
Fixed upstream
ipa-4-6:
https://pagure.io/freeipa/c/3b9997348d300e36a96730fb703e96ca46f0f4cb
Comment 16 Christian Heimes 2019-01-14 08:22:33 UTC 
I ran into a server or connection problem. The correct backport commit is:

Fixed upstream
ipa-4-7:
https://pagure.io/freeipa/c/aaf938307acbe987f5e1effc2392894c22235013
Comment 26 Rob Crittenden 2019-01-15 19:32:00 UTC 
Fixed bug in initial implementation upstream
master:
https://pagure.io/freeipa/c/965181362a901bb49ee2cfda8aa261a3717213cb
Comment 27 Christian Heimes 2019-01-16 08:56:05 UTC 
I have updated the errata to idm-DL1-820190115215331.5986f621
Comment 28 Christian Heimes 2019-01-16 08:58:35 UTC 
Fixed upstream
ipa-4-7:
https://pagure.io/freeipa/c/456abbc0f91a8575564f54d9ba330a6acfe49d8c
ipa-4-6:
https://pagure.io/freeipa/c/529a667311b0e190a87c09b012868536f3529669
Comment 34 anuja 2019-02-04 10:08:13 UTC 
Verified Using Version :
      ipa-client-4.7.1-10.module+el8+2699+aa606a46.x86_64
      ipa-server-4.7.1-10.module+el8+2699+aa606a46.x86_64
      ipa-server-trust-ad-4.7.1-10.module+el8+2699+aa606a46.x86_64
      sssd-ipa-2.0.0-38.el8.x86_64

Test-console output :

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Setup allow AD user via posix group, client, sshd with hbacrule05
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   Duration: 60s
::   Assertions: 1 good, 0 bad
::   RESULT: PASS

** Setup-allow-AD-user-via-posix-group-client-sshd-with-hbacrule05 PASS Score:0
Uploading resultoutputfile.log .done

::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::
::   allow AD user via posix group, client, sshd
::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::::

:: [ 12:36:07 ] :: [  BEGIN   ] :: Running 'service sssd stop; rm -rf /var/lib/sssd/{db,mc}/*; service sssd start'
Redirecting to /bin/systemctl stop sssd.service
Redirecting to /bin/systemctl start sssd.service
:: [ 12:36:08 ] :: [   PASS   ] :: Command 'service sssd stop; rm -rf /var/lib/sssd/{db,mc}/*; service sssd start' (Expected 0, got 0)
:: [ 12:36:08 ] :: [  BEGIN   ] :: Running 'sleep 10'
:: [ 12:36:18 ] :: [   PASS   ] :: Command 'sleep 10' (Expected 0, got 0)
:: [ 12:36:18 ] :: [  BEGIN   ] :: Running 'service firewalld stop ; service sssd stop ; service sssd start'
Redirecting to /bin/systemctl stop firewalld.service
Redirecting to /bin/systemctl stop sssd.service
Redirecting to /bin/systemctl start sssd.service
:: [ 12:36:19 ] :: [   PASS   ] :: Command 'service firewalld stop ; service sssd stop ; service sssd start' (Expected 0, got 0)
:: [ 12:36:37 ] :: [  BEGIN   ] :: Running 'cat ipa_trust_func_hbac_0005.cmNZ1N'
spawn ssh -l aduser1 vm-idm-038.j53.test
Password: 
**  **  **  **  **  **  **  **  **  **  **  **  **  **  **  **  **  **
         This System is part of the Red Hat Test System.              
                                                                      
      Please do not use this system for individual unit testing.                                        
                       
**  **  **  **  **  **  **  **  **  **  **  **  **  **  **  **  **  **
Last failed login: Wed Jan 23 12:34:23 IST 2019 from x.x.x.x on ssh:notty
There were 2 failed login attempts since the last successful login.
[aduser1@vm-idm-038 ~]$ exit
logout
Connection to vm-idm-038.j53.test closed.

:: [ 12:36:37 ] :: [   PASS   ] :: Command 'cat ipa_trust_func_hbac_0005.cmNZ1N' (Expected 0, got 0)
:: [ 12:36:37 ] :: [   PASS   ] :: File 'ipa_trust_func_hbac_0005.cmNZ1N' should contain 'successful login' 
:: [ 12:36:37 ] :: [   LOG    ] :: ssh login successful

Based on this marking bz as verified.