0 Replies Latest reply on Mar 6, 2015 6:42 AM by rniestroj

WildFly 8.2.0 -BufferOverflowException and long running requests in threads problem

rniestroj Mar 6, 2015 6:42 AM

Hi,

i have a problem with a WildFly installation in one of our clients. The problem is i get java.nio.BufferOverflowException 's and other exceptions and after a few days working the app eventually hangs and the server needs to be restarted. I saw this problem in this forums. There was mentioned that an update to WildFly 8.2.0 should help but we are using this version already. The application is configured to work over https. When googling for this BufferOverflowException i found that one guy had this also when configured with HTTPS and didnt have it with HTTP. But this thread was i think not related to Wildfly: https://groups.google.com/forum/#!topic/vertx/LPp4qnrVLiY

The Environment is (from JavaMelody):

Java memory used: 210 Mb / 494 Mb

Nb of http sessions: 21

Nb of active threads

(current http requests): 2

Nb of active jdbc connections: 0

Nb of used jdbc connections

(opened if no datasource): 0

OS: OS Windows 2003, Service Pack 2, x86/32 (1 cores)

Java: Java(TM) SE Runtime Environment, 1.7.0_71-b14

JVM: Java HotSpot(TM) Client VM, 24.71-b01, mixed mode, sharing The server mode has much better performance than the client mode, you should consider using the server mode if your are not in development

PID of process: 2116

Server: Server WildFly 8.2.0.Final - 1.1.0.Final

Webapp context:

Start: 15-03-04 09:44

JVM arguments: -Dprogram.name=standalone.bat

-Xms64M

-Xmx512M

-XX:MaxPermSize=256M

-Djava.net.preferIPv4Stack=true

-Djboss.modules.system.pkgs=org.jboss.byteman

-Dorg.jboss.boot.log.file=C:\wildfly-8.2.0.Final\standalone\log\server.log

-Dlogging.configuration=file:C:\wildfly-8.2.0.Final\standalone\configuration/logging.properties

Mean age of http sessions (min): 14

Memory: Non heap memory = 94 Mb (Perm Gen, Code Cache),

Loaded classes = 20,865,

Garbage collection time = 83,353 ms,

Process cpu time = 3,436,093 ms,

Committed virtual memory = 497 Mb,

Free physical memory = 602 Mb,

Total physical memory = 2,047 Mb,

Free swap space = 2,650 Mb,

Total swap space = 3,944 Mb

Perm Gen memory: 62 Mb / 256 Mb

Free disk space: 3 137 Mb

Here are extracted exceptions from logs from startup to shutdown:

Server startup date [Thu Feb 26 08:22:57 CET 2015];

2015-02-26 10:05:01,676 ERROR [io.undertow.request] (default task-4) Undertow request failed HttpServerExchange{ GET /jquery-ui-1.10.3.custom/css/custom-theme/images/ui-bg_highlight-hard_100_fafaf4_1x100.png}: java.nio.BufferOverflowException

2015-02-26 12:33:05,915 ERROR [io.undertow.request] (default task-2) Undertow request failed HttpServerExchange{ GET /main}: java.nio.BufferOverflowException

2015-02-26 13:20:39,130 ERROR [io.undertow.request] (default task-12) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:20:39,568 ERROR [io.undertow.request] (default task-8) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:21:01,208 ERROR [io.undertow.request] (default task-16) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:21:01,927 ERROR [io.undertow.request] (default task-13) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:21:01,630 ERROR [io.undertow.request] (default task-6) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:21:01,536 ERROR [io.undertow.request] (default task-3) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:21:05,208 ERROR [io.undertow.request] (default task-18) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:23:14,538 ERROR [io.undertow.request] (default task-16) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-26 13:29:34,199 ERROR [io.undertow.request] (default task-15) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-02-27 07:09:11,909 ERROR [io.undertow.request] (default task-15) Undertow request failed HttpServerExchange{ GET /main}: java.nio.BufferOverflowException

2015-02-27 07:09:11,909 ERROR [stderr] (default task-15) Exception in thread "default task-15" java.nio.BufferOverflowException

2015-02-27 12:20:09,854 ERROR [io.undertow.request] (default task-18) Undertow request failed HttpServerExchange{ GET /jquery-ui-1.10.3.custom/css/custom-theme/images/ui-bg_highlight-soft_25_67b021_1x100.png}: java.nio.BufferOverflowException

2015-02-27 12:20:09,870 ERROR [stderr] (default task-18) Exception in thread "default task-18" java.nio.BufferOverflowException

