Bug 62620

Summary: Async servlet over HTTP/2 large write data corrupted
Product: Tomcat 9 Reporter: Dapeng Zhang <zdapeng>
Component: ServletAssignee: Tomcat Developers Mailing List <dev>
Status: RESOLVED FIXED    
Severity: normal    
Priority: P2    
Version: 9.0.10   
Target Milestone: -----   
Hardware: PC   
OS: Linux   

Description Dapeng Zhang 2018-08-13 17:39:00 UTC
Related to the fix of https://bz.apache.org/bugzilla/show_bug.cgi?id=62614

Test case 1.
import java.io.IOException;
import javax.servlet.AsyncContext;
import javax.servlet.ServletOutputStream;
import javax.servlet.WriteListener;
import javax.servlet.annotation.WebServlet;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

@WebServlet(urlPatterns = {"/largeasyncwrite"}, asyncSupported = true)
public class LargeAsyncWrite extends HttpServlet {
  @Override
  protected void doGet(HttpServletRequest request, HttpServletResponse response)
      throws IOException {
    final AsyncContext asyncContext = request.startAsync();

    response.setStatus(HttpServletResponse.SC_OK);
    response.setContentType("application/binary");

    final ServletOutputStream output = response.getOutputStream();
    output.setWriteListener(new WriteListener() {
      int i;
      byte[] bytes = new byte[65536];
      int expectedBytesSentOut;

      @Override
      public void onWritePossible() throws IOException {
        i++;
        System.out.println("onWritePossible called " + i + " times");

        if (i > 3) {
          System.out.println("complete");
          System.out.println("expected bytes sent out: " + expectedBytesSentOut);
          asyncContext.complete();
          return;
        }

        int j = 0;
        while(output.isReady()) {
          System.out.println("start write j = " + j);
          output.write(bytes);
          expectedBytesSentOut += 65536;
          System.out.println("write complete j = " + j);
          j++;
        }

        System.out.println("output.isReady() = " + false);
      }

      @Override
      public void onError(Throwable t) {
        t.printStackTrace();
      }
    });
  }
}

Client side, run the command:
$ nghttp "http://localhost:8080/largeasyncwrite" -v

From the output, sum up the length of DATA frames it received, that's the total number of bytes actually received.
Check "logs/catalina.out" for the expected bytes sent out, it should equal to the actual bytes received but not.

Test case 2.
import java.io.IOException;
import java.util.concurrent.Executors;
import java.util.concurrent.Future;
import java.util.concurrent.ScheduledExecutorService;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicInteger;
import javax.servlet.AsyncContext;
import javax.servlet.ServletOutputStream;
import javax.servlet.WriteListener;
import javax.servlet.annotation.WebServlet;
import javax.servlet.http.HttpServlet;
import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

@WebServlet(urlPatterns = {"/largeasyncwrite2"}, asyncSupported = true)
public class LargeAsynWrite2 extends HttpServlet {
  static final ScheduledExecutorService scheduler = Executors.newScheduledThreadPool(1);

  @Override
  protected void doGet(HttpServletRequest request, HttpServletResponse response)
      throws IOException {

    final AsyncContext asyncContext = request.startAsync();
    response.setStatus(HttpServletResponse.SC_OK);
    response.setContentType("application/binary");

    final ServletOutputStream output = response.getOutputStream();
    output.setWriteListener(
        new WriteListener() {
          final AtomicInteger i = new AtomicInteger();
          final byte[] bytes = new byte[65536];
          volatile Future<?> future;
          volatile int expectedBytesSentOut;

          @Override
          public void onWritePossible() {
            i.incrementAndGet();
            System.out.println("onWritePossible");

            if (i.get() > 3) {
              System.out.println("complete");
              System.out.println("expected bytes sent out: " + expectedBytesSentOut);
              asyncContext.complete();
              return;
            }

            System.out.println(
                "I don't have data to write right now, and have to exit onWritePossible()");

            future =
                scheduler.schedule(
                    () -> {
                      boolean ready;
                      int j = 0;
                      while (ready = output.isReady() && i.get() <= 3) {
                        try {
                          System.out.println("start write, j = " + j);
                          output.write(bytes);
                          expectedBytesSentOut += 65536;
                          System.out.println("end write, j = " + j);
                          j++;
                        } catch (IOException e) {
                          e.printStackTrace();
                        }
                      }

                      System.out.println("output.isReady() = " + ready);

                      if (ready && i.get() > 3) {
                        System.out.println("complete");
                        System.out.println("expected bytes sent out: " + expectedBytesSentOut);
                        asyncContext.complete();
                        return;
                      }
                    },
                    2,
                    TimeUnit.SECONDS);
          }

          @Override
          public void onError(Throwable t) {
            if (future != null) {
              future.cancel(false);
            }

            t.printStackTrace();
          }
        });
  }
}

Client side, run the command
$ nghttp "http://localhost:8080/largeasyncwrite2" -v

Also check the actual bytes the client received. Run multiple times, the result should be reliable and stable.
Comment 1 Mark Thomas 2018-08-14 14:54:00 UTC
Thanks I can recreate this. I'll update the bug when I have a fix.
Comment 2 Mark Thomas 2018-08-15 15:09:45 UTC
Fixed in:
- trunk for 9.0.12 onwards
- 8.5.x for 8.5.34 onwards