PDA

View Full Version : [Mondrian] Thread hangs with RolapStar.clearAggregationRequests



Richard Emberson
02-24-2007, 05:30 PM
QA testing on a linux box with 1.4.2_13 x86 with the
Mondrian and JPivot head, the Java
process pegged at 99% for 2 1/2 hours (before I
was called and I looked into it). Using 'kill -3 pid',
I got the following thread dumps:


INFO | jvm 1 | 2007/02/24 11:46:10 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)


INFO | jvm 1 | 2007/02/24 12:02:20 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)

INFO | jvm 1 | 2007/02/24 12:17:29 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:17:29 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)

INFO | jvm 1 | 2007/02/24 12:29:42 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:29:42 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)

INFO | jvm 1 | 2007/02/24 12:56:11 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
java.util.AbstractList.iterator(AbstractList.java:336)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:244)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)


INFO | jvm 1 | 2007/02/24 12:56:39 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)


INFO | jvm 1 | 2007/02/24 12:56:40 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
java.util.AbstractList$Itr.hasNext(AbstractList.java:415)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:575)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)

INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)

INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)


INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)

INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapStar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCube.java:1127)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapResult.<init>(RolapResult.java:230)

Based upon the code, this looks like an impossible situation.
Note the times of the thread dumps. At no time was
this thread above the RolapStar.clearAggregationRequests method.
My current explanation it a hotspot compilation error.
Anyone have other thoughts or have seen this before?
Thanks.

Richard

--
Quis custodiet ipsos custodes:
This email message is for the sole use of the intended recipient(s) and
may contain confidential information. Any unauthorized review, use,
disclosure or distribution is prohibited. If you are not the intended
recipient, please contact the sender by reply email and destroy all
copies of the original message.
_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian

Pappyn Bart
02-26-2007, 05:00 AM
Richard,

There is a problem in recordAggregationRequest. It will log each
request, even if it's already logged.
This will lead to clearAggregationRequests to have a lot of work
clearing all requests.

I have changed this and will check it in.

Bart

-----Original Message-----
From: mondrian-bounces (AT) pentaho (DOT) org [mailto:mondrian-bounces (AT) pentaho (DOT) org]
On Behalf Of Richard Emberson
Sent: zaterdag 24 februari 2007 22:24
To: mondrian (AT) pentaho (DOT) org
Subject: [Mondrian] Thread hangs with RolapStar.clearAggregationRequests


QA testing on a linux box with 1.4.2_13 x86 with the Mondrian and JPivot
head, the Java process pegged at 99% for 2 1/2 hours (before I was
called and I looked into it). Using 'kill -3 pid', I got the following
thread dumps:


INFO | jvm 1 | 2007/02/24 11:46:10 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)


INFO | jvm 1 | 2007/02/24 12:02:20 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)

INFO | jvm 1 | 2007/02/24 12:17:29 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:17:29 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)

INFO | jvm 1 | 2007/02/24 12:29:42 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:29:42 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)

INFO | jvm 1 | 2007/02/24 12:56:11 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
java.util.AbstractList.iterator(AbstractList.java:336)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:244)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)


INFO | jvm 1 | 2007/02/24 12:56:39 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)


INFO | jvm 1 | 2007/02/24 12:56:40 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
java.util.AbstractList$Itr.hasNext(AbstractList.java:415)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:575)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)

INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)

INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - waiting to
lock <0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)


INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)

INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
daemon prio=1 tid=0x6bab7638 nid=0x781 runnable [0x69433000..0x69435228]
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractList$Itr.remove(AbstractList.java:436)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
java.util.AbstractCollection.remove(AbstractCollection.java:255)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec4c8> (a java.util.ArrayList)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCache(RolapSt
ar.java:506)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
<0x841ec398> (a mondrian.rolap.RolapStar)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCache(RolapCu
be.java:1127)
INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
mondrian.rolap.RolapResult.<init>(RolapResult.java:230)

Based upon the code, this looks like an impossible situation.
Note the times of the thread dumps. At no time was this thread above the
RolapStar.clearAggregationRequests method.
My current explanation it a hotspot compilation error.
Anyone have other thoughts or have seen this before?
Thanks.

Richard

