cassandra-commits mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From "Ryan McGuire (JIRA)" <j...@apache.org>
Subject [jira] [Updated] (CASSANDRA-5360) Disable Thread Biased Locking in the JVM
Date Thu, 04 Apr 2013 15:21:16 GMT

     [ https://issues.apache.org/jira/browse/CASSANDRA-5360?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]

Ryan McGuire updated CASSANDRA-5360:
------------------------------------

    Tester: enigmacurry
    
> 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
>         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

Mime
View raw message