Skip to content

Wait for the test proxies to bind, and stop ConnectionTests leaking clients - #1863

Open
Ewerton Scaboro da Silva (ewertons) wants to merge 4 commits into
mainfrom
fix-e2e-proxy-bind-race-and-client-leak
Open

Wait for the test proxies to bind, and stop ConnectionTests leaking clients#1863
Ewerton Scaboro da Silva (ewertons) wants to merge 4 commits into
mainfrom
fix-e2e-proxy-bind-race-and-client-leak

Conversation

@ewertons

Copy link
Copy Markdown
Contributor

Salvages the three test-harness fixes from #1856 that are still relevant. That PR is now CONFLICTING and most of it has been overtaken — this carries forward only the parts that were never picked up, rebased onto current main.

Relationship to #1856

#1856 proposed Status
ProxiedSSLSocket honors the connect timeout already fixed independently in #1859
HttpProxySocketFactory returns an unconnected socket already fixed in #1859
ProxiedSSLSocket.close() null-safety already on main
Remove @Test(timeout = 60000) superseded, see below
Wait for the proxies to bind carried forward here
ConnectionTests client leak carried forward here
Unused @Mocked Object carried forward here

On the timeout: #1856 read the 60s-vs-60s collision as a race to be won by changing one of the numbers. It isn't. These tests call open(true), and the default retry policy is ExponentialBackoffWithJitter with retryCount = Integer.MAX_VALUE, so the client never gives up and never throws — no timeout value changes that, and falling back to the 2 minute rule would just fail slower. #1862 addressed it with connection status logging plus the threadCount cap that fixes the underlying starvation.

1. Wait for the test proxies to bind

HttpProxyServer.startAsync(int) returns CompletionStage<Void> that completes once the port is listening. All four classes that stand up a local proxy discarded it. Because the e2e tests run in parallel, a test can start sending traffic before the proxy is accepting and get a connection refused from a proxy that is about to be perfectly healthy.

ProxyServerTools.startProxyServer waits on that future, capped at 30s so a proxy that never binds fails the run with a clear error instead of hanging.

Applied to all five call sites across ConnectionTests, FileUploadTests, MultiplexingClientTests and TokenRenewalTests.

2. ConnectionTests was leaking every client it opened

ConnectionTestInstance.dispose() was dead code — defined, never called. Four other test classes call testInstance.dispose(); this one didn't. So every CanOpenConnection variant leaked its client and its identity.

Those clients keep retrying for the life of the JVM, and the proxied ones keep retrying through the proxies this class runs locally, competing with tests that are still running. Once stopProxy() closes them they retry against a dead port for the rest of the job.

This is the same leak #1861 fixed in TokenRenewalTests, and it works directly against the parallelism cap added in #1862 — the entire point of that cap was to stop these proxies being starved. Now called from an @After.

ECC identities have to be deleted, not recycled

Worth calling out, because it is a trap. Unlike every other identity here, the ECC ones are created by the test rather than drawn from the shared pool, and carry a self-signed cert only this test knows about. disposeTestIdentity recycles rather than deletes when RECYCLE_TEST_IDENTITIES is set, and these are SELF_SIGNED — so recycling one would drop a device with an unknown thumbprint into the x509 pool for a later test to fail on. They are removed from the registry instead.

3. Unused @Mocked Object in the provisioning tests

ContractAPIMqttTest declared @Mocked Object mockSendLock and @Mocked Integer mockedInteger; ContractAPIAmqpTest declared @Mocked Object mockSendLock. None of the three is referenced anywhere. Mocking java.lang.Object makes JMockit retransform it, which is a hazard to the whole JVM rather than to one test.

Being straight about the evidence: this is not currently failing. #1856 cited build 161517, but I could not reproduce it — the full provisioning suite passes on JDK 8 with reruns disabled, and no ContractAPI* failure appears in the last seven CI builds. These are removed because they are unused and risky, not because they are breaking something today. If you would rather not touch them, that commit can be dropped without affecting the other two fixes.

Verification

