#360 ldapmodify returns Operations error

Created 5 years ago by rmeggins
Modified 3 months ago

https://bugzilla.redhat.com/show_bug.cgi?id=819409 (Fedora)

Description of problem:
When installing FreeIPA, ldapmodify reports Operations Error and does not write
data to LDAP (privilege objects in this case). This causes subsequent issues in
FreeIPA install:

# ipa-server-install
...
Configuring directory server: Estimated time 1 minute
  [1/35]: creating directory server user
  [2/35]: creating directory server instance
  [3/35]: adding default schema
  [4/35]: enabling memberof plugin
  [5/35]: enabling referential integrity plugin
  [6/35]: enabling winsync plugin
  [7/35]: configuring replication version plugin
  [8/35]: enabling IPA enrollment plugin
  [9/35]: enabling ldapi
  [10/35]: configuring uniqueness plugin
  [11/35]: configuring uuid plugin
  [12/35]: configuring modrdn plugin
  [13/35]: enabling entryUSN plugin
  [14/35]: configuring lockout plugin
  [15/35]: creating indices
  [16/35]: configuring ssl for ds instance
  [17/35]: configuring certmap.conf
  [18/35]: configure autobind for root
  [19/35]: configure new location for managed entries
  [20/35]: restarting directory server
  [21/35]: adding default layout
  [22/35]: adding delegation layout
ipa         : CRITICAL Failed to load delegation.ldif: Command
'/usr/bin/ldapmodify -h vm-109.idm.lab.bos.redhat.com -v -f /tmp/tmpM7h8OS -x
-D cn=Directory Manager -y /tmp/tmpW0nOK4' returned non-zero exit status 1
  [23/35]: adding replication acis
  [24/35]: creating container for managed entries
  [25/35]: configuring user private groups
  [26/35]: configuring netgroups from hostgroups
...


ipaserver-install.log excerpt:
2012-05-07T06:45:15Z DEBUG   [22/35]: adding delegation layout
2012-05-07T06:45:16Z DEBUG args=/usr/bin/ldapmodify -h
vm-109.idm.lab.bos.redhat.com -v -f /tmp/       tmpM7h8OS -x -D cn=Directory
Manager -y /tmp/tmpW0nOK4
2012-05-07T06:45:16Z DEBUG stdout=add objectClass:
    top
    nsContainer
add cn:
    roles
adding new entry "cn=roles,cn=accounts,dc=idm,dc=lab,dc=bos,dc=redhat,dc=com"
modify complete

add objectClass:
    top
    nsContainer
add cn:
    pbac
adding new entry "cn=pbac,dc=idm,dc=lab,dc=bos,dc=redhat,dc=com"
modify complete
...
add objectClass:
    top
    groupofnames
    nestedgroup
add cn:
    Group Administrators
add description:
    Group Administrators
adding new entry "cn=Group
Administrators,cn=privileges,cn=pbac,dc=idm,dc=lab,dc=bos,dc=redhat,dc=com"


