mirror of https://github.com/OpenIdentityPlatform/OpenDJ.git

Valery Kharseko
23 hours ago c4d91fab9e005179803a3ab978e8f2896a5a5b16
[#1208] Restart a directory server during the load of the replication convergence run, in rows of its own (#1233)

Part of #1208: the first disturbance, a directory server restarted
during the load, and what every later one needs. The others (a
replication server killed or stopped, failover, scale in and out) follow
one PR at a time; this one does not close the issue.

## What it does

- **A disturbance per run** (`run.sh`, `lib.sh`): `DISTURBANCE=<name>`
sources `disturb-<name>.sh` next to the run, which names the `DISTURBED`
server and defines `disturb`, which takes the topology down in one way
`DISTURB_AT` seconds into the load (a third of it by default) and
returns once the server serves again, and `settle`, which `run.sh` calls
after the load, before the wait for convergence (`DISTURB_TIMEOUT`, 900
s, for each). `none`, the default, is the base run as before. A
disturbed run takes 900 s of load by default, as its CI rows do; the 120
s of the base run would leave no load after a restart. An unknown name
or a `DISTURB_AT` outside the load ends the run with 2 before anything
starts. The convergence time still counts from the end of the load
(`wait_converged [<start>]`).
- **`restart-ds`** (`disturb-restart-ds.sh`): `docker restart -t 120` of
the second directory server - the default 10 s would kill a server that
stops under load, which is another disturbance - then the wait until the
server logs that it started (msgID 135) after the restart
(`started_since`, `docker logs --since`). Not until its container is
healthy again: the probe of the health check is a JVM of its own and
does not get through its 30 s on a loaded runner (below). `settle` waits
for its join, which the image runs on every start, to end, as
`topology_up` waits for it. In `combined` its replication server
restarts with it.
- **Load in segments** (`load.sh`): the clients of the restarted server
get `--maxDuration DISTURB_AT` and end on their own before the restart,
so that it cuts none of their operations off: one that already had its
CSN would read as a lost change. Once the server serves again, a second
segment of clients takes the rest of the load. It adds entries under a
uid prefix of its own (the 100 newest of the first segment are still
there) and writes values that start with its own name (`cv-d1-2-…`): the
rate tools are seeded alike, and the second segment would otherwise
write the values of the first again, in the same order. `check_client`
checks each client against the seconds it was to run; a server that
serves again too late to take 30 s of load fails the run.
- **Changelogs** (`changelog-gaps.py`, docstring only): a restart leaves
no gap of its own, so the check reads the changes of a restarted server
as it reads the others, and a gap around the restart is a lost change,
the kind #1195 lost. A directory server that stops numbers its
`ReplicaOfflineMsg` like a change, but the message does not enter the
`ServerState` of the replica
(`ReplicaOfflineMsg.contributesToDomainState()` is false), from which
`CSNGenerator` numbers again on the start: the first change after the
restart takes the sequence number of the message again, at a later time.
#1192 wrote the opposite into the docstring - that a restart would read
as a lost change - and that was wrong: in run 39834888428 the changes of
the restarted `cv-d1` were numbered 1 to 139792 without a gap.
- **Errors logs** (`assert-converged.sh`): a server that starts on a
loaded runner fails handshakes, the other end giving up first, and
connects elsewhere a few seconds later. So `disturb` opens a window over
the errors log of every server before the restart and closes it 10 s
after the restarted server serves again (`window_open`, `window_close`:
line counts, as `mark_logs` takes them). The 10 s cover a handshake the
start began and a peer's wait for the domain lock, of up to 8 s, after
which it logs 145. `replication_errors` expects such a handshake in a
window: msgID 178 or 179 at ERROR (a directory server or a replication
server that disconnected in the handshake, logged by the replication
server it connected to), 145 at ERROR (a replication server whose
connection crossed one the other way and lost the domain lock to it,
which `lockDomainWithTimeout` does on purpose), or
`SSLHandshakeException(Remote host terminated the handshake)` at WARNING
(a peer that closed the handshake once its read timed out). 145 is a
warning by its descriptor, and 178 and 179 are logged at WARNING by the
other end: `abortStart` logs them all at ERROR, which #1241 is about. A
window expects them on any server, not only on the connections of the
restarted one: 178 and 179 name servers by id alone. Those go to
`logs/<node>.expected` and to the summary; outside a window, and
anything else inside one, they fail the run as before. An errors log
that cannot be read stops the run: `errors_lines` reads it with a
redirect, where `cat … | wc -l` counted 0 lines and exited 0, and
`window_open` took that for a window from the first line.
- **Self-tests** of what a green row does not show: nothing a window
expects is logged outside it there, a base row has no window, and a row
turns red on the order of `disturb` only when a handshake record lands
where the order moved. `docker-convergence` runs both in every row,
before it downloads the image.
- `selftest-replication-errors.sh`: `replication_errors` on 20 synthetic
errors logs, through a `docker` stub, so that `mark_logs`,
`window_open`, `window_close` and `since_mark` read them as they read a
container's.
- `selftest-disturb-restart-ds.sh`: `disturb` and `settle` against stubs
that record their calls and move the clock. The window opens before the
restart and closes 10 s after the server serves again, and
`disturbances.txt` ends the restart when the server served, not after
the grace.
- **Summary** (`collect.sh`): a row with what was disturbed, when, and
how long it took to serve again (`disturbances.txt`), or that the
disturbance did not complete, or did not start because the run ended
before the load; the handshakes a window expected.

## CI

`docker-convergence` gets the matrix axis `disturbance: [none,
restart-ds]`, four rows, each on a runner of its own:

| row | load | artifact |
|---|---|---|
| `rs534, none` | 1800 s | `convergence-rs534` (as before) |
| `combined, none` | 1800 s | `convergence-combined` (as before) |
| `rs534, restart-ds` | 900 s | `convergence-rs534-restart-ds` |
| `combined, restart-ds` | 900 s | `convergence-combined-restart-ds` |

A disturbed row runs half the load of a base one: what it is after
happens around the disturbance, and it holds one of the runners the
organization shares. Each row runs the two self-tests first, in seconds
and without Docker. A red row of either kind turns the Build run red and
skips the deploy of a push to master, as a base row does. The job names
change (`docker-convergence (rs534, none)` and so on); master has no
required status checks. The comment of the job that `rs534` and
`combined` fail until #1206, #1215 and #1195 are fixed goes: all three
are, and both rows were green on the last three Build runs of master.

## Testing

CI of the fourth round, run
[40544021845](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/40544021845)
(at ead0e02): every job green, 24 of 24.

| row | restart until serving | second segment | converged after the
load | result |
|---|---|---|---|---|
| `rs534, restart-ds` | 131 s | 453 s | 260 s | green, no record
expected |
| `combined, restart-ds` | 225 s | 350 s | 884 s | green, one record
expected: 178 on `cv-c0`, 31 s before the window closed |

Neither restart lost a change: `ldifdiff`, `verify-index` and the
changelogs were green, the changes of each restarted server without a
gap, as in every restart-ds row of the rounds before that got to the
checks. In the restart-ds rows of rounds 2 to 4 only the restarted
directory server reconnected (`reconnections.txt`).

The rounds before:

- **Round 5**, run
[40653842203](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/40653842203)
(at 53444f2): cancelled by the push of the sixth round before the
convergence rows ran.
- **Round 3**, run
[40463887505](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/40463887505)
(at a1d1944): `combined, restart-ds` failed on 145 at ERROR on `cv-c2`,
within the window, on the connection of the restarted `cv-c1`. The
fourth round expects 145 within a window.
- **Round 2**, run
[39909337627](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/39909337627)
(at 249e520): both `restart-ds` rows failed on one record each, 119 at
WARNING on the restarted `cv-d1` in `rs534`, 178 at ERROR on `cv-c0` in
`combined`. The third round expects them within the window of a restart.
- **Round 1**, run
[39834888428](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/39834888428)
(at 0863114): `combined, restart-ds` waited for the health of the
restarted container, which a probe that did not get through its 30 s on
the loaded runner held back 7 minutes after the server served. The
second round waits for the start instead, and showed that a restart
leaves no gap in the changelog.
- The base rows were green in the runs of rounds 1 to 4.

Locally, rounds 5 and 6:

- `selftest-replication-errors.sh`: 20 of 20 with the awk of macOS and
with mawk (`debian:bookworm-slim`). Against 21 mutants of
`assert-converged.sh` it fails on 19:
- the window bounds dropped or off by one, the first line or the mark
off by one;
- 145 or 179 out of the list, the space after the msgID dropped, or the
msgID anchor loosened to `.*(145|178|179) `;
- the WARNING clause dropped, or widened in severity, in category or to
any `SSLHandshakeException`;
- `bad_certificate` out of the first filter, the loop over the windows
off, `window_close` writing the wrong count.

The two that survive widen the clause of 145/178/179 to any severity or
any category. No record that gets past the first filter tells them
apart: outside SYNC at ERROR it gets past only with
`SSLHandshakeException` or `bad_certificate` in it, which those messages
do not carry.
- `selftest-disturb-restart-ds.sh`: passes with the bash of macOS and
with bash 5 (`debian:bookworm-slim`), and fails on 14 mutants of
`disturb-restart-ds.sh`:
- the grace dropped, the window closed before it or not at all;
- the window opened after the restart, or the stamp of serving taken
after the grace;
- `-t 120` dropped;
- the start of the restart taken after it, or the wrong start handed to
`started_since`;
- another timeout, the first directory server restarted, the stamp in
seconds;
- `settle` waiting on another server or with another timeout.
- `disturb` against a stubbed `docker` (round 5): a 145 logged 5 s into
the grace goes to `.expected`.
- `errors_lines` against a `debian:bookworm-slim` container without the
errors log, in a shell with `set -eE -o pipefail` as `run.sh` runs them.
With `cat … | wc -l`, `mark_logs`, `window_open` and `window_close` went
on, `window_open` writing 0. With the redirect, each stopped the shell
with 2, and with a log of 3 lines there it counts 3.
- `summarize`: "not started" with no `LOAD_START_MS`, "not completed"
with one and no `disturbances.txt`, the restart with it, no row without
a disturbance.
- `lib.sh`: no `DISTURBANCE` gives 120 s of load,
`DISTURBANCE=restart-ds` 900 s with `DISTURB_AT=300`, and a `DURATION`
that is set wins.
- `bash -n` of every script; `build.yml` parses, with the matrix, the
`DURATION` expression, the artifact names as above and the self-tests as
the first step after the checkout.
- Not run end to end locally: the Docker VM here (4 CPU, 3.8 GB) brings
`rs534` up in no less than 2400 s, and `combined` stalls under the load
before the checks.

The branch is on master `cba3c0f461` again.
8 files modified
3 files added
482 ■■■■■ changed files
.github/scripts/replication/assert-converged.sh 64 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/changelog-gaps.py 15 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/collect.sh 19 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/disturb-restart-ds.sh 53 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/lib.sh 26 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/load.sh 89 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/monitor.sh 8 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/run.sh 15 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/selftest-disturb-restart-ds.sh 58 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/selftest-replication-errors.sh 108 ●●●●● patch | view | raw | blame | history
.github/workflows/build.yml 27 ●●●●● patch | view | raw | blame | history
.github/scripts/replication/assert-converged.sh
@@ -141,12 +141,18 @@
# The number of lines each server's errors log held once the topology was up: the joins log
# replication errors of their own while the servers come up one after the other, and only what
# follows is the run's
# follows is the run's. A log that cannot be read fails the run: a cat that fails in a pipe
# would count 0 lines and exit 0, and window_open would take that for a window from the first
# line, while a redirect that fails ends sh with 2
errors_lines() { # <node>
  docker exec $1 sh -c 'wc -l </opt/opendj/data/logs/errors'
}
mark_logs() {
  local n
  mkdir -p "$OUT/logs"
  for n in $ALL_NODES; do
    docker exec $n sh -c 'cat /opt/opendj/data/logs/errors | wc -l' >"$OUT/logs/$n.mark"
    errors_lines $n >"$OUT/logs/$n.mark"
  done
}
@@ -154,6 +160,57 @@
  docker exec $1 tail -n +$(($(cat "$OUT/logs/$1.mark") + 1)) /opt/opendj/data/logs/errors
}
# A disturbance window over the errors log of every server (#1208): window_open before the
# disturbance, window_close once the disturbed server serves again, a line "<lines before>
# <lines after>" in logs/<node>.windows
window_open() {
  local n
  for n in $ALL_NODES; do
    errors_lines $n >"$OUT/logs/$n.window"
  done
}
window_close() {
  local n lines
  for n in $ALL_NODES; do
    lines=$(errors_lines $n)
    echo "$(cat "$OUT/logs/$n.window") $lines" >>"$OUT/logs/$n.windows"
    rm "$OUT/logs/$n.window"
  done
}
# The replication errors <node> logged after mark_logs. A disturbance window expects the
# handshakes that a server starting on a loaded runner fails, the other end giving up first: a
# directory server (178) or a replication server (179) that disconnected in the handshake, both
# at ERROR on the replication server it connected to, a replication server whose connection
# crossed one the other way and lost the domain lock to it (145, a warning that abortStart logs
# at ERROR, as it does 178 and 179: #1241), and the SSLHandshakeException of a server whose peer
# closed the handshake once its read timed out. In run 39909337627 a restarted directory server
# timed out connecting (212) and its replication server logged 178, and a replication server
# logged 311 with SocketTimeoutException when the restarted server logged 119 with "Remote host
# terminated the handshake"; in run 40463887505 a replication server logged 145 on the
# connection of the restarted one. Those go to logs/<node>.expected; outside a window, and
# anything else inside one, they are errors. A window expects them on any server, not only on
# the connections of the disturbed one: 178 and 179 name the servers by id alone, and a server
# has one in each of its domains and another for its replication server. A handshake that fails
# is followed by a connection elsewhere, and a change it lost the checks of the data find
replication_errors() { # <node>
  local windows=
  [ ! -f "$OUT/logs/$1.windows" ] || windows=$(tr '\n' ' ' <"$OUT/logs/$1.windows")
  since_mark $1 | awk -v first=$(($(cat "$OUT/logs/$1.mark") + 1)) -v windows="$windows" \
                      -v expected="$OUT/logs/$1.expected" '
    BEGIN { n = split(windows, w, " ") }
    !/category=SYNC severity=ERROR|SSLHandshakeException|bad_certificate/ { next }
    {
      line = first + NR - 1
      if (/category=SYNC severity=ERROR msgID=(145|178|179) / \
          || /category=SYNC severity=WARNING .*SSLHandshakeException\(Remote host terminated the handshake\)/)
        for (i = 1; i < n; i += 2)
          if (line > w[i] + 0 && line <= w[i + 1] + 0) { print >expected; next }
      print
    }'
}
# How often each directory server connected to a replication server again after the topology
# came up, whatever made it: a switch the broker decided on (msgID 188, or 213 to spread the
# load), a replication server that closed the connection (63), a connection that broke. Each
@@ -218,10 +275,9 @@
    fi
  done
  for n in $ALL_NODES; do
    if ! lines=$(since_mark $n); then
    if ! lines=$(replication_errors $n); then
      echo "::error::the errors log of $n could not be read"; failed=1; continue
    fi
    lines=$(grep -E "category=SYNC severity=ERROR|SSLHandshakeException|bad_certificate" <<<"$lines" || true)
    [ -z "$lines" ] || { printf '%s\n' "$lines" >"$OUT/logs/$n.errors"; echo "::error::$n logged replication errors, see logs/$n.errors"; failed=1; }
  done
  assert_rs_mesh || failed=1
