[
https://issues.apache.org/jira/browse/HTTPCLIENT-2301?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=17770097#comment-17770097
]
Pierre N. edited comment on HTTPCLIENT-2301 at 9/28/23 3:09 PM:
----------------------------------------------------------------
I expected this kind of response because that's exactly what I thought when I
encountered this bug...
For the story, I discovered this bug in production with
[Serposcope|https://www.serposcope.com/en/]. One of my user had [inverted
response|https://forum.serposcope.com/d/101-error-with-scrapingant-api], when
sending a request to Google it would sometimes have the response of a previous
request.
It was hell to debug... To the point I suspected, like you, the server was
responsible for this. I would never have expected a library I have been using
for a decade to have such bug.
But in my production code I don't use Wiremock... I just used it to
troubleshooting and reproduce this bug.
But here you go, the same bug using httpbin.org, no mocking :
{color:#0033b3}internal class
{color}{color:#000000}HttpClientRaceConditionDebug {color}{
{color:#9e880d}@Test{color}{color:#9e880d} {color}{color:#0033b3}fun
{color}{color:#00627a}bugbug{color}() {
{color:#0033b3}val {color}{color:#000000}client {color}=
{color:#000000}HttpClients{color}.custom()
.setConnectionManager(BasicHttpClientConnectionManager())
{color:#8c8c8c}//
.setConnectionManager(PoolingHttpClientConnectionManager()){color}
.setDefaultRequestConfig(
{color:#000000}RequestConfig{color}.custom()
.setResponseTimeout({color:#000000}Timeout{color}.ofSeconds({color:#1750eb}1{color}))
.build()
)
.build()
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?1"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/delay/2?2"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/delay/2?2"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?3"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?3"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?3"{color})
}
{color:#0033b3}private fun
{color}{color:#000000}CloseableHttpClient{color}.{color:#00627a}executeAndLog{color}(uri:
{color:#000000}String{color}) {
{color:#0033b3}try {color}{
execute(HttpGet({color:#000000}uri{color})) {
{color:#00627a}println{color}({color:#067d17}"{color}{color:#0037a6}${color}uri{color}{color:#067d17}
->
{color}{color:#0037a6}${{color}{color:#000000}EntityUtils{color}.toString(it.{color:#871094}entity{color}).{color:#00627a}split{color}({color:#067d17}"{color}{color:#0037a6}\n{color}{color:#067d17}"{color}).{color:#00627a}filter
{color}{ it.{color:#00627a}contains{color}({color:#067d17}"url"{color})
}\{color:#0037a6}}") }
} {color:#0033b3}catch {color}({color:#000000}ex{color}:
{color:#000000}Exception{color}) {
{color:#00627a}println{color}({color:#067d17}"{color}{color:#0037a6}${color}uri{color}{color:#067d17}
-> {color}{color:#0037a6}${color}ex{color}{color:#067d17}"{color})
}
}
}
It returns:
{quote}[https://httpbin.org/anything?1] -> [ "url":
"https://httpbin.org/anything?1";]
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/anything?3] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/delay/2?2";]
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
{quote}
Replace with PoolingHttpClientConnectionManager and it will work correctly :
{quote}[https://httpbin.org/anything?1] -> [ "url":
"https://httpbin.org/anything?1";]
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
{quote}
Do you think the bug is also on httpbin.org ? :D
was (Author: pierz):
I expected this kind of response because that's exactly what I thought when I
encountered this bug...
For the story, I discovered this bug in production with
[Serposcope|http://atlassian.com/]. One of my user had [inverted
response|https://forum.serposcope.com/d/101-error-with-scrapingant-api], when
sending a request to Google it would sometimes have the response of a previous
request.
It was hell to debug... To the point I suspected, like you, the server was
responsible for this. I would never have expected a library I have been using
for a decade to have such bug.
But in my production code I don't use Wiremock... I just used it to
troubleshooting and reproduce this bug.
But here you go, the same bug using httpbin.org, no mocking :
{color:#0033b3}internal class
{color}{color:#000000}HttpClientRaceConditionDebug {color}{
{color:#9e880d}@Test{color}{color:#9e880d} {color}{color:#0033b3}fun
{color}{color:#00627a}bugbug{color}() {
{color:#0033b3}val {color}{color:#000000}client {color}=
{color:#000000}HttpClients{color}.custom()
.setConnectionManager(BasicHttpClientConnectionManager())
{color:#8c8c8c}//
.setConnectionManager(PoolingHttpClientConnectionManager()){color}
.setDefaultRequestConfig(
{color:#000000}RequestConfig{color}.custom()
.setResponseTimeout({color:#000000}Timeout{color}.ofSeconds({color:#1750eb}1{color}))
.build()
)
.build()
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?1"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/delay/2?2"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/delay/2?2"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?3"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?3"{color})
{color:#000000}client{color}.{color:#00627a}executeAndLog{color}({color:#067d17}"https://httpbin.org/anything?3"{color})
}
{color:#0033b3}private fun
{color}{color:#000000}CloseableHttpClient{color}.{color:#00627a}executeAndLog{color}(uri:
{color:#000000}String{color}) {
{color:#0033b3}try {color}{
execute(HttpGet({color:#000000}uri{color})) {
{color:#00627a}println{color}({color:#067d17}"{color}{color:#0037a6}${color}uri{color}{color:#067d17}
->
{color}{color:#0037a6}${{color}{color:#000000}EntityUtils{color}.toString(it.{color:#871094}entity{color}).{color:#00627a}split{color}({color:#067d17}"{color}{color:#0037a6}\n{color}{color:#067d17}"{color}).{color:#00627a}filter
{color}{ it.{color:#00627a}contains{color}({color:#067d17}"url"{color})
}\{color:#0037a6}}") }
} {color:#0033b3}catch {color}({color:#000000}ex{color}:
{color:#000000}Exception{color}) {
{color:#00627a}println{color}({color:#067d17}"{color}{color:#0037a6}${color}uri{color}{color:#067d17}
-> {color}{color:#0037a6}${color}ex{color}{color:#067d17}"{color})
}
}
}
It returns:
{quote}[https://httpbin.org/anything?1] -> [ "url":
"https://httpbin.org/anything?1";]
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/anything?3] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/delay/2?2";]
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
{quote}
Replace with PoolingHttpClientConnectionManager and it will work correctly :
{quote}[https://httpbin.org/anything?1] -> [ "url":
"https://httpbin.org/anything?1";]
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/delay/2?2] -> java.net.SocketTimeoutException: Read timed
out
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
[https://httpbin.org/anything?3] -> [ "url": "https://httpbin.org/anything?3";]
{quote}
Do you think the bug is also on httpbin.org ? :D
> BasicHttpClientConnectionManager returns response of previous requests
> ----------------------------------------------------------------------
>
> Key: HTTPCLIENT-2301
> URL: https://issues.apache.org/jira/browse/HTTPCLIENT-2301
> Project: HttpComponents HttpClient
> Issue Type: Bug
> Components: HttpClient (classic)
> Affects Versions: 5.2.1, 5.3-alpha1
> Environment: JAVA 18
> kotlin 1.7.22
> Ubuntu 22.04 x64
> Reporter: Pierre N.
> Priority: Major
> Attachments: test.kt
>
>
> BasicHttpClientConnectionManager doesn't handle request timeout correctly and
> return the response of a previous request.
> The unit test below should output:
> {quote}
> http://localhost:41751/1 -> 1
> http://localhost:41751/2 -> java.net.SocketTimeoutException: Read timed out
> http://localhost:41751/2 -> java.net.SocketTimeoutException: Read timed out
> http://localhost:41751/3 -> 3
> http://localhost:41751/3 -> 3
> http://localhost:41751/3 -> 3
> {quote}
> But instead it returns:
> {quote}
> http://localhost:33875/1 -> 1
> http://localhost:33875/2 -> java.net.SocketTimeoutException: Read timed out
> http://localhost:33875/2 -> java.net.SocketTimeoutException: Read timed out
> http://localhost:33875/3 -> java.net.SocketTimeoutException: Read timed out
> http://localhost:33875/3 -> 2
> http://localhost:33875/3 -> 3
> {quote}
> As you can see it returns 2 when requesting the uri /3 which returned 3.
> Also it timeout on the first request to /3 while it shouldn't.
> Replace with PoolingHttpClientConnectionManager() and it works as expected.
> Kotlin unit test to reproduce :
> {quote}
> import com.github.tomakehurst.wiremock.client.WireMock.*
> import com.github.tomakehurst.wiremock.junit5.WireMockRuntimeInfo
> import com.github.tomakehurst.wiremock.junit5.WireMockTest
> import org.apache.hc.client5.http.classic.methods.HttpGet
> import org.apache.hc.client5.http.config.RequestConfig
> import org.apache.hc.client5.http.impl.classic.CloseableHttpClient
> import org.apache.hc.client5.http.impl.classic.HttpClients
> import org.apache.hc.client5.http.impl.io.BasicHttpClientConnectionManager
> import org.apache.hc.core5.http.io.entity.EntityUtils
> import org.apache.hc.core5.util.Timeout
> import org.junit.jupiter.api.Test
> @WireMockTest
> internal class HttpClientRaceConditionDebug {
> @Test
> fun `debugging z`(wm: WireMockRuntimeInfo) {
> stubFor(get(urlEqualTo("/1")).willReturn(aResponse().withBody("1")))
>
> stubFor(get(urlEqualTo("/2")).willReturn(aResponse().withFixedDelay(2000).withBody("2")))
> stubFor(get(urlEqualTo("/3")).willReturn(aResponse().withBody("3")))
> val client = HttpClients.custom()
> .setConnectionManager(BasicHttpClientConnectionManager())
> // .setConnectionManager(PoolingHttpClientConnectionManager())
> .setDefaultRequestConfig(
> RequestConfig.custom()
> .setResponseTimeout(Timeout.ofSeconds(1))
> .build()
> )
> .build()
> client.executeAndLog("${wm.httpBaseUrl}/1")
> client.executeAndLog("${wm.httpBaseUrl}/2")
> client.executeAndLog("${wm.httpBaseUrl}/2")
> client.executeAndLog("${wm.httpBaseUrl}/3")
> client.executeAndLog("${wm.httpBaseUrl}/3")
> client.executeAndLog("${wm.httpBaseUrl}/3")
> }
> private fun CloseableHttpClient.executeAndLog(uri: String) {
> try {
> execute(HttpGet(uri)) { println("$uri ->
> ${EntityUtils.toString(it.entity)}") }
> } catch (ex: Exception) {
> println("$uri -> $ex")
> }
> }
> }
> {quote}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscr...@hc.apache.org
For additional commands, e-mail: dev-h...@hc.apache.org