On JDK 8:

  • mvn -pl iot-e2e-tests/common -am test-compile — BUILD SUCCESS
  • mvn -pl provisioning/provisioning-device-client test -Dsurefire.rerunFailingTestsCount=0544 tests, 0 failures, the same count as before the removal

The proxy bind wait and the client leak fix only show their effect in a live gated run, so those are exercised by the gate rather than locally.

Closes #1856.

…lients

Three test harness problems, salvaged from PR 1856. The SDK half of that PR was
fixed independently in PR 1859, and the timeout change it proposed is superseded
by PR 1862, but these three were never picked up.

HttpProxyServer.startAsync only initiates the bind and returns a CompletionStage
that completes once the port is listening. All four test classes that stand up a
local proxy discarded it. Because the e2e tests run in parallel, tests can start
sending traffic before the proxy is accepting, and get a connection refused from
a proxy that is about to be perfectly healthy. ProxyServerTools.startProxyServer
waits on that future, with a 30 second cap so a proxy that never binds fails the
run with a clear error rather than hanging.

ConnectionTests.ConnectionTestInstance.dispose was dead code. Nothing ever
called it, so every test in the class leaked the client it opened along with its
identity. Those clients keep retrying for the rest of the JVM's life, and the
ones configured with proxy settings keep retrying through the proxies this class
runs locally, competing with the tests still running. Once stopProxy closes those
proxies they retry against a dead port instead, for the remainder of the job.
This is the same leak that PR 1861 fixed in TokenRenewalTests, and it works
against the parallelism cap added in PR 1862, since the whole point of that cap
was to stop the proxies being starved. It is now called from an @after.

While wiring that up, the ECC identities need care. Unlike every other identity
in this class they are created by the test rather than taken from the shared
pool, and they carry a self signed certificate that only this test knows about.
disposeTestIdentity recycles rather than deletes when RECYCLE_TEST_IDENTITIES is
set, and these are SELF_SIGNED, so recycling one would put a device with an
unknown thumbprint into the x509 pool for a later test to fail on. They are
deleted from the registry instead.

ContractAPIMqttTest declared @mocked Object mockSendLock and @mocked Integer
mockedInteger, and ContractAPIAmqpTest declared @mocked Object mockSendLock.
None of the three is referenced anywhere. Mocking java.lang.Object makes JMockit
retransform it, which is a hazard to the whole JVM rather than to one test. To
be clear about the evidence: this is not currently failing. The full
provisioning suite passes on JDK 8 with reruns disabled, and no ContractAPI
failure appears in the last seven CI builds. These are removed because they are
unused and risky, not because they are breaking something today.

Verified on JDK 8: iot-e2e-common test compilation succeeds, and
provisioning-device-client runs 544 tests with no failures and no reruns, the
same count as before the removal.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@ewertons

Copy link
Copy Markdown
Contributor Author

Fresh evidence from main build 162121 that this matters

This is the first nightly main build carrying the threadCount=6 cap from #1862, and it also carries the connection-status logging from that PR — so for the first time these failures come with diagnostics attached. The result supports both halves of this PR.

The parallelism cap helped materially. tokenRenewalWorks passed, and JDK 8, 17 and 21 were completely clean. But CanOpenConnection[MQTT_WS_SAS_DEVICE_CLIENT_true_false] still failed on JDK 11, so the proxied path is not fully fixed yet.

What the new logging shows

All three attempts of that test, from its own thread:

22:23:57.610  Starting test
22:23:57.611  Acquiring test device from testSasDeviceQueue
              ... 60s of nothing, no status transition at all ...
22:24:57.614  Test failed on run 1, test timed out after 60000 ms

22:24:57.615  Acquiring test device
22:24:58.225  CONNECTED, CONNECTION_OK          <-- opened in 0.6s
22:24:58.226  Device client opened successfully
22:24:58.226  Closing device client...
              ... 59 seconds in close() ...
22:25:57.616  Device client closed successfully
22:25:57.616  Test failed on run 2, test timed out after 60000 ms

