Bug 39535 - Another S4 sync problem
Another S4 sync problem
Status: RESOLVED DUPLICATE of bug 35336
Product: UCS
Classification: Unclassified
Component: S4 Connector
UCS 4.0
Other Linux
: P5 normal (vote)
: ---
Assigned To: Connector maintainers
:
Depends on:
Blocks:
  Show dependency treegraph
 
Reported: 2015-10-14 15:38 CEST by Philipp Hahn
Modified: 2015-10-15 15:23 CEST (History)
1 user (show)

See Also:
What kind of report is it?: ---
What type of bug is this?: ---
Who will be affected by this bug?: ---
How will those affected feel about the bug?: ---
User Pain:
Enterprise Customer affected?:
School Customer affected?:
ISV affected?:
Waiting Support:
Flags outvoted (downgraded) after PO Review:
Ticket number:
Bug group (optional):
Max CVSS v3 score:


Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description Philipp Hahn univentionstaff 2015-10-14 15:38:00 CEST
Jenkins regression:
<http://jenkins.knut.univention.de:8080/job/UCS-4.0/job/UCS-4.0-3/job/Autotest%20MultiEnv/lastCompletedBuild/SambaVersion=s4,Systemrolle=master/testReport/61_udm-users/28_displayName_update/test/>

I've been able to reproduce it by running test 61/28 in a tight loop:

| Starting 1 ucs-test at 2015-10-14 14:26:00 to /dev/null
...
| OK: replication complete (nid=16289 lid=16289)
| >>> change firstname and lastname in one step
| Modifying users/user object with {'dn': 'uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa', 'lastname': 'jcn4i1j1gn', 'firstname': '568qm3qo4e'}
| WARNING: replication is in process (nid=16293 lid=16290)
| WARNING: replication is in process (nid=16297 lid=16296)
| OK: replication complete (nid=16302 lid=16302)
| 
| Cleanup after exception: <class 'univention.testing.utils.LDAPObjectValueMissing'> DN: uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa
| displayName: ['yzrpxu9r9b'], missing: '568qm3qo4e jcn4i1j1gn'


From /var/lib/univention-ldap/notify/transaction
| 16289 uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa m
| 
| 16290 cn=S-1-5-21-1488765419-3067749694-130429314-2266,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa a
| 16291 uid=o3j6lmbdqp,cn=users,dc=phahn,dc=qa m
| 16292 cn=S-1-5-21-1488765419-3067749694-130429314-2266,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa d
| 
| 16293 uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa m
| 
| 16294 cn=S-1-5-21-1488765419-3067749694-130429314-2267,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa a
| 16295 uid=odtsnim1pn,cn=users,dc=phahn,dc=qa m
| 16296 cn=S-1-5-21-1488765419-3067749694-130429314-2267,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa d
| 
| 16297 cn=S-1-5-21-1488765419-3067749694-130429314-2268,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa a
| 16298 uid=g86d8fk5fz,cn=users,dc=phahn,dc=qa m
| 16299 cn=S-1-5-21-1488765419-3067749694-130429314-2268,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa d
| 
| 16300 cn=S-1-5-21-1488765419-3067749694-130429314-2269,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa a
| 16301 uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa m
| 16302 cn=S-1-5-21-1488765419-3067749694-130429314-2269,cn=sid,cn=temporary,cn=univention,dc=phahn,dc=qa d

Why does a simple *modify* create temporary SIDs?


