diff --git a/okhttp-coroutines/build.gradle.kts b/okhttp-coroutines/build.gradle.kts index c6ed8a804bb8..97eb90572741 100644 --- a/okhttp-coroutines/build.gradle.kts +++ b/okhttp-coroutines/build.gradle.kts @@ -6,6 +6,7 @@ plugins { id("org.jetbrains.dokka") id("com.vanniktech.maven.publish.base") id("binary-compatibility-validator") + id("app.cash.burst") } project.applyOsgi( diff --git a/okhttp-coroutines/src/test/kotlin/okhttp3/coroutines/Bug9191ReproTest.kt b/okhttp-coroutines/src/test/kotlin/okhttp3/coroutines/Bug9191ReproTest.kt new file mode 100644 index 000000000000..23c9e5d0cb38 --- /dev/null +++ b/okhttp-coroutines/src/test/kotlin/okhttp3/coroutines/Bug9191ReproTest.kt @@ -0,0 +1,151 @@ +package okhttp3.coroutines + +import app.cash.burst.Burst +import assertk.assertThat +import assertk.assertions.isLessThan +import java.io.IOException +import java.net.InetAddress +import java.net.InetSocketAddress +import java.net.Proxy +import java.net.ServerSocket +import java.time.Duration +import java.time.Instant +import java.util.concurrent.Executors +import kotlinx.coroutines.runBlocking +import okhttp3.Call +import okhttp3.Dns +import okhttp3.EventListener +import okhttp3.OkHttpClient +import okhttp3.Request +import org.junit.jupiter.api.AfterEach +import org.junit.jupiter.api.Test + +@Burst +class ReproduceOkHttpIssueTest { + val executorService = Executors.newFixedThreadPool(2) + val stallingServer = StallingServer() + + // 1. Define Hostname + val proxyHost = "unresponsive-proxy-host" + + // 2. Set Timeouts + val callTimeout = Duration.ofSeconds(3) + val connectTimeout = Duration.ofSeconds(1) + val readTimeout = Duration.ofSeconds(2) + + // 3. Build the Client with the Custom Dns + var client = OkHttpClient.Builder() + .callTimeout(callTimeout) + .connectTimeout(connectTimeout) + .readTimeout(readTimeout) + .dns(Dns { hostname: String? -> + if (hostname == proxyHost) + listOf(InetAddress.getByName("127.0.0.1"), InetAddress.getByName("127.0.0.1")) + else + Dns.Companion.SYSTEM.lookup(hostname!!) + }) + .eventListener(object : EventListener() { + override fun connectStart(call: Call, inetSocketAddress: InetSocketAddress, proxy: Proxy) { + println( + "connect start - %s - inetSocketAddress: %s, proxy: %s".format( + call.request().url, + inetSocketAddress, + proxy + ) + ) + } + }) + .proxy(Proxy(Proxy.Type.HTTP, InetSocketAddress.createUnresolved(proxyHost, 8080))) + .build() + + // 4. Test the Call + val request = Request.Builder().url("https://github.com/").build() // Any valid target URL which is https + + @AfterEach + fun close() { + executorService.shutdownNow() + stallingServer.stop() + } + + @Test + @Throws(InterruptedException::class) + fun test(execute: Boolean = true, increasedReadTimeout: Boolean = false) { + if (increasedReadTimeout) { + client = client.newBuilder() + .readTimeout(readTimeout.multipliedBy(2)) + .build() + } + + executorService.submit(Runnable { stallingServer.start(8080) }) + Thread.sleep(2000) + + val startTime = Instant.now() + + try { + if (execute) { + client.newCall(request).execute().use { response -> + println("Call Succeeded unexpectedly.") + } + } else { + runBlocking { client.newCall(request).executeAsync() }.use { response -> + println("Call Succeeded unexpectedly.") + } + } + } catch (e: Exception) { + val totalTime = Duration.between(startTime, Instant.now()) + println("--- TEST RESULT ---") + println("Exception: " + e.javaClass.getName() + ": " + e.message) + println("Total Time: $totalTime") + println("Expected Time (Call Timeout): $callTimeout") + println("Observed Time (2 x Read Timeout): " + readTimeout.multipliedBy(2)) + assertThat(totalTime).isLessThan(readTimeout.multipliedBy(2)) + } + } + + class StallingServer { + private lateinit var serverSocket: ServerSocket + + fun start(port: Int) { + try { + serverSocket = ServerSocket(port) + serverSocket.use { serverSocket -> + println("Java server listening on port $port") + while (true) { + val clientSocket = serverSocket.accept() + println("Connection accepted from " + clientSocket.getInetAddress()) + + Thread(Runnable { + try { + clientSocket.use { sock -> + // 1. Read the client's initial request (e.g., "CONNECT google.com:443 HTTP/1.1") + val `in` = sock.getInputStream() + val buffer = ByteArray(1024) + val bytesRead = `in`.read(buffer) + println("Received $bytesRead bytes. Now stalling...") + + // 2. Respond with "200 OK" to open the tunnel (Critical step for TLS simulation) + val successResponse = "HTTP/1.1 200 Connection established\r\n\r\n" + sock.getOutputStream().write(successResponse.toByteArray()) + sock.getOutputStream().flush() + println("Tunnel established on port $port. Now stalling (TLS Handshake)...") + + // 3. Block this thread indefinitely. + // The OkHttp client will now send the TLS ClientHello and hit the Read Timeout (10s) waiting for the ServerHello. + Thread.sleep(Long.Companion.MAX_VALUE) + } + } catch (e: Exception) { + System.err.println("Connection handling error: " + e.message) + } + }).start() + } + } + } catch (e: IOException) { + throw RuntimeException(e) + } + } + + fun stop() { + serverSocket.close() + } + } +} diff --git a/okhttp/src/commonJvmAndroid/kotlin/okhttp3/internal/connection/RealCall.kt b/okhttp/src/commonJvmAndroid/kotlin/okhttp3/internal/connection/RealCall.kt index e2a4f7381024..48cfb3a5668f 100644 --- a/okhttp/src/commonJvmAndroid/kotlin/okhttp3/internal/connection/RealCall.kt +++ b/okhttp/src/commonJvmAndroid/kotlin/okhttp3/internal/connection/RealCall.kt @@ -19,6 +19,7 @@ import java.io.IOException import java.io.InterruptedIOException import java.lang.ref.WeakReference import java.net.Socket +import java.time.LocalTime import java.util.concurrent.CopyOnWriteArrayList import java.util.concurrent.ExecutorService import java.util.concurrent.RejectedExecutionException @@ -28,6 +29,8 @@ import java.util.concurrent.atomic.AtomicInteger import java.util.concurrent.atomic.AtomicReference import java.util.concurrent.atomic.AtomicReferenceFieldUpdater import kotlin.reflect.KClass +import kotlin.time.Duration.Companion.milliseconds +import kotlin.time.Duration.Companion.nanoseconds import okhttp3.Call import okhttp3.Callback import okhttp3.EventListener @@ -76,11 +79,19 @@ class RealCall( private val timeout = object : AsyncTimeout() { + override fun timedOut() { + Exception("Timeout").printStackTrace() + println("RealCall: Timed out ${LocalTime.now()}") this@RealCall.cancel() } + + override fun toString(): String { + return "RealCall.timeout ${this.timeoutNanos().nanoseconds.inWholeSeconds}" + } }.apply { timeout(client.callTimeoutMillis.toLong(), MILLISECONDS) + println("RealCall: new timeout $this ${LocalTime.now()} " + client.callTimeoutMillis.milliseconds.inWholeSeconds) } private val executed = AtomicBoolean() @@ -180,6 +191,7 @@ class RealCall( override fun execute(): Response { check(executed.compareAndSet(false, true)) { "Already Executed" } + println("RealCall: execute ${LocalTime.now()}") timeout.enter() callStart() try { @@ -465,6 +477,7 @@ class RealCall( private fun timeoutExit(cause: IOException?): IOException? { if (timeoutEarlyExit) return cause + println("RealCall: timeoutExit ${LocalTime.now()}") if (!timeout.exit()) return cause val e = InterruptedIOException("timeout") @@ -479,6 +492,7 @@ class RealCall( fun timeoutEarlyExit() { check(!timeoutEarlyExit) timeoutEarlyExit = true + println("RealCall: exit ${LocalTime.now()}") timeout.exit() } @@ -578,6 +592,7 @@ class RealCall( override fun run() { threadName("OkHttp ${redactedUrl()}") { var signalledCallback = false + println("RealCall: timeout enter ${LocalTime.now()}") timeout.enter() try { val response = getResponseWithInterceptorChain()