Run 2 is the interesting one: the open took 0.6 seconds and the close took 59. So on that attempt the connect path was fine and the entire 60s budget went to close(). That points at Mqtt.DISCONNECTION_TIMEOUT, which is also 60s, rather than at the connect timeout.

The leak this PR fixes is visibly firing in that same run

At the very end of the job, 22:44:00, there are 58 stacks of

java.net.ConnectException: Connection refused
    at ...ProxiedSSLSocket.connectToProxy(ProxiedSSLSocket.java:165)

all within 93 milliseconds of each other, and all after ConnectionTests finished and stopProxy() closed the proxies. Those are leaked clients from this exact class still retrying through proxies that no longer exist. The log also shows two of them going CONNECTED -> DISCONNECTED_RETRYING (NO_NETWORK) at the moment the proxies closed, then RETRY_EXPIRED four minutes later.

That is precisely the leak the @After in this PR removes. It is not hygiene: those clients are consuming CPU and proxy capacity while the remaining tests in the job are still running, which is the same resource contention #1862 was trying to relieve.

What this means

I do not want to overclaim — this PR is not guaranteed to fix that JDK 11 failure, and the 59 second close() in run 2 is a separate thread worth pulling on, since Mqtt.CONNECTION_TIMEOUT and DISCONNECTION_TIMEOUT are both 60s and a slow close alone can consume the whole test budget. But removing 58 background reconnect attempts from a job that is already contended is a clear step in the right direction, and it is now demonstrably happening rather than theoretical.

@ewertons

Copy link
Copy Markdown
Contributor Author

More evidence from main, and it strengthens the case for this PR

Two nightly results landed since the last comment.

Java Linux 162187 was completely clean — the first fully green nightly on main in a while:

Job Result Wall
Linux JDK 8 2589 passed, 0 failed 12.8 min
Linux JDK 11 316 passed, 0 failed 12.7 min
Linux JDK 17 316 passed, 0 failed 12.7 min
Linux JDK 21 316 passed, 0 failed 12.7 min

Note 316 executed on main versus 158 in PR builds, so these runs include the @FlakeyTest and @ContinuousIntegrationTest cases that PR builds skip. Wall clock is unchanged at 12.7–12.8 min, confirming again that threadCount=6 costs nothing.

Java Windows 162204 failed, and it is directly relevant here.

The Windows failure is the ECC test, and it has always been the ECC test

Every Windows failure in the last 15 main builds is the same test:

162204  failed  CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_false, _true_true]
162122  failed  CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_false]
162052  failed  CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_true]
161876  failed  CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_false, _true_true]
161823  failed  CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_true]
161523  failed  CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_false, _true_true]

Nothing else has failed on Windows in that window, and this predates all of the recent work — 161523 and 161876 are on 8abba69bc and d1583cc9c. The trailing _true_* is useHttpProxy, so this is the proxied path again.

It also explains a pattern that had been bothering me: this test carries @FlakeyTest, so it is skipped in PR builds and only runs on main. That is why PRs go green while main goes red on the same commit.

This PR's leak fix is firing in that exact run

The Windows log shows 15 ECC devices created and 0 removed:

Successfully added device ecc-test-device-...   x15
Removing device ecc-test-device-...             x0

CanOpenConnectionWithECCCertificates calls setupEccDevice(), which registers a device and a module directly, and with dispose() never being called none of them are ever cleaned up. Three per failing test across three rerun attempts, plus the passing variants. Every one is left in the registry, and every one leaves a client behind retrying through the local proxies.

This PR fixes both halves of that: the @After closes the client, and the ECC branch deletes the identity from the registry rather than recycling it.

What this PR will not fix

Being clear so this is not oversold. The failing test itself shows 60 seconds of complete silence — the registry operations complete in about 70 ms and then there is not a single connection status transition before the timeout. So the client never gets far enough to report anything, on all three attempts. Removing the leaked clients reduces the contention that plausibly causes that, but I cannot claim from this evidence that it will resolve it.

