A Bug in a Java Servlet

Posted on

We have a legacy system, which is a web service, receives HTTP POST from clients, parses the data, then stores them in a file.

The function of the system is simple, and people already done functional and performance test, it's stable. As time drifted away, the system was copy and paste to some projects by only changing the data parsing logic.

I had a similar requirement recently, then I delved into the legacy code to check if it works in order to not reinventing the wheel.

WTF

At first, I noticed below code in a HttpServlet class, it allocates more than 1M memory for each HTTP POST request.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
   private static final long MAX_CONTENT_LENGTH = 1024 * 1024;
   private static final int BUFFER_SIZE = 4096;

   ...

public void doPost(HttpServletRequest request, HttpServletResponse response)
		throws ServletException, IOException {

       ...

       int requestContentBufSize = request.getContentLength() + MAX_CONTENT_LENGTH;
       ByteBuffer requestContentBuf = ByteBuffer.allocate(requestContentBufSize);
       byte[] buffer = new byte[BUFFER_SIZE];
       requestInputStream = new DataInputStream(request.getInputStream());
       int readBytes = 0;
       int totalReadBytes = 0;
       while ((readBytes = requestInputStream.read(buffer)) > 0) {
           requestContentBuf.put(buffer);
    	totalReadBytes = totalReadBytes + readBytes;
       }
       byte[] requestContent = Arrays.copyOf(requestContentBuf.array(), totalReadBytes);

       ...
   }

It's insane, I believe the memory should be the same as each HTTP POST body size. Then I changed the code.

1
int requestContentBufSize = request.getContentLength();

Deployed the service and sent one HTTP POST request to it.

curl -d 'Hello, World' http://my.server.com:9000/log

An Exception occurred.

The BufferOverflowException

After reducing the memory allocated for ByteBuffer, it overflows.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
java.nio.BufferOverflowException
	at java.nio.HeapByteBuffer.put(HeapByteBuffer.java:183)
	at java.nio.ByteBuffer.put(ByteBuffer.java:830)
	at com.myproject.servlet.LogServer.doPost(LogServer.java:99)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:643)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:723)
	at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:290)
	at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:206)
	at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:233)
	at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:191)
	at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:127)
	at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
	at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:109)
	at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:293)
	at org.apache.coyote.http11.Http11Processor.process(Http11Processor.java:861)
	at org.apache.coyote.http11.Http11Protocol$Http11ConnectionHandler.process(Http11Protocol.java:606)
	at org.apache.tomcat.util.net.JIoEndpoint$Worker.run(JIoEndpoint.java:489)
	at java.lang.Thread.run(Thread.java:701)

I thought I'd better dig into how does the servlet do to make ByteBuffer get its data?

  1. It creates a small buffer occupied BUFFER_SIZE (4096) bytes.
  2. It iterates the HTTP request input stream, to put the data into the small buffer.
  3. It puts the small buffer to ByteBuffer and loop back to 1.

Well, in the last loop, the data read from the HTTP request input stream might smaller than the BUFFER_SIZE, but the servlet still puts BUFFER_SIZE bytes to ByteBuffer.

Then, to fix the ExceptionBufferOverflowException, I increased the capacity of previous ByteBuffer by BUFFER_SIZE.

1
int requestContentBufSize = request.getContentLength() + BUFFER_SIZE;

Deployed again, and

curl -d 'Hello, World' http://my.server.com:9000/log

The bug was fixed.

Did I?

The ServletInputStream

When client posts huge data, what could happen?

I created a String which is 7516 bytes, and sent to server.

curl -d 'very very long string' http://my.server.com:9000/log

Sometimes, the java.nio.BufferOverflowException occurred, and sometimes it didn't.

What went wrong?

To find the root cause, I added some logs to trace the ByteBuffer.

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
  int requestContentBufSize = request.getContentLength() + BUFFER_SIZE;
  ByteBuffer requestContentBuf = ByteBuffer.allocate(requestContentBufSize);
  byte[] buffer = new byte[BUFFER_SIZE];
  requestInputStream = new DataInputStream(request.getInputStream());
  int readBytes = 0;
  int totalReadBytes = 0;
  log.debug("1: ByteBuffer position: " + requestContentBuf.position() +
          ", buffer capacity: " + requestContentBuf.capacity() +
          ", buffer remaining: " + requestContentBuf.remaining());
  while ((readBytes = requestInputStream.read(buffer)) > 0) {
requestContentBuf.put(buffer);
totalReadBytes = totalReadBytes + readBytes;
      log.debug("2. Bytes read: " + readBytes);
      log.debug("1: ByteBuffer position: " + requestContentBuf.position() +
              ", buffer capacity: " + requestContentBuf.capacity() +
              ", buffer remaining: " + requestContentBuf.remaining());
  }

The log printed when no exception,

1
2
3
4
5
- 1: ByteBuffer position: 0, buffer capacity: 11612, buffer remaining: 11612
- 2. Bytes read: 4096
- 1: ByteBuffer position: 4096, buffer capacity: 11612, buffer remaining: 7516
- 2. Bytes read: 3420
- 1: ByteBuffer position: 8192, buffer capacity: 11612, buffer remaining: 3420

The log printed when exception occurred,

1
2
3
4
5
- 1: ByteBuffer position: 0, buffer capacity: 11612, buffer remaining: 11612
- 2. Bytes read: 1356
- 1: ByteBuffer position: 4096, buffer capacity: 11612, buffer remaining: 7516
- 2. Bytes read: 1356
- 1: ByteBuffer position: 8192, buffer capacity: 11612, buffer remaining: 3420

Now, it is easy to find out the root cause is in these lines of code.

1
2
while ((readBytes = requestInputStream.read(buffer)) > 0) {
    requestContentBuf.put(buffer);

The read method call won't put data to the buffer fully which was specified as 4096 bytes even when the input stream still has data.

And to fix it, just specify the offset and length of the small buffer.

1
2
while ((readBytes = requestInputStream.read(buffer)) > 0) {
    requestContentBuf.put(buffer, 0, readBytes);

I had increased the capacity of the ByteBuffer by BUFFER_SIZE, this change should also be reverted.

Now, the bug is fixed, and this is network programming.

Questions

"The system works a long time, and it shouldn't have this problem or we knew it long ago"

This is because the client seldom posts data more than 4096 bytes to server.

"I have read the Javadoc of DataInputStream, the read method will put data fully to the specified buffer"

It didn't, please read it again.

"I have tested the read method of DataInputStream on a file, it reads fully 4096 bytes in every iteration"

This is a web service, deploy it to a server and test.

"I have tested it on my local machine as a web service, and it reads fully 4096 bytes in every iteration"

This is a web service, it should be in a network.

At Last

When a potential bug was reported, we do tests to make it happen again and find the root cause.

We do not stop listening and just look for reasons to reject it.

When we find a bug, we do help others to make it reappear to collect information.

We do not sit there and just blame on others for their mistakes.