# sed -ne '/^14.10.2015 14:26:00/,$p' /var/log/univention/connector-s4.log | pmh
| 14:26:00,560 (PROCESS): sync from ucs: [          user] [    modify] cn=z9a84rnd1z,cn=users,DC=phahn,DC=qa
| 14:26:00,234 (PROCESS): sync from ucs: [          user] [    delete] cn=ls1s36svfl,cn=users,DC=phahn,DC=qa
| 14:26:00,599 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:00,622 (PROCESS): sync from ucs: [          user] [    delete] cn=ufle71rj1i,cn=users,DC=phahn,DC=qa
| 14:26:01,410 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:01,580 (PROCESS): sync from ucs: [          user] [    delete] cn=sibitbyisy,cn=users,DC=phahn,DC=qa
| 14:26:01,451 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:01,481 (PROCESS): sync from ucs: [          user] [    delete] cn=ehqzhuezbi,cn=users,DC=phahn,DC=qa
| 14:26:02,821 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:02,854 (PROCESS): sync from ucs: [          user] [    delete] cn=z9a84rnd1z,cn=users,DC=phahn,DC=qa
| 14:26:03,353 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:04,376 (PROCESS): sync from ucs: [          user] [       add] cn=pq8ywwowbi,cn=users,DC=phahn,DC=qa
| 14:26:05,116 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:05,154 (PROCESS): sync from ucs: [          user] [    modify] cn=pq8ywwowbi,cn=users,DC=phahn,DC=qa
| 14:26:06,210 (PROCESS): sync from ucs: [          user] [    modify] cn=pq8ywwowbi,cn=users,DC=phahn,DC=qa
| 14:26:07,393 (PROCESS): sync from ucs: [          user] [    modify] cn=pq8ywwowbi,cn=users,DC=phahn,DC=qa
| 14:26:08,939 (PROCESS): sync to ucs:   [          user] [    delete] uid=vosigt3j6x,cn=users,dc=phahn,dc=qa
| 14:26:08,939 (WARNING): Object to delete doesn't exsist, ignore (uid=vosigt3j6x,cn=users,dc=phahn,dc=qa)
| 14:26:09,412 (PROCESS): sync to ucs:   [          user] [    delete] uid=qybyms5rhq,cn=users,dc=phahn,dc=qa
| 14:26:09,412 (WARNING): Object to delete doesn't exsist, ignore (uid=qybyms5rhq,cn=users,dc=phahn,dc=qa)
| 14:26:09,833 (PROCESS): sync to ucs:   [          user] [    delete] uid=t08ug8t5em,cn=users,dc=phahn,dc=qa
| 14:26:09,833 (WARNING): Object to delete doesn't exsist, ignore (uid=t08ug8t5em,cn=users,dc=phahn,dc=qa)
| 14:26:10,142 (PROCESS): sync to ucs:   [          user] [    delete] uid=vchl7m8dfw,cn=users,dc=phahn,dc=qa
| 14:26:10,142 (WARNING): Object to delete doesn't exsist, ignore (uid=vchl7m8dfw,cn=users,dc=phahn,dc=qa)
| 14:26:10,475 (PROCESS): sync to ucs:   [          user] [    delete] uid=q16c90ao7l,cn=users,dc=phahn,dc=qa
| 14:26:10,476 (WARNING): Object to delete doesn't exsist, ignore (uid=q16c90ao7l,cn=users,dc=phahn,dc=qa)
| 14:26:10,716 (PROCESS): sync to ucs:   [          user] [    delete] uid=e1eubv7eng,cn=users,dc=phahn,dc=qa
| 14:26:10,717 (WARNING): Object to delete doesn't exsist, ignore (uid=e1eubv7eng,cn=users,dc=phahn,dc=qa)
| 14:26:11,870 (PROCESS): sync to ucs:   [          user] [    delete] uid=lsbo0ee30j,cn=users,dc=phahn,dc=qa
| 14:26:11,870 (WARNING): Object to delete doesn't exsist, ignore (uid=lsbo0ee30j,cn=users,dc=phahn,dc=qa)
| 14:26:11,400 (PROCESS): sync to ucs:   [          user] [    delete] uid=oz5s112nch,cn=users,dc=phahn,dc=qa
| 14:26:11,401 (WARNING): Object to delete doesn't exsist, ignore (uid=oz5s112nch,cn=users,dc=phahn,dc=qa)
| 14:26:11,762 (PROCESS): sync to ucs:   [          user] [    delete] uid=o9nwu5zxeu,cn=users,dc=phahn,dc=qa
| 14:26:11,762 (WARNING): Object to delete doesn't exsist, ignore (uid=o9nwu5zxeu,cn=users,dc=phahn,dc=qa)
| 14:26:12,192 (PROCESS): sync to ucs:   [          user] [    delete] uid=xq57sc8cky,cn=users,dc=phahn,dc=qa
| 14:26:12,192 (WARNING): Object to delete doesn't exsist, ignore (uid=xq57sc8cky,cn=users,dc=phahn,dc=qa)
| 14:26:12,584 (PROCESS): sync to ucs:   [          user] [    delete] uid=xmyu1j8vfm,cn=users,dc=phahn,dc=qa
| 14:26:12,584 (WARNING): Object to delete doesn't exsist, ignore (uid=xmyu1j8vfm,cn=users,dc=phahn,dc=qa)
| 14:26:12,962 (PROCESS): sync to ucs:   [          user] [    delete] uid=xw8owluwus,cn=users,dc=phahn,dc=qa
| 14:26:12,962 (WARNING): Object to delete doesn't exsist, ignore (uid=xw8owluwus,cn=users,dc=phahn,dc=qa)
| 14:26:13,426 (PROCESS): sync to ucs:   [          user] [    delete] uid=l9tavox7qm,cn=users,dc=phahn,dc=qa
| 14:26:13,427 (WARNING): Object to delete doesn't exsist, ignore (uid=l9tavox7qm,cn=users,dc=phahn,dc=qa)
| 14:26:13,902 (PROCESS): sync to ucs:   [          user] [    delete] uid=ab6p573m3o,cn=users,dc=phahn,dc=qa
| 14:26:13,902 (WARNING): Object to delete doesn't exsist, ignore (uid=ab6p573m3o,cn=users,dc=phahn,dc=qa)
| 14:26:14,279 (PROCESS): sync to ucs:   [          user] [    delete] uid=lxt4o5e6cb,cn=users,dc=phahn,dc=qa
| 14:26:14,279 (WARNING): Object to delete doesn't exsist, ignore (uid=lxt4o5e6cb,cn=users,dc=phahn,dc=qa)
| 14:26:14,655 (PROCESS): sync to ucs:   [          user] [    delete] uid=sv5kj0arbu,cn=users,dc=phahn,dc=qa
| 14:26:14,656 (WARNING): Object to delete doesn't exsist, ignore (uid=sv5kj0arbu,cn=users,dc=phahn,dc=qa)
| 14:26:15,170 (PROCESS): sync to ucs:   [          user] [    delete] uid=pzmppf4rqx,cn=users,dc=phahn,dc=qa
| 14:26:15,170 (WARNING): Object to delete doesn't exsist, ignore (uid=pzmppf4rqx,cn=users,dc=phahn,dc=qa)
| 14:26:15,601 (PROCESS): sync to ucs:   [          user] [    delete] uid=c5mla0owsj,cn=users,dc=phahn,dc=qa
| 14:26:15,602 (WARNING): Object to delete doesn't exsist, ignore (uid=c5mla0owsj,cn=users,dc=phahn,dc=qa)
| 14:26:15,829 (PROCESS): sync to ucs:   [          user] [    delete] uid=fb3tx7pkak,cn=users,dc=phahn,dc=qa
| 14:26:15,829 (WARNING): Object to delete doesn't exsist, ignore (uid=fb3tx7pkak,cn=users,dc=phahn,dc=qa)
| 14:26:16,197 (PROCESS): sync to ucs:   [          user] [    delete] uid=ls1s36svfl,cn=users,dc=phahn,dc=qa
| 14:26:16,197 (WARNING): Object to delete doesn't exsist, ignore (uid=ls1s36svfl,cn=users,dc=phahn,dc=qa)
| 14:26:16,540 (PROCESS): sync to ucs:   [          user] [    delete] uid=ufle71rj1i,cn=users,dc=phahn,dc=qa
| 14:26:16,540 (WARNING): Object to delete doesn't exsist, ignore (uid=ufle71rj1i,cn=users,dc=phahn,dc=qa)
| 14:26:16,767 (PROCESS): sync to ucs:   [          user] [    delete] uid=sibitbyisy,cn=users,dc=phahn,dc=qa
| 14:26:16,768 (WARNING): Object to delete doesn't exsist, ignore (uid=sibitbyisy,cn=users,dc=phahn,dc=qa)
| 14:26:17,117 (PROCESS): sync to ucs:   [          user] [    delete] uid=ehqzhuezbi,cn=users,dc=phahn,dc=qa
| 14:26:17,118 (WARNING): Object to delete doesn't exsist, ignore (uid=ehqzhuezbi,cn=users,dc=phahn,dc=qa)
| 14:26:17,419 (PROCESS): sync to ucs:   [          user] [    delete] uid=z9a84rnd1z,cn=users,dc=phahn,dc=qa
| 14:26:17,419 (WARNING): Object to delete doesn't exsist, ignore (uid=z9a84rnd1z,cn=users,dc=phahn,dc=qa)
| 14:26:17,675 (PROCESS): sync to ucs:   [          user] [    modify] uid=pq8ywwowbi,cn=users,dc=phahn,dc=qa
| 14:26:18,521 (PROCESS): sync to ucs:   [          user] [    delete] uid=fwxfarzhtn,cn=users,dc=phahn,dc=qa
| 14:26:18,522 (WARNING): Object to delete doesn't exsist, ignore (uid=fwxfarzhtn,cn=users,dc=phahn,dc=qa)
| 14:26:25,260 (PROCESS): sync from ucs: [          user] [       add] cn=o3j6lmbdqp,cn=users,DC=phahn,DC=qa
| 14:26:26,431 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:26,452 (PROCESS): sync from ucs: [          user] [    modify] cn=o3j6lmbdqp,cn=users,DC=phahn,DC=qa
| 14:26:26,486 (PROCESS): sync from ucs: [          user] [    modify] cn=pq8ywwowbi,cn=users,DC=phahn,DC=qa
| 14:26:27,549 (PROCESS): sync from ucs: [          user] [    modify] cn=o3j6lmbdqp,cn=users,DC=phahn,DC=qa
| 14:26:27,804 (PROCESS): sync from ucs: [          user] [       add] cn=odtsnim1pn,cn=users,DC=phahn,DC=qa
| 14:26:29,609 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:29,640 (PROCESS): sync from ucs: [          user] [    modify] cn=odtsnim1pn,cn=users,DC=phahn,DC=qa
| 14:26:29,693 (PROCESS): sync from ucs: [          user] [    modify] cn=odtsnim1pn,cn=users,DC=phahn,DC=qa
| 14:26:30,835 (PROCESS): sync from ucs: [          user] [       add] cn=g86d8fk5fz,cn=users,DC=phahn,DC=qa
| 14:26:31,725 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:31,744 (PROCESS): sync from ucs: [          user] [    modify] cn=g86d8fk5fz,cn=users,DC=phahn,DC=qa
| 14:26:32,790 (PROCESS): sync from ucs: [          user] [    modify] cn=g86d8fk5fz,cn=users,DC=phahn,DC=qa
| 14:26:32,965 (PROCESS): sync from ucs: [          user] [    modify] cn=g86d8fk5fz,cn=users,DC=phahn,DC=qa
| 14:26:34,132 (PROCESS): sync from ucs: [          user] [       add] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:34,928 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:34,952 (PROCESS): sync from ucs: [          user] [    modify] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:36,100 (PROCESS): sync from ucs: [          user] [    modify] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:37,188 (PROCESS): sync from ucs: [          user] [    modify] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:38,911 (PROCESS): sync to ucs:   [          user] [    modify] uid=o3j6lmbdqp,cn=users,dc=phahn,dc=qa
| 14:26:39,845 (PROCESS): sync to ucs:   [          user] [    modify] uid=odtsnim1pn,cn=users,dc=phahn,dc=qa
| 14:26:40,463 (PROCESS): sync to ucs:   [          user] [    modify] uid=g86d8fk5fz,cn=users,dc=phahn,dc=qa
| 14:26:41,360 (PROCESS): sync to ucs:   [          user] [    modify] uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa
| 14:26:48,301 (PROCESS): sync from ucs: [          user] [    modify] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:48,416 (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa) was not found. The object was removed.
| 14:26:48,438 (PROCESS): sync from ucs: [          user] [    modify] cn=o3j6lmbdqp,cn=users,DC=phahn,DC=qa
| 14:26:48,445 (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=o3j6lmbdqp,cn=users,dc=phahn,dc=qa) was not found. The object was removed.
| 14:26:48,463 (PROCESS): sync from ucs: [          user] [    modify] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:48,595 (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa) was not found. The object was removed.
| 14:26:48,614 (PROCESS): sync from ucs: [          user] [    modify] cn=odtsnim1pn,cn=users,DC=phahn,DC=qa
| 14:26:48,620 (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=odtsnim1pn,cn=users,dc=phahn,dc=qa) was not found. The object was removed.
| 14:26:48,639 (PROCESS): sync from ucs: [          user] [    modify] cn=g86d8fk5fz,cn=users,DC=phahn,DC=qa
| 14:26:48,646 (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=g86d8fk5fz,cn=users,dc=phahn,dc=qa) was not found. The object was removed.
| 14:26:48,665 (PROCESS): sync from ucs: [          user] [    modify] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:48,787 (PROCESS): primary_group_sync_from_ucs: The UCS object (uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa) was not found. The object was removed.
| 14:26:48,806 (PROCESS): sync from ucs: [          user] [    delete] cn=pq8ywwowbi,cn=users,DC=phahn,DC=qa
| 14:26:49,149 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:49,168 (PROCESS): sync from ucs: [          user] [    delete] cn=o3j6lmbdqp,cn=users,DC=phahn,DC=qa
| 14:26:49,546 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:49,567 (PROCESS): sync from ucs: [          user] [    delete] cn=odtsnim1pn,cn=users,DC=phahn,DC=qa
| 14:26:49,896 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:49,916 (PROCESS): sync from ucs: [          user] [    delete] cn=g86d8fk5fz,cn=users,DC=phahn,DC=qa
| 14:26:50,252 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:50,270 (PROCESS): sync from ucs: [          user] [    delete] cn=wc3xnzp7gk,cn=users,DC=phahn,DC=qa
| 14:26:50,618 (PROCESS): sync from ucs: [         group] [    modify] cn=domain users,cn=groups,DC=phahn,DC=qa
| 14:26:51,936 (PROCESS): sync to ucs:   [          user] [    delete] uid=pq8ywwowbi,cn=users,dc=phahn,dc=qa
| 14:26:51,936 (WARNING): Object to delete doesn't exsist, ignore (uid=pq8ywwowbi,cn=users,dc=phahn,dc=qa)
| 14:26:52,443 (PROCESS): sync to ucs:   [          user] [    delete] uid=o3j6lmbdqp,cn=users,dc=phahn,dc=qa
| 14:26:52,443 (WARNING): Object to delete doesn't exsist, ignore (uid=o3j6lmbdqp,cn=users,dc=phahn,dc=qa)
| 14:26:52,771 (PROCESS): sync to ucs:   [          user] [    delete] uid=odtsnim1pn,cn=users,dc=phahn,dc=qa
| 14:26:52,771 (WARNING): Object to delete doesn't exsist, ignore (uid=odtsnim1pn,cn=users,dc=phahn,dc=qa)
| 14:26:53,260 (PROCESS): sync to ucs:   [          user] [    delete] uid=g86d8fk5fz,cn=users,dc=phahn,dc=qa
| 14:26:53,260 (WARNING): Object to delete doesn't exsist, ignore (uid=g86d8fk5fz,cn=users,dc=phahn,dc=qa)
| 14:26:53,605 (PROCESS): sync to ucs:   [          user] [    delete] uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa
| 14:26:53,606 (WARNING): Object to delete doesn't exsist, ignore (uid=wc3xnzp7gk,cn=users,dc=phahn,dc=qa)
| 14:27:48,238 (PROCESS): sync to ucs: Resync rejected dn: CN=dt8goqv9kn,CN=Users,DC=phahn,DC=qa
| 14:27:48,592 (PROCESS): sync to ucs: Resync rejected dn: CN=v0w47de3hj,CN=Users,DC=phahn,DC=qa
| 14:27:48,678 (PROCESS): sync to ucs: Resync rejected dn: CN=kjgc3gt5es,CN=Users,DC=phahn,DC=qa
| 14:27:48,762 (PROCESS): sync to ucs: Resync rejected dn: CN=cigrwpiczh,CN=Users,DC=phahn,DC=qa
| 14:27:48,863 (PROCESS): sync to ucs: Resync rejected dn: CN=f7ldkt9c0m,CN=Users,DC=phahn,DC=qa
Comment 1 Stefan Gohmann univentionstaff 2015-10-15 15:23:37 CEST
It looks like a duplicate of Bug #35336.

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