What the evidence does establish is that the leak is real, it is happening on every Windows nightly, and it is worse than I described when opening this PR, because for ECC identities it leaks registry entries as well as clients.

CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_false]
and its true_true counterpart are the only tests that have failed on the Java
Windows nightly in the last 15 main builds. They fail intermittently, roughly a
third of runs, and always the same way: the registry work finishes in about 140
milliseconds and then there is 60 seconds of complete silence with no connection
status transition at all before the JUnit timeout fires.

setupEccDevice ignored useHttpProxyAuth. setup, which every other test in this
class uses, picks between the authenticated proxy on 8899 and the unauthenticated
one on 9000 based on that flag. setupEccDevice had only the first branch, so
every proxied ECC variant went to the authenticated proxy.

Two consequences. Both proxied ECC variants piled onto one embedded proxy while
the other sat idle, doubling the demand on a server that runs inside the same JVM
as the tests. And the true_false variant never tested what its name says: it
claims to cover ECC certificates through a proxy that does not require
authentication, and it actually exercised the authenticated one, so that
combination had no coverage at all.

The two tests that fail are exactly the two that were misrouted.

Rather than adding the missing branch to the second copy, both call sites now
share applyProxySettings. Having the same decision written out twice is what
allowed them to drift, and the copy that drifted was the one used by the test
that fails. CanOpenMultiplexingConnection keeps its own copy because it builds
MultiplexingClientOptions rather than ClientOptions, so it cannot share the
helper.

This should reduce the failure rate rather than being guaranteed to eliminate it.
The underlying condition is contention for the embedded proxies, and this removes
one contributor to it. Even on a passing Windows run these tests take about 11.4
seconds against a 60 second budget, so the headroom is smaller than the pass
result suggests.

Tracked by work item 39365585.

Verified with mvn -pl iot-e2e-tests/common -am test-compile on JDK 8. The
behaviour of setup() is unchanged, so the only functional difference is which
proxy the ECC variants use.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@ewertons

Copy link
Copy Markdown
Contributor Author

Added the fix for the Windows ECC failure, tracked as 39365585

Pushed bf7560ea9. This is in the same file and the same area as the leak fix, so it belongs on this PR rather than a separate one.

The defect

setupEccDevice() ignored useHttpProxyAuth. setup(), which every other test in the class uses, picks between two proxies:

if (this.useHttpProxy) {
    if (this.useHttpProxyAuth) { /* authenticated proxy, 8899, with credentials */ }
    else                       { /* unauthenticated proxy, 9000, no credentials */ }
}

setupEccDevice() had only the first branch, so every proxied ECC variant went to the authenticated proxy:

Test variant proxy used
CanOpenConnection _true_true 8899 (auth)
CanOpenConnection _true_false 9000 (no auth)
CanOpenConnectionWithECC _true_true 8899 (auth)
CanOpenConnectionWithECC _true_false 8899 (auth) — wrong

Two consequences. Both proxied ECC variants piled onto one embedded proxy while the other sat idle, doubling demand on a server running inside the same JVM as the tests. And _true_false never tested what its name says — it claims ECC through a proxy that does not require authentication, and actually exercised the authenticated one, so that combination had no coverage at all.

The two tests that fail are exactly the two that were misrouted.

Why this is on the Windows pipeline specifically

Every Windows failure across the last 15 main builds is this one test, including builds on 8abba69bc and d1583cc9c, so it long predates the recent work. Nothing else has failed on Windows in that window. It is intermittent — the same variants pass on 162070, 162027, 162004 and 161947.

The misrouting itself is platform independent, so the likely explanation is that Windows agents have less headroom and the extra load on one proxy is enough to push these past the 60s budget there but not on Linux. Even on a passing Windows run these take about 11.4s of the 60s budget: ~5s before the registry work, ~2.5s of registry calls, ~3.7s to connect.

On the shape of the fix

I added the missing branch by extracting applyProxySettings and routing both call sites through it, rather than pasting the branch into the second copy. Having the same decision written twice is what let them drift, and the copy that drifted was the one used by the failing test. CanOpenMultiplexingConnection keeps its own copy because it builds MultiplexingClientOptions rather than ClientOptions and cannot share the helper — I checked, and that one is correct.