.github/scripts/replication/changelog-gaps.py
@@ -35,12 +35,15 @@
What it cannot tell. A change lost at either end of a replica's changes in the window - its
last ones, or its first ones when no earlier change of the replica is in the changelog - leaves
no gap between two changes that are there; the data of the other replicas shows such a change
unless a later change of another server overwrites it. And not every sequence number that no
record holds is a lost change: a directory server that goes offline (a restart, its domain
disabled) numbers its ReplicaOfflineMsg like a change, and the changelog keeps only the newest
of them, in the offline.state of the replica, not in a log file. The convergence run restarts
no server after the topology is up; a run that did would read each restart in the window as a
lost change.
unless a later change of another server overwrites it.
A restart leaves no gap of its own. A directory server that stops numbers its ReplicaOfflineMsg
like a change, and no log file holds the message - only the offline.state of the replica, the
newest one. But the message does not enter the ServerState of the replica
(ReplicaOfflineMsg.contributesToDomainState()), from whose newest change of its own the server
numbers again once it starts (CSNGenerator), so its first change after the restart takes the
sequence number of the message again, at a later time: the changes of the restarted server had
no gap in run 39834888428 (#1208). A gap around a restart is a lost change, the kind #1195 lost.
The file format is the one of FileReplicaDB: every log file is cut into blocks of 256 bytes,
and every block after the first starts with a 4-byte offset (BlockLogWriter); in between, a
.github/scripts/replication/collect.sh
@@ -56,6 +56,15 @@
    echo "| servers | $ALL_NODES |"
    echo "| load | $DURATION s on each directory server, at most $LOAD_MOD_RATE modifications and $LOAD_ADD_RATE adds or deletes a second |"
    echo "| seeded users | $SAMPLE_DATA |"
    if [ -s "$OUT/disturbances.txt" ]; then
      awk -v start="${LOAD_START_MS:-0}" '{ printf "| disturbance | %s of %s %d s into the load, serving again %d s later |\n",
                                            $4, $3, ($1 - start) / 1000, ($2 - $1) / 1000 }' "$OUT/disturbances.txt"
    elif [ "$DISTURBANCE" != none ] && [ -z "${LOAD_START_MS:-}" ]; then
      # run.sh sets LOAD_START_MS as the load starts
      echo "| disturbance | $DISTURBANCE at $DISTURB_AT s into the load, not started: the run ended before the load |"
    elif [ "$DISTURBANCE" != none ]; then
      echo "| disturbance | $DISTURBANCE at $DISTURB_AT s into the load, not completed |"
    fi
    echo "| converged | ${CONVERGED_IN:--} s after the load |"
    if [ -s "$OUT/samples.txt" ]; then
      awk '{ t[$1] = 1 } END { for (s in t) { n++; if (!min || s < min) min = s; if (s > max) max = s }
