Thursday, 6 March 2014

Chasing pointers with scissors .. or something

Nitsan W has a great article on the dangers of using on heap pointers within the JVM. In fact Gil has a classically clear post on the same topic.

Try as I might though, I couldn't find someone who had posted a concrete example. Especially since rumours seem to abound that it's a possibility, it seemed a little bizarre that there were plenty of examples of "how to access unsafe" but none on "what not to do".

So I thought, it might be fun to put together a demo to show just how quickly this can cause problems. It's a contrived example, of course, so in the real world I'm sure it will take longer to show up, and will probably be more random.

The code is pretty simple, and self explanatory (I guess). Review the code and then run the example.

Just so:

[jason@freebsd01 ~/code/examples/pointers]$ mvn clean compile exec:exec
<< the usual maven build things >>
[INFO][INFO] --- exec-maven-plugin:1.1:exec (default-cli) @ pointers ---
[INFO] [GC 2621K->1388K(502464K), 0.0042790 secs]
<< lots of GC while the vm starts up >>
<< and now we get down to business >>
[INFO] initialising array
[INFO] address: 34913266488
[INFO] native address: 34913266488
[INFO] checking array:
[INFO] seems ok
[INFO] seems ok
<< carries on for a while >>
[INFO] seems ok
[INFO] seems ok
[INFO] seems ok
[INFO] making garbage
[INFO] seems ok
[INFO] seems ok
[INFO] seems ok
[INFO] seems ok
[INFO] seems ok
[INFO] [GC 132255K->129303K(502464K), 0.3024900 secs]
[INFO] seems ok
[INFO] oops! expected: 0; but found: 109260096
[INFO] inserted to map -> 1013558; map size ended at -> 950748
[INFO] garbage generator finished
[INFO] ------------------------------------------------------------------------
[INFO] BUILD SUCCESS
[INFO] ------------------------------------------------------------------------
[INFO] Total time: 14.938s
[INFO] Finished at: Thu Mar 06 22:29:41 EST 2014
[INFO] Final Memory: 10M/151M
[INFO] ------------------------------------------------------------------------


Build success!

Tuesday, 25 February 2014

Updating the Disruptor sample

Quick update to Disruptor sample

As a comment was posted on the previous blog asking about comparisons to the juc Executor implementations, I thought it was time to refresh the examples a little and update that with some additional examples and in particular a comparison to a thread pooled implementation (since that was the question).

The code simply does 10000 UDP "echo" packets, the service is expected to uppercase the characters. What I want to look at here is latency while bringing in an additional test to the mix.

This test is a pretty straightforward test - just looking to identify 99th percentile latency across a couple of scenarios. Since these are simple applications I've included a baseline blocking IO implementation to get a comparison.

Total runtime tests

The initial test is a total runtime test. This is a naive indicative number of relative performance. Test runs a number of 10K UDP request-response loops.



A single thread shows that the blocking IO send/receive loop is quicker than the Disruptor implementation, which is quicker than the threadpool. But - one issue; after more than one thread, the results are almost identical? What's going on here?

My initial assumption is that the log to file was causing issues as a cap on throughput, so let's remove it.

Latency with logging disabled


As you can see, similar results apply. Disruptor is only slightly slower than a blocking loop in the sleeping view. The threadpool is a bit further away but still close behind. Disruptor with busy spin waiting strategy - and the non blocking IO in a tight loop - results in the best latency. I think this requires a bit more investigation than I have time to understand but I would welcome comments.

Key observations

Suffice to say, similar key points come up as normally do:
  • A single thread processing is often the quickest approach. Avoid threads until there is a clear reason. Not only that, but the code is significantly shorter and simpler.
  • Disruptor is very quick for handoff between threads. In fact, the message passes between three threads nearly as quick as the single threaded code.
  • Disruptor response times are very sensitive to the choice of blocking strategy. By choosing the wrong strategy, you will burn 100pc CPU across multiple cores while getting worse latency.
  • Threadpool is "quick enough" for many cases. Unless your architecture and design is already very efficient, you're unlikely to notice magical performance gains without significant tuning to other areas of the codebase. It's probable that other areas of the codebase need optimisations first.

The test code and bench

I've tried to write the code in a fairly "natural" style for each approach, so the comparisons are not strictly apples to apples - I think they are more indicative of real-world usage. For example, the creation of a dedicated outbound socket for the threadpool approach is used, where the single threaded and disruptor code can quite easily create a single outbound UDP socket to transmit all responses. I'd be happy to take pull requests.

Beware when you are running the samples that you will need a quiet network to avoid any dropped UDP packets.

Running the client -> mvn clean package ; java -jar target/disruptor-1.0-SNAPSHOT.jar <<serveripaddress>> <<numclients>>
Running the server -> mvn exec:java -Dbio (or -Dthreadpool or -Ddisruptor), will open UDP port 9999.

The code.

Sunday, 29 September 2013

The cost of a null check

UPDATE: Thanks to Jin, Vladimir, and Gil for responding on the list. I've made updates below.

