https://bugs.openldap.org/show_bug.cgi?id=10597
Issue ID: 10597 Summary: slapo-accesslog frees a shared `entryUUID` value from operations that do not hold the mutex guarding it, causing a double free and heap corruption. Introduced in 2.6.14 by the fix for ITS#10482. Product: OpenLDAP Version: 2.6.14 Hardware: All OS: All Status: UNCONFIRMED Keywords: needs_review Severity: normal Priority: --- Component: overlays Assignee: bugs@openldap.org Reporter: bohdan.kmit@kiteworks.com Target Milestone: ---
Created attachment 1212 --> https://bugs.openldap.org/attachment.cgi?id=1212&action=edit Patch
# Symptom
`slapd` terminates with SIGSEGV under concurrent write and search load. glibc reports the corruption at whatever the process allocates next, so the message varies:
``` double free or corruption (out) malloc(): unaligned fastbin chunk detected malloc(): unaligned tcache chunk detected free(): invalid pointer ```
Of ten cores collected from one instance, nine abort inside `malloc()` or `calloc()` at unrelated allocation sites and carry no information about the origin. One caught the faulting free itself:
``` #4 free () #5 accesslog_response (op=<optimized out>, rs=...) at accesslog.c:2034 #6 ... #8 slap_send_ldap_result () ```
(line 2034 in 2.6.15; the equivalent is 2176 in current master.)
# Analysis
`accesslog_response()` ends with:
```c skip: if ( !BER_BVISNULL( &li->li_uuid ) ) { ber_memfree( li->li_uuid.bv_val ); BER_BVZERO( &li->li_uuid ); } if ( lo->mask & LOG_OP_WRITES ) { /* We haven't transitioned to li_log_mutex yet */ ldap_pvt_thread_mutex_unlock( &li->li_op_rmutex ); } return SLAP_CB_CONTINUE; ```
`li_uuid` is a field of the shared `log_info` instance, not of the operation. Access to it is asymmetric:
* Write operations (`bi_op_add`, `bi_op_delete`, `bi_op_modify`, `bi_op_modrdn` → `accesslog_op_mod()`) acquire `li_op_rmutex` and populate `li_uuid` with `ber_dupbv()` while holding it. They still hold it on entry to `accesslog_response()`, free under it at `skip:`, and release it immediately after. This is correct.
* Non-write operations (`bi_op_bind`, `bi_op_compare`, `bi_op_search`, `bi_extended` → `accesslog_op_misc()`) take no lock at all. `accesslog_response()` acquires `li_op_rmutex` for them only part-way through the function, and **all four `goto skip` sites precede that acquisition** (master: 1656, 1661, 1671, 1683 versus the lock at 1693). Such an operation therefore reaches `skip:` holding no lock, and frees a pointer it never set.
The `goto skip` conditions reachable this way are:
| site | condition | |------|-----------------------------------------------------| | 1656 | log database absent or not open | | 1661 | `op->o_dont_replicate` | | 1671 | `li_success` configured and the operation failed | | 1683 | operation not in `li_ops` and no matching `logbase` |
Two consequences follow:
1. Two non-write operations completing concurrently both observe a non-NULL `li_uuid` and both call `ber_memfree()` on it — a double free. 2. A non-write operation can free it in the window between a write operation storing the value and that write operation taking ownership of it (master 1716–1718, under both mutexes). The write path then works with, and frees, a dangling pointer.
Either way the allocator's free lists are corrupted, and the failure surfaces later at an unrelated allocation, which is why almost every core points somewhere innocent.
The exposure depends strongly on configuration. With `olcAccessLogOps: writes`, searches are not in `li_ops`, so **every search** fails the test at 1673 and takes `goto skip` at 1683. A read-heavy workload therefore executes the unlocked free at close to search rate. Note that 1683 is unreachable for write operations, since `accesslog_op_mod()` applies the same test before registering the callback.
Access to the tree of related state is otherwise correct: every use of `li_mincsn`, `li_sids` and `li_numcsns` in `log_old_lookup()`, `accesslog_purge()`, `accesslog_response()` and `accesslog_db_root()` is serialised by `li_log_mutex`, and no locked region in the file contains a `return` or `goto` that bypasses its unlock. `li_uuid` is the only unserialised mutation.
# Regression
The unconditional free was added by:
``` 5c4e7f2f1a ITS#10482 slapo-accesslog: do not leak entryUUID (2026-03-31) ab4e53e54b same, backported to the 2.6 branch ```
That commit consists solely of those four lines. It plugs a genuine leak but places the release on a path reachable without the mutex.
# Affected versions
| release | affected | |--------------|----------| | 2.6.13 | no | | 2.6.14 | yes | | 2.6.15 | yes | | 2.7.0, 2.7.1 | yes | | master | yes |
Observed on 2.6.15, x86-64, glibc, back-mdb, with `syncprov` and `accesslog` on the same database and delta-syncrepl consumers reading the accesslog.
# Reproduction
Configuration: `accesslog` over back-mdb with `olcAccessLogOps: writes` and `olcAccessLogSuccess: TRUE`.
Load: six concurrent MODIFY streams cycling over four DNs (to maximise same-target concurrency), two more spread over twenty DNs, one stream of ADDs of existing entries (returning `entryAlreadyExists`), and twelve concurrent search streams over the same subtree.
Result: SIGSEGV within **13–24 seconds**, repeatably — effectively one crash per load application.
Two observations that isolate the mechanism:
* The **same write load with no search streams ran 300 seconds without a fault.** Searches are required, because only non-write operations take the unlocked path. * Instances receiving the identical replicated write stream but carrying **no local search traffic** ran 68 minutes without a fault, while an instance with local searches plus the same replicated writes crashed.
`MALLOC_CHECK_` does not help: by the time of the second free the chunk has typically been handed to another allocation, so it is a valid live chunk and nothing is flagged at the free.
# Proposed fix
Free the value only on the path that owns it and already holds the mutex:
```diff skip: - if ( !BER_BVISNULL( &li->li_uuid ) ) { - ber_memfree( li->li_uuid.bv_val ); - BER_BVZERO( &li->li_uuid ); - } if ( lo->mask & LOG_OP_WRITES ) { + /* Only this path holds li_op_rmutex, which guards li_uuid */ + if ( !BER_BVISNULL( &li->li_uuid ) ) { + ber_memfree( li->li_uuid.bv_val ); + BER_BVZERO( &li->li_uuid ); + } /* We haven't transitioned to li_log_mutex yet */ ldap_pvt_thread_mutex_unlock( &li->li_op_rmutex ); } ```
Non-write operations never populate `li_uuid`, so they have nothing to release; the leak ITS#10482 addressed remains fixed for the write path, which is the only producer. Because every `goto skip` precedes the mutex acquisition, no path can now reach the label holding the lock without releasing it.
# Related observation, not addressed by this patch
`li_old` has the same missing release. `accesslog_op_mod()` assigns `li->li_old = entry_dup( e )` without freeing any previous value, `accesslog_response()` moves it out only on the non-skip path, and neither `skip:` nor `accesslog_db_destroy()` releases it. A write operation whose response takes `goto skip` therefore strands an `Entry`, which the next write overwrites and leaks. This requires `olcAccessLogOld` to be configured and is a leak only — no unserialised free, so no corruption. Reported for completeness rather than fixed here.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #1 from jukka.karvonen@helsinki.fi --- We noticed this yesterday with one upgrade. Couldn't identify the reason, other than incoming syncrepl connection seemed to terminate to "free(): invalid pointer" error with versions newer than 2.6.13. We have had some nodes running 2.6.14 for couple of weeks and those didn't seem to be affected, but they also didn't get as much load and no writes, other than syncrepl.
Today was trying to reproduce this, until noticed this issue. Error usually happened when getting syncrepl connection while writing new objects. After one failure, new slapd process seemed to terminate immediately when receiving syncrepl connection from other node.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #2 from bohdan.kmit@kiteworks.com --- Verification of attachment 1212.
Build under test: 2.6.15 with attachment 1212 applied, no other source changes. Topology as in the original report: three providers in a multi-provider mesh, plus three delta-syncrepl consumers reading the accesslog, back-mdb, olcAccessLogOps: writes, olcAccessLogSuccess: TRUE, ~25-30 writes/s of live traffic, ~2.08M entries.
1. Controlled comparison, same host, same load profile
Load: 8 MODIFY streams plus a stream of ADDs of existing entries (returning entryAlreadyExists), and 12 concurrent search streams over the same subtree.
unpatched 2.6.15 10 SIGSEGVs in 30 minutes, first within 30 seconds patched 0 SIGSEGVs in 30 minutes, at a higher search rate
Peers carrying the same replicated writes but with no local search traffic did not fault in either run, consistent with the unlocked path being reachable only by non-write operations.
2. Rollout to the full deployment
All six instances were moved to the patched build. Crash cadence before the change, taken from coredump timestamps on each host:
consumer 0 131 cores mean interval 58 min consumer 1 121 cores mean interval 62 min consumer 2 127 cores mean interval 59 min provider 0 79 cores mean interval 91 min provider 1 1 core provider 2 0 cores
After the change, measured over the first four hours: 621 consumer instance-minutes and 712 provider instance-minutes with zero coredumps and no abnormal slapd exits. At the previous rate that window predicted approximately 13 crashes; the probability of observing none by chance is on the order of 1e-6.
3. Additional evidence for the accesslog attribution
One core from the unpatched build contained no allocator frame and instead aborted in an assertion, which locates a freed allocation that belongs to the accesslog entry itself:
#0 abort #1 __assert_perror_fail #2 entry_schema_check schema_check.c assert(a->a_vals[0].bv_val != NULL) #3 mdb_add add.c #6 accesslog_response accesslog.c #10 mdb_modify modify.c #13 syncrepl_message_to_op syncrepl.c
The entry was the log entry being written for a MODIFY received over syncrepl. The failing attribute was reqSession, a_numvals = 1, with a_vals[0] = { bv_len = <heap pointer>, bv_val = NULL } - the freed-chunk layout, a free-list link in the first word and the second word cleared. reqSession is merged with attr_merge_one(e, ad_reqSession, &rdn, NULL), so the value array is a plain heap allocation; the operation slab bounds were read from the core and the address lies outside them, confirming heap rather than slab memory. So an allocation made by the accesslog overlay was released while still referenced.
4. Note on a related report
The coredump signature described in ITS#10591 https://bugs.openldap.org/show_bug.cgi?id=10591 (unlinked syncprov modtarget nodes) has also not recurred since the patch. In that report 82 of 89 cores aborted inside an allocator, i.e. the heap was already damaged before the fault; the AVL nodes observed holding freed memory are best explained as downstream of the free described here rather than as an independent lifetime defect. That report should be treated as superseded by this one.
https://bugs.openldap.org/show_bug.cgi?id=10597
bohdan.kmit@kiteworks.com changed:
What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.openldap.org/s | |how_bug.cgi?id=10591
https://bugs.openldap.org/show_bug.cgi?id=10597
bohdan.kmit@kiteworks.com changed:
What |Removed |Added ---------------------------------------------------------------------------- See Also| |https://bugs.openldap.org/s | |how_bug.cgi?id=10482
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #3 from Geert Hendrickx geert@hendrickx.be --- We observed the same crashes after upgrading two 4-way delta-syncrepl setups from 2.6.13-3 to 2.6.15-1 packages from the Symas repo (on RHEL 8).
free(): invalid pointer double free or corruption (out) malloc(): unaligned tcache chunk detected malloc(): unaligned fastbin chunk detected munmap_chunk(): invalid pointer
Rolled back to 2.6.13 now.
https://bugs.openldap.org/show_bug.cgi?id=10597
Howard Chu hyc@openldap.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Assignee|bugs@openldap.org |hyc@openldap.org Ever confirmed|0 |1 Target Milestone|--- |2.6.16 Status|UNCONFIRMED |IN_PROGRESS Keywords|needs_review |
--- Comment #4 from Howard Chu hyc@openldap.org --- Fixed in https://git.openldap.org/openldap/openldap/-/merge_requests/923
https://bugs.openldap.org/show_bug.cgi?id=10597
Bohdan Kmit bohdan.kmit@kiteworks.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|IN_PROGRESS |RESOLVED Resolution|--- |FIXED
--- Comment #5 from Bohdan Kmit bohdan.kmit@kiteworks.com --- Thank you — the per-operation lmodinfo is a better fix than attachment 1212.
Withdrawing attachment 1212 as superseded.
One question: the milestone is 2.6.16 and the commit is currently on master only. Is a backport to the 2.6 branch planned? We are carrying the interim patch here until a 2.6 release contains the proper fix.
https://bugs.openldap.org/show_bug.cgi?id=10597
Quanah Gibson-Mount quanah@openldap.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Resolution|FIXED |TEST
--- Comment #6 from Quanah Gibson-Mount quanah@openldap.org --- head:
• 1d1db868 by Howard Chu at 2026-09-22T15:49:40+00:00 ITS#10597 slapo-accesslog: don't store per-op info in global state
Never belonged there. Also fix redundant nop checks.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #7 from Quanah Gibson-Mount quanah@openldap.org --- RE26:
c0b77e08 by Howard Chu at 2026-10-01T20:07:46+00:00
ITS#10597 slapo-accesslog: don't store per-op info in global state
Never belonged there. Also fix redundant nop checks.
RE27:
1c19a6fe by Howard Chu at 2026-10-01T20:07:04+00:00
ITS#10597 slapo-accesslog: don't store per-op info in global state
Never belonged there. Also fix redundant nop checks.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #8 from Shawn McKinney smckinney@symas.com --- Created attachment 1228 --> https://bugs.openldap.org/attachment.cgi?id=1228&action=edit backtrace attached
slapd abends on startup when autogroup + accesslog are enabled.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #9 from Quanah Gibson-Mount quanah@openldap.org --- head:
4701b8cb by Ondřej Kuzník at 2026-10-15T11:16:28+01:00
ITS#10597 slapo-accesslog: fix prev commit
RE27:
0c8d191f by Ondřej Kuzník at 2026-10-15T17:33:46+00:00
ITS#10597 slapo-accesslog: fix prev commit
RE26:
61a78c25 by Ondřej Kuzník at 2026-10-15T17:33:54+00:00
ITS#10597 slapo-accesslog: fix prev commit
https://bugs.openldap.org/show_bug.cgi?id=10597
Quanah Gibson-Mount quanah@openldap.org changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |VERIFIED Resolution|TEST |FIXED
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #10 from jukka.karvonen@helsinki.fi --- After updating from 2.6.13 to 2.6.16, where this was marked fixed, we still get "free(): invalid pointer" immediately after syncrepl starts. Downgrading back to 2.6.13 fixes this.
Using Symas packages (RHEL 9), two servers in mirrormode. Crash happens even when there are no changes to data.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #11 from Howard Chu hyc@openldap.org --- Please provide stack traces and/or valgrind output.
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #12 from jukka.karvonen@helsinki.fi --- Created attachment 1244 --> https://bugs.openldap.org/attachment.cgi?id=1244&action=edit backtrace and debug log
https://bugs.openldap.org/show_bug.cgi?id=10597
--- Comment #13 from Howard Chu hyc@openldap.org --- (In reply to jukka.karvonen from comment #12)
Created attachment 1244 [details] backtrace and debug log
I think we should move this to a new ticket. Also, we will need a minimal config and steps to reproduce this since we're not seeing the problem in our own testing.