Skip to content

When Request Method is "HEAD" and setFollowRedirect is set to true. The method of the second redirect request is GET. #1728

Closed
#1736
Closed
When Request Method is "HEAD" and setFollowRedirect is set to true. The method of the second redirect request is GET.#1728
#1736
Assignees
TomGranot
Milestone
2.12.3

Description

@lakxtxue
lakxtxue
opened on Jun 20, 2020

When Request Method is "HEAD" and setFollowRedirect is set to true. The method of the second redirect request is GET.
When I download a large file, it will time out here, in fact it has been downloading

Caused by: java.util.concurrent.TimeoutException: Request timeout to 127.0.0.1/127.0.0.1:8888 after 60000 ms at org.asynchttpclient.netty.timeout.TimeoutTimerTask.expire(TimeoutTimerTask.java:43) at org.asynchttpclient.netty.timeout.RequestTimeoutTimerTask.run(RequestTimeoutTimerTask.java:50) at io.netty.util.HashedWheelTimer$HashedWheelTimeout.expire(HashedWheelTimer.java:672) at io.netty.util.HashedWheelTimer$HashedWheelBucket.expireTimeouts(HashedWheelTimer.java:747) at io.netty.util.HashedWheelTimer$Worker.run(HashedWheelTimer.java:472) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.base/java.lang.Thread.run(Thread.java:834)

Activity

  1. TomGranot commented on Aug 23, 2020

    @TomGranot
    TomGranot
    on Aug 23, 2020
    Contributor

    @lakxtxue hi - I've applied to maintain this library, so I'm taking a look at open issues to see whether I can maybe help out.

    As a general note, a paste of the code tends to help in these issues - if not for better comprehension then at least to save a few lines of reproduction:)

    Just to make sure I follow: you've got a large resource located at urlA. When dispatching a HEAD request to urlA, you're getting back a 301 that points to urlB, which is followed because setFollowRedirect is set to true. The request to urlB is not a HEAD but a GET.

    Since the resource hiding behind urlA (and in effect, urlB) is quite large, you're getting a timeout instead of getting a response back from urlB.

    What I assume you'd like to happen is for the same request type that was originally dispatched to be used in the followup requests as well.

    Is this a correct assessment?

  2. lakxtxue commented on Aug 24, 2020

    @lakxtxue
    lakxtxue
    on Aug 24, 2020
    Author

    @Tomgs hi, yes, that's what I mean, because I use http to download large files, I need to get the size of the file first. When accessing this file resource, there will be a redirection to the real address. I use the HEAD request method to get the file size. AsyncHttpClient encounters a 301 When it was directed, it did not continue to access with a HEAD request but used a GET request to access the redirected address. Now I use HttpURLConnection instead, and I get the result I want correctly.
    This is my code using HttpURLConnection

    URL u = new URL(url);
