search

akkornel / syncrepl

Python LDAP Syncrepl client
BSD 3-Clause "New" or "Revised" License
12 stars 8 forks source link

Modifying multiple records at a time do not trigger all callbacks #27

Closed matthewh closed 6 years ago

matthewh commented 6 years ago

I have a FreeIPA server and I'm adding users and adding those users to groups.

FreeIPA does 3 things:

  1. Creates the user.
  2. Updates the group member attribute with the user dn.
  3. Updates the user memberOf attribute with the group dn.

SyncRepl only sees 1 and 2. If I restart my client it will then see the "missing" event 3.

The scary part is IF I create another user without restarting the client, event 3 is permanently lost because syncrepl has moved to a newer cookie value even though it did not handle all of the events.

My best guess is that 2 and 3 are happening so quickly that syncrepl isn't handling it for some reason.

I'm running with REFRESH_AND_PERSIST and have confirmed this behavior with the logging callback.

Any advice?

akkornel commented 6 years ago

Hi Matt,

I think you are seeing this behavior because the memberOf attribute is not actually being stored, it's being generated on the fly by the LDAP server (as if your query included a SQL sub-query / JOIN).

I've seen this before with OpenLDAP, and it seems to me like FreeIPA is using 389, which I believe also does this.

I've written up this behavior here: http://syncrepl-client.readthedocs.io/en/latest/gotchas.html#derived-attribites-like-memberof

Take a look, and see if what I detail matches what you've experienced!

matthewh commented 6 years ago

If I may use an analogy, since it is the season, I feel like a child whose been told Santa isn't real and I don't want to believe. However, your documentation for derived attributes makes sense. Armed with that info I'm reworking my logging to better understand what I'm seeing. Thanks for the info.

matthewh commented 6 years ago

I return for round 2 armed with logs. I still see behavior that I would describe as unexpected.

  1. Start SyncREPL Client There are no changes to process. Cookie at 6601.

    LOADING CALLBACK FROM FILE /opt/syncrepl_client/syncrepl_callback.py
CLIENT SETUP START ldap://localhost:389/cn%3Daccounts%2Cdc%3Dexample%2Cdc%3Dcom??sub?%28%7C%28objectclass%3Dorganizationalperson%29%28objectclass%3Dipausergroup%29%29?bindname=cn%3DDirectory%20Manager,X-BINDPW=password
CLIENT SETUP COMPLETE!
COOKIE ipa.example.com:389#cn=directory manager:cn=accounts,dc=example,dc=com:(|(objectClass=organizationalperson)(objectClass=ipausergroup))#6601
REFRESH COMPLETE

  2. Add a new user, uid=user2, to FreeIPA. All users added will also be put into the ipausers group.

  3. SyncREPL Client sees an ADD user and CHANGE ipausers group. This is expected.

    ADD uid=user2,cn=users,cn=accounts,dc=example,dc=com
krbPrincipalName
    b'user2@EXAMPLE.COM'
userPassword
    b'{SSHA}CKBWSzGDxVxNRsNylP/wLabelLVsujSKOhsgEA=='
givenName
    b'User'
cn
    b'User 2'
mail
    b'user2@example.com'
krbCanonicalName
    b'user2@EXAMPLE.COM'
loginShell
    b'/bin/sh'
displayName
    b'User 2'
ipaUniqueID
    b'e2c09026-dbc7-11e7-b74b-0242ac120002'
initials
    b'U2'
gidNumber
    b'8600045'
gecos
    b'User 2'
uidNumber
    b'8600045'
