Jetty crash

Cesc Travesa francesc.travesa at oist.jp
Tue Jun 16 01:00:23 EDT 2015 

Hi,

Today we have seen jetty crash and the only thing it hosts is the Shibboleth 3.1 IdP.

This is the error:

too many open files.

tail -n 1000 /var/www/jettybase/logs/jetty.log

################ text wall ##########

12:17:47.605 - WARN [org.eclipse.jetty.server.HttpChannel:395] - /idp/profile/SAML2/Redirect/SSO?execution=e1s1
javax.servlet.ServletException: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.IllegalStateException: STREAM
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:130) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.Server.handle(Server.java:497) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257) [jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540) [jetty-io-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635) [jetty-util-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555) [jetty-util-9.2.10.v20150310.jar:9.2.10.v20150310]
        at java.lang.Thread.run(Thread.java:745) [na:1.8.0_40]
Caused by: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.IllegalStateException: STREAM
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:978) ~[na:na]
        at org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:868) ~[na:na]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:707) ~[servlet-api-3.1.jar:3.1.0]
        at org.springframework.web.servlet.FrameworkServlet.service(FrameworkServlet.java:842) ~[na:na]
        at javax.servlet.http.HttpServlet.service(HttpServlet.java:790) ~[servlet-api-3.1.jar:3.1.0]
        at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:808) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1669) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at net.shibboleth.idp.log.SLF4JMDCServletFilter.doFilter(SLF4JMDCServletFilter.java:64) ~[na:na]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at net.shibboleth.utilities.java.support.net.RequestResponseContextFilter.doFilter(RequestResponseContextFilter.java:60) ~[na:na]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.springframework.web.filter.CharacterEncodingFilter.doFilterInternal(CharacterEncodingFilter.java:88) ~[na:na]
        at org.springframework.web.filter.OncePerRequestFilter.doFilter(OncePerRequestFilter.java:107) ~[na:na]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.opensaml.storage.impl.ServletRequestScopedStorageService.doFilter(ServletRequestScopedStorageService.java:276) ~[na:na]
        at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) ~[na:na]
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) ~[na:na]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.opensaml.storage.impl.ServletRequestScopedStorageService.doFilter(ServletRequestScopedStorageService.java:276) ~[na:na]
        at org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:344) ~[na:na]
        at org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:261) ~[na:na]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at net.shibboleth.utilities.java.support.net.CookieBufferingFilter.doFilter(CookieBufferingFilter.java:67) ~[na:na]
        at org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577) ~[jetty-security-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515) ~[jetty-servlet-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at org.eclipse.jetty.server.handler.HandlerCollection.handle(HandlerCollection.java:110) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        ... 8 common frames omitted
Caused by: java.lang.IllegalStateException: STREAM
        at org.eclipse.jetty.server.Response.getWriter(Response.java:920) ~[jetty-server-9.2.10.v20150310.jar:9.2.10.v20150310]
        at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:152) ~[servlet-api-3.1.jar:3.1.0]
        at net.shibboleth.utilities.java.support.net.CookieBufferingFilter$CookieBufferingHttpServletResponseProxy.getWriter(CookieBufferingFilter.java:116) ~[na:na]
        at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:152) ~[servlet-api-3.1.jar:3.1.0]
        at org.opensaml.storage.impl.ServletRequestScopedStorageService$OutputInterceptingHttpServletResponseProxy.getWriter(ServletRequestScopedStorageService.java:564) ~[na:na]
        at javax.servlet.ServletResponseWrapper.getWriter(ServletResponseWrapper.java:152) ~[servlet-api-3.1.jar:3.1.0]
        at org.opensaml.storage.impl.ServletRequestScopedStorageService$OutputInterceptingHttpServletResponseProxy.getWriter(ServletRequestScopedStorageService.java:564) ~[na:na]
        at org.springframework.web.servlet.view.velocity.VelocityView.mergeTemplate(VelocityView.java:517) ~[na:na]
        at org.springframework.web.servlet.view.velocity.VelocityView.doRender(VelocityView.java:462) ~[na:na]
        at org.springframework.web.servlet.view.velocity.VelocityView.renderMergedTemplateModel(VelocityView.java:292) ~[na:na]
        at org.springframework.web.servlet.view.AbstractTemplateView.renderMergedOutputModel(AbstractTemplateView.java:167) ~[na:na]
        at org.springframework.web.servlet.view.AbstractView.render(AbstractView.java:303) ~[na:na]
        at org.springframework.web.servlet.DispatcherServlet.render(DispatcherServlet.java:1228) ~[na:na]
        at org.springframework.web.servlet.DispatcherServlet.processDispatchResult(DispatcherServlet.java:1011) ~[na:na]
        at org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:955) ~[na:na]
        at org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:877) ~[na:na]
        at org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:966) ~[na:na]
        ... 42 common frames omitted
