Bug 1139361 - RHEL6.6 ssh as admin on ipa server fails after 389-ds-base update
Summary: RHEL6.6 ssh as admin on ipa server fails after 389-ds-base update
Keywords:
Status: CLOSED DUPLICATE of bug 1112702
Alias: None
Product: Red Hat Enterprise Linux 6
Classification: Red Hat
Component: 389-ds-base
Version: 6.6
Hardware: Unspecified
OS: Unspecified
unspecified
unspecified
Target Milestone: rc
: ---
Assignee: Noriko Hosoi
QA Contact: Sankar Ramalingam
URL:
Whiteboard:
Depends On:
Blocks: 990143 1109379
TreeView+ depends on / blocked
 
Reported: 2014-09-08 18:19 UTC by Scott Poore
Modified: 2014-09-11 18:43 UTC (History)
8 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-09-11 18:43:16 UTC
Target Upstream Version:


Attachments (Terms of Use)
dirsrv/ logs (42.72 KB, application/octet-stream)
2014-09-08 18:22 UTC, Scott Poore
no flags Details
/var/log/sssd dir (24.50 KB, application/octet-stream)
2014-09-09 14:02 UTC, Scott Poore
no flags Details

Description Scott Poore 2014-09-08 18:19:55 UTC
Description of problem:

On RHEL6.6 server built from 9/03 source, I installed IPA server.  Then to update, I updated 389-ds-base to version 389-ds-base-1.2.11.15-43.el6.x86_64.  I can no longer log in as admin on the IPA server:

[root@rhel6-1 ~]# ssh admin@$(hostname) "hostname; id"
admin@rhel6-1.testrelm.test's password: 
Connection closed by UNKNOWN


Version-Release number of selected component (if applicable):
389-ds-base-1.2.11.15-43.el6.x86_64

How reproducible:
always

Steps to Reproduce:
1.  Install RHEL6.6 version with 389-ds-base-1.2.11.15-42
2.  ipa-server-install
3.  ssh admin@$(hostname)
works so far
4.  update 389-ds-base to 1.2.11.15-43
3.  ssh admin@$(hostname)

Actual results:

fails on the ssh after updating 389-ds-base

[root@rhel6-1 ~]# yum update 389-ds-base
Loaded plugins: product-id, subscription-manager
This system is not registered to Red Hat Subscription Management. You can use subscription-manager to register.
Setting up Update Process
Resolving Dependencies
--> Running transaction check
---> Package 389-ds-base.x86_64 0:1.2.11.15-42.el6 will be updated
---> Package 389-ds-base.x86_64 0:1.2.11.15-43.el6 will be an update
--> Processing Dependency: 389-ds-base-libs = 1.2.11.15-43.el6 for package: 389-ds-base-1.2.11.15-43.el6.x86_64
--> Running transaction check
---> Package 389-ds-base-libs.x86_64 0:1.2.11.15-42.el6 will be updated
---> Package 389-ds-base-libs.x86_64 0:1.2.11.15-43.el6 will be an update
--> Finished Dependency Resolution

Dependencies Resolved

=======================================================================================================
 Package                Arch         Version                 Repository                           Size
=======================================================================================================
Updating:
 389-ds-base            x86_64       1.2.11.15-43.el6        beaker-rhel-6.6-latest-server       1.5 M
Updating for dependencies:
 389-ds-base-libs       x86_64       1.2.11.15-43.el6        beaker-rhel-6.6-latest-server       417 k

Transaction Summary
=======================================================================================================
Upgrade       2 Package(s)

Total download size: 1.9 M
Is this ok [y/N]: y
Downloading Packages:
(1/2): 389-ds-base-1.2.11.15-43.el6.x86_64.rpm                                  | 1.5 MB     00:02     
(2/2): 389-ds-base-libs-1.2.11.15-43.el6.x86_64.rpm                             | 417 kB     00:00     
-------------------------------------------------------------------------------------------------------
Total                                                                  524 kB/s | 1.9 MB     00:03     
Running rpm_check_debug
Running Transaction Test
Transaction Test Succeeded
Running Transaction
  Updating   : 389-ds-base-libs-1.2.11.15-43.el6.x86_64                                            1/4 
  Updating   : 389-ds-base-1.2.11.15-43.el6.x86_64                                                 2/4 
  Cleanup    : 389-ds-base-1.2.11.15-42.el6.x86_64                                                 3/4 
  Cleanup    : 389-ds-base-libs-1.2.11.15-42.el6.x86_64                                            4/4 
  Verifying  : 389-ds-base-libs-1.2.11.15-43.el6.x86_64                                            1/4 
  Verifying  : 389-ds-base-1.2.11.15-43.el6.x86_64                                                 2/4 
  Verifying  : 389-ds-base-1.2.11.15-42.el6.x86_64                                                 3/4 
  Verifying  : 389-ds-base-libs-1.2.11.15-42.el6.x86_64                                            4/4 

