Handling of minRequestDataRate is too fragile against short process delays

[mattiaslundstrom]

Jetty version
9.4.21.v20190926

Java version
OpenJDK 64-Bit Server VM 18.9 (build 11.0.2+9, mixed mode)

OS type/version
Linux Mint

Description
When using minRequestDataRate, the algorithm is fragile against any short "stutter" or delay in the server process and may incorrectly reject valid requests depending on timing.

The code in question in HttpInput is

  long minRequestDataRate = _channelState.getHttpChannel().getHttpConfiguration().getMinRequestDataRate();
  if (minRequestDataRate > 0 && _firstByteTimeStamp != -1)
  {
    long period = System.nanoTime() - _firstByteTimeStamp;
    if (period > 0)
    {
      long minimumData = minRequestDataRate * TimeUnit.NANOSECONDS.toMillis(period) / TimeUnit.SECONDS.toMillis(1);
      if (_contentArrived < minimumData)
      {

where the request is rejected.

The problem is that this is very sensitive to short delays introduced by the server process. In our application this seems to happen shortly after process restart and is at a guess related to class loading, but this could also happen if you have for example short GC delays in the server process. Regardless, the end result is that there are some valid requests that are rejected after just a small fraction of a second.

A suggested fix would be to change the above to something like

    if (period > GRACE_PERIOD)
    {

so that a request is not rejected unless it has delayed for at least a few seconds (or whatever we want that grace period to be).

It seems that the same type of logic could be useful regarding the minResponseDataRate logic in HttpOutput,

[mattiaslundstrom]

I added a quick commit/pull request to illustrate the above suggested solution for the issue
#4642

[mattiaslundstrom]

My original diagnosis of the problem was incorrect. The theory was that there were multiple short reads with internal process delays between, but some additional debugging shows that this is not the case.

After doing some debugging, I can see that HttpInput.addContent is called with a zero size Content. (This is for GET requests so, no content is correct I guess)

So in HttpInput.addContent we get _firstByteTimeStamp set, but _contentArrived is still zero. Then a little later HttpInput.read is called and the test for minRequestDataRate fails. This will always happen if the delay between addContent and read is large enough that the minimum required bytes are not truncated to 0.

Changing addContent not setting _firstByteTimeStamp if content size is zero should be enough to fix this issue.

This issue was reproduced in 9.4.21.v20190926, however when switching to 9.4.27.v20200227, it seems the program flow has changed. The time between the addContent and read calls is much smaller and the bug does not seem to hit anymore in our testcase.

The larger question about whether we are too dependent on small timing variations when measuring the data rate is still a bit of an open question.

[mattiaslundstrom]

The more general question about timing sensitivity for the minRequest/ResponseDataRate can I think be handled in the older issue #4014

[gregw]

So is it OK to close this issue in favour of #4014?

[mattiaslundstrom]

I think so. Closing and moving the discussion to #4014