fix: http call waiting for idle connection monitor to finish #1178

0marperez · 2024-11-11T22:16:45Z

Issue #

Original issue that sparked idle connection monitoring: aws/aws-sdk-kotlin#1214
OkHttp4 was broken by idle connection monitoring: #1176

Description of changes

Launching the connection monitors using the call context was causing the call to wait on the connection monitor coroutines. This fix creates a coroutine scope dedicated to connection monitors. This new scope will be cancelled/joined when the HTTP engine being used is closed.
Noticed shutdown was missing from OkHttp4Engine so added it.
The refactoring of OkHttpEngineConfig.buildClient fixes OkHttp4 Support Broken Due to Idle Connection PR #1176 by not including connectionListener as part of OkHttp4Engine

Calling S3 getObject twice went from taking ~6 sec to ~370ms

By submitting this pull request, I confirm that my contribution is made under the terms of the Apache 2.0 license.

ianbotsf · 2024-11-12T23:49:16Z

runtime/protocol/http-client-engines/http-client-engine-okhttp/build.gradle.kts


        all {
            languageSettings.optIn("aws.smithy.kotlin.runtime.InternalApi")
+            languageSettings.optIn("okhttp3.ExperimentalOkHttpApi")


Correctness: We should generally not opt into experimental/internal annotations we don't own across entire modules. Our opt-ins should be narrowly scoped and intentional. Please remove this and add @OptIn(ExperimentalOkHttpApi::class) on the specific methods or lines that require the opt-in.

ianbotsf · 2024-11-12T23:57:07Z

...-engine-okhttp/jvm/src/aws/smithy/kotlin/runtime/http/engine/okhttp/ConnectionIdleMonitor.kt


-@OptIn(ExperimentalOkHttpApi::class)
 internal class ConnectionIdleMonitor(val pollInterval: Duration) : ConnectionListener() {
+    private val monitorScope = CoroutineScope(Dispatchers.IO + SupervisorJob())


Question: HTTP engines have their own coroutine scope. Could we reuse that as a parent scope instead of creating a new one from scratch?

I think so, let me test this.

I'm seeing some issues trying to use the HTTP engine scope. We try to wait for the HTTP engine job to complete before calling shutdown. And that make us wait on the connection idle monitor to just fail it seems like, since it's running in a while loop.

Hmm, that's unfortunate. We could probably structure engine closure a bit better to allow for child scopes/jobs but that's a bigger and riskier change. We can stick with this for now.

ianbotsf · 2024-11-13T00:01:31Z

...-engine-okhttp/jvm/src/aws/smithy/kotlin/runtime/http/engine/okhttp/ConnectionIdleMonitor.kt

+    fun close(): Unit = runBlocking {
+        monitors.values.forEach { it.cancelAndJoin() }
+        monitorScope.cancel()
+    }
+


Question: Cancelling/joining child jobs sequentially in a loop is time-consuming. Moreover, the docs say that cancelling a parent job (even a SupervisorJob) should automatically cancel all child jobs. Does this code accomplish the same thing?

fun close(): Unit = runBlocking { monitorScope.cancel() }

The difference is that we're not waiting for the child jobs to actually finish cancelling (join). So we could be leaving some resources behind.

I think it should improve performance if we just cancel and don't wait for a join. It shouldn't be an issue unless someone is using a lot of clients.

I tested this and time to cancel the connection idle monitor(s) went from ~200ms to ~600us. Now that I think of it, if someone is opening and closing clients very often and with a lot of connections per client then not waiting for the connection monitors to join could be a bigger issue.

Ah I see, you're right that could be an issue. So then how about:

fun close(): Unit = runBlocking { monitorScope.cancelAndJoin() }

Unfortunately there's no cancelAndJoin for CoroutineScope, only Job.

Oh jeez you're right. Well the CoroutineScope.cancel() method implementation pretty much just verifies the scope contains a job and then calls cancel on that job. We can do something similar here:

val monitorJob = requireNotNull(monitorScope.coroutineContext[Job]) { "<some error msg>" } monitorJob.cancelAndJoin()

ianbotsf · 2024-11-13T00:08:44Z

...tp-client-engine-okhttp/jvm/src/aws/smithy/kotlin/runtime/http/engine/okhttp/OkHttpEngine.kt


    private val metrics = HttpClientMetrics(TELEMETRY_SCOPE, config.telemetryProvider)
-    private val client = config.buildClient(metrics)
+    private val connectionIdleMonitor = if (config.connectionIdlePollingInterval != null) ConnectionIdleMonitor(config.connectionIdlePollingInterval) else null


Nit:

private val connectionIdleMonitor = config.connectionIdlePollingInterval?.let { ConnectionIdleMonitor(it) }

ianbotsf · 2024-11-13T00:16:08Z

...tp-client-engine-okhttp/jvm/src/aws/smithy/kotlin/runtime/http/engine/okhttp/OkHttpEngine.kt

-        @OptIn(ExperimentalOkHttpApi::class)
-        val connectionListener = if (config.connectionIdlePollingInterval == null) {
-            ConnectionListener.NONE
-        } else {
-            ConnectionIdleMonitor(connectionIdlePollingInterval)
-        }
-
        // use our own pool configured with the timeout settings taken from config
-        @OptIn(ExperimentalOkHttpApi::class)
        val pool = ConnectionPool(
            maxIdleConnections = 5, // The default from the no-arg ConnectionPool() constructor
            keepAliveDuration = config.connectionIdleTimeout.inWholeMilliseconds,
            TimeUnit.MILLISECONDS,
-            connectionListener = connectionListener,
        )
-        connectionPool(pool)
+        connectionPool(poolOverride ?: pool)


Nit: With this change we're now constructing a ConnectionPool we'll just throw away if poolOverride is set. We should only construct the OkHttp4-safe pool if poolOverride is null.

lauzadis · 2024-11-13T16:35:35Z

...-engine-okhttp/jvm/src/aws/smithy/kotlin/runtime/http/engine/okhttp/ConnectionIdleMonitor.kt

                logger.trace { "Attempting to reset soTimeout..." }
                try {
                    conn.socket().soTimeout = oldTimeout
+                    logger.trace { "SoTimeout reset." }


nit: soTimeout

lauzadis · 2024-11-13T16:38:41Z

...client-engine-okhttp4/jvm/src/aws/smithy/kotlin/runtime/http/engine/okhttp4/OkHttp4Engine.kt

+    override fun shutdown() {
+        client.connectionPool.evictAll()
+        client.dispatcher.executorService.shutdown()
+        metrics.close()
+    }


ianbotsf

Approved pending cancelAndJoin feedback.

github-actions · 2024-11-14T16:02:50Z

Affected Artifacts

Changed in size

Artifact	Pull Request (bytes)	Latest Release (bytes)	Delta (bytes)	Delta (percentage)
http-client-engine-okhttp-jvm.jar	115,427	112,330	3,097	2.76%
http-client-engine-okhttp4-jvm.jar	14,324	14,095	229	1.62%

0marperez added 2 commits November 11, 2024 17:03

fix: http call waiting for idle connection monitor to finish

ac87eab

lint

330353e

0marperez added the no-changelog Indicates that a changelog entry isn't required for a pull request. Use sparingly. label Nov 11, 2024

This comment has been minimized.

Sign in to view

0marperez marked this pull request as ready for review November 11, 2024 22:32

0marperez requested a review from a team as a code owner November 11, 2024 22:32

ianbotsf requested changes Nov 13, 2024

View reviewed changes

PR feedback

38e3cf2

This comment has been minimized.

Sign in to view

lauzadis approved these changes Nov 13, 2024

View reviewed changes

SoTimeout -> soTimeout in logs

6ef2a48

This comment has been minimized.

Sign in to view

ianbotsf approved these changes Nov 13, 2024

View reviewed changes

Cancel and join monitor job

3b23c49

0marperez merged commit 20d93fc into main Nov 14, 2024
16 checks passed

0marperez deleted the connection-idle-monitor-latency branch November 14, 2024 16:32

fix: http call waiting for idle connection monitor to finish #1178

fix: http call waiting for idle connection monitor to finish #1178

Uh oh!

Conversation

0marperez commented Nov 11, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Issue #

Description of changes

Uh oh!

This comment has been minimized.

This comment has been minimized.

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

0marperez Nov 13, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

This comment has been minimized.

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

This comment has been minimized.

ianbotsf left a comment

Choose a reason for hiding this comment

Uh oh!

github-actions bot commented Nov 14, 2024

Affected Artifacts

Uh oh!

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

3 participants

0marperez commented Nov 11, 2024 •

edited

Loading

0marperez Nov 13, 2024 •

edited

Loading