You signed in with another tab or window. Reload to refresh your session.You signed out in another tab or window. Reload to refresh your session.You switched accounts on another tab or window. Reload to refresh your session.Dismiss alert
AssuredReplicationServerTest.testSafeDataFromRS fails intermittently on CI. Latest
occurrence: the ubuntu-latest / 25 leg of the run for PR #788
(job 90818344106),
which is unrelated to that PR (it only touches DebugLogPublisher; the other eight
matrix legs — ubuntu 11/17/21/26, macOS 11/26, Windows 11/26 — passed on the same commit).
Failure was on invocation 26 of 360 ([sdLevel=2, fakeRsGid=2, fakeRsGenId=48, sendInAssured=true]),
after ~5 minutes of the class running happily on the same ports.
What actually happened
Connection refused is a downstream symptom. The test dump shows the real cause one
step earlier, in the same second:
category=SYNC severity=ERROR msgID=6
msg=Replication Server failed to start : could not bind to the listen port : 65531.
Error : Address already in use
Chain of events:
AssuredReplicationServerTest allocates its four RS ports once, in @BeforeClass
(AssuredReplicationServerTest.java:208, TestCaseUtils.findFreePorts(4)); in this
JVM they were 65531–65528, so rsPorts[0] = 65531 is the port of rs1 (RS1_ID = 101).
All 360 invocations of the class re-create the real RS on those same fixed ports.
On this invocation listenSocket.bind() failed with EADDRINUSE — something else held
65531 for a moment.
ReplicationServer.initialize()
(ReplicationServer.java:445-483)
only logsERR_COULD_NOT_BIND_CHANGELOG and returns normally. The constructor
"succeeds", the ReplicationServer object exists, but no listen thread was ever started.
The test proceeds, and FakeReplicationServer.connect()
(AssuredReplicationServerTest.java:837) gets ConnectException: Connection refused
0.006 s later — 400 lines away from the actual failure.
A few seconds later the port was free again: the remaining invocations of the same method
passed and the class finished.
This is the same failure mode as #728 ("Replication port stolen … RS silently starts
without listener"), which was fixed in #729 by rejecting TCP self-connects in ReplicationBroker.performPhaseOneHandshake() and ReplicationServer.connect().
That fix is in master (85631013fb) and this run contains it, so #729 reduced the
window but did not close it — the port can still be occupied at the exact moment the
next RS binds.
Worth noting what is ruled out by the evidence:
TIME_WAIT — the JDK enables SO_REUSEADDR on ServerSocket by default on POSIX
(verified: new ServerSocket().getReuseAddress() == true), and binding over TIME_WAIT
remnants is allowed. The port was held by a live socket.
Cross-JVM collision — failsafe runs with reuseForks=false/forkCount=1, so the
class had its own JVM; ports are handed out by a monotonically decreasing counter
(TestCaseUtils.port = 65535, bindFreePort()), i.e. no port is handed out twice
inside one JVM.
Candidates for the momentary holder (not distinguishable from the logs we currently keep):
a self-connected socket in the small window between connect() and the isSelfConnection()
rejection; a lingering socket from the previous invocation's RS/handler shutdown; or an
ordinary client socket that got 65531 as its local ephemeral port (TestCaseUtils
deliberately allocates from the top of the port space to avoid this, which only holds
while the runner keeps the default ip_local_port_range).
Proposed fixes
Fail fast on bind failure — this is follow-up item 1 already recorded in Replication port stolen by TCP self-connect: RS silently starts without listener (testSafeDataLevelOne CI flake) #728 and
still open. ReplicationServer.initialize() must not swallow the IOException: an RS
whose listen port is not bound is dead, and every consumer (tests, embedded server,
production start-up) currently learns about it only as a confusing "connection refused"
somewhere else. Propagate it (ConfigException/InitializationException) and/or retry
the bind a few times with a short back-off, which would also make the transient case
self-healing.
Test infrastructure — AssuredReplicationServerTest (and the other replication
tests with the same shape) pins four ports for the whole class and re-binds them ~360
times over ~20 minutes. Allocating the port right before the RS is created, or retrying
with a fresh port on EADDRINUSE, removes the TOCTOU window inherent in bindFreePort() (it closes the probe socket and returns the number).
Retry safety net does not cover this test.rerunFailingTestsCount=3 is configured
for the precommit profile (opendj-server-legacy/pom.xml:1284), yet the report has no Flakes: section and the build failed on the first occurrence — the rerun did not
trigger for this TestNG @DataProvider-driven method. Worth confirming and, if it is
the known surefire/TestNG data-provider limitation, deciding whether we rely on the
setting at all for the replication suites.
Doing (1) alone would turn every future occurrence into a one-line diagnosis instead of a
stochastic Connection refused in an unrelated place.
Symptom
AssuredReplicationServerTest.testSafeDataFromRSfails intermittently on CI. Latestoccurrence: the
ubuntu-latest / 25leg of the run for PR #788(job 90818344106),
which is unrelated to that PR (it only touches
DebugLogPublisher; the other eightmatrix legs — ubuntu 11/17/21/26, macOS 11/26, Windows 11/26 — passed on the same commit).
Failure was on invocation 26 of 360 (
[sdLevel=2, fakeRsGid=2, fakeRsGenId=48, sendInAssured=true]),after ~5 minutes of the class running happily on the same ports.
What actually happened
Connection refusedis a downstream symptom. The test dump shows the real cause onestep earlier, in the same second:
Chain of events:
AssuredReplicationServerTestallocates its four RS ports once, in@BeforeClass(
AssuredReplicationServerTest.java:208,TestCaseUtils.findFreePorts(4)); in thisJVM they were 65531–65528, so
rsPorts[0] = 65531is the port ofrs1(RS1_ID = 101).All 360 invocations of the class re-create the real RS on those same fixed ports.
listenSocket.bind()failed withEADDRINUSE— something else held65531 for a moment.
ReplicationServer.initialize()(ReplicationServer.java:445-483)
only logs
ERR_COULD_NOT_BIND_CHANGELOGand returns normally. The constructor"succeeds", the
ReplicationServerobject exists, but no listen thread was ever started.FakeReplicationServer.connect()(
AssuredReplicationServerTest.java:837) getsConnectException: Connection refused0.006 s later — 400 lines away from the actual failure.
A few seconds later the port was free again: the remaining invocations of the same method
passed and the class finished.
Relation to #728 / #729
This is the same failure mode as #728 ("Replication port stolen … RS silently starts
without listener"), which was fixed in #729 by rejecting TCP self-connects in
ReplicationBroker.performPhaseOneHandshake()andReplicationServer.connect().That fix is in master (
85631013fb) and this run contains it, so #729 reduced thewindow but did not close it — the port can still be occupied at the exact moment the
next RS binds.
Worth noting what is ruled out by the evidence:
SO_REUSEADDRonServerSocketby default on POSIX(verified:
new ServerSocket().getReuseAddress() == true), and binding over TIME_WAITremnants is allowed. The port was held by a live socket.
reuseForks=false/forkCount=1, so theclass had its own JVM; ports are handed out by a monotonically decreasing counter
(
TestCaseUtils.port = 65535,bindFreePort()), i.e. no port is handed out twiceinside one JVM.
Candidates for the momentary holder (not distinguishable from the logs we currently keep):
a self-connected socket in the small window between
connect()and theisSelfConnection()rejection; a lingering socket from the previous invocation's RS/handler shutdown; or an
ordinary client socket that got 65531 as its local ephemeral port (
TestCaseUtilsdeliberately allocates from the top of the port space to avoid this, which only holds
while the runner keeps the default
ip_local_port_range).Proposed fixes
still open.
ReplicationServer.initialize()must not swallow theIOException: an RSwhose listen port is not bound is dead, and every consumer (tests, embedded server,
production start-up) currently learns about it only as a confusing "connection refused"
somewhere else. Propagate it (
ConfigException/InitializationException) and/or retrythe bind a few times with a short back-off, which would also make the transient case
self-healing.
AssuredReplicationServerTest(and the other replicationtests with the same shape) pins four ports for the whole class and re-binds them ~360
times over ~20 minutes. Allocating the port right before the RS is created, or retrying
with a fresh port on
EADDRINUSE, removes the TOCTOU window inherent inbindFreePort()(it closes the probe socket and returns the number).rerunFailingTestsCount=3is configuredfor the
precommitprofile (opendj-server-legacy/pom.xml:1284), yet the report has noFlakes:section and the build failed on the first occurrence — the rerun did nottrigger for this TestNG
@DataProvider-driven method. Worth confirming and, if it isthe known surefire/TestNG data-provider limitation, deciding whether we rely on the
setting at all for the replication suites.
Doing (1) alone would turn every future occurrence into a one-line diagnosis instead of a
stochastic
Connection refusedin an unrelated place.