[Issue 10603] New: slapd 2.6.10 aborts in mdb_opinfo_get (id2entry.c:828) serving syncrepl refresh - thread-cached reader txn still active, mdb_txn_renew returns EINVAL
https://bugs.openldap.org/show_bug.cgi?id=10603
Issue ID: 10603 Summary: slapd 2.6.10 aborts in mdb_opinfo_get (id2entry.c:828) serving syncrepl refresh - thread-cached reader txn still active, mdb_txn_renew returns EINVAL Product: OpenLDAP Version: 2.6.10 Hardware: x86_64 OS: Linux Status: UNCONFIRMED Keywords: needs_review Severity: normal Priority: --- Component: slapd Assignee: bugs@openldap.org Reporter: vojtech@dusatko.org Target Milestone: ---
Created attachment 1215 --> https://bugs.openldap.org/attachment.cgi?id=1215&action=edit thread apply all bt (coredump + gdb)
Three-node multiprovider cluster (olcMultiProvider on {0}config and the data DB), back-mdb, replicating one suffix. Overlay stack on the data DB in insertion order: auditlog, memberof, refint, syncprov, ppolicy, unique. syncprov had no checkpoint/sessionlog configured. Consumers use refreshAndPersist, retry "5 20 300 +".
Binary: Debian 13 (trixie) official package slapd 2.6.10+dfsg-1 from deb.debian.org (build "May 29 2025 23:41:48", Debian OpenLDAP Maintainers); symbols from slapd-dbgsym 2.6.10+dfsg-1 (debian-debug archive). No local patches.
Symptom: whenever a provider slapd is (re)started and a consumer reconnects and begins its refresh (present phase; consumer search is base=<suffix> scope=sub deref=0 filter=(objectClass=*) attrs=* +), the provider aborts within seconds:
slapd: ../../../../../servers/slapd/back-mdb/id2entry.c:828: mdb_opinfo_get: Assertion `!rc' failed.
Reproduced 5+ times over two days; effectively every provider restart followed by a consumer refresh crashes it. Environment is small and healthy: data.mdb 1.5 MB, olcDbMaxSize 1 GiB, olcDbMaxReaders default, >20 GB free disk, no other process opens the LMDB env (verified). The DB had been slapindex'ed offline (slapd stopped) before the first occurrence; the crash also reproduces on a freshly started slapd. Loglevel "stats acl filter" during the captured crash.
Analysis from the core: id2entry.c:828 is the mdb_txn_renew() of the thread's cached reader transaction inside mdb_opinfo_get() (rdonly=1, renew=1). The cached txn retrieved via the thread-pool key has mt_flags = 0x20000 (MDB_TXN_RDONLY set, MDB_TXN_FINISHED NOT set), i.e. it was still active, not reset - so mdb_txn_renew() returned EINVAL and the assert fired. The env is healthy: me_flags = 0x30000000 (MDB_ENV_ACTIVE|MDB_ENV_TXKEY, no MDB_FATAL_ERROR). The failing call is syncprov's internal findbase search nested on the same worker thread under the consumer's refresh search; the fresh stack-local mdb_op_info (moi_ref = 0, reader flag) borrowed the thread's cached reader txn while it was still in use - reentrant/unbalanced use of the per-thread cached read transaction (an outer op holding it active, or an earlier op missing its mdb_txn_reset).
Relevant locals at frame 4 (mdb_opinfo_get): renew = 1 data = 0x7f3134105580 (thread-pool cached txn) moi = 0x7f313b7ebc50 {moi_txn = 0x7f3134105580, moi_ref = 0, moi_flag = 1} moi->moi_txn->mt_flags = 0x20000 (RDONLY, not FINISHED -> mdb_txn_renew EINVAL) mdb->mi_dbenv->me_flags = 0x30000000 (no MDB_FATAL_ERROR)
Backtrace of the aborting thread (full "thread apply all bt" attached):
#4 mdb_opinfo_get (op=0x7f313b7fc070, mdb=0x7f31811e9010, rdonly=1, moip=0x7f313b7ebb48) at back-mdb/id2entry.c:828 #5 mdb_search (op=0x7f313b7fc070, rs=0x7f313b7fc000) at back-mdb/search.c:449 #6 overlay_op_walk (op=0x7f313b7fc070, ...) at backover.c:706 #7 over_op_func (op=0x7f313b7fc070, ...) at backover.c:766 #8 syncprov_findbase (op=0x7f3134103be0, fc=0x7f313b7fc330) at overlays/syncprov.c:530 #9 syncprov_op_search (op=0x7f3134103be0, rs=0x7f313b7fd9a0) at overlays/syncprov.c:3175 #10 overlay_op_walk (op=0x7f3134103be0, ...) at backover.c:691 #11 over_op_func (op=0x7f3134103be0, ...) at backover.c:766 #12 fe_op_search (op=0x7f3134103be0, ...) at search.c:426 #13 do_search ... at search.c:267 #14 connection_operation ... at connection.c:1115 #15 connection_read_thread ... at connection.c:1267
Note the two distinct op pointers: the consumer's search op (0x7f3134103be0, frames 8-15) and syncprov's internal findbase op (0x7f313b7fc070, frames 4-7) on the same worker thread. At crash time another worker thread was serving an unrelated cn=config subtree search (config_back_search) and a third was blocked in syslog(3) writing filter-level debug output, in case concurrency is relevant.
slapd log tail before one abort:
conn=1355 fd=18 ACCEPT from IP=<consumer-ip>:48480 (IP=<provider-ip>:1389) conn=1355 op=0 BIND dn="cn=admin,<suffix>" mech=SIMPLE ssf=0 conn=1355 op=1 SRCH base="<suffix>" scope=2 deref=0 filter="(objectClass=*)" conn=1355 op=1 SRCH attr=* + slapd: ../../../../../servers/slapd/back-mdb/id2entry.c:828: mdb_opinfo_get: Assertion `!rc' failed.
Reproduction: restart slapd on a provider; wait for a consumer's syncrepl retry to reconnect and start refresh (seconds to ~1 min). Ordinary application traffic only, no special load.
Timeline note: crashes began after a config deploy that (a) added a slapo-unique instance to the overlay stack, (b) added one new eq index followed by an offline slapindex, (c) changed loglevel to "stats acl filter". We cannot exclude the changed overlay stack being a precondition rather than coincidence.
https://bugs.openldap.org/show_bug.cgi?id=10603
--- Comment #1 from Ondřej Kuzník ondra@mistotebe.net --- Thanks for the report.
This issue tends to correlate with an entry being borrowed from the underlying DB and not returned yet at the point we ask for another (as you see with the open txn). Overlay list and order would matter in exposing the issue. Can you check whether removing (or reordering) an overlay helps mask this issue again and which two overlay's order matters here?
https://bugs.openldap.org/show_bug.cgi?id=10603
Quanah Gibson-Mount quanah@openldap.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Keywords|needs_review | Target Milestone|--- |2.6.16
https://bugs.openldap.org/show_bug.cgi?id=10603
--- Comment #2 from vojtech@dusatko.org --- We attempted to answer the overlay question on a test instance (same 2.6.10+dfsg-1 package, same config and schema). Findings: - The overlay stack and order are identical on the crashing production nodes and on the test instance: auditlog, memberof, refint, syncprov, ppolicy, unique — so there is no ordering difference to bisect against. - We could not reproduce the assert on a single node despite heavy stress: repeated 900 s runs with 8 parallel ldapsearch -E sync=ro full-refresh clients, 8 plain search clients, cn=config searches, continuous add/delete write churn, restarts under load, and syncrepl consumers configured on the instance itself (olcMultiProvider + olcServerID, provider given as literal IP to bypass the "consumer points to current server" skip). - We believe the missing ingredient is a genuinely lagged consumer: a self-consumer's cookie always equals the provider's contextCSN, so refreshes are empty and duplicate deliveries are dropped at the CSN check — the apply-error paths never execute. On production, the asserts always occurred while syncprov was serving a refresh to a reconnecting consumer, and journals show syncrepl_entry: rid=002 be_modify failed (16) and null_callback : error code 0x10 shortly before each crash. - Bisecting overlays on the production cluster itself is not something we can do. We have a full core with debug symbols and can provide further backtraces or dumps on request; meanwhile we run with Restart=on-failure and syncprov sessionlog as mitigations.
-
openldap-its＠openldap.org