You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@cassandra.apache.org by "Ryan McGuire (JIRA)" <ji...@apache.org> on 2014/04/30 02:57:20 UTC
[jira] [Updated] (CASSANDRA-5360) Disable Thread Biased Locking in
the JVM
[ https://issues.apache.org/jira/browse/CASSANDRA-5360?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel ]
Ryan McGuire updated CASSANDRA-5360:
------------------------------------
Labels: qa-resolved (was: )
> 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
> Assignee: amorton
> Priority: Minor
> Labels: qa-resolved
> 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 was sent by Atlassian JIRA
(v6.2#6252)