One thing that the JVM's JIT can do is optimise away the cost of a null check in certain cases. This is a nice optimisation; a common pattern is if(a != null) { doSomethingTo(a); }. In this case, the JIT might decide to not compile in the nullcheck, and go straight to execution the method. If a is indeed null, a signal is trapped from the hardware and the handler can then determine the signal can be safely ignored and proceeds.

The intent here is to find out a relative cost of null check and what the likely cost of this extra signal work is. The original discussion was regarding flags for code path enablement. Using a static final likely avoids the null checks here. So - the check was written to avoid the 10K compile threshold and simulates more the use of null/present for control flow and compares it with true/false.

The checks:

package com.bluedevel.nulls;


import org.openjdk.jmh.annotations.GenerateMicroBenchmark;
import org.openjdk.jmh.annotations.OperationsPerInvocation;
import org.openjdk.jmh.annotations.Scope;
import org.openjdk.jmh.annotations.State;
import org.openjdk.jmh.annotations.Setup;

@State(Scope.Thread)
/**
 * {@code java -ea -jar target/microbenchmarks.jar ".*NeverNullAlwaysTrue.*"}
 */
public class NeverNullAlwaysTrue {

    private Operations ops = new Operations();
    public int output = 0;

    // hopefully this means output is not eliminated
    public int getOutput() {
        return output;
    }

    @GenerateMicroBenchmark
    public int testPresentPresent() {
        
        output = doTestPP(output, ops);
        output = doTestPP(output, ops);
        
        return output;
    }

    private int doTestPP(int input, Operations o) {
        output = input;
        if (o != null) {
            output = o.op1(output);
        } else {
            output = ops.op2(output);
        }
        return output;
    }

    @GenerateMicroBenchmark
    public int testTrueTrue() {
        
        output = doTestTT(output, true);
        output = doTestTT(output, true);
        
        return output;
    }

    private int doTestTT(int input, boolean b) {
        output = input;
        if (b) {
            output = ops.op1(output);
        } else {
            output = ops.op2(output);
        }
        return output;
    }

    @GenerateMicroBenchmark
    public int testZPresentPresent() {
        
        output = doTestPP(output, ops);
        output = doTestPP(output, ops);
        
        return output;
    }
    @GenerateMicroBenchmark
    public int testZTrueTrue() {
        
        output = doTestTT(output, true);
        output = doTestTT(output, true);
        
        return output;
    }

}
And with Operations as:
package com.bluedevel.nulls;

public class Operations {
 public int op1(int i) { return i + 2; } 
 public int op2(int i) { return i + 3; }
}
The results below are interesting. If you are using the client VM, then you need to pay attention to your test approach. If you are using the server VM, then you can safely ignore it, as the code seems to run at approximately the same performance.

server:
Benchmark                                         Mode Thr    Cnt  Sec         Mean   Mean error    Units
c.b.n.NeverNullAlwaysTrue.testPresentPresent     thrpt   1     20    5   492452.297     1015.518 ops/msec
c.b.n.NeverNullAlwaysTrue.testTrueTrue           thrpt   1     20    5   482684.551     2934.298 ops/msec
c.b.n.NeverNullAlwaysTrue.testZPresentPresent    thrpt   1     20    5   485969.596     8488.587 ops/msec
c.b.n.NeverNullAlwaysTrue.testZTrueTrue          thrpt   1     20    5   484919.891     2415.732 ops/msec

client:
Benchmark                                         Mode Thr    Cnt  Sec         Mean   Mean error    Units
c.b.n.NeverNullAlwaysTrue.testPresentPresent     thrpt   1     20    5    67216.614     2456.394 ops/msec
c.b.n.NeverNullAlwaysTrue.testTrueTrue           thrpt   1     20    5    78801.555     2455.900 ops/msec
c.b.n.NeverNullAlwaysTrue.testZPresentPresent    thrpt   1     20    5    71080.747      790.894 ops/msec
c.b.n.NeverNullAlwaysTrue.testZTrueTrue          thrpt   1     20    5    83989.886      458.524 ops/msec

Saturday, 31 August 2013

Caching Classes from the ClassLoader?

Code for the article is here. I also submitted an enhancement patch to Tomcat bugtracker.

I noticed previously that the Tomcat WebappClassLoader is heavily serialized. In fact, the entire loadClass entry point is marked synchronized, so for any poorly designed libraries, the impact of this on scalability is pretty remarkable. Of course, the ideal is not to hit the ClassLoader hundreds of times per second but sometimes that's out of your control.

I decided to play some more with JMH and run some trials to compare the impacts of various strategies to break the serialization.

I trialled four implementations:
1) GuavaCaching - a decorator on WebappCL which uses a Guava cache
2) ChmCaching - a decorator on WebappCL which uses a ConcurrentHashMap (no active eviction)
3) ChmWebappCL - a modified WebappCL using ConcurrentHashMap so that loadClass is only synchronized when it reaches up to parent loader, classes loaded through current loader are found in local map
4) Out of the box Tomcat 8.0.0-RC1 WebappClassLoader - synchronized fully around loadClass method

The results; in operations per microsecond, where an operation is a lookup of java.util.ArrayList and java.util.ArrayDeque.

