I have run into this problem today during syncrepl testing, so changed "Ticket origin" to IPA.

I was unable to reproduce the problem (kind of hang of the task). Using a test case (lib389), it succeeds to index an attribute (here 'cn').
For example:

{{{
dn: cn=db2index_2014_2_7_17_55_14,cn=index,cn=tasks,cn=config
objectClass: top
objectClass: extensibleObject
cn: db2index_2014_2_7_17_55_14
nsinstance: changelog
nsindexattribute: cn
nstaskcurrentitem: 0
nstasktotalitems: 1
nstasklog:: Y2hhbmdlbG9nOiBJbmRleGluZyBhdHRyaWJ1dGU6IGNuCmNoYW5nZWxvZzogRmluaX
NoZWQgaW5kZXhpbmcu
nstaskstatus: changelog: Finished indexing.
nstaskexitcode: 0
}}}

The problem is possibly not systematic or has been fixed since it was reported.
I will continue investigation

attachment
ticket47619_test.py

I am still failing to reproduce with the attached test case.
The test case does the following:
- create 1Master-1Consumer
- On master enable: referential integrity, memberof, retro-changelog
- Create entries on the replicated suffix
- Creates several indexes on the 'cn=changelog' suffix and reindex them with tasks.

All reindex completed successfully, although the index are empty.
I fail to reproduce on master, 1.3.1, 1.2.11

Interesting. I don't have the original VM anymore so I will close the ticket.

Thank you for your time!

Hi Peter,

I reproduced locally the problem:

{{{

0 pthread_rwlock_wrlock () at ../nptl/sysdeps/unix/sysv/linux/x86_64/pthread_rwlock_wrlock.S:86

1 0x00007fa093178b59 in slapi_rwlock_wrlock (rwlock=0x138e2b0) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/slapi2nspr.c:267

2 0x00007fa0930ed397 in slapi_be_Wlock (be=0x1380950) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/backend_manager.c:436

3 0x00007fa0931384c0 in slapi_mtn_be_set_readonly (be=0x1380950, readonly=1) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/mapping_tree.c:3724

4 0x00007fa08fa48b6a in instance_set_busy_and_readonly (inst=0x132a910) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/back-ldbm/misc.c:210

5 0x00007fa08fa41c63 in ldbm_back_ldbm2index (pb=0x7fa044003810) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/back-ldbm/ldif2ldbm.c:1742

6 0x00007fa093184aa8 in task_index_thread (arg=0x7fa044003810) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/task.c:1644

7 0x0000003c53028b46 in _pt_root (arg=0x7fa044003ad0) at ../../../nspr/pr/src/pthreads/ptthread.c:204

8 0x0000003bee407d14 in start_thread (arg=0x7fa066fe5700) at pthread_create.c:309

9 0x0000003bee0f168d in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:115

}}}

Talking with Ludwig yesterday, I realized that the difference of my test case vs. what he did was that the instance was restarted before the reindex. It makes the difference and allow me to reproduce.

I reopen that ticket.

Sorry for the noise

To do a reindex task, the 'changelog' backend needs to be acquired in Write. The hang of the thread processing the task is due to the 'changelog' backend being already acquired in Read.

This seems to be triggered by the retro-changelog plugin startup routine that acquires the backend in Read but does not to release it after the plugin initialization.

