Random IllegalArgumentException and NullPointerException exceptions when executing queries in parallel threads

Julian Hyde added a comment - 21/May/12 3:45 PM Luc, Can you take a look at this one? It looks bad (and not just for JRuby users). Worst concurrency issue we've seen for a while. Just spend 10 minutes looking at it and let me know if you could think of a probable cause. We can ask the Raimonds to gather extra diagnostics.

Luc Boudreau added a comment - 22/May/12 10:51 AM The error seems to be caused by the rollup code when it performs in-memory aggregations. The code expects the data cells to be one of Integer, Double or Long. Seems like the data that gets passed is of another type. The other issue is an actual bug. We are performing a "+=" operation on objects that might be null. Raimonds, can you reproduce this issue and set a breakpoint, or find a way to discover what is the data type that wasn't encountered for?

Raimonds Simanovskis added a comment - 28/May/12 8:09 AM I managed to set a breakpoint using jdb and got more information about this issue. The issue is with this aggregate method (RollapAggregator.java starting from line 50):             public Object aggregate(List<Object> rawData) {                 assert rawData.size() > 0;                 if (rawData.get(0) instanceof Integer) {                     int totalValue = 0;                     for (Object data : rawData) {                         totalValue += (Integer)data;                     }                     return totalValue;                 }                 if (rawData.get(0) instanceof Double) {                     double totalValue = 0d;                     for (Object data : rawData) {                         totalValue += (Double)data;                     }                     return totalValue;                 }                 if (rawData.get(0) instanceof Long) {                     long totalValue = 0l;                     for (Object data : rawData) {                         totalValue += (Long)data;                     }                     return totalValue;                 }                 throw new IllegalArgumentException();             } When this method was failing it received as argument List of object but the first element of this list was null (and later in that list there were integers). But as you can see this method just check data type of first element and if it is null then exception is raised. The other exception was NullPointerException at this line:                         totalValue += (Double)data; In this case it is caused when first element of List was double but then later in the list was null value and casting null to Double raised NullPointerException. Is this information enough for you or do you need something more?

Luc Boudreau added a comment - 11/Jun/12 1:00 PM Assigning to triage. We have enough information to fix this.

Luc Boudreau added a comment - 17/Aug/12 10:14 AM Fixed in https://github.com/pentaho/mondrian/commit/48fa4b0b553a208f089616b121f5631a732cbcbd

Luc Boudreau added a comment - 17/Aug/12 10:46 AM Wrote some tests and found some issues. Will add more fixes.

Luc Boudreau added a comment - 17/Aug/12 10:55 AM - edited Added some unit tests and fixed a few issues I've discovered while writing the tests. https://github.com/pentaho/mondrian/commit/25283a2b90b8e8741bcb5bb209b9511ace22cdfb https://github.com/pentaho/mondrian/commit/f0bf51f02ba297ecb1ed77036e62a3414b5f876c New tests are in : mondrian.rolap.FastBatchingCellReaderTest.testInMemoryAggSum() mondrian.rolap.FastBatchingCellReaderTest.testInMemoryAggMin() mondrian.rolap.FastBatchingCellReaderTest.testInMemoryAggMax()

Raimonds Simanovskis added a comment - 27/Aug/12 6:21 AM I tried the same test with the same data running many parallel queries and used latest Mondrian build from http://ci.pentaho.com/job/mondrian-git/48/ Unfortunately I again started to get different random exceptions when performing this test. All exceptions have the following stack traces org.olap4j.OlapException: mondrian gave exception while executing query     "root cause: java.lang.ClassCastException: java.lang.Integer cannot be cast to java.lang.Double",     "root cause: mondrian.rolap.agg.SegmentBuilder.rollup(SegmentBuilder.java:384)",     "root cause: mondrian.rolap.FastBatchingCellReader.loadAggregations(FastBatchingCellReader.java:299)",     "root cause: mondrian.rolap.RolapResult.phase(RolapResult.java:505)",     "root cause: mondrian.rolap.RolapResult.loadMembers(RolapResult.java:614)",     "root cause: mondrian.rolap.RolapResult.<init>(RolapResult.java:286)",     "mondrian/olap4j/MondrianOlap4jConnection.java:762:in `createException'",     "mondrian/olap4j/MondrianOlap4jStatement.java:421:in `executeOlapQueryInternal'",     "mondrian/olap4j/MondrianOlap4jPreparedStatement.java:72:in `executeQuery'", Here is example anonymized MDX statement which was giving this exception SELECT NON EMPTY CROSSJOIN({[Measures].[Actual hours], [Measures].[Actual / Estimated hours %], [Measures].[Estimated hours]}, HIERARCHIZE({[People].[All People], [People].[All People].Children, [People].[XXX].Children})) ON COLUMNS,       NON EMPTY EXCEPT(HIERARCHIZE({[Projects and Tasks].[Company].Members, [Projects and Tasks].[XXX].Children, [Projects and Tasks].[XXX].[AAA].Children, [Projects and Tasks].[XXX].[AAA].[(no milestone)].Children, [Projects and Tasks].[XXX].[BBB].Children, [Projects and Tasks].[XXX].[BBB].[(no milestone)].Children, [Projects and Tasks].[CCC].Children, [Projects and Tasks].[CCC].[DDD].Children, [Projects and Tasks].[CCC].[DDD].[(no milestone)].Children}), {[Projects and Tasks].[CCC], [Projects and Tasks].[CCC].[EEE], [Projects and Tasks].[CCC].[FFF], [Projects and Tasks].[CCC].[GGG], [Projects and Tasks].[HHH]}) ON ROWS       FROM [Projects]       WHERE ([Project Status].[Active], [Completion Status].[All Completion Statuses], [Time].[2012]) Is this enough information for this issue or do you need something more?