12:17:47.605 - WARN [org.eclipse.jetty.server.HttpChannel:481] - Could not send response error 500: javax.servlet.ServletException: org.springframework.web.util.NestedServletException: Request processing failed; nested exception is java.lang.IllegalStateException: STREAM
12:26:53.811 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:26:53.812 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=199<=200,i=168,q=4}
12:26:58.494 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:26:58.494 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=199<=200,i=191,q=4}
12:27:06.994 - WARN [org.eclipse.jetty.io.SelectorManager:315] - Exception while notifying connection SslConnection at 2b640ca{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection at 7982116a{IDLE}
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:28:48.202 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:30:21.149 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in [FAILED toString()]
12:30:49.946 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=195<=200,i=188,q=0}
12:31:09.737 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:31:20.793 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=194<=200,i=186,q=0}
12:31:22.329 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:31:54.615 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:32:00.976 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=193<=200,i=185,q=0}
12:32:11.918 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:32:17.410 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=193<=200,i=184,q=0}
12:32:41.996 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:32:46.144 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=192<=200,i=183,q=0}
12:32:57.329 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:33:06.519 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=192<=200,i=183,q=0}
12:33:14.547 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:33:19.584 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:610] -
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:33:21.377 - WARN [org.eclipse.jetty.util.thread.QueuedThreadPool:617] - Unexpected thread death: org.eclipse.jetty.util.thread.QueuedThreadPool$3 at 54c2aa8e in qtp2008362258{STARTED,10<=192<=200,i=183,q=0}
12:33:55.001 - WARN [org.eclipse.jetty.io.SelectorManager:315] - Exception while notifying connection SslConnection at 6325cf22{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection at 2dd4b956{IDLE}
java.lang.OutOfMemoryError: GC overhead limit exceeded
12:34:15.786 - WARN [org.eclipse.jetty.io.SelectorManager:315] - Exception while notifying connection SslConnection at 167b8f2d{NEED_UNWRAP,eio=-1/-1,di=-1} -> HttpConnection at f2f4557{IDLE}
java.lang.OutOfMemoryError: GC overhead limit exceeded
13:39:12.848 - INFO [org.eclipse.jetty.server.ServerConnector:306] - Stopped ServerConnector at 9a19a45{SSL-http/1.1}{0.0.0.0:8443}
13:39:12.856 - INFO [org.eclipse.jetty.server.ServerConnector:306] - Stopped ServerConnector at 159ac15f{SSL-http/1.1}{0.0.0.0:8444}
13:39:12.871 - INFO [/idp:2052] - Destroying Spring FrameworkServlet 'idp'
13:39:12.980 - INFO [/idp:2052] - Closing Spring root WebApplicationContext
13:39:13.312 - INFO [org.eclipse.jetty.server.handler.ContextHandler:865] - Stopped o.e.j.w.WebAppContext at 5ad122c0{/idp,[file:/var/www/jettybase/tmp/jetty-0.0.0.0-8443-idp.war-_idp-any-4649516724403521893.dir/webinf/, jar:file:/opt/shibboleth-idp/war/idp.war!/],UNAVAILABLE}{/opt/shibboleth-idp/war/idp.war}

The Shibboleth Log appeared just alright with nothing special to point out.

Has somebody else encountered this or have any idea of what can we wrong? I would give more information of our configuration but I'm afraid to put too much unnecessary text.

I have reasons to believe it is related to the IP authentication flow. Might it be related that in the shibboleth log appears this constantly?:

2015-06-16 13:40:10,656 - INFO [net.shibboleth.idp.authn.impl.SelectAuthenticationFlow:121] - Profile Action SelectAuthenticationFlow: Moving incomplete flow authn/IPAddress to intermediate set

Regards,
Cesc

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://shibboleth.net/pipermail/users/attachments/20150616/50a5793a/attachment-0001.html>

More information about the users mailing list