{{{
(gdb) where

0 slapi_be_Rlock (be=0x93ac90) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/backend_manager.c:430

1 0x00007ffff7d44c08 in mtn_get_be (target_node=0x7a5e60, pb=0xa8c160, be=0x7fffffffb990, index=0x7fffffffb940,

referral=0x7fffffffb998, errorbuf=0x7fffffffb9b0 "")
at ../workspaces/389-master-branch/ds/ldap/servers/slapd/mapping_tree.c:2789

2 0x00007ffff7d43978 in slapi_mapping_tree_select (pb=0xa8c160, be=0x7fffffffb990, referral=0x7fffffffb998,

errorbuf=0x7fffffffb9b0 "") at ../workspaces/389-master-branch/ds/ldap/servers/slapd/mapping_tree.c:2214

3 0x00007ffff30a5ada in retrocl_select_backend ()

at ../workspaces/389-master-branch/ds/ldap/servers/plugins/retrocl/retrocl.c:241

4 0x00007ffff30a5d07 in retrocl_start (pb=0x9037e8)

at ../workspaces/389-master-branch/ds/ldap/servers/plugins/retrocl/retrocl.c:333

5 0x00007ffff7d5e7cc in plugin_call_func (list=0x82b1b0, operation=212, pb=0x9037e8, call_one=1)

at ../workspaces/389-master-branch/ds/ldap/servers/slapd/plugin.c:1474

6 0x00007ffff7d5e6b9 in plugin_call_one (list=0x82b1b0, operation=212, pb=0x9037e8)

at ../workspaces/389-master-branch/ds/ldap/servers/slapd/plugin.c:1442

7 0x00007ffff7d5deca in plugin_dependency_startall (argc=9, argv=0x7fffffffe2d8,

errmsg=0x7ffff7dbc254 "plugin startup failed\n", operation=212)
at ../workspaces/389-master-branch/ds/ldap/servers/slapd/plugin.c:1214

8 0x00007ffff7d5e5eb in plugin_startall (argc=9, argv=0x7fffffffe2d8, start_backends=1, start_global=1)

at ../workspaces/389-master-branch/ds/ldap/servers/slapd/plugin.c:1404

9 0x00000000004239f7 in main (argc=9, argv=0x7fffffffe2d8) at ../workspaces/389-master-branch/ds/ldap/servers/slapd/main.c:1187

}}}

What I do not understand is why it requires a restart between index configuration and reindex to trigger the hang.

If the server is not restarted is the index really active, does indexing work and try to acquire the lock ?

Regarding the test case:
After enabling the RetroCL plugin, at restart, the backend is not found. So it is not locked (in read), just created.
Later restart, will find the backend, that is this time acquired in Read and could trigger this hang.

Regarding the index:
I need to check. Indexes are created/used with a restart between 'index' configuratin and reindex.
I will check without restart

Regarding index:

Once retroCL is enabled and the server restarted.
Indexes are really active as soon as the index entry is created and reindex task complete.
It does not require a restart to make active the new indexes

attachment
0001-Ticket-47619-test-case.patch

attachment
0002-Ticket-47619-cannot-reindex-retrochangelog.patch

git merge ticket47619

Updating 5b8dfcd..8087f05
Fast-forward
dirsrvtests/tickets/ticket47619_test.py | 299 ++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++++
ldap/servers/plugins/retrocl/retrocl.c | 3 +
2 files changed, 302 insertions(+)
create mode 100644 dirsrvtests/tickets/ticket47619_test.py

git push origin master

Counting objects: 18, done.
Delta compression using up to 4 threads.
Compressing objects: 100% (10/10), done.
Writing objects: 100% (10/10), 4.09 KiB, done.
Total 10 (delta 6), reused 0 (delta 0)
To ssh://git.fedorahosted.org/git/389/ds.git
5b8dfcd..8087f05 master -> master

commit 8087f058cd9acc304de351412742fd8ceb3ceb48
Author: Thierry bordaz (tbordaz) tbordaz@redhat.com
Date: Wed Jan 15 09:59:13 2014 +0100

Pushed to 389-ds-base-1.2.11:

9034668..a5499cb 389-ds-base-1.2.11 -> 389-ds-base-1.2.11
commit a5499cbf60c6b8277f0acffed8763ffe52ae4aff

389-ds-base is moving from Pagure to Github. This means that new issues and pull requests
will be accepted only in 389-ds-base's github repository.

This issue has been cloned to Github and is available here:
- https://github.com/389ds/389-ds-base/issues/956

If you want to receive further updates on the issue, please navigate to the github issue
and click on subscribe button.

Thank you for understanding. We apologize for all inconvenience.