Luc Boudreau added a comment - 27/Aug/12 9:27 AM Raimonds, This exception is different. It happens at a later stage. It seems that the cells which form the segment to be rolled up are of different classes. Not sure how that's possible. Is there any way to reproduce this on FoodMart / Steelwheels? That would speed up greatly the fix. BTW. Not that I want to dismiss this issue (I want to get to the bottom of it) but if you need to use this Mondrian version despite this snag in the rollup code, you can disable the rollup by setting mondrian.rolap.EnableInMemoryRollup=false

Raimonds Simanovskis added a comment - 30/Aug/12 10:06 AM The issue is that this error also happens when there are many MDX queries executed in parallel - I am able to reproduce just on one set of production data when running several reports in parallel. When I try to execute this MDX statement sequentially then there are no errors. And these errors also happen when Mondrian cache is empty, after first errors when trying to re-execute these queries then there are no errors. So therefore have not tried to reproduce these errors on FoodMart / Steelwheels as I don't know how what exact case I should reproduce :) I tried mondrian.rolap.EnableInMemoryRollup=false and then everything worked fine without any errors. But I could not find more detailed documentation about this EnableInMemoryRollup option - how it could affect overall system performance? And are there any benefits to switch from Mondrian 3.3 to Mondrian 3.4 with EnableInMemoryRollup=false?

Raimonds Simanovskis added a comment - 30/Aug/12 11:51 AM I managed to catch this exception with jdb breakpoint and here are the values of variables when this exception happens in SegmentBuilder.java line 384                     data[offset] =                         (Double)rollupAggregator.aggregate(entry.getValue()); --------------------- > print cellValues.entrySet()  cellValues.entrySet() = "[(0, 1, 2)=[1.0, 0.5, 1.0, 1.0, null, null, 1.5, 1.5, null, 1.0, 2.0, 2.0, 1.0, 3.0, null, 4.0, 4.5, 2.5, 1.0, 1.5, 2.0, 0.5, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, 7.0, 4.5, 10.5, null, null, null, null, null, 14.0, null, 5.5, 26.5, 16.0, null, null, 8.0, null, 19.5, null, 17.5, null, 55.25, 35.75, 56.1, 54.5, 32.75, 44.35, 60.0, 36.0, 11.25, 2.75, 39.45, 42.8, 39.0, 35.25, null, 8.5, 3.25, null, null, null, 48.25, 39.25, 31.85, 39.5, 33.65, null, 7.0, 5.0, 1.5, 4.75, 1.0, 1.25, null, null, null, null, null, null, 1.5, null, null, null, null, null, null, null, null, null, null, null, null, null, 1.0, null, null, 2.75, null, null, null, null, null, null, null, null, null, 4.17, null, 11.5], (0, 2, 0)=[null, null], (0, 0, 1)=[null, null, null, null, null], (0, 2, 1)=[null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null], (0, 0, 2)=[null, null, null, null, null, null], (0, 4, 2)=[null, null], (0, 5, 2)=[null, null, null, null], (0, 1, 1)=[null, null, null, null, 3.5, 3.25, 3.5, 7.25, null, 1.0, null, null, null, null, null, null, null, null, null, null, null, null, 6.95, null, 6.0, 1.5, 5.5, 1.0, null, 1.5, 1.0, 4.0, null, 3.0, 2.0, null, null, null, 8.0, 1.0, 8.0, 6.0, null, null, 4.0, 2.0, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, 3.1, 4.0, 6.9, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, 3.0, null, 4.0, null, null, null, null, null, null, null, null, 14.5, null, null, null, 38.5, null, 67.5, 34.5, 3.0, 20.0, null, null, 3.25, 1.5, null, null, null, null, null, null, 0.5, 12.0, 1.5, 25.0, 1.0, 3.0, 1.5, null, 3.0, 5.3, null, null, null, null, 6.5, 1.0, 26.5, 2.0, 16.5, 6.0, null, 4.5, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, 43.5, 41.0, 42.0, 43.75, 8.5, 43.55, 34.5, 46.25, 41.5, 40.25, 33.0, 33.5, 38.25, 57.25, 49.0, 26.55, 41.05, 0.5, 5.0, 29.95, 16.4, 49.85, 31.6, 25.75, 39.0, 31.5, 44.25, 26.5, 35.6, 50.0, 32.3, 11.0, 21.9, 3.25, 7.75, 29.3, 9.0, 19.55, 9.0, 2.83, 47.0, 6.1, 40.0, 2.0, 38.75, 2.5, 34.6, 0.25, 31.3, 35.75, 7.33, 31.0, 37.0, 23.75, 23.25, null, 18.35, null, 19.0, null, 27.75, 28.5, null, 13.0, null, null, null, null, null, null, 7.5, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null], (0, 1, 0)=[null, null, 2.0, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, 43.0, 30.0, 2.5, 57.5, 7.0, 14.2, null, 3.5, 10.2, 3.5, 0.9, 12.0, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, null, 19.5, 1.5, 25.75, 11.0, 20.75, 26.5, 32.75, 25.6, 26.25, 33.75, 44.25, 25.25, 28.0, 28.75, 21.5, 12.0, 16.0, 30.0, 21.4, 18.75, 28.25, 9.75, 26.5, 27.25, 31.35, 26.85, 14.0, 6.0, 26.5, 36.6, 25.4, 19.3, 18.75, 4.5, 1.5, 2.0, 1.5], (0, 3, 1)=[null, null]]" > print peek  peek = "1.0" > print offset  offset = 6 > print entry.getValue()  entry.getValue() = "[null, null]" > print rollupAggregator.aggregate(entry.getValue())  rollupAggregator.aggregate(entry.getValue()) = "0" --------------------- Do I understand correctly that the issue is that when iterating through all other sets there were both double values and null values and therefore returned value was double. But then when iterating on last set there were only null values and then aggregated value was integer 0 and it could not be cast to double?