2012-05-07T06:45:16Z DEBUG stderr=ldap_initialize(
ldap://vm-109.idm.lab.bos.redhat.com )
ldap_add: Operations error (1)

2012-05-07T06:45:16Z CRITICAL Failed to load delegation.ldif: Command
'/usr/bin/ldapmodify -h vm-109.  idm.lab.bos.redhat.com -v -f /tmp/tmpM7h8OS -x
-D cn=Directory Manager -y /tmp/tmpW0nOK4' returned non-zero exit status 1


I found a strange error in dirsrv error log (full log attached) which may be
relevant:

[07/May/2012:02:45:13 -0400] - slapd stopped.
[07/May/2012:02:45:14 -0400] - 389-Directory/1.2.11.3 B2012.126.1429 starting
up
[07/May/2012:02:45:14 -0400] attrcrypt - No symmetric key found for cipher AES
in backend userRoot,    attempting to create one...
[07/May/2012:02:45:14 -0400] attrcrypt - Key for cipher AES successfully
generated and stored
[07/May/2012:02:45:14 -0400] attrcrypt - No symmetric key found for cipher 3DES
in backend userRoot,   attempting to create one...
[07/May/2012:02:45:14 -0400] attrcrypt - Key for cipher 3DES successfully
generated and stored
[07/May/2012:02:45:14 -0400] ipaenrollment_start - [file ipa_enrollment.c, line
390]: Failed to get    default realm?!
[07/May/2012:02:45:14 -0400] - slapd started.  Listening on All Interfaces port
389 for LDAP requests
[07/May/2012:02:45:14 -0400] - Listening on All Interfaces port 636 for LDAPS
requests
[07/May/2012:02:45:14 -0400] - Listening on
/var/run/slapd-IDM-LAB-BOS-REDHAT-COM.socket for LDAPI     requests
[07/May/2012:02:45:15 -0400] - Skipping CoS Definition cn=Password
Policy,cn=accounts,dc=idm,dc=lab,   dc=bos,dc=redhat,dc=com--no CoS Templates
found, which should be added before the CoS Definition.
[07/May/2012:02:45:15 -0400] - libdb: BDB0102 previous transaction deadlock
return not resolved
[07/May/2012:02:45:15 -0400] entryrdn-index - _entryrdn_put_data: Adding the
self link (61) failed:    Invalid argument (22)
[07/May/2012:02:45:15 -0400] - add: attempt to index 61 failed


Version-Release number of selected component (if applicable):
389-ds-base-1.2.11.3-1.fc17.x86_64

How reproducible:


Steps to Reproduce:
1. Install freeipa on F-17 and observe installation
2.
3.

Actual results:
Installation reports 389-ds errors

Expected results:
Installation succeeds without 389-ds errors

Additional info:
Target VM has 1G memory, there were several related warnings in the beginning
of the error log, not sure if it is connected with the error.

The entryrdn code does this:
{{{
for (db_retry = 0; db_retry < RETRY_TIMES; db_retry++) {
rc = cursor->c_put(cursor, key, data, DB_NODUPDATA);
if (rc == DB_LOCK_DEADLOCK) {
random_sleep();
continue; / retry /
}
...
}
}}}

Unfortunately, this won't work, according to the bdb docs:
file:///usr/share/doc/db4-devel-4.7.25/gsg_txn/C/lockingsubsystem.html

When DB determines that a deadlock has occurred, it will select a thread of control to resolve the deadlock and then return DB_LOCK_DEADLOCK to that thread. If a deadlock is detected, the thread must:

Cease all read and write operations.

Close all open cursors.

Abort the transaction.

Optionally retry the operation. If your application retries deadlocked operations, the new attempt must be made using a new transaction.

Note

If a thread has deadlocked, it may not make any additional database calls using the handle that has deadlocked.

Everywhere in our code that may potentially get a DB_LOCK_DEADLOCK return will have to bubble that error up to the highest level where the transaction was created.

0001-Ticket-360-ldapmodify-returns-Operations-error.patch
0001-Ticket-360-ldapmodify-returns-Operations-error.patch

commit changeset 48b8ace/389-ds-base
Author: Rich Megginson rmeggins@redhat.com
Date: Mon May 14 15:14:28 2012 -0600

0001-Ticket-360-ldapmodify-returns-Operations-error-fix-d.patch
0001-Ticket-360-ldapmodify-returns-Operations-error-fix-d.patch

To ssh://git.fedorahosted.org/git/389/ds.git
97ef3dd. 79799c9 master -> master
commit changeset 79799c9/389-ds-base
Author: Rich Megginson rmeggins@redhat.com
Date: Wed Jun 13 14:28:51 2012 -0600

txn retry must remove tombstone from cache before adding back orig entry
0005-Ticket-360-ldapmodify-returns-Operations-error-fix-d.patch

master:
commit changeset c3a3eca/389-ds-base
Author: Rich Megginson rmeggins@redhat.com
Date: Fri Jun 15 18:15:45 2012 -0600

1.2.11:
commit changeset bc428d4/389-ds-base
Author: Rich Megginson rmeggins@redhat.com
Date: Fri Jun 15 18:15:45 2012 -0600

Added initial screened field value.

3 months ago

Metadata Update from @nkinder:
- Issue assigned to rmeggins
- Issue set to the milestone: 1.2.11.5

Login to comment on this ticket.