1 2 3 4 5 6 7 8 9 10 11 12 13 14 15 16
GuavaCaching 3687 978 1150 1129 1385 1497 1607 1679 1777 1733 1834
ChmCaching 27241 51062 81678 107376 134798 162125 188192 213007 208034 210812 200231 211744 214431 215283 209782 212297
ChmWebappCL 185 48 81 81 83 81 84 85 85 85 80 84 82 83 83 84
WebappCL 181 69 91 92 91 92 100 98 95 94 94 95 102 102 95 98

And the explanation -
  • GuavaCaching seems remarkably slow compared to CHM. Might be worth investigating further. I also noticed significant issues with Guava implementation; some tests were running for extremely long time, seems there is an issue in the dequeue (quick look, it appears stalled in a while loop).
  • ChmCaching seems very effective; although it is caching classes loaded from parent and system loader. This seems OK per the API but unusual, I will have to check the API in more detail. Scales linearly with cores (it is an 8 core machine).
  • ChmWebappCL seemed to have less of an effect. This is likely because I am testing loading classes against core java.util.* rather than from a JAR added to the classloader. I expect ChmWebappCL can approach ChmCaching speed if I attach JARs directly to the class loader rather than passing through to system loader. (Going to system loader means entering the synchronized block).
  • WebappCL - very slow performance.

And pretty pictures. You can see that CHM caching is far and away the best of this bunch.

.


Same picture, at log scale -


Tuesday, 16 July 2013

Gatling JMS API now ready for wider testing

Please take a look on here - https://github.com/jasonk000/gatling-jms

In brief, the Gatling JMS extension allows testing of JMS provider APIs using the nice Gatling DSL that you are familiar with.




You can get a pretty diagram, quite quickly, testing a JMS service, using the simulation script below.
package com.bluedevel.gatling.jms

import net.timewalker.ffmq3.FFMQConstants
import io.gatling.core.Predef._
import com.bluedevel.gatling.jms.Predef._
import scala.concurrent.duration._
import bootstrap._
import javax.jms.{ Message, TextMessage }

class TestJmsDsl extends Simulation {

  val jmsConfig = JmsProtocolBuilder.default
    .connectionFactoryName(FFMQConstants.JNDI_CONNECTION_FACTORY_NAME)
    .url("tcp://localhost:10002")
    .credentials("user", "secret")
    .contextFactory(FFMQConstants.JNDI_CONTEXT_FACTORY)
    .listenerCount(1)
    .deliveryMode(javax.jms.DeliveryMode.PERSISTENT)

  val scn = scenario("JMS DSL test").repeat(1) {
    exec(jms("req reply testing").reqreply
      .queue("jmstestq")
// -- four message types are supported; only StreamMessage is not currently supported
      .textMessage("hello from gatling jms dsl")
//      .bytesMessage(new Array[Byte](1))
//      .mapMessage(new ListMap[String, Object])
//      .objectMessage("hello!")
      .addProperty("test_header", "test_value")
      .addCheck(checkBodyTextCorrect)
    )
  }

  setUp(scn.inject(
       rampRate(10 usersPerSec) to (1000 usersPerSec) during (2 minutes)
    )).protocols(jmsConfig)

  /**
   * Checks if a body text is correct.
   * <p>
   * Note the contract on the checks is Message => Boolean, so you can perform
   * any processing you like on the message (check headers, check type, check body,
   * complex checks, etc).
   */
  def checkBodyTextCorrect(m: Message) = {
    // this assumes that the service just does an "uppercase" transform on the text
    val BODY_SHOULD_BE = "HELLO FROM GATLING JMS DSL"
    m match {
      case tm: TextMessage => (tm.getText.toString == BODY_SHOULD_BE)
      case _ => false
    }
  }

}

Monday, 17 June 2013

Gatling JMS (first pass)

Simple add-in to Gatling to support JMS testing.

First cut is available on github - https://github.com/jasonk000/gatling-jms

Lots of work to do, but I thought I'd push it here so you can see a basic example of a gatling test.

Thursday, 30 May 2013

Tomcat WebappClassLoader class loader performance degradation

Interesting performance degradation after upgrading to (relatively) recent versions of the Tomcat application stack - since 7.0.x, fix has been backported to 6.x and 5.5x as well. Sharing / documenting it here in case it helps others.

This stems from a change introduced to Tomcat as part of bug 48903/44041/48694 to fix a deadlock some users were experiencing.
http://svn.apache.org/viewvc?view=revision&amp;revision=927565

For us, this issue was shown due to our use of the Saxon XSLT transformer library showing higher contended time.

The particular problem is that Saxon 9.1.x library, for each transform:
- To get an emitter, calls the Configuration.makeEmitter()
- This calls DynamicLoader.getInstance()
- Inside the container, this defers to WebappClassLoader
- loadClass on WebappClassLoader is now declared synchronized.

Other platforms eg Struts2 have worked around this by caching classes loaded through the class loader - see https://issues.apache.org/jira/browse/WW-3902 .

Haven't worked out the fix yet - ideal solution will be to remove the need for XSLT in the processing path, unlikely but one can hope. (XSLT is required here to support a particular legacy expectation of the formatting of the returned XML).