Raimonds Simanovskis added a comment - 27/Sep/12 12:53 PM It would be good either to change status from Resolved back to Open or create new issue for the current unresolved problem that I described. Would be very happy to hear any progress about this quite critical issue :)

Luc Boudreau added a comment - 05/Oct/12 7:36 AM This should be all fixed in https://github.com/pentaho/mondrian/commit/6ad920a317277855771d1a4dd0801d1d9f6ea6d4 Instead of doing a bunch of instanceof checks I'm using the measure datatype to determine the correct class to aggregate to.

Raimonds Simanovskis added a comment - 09/Oct/12 4:33 AM I tried to use latest build from http://ci.pentaho.com/job/mondrian-git/112/ and now all parallel queries (that previously were giving random failures) completed successfully. So it seems that this issue is fixed. Thanks a lot for the solution :)

Raimonds Simanovskis added a comment - 09/Oct/12 6:43 AM Testing this latest Mondrian build in production with the same many parallels queries got new error messages :( Here is the top of the stack trace: Mondrian::OLAP::Error: org.olap4j.OlapException: mondrian gave exception while executing query     "root cause: java.lang.ClassCastException: java.util.ArrayList cannot be cast to mondrian.rolap.SmartRestrictedMemberReader$AccessAwareMemberList",     "root cause: mondrian.rolap.SmartRestrictedMemberReader.getMemberChildren(SmartRestrictedMemberReader.java:37)",     "root cause: mondrian.rolap.RolapSchemaReader.internalGetMemberChildren(RolapSchemaReader.java:167)",     "root cause: mondrian.rolap.RolapSchemaReader.getMemberChildren(RolapSchemaReader.java:149)",     "root cause: mondrian.olap.DelegatingSchemaReader.getMemberChildren(DelegatingSchemaReader.java:246)",     "root cause: mondrian.olap.fun.FunUtil.getNonEmptyMemberChildren(FunUtil.java:2164)",     "mondrian/olap4j/MondrianOlap4jConnection.java:827:in `createException'",     "mondrian/olap4j/MondrianOlap4jStatement.java:421:in `executeOlapQueryInternal'",     "mondrian/olap4j/MondrianOlap4jPreparedStatement.java:72:in `executeQuery'",     "mondrian/olap4j/MondrianOlap4jPreparedStatement.java:42:in `executeQuery'" As I see in SmartRestrictedMemberReader.java the failing code is                 (AccessAwareMemberList) reader.cacheHelper                     .getChildrenFromCache(parentMember, constraint); Do you have idea why this is sometimes failing or do you need some output from jdb to find out what is the result of getChildrenFromCache method call in this case?

Luc Boudreau added a comment - 09/Oct/12 9:38 AM This is a different issue. MONDRIAN-1259 It should be fixed in the following hours. Marking this issue as fixed for now.