2015-02-27 12:54:04,245 ERROR [io.undertow.request] (default task-12) UT005023: Exception handling request to /wicket/resource/com.mycompany.nekop.resources.WebappResourceReference/images/btn.png: java.nio.BufferOverflowException

2015-03-02 08:53:19,347 ERROR [io.undertow.request] (default task-14) UT005023: Exception handling request to /wicket/page: java.lang.IllegalStateException: UT000010: Session not found 5X9XLwWsVRCplfODq2lRiULR

2015-03-02 12:37:51,695 ERROR [io.undertow.request] (default task-14) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-03-02 13:32:45,210 SEVERE [EKOPL] (default task-16) [2015-03-02 13:32:45][null][PWAtut1990][ndzOaBWJ6UIgBfiTM6DuPGTK][83.0.225.50][22]Error in application java.io.IOException: An established connection was aborted by the software in your host machine: org.apache.wicket.protocol.http.servlet.ResponseIOException: java.io.IOException: An established connection was aborted by the software in your host machine

Caused by: java.io.IOException: An established connection was aborted by the software in your host machine

2015-03-02 13:32:45,476 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:45,726 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:45,945 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:46,304 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:46,429 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:46,601 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:47,804 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:47,945 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:48,117 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:48,273 SEVERE [EKOPL] (default task-16) UT010019: Response already commited: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 13:32:48,413 ERROR [org.apache.wicket.request.cycle.RequestCycle] (default task-16) Error during processing error message: java.lang.IllegalStateException: UT010019: Response already commited

2015-03-02 21:16:42,855 ERROR [io.undertow.request] (default task-14) UT005023: Exception handling request to /wicket/page: java.nio.BufferOverflowException

2015-03-03 10:24:37,835 ERROR [io.undertow.request] (default task-19) UT005023: Exception handling request to /wicket/resource/org.apache.wicket.resource.JQueryResourceReference/jquery/jquery-1.11.0.min-ver-8FC25E27D42774AEAE6EDBC0A18B72AA.js: org.apache.wicket.protocol.http.servlet.ResponseIOException: java.io.IOException: An existing connection was forcibly closed by the remote host

Caused by: java.io.IOException: An existing connection was forcibly closed by the remote host

2015-03-03 15:02:45,024 ERROR [org.apache.wicket.MarkupContainer] (default task-19) Unable to find component with id 'errorLabel' in [AjaxLink [Component id = open14Link]]

2015-03-04 07:43:06,258 ERROR [org.jboss.remoting.remote.connection] (XNIO-1 I/O-1) JBREM000200: Remote connection failed: java.io.IOException: An established connection was aborted by the software in your host machine

2015-03-04 07:43:06,351 INFO [org.jboss.as.connector.deployers.jdbc] (MSC service thread 1-2) JBAS010418: Stopped Driver service with driver-name = nekop.war_org.sqlite.JDBC_3_7

2015-03-04 07:43:07,601 INFO [org.springframework.web.context.support.XmlWebApplicationContext] (MSC service thread 1-1) Closing Root WebApplicationContext: startup date [Thu Feb 26 08:22:57 CET 2015]; Stopping server

And this goes on for a few weeks so.

In javamelody i see it then like this. The screenshot below is not coresponding to the logs above. This i a current screeshot. The logs above are from the previous "iteration"

The threads chart looks like this:

The two threads in text format are:

"default task-15" prio=5 RUNNABLE

sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)

sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)

sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)

sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)

sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)

sun.nio.ch.SelectorImpl.select(Unknown Source)

org.xnio.nio.SelectorUtils.await(SelectorUtils.java:46)

org.xnio.nio.NioSocketConduit.awaitWritable(NioSocketConduit.java:226)

org.xnio.conduits.AbstractSinkConduit.awaitWritable(AbstractSinkConduit.java:66)

org.xnio.ssl.JsseSslStreamSinkConduit.awaitWritable(JsseSslStreamSinkConduit.java:152)

org.xnio.conduits.AbstractSinkConduit.awaitWritable(AbstractSinkConduit.java:66)

io.undertow.conduits.ChunkedStreamSinkConduit.awaitWritable(ChunkedStreamSinkConduit.java:353)

org.xnio.conduits.ConduitStreamSinkChannel.awaitWritable(ConduitStreamSinkChannel.java:134)

io.undertow.channels.DetachableStreamSinkChannel.awaitWritable(DetachableStreamSinkChannel.java:86)

io.undertow.server.HttpServerExchange$WriteDispatchChannel.awaitWritable(HttpServerExchange.java:1788)