Updated:
  389-ds-base.x86_64 0:1.2.11.15-43.el6                                                                

Dependency Updated:
  389-ds-base-libs.x86_64 0:1.2.11.15-43.el6                                                           

Complete!

[root@rhel6-1 ~]# ipactl restart
Restarting Directory Service
Shutting down dirsrv: 
    PKI-IPA...                                             [  OK  ]
    TESTRELM-TEST...                                       [  OK  ]
Starting dirsrv: 
    PKI-IPA...                                             [  OK  ]
    TESTRELM-TEST...                                       [  OK  ]
Restarting KDC Service
Stopping Kerberos 5 KDC:                                   [  OK  ]
Starting Kerberos 5 KDC:                                   [  OK  ]
Restarting KPASSWD Service
Stopping Kerberos 5 Admin Server:                          [  OK  ]
Starting Kerberos 5 Admin Server:                          [  OK  ]
Restarting DNS Service
Stopping named:                                            [  OK  ]
Starting named:                                            [  OK  ]
Restarting MEMCACHE Service
Stopping ipa_memcached:                                    [  OK  ]
Starting ipa_memcached:                                    [  OK  ]
Restarting HTTP Service
Stopping httpd: service s                                  [  OK  ]
Starting httpd: ssd                                        [  OK  ]
Restarting CA Service
 resStopping pki-ca: tart
                                                           [  OK  ]
Starting pki-ca:                                           [  OK  ]
[root@rhel6-1 ~]# service sssd restart
Stopping sssd:                                             [  OK  ]
Starting sssd:                                             [  OK  ]

[root@rhel6-1 ~]# ssh admin@$(hostname) "hostname; id"
admin@rhel6-1.testrelm.test's password: 
Connection closed by UNKNOWN

Expected results:

ssh works

Additional info:

From /var/log/secure:

Sep  8 13:07:19 rhel6-1 sshd[3351]: pam_unix(sshd:auth): authentication failure; logname= uid=0 euid=0 tty=ssh ruser= rhost=rhel6-1.testrelm.test  user=admin
Sep  8 13:07:20 rhel6-1 sshd[3351]: pam_sss(sshd:auth): authentication success; logname= uid=0 euid=0 tty=ssh ruser= rhost=rhel6-1.testrelm.test user=admin
Sep  8 13:07:20 rhel6-1 sshd[3351]: pam_sss(sshd:account): Access denied for user admin: 4 (System error)
Sep  8 13:07:20 rhel6-1 sshd[3351]: Failed password for admin from 192.168.122.61 port 60100 ssh2
Sep  8 13:07:20 rhel6-1 sshd[3352]: fatal: Access denied for user admin by PAM account configuration


From /var/log/messages:

Sep  8 13:07:20 rhel6-1 sssd[be[testrelm.test]]: dereference processing failed : No such file or directory

I'll attach dirsrv logs separately.

Comment 1 Scott Poore 2014-09-08 18:22:19 UTC
Created attachment 935431 [details]
dirsrv/ logs

Comment 2 Scott Poore 2014-09-08 18:23:33 UTC
Fyi, marking testblocker because it was preventing ipa-replica-install from successfully passing the ipa-replica-conncheck.

Comment 5 Noriko Hosoi 2014-09-08 19:47:17 UTC
Hi Scott,

I think you had no problem with 389-ds-base-1.2.11.15-42.  1.2.11.15-43 was built with this patch on top of 1.2.11.15-42.

* Fri Sep  5 2014 Noriko Hosoi <nhosoi@redhat.com> - 1.2.11.15-43
- Release 1.2.11.15-43
- Resolves: #1112702 - Broken dereference control with the FreeIPA 4.0 ACIs (#47885)

Looking into the access log in /var/log/dirsrv/slapd-TESTRELM-TEST, it ends with ABANDON.  The timestamp matches "Sep  8 13:07:20 rhel6-1 sshd[3351]: pam_sss(sshd:account): Access denied for user admin: 4 (System error)" (although, since the DS access logs are buffered, the timestamp is not very accurate.)

[08/Sep/2014:13:07:20 -0500] conn=11 op=16 SRCH base="cn=accounts,dc=testrelm,dc=test" scope=2 filter="(&(objectClass=ipaHost)(fqdn=rhel6-1.testrelm.test))" attrs="objectClass cn fqdn serverHostName memberOf ipaSshPubKey ipaUniqueID"
[08/Sep/2014:13:07:20 -0500] conn=11 op=16 RESULT err=0 tag=101 nentries=1 etime=0 notes=P
[08/Sep/2014:13:07:20 -0500] conn=11 op=17 SRCH base="fqdn=rhel6-1.testrelm.test,cn=computers,cn=accounts,dc=testrelm,dc=test" scope=0 filter="(objectClass=*)" attrs="objectClass cn memberOf ipaUniqueID"
[08/Sep/2014:13:07:20 -0500] conn=11 op=17 RESULT err=0 tag=101 nentries=1 etime=0 notes=P
[08/Sep/2014:13:07:20 -0500] conn=11 op=18 ABANDON targetop=NOTFOUND msgid=17

