[ https://issues.apache.org/jira/browse/CASSANDRA-5360?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
amorton updated CASSANDRA-5360: ------------------------------- Attachment: 5360.txt > Disable Thread Biased Locking in the JVM > ---------------------------------------- > > Key: CASSANDRA-5360 > URL: https://issues.apache.org/jira/browse/CASSANDRA-5360 > Project: Cassandra > Issue Type: Improvement > Components: Core > Affects Versions: 1.0.12, 1.1.10, 1.2.3 > Reporter: amorton > Priority: Minor > Attachments: 5360.txt, cassandra-biased-locking-tests.txt > > > Biased Locking > (https://blogs.oracle.com/dave/entry/biased_locking_in_hotspot) is enabled by > default in JVM 6 and is designed to optimise applications where a locks are > normally used by one thread. This is the opposite of how the worker pools > cassandra work. Disabling Biased Locking (-XX:-UseBiasedLocking) has yielded > improvements of 5% to 10% in throughput and reduced JVM pauses. > Details follow. > h1. Application Pausing > The following was observed on a 16 core EC2 SSD instance... > {noformat} > Heap after GC invocations=32 (full 0): > par new generation total 1024000K, used 59799K [0x00000006fae00000, > 0x0000000745e00000, 0x0000000745e00000) > eden space 819200K, 0% used [0x00000006fae00000, 0x00000006fae00000, > 0x000000072ce00000) > from space 204800K, 29% used [0x000000072ce00000, 0x0000000730865ff8, > 0x0000000739600000) > to space 204800K, 0% used [0x0000000739600000, 0x0000000739600000, > 0x0000000745e00000) > concurrent mark-sweep generation total 2965504K, used 416618K > [0x0000000745e00000, 0x00000007fae00000, 0x00000007fae00000) > concurrent-mark-sweep perm gen total 22592K, used 22578K > [0x00000007fae00000, 0x00000007fc410000, 0x0000000800000000) > } > Total time for which application threads were stopped: 0.0175680 seconds > Total time for which application threads were stopped: 0.0008680 seconds > Total time for which application threads were stopped: 0.0004030 seconds > Total time for which application threads were stopped: 0.0006460 seconds > Total time for which application threads were stopped: 0.0009210 seconds > Total time for which application threads were stopped: 0.0007250 seconds > Total time for which application threads were stopped: 0.0016340 seconds > Total time for which application threads were stopped: 0.0005570 seconds > Total time for which application threads were stopped: 0.0007270 seconds > Total time for which application threads were stopped: 0.0010170 seconds > Total time for which application threads were stopped: 0.0006240 seconds > Total time for which application threads were stopped: 0.0013250 seconds > {Heap before GC invocations=32 (full 0): > par new generation total 1024000K, used 878999K [0x00000006fae00000, > 0x0000000745e00000, 0x0000000745e00000) > eden space 819200K, 100% used [0x00000006fae00000, 0x000000072ce00000, > 0x000000072ce00000) > from space 204800K, 29% used [0x000000072ce00000, 0x0000000730865ff8, > 0x0000000739600000) > to space 204800K, 0% used [0x0000000739600000, 0x0000000739600000, > 0x0000000745e00000) > concurrent mark-sweep generation total 2965504K, used 416618K > [0x0000000745e00000, 0x00000007fae00000, 0x00000007fae00000) > concurrent-mark-sweep perm gen total 22784K, used 22591K > [0x00000007fae00000, 0x00000007fc440000, 0x0000000800000000) > 2013-03-15T21:21:17.015+0000: 1038.849: [GC Before GC: > Statistics for BinaryTreeDictionary: > {noformat} > The extra "were stopped" lines were annoying me, and the JVM Performance book > offered this explanation: > bq. If there happens to be additional safepoints between garbage collections, > the output will show Application time: and Total time for which application > threads were stopped: messages for each safepoint that occurs between garbage > collections. > h1. Safepoints > Safepoints are times when the JVM pauses all application threads to run a > single VM thread that needs to know the heap is not going to change. GC is > one cause, others are (from Java Performance): > bq. There many other safepoints, such as biased locking revocation, thread > stack dumps, thread suspension or stopping (i.e., java.lang.Thread.stop() > method), and numerous inspection and modification operations requested > through JVMTI. > On my MBP (corei7, 16Gb, ssd) I ran cassandra with the stress test with > -XX:-PrintGCApplicationConcurrentTime and -XX:-PrintSafepointStatistics which > outputs information when the JVM exits. The biased-locking-tests.txt > attachment shows that stress took 1m 23 seconds to complete and the > safepoint statistics show most of the pauses were to revoke biased locks. > A second test was run (both with a clean data dir) with biased locking > disabled that took 1 minute 18 seconds. The safepoint stats did not include > any pauses to revoke biased locks (in attachment). > The GC logs did show some application pauses not related to GC, which are > also included in the safepoint output and not related to revoking biased > locks. > > -- This message is automatically generated by JIRA. If you think it was sent incorrectly, please contact your JIRA administrators For more information on JIRA, see: http://www.atlassian.com/software/jira