@@ -85,6 +94,16 @@
      done | grep . || echo "none"
      echo '```'
    fi
    if ls "$OUT"/logs/*.expected >/dev/null 2>&1; then
      echo
      echo "Handshakes failed while a disturbed server came back, which the disturbance expects (logs/*.expected):"
      echo
      echo '```'
      for f in "$OUT"/logs/*.expected; do
        sed "s/^/$(basename "$f" .expected): /" "$f"
      done
      echo '```'
    fi
    if ls "$OUT"/load/*.csv >/dev/null 2>&1; then
      echo
      echo "| client | average ops/s | intervals |"
.github/scripts/replication/disturb-restart-ds.sh
New file
@@ -0,0 +1,53 @@
#
#
# The contents of this file are subject to the terms of the Common Development and
# Distribution License (the License). You may not use this file except in compliance with the
# License.
#
# You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the
# specific language governing permission and limitations under the License.
#
# When distributing Covered Software, include this CDDL Header Notice in each file and include
# the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL
# Header, with the fields enclosed by brackets [] replaced by your own identifying
# information: "Portions copyright [year] [name of copyright owner]".
#
# Copyright 2026 3A Systems, LLC.
# The disturbance restart-ds of the replication convergence run (#1208), sourced by run.sh: a
# directory server restarts DISTURB_AT seconds into the load, as docker restart or a rolling
# update restarts it, while the others go on taking the load. run_load stops its clients
# before and starts others once it serves again. It is the second directory server, the one
# inject_divergence writes to: in rs534 it runs no replication server, in combined the one it
# runs restarts with it.
DISTURBED=$(echo $DS_NODES | cut -d' ' -f2)
# docker restart sends SIGTERM and kills the server once its timeout is over: 10 s by default,
# less than a server under load may need to stop, and a killed server is another disturbance.
# stop_all gives it 120 s as well. The restart goes to disturbances.txt for the summary, from
# the restart until the server serves again, and is a window of the errors logs: the handshakes
# its start fails on a loaded runner are expected there (replication_errors). The window closes
# 10 s after the server serves again: a handshake its start began can still fail then, and a
# peer logs 145 only once its wait for the domain lock, of up to 8 s, is over
# (ServerHandler.lockDomainWithTimeout). A handshake that fails later is an error again
disturb() {
  local from served
  echo "    [$SECONDS s] restarting $DISTURBED"
  window_open
  from=$(date +%s)
  docker restart -t 120 $DISTURBED >/dev/null
  wait_until $DISTURB_TIMEOUT "$DISTURBED serves again" started_since $DISTURBED $from
  served=$(date +%s)
  echo "    [$SECONDS s] $DISTURBED serves again"
  sleep 10
  window_close
  echo "$((from * 1000)) $((served * 1000)) $DISTURBED restart" >>"$OUT/disturbances.txt"
}
# After the load, before the wait for convergence: the join of the restarted server, which runs
# again on every start, has ended, as topology_up waits for it. Its container is not waited to
# be healthy again: the probe may not get through while the replicas catch up either
settle() {
  wait_until $DISTURB_TIMEOUT "the join of $DISTURBED ends" bootstrap_ended $DISTURBED
}
.github/scripts/replication/lib.sh
@@ -18,8 +18,17 @@
# setting comes from the environment, so that the same run goes in CI and on a laptop.
TOPOLOGY=${TOPOLOGY:-rs534}
# seconds of load
DURATION=${DURATION:-120}
# what disturbs the topology during the load (#1208): none, or the <name> of a disturb-<name>.sh
# next to this script, which names the DISTURBED server and defines disturb, run during the load,
# and settle, run after it
DISTURBANCE=${DISTURBANCE:-none}
# seconds of load. A disturbed run takes the load of its CI rows: a restarted server served
# again 131 to 225 s after the restart there, and the load has to go on after that
if [ "$DISTURBANCE" = none ]; then
  DURATION=${DURATION:-120}
else
  DURATION=${DURATION:-900}
fi
# the most modifications, and adds or deletes, per second the load sends to each directory
# server; a runner that cannot keep up sends fewer, which the summary shows
LOAD_MOD_RATE=${LOAD_MOD_RATE:-423}
@@ -38,6 +47,10 @@
QUIESCE_TIMEOUT=${QUIESCE_TIMEOUT:-900}
# 1: write to one replica only, which the run must report (a self-test of its checks)
INJECT_DIVERGENCE=${INJECT_DIVERGENCE:-0}
# seconds into the load at which the disturbance starts
DISTURB_AT=${DISTURB_AT:-$((DURATION / 3))}
# seconds a disturbed server is given to serve again, and its join to end after the load
DISTURB_TIMEOUT=${DISTURB_TIMEOUT:-900}
# where the summary, the samples, the exports, the differences and a failed run's state go: a
# directory that is new or empty
OUT=${OUT:-$PWD/replication-out}
@@ -128,6 +141,15 @@
  [ "$(docker inspect --format='{{.State.Health.Status}}' "$1")" = healthy ]
}
# The server of the container logged that it started (msgID 135, once its connection handlers
# listen) after the Unix time <seconds>: it serves. Not the health of the container: its probe,
# a JVM of its own, does not get through its 30 s on a runner under load - in run 39834888428 a
# restarted server served 7 minutes before its container was healthy again. No grep -q: it
# would cut docker logs off, and pipefail would take that for no match
started_since() { # <container> <seconds>
  docker logs --since "$2" "$1" 2>&1 | grep 'category=CORE severity=NOTICE msgID=135 ' >/dev/null
}
# The background join of the image goes on once the container reports itself healthy: it adds
# replication servers to the replication server lists while its peers register
# (repair_replication_servers in join.sh). Ended once no bootstrap script runs any more, as
.github/scripts/replication/load.sh
@@ -17,7 +17,8 @@
# The load of the replication convergence run (#1090), sourced by run.sh: every directory
# server is written to at once, for DURATION seconds, by rate tools that run in containers of
# the same image on the network of the topology. Only writes: a read sends nothing to the
# replication servers.
# replication servers. The server a disturbance takes down (#1208) is written to before it and
# after it, by clients of their own.
# <client> <tool> <argument>... : a container that runs one tool of the image against one server
start_client() {
@@ -31,19 +32,21 @@
# seconds between two lines of the output of a rate tool
STAT_INTERVAL=10
# The clients of one directory server for <seconds> of the load, a modrate and an addrate.
# Segment 1 starts with the load; a later one once a disturbance let the server serve again,
# and it adds entries of its own: the 100 newest of the segment before are still there.
# Plain LDAP: the run is after the changes the replication carries, and TLS between a client
# and its server only takes CPU from them. --noRebind: every client keeps its connections open
# and binds once, as an application does, rather than connecting and binding for every
# operation, which would cost more than the operation itself. --connectTimeout: the clients
# start at once next to the servers, and a runner that is short of CPU for a while accepts
# their connections late
run_load() {
  local n c failed
  mkdir -p "$OUT/load"
  for n in $DS_NODES; do
    # entries of its own on each server, so that the adds and deletes of two servers never meet
    # on one DN: a naming conflict is not what this load is after
    cat >"$OUT/load/addrate-$n.template" <<TEMPLATE
start_clients() { # <node> <segment> <seconds>
  local n=$1 name=$1 c
  [ "$2" -eq 1 ] || name=$1-$2
  # entries of its own on each server, so that the adds and deletes of two servers never meet
  # on one DN: a naming conflict is not what this load is after
  cat >"$OUT/load/addrate-$name.template" <<TEMPLATE
define suffix=$BASE_DN
branch: ou=People,[suffix]
@@ -55,30 +58,56 @@
objectClass: person
objectClass: organizationalPerson
objectClass: inetOrgPerson
uid: addrate-$n.<sequential:0>
uid: addrate-$name.<sequential:0>
cn: AddRate {uid}
sn: AddRate
userPassword: password
TEMPLATE
    chmod 644 "$OUT/load/addrate-$n.template"
    # the same entries from every server at once: concurrent modifications of one attribute of
    # one entry, applied in the order of their change numbers on every replica (#139). The value
    # starts with the name of the server: rand and randstr are seeded alike in every client, so
    # all of them write the same values in the same order, and a change lost on its way would
    # hide behind the same value written later by another server; the name also tells which
    # server a value in a diff or a changelog comes from (#1206)
    start_client load-mod-$n modrate --hostname $n --port 1389 --connectTimeout 120000 --noRebind \
      --bindDN "cn=Directory Manager" --bindPassword "$ROOT_PASSWORD" --maxDuration "$DURATION" \
      --statInterval $STAT_INTERVAL --numConnections 8 --numThreads 1 --scriptFriendly --targetThroughput "$LOAD_MOD_RATE" \
      --targetDN "uid=user.%d,ou=People,$BASE_DN" --argument "rand(0,$((SAMPLE_DATA - 1)))" \
      --argument "randstr(16)" "description:$n-%2\$s"
    # adds, and deletes of the oldest once 100 of them are there: a slow runner gets to the deletes as well
    start_client load-add-$n addrate --hostname $n --port 1389 --connectTimeout 120000 --noRebind \
      --bindDN "cn=Directory Manager" --bindPassword "$ROOT_PASSWORD" --maxDuration "$DURATION" \
      --statInterval $STAT_INTERVAL --numConnections 8 --numThreads 1 --scriptFriendly --targetThroughput "$LOAD_ADD_RATE" \
      --deleteMode fifo --deleteSizeThreshold 100 "/load/addrate-$n.template"
    CLIENTS="$CLIENTS load-mod-$n load-add-$n"
  chmod 644 "$OUT/load/addrate-$name.template"
  # the same entries from every server at once: concurrent modifications of one attribute of
  # one entry, applied in the order of their change numbers on every replica (#139). The value
  # starts with the name of the server, and of the segment after the first (cv-d1-2): rand and
  # randstr are seeded alike in every client, so all of them write the same values in the same
  # order - the two segments of one server as well - and a change lost on its way would hide
  # behind the same value written later by another client; the name also tells which server,
  # and which segment, a value in a diff or a changelog comes from (#1206)
  start_client load-mod-$name modrate --hostname $n --port 1389 --connectTimeout 120000 --noRebind \
    --bindDN "cn=Directory Manager" --bindPassword "$ROOT_PASSWORD" --maxDuration "$3" \
    --statInterval $STAT_INTERVAL --numConnections 8 --numThreads 1 --scriptFriendly --targetThroughput "$LOAD_MOD_RATE" \
    --targetDN "uid=user.%d,ou=People,$BASE_DN" --argument "rand(0,$((SAMPLE_DATA - 1)))" \
    --argument "randstr(16)" "description:$name-%2\$s"
  # adds, and deletes of the oldest once 100 of them are there: a slow runner gets to the deletes as well
  start_client load-add-$name addrate --hostname $n --port 1389 --connectTimeout 120000 --noRebind \
    --bindDN "cn=Directory Manager" --bindPassword "$ROOT_PASSWORD" --maxDuration "$3" \
    --statInterval $STAT_INTERVAL --numConnections 8 --numThreads 1 --scriptFriendly --targetThroughput "$LOAD_ADD_RATE" \
    --deleteMode fifo --deleteSizeThreshold 100 "/load/addrate-$name.template"
  # check_client reads how long each client was to run
  for c in load-mod-$name load-add-$name; do
    echo "$3" >"$OUT/load/$c.seconds"
  done
  CLIENTS="$CLIENTS load-mod-$name load-add-$name"
}
run_load() {
  local n c failed start=$SECONDS left
  mkdir -p "$OUT/load"
  for n in $DS_NODES; do
    if [ "$n" = "${DISTURBED:-}" ]; then
      start_clients $n 1 "$DISTURB_AT"
    else
      start_clients $n 1 "$DURATION"
    fi
  done
  if [ "$DISTURBANCE" != none ]; then
    # the clients of the disturbed server end on their own before the disturbance, which then
    # cuts none of their operations off: one that had its CSN would read as a lost change
    docker wait load-mod-$DISTURBED load-add-$DISTURBED >/dev/null
    disturb
    left=$((DURATION - (SECONDS - start)))
    [ "$left" -ge $((3 * STAT_INTERVAL)) ] \
      || fail "$DISTURBED served again $((SECONDS - start)) s into the load of $DURATION s, too late to take load again"
    start_clients $DISTURBED 2 $left
  fi
  for c in $CLIENTS; do
    docker wait $c >/dev/null
  done
@@ -100,10 +129,10 @@
# too, leaves out the line of its last interval - the one that would count the error - and
# prints the error to its error output, which goes to the same file. So the client has to have
# done work, every interval of its CSV output has to report no errors (the "Errors/second"
# column), the output has to cover the load - a line every STAT_INTERVAL seconds, of which the
# last may be missing - and hold nothing but the CSV
# column), the output has to cover the seconds the client was to run - a line every
# STAT_INTERVAL seconds, of which the last may be missing - and hold nothing but the CSV
check_client() { # <client>
  awk -F, -v c=$1 -v exit_state="$(cat "$OUT/load/$1.exit")" -v want=$((DURATION / STAT_INTERVAL - 1)) '
  awk -F, -v c=$1 -v exit_state="$(cat "$OUT/load/$1.exit")" -v want=$(($(cat "$OUT/load/$1.seconds") / STAT_INTERVAL - 1)) '
    /^Time \(seconds\)/ { for (i = 1; i <= NF; i++) { if ($i == "Recent throughput (ops/second)") t = i; if ($i == "Errors/second") e = i }; next }
    t && $1 ~ /^[0-9.]+$/ { rows++; ops += $t; errors += $e; last = $0; next }
    NF { other++ }
.github/scripts/replication/monitor.sh
@@ -71,10 +71,10 @@
MONITORING_PERIOD=60
# Three converged samples in a row, the last one started more than a monitoring period (and
# the publisher's 5 s latch) after the first ended. Sets CONVERGED_IN to the seconds until the
# first of them
wait_converged() {
  local start=$SECONDS hits=0 first= last=
# the publisher's 5 s latch) after the first ended. Sets CONVERGED_IN to the seconds from
# <start> (a value of SECONDS, now by default) until the first of them
wait_converged() { # [<start>]
  local start=${1:-$SECONDS} hits=0 first= last=
  until [ $hits -ge 3 ] && [ $((last - first)) -gt $((MONITORING_PERIOD + 5)) ]; do
    last=$SECONDS
    if converged_once; then hits=$((hits + 1)); first=${first:-$SECONDS}; else hits=0; first=; fi
.github/scripts/replication/run.sh
@@ -33,6 +33,13 @@
. "$HERE/load.sh"
. "$HERE/assert-converged.sh"
. "$HERE/collect.sh"
if [ "$DISTURBANCE" != none ]; then
  [ -f "$HERE/disturb-$DISTURBANCE.sh" ] \
    || { echo "unknown DISTURBANCE $DISTURBANCE: none, or the <name> of a disturb-<name>.sh in $HERE" >&2; exit 2; }
  [ "$DISTURB_AT" -gt 0 ] && [ "$DISTURB_AT" -lt "$DURATION" ] \
    || { echo "DISTURB_AT=$DISTURB_AT is not within the load of $DURATION s" >&2; exit 2; }
  . "$HERE/disturb-$DISTURBANCE.sh"
fi
# the files of an earlier run would mix into this one's: the samples are appended to, and the
# summary of a run that failed early would show what a run that got further left
@@ -67,7 +74,7 @@
mark_logs
record_server_ids
phase "load ($DURATION s)"
phase "load ($DURATION s${DISTURBED:+, $DISTURBANCE of $DISTURBED at $DISTURB_AT s})"
# the changes of the load: assert_changelogs looks for gaps among the changes made in between
LOAD_START_MS=$(($(date +%s) * 1000))
sampler_start
@@ -75,7 +82,11 @@
sampler_stop
phase "converge"
wait_converged
load_end=$SECONDS
# a disturbed server is left as topology_up leaves every server, and the wait for convergence
# still counts from the end of the load
[ "$DISTURBANCE" = none ] || settle
wait_converged $load_end
echo "converged in $CONVERGED_IN s"
LOAD_END_MS=$(($(date +%s) * 1000))
.github/scripts/replication/selftest-disturb-restart-ds.sh
New file
@@ -0,0 +1,58 @@
#!/usr/bin/env bash
#
#
# The contents of this file are subject to the terms of the Common Development and
# Distribution License (the License). You may not use this file except in compliance with the
# License.
#
# You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the
# specific language governing permission and limitations under the License.
#
# When distributing Covered Software, include this CDDL Header Notice in each file and include
# the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL
# Header, with the fields enclosed by brackets [] replaced by your own identifying
# information: "Portions copyright [year] [name of copyright owner]".
#
# Copyright 2026 3A Systems, LLC.
# A self-test of the disturbance restart-ds of the replication convergence run (#1208), with no
# topology: what disturb and settle call, in which order, and what disturb writes to
# disturbances.txt. The window of the errors logs opens before the restart and closes 10 s after
# the server serves again, and the restart ends when the server served, not after the grace. A
# restart-ds row shows neither, unless a handshake record lands where the order moved. docker,
# wait_until, window_open, window_close, date and sleep are stubs that record their calls, and
# the clock moves in the stubs alone: the restart takes 5 s, the wait for the server 30 s.
#
# Usage: selftest-disturb-restart-ds.sh
set -eE -o pipefail
HERE=$(cd "$(dirname "$0")" && pwd)
DS_NODES="d0 d1" DISTURB_TIMEOUT=900
OUT=$(mktemp -d)
trap 'rm -rf "$OUT"' EXIT
. "$HERE/disturb-restart-ds.sh"
now=100 calls=
date() { echo $now; }
sleep() { calls="$calls sleep $1"; now=$((now + $1)); }
docker() { calls="$calls docker $*"; now=$((now + 5)); }
wait_until() { calls="$calls wait_until $*"; now=$((now + 30)); }
window_open() { calls="$calls window_open"; }
window_close() { calls="$calls window_close"; }
failed=0
check() { # <what> <got> <want>
  [ "$2" = "$3" ] || { echo "::error::$1:$2, not$3"; failed=$((failed + 1)); }
}
disturb >/dev/null
check "disturb called" "$calls" \
  " window_open docker restart -t 120 d1 wait_until 900 d1 serves again started_since d1 100 sleep 10 window_close"
check "disturbances.txt holds" " $(cat "$OUT/disturbances.txt")" " 100000 135000 d1 restart"
calls=
settle
check "settle called" "$calls" " wait_until 900 the join of d1 ends bootstrap_ended d1"
echo "disturb-restart-ds: $((3 - failed)) checks passed, $failed failed"
[ "$failed" -eq 0 ]
.github/scripts/replication/selftest-replication-errors.sh
New file
@@ -0,0 +1,108 @@
#!/usr/bin/env bash
#
#
# The contents of this file are subject to the terms of the Common Development and
# Distribution License (the License). You may not use this file except in compliance with the
# License.
#
# You can obtain a copy of the License at legal/CDDLv1.0.txt. See the License for the
# specific language governing permission and limitations under the License.
#
# When distributing Covered Software, include this CDDL Header Notice in each file and include
# the License file at legal/CDDLv1.0.txt. If applicable, add the following below the CDDL
# Header, with the fields enclosed by brackets [] replaced by your own identifying
# information: "Portions copyright [year] [name of copyright owner]".
#
# Copyright 2026 3A Systems, LLC.
# A self-test of the errors log check of the replication convergence run (#1208), with no
# topology: which records replication_errors takes for errors and which ones a disturbance
# window expects. A green row does not show it - nothing a disturbance expects is logged outside
# its window there, and the base rows have no window - so docker-convergence runs this first.
# docker is a stub that reads a local errors log: mark_logs, window_open and window_close count
# its lines, since_mark reads it, as they do in a container.
#
# Usage: selftest-replication-errors.sh
set -eE -o pipefail
HERE=$(cd "$(dirname "$0")" && pwd)
. "$HERE/assert-converged.sh"
ALL_NODES=n0
OUT=$(mktemp -d)
trap 'rm -rf "$OUT"' EXIT
LOG=$OUT/errors
docker() { # exec <node> sh -c <the line count of the errors log> | exec <node> tail -n +<first> <errors log>
  case "$1 $3" in
    "exec sh") wc -l <"$LOG" | tr -d ' ' ;;
    "exec tail") tail -n "$5" "$LOG" ;;
    *) echo "unexpected docker $*" >&2; return 1 ;;
  esac
}
E178='[t] category=SYNC severity=ERROR msgID=178 msg=Directory server 32536 was attempting to connect to replication server 31531 but has disconnected in handshake phase'
E179='[t] category=SYNC severity=ERROR msgID=179 msg=Replication server 1 was attempting to connect to replication server 2 but has disconnected in handshake phase'
E145='[t] category=SYNC severity=ERROR msgID=145 msg=Timed out while trying to acquire the domain lock for domain "dc=example,dc=com". The connection attempt from replication server RS(29892) at cv-c1.convergence/172.18.0.3:52382 to this replication server RS(27915) will be aborted. This is probably benign and a result of a simultaneous cross connection attempt'
W119='[t] category=SYNC severity=WARNING msgID=119 msg=Directory server DS(24329) encountered an unexpected error while connecting to replication server cv-r0:8989 for domain "cn=schema": SSLHandshakeException(Remote host terminated the handshake)'
E119=${W119/severity=WARNING/severity=ERROR}
W119CORE=${W119/category=SYNC/category=CORE}
WBAD='[t] category=SYNC severity=WARNING msgID=119 msg=Directory server DS(1) encountered an unexpected error while connecting: SSLHandshakeException(Received fatal alert: bad_certificate)'
WBADCORE='[t] category=CORE severity=WARNING msgID=1 msg=SSLException(Received fatal alert: bad_certificate)'
E106='[t] category=SYNC severity=ERROR msgID=106 msg=another replication error'
E1450='[t] category=SYNC severity=ERROR msgID=1450 msg=an id that starts like one a window expects'
E45='[t] category=SYNC severity=ERROR msgID=45 msg=an id that ends like one a window expects'
E106ID='[t] category=SYNC severity=ERROR msgID=106 msg=Replication server 32179 lost its connection'
N62='[t] category=SYNC severity=NOTICE msgID=62 msg=Directory server DS(1) has connected'
CORE178='[t] category=CORE severity=ERROR msgID=178 msg=not a replication error'
passed=0 failed=0
# case <name> <errors> <expected> <record, [ or ]>...: the errors log holds two errors before
# mark_logs, which are not the run's, then the records given; [ opens a window and ] closes it.
# The number of records replication_errors prints, and of those it sends to logs/n0.expected
case_() {
  local name=$1 want_errors=$2 want_expected=$3 record errors expected
  shift 3
  rm -rf "$OUT/logs"
  printf '%s\n' "$E178" "$E106" >"$LOG"
  mark_logs
  for record; do
    case $record in
      '[') window_open ;;
      ']') window_close ;;
      *) echo "$record" >>"$LOG" ;;
    esac
  done
  errors=$(replication_errors n0 | grep -c . || true)
  expected=$( [ ! -f "$OUT/logs/n0.expected" ] || grep -c . "$OUT/logs/n0.expected" || true)
  if [ "$errors" = "$want_errors" ] && [ "${expected:-0}" = "$want_expected" ]; then
    passed=$((passed + 1))
  else
    failed=$((failed + 1))
    echo "::error::$name: $errors errors and ${expected:-0} expected, not $want_errors and $want_expected"
  fi
}
case_ 178-outside-a-window       1 0     "$E178"
case_ 145-outside-a-window       1 0     "$E145"
case_ 178-in-a-window            0 1 '[' "$E178" ']'
case_ 179-in-a-window            0 1 '[' "$E179" ']'
case_ 145-in-a-window            0 1 '[' "$E145" ']'
case_ terminated-handshake       0 1 '[' "$W119" ']'
case_ terminated-handshake-error 1 0 '[' "$E119" ']'
case_ terminated-elsewhere       1 0 '[' "$W119CORE" ']'
case_ bad-certificate            1 0 '[' "$WBAD" ']'
case_ bad-certificate-elsewhere  1 0 '[' "$WBADCORE" ']'
case_ another-error-in-a-window  1 0 '[' "$E106" ']'
case_ ids-like-expected-ones     2 0 '[' "$E1450" "$E45" ']'
case_ an-id-in-the-message       1 0 '[' "$E106ID" ']'
case_ another-category           0 0 '[' "$CORE178" ']'
case_ a-notice                   0 0     "$N62"
case_ before-a-window            1 1     "$E178" '[' "$E178" ']'
case_ after-a-window             1 1 '[' "$N62" "$E178" ']' "$E178"
case_ two-windows                0 2 '[' "$E178" ']' "$N62" '[' "$E179" ']'
case_ between-two-windows        1 2 '[' "$E178" ']' "$E179" '[' "$E178" ']'
case_ mixed                      2 2 '[' "$E178" "$E106" "$W119" "$WBAD" "$N62" ']'
echo "replication_errors: $passed cases passed, $failed failed"
[ "$failed" -eq 0 ]
.github/workflows/build.yml
@@ -1124,11 +1124,11 @@
  docker-convergence:
    # #1090: writes to every directory server of a replication topology at once, then checks
    # that the replicas hold the same data; next to docker-test, on the image of build-docker
    # that the replicas hold the same data; next to docker-test, on the image of build-docker.
    # Each row but the base one disturbs the topology during the load in one way (#1208)
    needs: build-docker
    # a red row turns the Build run red, and deploy.yml then skips the snapshot deploy and the
    # publishing of the docs of a push to master: rs534 fails until #1206 is fixed and can fail
    # until #1215 is, combined can fail until #1195 is
    # publishing of the docs of a push to master
    runs-on: 'ubuntu-latest'
    permissions:
      contents: read
@@ -1136,11 +1136,21 @@
      fail-fast: false
      matrix:
        topology: [rs534, combined]
        # none: the base run; restart-ds: a directory server restarts during the load
        disturbance: [none, restart-ds]
    steps:
      - uses: actions/checkout@3d3c42e5aac5ba805825da76410c181273ba90b1 # v7.0.1
        with:
          sparse-checkout: |
            .github/scripts/replication
      # what a green row does not show: what a disturbance window of the errors log check
      # expects - nothing it expects is logged outside the window there, and a base row has
      # none - and where restart-ds opens and closes the window
      - name: Self-tests of the errors log check and of restart-ds
        shell: bash
        run: |
          .github/scripts/replication/selftest-replication-errors.sh
          .github/scripts/replication/selftest-disturb-restart-ds.sh
      - name: Download the image
        uses: actions/download-artifact@9000827ccba6bdab643e8b6fd33ac0654aef8333 # v8.0.2
        with:
@@ -1149,11 +1159,15 @@
      - name: Load the image
        shell: bash
        run: docker load -i "$RUNNER_TEMP/image/image.tar"
      - name: Convergence run (${{ matrix.topology }})
      - name: Convergence run (${{ matrix.topology }}, ${{ matrix.disturbance }})
        shell: bash
        env:
          TOPOLOGY: ${{ matrix.topology }}
          DURATION: "1800"
          DISTURBANCE: ${{ matrix.disturbance }}
          # a disturbed row runs half the load of the base one: what it is after happens around
          # the disturbance, a third of the way in, and for as long as it runs it holds one of
          # the runners the whole organization shares
          DURATION: ${{ matrix.disturbance == 'none' && '1800' || '900' }}
          # the replicas fall behind during the load and catch up after it: 900 s at 325 and 65
          # a second converged in 396 s (run 38944365728), 1800 s at 423 and 85 in 2489 s (run
          # 39043600905), the backlog growing faster than the load above the replay capacity; a
@@ -1166,7 +1180,8 @@
        if: always()
        uses: actions/upload-artifact@cf430e030ddbb5b0abf93d22962f4752f3646cd9 # v7.0.2
        with:
          name: convergence-${{ matrix.topology }}
          # the base rows keep the names they had before the disturbed ones came
          name: convergence-${{ matrix.topology }}${{ matrix.disturbance != 'none' && format('-{0}', matrix.disturbance) || '' }}
          path: ${{ runner.temp }}/replication-out
          if-no-files-found: warn
          retention-days: 5