[#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)`).
| | |
| | | } |
| | | |
| | | # 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 |
| | |
| | | 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" |