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

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

Attach filesAttach ScreenshotVotersWatch issueWatchersCreate sub-taskLinkCloneUpdate Comment AuthorReplace String in CommentUpdate Comment VisibilityDelete Comments
    XMLWordPrintableJSON

Details

    • Bug
    • Status: Resolved
    • Blocker
    • Resolution: Fixed
    • 5.0-beta8
    • 5.0-beta9
    • HttpCore NIO
    • None
    • 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

        Activity

          This comment will be Viewable by All Users Viewable by All Users
          Cancel

          People

            Unassigned Unassigned
            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

                Issue deployment