Pregunta Faltan solicitudes de error en el registro localhost_access del tomcat, mientras que IOException durante la invocación de Jackson aparece en el registro de la aplicación


Alguna situación extraña. Durante una prueba de rendimiento de una aplicación web (war), el cliente obtiene 500 en aproximadamente el 2% de las solicitudes. Al buscar en el registro de la aplicación, hay algunas excepciones allí:

 java.io.IOException: Stream closed
    at org.apache.catalina.connector.InputBuffer.read(InputBuffer.java:394)
    at org.apache.catalina.connector.CoyoteReader.read(CoyoteReader.java:110)
    at org.codehaus.jackson.impl.ReaderBasedParserBase.loadMore(ReaderBasedParserBase.java:95)
    at org.codehaus.jackson.impl.ReaderBasedParser._skipWSOrEnd(ReaderBasedParser.java:935)
    at org.codehaus.jackson.impl.ReaderBasedParser.nextToken(ReaderBasedParser.java:245)
    at org.codehaus.jackson.map.ObjectMapper._initForReading(ObjectMapper.java:2432)
    at org.codehaus.jackson.map.ObjectMapper._readMapAndClose(ObjectMapper.java:2389)
    at org.codehaus.jackson.map.ObjectMapper.readValue(ObjectMapper.java:1618)
    at MyServlet.doPost(MyServlet.java:25)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:641)
    at javax.servlet.http.HttpServlet.service(HttpServlet.java:722)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:304)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at MyFilter.doFilter(MyFilter.java:67)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at MyFilter.doFilter(MyFilter.java:28)
    at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:243)
    at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:210)
    at org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:224)
    at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:169)
    at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:472)
    at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:168)
    at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:100)
    at org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:929)
    at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:118)
    at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:405)
    at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:964)
    at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:515)
    at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:304)
    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:908)
    at java.lang.Thread.run(Thread.java:662)

Sin embargo, el localhost_access está vacío y todas las solicitudes tienen 200 códigos de estado.

Apreciaré cualquier idea sobre este problema:

  • ¿Cómo puede suceder que al registro localhost_access le falten 500 solicitudes, mientras que el cliente las recibe? ¿Cuándo sucede esto?
  • Por qué java.io.IOException se lanza solo ocasionalmente (menos del 2% de las solicitudes)?

Actualización 1: El problema ocurre con Tomcat 7.0.22 y Java 6

Actualización 2: Aquí hay una solicitud de muestra para un archivo html estático (ni siquiera para un servlet, por lo que no hay ninguna excepción en el registro y nada en localhost_access):

Response headers:
HTTP/1.1 500 Internal Server Error
Server: Apache-Coyote/1.1
Content-Type: text/html;charset=utf-8
Transfer-Encoding: chunked
Date: Mon, 02 Apr 2012 07:35:06 GMT
Connection: close

Actualización 3: para eliminar la red ejecuté las mismas pruebas en el localhost. No afectó los resultados de la prueba. Así que no es la red.

Actualización 4: El reinicio de Tomcat ayudó. Y todavía no entiendo qué causó el problema original.

Actualización 5: Tomcat se actualizó a 7.0.26, pero no resolvió el problema.

Actualización 6: Movido a Jetty. Los errores se han ido. ¿Debo decir "adiós" a Tomcat después de todos estos años?


5
2018-04-01 11:32


origen


Respuestas:


No dices qué versión de Tomcat estás ejecutando, lo que sería de gran ayuda. Mi conjetura, basada en lo que ves, es que es relativamente antigua.
El registro de acceso se implementa como una válvula. Si se rechaza una solicitud antes de llegar a las Válvulas, nunca aparecerá en el registro de acceso. Esto suele ocurrir cuando la solicitud tiene un formato incorrecto, pero existen otras circunstancias que podrían desencadenarla.
A partir de Tomcat 6.0.30 (y todas las versiones 7.0.x), el mecanismo de registro de acceso se refactorizó para garantizar que los mensajes se escriben en el registro de acceso, incluso si la solicitud se rechaza antes de que llegue a AccessLogValve.

La excepción IOException se produce cuando el cliente cierra la conexión. Si eso se debe a 500 o está causando que 500 no está claro a partir de la información proporcionada.


5
2018-04-01 13:42



Un mensaje de error sugiere que IOException llega justo cuando Jackson intenta inicializar el análisis, lo que significa que la conexión HTTP subyacente ya está cerrada cuando se comienza a analizar la solicitud. Entonces algo ha cerrado la conexión; y aunque podría ser tanto un cliente como un servidor (HTTP permite que ambos extremos cierren las conexiones en cualquier punto), a menudo es algo en el medio (firewall, proxy, loadbalancer); a menudo debido a un tiempo de espera de algún tipo.


4
2018-04-01 18:19



AJAX Post en IE tiene problemas intermitentes de falla. Hemos visto sockettimeetexceptions. Puede deshabilitar KeepAlive e intentar, o deshabilitar KeepAlive para AJAX POST mediante el uso de un encabezado de 'conexión: cerrar'. Ajuste apache requestreadtimeout para ninguna solicitud de cuerpo.


1
2017-07-17 18:52