Apache – IOException: Socket Read Failed Using Apache 2, mod_jk, and Tomcat Over AJP

apache-2.2jsonmod-jktomcat

I am getting the following Exception from time to time when my users are connecting with their Android devices to out JSON Rest Service:

java.io.IOException: Socket read failed
       at org.apache.coyote.ajp.AjpProcessor.read(AjpProcessor.java:313)
       at org.apache.coyote.ajp.AjpProcessor.readMessage(AjpProcessor.java:364)
       at org.apache.coyote.ajp.AjpProcessor.receive(AjpProcessor.java:331)
       at org.apache.coyote.ajp.AbstractAjpProcessor.refillReadBuffer(AbstractAjpProcessor.java:614)
       at org.apache.coyote.ajp.AbstractAjpProcessor$SocketInputBuffer.doRead(AbstractAjpProcessor.java:1065)
       at org.apache.coyote.Request.doRead(Request.java:422)
       at org.apache.catalina.connector.InputBuffer.realReadBytes(InputBuffer.java:290)
       at org.apache.tomcat.util.buf.ByteChunk.substract(ByteChunk.java:431)
       at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:315)
       at org.apache.catalina.connector.CoyoteInputStream.read(CoyoteInputStream.java:200)
       at org.codehaus.jackson.impl.ByteSourceBootstrapper.ensureLoaded(ByteSourceBootstrapper.java:340)
       at org.codehaus.jackson.impl.ByteSourceBootstrapper.detectEncoding(ByteSourceBootstrapper.java:137)
       at org.codehaus.jackson.impl.ByteSourceBootstrapper.constructParser(ByteSourceBootstrapper.java:197)
       at org.codehaus.jackson.JsonFactory._createJsonParser(JsonFactory.java:542)
       at org.codehaus.jackson.JsonFactory.createJsonParser(JsonFactory.java:389)
       at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1454)
       at org.springframework.http.converter.json.MappingJacksonHttpMessageConverter.readInternal(MappingJacksonHttpMessageConverter.java:124)
       at org.springframework.http.converter.AbstractHttpMessageConverter.read(AbstractHttpMessageConverter.java:153)
       at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.readWithMessageConverters(HandlerMethodInvoker.java:641)
       at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.resolveRequestBody(HandlerMethodInvoker.java:605)
       at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.resolveHandlerArguments(HandlerMethodInvoker.java:354)
       at org.springframework.web.bind.annotation.support.HandlerMethodInvoker.invokeHandlerMethod(HandlerMethodInvoker.java:171)
       at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.invokeHandlerMethod(AnnotationMethodHandlerAdapter.java:436)
       at org.springframework.web.servlet.mvc.annotation.AnnotationMethodHandlerAdapter.handle(AnnotationMethodHandlerAdapter.java:424)
       at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
       at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
       at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
       at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:789)

I am running

  • Apache/2.2.20
  • mod_jk 1.2.36
  • Tomcat 7.0.27

Could this have something to do with a timeout? Like the client closes the connection and the server is not able to read from the socket anymore? Or is it more likely a problem of the server configuration?

UPDATE:

Doing some Apache log awk I found the following Apache log lines corresponding to those Tomcat log exceptions:

192.186.30.116 - - [25/Jun/2012:10:47:14 +0200] "POST /myapp/methodX HTTP/1.1" 400 145 "-" "clientApp BlackBerry9360/7.0.0.530 VendorID/168" 10012655 
192.186.30.120 - - [25/Jun/2012:10:53:13 +0200] "POST /myapp/methodY HTTP/1.1" 400 145 "-" "clientApp BlackBerry9800/6.0.0.668 VendorID/124" 10012164 
192.186.30.116 - - [25/Jun/2012:10:53:36 +0200] "POST /myapp/methodZ HTTP/1.1" 400 145 "-" "clientApp BlackBerry9360/7.0.0.530 VendorID/168" 10012677 
192.82.68.16 - - [25/Jun/2012:11:22:31 +0200] "POST /myapp/methodX HTTP/1.1" 400 145 "-" "clientApp BlackBerry9930/7.1.0.402 VendorID/104" 10012667 
192.82.68.16 - - [25/Jun/2012:11:23:21 +0200] "POST /myapp/methodZ HTTP/1.1" 400 145 "-" "clientApp BlackBerry9930/7.1.0.402 VendorID/104" 10012562 

You can see the status code 400 Bad Request sent to the clients for those requests.

The large numbers at the end of the line (e.g. 10012562) show the time the request was processed on the server in microseconds: 10012562 = about 10 seconds

Looks like the connection is somehow terminated after ten seconds? I looked into the AJP configuration but there is no timeout defined – 10 seconds would be the timeout for async requests which I am not using

Best Answer

I found the reason. Problem was caused by default configuration of Apache module mod_reqtimeout:

<IfModule reqtimeout_module>

# mod_reqtimeout limits the time waiting on the client to prevent an
# attacker from causing a denial of service by opening many connections
# but not sending requests. This file tries to give a sensible default
# configuration, but it may be necessary to tune the timeout values to
# the actual situation. Note that it is also possible to configure
# mod_reqtimeout per virtual host.


# Wait max 20 seconds for the first byte of the request line+headers
# From then, require a minimum data rate of 500 bytes/s, but don't
# wait longer than 40 seconds in total.
# Note: Lower timeouts may make sense on non-ssl virtual hosts but can
# cause problem with ssl enabled virtual hosts: This timeout includes
# the time a browser may need to fetch the CRL for the certificate. If
# the CRL server is not reachable, it may take more than 10 seconds
# until the browser gives up.
RequestReadTimeout header=20-40,minrate=500

# Wait max 10 seconds for the first byte of the request body (if any)
# From then, require a minimum data rate of 500 bytes/s
RequestReadTimeout body=10,minrate=500

</IfModule>

I guess BlackBerry clients wer hit harder because sending request body via RIM BIS infrastructure takes longer.

Set the value to 100 seconds and monitoring if clients are still affected.