Ticket #360 (closed defect: fixed)

Opened 2 years ago

Last modified 22 months ago

ldapmodify returns Operations error

Reported by: rmeggins Owned by: rmeggins
Priority: blocker Milestone: 1.2.11.5
Component: Database - General Version:
Keywords: Cc: amessina@…
Blocked By: Blocking:
Review: ack Ticket origin:
Red Hat Bugzilla: 819409, 820265, 833218

Description

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.

Attachments

0001-Ticket-360-ldapmodify-returns-Operations-error.patch (111.8 KB) - added by rmeggins 2 years ago.
0001-Ticket-360-ldapmodify-returns-Operations-error.patch
0001-Ticket-360-ldapmodify-returns-Operations-error-fix-d.patch (3.1 KB) - added by rmeggins 22 months ago.
0001-Ticket-360-ldapmodify-returns-Operations-error-fix-d.patch
0005-Ticket-360-ldapmodify-returns-Operations-error-fix-d.patch (1.8 KB) - added by rmeggins 22 months ago.
txn retry must remove tombstone from cache before adding back orig entry

Change History

comment:1 Changed 2 years ago by rmeggins

  • Owner changed from nhosoi to rmeggins
  • Status changed from new to accepted

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.

comment:2 Changed 2 years ago by amessina

  • Cc amessina@… added

comment:3 Changed 2 years ago by nkinder

  • Red Hat Bugzilla changed from [https://bugzilla.redhat.com/show_bug.cgi?id=819409 819409] to [https://bugzilla.redhat.com/show_bug.cgi?id=819409 819409], [https://bugzilla.redhat.com/show_bug.cgi?id=820265 820265]

comment:4 Changed 2 years ago by rmeggins

  • Milestone changed from 1.2.11.rc1 to 1.2.11.4

Changed 2 years ago by rmeggins

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

comment:5 Changed 2 years ago by rmeggins

  • Review changed from Needs Review to review?

comment:6 Changed 23 months ago by mreynolds

  • Review changed from review? to ack

Looks good

comment:7 Changed 23 months ago by rmeggins

  • Resolution set to fixed
  • Status changed from accepted to closed

commit changeset:48b8ace54583662306c75f22f2f243fc274251af/389-ds-base
Author: Rich Megginson <rmeggins@…>
Date: Mon May 14 15:14:28 2012 -0600

comment:8 Changed 22 months ago by rmeggins

  • Resolution fixed deleted
  • Status changed from closed to reopened

Changed 22 months ago by rmeggins

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

comment:9 Changed 22 months ago by rmeggins

  • Review changed from ack to review?
  • Milestone changed from 1.2.11.4 to 1.2.11.5

comment:10 Changed 22 months ago by nhosoi

  • Review changed from review? to ack

comment:11 Changed 22 months ago by rmeggins

  • Resolution set to fixed
  • Status changed from reopened to closed

To ssh://git.fedorahosted.org/git/389/ds.git

97ef3dd..79799c9 master -> master

commit changeset:79799c93959d9cc3f836423fd65a1aed9ea6f1f5/389-ds-base
Author: Rich Megginson <rmeggins@…>
Date: Wed Jun 13 14:28:51 2012 -0600

comment:12 Changed 22 months ago by rmeggins

  • Resolution fixed deleted
  • Status changed from closed to reopened

Changed 22 months ago by rmeggins

txn retry must remove tombstone from cache before adding back orig entry

comment:13 Changed 22 months ago by rmeggins

  • Review changed from ack to review?

comment:14 Changed 22 months ago by nkinder

  • Review changed from review? to ack

comment:15 Changed 22 months ago by nkinder

  • Red Hat Bugzilla changed from [https://bugzilla.redhat.com/show_bug.cgi?id=819409 819409], [https://bugzilla.redhat.com/show_bug.cgi?id=820265 820265] to [https://bugzilla.redhat.com/show_bug.cgi?id=819409 819409], [https://bugzilla.redhat.com/show_bug.cgi?id=820265 820265], [https://bugzilla.redhat.com/show_bug.cgi?id=833218 833218]

Ticket has been cloned to Bugzilla: https://bugzilla.redhat.com/show_bug.cgi?id=833218

comment:16 Changed 22 months ago by rmeggins

  • Resolution set to fixed
  • Status changed from reopened to closed

master:
commit changeset:c3a3eca5ce57de6d2ed24cb02adf75cb7ab34d4e/389-ds-base
Author: Rich Megginson <rmeggins@…>
Date: Fri Jun 15 18:15:45 2012 -0600

1.2.11:
commit changeset:bc428d413c29f0aba78674fb20b85846f67c1bc2/389-ds-base
Author: Rich Megginson <rmeggins@…>
Date: Fri Jun 15 18:15:45 2012 -0600

comment:17 Changed 20 months ago by nkinder

  • screened set to 1

Added initial screened field value.

Note: See TracTickets for help on using tickets.