Ayub Khan created ATLAS-1068:
--------------------------------
Summary: Under stress conditions, all Atlas threads run in to
BLOCKED state and returns 500 server error for a valid search query.
Key: ATLAS-1068
URL: https://issues.apache.org/jira/browse/ATLAS-1068
Project: Atlas
Issue Type: Bug
Affects Versions: 0.7-incubating
Reporter: Ayub Khan
Priority: Critical
During some random experiments to check Atlas behavior under stress, found that
most of the Atlas threads are in blocked state and Atlas server was throwing
below error in the logs.
Steps to repro:
* Stop Atlas server
* Start a batch command to create some 1000 hive ctas queries
* Parallely run fulltext queries( using threads ) from command line (query=*)
* Once the query count reaches to 100. Now in the logs, below exception can be
seen.
* Also Jstack trace of all the threads shows that all threads are in blocked
state.
*Impact: Response from Atlas is very slow, most of the times request timesout
or 500 server error is observed.*
Atlas application log snapshot:
{noformat}
2016-07-30 16:09:52,894 WARN - [qtp511473681-13:] ~ Could not send response
error 500: java.lang.IllegalStateException: Committed (HttpChannel:481)
2016-07-30 16:09:52,896 INFO - [qtp511473681-13 -
8ccee9fb-8efb-43b2-8eba-2920cad69e04:] ~ Audit: admin/172.22.114.250 performed
request GET
http://atlas-r6-1088-simple-2.openstacklocal:21000/api/atlas/discovery/search/fulltext?limit=25&query=*&FSBX=HQKDJ
(172.22.114.26) at time 2016-07-30T16:09Z (AuditFilter:91)
2016-07-30 16:09:52,896 INFO - [qtp511473681-13 -
8ccee9fb-8efb-43b2-8eba-2920cad69e04:] ~ Audit:
admin/172.22.114.250-172.22.114.250 performed request GET
http://atlas-r6-1088-simple-2.openstacklocal:21000/api/atlas/discovery/search/fulltext?limit=25&query=*&FSBX=HQKDJ
(172.22.114.26) at time 2016-07-30T16:09Z (AUDIT:104)
2016-07-30 16:09:52,897 INFO - [qtp511473681-13 -
8ccee9fb-8efb-43b2-8eba-2920cad69e04:] ~ Converted query string with 1
replacements: [v."entityText":(*)] => [pad_t:(*)] (IndexSerializer:648)
2016-07-30 16:09:53,070 ERROR - [qtp511473681-15 -
9ea08823-81dd-4fcf-8324-32c760e9950c:] ~ The response of the
WebApplicationException cannot be utilized as the response is already
committed. Re-throwing to the HTTP container (WebApplicationImpl:1514)
javax.ws.rs.WebApplicationException: java.lang.Exception: Error writing JSON
object.
at
com.sun.jersey.json.impl.provider.entity.JSONObjectProvider.writeTo(JSONObjectProvider.java:113)
at
com.sun.jersey.json.impl.provider.entity.JSONObjectProvider$App.writeTo(JSONObjectProvider.java:65)
at
com.sun.jersey.spi.container.ContainerResponse.write(ContainerResponse.java:302)
at
com.sun.jersey.server.impl.application.WebApplicationImpl._handleRequest(WebApplicationImpl.java:1510)
at
com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1419)
at
com.sun.jersey.server.impl.application.WebApplicationImpl.handleRequest(WebApplicationImpl.java:1409)
at
com.sun.jersey.spi.container.servlet.WebComponent.service(WebComponent.java:409)
at
com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:558)
at
com.sun.jersey.spi.container.servlet.ServletContainer.service(ServletContainer.java:733)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
at
com.google.inject.servlet.ServletDefinition.doServiceImpl(ServletDefinition.java:287)
at
com.google.inject.servlet.ServletDefinition.doService(ServletDefinition.java:277)
at
com.google.inject.servlet.ServletDefinition.service(ServletDefinition.java:182)
at
com.google.inject.servlet.ManagedServletPipeline.service(ManagedServletPipeline.java:91)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:85)
at
org.apache.atlas.web.filters.AuditFilter.doFilter(AuditFilter.java:71)
at
com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:82)
at
com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:119)
at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:133)
at com.google.inject.servlet.GuiceFilter$1.call(GuiceFilter.java:130)
at
com.google.inject.servlet.GuiceFilter$Context.call(GuiceFilter.java:203)
at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:130)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
at
org.springframework..web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at
org.apache.atlas.web.filters.AtlasAuthorizationFilter.doFilter(AtlasAuthorizationFilter.java:154)
at
org.springframework..web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework..web.access.intercept.FilterSecurityInterceptor.invoke(FilterSecurityInterceptor.java:118)
at
org.springframework.security.web.access.intercept.FilterSecurityInterceptor.doFilter(FilterSecurityInterceptor.java:84)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.access.ExceptionTranslationFilter.doFilter(ExceptionTranslationFilter.java:113)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.session.SessionManagementFilter.doFilter(SessionManagementFilter.java:103)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.authentication.AnonymousAuthenticationFilter.doFilter(AnonymousAuthenticationFilter.java:113)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.apache.atlas.web.filters.AtlasCSRFPreventionFilter$ServletFilterHttpInteraction.proceed(AtlasCSRFPreventionFilter.java:232)
at
org.apache.atlas.web.filters.AtlasCSRFPreventionFilter.handleHttpInteraction(AtlasCSRFPreventionFilter.java:177)
at
org.apache.atlas.web.filters.AtlasCSRFPreventionFilter.doFilter(AtlasCSRFPreventionFilter.java:187)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.apache.atlas.web.filters.AtlasAuthenticationFilter.doFilter(AtlasAuthenticationFilter.java:301)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter.doFilter(SecurityContextHolderAwareRequestFilter.java:54)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.savedrequest.RequestCacheAwareFilter.doFilter(RequestCacheAwareFilter.java:45)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.authentication.www.BasicAuthenticationFilter.doFilter(BasicAuthenticationFilter.java:201)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.authentication.AbstractAuthenticationProcessingFilter.doFilter(AbstractAuthenticationProcessingFilter.java:183)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.authentication.logout.LogoutFilter.doFilter(LogoutFilter.java:105)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.context.SecurityContextPersistenceFilter.doFilter(SecurityContextPersistenceFilter.java:87)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:342)
at
org.springframework.security.web.FilterChainProxy.doFilterInternal(FilterChainProxy.java:192)
at
org.springframework.security.web.FilterChainProxy.doFilter(FilterChainProxy.java:160)
at
org.springframework.web.filter.DelegatingFilterProxy.invokeDelegate(DelegatingFilterProxy.java:346)
at
org.springframework.web.filter.DelegatingFilterProxy.doFilter(DelegatingFilterProxy.java:259)
at
org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1652)
at
org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:585)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
at
org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:577)
at
org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:223)
at
org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)
at
org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)
at
org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
at
org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)
at
org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
at
org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)
at org.eclipse.jetty.server.Server.handle(Server.java:499)
at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:310)
at
org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)
at
org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:540)
at
org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)
at
org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.Exception: Error writing JSON object.
... 75 more
Caused by: org.codehaus.jettison.json.JSONException
at org.codehaus.jettison.json.JSONObject.write(JSONObject.java:1385)
at org.codehaus.jettison.json.JSONArray.write(JSONArray.java:897)
at org.codehaus.jettison.json.JSONObject.write(JSONObject.java:1372)
at
com.sun.jersey.json.impl.provider.entity.JSONObjectProvider.writeTo(JSONObjectProvider.java:110)
... 74 more
Caused by: org.eclipse.jetty.io.EofException
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:192)
at org.eclipse.jetty.io.WriteFlusher.flush(WriteFlusher.java:408)
at org.eclipse.jetty.io.WriteFlusher.write(WriteFlusher.java:302)
at
org.eclipse.jetty.io.AbstractEndPoint.write(AbstractEndPoint.java:129)
at
org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:690)
at
org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:246)
at
org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:208)
at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:480)
at
org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:768)
at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:801)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:147)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:140)
at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:355)
at
org.springframework.security.web.context.SaveContextOnUpdateOrErrorResponseWrapper$SaveContextServletOutputStream.write(SaveContextOnUpdateOrErrorResponseWrapper.java:435)
at
com.sun.jersey.spi.container.servlet.WebComponent$Writer.write(WebComponent.java:300)
at
com.sun.jersey.spi.container.ContainerResponse$CommittingOutputStream.write(ContainerResponse.java:135)
at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
at sun.nio.cs.StreamEncoder.implWrite(StreamEncoder.java:282)
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:125)
at sun.nio.cs.StreamEncoder.write(StreamEncoder.java:135)
at java.io.OutputStreamWriter.write(OutputStreamWriter.java:220)
at java.io.Writer.write(Writer.java:157)
at org.codehaus.jettison.json.JSONObject.write(JSONObject.java:1374)
... 77 more
Caused by: java.io.IOException: Connection reset by peer
at sun.nio.ch.FileDispatcherImpl.write0(Native Method)
at sun.nio.ch.SocketDispatcher.write(SocketDispatcher.java:47)
at sun.nio.ch.IOUtil.writeFromNativeBuffer(IOUtil.java:93)
at sun.nio.ch.IOUtil.write(IOUtil.java:65)
at sun.nio.ch.SocketChannelImpl.write(SocketChannelImpl.java:471)
at org.eclipse.jetty.io.ChannelEndPoint.flush(ChannelEndPoint.java:170)
... 99 more
2016-07-30 16:09:53,122 WARN - [qtp511473681-15 -
9ea08823-81dd-4fcf-8324-32c760e9950c:] ~ Committed before 500 null
(Response:565)
{noformat}
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