HttpURLConnection httpConnection = (HttpURLConnection) u.openConnection();
httpConnection.setRequestMethod("HEAD");
httpConnection.connect();
this.dataSize = httpConnection.getContentLengthLong();

    I used AsyncHttpClient to do the same thing. I also set the HEAD request method and configured setFollowRedirect to true. The result was a timeout. I found through packet capture that AsyncHttpClient used GET request when redirecting and started to download files. I hope it will behave like HttpURLConnection.

    I don’t know if the expression is clear or not, because my English is not very good. I have found a lot of http libraries. AsyncHttpClient is the only one that can provide me with the greatest flexibility. I really hope it will get better and better.

  3. TomGranot commented on Aug 24, 2020

    @TomGranot
    TomGranot
    on Aug 24, 2020
    Contributor

    @lakxtxue I see what you're saying, and it's perfectly clear. Your English is much better than many of the non-native English speakers I've met (I'm also not a native speaker, btw!).

    I actually wasn't sure what the HTTP protocol specification says about method handling in redirects.

    I didn't go to the spec itself, but MDN says that when a user-agent (like AsyncHttpClient) sends a request and encounters a 301, only GET requests remain unchanged, an the rest of the HTTP methods "may or may not be changed".

    I am still familiarising myself with the library, but an initial search seems to show that it's related to the underlying Netty provider this library is using.

    I'd say that it's reasonable for the method to persist between redirects, but would have to dig deeper later tonight to see how it can be actually implemented and open a PR. If I forget to follow up please ping me in a few days!

  4. TomGranot commented on Aug 24, 2020

    @TomGranot
    TomGranot
    on Aug 24, 2020
    Contributor

    Alright, so I think I found the culprit (not sure why it's not embedding the code lines properly):

    https://github.com/TomGranot/async-http-client/blob/master/client/src/main/java/org/asynchttpclient/netty/handler/intercept/Redirect30xInterceptor.java#L88-L91

    It basically switches to GET if the original method was not GET and a redirect was encountered. The logic there is too intricate to be added as an afterthought - but looking at the original history here doesn't give much of a clue as the original file was in a different location (client/src/main/java/org/asynchttpclient/netty/handler/Redirect30xHandler.java).

    Will dig a little further and get to the root of this - @slandelle this was before your time, but if there's any chance you remember why there's a default to GET for requests I would appreciate a lead (although this is very old).

  5. TomGranot commented on Aug 24, 2020

    @TomGranot
    TomGranot
    on Aug 24, 2020
    Contributor

    So I asked around and received other use cases where it makes sense to have a the next request in the cycle be a GET instead. I think this can be easily solved by adding another config option for the RequestBuilder called persistMethodBetweenRedirects that will basically allow you to do HEAD all the way if you wanted to.

    I'll write a PR in a bit tomorrow, made the change but need to modify tests (and maybe write a couple more).

  6. slandelle commented on Aug 24, 2020

    @slandelle
    slandelle
    on Aug 24, 2020
    Contributor

    Here’s what I do in Gatling: gatling/gatling@a87729b

  7. TomGranot commented on Aug 24, 2020

    @TomGranot
    TomGranot
    on Aug 24, 2020
    Contributor

    Ah, that makes sense, this way you allow it for HEAD and OPTIONS but disallow it for POST that can pass too much information away. Thanks @slandelle!

  8. TomGranot commented on Aug 31, 2020

    @TomGranot
    TomGranot
    on Aug 31, 2020
    Contributor

    Still need to open a PR, just not getting to it. Will do so sometime this week (need to re-write the tests so Maven won't be angry).

  9. TomGranot commented on Sep 28, 2020

    @TomGranot
    TomGranot
    on Sep 28, 2020
    Contributor

    Out of the two failing tests, one of them - AsyncStreamHandlerTest.asyncOptionsTest() - is flaky (see #1735).

    That leaves us with one problematic test, Head302Test.testHEAD302(), which hits this:

    java.util.concurrent.ExecutionException: org.asynchttpclient.handler.MaxRedirectException: Maximum redirect reached: 5

    Looking now. Full test dump shows that fixing the interceptor with @slandelle's fix works fine - each following request is a HEAD:

    2020-09-28 15:01:45,288 [main] DEBUG io.netty.util.internal.logging.InternalLoggerFactory - Using SLF4J as the default logging framework
2020-09-28 15:01:45,290 [main] DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetection.level: simple
2020-09-28 15:01:45,290 [main] DEBUG io.netty.util.ResourceLeakDetector - -Dio.netty.leakDetection.targetRecords: 4
2020-09-28 15:01:45,293 [main] DEBUG io.netty.util.ResourceLeakDetectorFactory - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@708f5957
2020-09-28 15:01:45,304 [main] DEBUG io.netty.util.internal.PlatformDependent - Platform: MacOS
2020-09-28 15:01:45,305 [main] DEBUG io.netty.util.internal.PlatformDependent0 - -Dio.netty.noUnsafe: false
2020-09-28 15:01:45,305 [main] DEBUG io.netty.util.internal.PlatformDependent0 - Java version: 8
2020-09-28 15:01:45,306 [main] DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.theUnsafe: available
2020-09-28 15:01:45,306 [main] DEBUG io.netty.util.internal.PlatformDependent0 - sun.misc.Unsafe.copyMemory: available
2020-09-28 15:01:45,306 [main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Buffer.address: available
2020-09-28 15:01:45,306 [main] DEBUG io.netty.util.internal.PlatformDependent0 - direct buffer constructor: available
2020-09-28 15:01:45,307 [main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.Bits.unaligned: available, true
2020-09-28 15:01:45,307 [main] DEBUG io.netty.util.internal.PlatformDependent0 - jdk.internal.misc.Unsafe.allocateUninitializedArray(int): unavailable prior to Java9
2020-09-28 15:01:45,307 [main] DEBUG io.netty.util.internal.PlatformDependent0 - java.nio.DirectByteBuffer.<init>(long, int): available
2020-09-28 15:01:45,307 [main] DEBUG io.netty.util.internal.PlatformDependent - sun.misc.Unsafe: available
2020-09-28 15:01:45,307 [main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.tmpdir: /var/folders/yj/5yjqs2jd0b92698_fqsbs3_40000gn/T (java.io.tmpdir)
2020-09-28 15:01:45,307 [main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.bitMode: 64 (sun.arch.data.model)
2020-09-28 15:01:45,308 [main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.maxDirectMemory: 3817865216 bytes
2020-09-28 15:01:45,308 [main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.uninitializedArrayAllocationThreshold: -1
2020-09-28 15:01:45,309 [main] DEBUG io.netty.util.internal.CleanerJava6 - java.nio.ByteBuffer.cleaner(): available
2020-09-28 15:01:45,309 [main] DEBUG io.netty.util.internal.PlatformDependent - -Dio.netty.noPreferDirect: false
2020-09-28 15:01:45,315 [main] DEBUG io.netty.util.internal.PlatformDependent - org.jctools-core.MpscChunkedArrayQueue: available
2020-09-28 15:01:45,410 [main] DEBUG io.netty.handler.ssl.JdkSslContext - Default protocols (JDK): [TLSv1.2, TLSv1.1, TLSv1] 
2020-09-28 15:01:45,410 [main] DEBUG io.netty.handler.ssl.JdkSslContext - Default cipher suites (JDK): [TLS_ECDHE_ECDSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_ECDSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_128_GCM_SHA256, TLS_ECDHE_RSA_WITH_AES_256_GCM_SHA384, TLS_ECDHE_RSA_WITH_AES_128_CBC_SHA, TLS_ECDHE_RSA_WITH_AES_256_CBC_SHA, TLS_RSA_WITH_AES_128_GCM_SHA256, TLS_RSA_WITH_AES_128_CBC_SHA, TLS_RSA_WITH_AES_256_CBC_SHA]
2020-09-28 15:01:45,424 [main] DEBUG io.netty.util.internal.InternalThreadLocalMap - -Dio.netty.threadLocalMap.stringBuilder.initialSize: 1024
2020-09-28 15:01:45,424 [main] DEBUG io.netty.util.internal.InternalThreadLocalMap - -Dio.netty.threadLocalMap.stringBuilder.maxSize: 4096
2020-09-28 15:01:45,428 [main] DEBUG io.netty.channel.MultithreadEventLoopGroup - -Dio.netty.eventLoopThreads: 32
2020-09-28 15:01:45,432 [main] DEBUG io.netty.channel.nio.NioEventLoop - -Dio.netty.noKeySetOptimization: false
2020-09-28 15:01:45,432 [main] DEBUG io.netty.channel.nio.NioEventLoop - -Dio.netty.selectorAutoRebuildThreshold: 512
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numHeapArenas: 32
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.numDirectArenas: 32
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.pageSize: 8192
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxOrder: 11
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.chunkSize: 16777216
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.tinyCacheSize: 512
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.smallCacheSize: 256
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.normalCacheSize: 64
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxCachedBufferCapacity: 32768
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.cacheTrimInterval: 8192
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.cacheTrimIntervalMillis: 0
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.useCacheForAllThreads: true
2020-09-28 15:01:45,447 [main] DEBUG io.netty.buffer.PooledByteBufAllocator - -Dio.netty.allocator.maxCachedByteBuffersPerChunk: 1023
2020-09-28 15:01:45,453 [main] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.allocator.type: pooled
2020-09-28 15:01:45,453 [main] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.threadLocalDirectBufferSize: 0
2020-09-28 15:01:45,453 [main] DEBUG io.netty.buffer.ByteBufUtil - -Dio.netty.maxThreadLocalCharBufferSize: 16384
2020-09-28 15:01:45,676 [main] DEBUG io.netty.channel.DefaultChannelId - -Dio.netty.processId: 56861 (auto-detected)
2020-09-28 15:01:45,677 [main] DEBUG io.netty.util.NetUtil - -Djava.net.preferIPv4Stack: false
2020-09-28 15:01:45,677 [main] DEBUG io.netty.util.NetUtil - -Djava.net.preferIPv6Addresses: false
2020-09-28 15:01:45,679 [main] DEBUG io.netty.util.NetUtil - Loopback interface: lo0 (lo0, 0:0:0:0:0:0:0:1%lo0)
2020-09-28 15:01:45,679 [main] DEBUG io.netty.util.NetUtil - Failed to get SOMAXCONN from sysctl and file /proc/sys/net/core/somaxconn. Default: 128
2020-09-28 15:01:45,682 [main] DEBUG io.netty.channel.DefaultChannelId - -Dio.netty.machineId: ac:de:48:ff:fe:00:11:22 (auto-detected)
2020-09-28 15:01:45,717 [AsyncHttpClient-3-1] DEBUG io.netty.buffer.AbstractByteBuf - -Dio.netty.buffer.checkAccessible: true
2020-09-28 15:01:45,717 [AsyncHttpClient-3-1] DEBUG io.netty.buffer.AbstractByteBuf - -Dio.netty.buffer.checkBounds: true
2020-09-28 15:01:45,717 [AsyncHttpClient-3-1] DEBUG io.netty.util.ResourceLeakDetectorFactory - Loaded default ResourceLeakDetector: io.netty.util.ResourceLeakDetector@1394a12a
2020-09-28 15:01:45,728 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.channel.NettyConnectListener - Using new Channel '[id: 0x10f3cdd8, L:/127.0.0.1:53379 - R:localhost/127.0.0.1:53377]' for 'HEAD' to '/Test'
2020-09-28 15:01:45,747 [AsyncHttpClient-3-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxCapacityPerThread: 4096
2020-09-28 15:01:45,747 [AsyncHttpClient-3-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.maxSharedCapacityFactor: 2
2020-09-28 15:01:45,747 [AsyncHttpClient-3-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.linkCapacity: 16
2020-09-28 15:01:45,747 [AsyncHttpClient-3-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.ratio: 8
2020-09-28 15:01:45,747 [AsyncHttpClient-3-1] DEBUG io.netty.util.Recycler - -Dio.netty.recycler.delayedQueue.ratio: 8
2020-09-28 15:01:45,812 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.HttpHandler - 

Request DefaultFullHttpRequest(decodeResult: success, version: HTTP/1.1, content: EmptyByteBufBE)
HEAD /Test HTTP/1.1
host: localhost:53377
accept: */*
user-agent: AHC/2.1

Response DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 302 Found
Date: Mon, 28 Sep 2020 12:01:45 GMT
Location: /Test_moved
Content-Length: 0
Server: Jetty(9.4.18.v20190429)

2020-09-28 15:01:45,813 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Redirecting to http://localhost:53377/Test_moved
2020-09-28 15:01:45,813 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Sending redirect to http://localhost:53377/Test_moved
2020-09-28 15:01:45,814 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.request.NettyRequestSender - Using open Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 - R:localhost/127.0.0.1:53377] for HEAD '/Test_moved'
2020-09-28 15:01:45,816 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.HttpHandler - 

Request DefaultFullHttpRequest(decodeResult: success, version: HTTP/1.1, content: EmptyByteBufBE)
HEAD /Test_moved HTTP/1.1
host: localhost:53377
accept: */*
user-agent: AHC/2.1

Response DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 302 Found
Date: Mon, 28 Sep 2020 12:01:45 GMT
Location: /Test_moved_moved
Content-Length: 0
Server: Jetty(9.4.18.v20190429)

2020-09-28 15:01:45,816 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Redirecting to http://localhost:53377/Test_moved_moved
2020-09-28 15:01:45,816 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Sending redirect to http://localhost:53377/Test_moved_moved
2020-09-28 15:01:45,816 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.request.NettyRequestSender - Using open Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 - R:localhost/127.0.0.1:53377] for HEAD '/Test_moved_moved'
2020-09-28 15:01:45,817 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.HttpHandler - 

Request DefaultFullHttpRequest(decodeResult: success, version: HTTP/1.1, content: EmptyByteBufBE)
HEAD /Test_moved_moved HTTP/1.1
host: localhost:53377
accept: */*
user-agent: AHC/2.1

Response DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 302 Found
Date: Mon, 28 Sep 2020 12:01:45 GMT
Location: /Test_moved_moved_moved
Content-Length: 0
Server: Jetty(9.4.18.v20190429)

2020-09-28 15:01:45,817 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Redirecting to http://localhost:53377/Test_moved_moved_moved
2020-09-28 15:01:45,817 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Sending redirect to http://localhost:53377/Test_moved_moved_moved
2020-09-28 15:01:45,818 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.request.NettyRequestSender - Using open Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 - R:localhost/127.0.0.1:53377] for HEAD '/Test_moved_moved_moved'
2020-09-28 15:01:45,819 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.HttpHandler - 

Request DefaultFullHttpRequest(decodeResult: success, version: HTTP/1.1, content: EmptyByteBufBE)
HEAD /Test_moved_moved_moved HTTP/1.1
host: localhost:53377
accept: */*
user-agent: AHC/2.1

Response DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 302 Found
Date: Mon, 28 Sep 2020 12:01:45 GMT
Location: /Test_moved_moved_moved_moved
Content-Length: 0
Server: Jetty(9.4.18.v20190429)

2020-09-28 15:01:45,819 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Redirecting to http://localhost:53377/Test_moved_moved_moved_moved
2020-09-28 15:01:45,819 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.intercept.Redirect30xInterceptor - Sending redirect to http://localhost:53377/Test_moved_moved_moved_moved
2020-09-28 15:01:45,819 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.request.NettyRequestSender - Using open Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 - R:localhost/127.0.0.1:53377] for HEAD '/Test_moved_moved_moved_moved'
2020-09-28 15:01:45,820 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.HttpHandler - 

Request DefaultFullHttpRequest(decodeResult: success, version: HTTP/1.1, content: EmptyByteBufBE)
HEAD /Test_moved_moved_moved_moved HTTP/1.1
host: localhost:53377
accept: */*
user-agent: AHC/2.1

Response DefaultHttpResponse(decodeResult: success, version: HTTP/1.1)
HTTP/1.1 302 Found
Date: Mon, 28 Sep 2020 12:01:45 GMT
Location: /Test_moved_moved_moved_moved_moved
Content-Length: 0
Server: Jetty(9.4.18.v20190429)

2020-09-28 15:01:45,820 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.channel.ChannelManager - Closing Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 - R:localhost/127.0.0.1:53377] 
2020-09-28 15:01:45,822 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.request.NettyRequestSender - Aborting Future NettyResponseFuture{currentRetry=0,
	isDone=0,
	isCancelled=0,
	asyncHandler=org.asynchttpclient.Head302Test$1@5abf39d2,
	nettyRequest=org.asynchttpclient.netty.request.NettyRequest@59e14ed9,
	future=java.util.concurrent.CompletableFuture@34db6bb0[Not completed, 1 dependents],
	uri=http://localhost:53377/Test_moved_moved_moved_moved,
	keepAlive=true,
	redirectCount=5,
	timeoutsHolder=org.asynchttpclient.netty.timeout.TimeoutsHolder@3d17d3b2,
	inAuth=0,
	touch=1601294505820}

2020-09-28 15:01:45,823 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.request.NettyRequestSender - Maximum redirect reached: 5
org.asynchttpclient.handler.MaxRedirectException: Maximum redirect reached: 5
2020-09-28 15:01:45,824 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.AsyncCompletionHandler - Maximum redirect reached: 5
org.asynchttpclient.handler.MaxRedirectException: Maximum redirect reached: 5
2020-09-28 15:01:45,824 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.channel.ChannelManager - Closing Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 ! R:localhost/127.0.0.1:53377] 
2020-09-28 15:01:45,824 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.handler.HttpHandler - Unexpected I/O exception on channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 ! R:localhost/127.0.0.1:53377]
org.asynchttpclient.handler.MaxRedirectException: Maximum redirect reached: 5
2020-09-28 15:01:45,824 [AsyncHttpClient-3-1] DEBUG org.asynchttpclient.netty.channel.ChannelManager - Closing Channel [id: 0x10f3cdd8, L:/127.0.0.1:53379 ! R:localhost/127.0.0.1:53377] 



java.util.concurrent.ExecutionException: org.asynchttpclient.handler.MaxRedirectException: Maximum redirect reached: 5

  10. TomGranot commented on Sep 28, 2020

    @TomGranot
    TomGranot
    on Sep 28, 2020
    Contributor

    One of the really fun things about long-standing repos is that each piece of code has a rich history behind it, with various people facing the same(-ish) problem at different points in time, adding fixes and thought-nuggets into the code over the years. This seems to be exactly one of those cases - looking at https://github.com/TomGranot/async-http-client/commits/master/client/src/test/java/org/asynchttpclient/Head302Test.java reveals that this test actually has been fixed in the past.

    Specifically in our case, it seems that TomGranot@3c25a42#diff-64fc1f6f6a5d572c250342b4cdfda122 made this very test added the behaviour that causes this endless loop we're looking at right now - the Head302Hander is specifically written to keep on appending _moved to the URI and send back 302 after every 302 response.

    In plain terms, this means that the test expects a HEAD to be followed with a GET and then terminate successfully. Since we now send followup HEADs upon a HEAD where setFollowRedirect is true, we should probably fix it in the handler - decide on a number of redirects following which a GET is sent instead of a HEAD in this redirect chain, which is less than the maximum number of allowed redirects (defaults to 5, as the test dump above shows).

    And.... PR done. See below.

  11. TomGranot
    added a commit that references this issue on Sep 28, 2020

    Account for recurring HEADs in Head302Test

    51da4d5
  12. TomGranot
    closed this as completedin #1736on Jan 5, 2021
  13. TomGranot
    added a commit that references this issue on Jan 5, 2021

    Use original method in redirects for HEAD / OPTIONS requests (#1736)

    bd7b5bd
  14. TomGranot
    self-assigned this
    on Jan 5, 2021
  15. TomGranot
    added this to the 2.12.3 milestone on Jan 5, 2021

  16. TomGranot commented on Jan 5, 2021

    @TomGranot
    TomGranot
    on Jan 5, 2021
    Contributor

    @lakxtxue Merged to master, should be deployed in 2.12.3.

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

Metadata

Metadata

Assignees

Labels

No labels
No labels

Type

No type

Projects

No projects

    Milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions