Bound e2e test parallelism, set the MQTT connect timeout explicitly, and improve failure diagnostics - #1862
Conversation
…tests Two related problems, both about a connection failure being reported without anything that explains it. MqttIotHubConnection built its MqttConnectOptions without ever calling setConnectionTimeout, so the timeout Paho applied while establishing the connection was whichever default that version of Paho happened to ship. The effective value was therefore chosen by the library rather than by us, and it would change silently underneath us if Paho ever changed it. It also matters that this value stays below the 60 seconds that Mqtt.connect waits for the CONNECT to be acknowledged. If Paho were given as much time as the outer wait, a connection that cannot be established at all would surface as the outer wait expiring, which reports only "Timed out waiting for a response from the server" and says nothing about what actually went wrong. That is exactly the message the recent tokenRenewalWorks failures came back with. It is now set from Mqtt.CONNECTION_TIMEOUT so the two cannot drift apart. The value works out to 30 seconds, which is what Paho was already applying, so this does not change behaviour today. CONNECTION_TIMEOUT changes from private to package private so the derivation can reference it, and both constants now explain what they bound. Added constructorSetsConnectTimeoutShorterThanTheOverallConnectTimeout, which verifies the call is made and asserts the relationship between the two values holds. Removing the setConnectionTimeout call fails it with MissingInvocation. The second problem is on the test side. ConnectionTests.CanOpenConnection is annotated @test(timeout = 60000), the same 60 seconds as the SDK's connect timeout, which was originally reported as a race between the two. Looking at it properly, it is not a race that can be won by changing either number. These tests call open(true), and the default retry policy is ExponentialBackoffWithJitter with retryCount set to Integer.MAX_VALUE, so a connection that never succeeds is never abandoned. The client never throws, and the only thing that ends the test is the JUnit timeout, which reports nothing beyond the line it was stuck on: org.junit.runners.model.TestTimedOutException: test timed out after 60000 milliseconds at ...ConnectionTests.CanOpenConnection(ConnectionTests.java:244) Raising the test timeout would only make it take longer to say the same thing. The reason for the failure is only ever visible through the connection status change callback, so the two tests that open a client now register one and log every transition with its reason and cause. A run that times out now leaves behind the sequence of statuses and the underlying throwable, which is what was missing when triaging the recent MQTT_WS failures. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Seven separate rules decide whether an integration test should run, and all of them skipped with the same message, so a skipped test told you nothing about which rule skipped it or why. That matters most for the rules keyed off isPullRequest, FlakeyTestRule and ContinuousIntegrationTestRule, because a test annotated @FlakeyTest never runs in a pull request build at all. That is deliberate, and it should stay that way given how much noise those tests add, but until now it happened silently and the annotation quietly removed the test from the gate with nothing in the output to say so. Each rule now names the annotation or the environment variable responsible, following what ErrInjTestRule was already doing. No behaviour changes, only the message attached to the assumption. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
There was a problem hiding this comment.
Pull request overview
This PR improves MQTT connection diagnostics and integration-test skip reporting.
Changes:
- Explicitly configures and tests the Paho connection timeout.
- Logs connection status transitions in connection tests.
- Replaces generic skip messages with specific explanations.
Reviewed changes
Copilot reviewed 11 out of 11 changed files in this pull request and generated no comments.
Show a summary per file
| File | Description |
|---|---|
MqttIotHubConnectionTest.java |
Tests explicit timeout configuration. |
MqttIotHubConnection.java |
Configures Paho’s connection timeout. |
Mqtt.java |
Exposes and documents the overall timeout. |
ConnectionTests.java |
Logs connection status and failure causes. |
StandardTierHubOnlyTestRule.java |
Clarifies standard-tier skips. |
IotHubTestRule.java |
Clarifies IoT Hub test skips. |
FlakeyTestRule.java |
Clarifies flaky-test skips. |
DigitalTwinTestRule.java |
Adds a skip explanation, but names the wrong setting. |
DeviceProvisioningServiceTestRule.java |
Clarifies provisioning-test skips. |
ContinuousIntegrationTestRule.java |
Clarifies CI-test skips. |
BasicTierHubOnlyTestRule.java |
Clarifies basic-tier skips. |
💡 Add a code-review agent skill or configure MCP servers for context-aware, tailored reviews. Learn more in the docs.
|
/azp run Java Linux, Java Windows, Java Android |
|
Azure Pipelines: Successfully started running 3 pipeline(s). |
The e2e tests run in a single JVM with parallel=both and useUnlimitedThreads, so there was no cap on how many tests ran at once. Several of those tests stand up an embedded proxyee server inside that same JVM: ConnectionTests on 8899 and 9000, TokenRenewalTests on 8898, FileUploadTests on 8897 and MultiplexingClientTests on 8849. Those proxies have to be scheduled promptly to forward traffic, and a burst of test threads could starve them of CPU on a two core hosted agent. That explains the failure signature that has been on main for months. Only the proxied variants ever fail, and they fail by connecting and then having nothing flow, rather than by failing to connect. It is not specific to one protocol or one test class: CanOpenConnection[MQTT_WS_SAS_DEVICE_CLIENT_true_true] ConnectionTests CanOpenConnection[MQTT_WS_SAS_DEVICE_CLIENT_true_false] ConnectionTests getAndCompleteSasUriWithoutUpload[HTTPS_SAS_true] FileUploadTests getSasUriWithoutUploadConnectionToggle[HTTPS_SAS_true] FileUploadTests tokenRenewalWorks TokenRenewalTests Three test classes, three separate embedded proxies, both HTTPS and MQTT_WS, and in every case the non proxied variant of the same test passes in the same run. A non proxied client talks straight to Azure and does not need local CPU to make progress, which is why it is unaffected. Sets threadCount to 6 instead. This is expected to leave the total run time unchanged. Measured on build 162050, a successful run of this suite is 49 CPU-minutes completing in 12.8 minutes of wall clock, which is an average of 3.8 tests running at a time, so the unlimited setting was not buying throughput. The wall clock is floored by tokenRenewalWorks, which takes 12.8 minutes on its own because it deliberately waits out a sas token expiry, and 49 CPU-minutes spread over 6 threads is 8.2 minutes, comfortably inside that. Anything from 4 upwards predicts the same 12.8 minute run; 6 was chosen to leave headroom above the 3.8 average rather than to sit right on it. This does not make a slow agent fast. It stops an unbounded burst of test threads from starving a server that the same JVM is depending on. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
Validation of the parallelism changeAll 33 checks are green, including Same PR, same commit content, only the failsafe config differs — build 162059 (
Three things worth pointing out: No run time cost. This was the open question and the prediction held exactly. Wall clock is unchanged, and JDK 11 is actually 2 minutes faster — because the failure it used to hit was burning ~15 minutes before giving up. No coverage lost. Passed counts are identical (158 and 2273), and the collected set is 498 distinct test names in both. Worth stating explicitly because a thread cap is exactly the kind of change that could silently drop tests. The failure it targets went away. JDK 11's single failure under unlimited threads was I want to be careful not to overclaim on that last point. This failure is intermittent — roughly 50% of nightly For reference, the earlier red run on this PR (build 162059) was: Maven Central TLS handshake failure on Windows, emulator DNS failure on Android, and this |
The message said RUN_DIGITAL_TWIN_TESTS. The variable that actually controls this is RUN_DIGITAL_TESTS, read into IntegrationTest.runDigitalTwinTests. The field name and the variable name differ, and I followed the field name when writing the message. Checked the other six rules against the real mapping in IntegrationTest at the same time. The four that name a variable, RUN_PROVISIONING_TESTS, RUN_IOTHUB_TESTS, RUN_ERRINJ_TESTS and RUN_DIGITAL_TESTS, are now all correct. The three keyed off isBasicTierHub and isPullRequest name an annotation rather than a variable, which is right, because those are not set from the environment in the same way. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>
|
Thanks — the review summary flagged The message said public static boolean runDigitalTwinTests =
Boolean.parseBoolean(Tools.retrieveEnvironmentVariableValue("RUN_DIGITAL_TESTS", "true"));The field name and the environment variable name differ, and I wrote the message from the field name without checking. That is exactly the failure mode this change is meant to prevent, so it is worth catching. Since I clearly could not trust my recollection here, I audited all seven rules against the real mapping in
The three keyed off
|
Addresses four items on ADO 39339528. All four are about a failure arriving with nothing that explains it, or a failure that is nobody's fault but the harness's.
1. Bound the e2e test parallelism so the embedded proxies are not starved
This is the one that should fix the long-running red on
main.The e2e tests run in a single JVM with
parallel=bothanduseUnlimitedThreads, so there was no cap on how many ran at once. Several of them stand up an embeddedproxyeeserver inside that same JVM —ConnectionTestson 8899/9000,TokenRenewalTestson 8898,FileUploadTestson 8897,MultiplexingClientTestson 8849. Those proxies must be scheduled promptly to forward traffic, and a burst of test threads starves them of CPU on a two core hosted agent.That explains the failure signature that has been on
mainfor months. Only the proxied variants ever fail, and they fail by connecting and then having nothing flow — not by failing to connect. It is not specific to one protocol or one class:CanOpenConnection[MQTT_WS_SAS_DEVICE_CLIENT_true_true]CanOpenConnection[MQTT_WS_SAS_DEVICE_CLIENT_true_false]getAndCompleteSasUriWithoutUpload[HTTPS_SAS_true]getSasUriWithoutUploadConnectionToggle[HTTPS_SAS_true]tokenRenewalWorksThree classes, three separate proxies, both HTTPS and MQTT_WS — and in every case the non-proxied variant of the same test passes in the same run. A non-proxied client talks straight to Azure and needs no local CPU to make progress, which is why it is unaffected.
This is expected to cost nothing in run time
I measured rather than guessed. On build 162050 (a successful run):
tokenRenewalWorksaloneuseUnlimitedThreadswas not buying throughput — the suite only ever reached 3.8x. And the wall clock is floored bytokenRenewalWorks, which takes 12.8 minutes on its own because it deliberately waits out a SAS token expiry.Predicted wall =
max(longest test, totalCPU / threadCount):49 CPU-minutes over 6 threads is 8.2 minutes, comfortably inside the 12.8 minute floor, leaving ~4.6 minutes of scheduling slack. 6 was chosen to sit above the 3.8x average rather than right on it.
This does not make a slow agent fast. It stops an unbounded burst of test threads from starving a server the same JVM depends on.
2. The MQTT connect timeout was whatever Paho happened to default to
MqttIotHubConnectionbuilt itsMqttConnectOptionswithout ever callingsetConnectionTimeout, so the value was chosen by the library rather than by us, and would change silently underneath us if Paho changed it.It also needs to stay below the 60s that
Mqtt.connectwaits for the CONNECT to be acknowledged. If Paho were given as much time as the outer wait, a connection that cannot be established would surface as the outer wait expiring, reporting onlyTimed out waiting for a response from the server— exactly the unhelpful message the recenttokenRenewalWorksfailures came back with.It is now derived from
Mqtt.CONNECTION_TIMEOUTso the two cannot drift. The value works out to 30s, which is what Paho was already applying, so behaviour is unchanged today.constructorSetsConnectTimeoutShorterThanTheOverallConnectTimeoutverifies the call and asserts the relationship holds. Deleting thesetConnectionTimeoutline fails it withMissingInvocation.3.
CanOpenConnectiontiming out with no diagnosticsThe work item originally described this as a race between the SDK's 60s timeout and the test's
@Test(timeout = 60000), fixable by changing one of the numbers. That was my own diagnosis and it was wrong.These tests call
open(true), and the default retry policy isExponentialBackoffWithJitterwithretryCount = Integer.MAX_VALUE. A connection that never succeeds is never abandoned, so the client never throws. Nothing ends the test but the JUnit timeout, and no timeout value changes that — raising it would only make it take longer to say:The reason is only visible through the connection status change callback, so the two tests that open a client now register one and log every transition with reason and cause.
4. Skipped tests all said the same thing
Seven rules decide whether an integration test runs, and every one skipped with
"Test is ignored", so a skipped test told you nothing about which rule fired or why. Each now names the annotation or environment variable responsible, following whatErrInjTestRulealready did.I deliberately did not enable
@FlakeyTesttests in PR builds. Turning known-flaky tests back on would make PR builds less reliable, which is the opposite of the point. Only four tests are affected, and they still run in non-PR builds.Verification
iot-device-clientunit tests: 959 + 1 new = 0 failures on JDK 8.MissingInvocationwhen the fix is removed.CanOpenConnectionpassed 28/28 variants on every JDK in CI on the previous push, confirming the status-callback change is sound.mvn -pl iot-e2e-tests/common -am test-compileon JDK 8: BUILD SUCCESS; POM parses withparallel=both,threadCount=6,useUnlimitedThreadsremoved.Note on the earlier red run: the three failures on the previous push were a Maven Central TLS failure (Windows), emulator DNS failure (Android), and
tokenRenewalWorks— i.e. two infra flakes and the very issue item 1 above addresses.