setup()'s behaviour is unchanged; the only functional difference is which proxy the ECC variants use.

Scope

I want to be careful not to oversell this. The underlying condition is contention for the embedded proxies, and this removes one contributor. It should reduce the failure rate rather than being guaranteed to eliminate it, and the nightlies will show whether more is needed. What it definitely does fix is the coverage gap, which is a real defect regardless of the timing.

Copilot AI left a comment

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Pull request overview

Improves e2e test reliability and prevents leaked clients and risky unused mocks.

Changes:

  • Waits up to 30 seconds for local proxies to bind.
  • Cleans up ConnectionTests clients and ECC identities.
  • Removes unused JMockit fields.

Reviewed changes

Copilot reviewed 7 out of 7 changed files in this pull request and generated 2 comments.

Show a summary per file
File Description
ContractAPIMqttTest.java Removes unused mocked fields.
ContractAPIAmqpTest.java Removes an unused mocked field.
TokenRenewalTests.java Waits for proxy startup.
MultiplexingClientTests.java Waits for proxy startup.
FileUploadTests.java Waits for proxy startup.
ConnectionTests.java Adds cleanup, proxy waits, and shared proxy configuration.
ProxyServerTools.java Adds bounded proxy-start helper.

💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.

setupEccDevice registers the ECC device before it has anything to assign
to identity, and for module variants it then registers a module and
constructs a client, either of which can throw. When that happened the
new @after reached dispose() with identity still null, took the early
return, and left the device behind in the registry - the same leak the
rest of this change is removing.

Record the device id as soon as the registration succeeds and drive the
cleanup off that instead of off identity, so a half provisioned ECC
identity is still deleted. Deleting the device deletes its module too,
so the module needs no separate tracking.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@ewertons

Copy link
Copy Markdown
Contributor Author

Gate failure on this PR, and where build 162204 actually stands

1. The red check on this PR is not caused by this PR

Java Linux build 162266 failed on one job only, Linux JDK 11, with one test:

TwinTests.sendReportedPropertiesWithoutVersion[AMQPS_SAS_MODULE_CLIENT]
IotHubClientException: Timed out waiting for service to respond to getTwin request
    at TwinTests.sendReportedPropertiesWithoutVersion(TwinTests.java:74)

Line 74 is the first getTwin() call. Everything else in that build passed — Linux JDK 8 (2273/2274), JDK 17, JDK 21, Java Windows 162267, Java Android 162268, SDL, and horton-java-gate were all green.

Why this is not attributable to this change:

  • TwinTests is not touched here, and neither is anything it uses. The failure mode is a service response timeout, not a connection, proxy or identity problem.
  • The one shared surface is identity recycling: ConnectionTests now returns identities to the pool. That is safe by construction — getSasTestModule builds a new ModuleClient for a recycled identity rather than reusing the old one, and disposeTestIdentity requeues on the identity's existing twinUpdated flag, so a clean-twin consumer cannot be handed a dirty identity. ConnectionTests never touches a twin.
  • The previous gate run on this branch, 162183/162184 on commit 7e1f383, was fully green.
  • The same class of service-side timeout shows up on untouched main, e.g. 162063 tokenRenewalWorks: Timed out waiting for service to acknowledge telemetry.

I have requested a re-queue of Java Linux (definition 533) against refs/pull/1863/merge; that request is held for a human to approve and has not run yet. A fresh push to the branch would re-trigger it as well.

2. Build 162204: this PR helps, but does not fully fix it

The failure in 162204 is CanOpenConnectionWithECCCertificates[MQTT_WS_SELF_SIGNED_MODULE_CLIENT_true_false] and [..._true_true], on Windows JDK 11 only, 180s each (3 × 60s reruns). It is still failing: nightly 162391 (2026-08-24) failed on both of the same variants.

Pulling the actual log for 162204 shows the failure has two different shapes across the three reruns of the same test, which matters for how much this PR can claim:

run 1  06:36:02.688  Attempting to add device ecc-test-device-5e51b95b...
       06:36:02.758  Successfully added device
       06:36:02.758  Attempting to add module ecc-test-module-b7f3f154...
                     <no success line, ever>
       06:37:02.682  Test failed on run 1, timed out after 60000 ms

run 2  06:37:02.698  Attempting to add device ...
       06:37:02.790  Successfully added device
       06:37:02.857  Successfully added module ecc-test-module-8f08e326...
                     <60s of total silence, not one connection status transition>
       06:38:02.686  Test failed on run 2, timed out after 60000 ms

run 3  06:38:02.713  add device -> 06:38:02.845 module added -> silence -> 06:39:02.694 final failure

Two things follow.

Run 1 hung inside registryClient.addModule. That is a plain HTTPS registry call that never goes through a proxy. So at least one of the three failures is not a proxy-routing problem at all — it is the agent being starved badly enough that a ~70ms registry call did not return within 60 seconds. Note also that the JUnit 60s budget covers the registry work, not just the connection.

Runs 2 and 3 hung after the module was registered, with no status transition ever emitted. The status callback is installed immediately after setupEccDevice returns, so silence means open(true) never got far enough for the transport to change state — consistent with a proxy that accepts the TCP connection and never answers CONNECT.

The proxied DEVICE_CLIENT ECC variants pass in under a second in the same run, at 06:35:58–06:36:02, and the MODULE_CLIENT ones fail from 06:36:02 onward. Whatever wedges the proxies does so partway through the class — which is exactly when the leaked, never-closed clients from the earlier CanOpenConnection variants have accumulated.

Verdict. This PR removes two real contributors: the leaked clients that keep retrying through the embedded proxies, and the misrouting that piled both proxied ECC variants onto one proxy while the other sat idle. Both are demonstrably firing in that build. But it does not explain run 1 hanging in addModule, and no change in this PR bounds that. So: expect the failure rate to drop, do not expect it to be proven fixed here — and the gate cannot show it either way, because CanOpenConnectionWithECCCertificates is @FlakeyTest and only runs on nightly main.

3. Review comments

Both Copilot comments are answered inline. The first one found a real bug — dispose()'s early return on identity == null leaked any ECC device whose registration succeeded before the rest of setup failed, which is precisely what run 1 above does. Fixed by recording the device id at registration time and driving cleanup off that. That commit is prepared but not yet pushed, as pushing is not available in this session.

…sing

Build 162413 failed on Linux JDK 17 and JDK 21 with

  NullPointerException: Cannot invoke TestIdentity.getClient() because
  this.testInstance.identity is null
    at ConnectionTests.CanOpenConnection(ConnectionTests.java:336)

Line 336 is the closing client.close(). Every test in this class is
bounded by @test(timeout = 60000), and JUnit runs the method body on a
separate thread that it abandons, still running, when the timeout
fires. @after is outside that timeout, so the dispose() added by this
change ran on the main thread while the abandoned thread was still
partway through the test body, and the identity = null in dispose()
pulled the field out from under it.

The four other classes that dispose from an @after do not clear the
field, and none of them bound their tests with a timeout. Clearing it
was hygiene rather than a requirement - setup() assigns the field on
every attempt - so it is dropped, which restores the existing
convention.

The two timeout bounded test bodies now also take the client once into
a local rather than re-reading it off the shared instance for each
call, so they no longer depend on that field surviving the test.

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
@ewertons

Copy link
Copy Markdown
Contributor Author

Build 162413: the JDK 11 flake cleared, but it exposed a real bug in this PR

I re-queued Java Linux on the same commit f050bce that failed as 162266. Result, build 162413:

Job 162266 162413
Linux JDK 8 pass pass
Linux JDK 11 FAIL TwinTests.sendReportedPropertiesWithoutVersion pass
Linux JDK 17 pass FAIL
Linux JDK 21 pass FAIL

