No message after connection host error

[DSantonastaso]

Using an analysis that takes more time to set up mondrian, it does not show any message to the user of a lost connection. The error is only shown in the log:

2013-03-05 22:27:10,042 ERROR [com.eyeq.pivot4j.primefaces.exception.Pivot4JExceptionHandler] Unhandled exception has occurred org.apache.myfaces.view.facelets.el.ContextAwareELException: javax.el.ELException: java.lang.RuntimeException: org.olap4j.OlapException: Connection is closed.

Complete log ( http://pastebin.com/VB78Rtwy )

The error only occurs if the analysis is longer than the time set in parameter mondrian.rolap.queryTimeout

[mysticfall]

http://pastebin.com/25Qf8YrU

[mysticfall]

@DSantonastaso Could you do another test for me?

First, shutdown the server and delete the pentaho.log file then without opening any other Pivot4J report windows than the one you need to reproduce the problem, reproduce the connection closed error and attach the whole pentaho.log file.

Thanks!

[DSantonastaso]

Hi, the log: http://www.susydany.it/clienti/pivot4j/pentaho.zip

Thank you very much

[mysticfall]

@DSantonastaso The log shows that it fails to parse the Mondrian schema file due to missing 'name' attribute somewhere in the content :

2013-03-07 09:24:02,671 ERROR [org.pentaho.platform.plugin.action.mondrian.catalog.MondrianCatalogHelper] MondrianCatalogHelper.ERROR_0008 - an error occurred
org.eigenbase.xom.XOMException: In Schema: Attribute 'name' is unset and has no default value.
    at mondrian.olap.MondrianDef$Schema.<init>(MondrianDef.java:146)
    at org.pentaho.platform.plugin.action.mondrian.catalog.MondrianCatalogHelper.makeSchema(MondrianCatalogHelper.java:813)
    at org.pentaho.platform.plugin.action.mondrian.catalog.MondrianCatalogHelper.loadCatalogsIntoCache(MondrianCatalogHelper.java:689)
    at org.pentaho.platform.plugin.action.mondrian.catalog.MondrianCatalogHelper.init(MondrianCatalogHelper.java:229)
    at org.pentaho.platform.plugin.action.mondrian.catalog.MondrianCatalogHelper.listCatalogs(MondrianCatalogHelper.java:467)
    at com.eyeq.pivot4j.pentaho.datasource.PentahoDataSourceManager.getCatalogs(PentahoDataSourceManager.java:61)
    at com.eyeq.pivot4j.pentaho.ui.PentahoCatalogChooser.getCatalogs(PentahoCatalogChooser.java:54)

Could you confirm that if this error does not affect the current problem?

And I forgot to tell you that you should bump the log level up before reproduce the problem. Please open 'biserver-ce/tomcat/webapps/pentaho/WEB-INF/classes/log4j.xml' and paste below lines and repeat the process :

    <category name="com.eyeq.pivot4j" additivity="false">
        <priority value="debug" />
        <appender-ref ref="CONSOLE" />
    </category>

Thanks, and sorry for the inconvinience!

[DSantonastaso]

I do not think that's the problem, because changing the parameter of timeoout no error occurred. Below is the new log http://www.susydany.it/clienti/pivot4j/pentahofull.zip

Thanks

[mysticfall]

From the log file, it seems that an ajax request is hanging forever which blocks consequent 'keep alive' requests so after sufficient time is passed, the state manager think the view is expired and clean up the view state and close the connection.

I think we can prevent this from happening by making the keep alive polling request to be asynchronous. However I still have no idea why that long running query does not fail early with a timeout exception like shown in my log file.

I'll commit the related change and see if it really fixes this issue.

[mysticfall]

@DSantonastaso I'm sorry, but I was unable to pinpoint the cause of the problem from the last log file you posted.

It involves two different connections and view states, so it's rather confusing to trace the problem. Anyway, what I found out so far from the log is following :

• Request is made on the first page of the plugin, but it is failing because a save file of other plugin (possibly the old Analytics plugin) is mistakenly registered as a Mondrian schema file. I suppose it would making new Pivot4J report impossible, but from the following log entries, I can see that you were able to create a new report. Strange...
• After a new report was created, it seems it's working as expected till you issue a long running query which took 15 seconds. By the way, what was the value of your mondrian.rolap.queryTimeout? I thought it would be such that would issue a timeout when a query is running like 15 seconds, as you mentioned that the problem is only reproducible in such a scenario. However, from the log file, there was no timeout which is a bit strange to me.
• After that long running query, it seems that you have created a new report, but I have no idea what has become of the old one. Was there any visual feedback after that long running query got executed? Did you close the tab and opened a new one? I need to know what happened to understand what caused the issue.
• Again, the long running query is executed on the new report. And during that time, the abandoned old report seems to be expired and so its connection is closed by the plugin.
• We have a connection closed exception. And from the circumstance, it seems that its from the old report, which was still trying to render the big result till the connection is closed.
• At this time, the session itself is invalidated and the new report is also cleared from the memory, so causing another connection lost problem. I'm not sure why is the session invalidated. Have you click logout button then?

So, I need to know, and want to make it clear that (1) why there was no query timeout occurred (2) what happened to the report that was executing the long running query (3) what is the actual and expected behavior in that situation, and finally (4) why there were more than 2 reports are involved in the test.

Sorry to burden you with all these details, but I really need more information to pursue any further.

Thanks!

[mysticfall]

After discussing the issue with @DSantonastaso on the IRC channel, I now understand that the problem is the application is not giving enough feedback when the query is taking too long.

Additionally, we should block the UI in that case to prevent users from issuing further requests also.

[mysticfall]

Blocking UI during request processing is now implemented with #101.