Uploaded image for project: 'HttpComponents HttpCore'
  1. HttpComponents HttpCore
  2. HTTPCORE-599

Capacity feedback does not throttle AsyncDataConsumer.consume() for Http1

    XMLWordPrintableJSON

    Details

    • Type: Bug
    • Status: Resolved
    • Priority: Blocker
    • Resolution: Fixed
    • Affects Version/s: 5.0-beta8
    • Fix Version/s: 5.0-beta9
    • Component/s: HttpCore NIO
    • Labels:
      None
    • Environment:
      macOS Mojave using the IntelliJ CE 2019.2.1 runtime

      Description

      The capacity window mechanism in AbstractHttp1StreamDuplexer does not appear to be throttling calls to AsyncDataConsumer.consume(). This affects both client and server asynchronous entity consumers.

      The attached test program implements a simple 5.0 asynchronous HTTP/1.1 server. Aside from boilerplate code, the significant parts are:

      1. Set the HTTP1 initial window size to 8192.
      2. Add an AsyncExchangeHandler that creates an empty response and logs the AsyncDataConsumer method calls to the console.
      3. Updating the capacity channel is intentionally omitted, effectively providing an infinitely slow consumer.

      To test, post data of more than 8 KB to the server (e.g. using curl). I expect to see in the log consume() calls totaling at least 8192 and nothing after that until the socket times out. Instead, what I see is consume() calls delivering all the data and then streamEnd().

      Here is sample output for uploading almost 32 KB. I have used my IDE to add a logging breakpoint to show the capacity window on this line:

      https://github.com/apache/httpcomponents-core/blob/a60528ea58877d55dab266bd2813e065aac6ff2c/httpcore5/src/main/java/org/apache/hc/core5/http/impl/nio/AbstractHttp1StreamDuplexer.java#L313

      so those are also included in the output below.

      Mon Sep 09, 2019 10:27:18.893 AM SlowConsumerTest main FINE: Listening on /0:0:0:0:0:0:0:0:8080
      Mon Sep 09, 2019 10:27:31.294 AM SlowConsumerTest$MyExchangeHandler handleRequest FINEST: handleRequest called
      Mon Sep 09, 2019 10:27:31.332 AM SlowConsumerTest$MyExchangeHandler consume FINEST: consume 8192 total 8192
      AbstractHttp1StreamDuplexer:313 capacity=0
      Mon Sep 09, 2019 10:27:31.341 AM SlowConsumerTest$MyExchangeHandler updateCapacity FINEST: updateCapacity called
      Mon Sep 09, 2019 10:27:31.342 AM SlowConsumerTest$MyExchangeHandler consume FINEST: consume 8192 total 16384
      AbstractHttp1StreamDuplexer:313 capacity=-8192
      Mon Sep 09, 2019 10:27:31.346 AM SlowConsumerTest$MyExchangeHandler updateCapacity FINEST: updateCapacity called
      Mon Sep 09, 2019 10:27:31.348 AM SlowConsumerTest$MyExchangeHandler consume FINEST: consume 8192 total 24576
      AbstractHttp1StreamDuplexer:313 capacity=-16384
      Mon Sep 09, 2019 10:27:31.352 AM SlowConsumerTest$MyExchangeHandler updateCapacity FINEST: updateCapacity called
      Mon Sep 09, 2019 10:27:31.354 AM SlowConsumerTest$MyExchangeHandler consume FINEST: consume 8150 total 32726
      AbstractHttp1StreamDuplexer:313 capacity=-24534
      Mon Sep 09, 2019 10:27:31.357 AM SlowConsumerTest$MyExchangeHandler streamEnd FINEST: streamEnd called

        Attachments

        1. SlowConsumerTest.java
          4 kB
          Roy Hashimoto

          Issue Links

            Activity

              People

              • Assignee:
                Unassigned
                Reporter:
                rhashimoto Roy Hashimoto
              • Votes:
                0 Vote for this issue
                Watchers:
                3 Start watching this issue

                Dates

                • Created:
                  Updated:
                  Resolved:

                  Time Tracking

                  Estimated:
                  Original Estimate - Not Specified
                  Not Specified
                  Remaining:
                  Remaining Estimate - 0h
                  0h
                  Logged:
                  Time Spent - 50m
                  50m