So the TwinTests failure was indeed an unrelated flake — same commit, passes on re-run. But the new run surfaced something that is not a flake and is my fault.

The bug: the new @After nulls an identity that a timed-out test thread is still using

Both JDK 17 and JDK 21 failed on the same test with the same error:

CanOpenConnection[MQTT_WS_SAS_DEVICE_CLIENT_true_true]
java.lang.NullPointerException: Cannot invoke "TestIdentity.getClient()"
because "this.testInstance.identity" is null
    at ConnectionTests.CanOpenConnection(ConnectionTests.java:336)

Line 336 is the final testInstance.identity.getClient().close().

The mechanism, and why it is specific to this class:

  1. Every test here is @Test(timeout = 60000). JUnit implements that by running the method body on a separate Time-limited test thread and, when the timeout fires, abandoning that thread — still running — and reporting TestTimedOutException.
  2. @Before/@After are outside the timeout wrapper (withPotentialTimeout wraps only the method invocation, withAfters wraps the result). So the new @After disposeTestInstance() runs on the main thread concurrently with the abandoned thread.
  3. dispose() ended with this.identity = null. The abandoned thread then reached line 336 and dereferenced null.

This is why it appeared now and not in 162183/162184: it only triggers when a test actually times out, which is exactly the intermittent condition this PR is trying to reduce. MQTT_WS_..._true_true is the proxied variant, so it is the one most likely to time out.

Why the fix is to drop the line, not to guard it. The four other classes that dispose from an @AfterDirectMethodsCommon, SendMessagesCommon, ReceiveMessagesCommon, MultiplexingClientTests — all end dispose() with Tools.disposeTestIdentity(...) and none of them clears the field. None of them bounds its tests with a timeout either, which is why none of them hit this. Clearing was hygiene on my part, not a requirement: setup() assigns identity on every attempt, so nothing reads a stale value.

Pushed as 2fa541cfc:

  • dispose() no longer clears identity, with a comment recording why, so it does not get "tidied" back in.
  • CanOpenConnection and CanOpenConnectionWithECCCertificates now take the client into a local once instead of re-reading testInstance.identity for each of the four calls, so the body no longer depends on that field surviving.

Also pushed 7141d3cdc, the ECC cleanup fix from the review comment above.

The other failure in 162413 is pre-existing

Linux JDK 17 also failed tokenRenewalWorks after 889s with Failed to open the client due to network issues. That is not new: the identical failure and message occur on untouched main in 162026, and 162063 failed it with Timed out waiting for service to acknowledge telemetry. This PR's only change to TokenRenewalTests is waiting for the proxy to bind before tests start, which cannot make an open fail that would otherwise have succeeded.

Verification caveat

I could not run the build locally — Maven Central is unreachable from this environment, so no dependency resolution is possible. What I did verify: javac on the edited file produces exactly the same error profile as the unmodified baseline — 100 errors, all cannot find symbol / package does not exist from the absent classpath, and 0 syntax errors. Correctness of the change rests on the reasoning above plus the gate.

Gate run 162432 was triggered automatically by the push and is queued now.

@ewertons

Copy link
Copy Markdown
Contributor Author

Java Android 162434: transient DNS failure to the DPS endpoint, unrelated to this PR

Everything else on this push is green — Java Linux (all four JDKs, including the JDK 17/21 NPE that 2fa541cfc fixed), Java Windows, SDL, horton-java-gate, license/cla. The one red check is Java Android.

What failed

One job of thirteen, Android Test TestGroup1. Android Build, DeployCloudTestResources, TearDownCloudTestResources and TestGroup2 through TestGroup12 all passed.

Tests run: 17,  Failures: 5
Test failures detected, exiting...
##[error]Bash exited with code '255'

All 5 failures are in ProvisioningServiceClientAndroidRunner — which is the whole of that class, it has exactly 5 tests. Four are:

ProvisioningServiceClientTransportException: java.net.UnknownHostException:
Unable to resolve host "javasdkgatebgpks-dps.azure-devices-provisioning.net":
No address associated with hostname
    at ContractApiHttp.request(ContractApiHttp.java:157)
    at ProvisioningServiceClient.createOrUpdateIndividualEnrollment(...:230)

