Thank you for taking time to investigation.
Today I rerun the query and all the log are as follows.
Kylin_query.log:
root@MartiniTest000:/home/martini/kylin/logs# cat kylin_query.log
2016-06-16 09:04:10,795 DEBUG [http-bio-7070-exec-2] service.QueryService:291 :
getting table metas
2016-06-16 09:04:10,796 DEBUG [http-bio-7070-exec-2] service.QueryService:309 :
getting column metas
2016-06-16 09:04:10,804 DEBUG [http-bio-7070-exec-2] service.QueryService:323 :
done column metas
2016-06-16 09:04:25,880 DEBUG [http-bio-7070-exec-10] service.QueryService:291
: getting table metas
2016-06-16 09:04:25,882 DEBUG [http-bio-7070-exec-10] service.QueryService:309
: getting column metas
2016-06-16 09:04:25,889 DEBUG [http-bio-7070-exec-10] service.QueryService:323
: done column metas
2016-06-16 09:04:34,045 INFO [http-bio-7070-exec-10]
controller.QueryController:174 : Using project: CortanaTest
2016-06-16 09:04:34,046 INFO [http-bio-7070-exec-10]
controller.QueryController:175 : The original query: select count(distinct
userid) from cortanauu
2016-06-16 09:04:34,047 INFO [http-bio-7070-exec-10] service.QueryService:266
: The corrected query: select count(distinct userid) from cortanauu
LIMIT 50000
2016-06-16 09:04:34,104 INFO [http-bio-7070-exec-10] routing.QueryRouter:48 :
The project manager's reference is
org.apache.kylin.metadata.project.ProjectManager@419808ad
2016-06-16 09:04:34,105 INFO [http-bio-7070-exec-10] routing.QueryRouter:60 :
Find candidates by table CORTANAUU.CORTANAUU and project=CORTANATEST :
org.apache.kylin.query.routing.Candidate@f3ac47f
2016-06-16 09:04:34,105 INFO [http-bio-7070-exec-10] routing.QueryRouter:49 :
Applying rule: class
org.apache.kylin.query.routing.rules.RemoveUncapableRealizationsRule,
realizations before: [CortanaUUTest_clone(CUBE)], realizations after:
[CortanaUUTest_clone(CUBE)]
2016-06-16 09:04:34,105 INFO [http-bio-7070-exec-10] routing.QueryRouter:49 :
Applying rule: class org.apache.kylin.query.routing.rules.RealizationSortRule,
realizations before: [CortanaUUTest_clone(CUBE)], realizations after:
[CortanaUUTest_clone(CUBE)]
2016-06-16 09:04:34,106 INFO [http-bio-7070-exec-10] routing.QueryRouter:85 :
Adjust DimensionAsMeasure for FunctionDesc [expression=COUNT_DISTINCT,
parameter=ParameterDesc [type=column, value=USERID, nextParam=null],
returnType=null]
2016-06-16 09:04:34,106 INFO [http-bio-7070-exec-10] routing.QueryRouter:72 :
The realizations remaining: [CortanaUUTest_clone(CUBE)] And the final chosen
one is the first one
2016-06-16 09:04:34,152 DEBUG [http-bio-7070-exec-10]
enumerator.OLAPEnumerator:107 : query storage...
2016-06-16 09:04:34,405 DEBUG [http-bio-7070-exec-10]
enumerator.OLAPEnumerator:127 : return TupleIterator...
2016-06-16 09:06:46,286 ERROR [http-bio-7070-exec-10]
controller.QueryController:209 : Exception when execute sql
java.sql.SQLException: Error while executing SQL "select count(distinct userid)
from cortanauu
LIMIT 50000": Timeout visiting cube!
at org.apache.calcite.avatica.Helper.createException(Helper.java:56)
at org.apache.calcite.avatica.Helper.createException(Helper.java:41)
at
org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:143)
at
org.apache.calcite.avatica.AvaticaStatement.executeQuery(AvaticaStatement.java:186)
at
org.apache.kylin.rest.service.QueryService.execute(QueryService.java:361)
at
org.apache.kylin.rest.service.QueryService.queryWithSqlMassage(QueryService.java:273)
at
org.apache.kylin.rest.service.QueryService.query(QueryService.java:121)
at
org.apache.kylin.rest.service.QueryService$$FastClassByCGLIB$$4957273f.invoke(<generated>)
at net.sf.cglib.proxy.MethodProxy.invoke(MethodProxy.java:204)
at
org.springframework.aop.framework.Cglib2AopProxy$DynamicAdvisedInterceptor.intercept(Cglib2AopProxy.java:618)
at
org.apache.kylin.rest.service.QueryService$$EnhancerByCGLIB$$72e265c1.query(<generated>)
at
org.apache.kylin.rest.controller.QueryController.doQueryWithCache(QueryController.java:192)
at
org.apache.kylin.rest.controller.QueryController.query(QueryController.java:94)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.springframework.web.method.support.InvocableHandlerMethod.invoke(InvocableHandlerMethod.java:213)
at
org.springframework.web.method.support.InvocableHandlerMethod.invokeForRequest(InvocableHandlerMethod.java:126)
at
org.springframework.web.servlet.mvc.method.annotation.ServletInvocableHandlerMethod.invokeAndHandle(ServletInvocableHandlerMethod.java:96)
at
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.invokeHandlerMethod(RequestMappingHandlerAdapter.java:617)
at
org.springframework.web.servlet.mvc.method.annotation.RequestMappingHandlerAdapter.handleInternal(RequestMappingHandlerAdapter.java:578)
at
org.springframework.web.servlet.mvc.method.AbstractHandlerMethodAdapter.handle(AbstractHandlerMethodAdapter.java:80)
at
org.springframework.web.servlet.DispatcherServlet.doDispatch(DispatcherServlet.java:923)
at
org.springframework.web.servlet.DispatcherServlet.doService(DispatcherServlet.java:852)
at
org.springframework.web.servlet.FrameworkServlet.processRequest(FrameworkServlet.java:882)
at
org.springframework.web.servlet.FrameworkServlet.doPost(FrameworkServlet.java:789)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:646)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:303)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.apache.tomcat.websocket.server.WsFilter.doFilter(WsFilter.java:52)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.springframework.security.web.FilterChainProxy$VirtualFilterChain.doFilter(FilterChainProxy.java:330)
at
org.springframework.security.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.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.ui.DefaultLoginPageGeneratingFilter.doFilter(DefaultLoginPageGeneratingFilter.java:91)
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.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
com.thetransactioncompany.cors.CORSFilter.doFilter(CORSFilter.java:195)
at
com.thetransactioncompany.cors.CORSFilter.doFilter(CORSFilter.java:266)
at
org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at
org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at
org.apache.catalina.core.StandardWrapperValve.invoke(StandardWrapperValve.java:220)
at
org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:122)
at
org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:504)
at
org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:170)
at
org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at
org.apache.catalina.valves.AccessLogValve.invoke(AccessLogValve.java:950)
at
org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at
org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:421)
at
org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1074)
at
org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:611)
at
org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:316)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at
org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
at java.lang.Thread.run(Thread.java:745)
Caused by: java.lang.RuntimeException: Timeout visiting cube!
at
org.apache.kylin.storage.hbase.cube.v2.CubeHBaseEndpointRPC$ExpectedSizeIterator.next(CubeHBaseEndpointRPC.java:127)
at
org.apache.kylin.storage.hbase.cube.v2.CubeHBaseEndpointRPC$ExpectedSizeIterator.next(CubeHBaseEndpointRPC.java:81)
at
com.google.common.collect.TransformedIterator.next(TransformedIterator.java:48)
at com.google.common.collect.Iterators$6.hasNext(Iterators.java:583)
at
org.apache.kylin.storage.hbase.cube.v2.SequentialCubeTupleIterator.hasNext(SequentialCubeTupleIterator.java:96)
at
org.apache.kylin.query.enumerator.OLAPEnumerator.moveNext(OLAPEnumerator.java:74)
at Baz$1$1.moveNext(Unknown Source)
at
org.apache.calcite.linq4j.EnumerableDefaults.aggregate(EnumerableDefaults.java:112)
at
org.apache.calcite.linq4j.DefaultEnumerable.aggregate(DefaultEnumerable.java:107)
at Baz.bind(Unknown Source)
at
org.apache.calcite.jdbc.CalcitePrepare$CalciteSignature.enumerable(CalcitePrepare.java:326)
at
org.apache.calcite.jdbc.CalciteConnectionImpl.enumerable(CalciteConnectionImpl.java:281)
at
org.apache.calcite.jdbc.CalciteMetaImpl._createIterable(CalciteMetaImpl.java:545)
at
org.apache.calcite.jdbc.CalciteMetaImpl.createIterable(CalciteMetaImpl.java:536)
at
org.apache.calcite.avatica.AvaticaResultSet.execute(AvaticaResultSet.java:187)
at
org.apache.calcite.jdbc.CalciteResultSet.execute(CalciteResultSet.java:65)
at
org.apache.calcite.jdbc.CalciteResultSet.execute(CalciteResultSet.java:44)
at
org.apache.calcite.avatica.AvaticaConnection$1.execute(AvaticaConnection.java:566)
at
org.apache.calcite.jdbc.CalciteMetaImpl.prepareAndExecute(CalciteMetaImpl.java:578)
at
org.apache.calcite.avatica.AvaticaConnection.prepareAndExecuteInternal(AvaticaConnection.java:571)
at
org.apache.calcite.avatica.AvaticaStatement.executeInternal(AvaticaStatement.java:135)
... 80 more
2016-06-16 09:06:46,289 INFO [http-bio-7070-exec-10] service.QueryService:250
:
==========================[QUERY]===============================
SQL: select count(distinct userid) from cortanauu
User: ADMIN
Success: false
Duration: 0.0
Project: CortanaTest
Realization Names: [CortanaUUTest_clone]
Cuboid Ids: [1048062]
Total scan count: 0
Result row count: 0
Accept Partial: true
Is Partial Result: false
Hit Exception Cache: false
Storage cache used: false
Message: Error while executing SQL "select count(distinct userid) from
cortanauu LIMIT 50000": Timeout visiting cube!
==========================[QUERY]===============================
-----Original Message-----
From: hongbin ma [mailto:[email protected]]
Sent: Wednesday, June 15, 2016 10:09 PM
To: dev <[email protected]>
Subject: Re: Timeout visiting cube
actually, can you please attach latest 2 minutes' log before
2016-06-15 02:18:22,741?
it's still incomplete for our analysis
--
Regards,
*Bin Mahone | 马洪宾*
Apache Kylin:
https://na01.safelinks.protection.outlook.com/?url=http%3a%2f%2fkylin.io&data=01%7c01%7cjiaoli%40064d.mgd.microsoft.com%7ce53a04299632406e334208d395269be8%7c72f988bf86f141af91ab2d7cd011db47%7c1&sdata=vpTxGJMsJQ7CoMHsEjHWBxaRVgQWfLVp6mcuFmlqzzI%3d
Github: https://github.com/binmahone