krbPrincipalKey
    b"0\x81\xde\xa0\x03\x02\x01\x01\xa1\x03\x02\x01\x01\xa2\x03\x02\x01\x02\xa3\x03\x02\x01\x01\xa4\x81\xc70\x81\xc40h\xa0\x1b0\x19\xa0\x03\x02\x01\x04\xa1\x12\x04\x10cRl9`].NTNMPsZ6a\xa1I0G\xa0\x03\x02\x01\x12\xa1@\x04> \x00\t\xe61\x8e\x03\xd8\n\x1d\x1c\xf5\x95\xd0\x9b\xc8\x0fUp\xa4\x9e3D5E\xcf\xc9\x94I\xe8\xcag\xd1Ne\xa3\t{\x94\xcb\xb69\xf2\x1dK\x11(b\xda$ZZ\xb8^\xee\x0b\x11\x13\xac\xc3\x8d\xff0X\xa0\x1b0\x19\xa0\x03\x02\x01\x04\xa1\x12\x04\x10AB7d=US!:I_$;GS'\xa1907\xa0\x03\x02\x01\x11\xa10\x04.\x10\x00\xb2\x06n\xbe8\xef;\x8d\xd2\xa5\x1fGt\xb7\xe1\xf3X\x9c1\xf3\xb3#\x0bxc,c$\xa5\x9fU{E\xf3zj\xa0\x00M\xda\xd2\xe4L%"
sn
    b'2'
homeDirectory
    b'/home/user2'
uid
    b'user2'
objectClass
    b'ipaobject'
    b'person'
    b'top'
    b'ipasshuser'
    b'inetorgperson'
    b'organizationalperson'
    b'krbticketpolicyaux'
    b'krbprincipalaux'
    b'inetuser'
    b'posixaccount'
    b'ipaSshGroupOfPubKeys'
COOKIE ipa.example.com:389#cn=directory manager:cn=accounts,dc=example,dc=com:(|(objectClass=organizationalperson)(objectClass=ipausergroup))#6610
CHANGE cn=ipausers,cn=groups,cn=accounts,dc=example,dc=com
    cn
        b'ipausers'
    description
        b'Default group for all users'
    ipaUniqueID
        b'2792a222-c8f2-11e7-9bec-0242ac120002'
    objectClass
        b'top'
        b'groupofnames'
        b'nestedgroup'
        b'ipausergroup'
        b'ipaobject'
    member
        b'uid=user1,cn=users,cn=accounts,dc=example,dc=com'
        b'uid=user2,cn=users,cn=accounts,dc=example,dc=com'
OLD cn=ipausers,cn=groups,cn=accounts,dc=example,dc=com
    cn
        b'ipausers'
    description
        b'Default group for all users'
    ipaUniqueID
        b'2792a222-c8f2-11e7-9bec-0242ac120002'
    member
        b'uid=user1,cn=users,cn=accounts,dc=example,dc=com'
    objectClass
        b'top'
        b'groupofnames'
        b'nestedgroup'
        b'ipausergroup'
        b'ipaobject'
COOKIE ipa.example.com:389#cn=directory manager:cn=accounts,dc=example,dc=com:(|(objectClass=organizationalperson)(objectClass=ipausergroup))#6612

  4. Stop SyncREPL Client

  5. Start SyncREPL Client

    LOADING CALLBACK FROM FILE /opt/syncrepl_client/syncrepl_callback.py
CLIENT SETUP START ldap://localhost:389/cn%3Daccounts%2Cdc%3Dexample%2Cdc%3Dcom??sub?%28%7C%28objectclass%3Dorganizationalperson%29%28objectclass%3Dipausergroup%29%29?bindname=cn%3DDirectory%20Manager,X-BINDPW=password
CLIENT SETUP COMPLETE!
CHANGE cn=ipausers,cn=groups,cn=accounts,dc=example,dc=com
    cn
        b'ipausers'
    member
        b'uid=user1,cn=users,cn=accounts,dc=example,dc=com'
        b'uid=user2,cn=users,cn=accounts,dc=example,dc=com'
    description
        b'Default group for all users'
    objectClass
        b'top'
        b'groupofnames'
        b'nestedgroup'
        b'ipausergroup'
        b'ipaobject'
    ipaUniqueID
        b'2792a222-c8f2-11e7-9bec-0242ac120002'
