Hi,
we have seen TM1 server crashes with PA 2.0.3 at some pages.
We would like to know the last REST Requests, that Canvas sent to TM1 before it crashed, in order to localize the issue.
How do we turn on the Request Logging from the Canvas (Server) site?
Hi @mwirtz,
There is a logger named ActionBase that you can turn on. You can specifically activate this logger in the < canvas app >WEB-INF/classes/log4j.properties file by adding the following line:
log4j.logger.ActionBase=DEBUG
–
Paul
@cw-ch yes this is relevant and helpful.
I will setup a test environment and investigate as soon as I have the chance.
I think that @mwirtz started this thread after I asked him directly if he knows anything about PA crashes or Canvas logging.
I managed to localize the crash and get the debug info from Canvas. However I don’t know how to analyze this.
Here is the Canvas log. There isn’t anything available on the TM1 side.
2018-01-11 09:42:38 com.cubewise.rest.api.a DEBUG ActionBase:373 Not cached: http://localhost:9599/api/v1/Dimensions('%7DAPQ%20C3%20Canvas%20View%20Measure')/Hierarchies('%7DAPQ%20C3%20Canvas%20View%20Measure')/ElementAttributes?_t=1515660158903
2018-01-11 09:42:38 com.cubewise.rest.api.a DEBUG ActionBase:435 Added to cache: http://localhost:9599/api/v1/Dimensions('%7DAPQ%20C3%20Canvas%20View%20Measure')/Hierarchies('%7DAPQ%20C3%20Canvas%20View%20Measure')/ElementAttributes?_t=1515660158903
2018-01-11 09:42:38 com.cubewise.rest.api.a DEBUG ActionBase:373 Not cached: http://localhost:9599/api/v1/ExecuteMDX?$expand=Axes($select%3DTuples%3B$expand%3DTuples($select%3DMembers%3B$expand%3DMembers($select%3DName,UniqueName,Parent,Weight%3B$expand%3DElement($select%3DType,Index,Level)%3B$expand%3DParent($select%3DUniqueName%3B$expand%3DElement($select%3DName,UniqueName))))),Cells($select%3DValue)&_t=1515660158908
2018-01-11 09:42:44 com.cubewise.rest.api.DimensionAction ERROR DimensionAction:270 Unable to retrieve element dimensions [Connection refused: connect; <--- java.net.ConnectException: Connection refused: connect]
jodd.http.HttpException: Connection refused: connect; <--- java.net.ConnectException: Connection refused: connect
at jodd.http.HttpRequest.open(HttpRequest.java:623)
at jodd.http.HttpRequest.open(HttpRequest.java:608)
at com.cubewise.rest.api.a.send(SourceFile:386)
at com.cubewise.rest.api.a.executePost(SourceFile:260)
at com.cubewise.rest.api.a.executePost(SourceFile:233)
at com.cubewise.rest.api.m.getElementsByElementRequest(SourceFile:240)
at com.cubewise.rest.api.DimensionAction.listDimensionsElementsByPost(SourceFile:257)
at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at jodd.madvoc.ActionRequest.invokeActionMethod(ActionRequest.java:355)
at jodd.madvoc.ActionRequest$2.invoke(ActionRequest.java:241)
at jodd.madvoc.ActionRequest.invoke(ActionRequest.java:345)
at jodd.madvoc.interceptor.ServletConfigInterceptor.intercept(ServletConfigInterceptor.java:71)
at jodd.madvoc.interceptor.BaseActionInterceptor.invoke(BaseActionInterceptor.java:38)
at jodd.madvoc.ActionRequest.invoke(ActionRequest.java:345)
at jodd.madvoc.ActionRequest$1.invoke(ActionRequest.java:222)
at jodd.madvoc.ActionRequest.invoke(ActionRequest.java:345)
at jodd.madvoc.component.MadvocController.invoke(MadvocController.java:164)
at com.cubewise.rest.RestServletFilter.doFilter(SourceFile:65)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.filters.ExpiresFilter.doFilter(ExpiresFilter.java:1201)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at com.cubewise.rest.RestSecurityFilter.doFilter(SourceFile:108)
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:219)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
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.net.ConnectException: Connection refused: connect
at java.net.DualStackPlainSocketImpl.connect0(Native Method)
at java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:79)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:172)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:579)
at java.net.Socket.connect(Socket.java:528)
at java.net.Socket.<init>(Socket.java:425)
at java.net.Socket.<init>(Socket.java:208)
at javax.net.DefaultSocketFactory.createSocket(SocketFactory.java:271)
at jodd.http.net.SocketHttpConnectionProvider.createSocket(SocketHttpConnectionProvider.java:100)
at jodd.http.net.SocketHttpConnectionProvider.createHttpConnection(SocketHttpConnectionProvider.java:71)
at jodd.http.HttpRequest.open(HttpRequest.java:621)
... 41 more
---[cause]------------------------------------------------------------------------
java.net.ConnectException: Connection refused: connect
at java.net.DualStackPlainSocketImpl.connect0(Native Method)
at java.net.DualStackPlainSocketImpl.socketConnect(DualStackPlainSocketImpl.java:79)
at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:339)
at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:200)
at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:182)
at java.net.PlainSocketImpl.connect(PlainSocketImpl.java:172)
at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392)
at java.net.Socket.connect(Socket.java:579)
at java.net.Socket.connect(Socket.java:528)
at java.net.Socket.<init>(Socket.java:425)
at java.net.Socket.<init>(Socket.java:208)
at javax.net.DefaultSocketFactory.createSocket(SocketFactory.java:271)
at jodd.http.net.SocketHttpConnectionProvider.createSocket(SocketHttpConnectionProvider.java:100)
at jodd.http.net.SocketHttpConnectionProvider.createHttpConnection(SocketHttpConnectionProvider.java:71)
at jodd.http.HttpRequest.open(HttpRequest.java:621)
at jodd.http.HttpRequest.open(HttpRequest.java:608)
at com.cubewise.rest.api.a.send(SourceFile:386)
at com.cubewise.rest.api.a.executePost(SourceFile:260)
at com.cubewise.rest.api.a.executePost(SourceFile:233)
at com.cubewise.rest.api.m.getElementsByElementRequest(SourceFile:240)
at com.cubewise.rest.api.DimensionAction.listDimensionsElementsByPost(SourceFile:257)
at sun.reflect.GeneratedMethodAccessor61.invoke(Unknown Source)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at jodd.madvoc.ActionRequest.invokeActionMethod(ActionRequest.java:355)
at jodd.madvoc.ActionRequest$2.invoke(ActionRequest.java:241)
at jodd.madvoc.ActionRequest.invoke(ActionRequest.java:345)
at jodd.madvoc.interceptor.ServletConfigInterceptor.intercept(ServletConfigInterceptor.java:71)
at jodd.madvoc.interceptor.BaseActionInterceptor.invoke(BaseActionInterceptor.java:38)
at jodd.madvoc.ActionRequest.invoke(ActionRequest.java:345)
at jodd.madvoc.ActionRequest$1.invoke(ActionRequest.java:222)
at jodd.madvoc.ActionRequest.invoke(ActionRequest.java:345)
at jodd.madvoc.component.MadvocController.invoke(MadvocController.java:164)
at com.cubewise.rest.RestServletFilter.doFilter(SourceFile:65)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at org.apache.catalina.filters.ExpiresFilter.doFilter(ExpiresFilter.java:1201)
at org.apache.catalina.core.ApplicationFilterChain.internalDoFilter(ApplicationFilterChain.java:241)
at org.apache.catalina.core.ApplicationFilterChain.doFilter(ApplicationFilterChain.java:208)
at com.cubewise.rest.RestSecurityFilter.doFilter(SourceFile:108)
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:219)
at org.apache.catalina.core.StandardContextValve.invoke(StandardContextValve.java:110)
at org.apache.catalina.authenticator.AuthenticatorBase.invoke(AuthenticatorBase.java:506)
at org.apache.catalina.core.StandardHostValve.invoke(StandardHostValve.java:169)
at org.apache.catalina.valves.ErrorReportValve.invoke(ErrorReportValve.java:103)
at org.apache.catalina.core.StandardEngineValve.invoke(StandardEngineValve.java:116)
at org.apache.catalina.connector.CoyoteAdapter.service(CoyoteAdapter.java:445)
at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1115)
at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:637)
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)Hi,
none of the 2 requests at the top are listed in the TM1 Logs. Is that correct?
That sounds familiar. When we analysed TM1 crashes, I oberserved that the actual request, that made the TM1 Server crash was usually not listed in the TM1 Logs…
So my understanding of the logs is this:
The first request (against the ElementAttributes) or the second request (the MDX Query) or maybe the combination of both at the same time made the TM1 Server crash.
Hi @mwirtz
That is correct. The TM1 log looks clean, like nothing happened.
To replicate this issue, you just need to open the view definition in Apliqo UX and click on a dimension inside any view.
The server will immediately stop responding.
Hi @rcantor,
I don’t think this crash has much to do with Canvas other than it is executing the MDX statement. The first two calls get a list of element attributes on the }APQ C3 Canvas View Measure dimension and then the third is an MDX query. Fourth line (Connection refused: connect;) is Canvas trying to send another request to TM1 but at this point the server has already crashed…
We can add some extra info to Canvas so you can see the MDX query as well. As with most crashes it is probably a combination of things but if you know the MDX query you can test the single request with Postman.
Hi @tryan
I managed to isolate the crash on a controlled environment and on the IBM sample model as well.
It appears to be something related to the MDX Filter function.
If I run the following request through the REST client it will make the PA server crash.
http://10.77.19.60:9599/api/v1/ExecuteMDX?$expand=Axes($select%3DTuples%3B$expand%3DTuples($select%3DMembers%3B$expand%3DMembers($select%3DName,UniqueName,Parent,Weight%3B$expand%3DElement($select%3DType,Index,Level)%3B$expand%3DParent($select%3DUniqueName%3B$expand%3DElement($select%3DName,UniqueName))))),Cells($select%3DValue)&_t=1515762609656
{"MDX": "Select {FILTER({[}APQ C3 Canvas View Measure].[DashboardSettings]},[}APQ C3 Canvas View].([}APQ C3 Canvas View].[apq-c3-fin-dashboard1], [}APQ Dimensions].[Currency]) <> \"NA\")} on rows, {[}ElementAttributes_}APQ C3 Canvas View Measure].[Class]} on columns from [}ElementAttributes_}APQ C3 Canvas View Measure] "}
For the IBM sample model we can use the following example to replicate the crash:
{"MDX": "Select {FILTER( {[month].[}Export.All]}, [PriceCube].([actvsbud].[Actual], [region].[Argentina], [model].[S Series 1.8 L Sedan]) <> 0)} on rows, {[}ElementAttributes_month].[Caption]} on columns from [}ElementAttributes_month] "}
The same query works fine on the 10.2.2 version or if we take out the FILTER function.
@cw-ch I think this is something which we should raise to IBM. This only happens on the latest version of PA.
Awesome work @rcantor
As you know (or might not if you’re lucky). Creating tickets with IBM is a bit of work as everything needs to be spelled out in immense detail to the support analysts.
So before raising with IBM I need the following
Hi @prajtar,
according to IBM Fix Central website the version 11.1.4.2 is still PA 2.0.3 (updated on 13.12.2017).
Hi @cw-ch,
Here are the required details:
http://10.77.19.60:9599/api/v1/ExecuteMDX?$expand=Axes($select%3DTuples%3B$expand%3DTuples($select%3DMembers%3B$expand%3DMembers($select%3DName,UniqueName,Parent,Weight%3B$expand%3DElement($select%3DType,Index,Level)%3B$expand%3DParent($select%3DUniqueName%3B$expand%3DElement($select%3DName,UniqueName))))),Cells($select%3DValue)&_t=1515762609656
c) Set the following Headers:
content-type: application/json; charset=utf-8
accept: application/json,text/plain;odata.metadata=none
Authorization: Basic YWRtaW46YXBwbGU=
Please note that the Authorization can be different depending on the user name, password and CAM id (if any). However ARC will be able to auto generate this.
d) Set the following Body for the command. This contains the MDX statement which triggers the crash.
{“MDX”: "Select {FILTER( {[month].[}Export.All]}, [PriceCube].([actvsbud].[Actual], [region].[Argentina], [model].[S Series 1.8 L Sedan]) <> 0)} on rows, {[}ElementAttributes_month].[Caption]} on columns from [}ElementAttributes_month] "}
e) send the API command to the server. The TM1 server will immediately crash.
Hi @mmioduski,
Thanks for clarifying that!
That is actually pretty confusing to have one version (PAL 2.0.3) go by two different file versions:
@Vincent, I think it would be nice to update the blog post for this oddity.
Thanks @prajtar, I updated the article. It’s a bit confusing that IBM changed the TM1 server version number of PAL v2.0.3
I have raised this crash and have from IBM the case number TS000090430.
(Not surprisingly) their suggestion is to upgrade to PA 2.0.3 IF4 which has PA build number 2.0.3.1009 and the file version number for tm1sd is 11.1.4.3
(@Vincent you might want to edit the version number article again!)
Let’s see if it does fix it.
Hi @cw-ch
Where did you find this PAL 2.0.3 IF4? It is not available in the IBM Planning Analytics 2.0 Fix lists:
http://www-01.ibm.com/support/docview.wss?uid=swg27049229
Cheers,
Vincent