Hi Danilo,
The time accounted in java.lang.Object.wait and
java.net.PlainSocketImpl.socketAccept is just waiting time, so this one
does not consume cpu. The profiler does not account for active cpu time
but just for time spent in a method (which is likely to be long if you
wait and there is no activity).
From the second trace, it looks like
java.net.PlainDatagramSocketImpl.receive0 has a predominant cost. I
don't know why your cpu usage is so high for networking. If you remove
the time accounted in the methods just waiting, you spend all the time
in network I/O. So there might be a problem with your network driver
configuration that does not offload anything and keeps the cpu busy.
Another explanation would be a group communication misconfiguration (try
a config without group communication to see if the numbers change
drastically). Otherwise, it does not look like you have any hotspot in
the controller code (which is a good news for me :-) ).
Best regards,
Emmanuel
I did some tests with HPROF, and I noticed different results using cpu=times
and cpu=samples. In the former case 17.81% is java.lang.Object.wait, in the
latter 24.14% is java.net.PlainSocketImpl.socketAccept.
Hope those results can help (I found them little confusing...)
Danilo Levantesi
------------------------------------------
Configuration
------------------------------------------
1 Dedicated controller, 2 PostgreSQL backends
100Mb dedicated LAN
Controller:
Slackware 12, 2.6.21.5-smp, 2Gb RAM, JVM 1.5.0_15
JDBCBench (read-only queries):
Clients: 10
Transactions per client: 250
------------------------------------------
HPROF options:
heap=all
cpu=times
monitor=y
format=a
depth=5
interval=10
cutoff=0.0001
lineno=y
thread=n
doe=y
msa=n
force=y
verbose=y
CPU TIME (ms) BEGIN (total = 42353256) Mon Apr 28 10:49:33 2008
rank self accum count trace method
1 17.81% 17.81% 17 355483 java.lang.Object.wait
2 4.91% 22.72% 9 325458 java.net.PlainSocketImpl.accept
3 4.77% 27.49% 467 350536 java.net.PlainDatagramSocketImpl.receive
4 4.61% 32.10% 2 360904 java.lang.Object.wait
5 4.45% 36.56% 4 355482 java.lang.Object.wait
6 4.44% 41.00% 2 366671
org.continuent.sequoia.common.locks.DeadlockDetectionThread.run
7 4.41% 45.41% 2 366670
org.continuent.sequoia.controller.connection.VariablePoolConnectionManager$RemoveIdleConnectionsThread.run
8 2.47% 47.88% 1 387344 java.lang.ref.ReferenceQueue.remove
9 2.42% 50.30% 8501 305696 java.lang.ref.ReferenceQueue.remove
10 2.39% 52.68% 202 352582 java.net.PlainSocketImpl.accept
11 2.38% 55.06% 188 305685 java.lang.Object.wait
12 2.35% 57.41% 12 358500 java.net.PlainSocketImpl.accept
13 2.31% 59.72% 1 367902 java.lang.Object.wait
14 2.31% 62.03% 1 367904 java.lang.Object.wait
15 2.30% 64.33% 16 351203 java.lang.Object.wait
16 2.30% 66.62% 1476 348085
org.continuent.appia.core.TimerManager.goToSleep
17 2.29% 68.91% 1 365236 java.lang.Object.wait
18 2.25% 71.17% 21 354809 java.lang.Object.wait
19 2.11% 73.27% 817 358521 java.net.PlainDatagramSocketImpl.receive
20 2.05% 75.32% 7520 359053 java.net.SocketInputStream.read
21 2.03% 77.35% 6 330056 java.lang.ref.ReferenceQueue.remove
22 1.62% 78.98% 1733522 359723 java.util.regex.Pattern$Bound.check
23 1.25% 80.22% 11 366896
org.continuent.sequoia.controller.virtualdatabase.VirtualDatabaseWorkerThread.run
24 1.03% 81.25% 3384549 359720 java.lang.CharacterDataLatin1.getType
25 1.00% 82.25% 1733522 359718 java.lang.Character.codePointAt
[cut below 1%]
------------------------------------------
Clients: 10
Transactions per client: 250
HPROF options:
heap=all
cpu=samples
monitor=y
format=a
depth=5
interval=10
cutoff=0.0001
lineno=y
thread=n
doe=y
msa=n
force=y
verbose=y
CPU SAMPLES BEGIN (total = 188764) Mon Apr 28 11:03:58 2008
rank self accum count trace method
1 24.14% 24.14% 45561 305806 java.net.PlainSocketImpl.socketAccept
2 23.63% 47.76% 44599 312013 java.net.PlainDatagramSocketImpl.receive0
3 11.81% 59.58% 22301 311638 java.net.PlainSocketImpl.socketAccept
4 11.67% 71.25% 22030 313674 java.net.PlainSocketImpl.socketAccept
5 11.67% 82.92% 22029 313675 java.net.PlainDatagramSocketImpl.receive0
6 2.54% 85.46% 4798 306656 java.net.SocketInputStream.socketRead0
7 2.51% 87.97% 4735 313799 java.net.SocketInputStream.socketRead0
8 0.65% 88.62% 1232 312093 java.net.SocketInputStream.socketRead0
9 0.57% 89.19% 1079 309857
org.postgresql.core.v3.QueryExecutorImpl.receiveFields
10 0.53% 89.72% 999 313806 java.lang.Object.<init>
11 0.30% 90.02% 569 302519 java.lang.Object.<init>
12 0.24% 90.26% 446 314038 java.lang.Object.<init>
13 0.21% 90.47% 405 300213 java.lang.Object.<init>
14 0.21% 90.68% 396 314041 java.nio.HeapByteBuffer.<init>
15 0.18% 90.87% 342 314066 java.lang.Object.<init>
16 0.15% 91.02% 287 309330 java.lang.StringCoding.trim
17 0.14% 91.15% 255 314065 java.lang.Object.<init>
18 0.11% 91.26% 205 309643 java.lang.StringCoding$CharsetSE.encode
19 0.10% 91.36% 188 314087 java.lang.Object.<init>
20 0.09% 91.45% 178 313038 java.lang.Thread.yield
21 0.09% 91.55% 177 314052 java.lang.Object.<init>
22 0.09% 91.64% 174 300185 java.lang.StringCoding.trim
23 0.09% 91.73% 173 313747 java.lang.String.<init>
24 0.09% 91.82% 172 313909 java.lang.Object.<init>
25 0.09% 91.91% 171 314073 java.lang.Object.<init>
26 0.09% 92.00% 169 314074 java.lang.Object.<init>
27 0.09% 92.09% 166 313536 java.lang.Object.<init>
28 0.09% 92.18% 163 312213 java.lang.Object.<init>
29 0.09% 92.26% 163 314067 java.lang.Object.<init>
30 0.08% 92.35% 159 314083 java.lang.Object.<init>
31 0.08% 92.43% 158 314078 java.lang.Object.<init>
32 0.08% 92.52% 157 314090 java.lang.Object.<init>
33 0.08% 92.60% 156 314091 java.lang.Object.<init>
34 0.08% 92.68% 155 313835 java.lang.Object.<init>
35 0.08% 92.76% 152 309273 java.lang.Object.<init>
[cut]
Il Friday 25 April 2008 16:02:31 Emmanuel Cecchet ha scritto:
Hi,
Your observation is completely true: this piece of configuration is
part of one of the many tests I did and I forgot it in the
configuration file. By the way, I've just thrown it away, but no
changes in results: high cpu utilization still exists...
May it depend on some operating system settings? But in this case, I
have high load under Windows too, and it sounds strange.
Or some JVM setting? I tried to increase heap size (-Xmx1024m
-Xms1024m) without results.
Is there a "certified" platform/configuration to run Sequoia on?
I have not been running performance tests on Windows for quite a long
time so I can't tell.
Most Linux distributions work fine. Continuent certifies its products on
RedHat, I personally use Fedora on my workstation.
It would be interesting to use hprof
(http://java.sun.com/developer/technicalArticles/Programming/HPROF.html)
to see where this cpu consumption comes from. This might help finding
out something obviously wrong.
Your feedback is much appreciated,
Emmanuel
_______________________________________________
Sequoia mailing list
[email protected]
https://forge.continuent.org/mailman/listinfo/sequoia
--
Emmanuel Cecchet - Research scientist
EPFL - LABOS/DSLAB - IN.N 317
Phone: +41-21-693-7558
_______________________________________________
Sequoia mailing list
[email protected]
https://forge.continuent.org/mailman/listinfo/sequoia