No other errors nor operation failures are reported in the log files.  I wonder why the DS received ABANDON request.  And deref (fixed by the 47885 patch) is involved in the operations there?

Ludwig, do you have any idea?

Comment 6 Ludwig 2014-09-09 13:42:32 UTC
no. The change from .42 to .43 seems to be only the fix for #47885 and it changes the behaviour of the deref plugin (as requested by sssd). Now we have the message:

Sep  8 13:07:20 rhel6-1 sssd[be[testrelm.test]]: dereference processing failed : No such file or directory

So to me it looks like sssd is nothandling the change, but we need someone from sssd to look into it

Comment 7 Ludwig 2014-09-09 13:46:40 UTC
what is the IPA version you are using ?

Comment 8 Scott Poore 2014-09-09 13:56:11 UTC
[root@rhel6-1 ~]# rpm -q ipa-server sssd
ipa-server-3.0.0-42.el6.x86_64
sssd-1.11.6-4.el6.x86_64

Comment 9 Scott Poore 2014-09-09 14:02:56 UTC
Created attachment 935745 [details]
/var/log/sssd dir

Comment 10 Ludwig 2014-09-09 14:03:34 UTC
I thought the issue fixed in #47885 was only visible with the new acis in IPA 4.0.
So the question is if .43 is needed in that env ?

Comment 11 Jakub Hrozek 2014-09-09 16:22:15 UTC
Chances are this is caused by the same SSSD bug as 1139044.

Scott, can you re-test with an older SSSD version? 1.11.6-25 or older would do.

Comment 12 Scott Poore 2014-09-09 16:42:21 UTC
sssd-1.11.6-4.el6.x86_64 is the version I had on the server where I saw the problem.  Is that too old?

Comment 13 Scott Poore 2014-09-09 16:49:04 UTC
FYI, I tried with sssd-1.11.6-25.el6.x86_64 and see the same issue still.

Comment 14 Jakub Hrozek 2014-09-10 09:13:30 UTC
So the DS behaviour changed to something SSSD doesn't expect and I'm not sure which part behaves correctly. It's apparently fallout of the dereference changes.

We are dereferencing a memberof attribute of a host object that has no memberof attribute.

With the old version, whenever we searched and used the deref control, we got the deref control back in the reply. That's not the case with the new version and the SSSD dereference code relies on getting the control back.

Which of the two is the expected behavior?

Comment 15 Jakub Hrozek 2014-09-10 09:15:17 UTC
Here is the diff between the ldapsearches with DS-42 and 43:

diff new-version old-version
12c12,13
< krbLastSuccessfulAuth: 20140910090956Z
---
> control: 1.3.6.1.4.1.4203.666.5.16 false MIQAAAAA
> krbLastSuccessfulAuth: 20140910090146Z

The krbLastSuccessfulAuth changed b/c I was authenticating as the host.

Comment 16 Ludwig 2014-09-10 09:58:22 UTC
(In reply to Jakub Hrozek from comment #14)
> So the DS behaviour changed to something SSSD doesn't expect and I'm not
> sure which part behaves correctly. It's apparently fallout of the
> dereference changes.
> 
> We are dereferencing a memberof attribute of a host object that has no
> memberof attribute.
> 
> With the old version, whenever we searched and used the deref control, we
> got the deref control back in the reply. That's not the case with the new
> version and the SSSD dereference code relies on getting the control back.
> 
> Which of the two is the expected behavior?

This is part of the change, when removing entries returned with the deref control because there is no access I noticed that the list could be empty and then did not return the control - maybe this is incorrect. Will try to check the RFC and ask my team.

Comment 17 Ludwig 2014-09-10 10:07:05 UTC
I can revert this change and always return the control, even if it is empty. But reading this part of the spec:
>>
The control value may contain dereference attribute values without
   any dereferenced attribute values, as detailed in Section 2.3.  The
   control semantics does not specify whether this is a consequence of a
   dangling link or of the application of access restrictions on the
   values of the attributes to be dereferenced.
<<

it should also be ok to return references to entries without access.

Comment 18 Nathan Kinder 2014-09-11 18:43:16 UTC
This issue is a regression caused by the fix for bug 1112702.  Closing this as a duplicate, as we'll handle fixing this in the original bug.

*** This bug has been marked as a duplicate of bug 1112702 ***


Note You need to log in before you can comment on or make changes to this bug.