OLD cn=ipausers,cn=groups,cn=accounts,dc=example,dc=com
    cn
        b'ipausers'
    member
        b'uid=user1,cn=users,cn=accounts,dc=example,dc=com'
        b'uid=user2,cn=users,cn=accounts,dc=example,dc=com'
    description
        b'Default group for all users'
    objectClass
        b'top'
        b'groupofnames'
        b'nestedgroup'
        b'ipausergroup'
        b'ipaobject'
    ipaUniqueID
        b'2792a222-c8f2-11e7-9bec-0242ac120002'
CHANGE uid=user2,cn=users,cn=accounts,dc=example,dc=com
    objectClass
        b'ipaobject'
        b'person'
        b'top'
        b'ipasshuser'
        b'inetorgperson'
        b'organizationalperson'
        b'krbticketpolicyaux'
        b'krbprincipalaux'
        b'inetuser'
        b'posixaccount'
        b'ipaSshGroupOfPubKeys'
        b'mepOriginEntry'
    givenName
        b'User'
    mail
        b'user2@example.com'
    krbCanonicalName
        b'user2@EXAMPLE.COM'
    ipaUniqueID
        b'e2c09026-dbc7-11e7-b74b-0242ac120002'
    initials
        b'U2'
    gidNumber
        b'8600045'
    uidNumber
        b'8600045'
    sn
        b'2'
    uid
        b'user2'
    userPassword
        b'{SSHA}CKBWSzGDxVxNRsNylP/wLabelLVsujSKOhsgEA=='
    memberOf
        b'cn=ipausers,cn=groups,cn=accounts,dc=example,dc=com'
    krbLastPwdChange
        b'20171208032839Z'
    krbPrincipalName
        b'user2@EXAMPLE.COM'
    krbExtraData
        b'\x00\x02\xe7\x06*Zroot/admin@EXAMPLE.COM\x00'
    homeDirectory
        b'/home/user2'
    loginShell
        b'/bin/sh'
    displayName
        b'User 2'
    cn
        b'User 2'
    gecos
        b'User 2'
    krbPrincipalKey
        b"0\x81\xde\xa0\x03\x02\x01\x01\xa1\x03\x02\x01\x01\xa2\x03\x02\x01\x02\xa3\x03\x02\x01\x01\xa4\x81\xc70\x81\xc40h\xa0\x1b0\x19\xa0\x03\x02\x01\x04\xa1\x12\x04\x10cRl9`].NTNMPsZ6a\xa1I0G\xa0\x03\x02\x01\x12\xa1@\x04> \x00\t\xe61\x8e\x03\xd8\n\x1d\x1c\xf5\x95\xd0\x9b\xc8\x0fUp\xa4\x9e3D5E\xcf\xc9\x94I\xe8\xcag\xd1Ne\xa3\t{\x94\xcb\xb69\xf2\x1dK\x11(b\xda$ZZ\xb8^\xee\x0b\x11\x13\xac\xc3\x8d\xff0X\xa0\x1b0\x19\xa0\x03\x02\x01\x04\xa1\x12\x04\x10AB7d=US!:I_$;GS'\xa1907\xa0\x03\x02\x01\x11\xa10\x04.\x10\x00\xb2\x06n\xbe8\xef;\x8d\xd2\xa5\x1fGt\xb7\xe1\xf3X\x9c1\xf3\xb3#\x0bxc,c$\xa5\x9fU{E\xf3zj\xa0\x00M\xda\xd2\xe4L%"
    mepManagedEntry
        b'cn=user2,cn=groups,cn=accounts,dc=example,dc=com'
    krbPasswordExpiration
        b'20171208032839Z'