--
Quis custodiet ipsos custodes:
This email message is for the sole use of the intended recipient(s) and
may contain confidential information. Any unauthorized review, use,
disclosure or distribution is prohibited. If you are not the intended
recipient, please contact the sender by reply email and destroy all
copies of the original message.
_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian

______________________________________________________________________
This email has been scanned by the Email Security System.
______________________________________________________________________
_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian

Julian Hyde
02-26-2007, 05:50 AM
Bart,

It seems to me that clearAggregationRequests is an O(n ^ 2) algorithm:
aggregationRequests.remove(bitKey) takes O(n) time and
localAggregationRequests contains O(n) elements.

Your change will make localAggregationRequests smaller, but how much
smaller?

If there's a possibility that this routine is going to be a performance
bottleneck, let's tame it now.

You could make it an O(n . Log n) algorithm by putting
localAggregationRequests into a HashSet temporarily, scanning
aggregationRequests just once, and probing into the set each time.

So,

private void clearAggregationRequests() {
synchronized (aggregationRequests) {

for (BitKey bitKey :
localAggregationRequests.get()) {

// Remove first occurence
aggregationRequests.remove(bitKey);
}
localAggregationRequests.get().clear();
}
}

becomes

/**
* Clears the aggregation requests created by the current thread.
*/
private void clearAggregationRequests() {
synchronized (aggregationRequests) {
if (localAggregationRequests.get().isEmpty()) {
return;
}
// Build a set of requests for efficient probing.
Set<BitKey> localAggregationRequestSet =
new HashSet<BitKey>(
localAggregationRequests.get());
Iterator<BitKey> iter = aggregationRequests.iterator();
while (iter.hasNext()) {
BitKey bitKey = iter.next();
if (localAggregationRequestSet.contains(
aggregationRequest)) {
iter.remove();
// Make sure that bitKey is not removed
// more than once - other occurrences might
// exist for other threads.
localAggregationRequestSet.remove(bitKey);
if (localAggregationRequestSet.isEmpty()) {
// Nothing further to do
break;
}
}
}
localAggregationRequests.get().clear();
}
}

Julian

> -----Original Message-----
> From: mondrian-bounces (AT) pentaho (DOT) org
> [mailto:mondrian-bounces (AT) pentaho (DOT) org] On Behalf Of Pappyn Bart
> Sent: Monday, February 26, 2007 12:55 AM
> To: Mondrian developer mailing list
> Subject: RE: [Mondrian] Thread hangs with
> RolapStar.clearAggregationRequests
>
> Richard,
>
> There is a problem in recordAggregationRequest. It will log each
> request, even if it's already logged.
> This will lead to clearAggregationRequests to have a lot of work
> clearing all requests.
>
> I have changed this and will check it in.
>
> Bart
>
> -----Original Message-----
> From: mondrian-bounces (AT) pentaho (DOT) org
> [mailto:mondrian-bounces (AT) pentaho (DOT) org]
> On Behalf Of Richard Emberson
> Sent: zaterdag 24 februari 2007 22:24
> To: mondrian (AT) pentaho (DOT) org
> Subject: [Mondrian] Thread hangs with
> RolapStar.clearAggregationRequests
>
>
> QA testing on a linux box with 1.4.2_13 x86 with the Mondrian
> and JPivot
> head, the Java process pegged at 99% for 2 1/2 hours (before I was
> called and I looked into it). Using 'kill -3 pid', I got the following
> thread dumps:
>
>
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
>
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
>
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
>
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> java.util.AbstractList.iterator(AbstractList.java:336)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:244)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
>
>
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
>
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
> java.util.AbstractList$Itr.hasNext(AbstractList.java:415)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:575)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
>
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
>
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapResult.<init>(RolapResult.java:230)
>
> Based upon the code, this looks like an impossible situation.
> Note the times of the thread dumps. At no time was this
> thread above the
> RolapStar.clearAggregationRequests method.
> My current explanation it a hotspot compilation error.
> Anyone have other thoughts or have seen this before?
> Thanks.
>
> Richard
>
> --
> Quis custodiet ipsos custodes:
> This email message is for the sole use of the intended
> recipient(s) and
> may contain confidential information. Any unauthorized review, use,
> disclosure or distribution is prohibited. If you are not the intended
> recipient, please contact the sender by reply email and destroy all
> copies of the original message.
> _______________________________________________
> Mondrian mailing list
> Mondrian (AT) pentaho (DOT) org
> http://lists.pentaho.org/mailman/listinfo/mondrian
>
> ______________________________________________________________________
> This email has been scanned by the Email Security System.
> ______________________________________________________________________
> _______________________________________________
> Mondrian mailing list
> Mondrian (AT) pentaho (DOT) org
> http://lists.pentaho.org/mailman/listinfo/mondrian
>