and the fifth, individualEnrollmentGetAttestationMechanismX509, is the same call path with java.net.SocketTimeoutException: timeout. No test result attachment was published because the task aborted with 255, so these only appear in the task log.

Every one of them fails inside ContractApiHttp.request before any SDK logic runs. Nothing is asserting; the emulator cannot reach the host.

Why it is not this PR

Nothing this PR touches runs in the failing group. The four e2e classes this PR modifies map to different Android groups, and all four groups passed:

Class changed here Android runner Group Result
MultiplexingClientTests MultiplexingClientAndroidRunner TestGroup6 passed
FileUploadTests FileUploadAndroidRunner TestGroup10 passed
ConnectionTests ConnectionTestsAndroidRunner TestGroup11 passed
TokenRenewalTests TokenRenewalAndroidRunner TestGroup12 passed

ProvisioningServiceClientTests is not in this PR's diff. The only provisioning files here are ContractAPIAmqpTest and ContractAPIMqttTest, which are JMockit unit tests in provisioning-device-client — they never run on the emulator.

The host was resolvable in the same emulator run. TestGroup1 also contains ProvisioningClientSymmetricKeyAndroidRunner, which is the other 12 of the 17 tests, and all 12 passed. That class goes through ProvisioningCommon, which constructs new ProvisioningServiceClient(provisioningServiceConnectionString) against the same javasdkgatebgpks-dps... host and creates enrollments through it. So within one 80-second process, the same hostname resolved for 12 tests and failed to resolve for 5. That is transient DNS inside the emulator, not a missing or misdeployed resource — DeployCloudTestResources succeeded, and the DPS instance is created fresh per build with a random suffix, so a not-yet-propagated record early in the run fits the evidence.

Android has been green on this branch. 162185 and 162268 passed on earlier commits of this PR, and 162390 passed on main earlier today.

What I am not claiming

I cannot prove the ordering — whether the 5 failures ran before the 12 successes, which would make it a startup propagation window, or were interleaved, which would make it flaky emulator resolution. The log timestamps are all flushed at task end, so relative ordering within the run is not recoverable from it.

Recommendation: re-run Java Android. Nothing in the diff can affect it. I do not have permission to queue that build myself; it needs approval, or a maintainer can hit re-run on 162434.

@ewertons

Copy link
Copy Markdown
Contributor Author

Android re-run 162511: same failure, and it is a known environmental flake

Re-ran on the same commit. TestGroup1 failed again; all other 12 groups, Android Build and both cloud-resource jobs passed.

Cause is unchanged: UnknownHostException: Unable to resolve host "javasdkgate<random>-dps.azure-devices-provisioning.net" from ContractApiHttp.request, i.e. the per-build DPS hostname does not resolve inside the emulator.

Evidence that it is not this PR:

Build Branch TestGroup1 Failures / 17
161767 main failed 6
162061 PR #1862 failed 11
162434 this PR failed 5
162511 this PR failed 6
  • Identical exception and stack in all four, including on main on 12 Aug and on an unrelated PR — both predate the commits under review.
  • Base rate is 4 failures in the last 39 Android builds (~10%), spread across main and multiple PRs.
  • The failure count varies run to run (5, 6, 6, 11) and a subset of tests in the same emulator process resolves the same host successfully. A code defect would fail deterministically.
  • None of the classes changed here run in TestGroup1. They run in groups 6, 10, 11 and 12, all green in both runs.
  • Deploy-to-test gap does not explain it: the two failures were at ~34 min, while passing runs were at ~6, ~12 and ~70 min.

Correction to my earlier note: I called it transient after one occurrence. Two in a row on the same commit is worth more than that, so the base-rate check above is the actual basis, not the single observation.

This needs an infrastructure fix (DNS resolution for freshly created DPS instances inside the emulator), not a change to this PR. Happy to open a separate issue for it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

4 participants