randomly the Http Response has been committed

[oliver.yao]

In our project, using the jboss version

boss-eap-6.1.0. And in some case, the response is committed when we send a request and want a reponse. This will cause other unexpectly result. I want to know the reason. Is it jboss bug?

This is a test java source.

package test;

import java.io.IOException;

import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;

/**
* test for response encoding issue.
* add following to the top of the web.xml file.
<filter>
  <filter-name>TestFilter</filter-name>
  <display-name>TestFilter</display-name>
  <description>Test Filter</description>
  <filter-class>test.TestFilter</filter-class>
</filter>
<filter-mapping>
  <filter-name>TestFilter</filter-name>
  <servlet-name>/*</servlet-name>
</filter-mapping>
*
*
*/
public class TestFilter implements Filter {

public void destroy() {
}

public void doFilter(ServletRequest request, ServletResponse response,
   FilterChain chain) throws IOException, ServletException {
 
  System.out.println("******* investigationFilterIn: Response Committed (" + String.valueOf(response.isCommitted()) + "), CharEncoding (" + response.getCharacterEncoding() + ")");
 
  //response.setCharacterEncoding(pageCharEncoding);
  response.setContentType("text/html; charset=UTF-8"); // default response contentType. It could be changed later
  String resStatus = "";
  try {
   java.lang.reflect.Method method = response.getClass().getMethod("getStatus", null); // servlet 3.0 and above
   resStatus = method.invoke(response, null).toString();
  } catch (Exception e) {
   resStatus = "unknown";
  }
  System.out.println("******* investigationFilterOut: URL ("  + ((HttpServletRequest)request).getRequestURI() + "), Response Class (" + response.getClass().getName() + "), Status (" + resStatus + "), Committed (" + String.valueOf(response.isCommitted()) + "), CharEncoding (" + response.getCharacterEncoding() + "), Buffer size (" +  String.valueOf(response.getBufferSize()) + ")");
  if (!"UTF-8".equalsIgnoreCase(response.getCharacterEncoding())) System.out.println("+++++++++ investigationFilter Response CharEncoding Error.  URL is " + ((HttpServletRequest)request).getRequestURI());
 
  chain.doFilter(request, response);
}

public void init(FilterConfig cfg) throws ServletException {
}

}

This is the unexpected result after run the application.

10:02:42,307 INFO  [stdout] (http-/0.0.0.0:8980-8) ******* investigationFilterIn: Response Committed (true), CharEncoding (ISO-8859-1)

10:02:42,307 INFO  [stdout] (http-/0.0.0.0:8980-8) ******* investigationFilterOut: URL (/scf/cda/portalPanel.do), Response Class (org.apache.catalina.connector.ResponseFacade), Status (200), Committed (true), CharEncoding (ISO-8859-1), Buffer size (8192)

10:02:42,308 INFO  [stdout] (http-/0.0.0.0:8980-8) +++++++++ investigationFilter Response CharEncoding Error.  URL is /scf/cda/portalPanel.do

10:02:42,308 INFO  [stdout] (http-/0.0.0.0:8980-8) ******* investigationInit: URL (/scf/cda/portalPanel.do), Response Class (org.apache.catalina.connector.ResponseFacade), Status (200), Committed (true), CharEncoding (ISO-8859-1), Buffer size (8192)

10:02:42,308 INFO  [stdout] (http-/0.0.0.0:8980-8) +++++++++ investigationInit Response CharEncoding Error.  URL is /scf/cda/portalPanel.do

This is normal result after run the application.

10:02:43,968 INFO  [stdout] (http-/0.0.0.0:8980-10) ******* investigationFilterIn: Response Committed (false), CharEncoding (ISO-8859-1)

10:02:43,968 INFO  [stdout] (http-/0.0.0.0:8980-10) ******* investigationFilterOut: URL (/scf/cda/bankList.do), Response Class (org.apache.catalina.connector.ResponseFacade), Status (200), Committed (false), CharEncoding (UTF-8), Buffer size (8192)

10:02:43,969 INFO  [stdout] (http-/0.0.0.0:8980-10) ******* investigationInit: URL (/scf/cda/bankList.do), Response Class (org.apache.catalina.connector.ResponseFacade), Status (200), Committed (false), CharEncoding (UTF-8), Buffer size (8192)

10:02:43,993 INFO  [stdout] (http-/0.0.0.0:8980-10) ******* investigationTop: Response committed (false).   CharEncoding is UTF-8