_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian

Pappyn Bart
02-26-2007, 06:00 AM
Julian,

Most queries do not generate a lot of aggregation requests. But the
query I wrote today, using
LinRegPoint and Rank, resulted in a lot of aggregation requests (>
65000) - before my change.

After my change, only 3 requests where left in the list. There will be
no more aggregation requests
per thread than there will be aggregations, since only the unique
requests are kept now.

So the question to be asked is how much aggregations will there be used
by one query.

Your proposal will be faster if there are a lot of aggregations used by
one query and a lot
of concurrent threads. Of course, there is some overhead in allocating
and creating the new HashSet.

It's up to you if you wish to put these changes in, no problem by me.

Bart


-----Original Message-----
From: mondrian-bounces (AT) pentaho (DOT) org [mailto:mondrian-bounces (AT) pentaho (DOT) org]
On Behalf Of Julian Hyde
Sent: maandag 26 februari 2007 10:41
To: 'Mondrian developer mailing list'
Subject: RE: [Mondrian] Thread hangs with
RolapStar.clearAggregationRequests

Bart,

It seems to me that clearAggregationRequests is an O(n ^ 2) algorithm:
aggregationRequests.remove(bitKey) takes O(n) time and
localAggregationRequests contains O(n) elements.

Your change will make localAggregationRequests smaller, but how much
smaller?

If there's a possibility that this routine is going to be a performance
bottleneck, let's tame it now.

You could make it an O(n . Log n) algorithm by putting
localAggregationRequests into a HashSet temporarily, scanning
aggregationRequests just once, and probing into the set each time.

So,

private void clearAggregationRequests() {
synchronized (aggregationRequests) {

for (BitKey bitKey :
localAggregationRequests.get()) {

// Remove first occurence
aggregationRequests.remove(bitKey);
}
localAggregationRequests.get().clear();
}
}

becomes

/**
* Clears the aggregation requests created by the current thread.
*/
private void clearAggregationRequests() {
synchronized (aggregationRequests) {
if (localAggregationRequests.get().isEmpty()) {
return;
}
// Build a set of requests for efficient probing.
Set<BitKey> localAggregationRequestSet =
new HashSet<BitKey>(
localAggregationRequests.get());
Iterator<BitKey> iter = aggregationRequests.iterator();
while (iter.hasNext()) {
BitKey bitKey = iter.next();
if (localAggregationRequestSet.contains(
aggregationRequest)) {
iter.remove();
// Make sure that bitKey is not removed
// more than once - other occurrences might
// exist for other threads.
localAggregationRequestSet.remove(bitKey);
if (localAggregationRequestSet.isEmpty()) {
// Nothing further to do
break;
}
}
}
localAggregationRequests.get().clear();
}
}

Julian

