Brakujące żądania błędów w logu localhost_access tomcat, podczas gdy IOException podczas inwokacji Jacksona pojawia się w dzienniku aplikacji

Question

Jakaś dziwna sytuacja. Podczas testu wydajności aplikacji internetowej (wojna), klient dostaje 500 na około 2% wniosków. Podczas poszukiwania dziennik aplikacji, istnieją pewne wyjątki tam:

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) 

Jednak localhost_access jest pusty, a wszystkie wnioski nie mają 200 kod stanu.

Będę wdzięczny za wszelkie spostrzeżenia na ten problem:

• Jak może się zdarzyć, że dziennik localhost_access brakuje 500 wniosków, podczas gdy klient je kupujemy. Kiedy to w ogóle się dzieje?
• Dlaczego java.io.IOException jest rzucany tylko okazjonalnie (mniej niż 2% zapytań)?

Aktualizacja 1: Problem pojawia się z Tomcat 7.0.22 i Java 6

Aktualizacja 2: Oto niektóre przykładowy wniosek do statycznego pliku html (nawet do serwletu, więc nie nie jest wyjątkiem w dzienniku i nic w 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 

Update 3: wyeliminować sieć wpadłem same testy na localhost. Nie wpłynęło to na wyniki testu. Więc to nie jest sieć.

Aktualizacja 4: Restartowanie Tomcat pomogło. I nadal nie rozumiem, co spowodowało pierwotny problem.

Aktualizacja 5: Tomcat został uaktualniony do wersji 7.0.26, ale nie rozwiązał problemu.

Aktualizacja 6: Przeniesiono do pomostu. Błędy zniknęły. Czy po tych wszystkich latach powinienem powiedzieć "Good Bye" Tomcatowi?

Answer 1

Nie mówisz, z której wersji Tomcat korzystasz, co byłoby dużą pomocą. Zgaduję - w oparciu o to, co widzisz - jest to, że jest stosunkowo stary.
Dziennik dostępu jest implementowany jako zawór. Jeśli żądanie zostanie odrzucone, zanim dotrze do Zaworów, nigdy nie pojawi się w dzienniku dostępu. Zwykle dzieje się tak, gdy żądanie jest źle sformułowane, ale istnieją inne okoliczności, które mogłyby go uruchomić.
Od wersji 6.0.30 Tomcat (i wszystkich wersji 7.0.x) mechanizm rejestrowania dostępu został zreinstalowany w celu zapewnienia, że ​​komunikaty są zapisywane w dzienniku dostępu, nawet jeśli żądanie zostanie odrzucone, zanim dotrze do AccessLogValve.

Wyjątek IOException jest generowany, gdy klient zamyka połączenie. To, czy jest to spowodowane 500, czy powoduje 500, jest niejasne z dostarczonych informacji.

Answer 2

Komunikat o błędzie sugeruje, że IOException pojawia się, gdy Jackson próbuje zainicjować parsowanie, co oznacza, że ​​podstawowe połączenie HTTP jest już zamknięte po rozpoczęciu analizowania żądania. Coś zamknęło połączenie; i chociaż może to być zarówno klient, jak i serwer (HTTP pozwala, aby oba końce zamknęły połączenia w dowolnym punkcie), często jest to coś pośrodku (firewall, proxy, loadbalancer); często z powodu pewnego rodzaju przekroczenia limitu czasu.

Answer 3

Poczta AJAX na IE ma sporadyczne problemy z awariami. Widzieliśmy niedorzeczności. Możesz wyłączyć KeepAlive i wypróbować lub wyłączyć KeepAlive dla AJAX POST, używając nagłówka "connection: close". Dostosuj żądanie apache requestreadout do żądania braku treści.