We test 518 time. And the unexpected result have 6 time, the other is normal.

[jfclere]

The Committed state isn't an error in jbossweb. Probably the application return an error that is why the response is committed.

[oliver.yao]

Today.I do another test about this.

This is test web.

<!--

Add a servlet filter to check the response committed status:
Add following in web.xml:
<filter>
  <filter-name>TestFilter</filter-name>
  <display-name>TestFilter</display-name>
  <description>Test Filter</description>
  <filter-class>test.TestFilter</filter-class>
</filter>
<filter-mapping>
  <filter-name>TestFilter</filter-name>
  <url-pattern>/*</url-pattern>
</filter-mapping>

Following is the filter class TestFilter.java:

package test;
import java.io.IOException;
import javax.servlet.Filter;
import javax.servlet.FilterChain;
import javax.servlet.FilterConfig;
import javax.servlet.ServletException;
import javax.servlet.ServletRequest;
import javax.servlet.ServletResponse;
import javax.servlet.http.HttpServletRequest;
public class TestFilter implements Filter {
public void doFilter(ServletRequest request, ServletResponse response,
   FilterChain chain) throws IOException, ServletException {
 
  System.out.println("******* investigationFilter: URL (" + ((HttpServletRequest)request).getRequestURI() + "), Response Committed (" + String.valueOf(response.isCommitted()) + "), CharEncoding (" + response.getCharacterEncoding() + "), Response Object id (" + String.valueOf(System.identityHashCode(response)) + ")");
  if (response.isCommitted()) {
   System.out.println("+++++++++ investigationFilter Response Committed Already Error.  URL is " + ((HttpServletRequest)request).getRequestURI());
   Exception e = new Exception("Response Committed Already Error.");
   e.printStackTrace();
  }
 
  chain.doFilter(request, response);
}
public void init(FilterConfig cfg) throws ServletException {
}
public void destroy() {
}
}

-->

<script>
function getWaitTime() {
  var timeMs =  Math.random() * 100; // milliseconds in [2, 8]
  return(Math.floor(timeMs));
}
function refreshContent() {
  var ms = getWaitTime();
  document.getElementById("timeMS").innerText = ms;
    document.getElementById("myframe2").src="http://localhost:8080/OBD-Web/jsp/verifyCode.jsp?" + (new Date()).getTime();
 
  setTimeout(refreshContent, ms);
}

</script>
<body onload="refreshContent()">
Refresh in <b id="timeMS"></b>  milliseconds.<br>

<iframe id="myframe2" src="" width="600" height="300"></iframe><br>
</body>

===========================================================================================

This is verifyCode.jsp.

<% // generate verification code image and send back

com.pti.waf.util.VerifyCodeUtil.generateCodeAndImage(request, response);

if (1 == 1) return;

%>

=============================================================================================

This is java source for generateCodeAndImage.

public static void generateCodeAndImage(HttpServletRequest request, HttpServletResponse response) throws ServletException, IOException {
  if (!isVerifyCodeEnabled()) return;
  // get the image location
  String imgDir = request.getSession(true).getServletContext().getRealPath("/");
  imgDir += "/resources/" + WhiteLabelUtil.getThemeName(request) + codeInfo.getImageLocation();
  // now imgDir is the absolute path of images (ending with /)
 
  BufferedImage codeImage = null;
  BufferedImage letterImg = null;
  StringBuffer codeBuf = new StringBuffer();
  // generate code
  int x = 0;
  for (int i = 0; i < codeInfo.getCodeLength(); ++i) {
   char letter = codeInfo.getAvailableLetters().charAt(rand.nextInt(codeInfo.getAvailableLetters().length()));
   codeBuf.append(letter);
   String letterImgName = imgDir + letter +
    (codeInfo.getLetterFirstImgIndex() + rand.nextInt(codeInfo.getLetterLastImgIndex() - codeInfo.getLetterFirstImgIndex() + 1))
    + "." + codeInfo.getLetterImgFormat();
   File fl = new File(letterImgName);
   if (!fl.exists()) {
    logger.error("image " + letterImgName + " does not exist.");
    return;
   }
   // read the image
   letterImg = ImageIO.read(fl);
   if (codeImage == null) {
    // get background image
    String bgImgName = imgDir + codeInfo.getBgImgName() +
      (codeInfo.getBgFirstImgIndex() + rand.nextInt(codeInfo.getBgLastImgIndex() - codeInfo.getBgFirstImgIndex() + 1))
      + "." + codeInfo.getBgImgFormat();
    File fb = new File(bgImgName);
    if (!fb.exists()) {
     logger.error("image " + bgImgName + " does not exist.");
     return;
    }
    BufferedImage bgImg = ImageIO.read(fb);
    codeImage = bgImg.getSubimage(0, 0, letterImg.getWidth() * codeInfo.getCodeLength(), letterImg.getHeight());
   }
   for (int x1 = 0; x1 < letterImg.getWidth(); ++x1) {
    for (int y1 = 0; y1 < letterImg.getHeight(); ++y1) {
     int rgb = letterImg.getRGB(x1, y1);
     // if color is (r, g, b) = (255,255,255) then use background
     if ((rgb & 0x0FFFFFF) != 0x0FFFFFF) codeImage.setRGB(x + x1, y1, rgb);
    }
   }
   x += letterImg.getWidth();
  }

  // set code in session
  HttpSession session = request.getSession(true);
  session.setAttribute(VERIFY_CODE_ATTR_NAME, codeBuf.toString());
 
  // output to reponse
  Iterator it = ImageIO.getImageWritersByMIMEType(codeInfo.getCodeImageMIMEType());
  ImageWriter writer = (it != null && it.hasNext()) ? (ImageWriter)it.next() : null;
  if (writer != null) {
   response.setContentType(codeInfo.getCodeImageMIMEType());

   OutputStream os = response.getOutputStream();

   ImageOutputStream stream = ImageIO.createImageOutputStream(os);

   writer.setOutput(stream);

   writer.write(codeImage);

   //stream.flush();

   os.close();

   stream.close();

   writer.dispose();

  } else {
   logger.error("there is no image writer for image type " + codeInfo.getCodeImageMIMEType());
  }
}

=============================================================

It still has Response is Committed info.

17:36:10,906 INFO  [stdout] (http-/0.0.0.0:8080-24) ******* investigationFilterIn: Response Committed (true), CharEncoding (ISO-8859-1)

But when I change some part , there is not Response is Committed info.

  if (writer != null) {

   response.setContentType(codeInfo.getCodeImageMIMEType()); 

   OutputStream os = response.getOutputStream();

   ImageOutputStream stream = ImageIO.createImageOutputStream(os);

   writer.setOutput(stream);

   writer.write(codeImage);

   //stream.flush();

   os.close();

   stream.close();

   writer.dispose();

  } else {
   logger.error("there is no image writer for image type " + codeInfo.getCodeImageMIMEType());
  }

Modify like below.

  if (writer != null) {

   PrintWriter writer2 = response.getWriter();

   writer2.write("hello"+ Math.random()*100);

  writer2.flush();

  } else {
   logger.error("there is no image writer for image type " + codeInfo.getCodeImageMIMEType());
  }

Can you tell me why? Thank for the reply.

[jfclere]

The response is committed when the headers are sent.

I guess you fill the output buffer so the page and the headers are sent out in one case and not in the other.

[oliver.yao]

Thanks for your reply. I have do another test. The Modified source do not  cause the "response committed" error.

Below is cause the response committed source.

if (writer != null) {

   response.setContentType(codeInfo.getCodeImageMIMEType());

   OutputStream os = response.getOutputStream();

   ImageOutputStream stream = ImageIO.createImageOutputStream(os);

   writer.setOutput(stream);

   writer.write(codeImage);

   os.close();

   stream.close();

   writer.dispose();

}

Now ,modify the the below.

if (writer != null) {

   java.io.ByteArrayOutputStream bos = new java.io.ByteArrayOutputStream(4096);

   writer.setOutput(new MemoryCacheImageOutputStream(bos));

   writer.write(codeImage);

   bos.flush();

   byte[] imgBuf = bos.toByteArray();

   bos.close();

   writer.dispose();

   response.setContentType(codeInfo.getCodeImageMIMEType());

   response.setContentLength(imgBuf.length);

   OutputStream os = response.getOutputStream();

   os.write(imgBuf);

   os.flush();

   os.close();

}

After modify the source, in the application system response committed error . So the problem is solved.

I think like you had said,the second source could not cause output buffer become full.

But I still want to know why the first source cause buffer full,and the second not.

Is it jboss issue?

By the way, I test the same source in webshpere. It will not cause the "response committed" error