io.undertow.servlet.spec.ServletOutputStreamImpl.writeBufferBlocking(ServletOutputStreamImpl.java:570)

io.undertow.servlet.spec.ServletOutputStreamImpl.write(ServletOutputStreamImpl.java:220)

net.bull.javamelody.FilterServletOutputStream.write(FilterServletOutputStream.java:69)

net.bull.javamelody.CounterResponseStream.write(CounterResponseStream.java:82)

sun.nio.cs.StreamEncoder.writeBytes(Unknown Source)

sun.nio.cs.StreamEncoder.implWrite(Unknown Source)

sun.nio.cs.StreamEncoder.write(Unknown Source)

java.io.OutputStreamWriter.write(Unknown Source)

java.io.PrintWriter.write(Unknown Source)

java.io.PrintWriter.append(Unknown Source)

org.apache.wicket.protocol.http.servlet.ServletWebResponse.write(ServletWebResponse.java:109)

org.apache.wicket.protocol.http.HeaderBufferingWebResponse.write(HeaderBufferingWebResponse.java:174)

org.apache.wicket.ajax.AjaxRequestHandler.respond(AjaxRequestHandler.java:361)

org.apache.wicket.request.cycle.RequestCycle$HandlerExecutor.respond(RequestCycle.java:862)

org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:64)

org.apache.wicket.request.RequestHandlerStack.execute(RequestHandlerStack.java:97)

org.apache.wicket.request.cycle.RequestCycle.execute(RequestCycle.java:261)

org.apache.wicket.request.cycle.RequestCycle.processRequest(RequestCycle.java:218)

org.apache.wicket.request.cycle.RequestCycle.processRequestAndDetach(RequestCycle.java:289)

org.apache.wicket.protocol.http.WicketFilter.processRequestCycle(WicketFilter.java:259)

org.apache.wicket.protocol.http.WicketFilter.processRequest(WicketFilter.java:201)

org.apache.wicket.protocol.http.WicketFilter.doFilter(WicketFilter.java:282)

io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)

io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)

pl.atmoterm.nekop.JSessionIdRemovingFilter.doFilter(JSessionIdRemovingFilter.java:57)

io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)

io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)

pl.atmoterm.nekop.CustomHeadersFilter.doFilter(CustomHeadersFilter.java:33)

io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)

io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)

net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:198)

net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:176)

io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)

io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)

io.undertow.servlet.handlers.FilterHandler.handleRequest(FilterHandler.java:85)

io.undertow.servlet.handlers.security.ServletSecurityRoleHandler.handleRequest(ServletSecurityRoleHandler.java:61)

io.undertow.servlet.handlers.ServletDispatchingHandler.handleRequest(ServletDispatchingHandler.java:36)

org.wildfly.extension.undertow.security.SecurityContextAssociationHandler.handleRequest(SecurityContextAssociationHandler.java:78)

io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

io.undertow.servlet.handlers.security.SSLInformationAssociationHandler.handleRequest(SSLInformationAssociationHandler.java:131)

io.undertow.servlet.handlers.security.ServletAuthenticationCallHandler.handleRequest(ServletAuthenticationCallHandler.java:56)

io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

io.undertow.security.handlers.AuthenticationConstraintHandler.handleRequest(AuthenticationConstraintHandler.java:51)

io.undertow.security.handlers.AbstractConfidentialityHandler.handleRequest(AbstractConfidentialityHandler.java:45)

io.undertow.servlet.handlers.security.ServletConfidentialityConstraintHandler.handleRequest(ServletConfidentialityConstraintHandler.java:63)

io.undertow.servlet.handlers.security.ServletSecurityConstraintHandler.handleRequest(ServletSecurityConstraintHandler.java:56)

io.undertow.security.handlers.AuthenticationMechanismsHandler.handleRequest(AuthenticationMechanismsHandler.java:58)

io.undertow.servlet.handlers.security.CachedAuthenticatedSessionHandler.handleRequest(CachedAuthenticatedSessionHandler.java:70)

io.undertow.security.handlers.SecurityInitialHandler.handleRequest(SecurityInitialHandler.java:76)

io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

org.wildfly.extension.undertow.security.jacc.JACCContextIdHandler.handleRequest(JACCContextIdHandler.java:61)

io.undertow.server.handlers.PredicateHandler.handleRequest(PredicateHandler.java:43)

io.undertow.servlet.handlers.ServletInitialHandler.handleFirstRequest(ServletInitialHandler.java:261)

io.undertow.servlet.handlers.ServletInitialHandler.dispatchRequest(ServletInitialHandler.java:247)

