We doubt there is another HBase side error before throwing the timeout error, which can be the root cause. As HBase client will retry several times, and each time has an timeout, so that error was output to kylin.log in several minutes later (0 - 20 minutes are possible). Please take a check to see whether it is true. Or if you can share the full kylin.log to somewhere like gist, that would be great;
2016-06-22 9:48 GMT+08:00 Jiaojiao Li <jia...@microsoft.com>: > In my case, related information is like this. > Kylin version: 1.5.2 > HBase version: HBase 0.98.4.2.2.9.0-3393 > Cube size: 13.16GB > Source records: 85,794,927 > Dimension number: 20 (several joint groups) > Measure type: bigint > SQL query: select count(distinct userid) from XXX LIMIT 50000 > > If you need more information please let me know. > > -----Original Message----- > From: ShaoFeng Shi [mailto:shaofeng...@apache.org] > Sent: Tuesday, June 21, 2016 10:51 PM > To: dev@kylin.apache.org; u...@kylin.apache.org > Cc: mahong...@apache.org > Subject: Re: Timeout visiting cube > > Hi all, > > Recently we noticed a couple of users are facing this timeout error, even > with some tiny cubes; We will try to re-produce it in our side first; If > you can provide more information about your case (like hbase version, cube > size, dimension nubmer, measure type, SQL query, etc), that would be great! > > 2016-06-20 9:52 GMT+08:00 Jiaojiao Li <jia...@microsoft.com>: > > > Any update for this issue or can you share your insight for it? > > Increase the value of *kylin.query.cube.visit.timeout.times* doesn't > > work for me. > > > > Thanks! > > > > -----Original Message----- > > From: Jiaojiao Li > > Sent: Thursday, June 16, 2016 5:15 PM > > To: dev <dev@kylin.apache.org> > > Cc: 'mahong...@apache.org' <mahong...@apache.org> > > Subject: RE: Timeout visiting cube > > > > 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:mahong...@apache.org] > > Sent: Wednesday, June 15, 2016 10:09 PM > > To: dev <dev@kylin.apache.org> > > 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%7ce53a04299632406e33 > > 4208d395269be8%7c72f988bf86f141af91ab2d7cd011db47%7c1&sdata=vpTxGJMsJQ > > 7CoMHsEjHWBxaRVgQWfLVp6mcuFmlqzzI%3d > > Github: https://github.com/binmahone > > > > > > -- > Best regards, > > Shaofeng Shi > -- Best regards, Shaofeng Shi