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

Valery Kharseko
22 hours ago b76fa3619b91c597b2206552c34df618ca2a5c2d
[#1247] Wait for the join of the restarted replication server before the joins on empty volumes of the Docker replication test (#1249)

Fixes #1247

## What

At the end of the "roles: fail-over" phase of
`.github/scripts/docker-test-replication.sh`, the test now waits for the
join of the restarted dj-r0 to end, not only for its health. Only then
does it start dj-r1 on an empty volume, which is expected to join
through dj-r0.

```sh
members=$(logs_count dj-r0 "the health check may probe it")
docker start dj-r0 >/dev/null
rejoined() { [ "$(logs_count dj-r0 "the health check may probe it")" -gt "$members" ]; }
wait_until 300 "the restarted dj-r0 is a member again" rejoined
published_ready dj-r0 || fail "dj-r0 does not publish itself ready after it rejoined"
wait_healthy dj-r0
```

The comment of `logs_have_since` now also says when its anchor holds:
only once this start has logged it itself.

## Why

A replication server publishes itself `rejoining` on every start until
its join finds it a member again. It reports itself healthy as soon as
it serves, which comes before that. A joiner skips a rejoining peer. So
`wait_healthy dj-r0` could return while dj-r1 would still find dj-r0
rejoining and join through dj-d1. That happened in run
[40736306534](https://github.com/OpenIdentityPlatform/OpenDJ/actions/runs/40736306534)
(`docker-test (default)`); the issue has the details.

The wait counts the line "the health check may probe it", which
`joined()` logs once it has published the server ready. The count is
taken while dj-r0 is still down, the way `half_enabled_rejoins` takes
it, and the wait ends when the join of the new start adds one. On this
road `join.sh` is the only source of that line. Two simpler signals do
not work here:

- The published state is kept in cn=config on the volume, so it reads
`ready` from the previous start until the join of this start publishes
`rejoining`.
- The log after the last "Starting OpenDJ", which "roles: restarts"
reads, says nothing right after `docker start`. On a volume that holds
the data, `run.sh` prints "Starting OpenDJ" only after `upgrade -n
--force`. Until then the last such line, and the member line after it,
are those of the previous start. `wait_until` checks at once, so it
would return on that line, and `published_ready` would ask a server that
is not up yet.

The image itself is unchanged. It behaves as `run.sh` and `join.sh`
describe.

## Testing

- `bash -n .github/scripts/docker-test-replication.sh`
- The wait, as the script spells it, was run against every cut of the
container log of dj-r0 from the failed run, with `docker logs` stubbed
and the count taken on the log as it was while dj-r0 was down:
- every cut before the member line of the last start keeps waiting: the
log of the previous start alone, then with the upgrade output of the new
start, then the new start up to "already a member". The last of these is
the state in which the run failed;
- the cut that ends on the member line of the last start passes, and so
does the whole log.
- The same check catches the wait of the first round of this PR
(`logs_have_since dj-r0 "Starting OpenDJ" …`), which passes on the three
cuts before the new "Starting OpenDJ", and a count taken after the
member line, which never passes.
- The Docker test itself runs only in CI (`docker-test (default)` and
`docker-test (alpine)`).
1 files modified
15 ■■■■■ changed files
.github/scripts/docker-test-replication.sh 15 ●●●●● patch | view | raw | blame | history
.github/scripts/docker-test-replication.sh
@@ -95,7 +95,10 @@
}
# the container logged the text after the last line that holds <since> - after a restart,
# say, which the join of the start before may still have logged into until it was stopped
# say, which the join of the start before may still have logged into until it was stopped.
# Not right after the start: until this start logs <since> itself, the last such line and the
# text after it are those of the start before - run.sh prints "Starting OpenDJ" only after
# the upgrade
logs_have_since() { # <container> <since> <text>
  docker logs "$1" 2>&1 | awk -v s="$2" 'index($0, s) { buf = ""; next } { buf = buf $0 "\n" } END { printf "%s", buf }' \
    | grep -F -- "$3" >/dev/null
@@ -1045,7 +1048,17 @@
done
add_ou dj-d0 roles-other-rs
wait_has dj-d1 "ou=roles-other-rs,dc=example,dc=com"
# dj-r1 joins through dj-r0 below, and a joiner skips a peer that publishes itself rejoining:
# a replication server does so on every start until its join finds it a member again, and
# it reports itself healthy as soon as it serves, before that. What it published on its
# start before still reads ready until this join replaces it, so the join is waited for -
# by a count taken while dj-r0 is down: its log still holds the line the join of the start
# before logged, and the new start prints "Starting OpenDJ" only after its upgrade
members=$(logs_count dj-r0 "the health check may probe it")
docker start dj-r0 >/dev/null
rejoined() { [ "$(logs_count dj-r0 "the health check may probe it")" -gt "$members" ]; }
wait_until 300 "the restarted dj-r0 is a member again" rejoined
published_ready dj-r0 || fail "dj-r0 does not publish itself ready after it rejoined"
wait_healthy dj-r0
phase "roles: joins on empty volumes"