> -----Original Message-----
> From: mondrian-bounces (AT) pentaho (DOT) org
> [mailto:mondrian-bounces (AT) pentaho (DOT) org] On Behalf Of Pappyn Bart
> Sent: Monday, February 26, 2007 12:55 AM
> To: Mondrian developer mailing list
> Subject: RE: [Mondrian] Thread hangs with
> RolapStar.clearAggregationRequests
>
> Richard,
>
> There is a problem in recordAggregationRequest. It will log each
> request, even if it's already logged.
> This will lead to clearAggregationRequests to have a lot of work
> clearing all requests.
>
> I have changed this and will check it in.
>
> Bart
>
> -----Original Message-----
> From: mondrian-bounces (AT) pentaho (DOT) org
> [mailto:mondrian-bounces (AT) pentaho (DOT) org]
> On Behalf Of Richard Emberson
> Sent: zaterdag 24 februari 2007 22:24
> To: mondrian (AT) pentaho (DOT) org
> Subject: [Mondrian] Thread hangs with
> RolapStar.clearAggregationRequests
>
>
> QA testing on a linux box with 1.4.2_13 x86 with the Mondrian and
> JPivot head, the Java process pegged at 99% for 2 1/2 hours (before I
> was called and I looked into it). Using 'kill -3 pid', I got the
> following thread dumps:
>
>
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 11:46:10 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
>
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:02:20 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:17:29 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
>
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:29:42 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:47:03 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
>
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> java.util.AbstractList.iterator(AbstractList.java:336)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:244)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:11 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
>
>
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:39 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
>
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
> java.util.AbstractList$Itr.hasNext(AbstractList.java:415)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:575)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:40 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
>
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - waiting to
> lock <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:41 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:42 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
>
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
>
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] "TP-Processor2"
> daemon prio=1 tid=0x6bab7638 nid=0x781 runnable
> [0x69433000..0x69435228]
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractList$Itr.remove(AbstractList.java:436)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> java.util.AbstractCollection.remove(AbstractCollection.java:255)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.clearAggregationRequests(RolapStar.java:578)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec4c8> (a java.util.ArrayList)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapStar.pushAggregateModificationsToGlobalCac
> he(RolapSt
> ar.java:506)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] - locked
> <0x841ec398> (a mondrian.rolap.RolapStar)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapCube.pushAggregateModificationsToGlobalCac
> he(RolapCu
> be.java:1127)
> INFO | jvm 1 | 2007/02/24 12:56:43 | [java] at
> mondrian.rolap.RolapResult.<init>(RolapResult.java:230)
>
> Based upon the code, this looks like an impossible situation.
> Note the times of the thread dumps. At no time was this thread above
> the RolapStar.clearAggregationRequests method.
> My current explanation it a hotspot compilation error.
> Anyone have other thoughts or have seen this before?
> Thanks.
>
> Richard
>
> --
> Quis custodiet ipsos custodes:
> This email message is for the sole use of the intended
> recipient(s) and
> may contain confidential information. Any unauthorized review, use,
> disclosure or distribution is prohibited. If you are not the intended

> recipient, please contact the sender by reply email and destroy all
> copies of the original message.
> _______________________________________________
> Mondrian mailing list
> Mondrian (AT) pentaho (DOT) org
> http://lists.pentaho.org/mailman/listinfo/mondrian
>
> ______________________________________________________________________
> This email has been scanned by the Email Security System.
> ______________________________________________________________________
> _______________________________________________
> Mondrian mailing list
> Mondrian (AT) pentaho (DOT) org
> http://lists.pentaho.org/mailman/listinfo/mondrian
>

_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian

______________________________________________________________________
This email has been scanned by the Email Security System.
______________________________________________________________________
_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian

Julian Hyde
02-26-2007, 07:40 AM
OK, I'll put my changes in. The overhead of creating the HashSet should
be negligible if things are as you describe, and well worth if it avoids
a quadratic worst-case scenario.

Julian

> -----Original Message-----
> From: mondrian-bounces (AT) pentaho (DOT) org
> [mailto:mondrian-bounces (AT) pentaho (DOT) org] On Behalf Of Pappyn Bart
> Sent: Monday, February 26, 2007 1:57 AM
> To: Mondrian developer mailing list
> Subject: RE: [Mondrian] Thread hangs with
> RolapStar.clearAggregationRequests
>
> Julian,
>
> Most queries do not generate a lot of aggregation requests. But the
> query I wrote today, using
> LinRegPoint and Rank, resulted in a lot of aggregation requests (>
> 65000) - before my change.
>
> After my change, only 3 requests where left in the list.
> There will be
> no more aggregation requests
> per thread than there will be aggregations, since only the unique
> requests are kept now.
>
> So the question to be asked is how much aggregations will
> there be used
> by one query.
>
> Your proposal will be faster if there are a lot of
> aggregations used by
> one query and a lot
> of concurrent threads. Of course, there is some overhead in
> allocating
> and creating the new HashSet.
>
> It's up to you if you wish to put these changes in, no problem by me.
>
> Bart

_______________________________________________
Mondrian mailing list
Mondrian (AT) pentaho (DOT) org
http://lists.pentaho.org/mailman/listinfo/mondrian