OLD uid=user2,cn=users,cn=accounts,dc=example,dc=com
    krbPrincipalName
        b'user2@EXAMPLE.COM'
    userPassword
        b'{SSHA}CKBWSzGDxVxNRsNylP/wLabelLVsujSKOhsgEA=='
    givenName
        b'User'
    cn
        b'User 2'
    mail
        b'user2@example.com'
    krbCanonicalName
        b'user2@EXAMPLE.COM'
    loginShell
        b'/bin/sh'
    displayName
        b'User 2'
    ipaUniqueID
        b'e2c09026-dbc7-11e7-b74b-0242ac120002'
    initials
        b'U2'
    gidNumber
        b'8600045'
    gecos
        b'User 2'
    uidNumber
        b'8600045'
    krbPrincipalKey
        b"0\x81\xde\xa0\x03\x02\x01\x01\xa1\x03\x02\x01\x01\xa2\x03\x02\x01\x02\xa3\x03\x02\x01\x01\xa4\x81\xc70\x81\xc40h\xa0\x1b0\x19\xa0\x03\x02\x01\x04\xa1\x12\x04\x10cRl9`].NTNMPsZ6a\xa1I0G\xa0\x03\x02\x01\x12\xa1@\x04> \x00\t\xe61\x8e\x03\xd8\n\x1d\x1c\xf5\x95\xd0\x9b\xc8\x0fUp\xa4\x9e3D5E\xcf\xc9\x94I\xe8\xcag\xd1Ne\xa3\t{\x94\xcb\xb69\xf2\x1dK\x11(b\xda$ZZ\xb8^\xee\x0b\x11\x13\xac\xc3\x8d\xff0X\xa0\x1b0\x19\xa0\x03\x02\x01\x04\xa1\x12\x04\x10AB7d=US!:I_$;GS'\xa1907\xa0\x03\x02\x01\x11\xa10\x04.\x10\x00\xb2\x06n\xbe8\xef;\x8d\xd2\xa5\x1fGt\xb7\xe1\xf3X\x9c1\xf3\xb3#\x0bxc,c$\xa5\x9fU{E\xf3zj\xa0\x00M\xda\xd2\xe4L%"
    sn
        b'2'
    homeDirectory
        b'/home/user2'
    uid
        b'user2'
    objectClass
        b'ipaobject'
        b'person'
        b'top'
        b'ipasshuser'
        b'inetorgperson'
        b'organizationalperson'
        b'krbticketpolicyaux'
        b'krbprincipalaux'
        b'inetuser'
        b'posixaccount'
        b'ipaSshGroupOfPubKeys'
COOKIE ipa.example.com:389#cn=directory manager:cn=accounts,dc=example,dc=com:(|(objectClass=organizationalperson)(objectClass=ipausergroup))#6615
REFRESH COMPLETE

    This is not expected. Why does stopping and starting SyncREPL now indicate there are more events to process? Cookie #6612 - Cookie #6615?

  6. Stop SyncREPL Client

  7. Start SyncREPL Client

    Now there are no more events to process.

    LOADING CALLBACK FROM FILE /opt/syncrepl_client/syncrepl_callback.py
CLIENT SETUP START ldap://localhost:389/cn%3Daccounts%2Cdc%3Dexample%2Cdc%3Dcom??sub?%28%7C%28objectclass%3Dorganizationalperson%29%28objectclass%3Dipausergroup%29%29?X-BINDPW=password,bindname=cn%3DDirectory%20Manager
CLIENT SETUP COMPLETE!
COOKIE ipa.example.com:389#cn=directory manager:cn=accounts,dc=example,dc=com:(|(objectClass=organizationalperson)(objectClass=ipausergroup))#6615
REFRESH COMPLETE
matthewh commented 6 years ago

The plot thickens. I have identified another field, userPassword, that also behaves oddly. There is an option in the FreeIPA web UI to reset the user password. Resetting the password does not trigger a syncrepl change. Restarting my SyncREPL client will detect the changes.

The command line utility,ipa user-mod user1 --password, will always trigger a syncrepl change.

I ran tcpdump on the server while testing and can confirm the ldap server is not sending these changes when running in REFRESH_AND_PERSIST.

matthewh commented 6 years ago

FreeIPA manages userPassword with a plugin as well. In some instances other attributes are set that will cause the record to replicate with the updated password.

I'll close this one but #24 is still an issue.