io.undertow.servlet.handlers.ServletInitialHandler.access$000(ServletInitialHandler.java:76)

io.undertow.servlet.handlers.ServletInitialHandler$1.handleRequest(ServletInitialHandler.java:166)

io.undertow.server.Connectors.executeRootHandler(Connectors.java:197)

io.undertow.server.HttpServerExchange$1.run(HttpServerExchange.java:759)

java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)

java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)

java.lang.Thread.run(Unknown Source)

"default task-3" prio=5 RUNNABLE

sun.nio.ch.WindowsSelectorImpl$SubSelector.poll0(Native Method)

sun.nio.ch.WindowsSelectorImpl$SubSelector.poll(Unknown Source)

sun.nio.ch.WindowsSelectorImpl$SubSelector.access$400(Unknown Source)

sun.nio.ch.WindowsSelectorImpl.doSelect(Unknown Source)

sun.nio.ch.SelectorImpl.lockAndDoSelect(Unknown Source)

sun.nio.ch.SelectorImpl.select(Unknown Source)

org.xnio.nio.SelectorUtils.await(SelectorUtils.java:46)

org.xnio.nio.NioSocketConduit.awaitWritable(NioSocketConduit.java:226)

org.xnio.conduits.AbstractSinkConduit.awaitWritable(AbstractSinkConduit.java:66)

org.xnio.ssl.JsseSslStreamSinkConduit.awaitWritable(JsseSslStreamSinkConduit.java:152)

org.xnio.conduits.AbstractSinkConduit.awaitWritable(AbstractSinkConduit.java:66)

io.undertow.conduits.ChunkedStreamSinkConduit.awaitWritable(ChunkedStreamSinkConduit.java:353)

io.undertow.conduits.DeflatingStreamSinkConduit.awaitWritable(DeflatingStreamSinkConduit.java:258)

org.xnio.conduits.ConduitStreamSinkChannel.awaitWritable(ConduitStreamSinkChannel.java:134)

io.undertow.channels.DetachableStreamSinkChannel.awaitWritable(DetachableStreamSinkChannel.java:86)

io.undertow.server.HttpServerExchange$WriteDispatchChannel.awaitWritable(HttpServerExchange.java:1788)

org.xnio.channels.Channels.flushBlocking(Channels.java:64)

io.undertow.servlet.spec.ServletOutputStreamImpl.close(ServletOutputStreamImpl.java:609)

io.undertow.servlet.spec.ServletOutputStreamImpl.updateWritten(ServletOutputStreamImpl.java:364)

io.undertow.servlet.spec.ServletOutputStreamImpl.write(ServletOutputStreamImpl.java:223)

net.bull.javamelody.FilterServletOutputStream.write(FilterServletOutputStream.java:69)

net.bull.javamelody.CounterResponseStream.write(CounterResponseStream.java:82)

io.undertow.io.BlockingSenderImpl.writeBuffer(BlockingSenderImpl.java:215)

io.undertow.io.BlockingSenderImpl.writeBuffer(BlockingSenderImpl.java:187)

io.undertow.io.BlockingSenderImpl.invokeOnComplete(BlockingSenderImpl.java:244)

io.undertow.io.BlockingSenderImpl.send(BlockingSenderImpl.java:64)

io.undertow.server.handlers.resource.FileResource$1ServerTask.run(FileResource.java:159)

io.undertow.server.handlers.resource.FileResource.serve(FileResource.java:224)

org.wildfly.extension.undertow.deployment.ServletResource.serve(ServletResource.java:94)

io.undertow.server.handlers.resource.CachedResource.serve(CachedResource.java:167)

io.undertow.servlet.handlers.DefaultServlet.serveFileBlocking(DefaultServlet.java:288)

io.undertow.servlet.handlers.DefaultServlet.doGet(DefaultServlet.java:171)

javax.servlet.http.HttpServlet.service(HttpServlet.java:687)

javax.servlet.http.HttpServlet.service(HttpServlet.java:790)

io.undertow.servlet.handlers.ServletHandler.handleRequest(ServletHandler.java:85)

io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:130)

net.bull.javamelody.MonitoringFilter.doFilter(MonitoringFilter.java:160)

io.undertow.servlet.core.ManagedFilter.doFilter(ManagedFilter.java:60)

io.undertow.servlet.handlers.FilterHandler$FilterChainImpl.doFilter(FilterHandler.java:132)

org.apache.wicket.protocol.http.WicketFilter.processRequestCycle(WicketFilter.java:263)