Author: Romiko Derbynew

Neo4j, JMX and VisualVM

It might be necessary to use JMX to profile neo4j, which we are currently doing to address performance issues with Neo4j in combination with Windows Azure.

The first thing you will need to configure is additional switches in the neo4j-wrapper.conf file, here are mine:

wrapper.java.additional.1=-d64
wrapper.java.additional.1=-server
wrapper.java.additional.1=-Xss2048k
wrapper.java.additional.2=-Dcom.sun.management.jmxremote.port=6666
wrapper.java.additional.2=-Dcom.sun.management.jmxremote.ssl=false
wrapper.java.additional.2=-Dcom.sun.management.jmxremote.authenticate=false

Notice, that I am using a port number here, and this will allow remote JMX profiling, the reason for this is that in azure, the neo4j instance runs in a different user context than the remote desktop user, so we need a way to attach to the process, with VisualVM, we can do this via remote JMX.

Just add the neo4j JMX listener as a remote host. Then, if using the azure cloud:

  • Remote desktop into the worker role hosting Neo4j
  • Install the JDK
  • Install VisualVM
  • Configure the JMX Connectionas outlined below
    Right click Local and click Add JMX Connection:

image

image

image

From here we can now do profiling of the Neo4j application.

image

Romiko

Windows Azure SDK 1.6–CSX folder output breaking change..again..

Background

Automated deployments with SDK 1.6 have been broken with TeamCity.

Location of CSX folder in build output changed.

Location of CSRUN.exe moved to emulator folder.

Details

Before, when using the MSBUILD targets, the csx folder that is needed by CSRUN.exe for automated deployments has been changed, what is worse, is the old csx folder location is not cleaned up and is partially there, so to the untrained eye you think it is still there!

Also note, you will need to change the path of csrun.exe as this has been moved.

Old Location

CloudProject\bin\%BuildConfiguration%\CloudProject.csx

New Location

CloudProject\csx\%BuildConfiguration%

Why does the old location with impartial files still exist? Not sure…Because this was my new error when I tried to deploy.

The compute emulator had a error: Can’t locate service descriptions

image

Now the new location with all files

image

TeamCity Artefacts fix

Notice the new relative path to the project is \csx\release and not bin\release\MyProject.csx.

image

Summary

This is not the first time, that we get breaking changes. In 1.5 allot of the MSBuild target names changed, they were fine the way they were, sometimes I just do not understand certain changes that did not really need to be made.

So, can anyone explain why the folder before in bin\MyprojectName.csx was changed to a directory level up from bin and called only csx, it just seems to be changes that we really can do without, or is their some grand planned scheme that will make this change so exciting in the future…who knows?

Listening

As a listener, you grant yourself the ability to merge with anyone from any walk of life, even those you know nothing about, because rather than seeking to bathe your own ideas over others, you allow others’ to bathe over you

Chile Surf Yoga Trip April 2012

Just bought my tickets for a trip to remember, surfing big lefts in Chile, I am so excited to go and learn about the country, people and explore the places. Will be travelling with Maurice/Julie and some local surfers here in Sydney.

You can check out their website here: Chile Retreat 2012

I always wanted to check out South America, and no better way than to travel with people who are from Chile. I am really appreciative that my work, Readify,  has let me take unpaid leave.

Waters in Chile are freezing, and I don’t have a 4/.3 wetty, Maurice has been kind enough to offer one of his to use, so that puts me to just buy a hoody, booties and some gloves.

The average swell height is 4-6ft, perfect, I am a bit concerned that I might fall in love and stay there and just become a surf bum, ha ha!

Another place that I am definitely keen to surf will be Chicama in Peru, I guess I will plan this for 2013.

Well, I am hoping to survive the PNG trip, which is now only 2 weeks away, we changed the plans and will be travelling from Vanimo To Madang, and have cut out the mountain climbing, mainly due to timing, we would rather be surfing or diving instead.

Here are some picks of the last trip the guys had in Chile.

I am, well….Excited! Peace….

Actors Lab – Truth

Hi,

Finally completed the level 4 course Truth at Darlinghurst Theatre, in this performance we explored “letting go”, a place where we can perform on stage and strike a balance between Actors Craft and letting go, release real emotions. Definitely learned allot on this course, I feel it definitely contributed to successfully passing the audition yesterday at Sydney Theatre School

 

The scene I had was about Myth, Propaganda and Disaster…A professor who has gone a bit insane, or perhaps is a bit to passionate in standing up for what he believes in. The conversation is between him and a colleague who both immigrated to the US from Australia. The argue over their views on why the professor has decided to write a controversial book called “Myth, Propaganda and Disaster in Nazi Germany and Contemporary America – A Comparative study.

Having a short scene, allowed me to really focus on my feelings and emotions, it was an interesting week, as allot of the time, i would have to conjure intense emotions. It is kind of like a stem cell, you build up energy in your thorax and then just feel an emotion without thinking of a scene or past event, thus transforming energy into whatever emotion is you would like to feel, this then I believe allows for a more fluid experience.

One issue I had, is during normal day activities, I would feel intense emotions because of this, as my feelings were allowed to flow more easily, making you allot more open to experiences, from an acting perspective this is great, but be careful with it in normal day to day activities, I think a new aspect for me to learn is letting go totally after the scenes.

I feel there were two many people on the course, it would have been ideal to have 8, we had 12 on the course, and this makes it very challenging for the instructor to provide the individual attention required. Met some great people on the course and new people are always a great stream to be feed with new inspirations.

Here are some pictures from the performance.

 

Summary

Highly recommend the actors lab, if you want to get in touch with letting go. Check out www.darlinghursttheatre.com/

The Warrior

The basic difference between an ordinary man and a warrior is that a warrior takes everything as a challenge while an ordinary man takes everything as either a blessing or a curse

Papua New Guinea–Tickets Booked and High Level Plan

A friend of mine Jamal Abreu and I are heading off to Papua New Guinea on 17th December and fly back to Sydney on 8th January. Our aim is to be totally immersed in the culture and nature of Papua New Guinea, we want to not only surf but explore the variety and diversity PNG has to offer, off the beaten track.

High level plan

  • Fly into Ports Moresby, then catch connecting to Madang
  • Surf undiscovered spots
  • Avoid the tourist hot spots and go off the beaten track
  • Camp out with the local villagers
  • Learn as much as we can about the cultures we encounter
  • Visit the Volcano Manam
  • Climb Mount Hagen
  • Surf wherever we find breaks
  • Fly to Ports Moresby an fly to Syndey

Route

The route is simple. Land in Madang, climb mountain Hagen, head back to the coast, surf our way up to Vanimo, using Public Transport, Tractors, Donkeys, Boats, Foot, whatever we can climb onto, and umm PMV’s.

Stars on the map represent our main waypoints.

image

 

Equipment

Travel as light as possible, this means, very small day pack, and surfboards.

  • Surfboard bag with makeshift wheels
  • Hammock (Tenth-Wonder-Hammocks-and-Tarps) , Non Waterproof – keep it as airy as possible.
  • Hammock
  • Water proof Tarp (hex shape)
  • Camp gas stove, flints
  • Medical Kit  + Tea Tree Oil
  • Antibiotics
  • Cheap ass phone (not getting machete’d to pieces for an IPhone)
  • Water purification bottles (Aquapure-Traveller)
  • two shorts, two shirts, long sleeves, hat , perhaps some underwear
  • waterproof leggings + thin shell jacket (Mountains)
  • light airy hiking shoes
  • Mosquito repellent
  • rash vest, reef boots
  • torch
  • camera (need to figure out what to take that is not advertising MUG ME)
  • Surf boards ( 2 or 3)

Vaseline (Very useful, umm for lots of things)

Local Knowledge

Have met a local Australian, who lives in the Jungles and with the tribes of PNG, hooking up next week to get knowledge and tip on how to act and behave with the local tribesman. I think there is allot of misconceptions about PNG, so will document and found out how the place ticks first hand. There is not allot of information out there on PNG, so hoping this will be the first of many trips back to PNG.

Surfing

Here is a nice inspirational video on surfing in PNG. Click the link to view.

PNG Surfing Video

There is a surf association in PNG, and we keen to meet up with some of them in Vanimo, however, we will be spending our time finding un-surfed spots.

PNG Surf Association

    Safety

    From what I have gathered from the Lonely Planet guide, Papua New Guinea seems to be a surprisingly friendly place once you get out of the major cities. In fact it is encouraged to travel the same way the locals do and most villages will accept, and offer a hand to stay with them for a few days, that to me is even more friendly than our urban jungles. How many strangers in London would let you stay for a couple of nights, no obligations?

    Of course, with any place you go to, you need to me friendly and courteous to others and of course have some street smart savvy with you.

    Some Pictures from the net

    I guess, this is how people see PNG to be, I think with over 800 languages, there will be all sorts of cultures, definitely keen to meet with them, hopefully and I am sure that most are friendly.

papua-new-guinea

 

Neo4j Java JVM Garbage Collection Profiling/Heap Size/Log Rotation/Lucene Rest API performance analysis

We started running into some timeout issues when loading tens of thousands of nodes with full text indexes into Neo4j. We decided to have a look at it from a default install and then tune all the way up to acceptable levels. Currently when loading nodes via the Rest API it would fail at around the 4000 node mark. Below are the recordings of what we needed to do to get the import of nodes running successfully.

Note: This pertains to consuming Neo4j via the REST API only! We are leveraging the Neo4jClient, which can be found on NuGet: http://nuget.org/List/Packages/Neo4jClient

Of course if you using native java, then bypassing the rest api and using the intrinsic batch api will be MUCH faster!

We first ran calls via rest without batching, and then later introduced batching.

In Short:

Optimise Threads from your client to be below 80 as Neo4j Server allocated 80 threads to the JVM, so no point in sending rest calls on more than 80 threads. (This is for a machine with 8 cores (Neo4j allocated 10 threads per core)).

So if you neo4j server is a dual core (10 * 2) = 20 threads. Quad Core = 40 Threads.

Use the Rest batching API.

If using Gremlin, use parameterised queries.

Use Circuit Breaker pattern to implement retry logic if calls fail (Optional)

Steps to setup profiling

Ensure the following entries are in the neo4j-wrapper.conf file:

# Initial Java Heap Size (in MB)
wrapper.java.initmemory=<Your Value>

# Maximum Java Heap Size (in MB)
wrapper.java.maxmemory=<Your Value>

#Enable JVM Garbage Collection Logging
wrapper.java.additional.3=-Xloggc:data/log/neo4j-gc.log

Download the following tool to get a graphical view of GC and Heap statistics.

http://www.tagtraum.com/gcviewer.html

Scenario

  • Loading 30000 Client Nodes into Graph, With one relationship and +- 5 Full Text Index entries.
  • +- 12 Active HTTP Connections to the Neo4JServer
  • Neo4j is running on the Windows Azure Cloud Storage Emulator as a worker role.
  • Java 1.6

Machine Specification

Lenovo W701 laptop, 5400 Rpm Drive for Database, SSD for Boot/System, 18GB Memory, Intel LGA 1156 I7 820QM (Clarksfield)

Default Heap Size

# Initial Java Heap Size (in MB)
wrapper.java.initmemory=3

# Maximum Java Heap Size (in MB)
wrapper.java.maxmemory=64

image

  • Note the arrow shows allot of second generation GC collects (Black Lines), just after this occurred the import failed on roughly 4500 node entries and then we started getting timeouts from the Neo4j Server.
  • Java.exe was roughly consuming between 150MB to 200MB of memory.
  • GC Performance at 785M/S

Custom Heap Size (Windows)

# Initial Java Heap Size (in MB)
wrapper.java.initmemory=1024

# Maximum Java Heap Size (in MB)
wrapper.java.maxmemory=2048

image

  • Java.exe was roughly consuming between 600MB to 750MB of memory.
  • The heap size seemed to be reasonable location as there was plenty of available heap space to grow.
  • Timeouts started to occur at around 3500 nodes.
  • Garbage Collection (Second Generation) is now optimized, not not many black lines
  • The Heap Size shot up in size near point of timeouts
  • The Blue line is working nicely, this is the used heap, which is remaining consistent at around the 450MB mark.
  • GC performance at 4762 M/s

image

image

Another load run below, shows similar results but faster GC performance after the following changes to the system:

  • JRE 1.7.0
  • Windows Azure SDK 1.5
  • Load data to new clean DB store.

image

  • The GC performance is now at 12,974 M/s
    The custom heap size, definitely increased the productivity of the Garbage Collector, by having less second generation collections occurring, however, it has not solved the root cause of the problem, where web timeouts are occurring on the rest calls at around the 3500-4500 node mark.

The Rest API timed out at 3:11 local time.

[03:11:20] [Thread  27] Failed importing client

What is interesting is for the next 5 minutes, the server was utilisation all my 8 cores on the CPU, and I guess this was to flush or roll over the transaction logs, thus perhaps being the main cause for the rest API to become unresponsive. We can see evidence of this in the file system. As the datetime stamp is exactly 5 minutes after the 3:11 log entry when rest API stopped. Note size of file is in bytes. i.e. 3, 362,544 is +- 3MB.

Directory of C:\AzureTemp\neo4j-db

20/09/2011 03:16 PM 11 active_tx_log

20/09/2011 03:15 PM 3,362,544 nioneo_logical.log.

20/09/2011 03:16 PM 29,372 tm_tx_log.1

20/09/2011 03:16 PM 596 tm_tx_log.2

Directory of C:\AzureTemp\neo4j-db\index

20/09/2011 03:17 PM 1,499,357 lucene.log.1

Optimisation

JVM

The first thing I added was to ensure the JVM is running in Server Mode, 64 bit with a stack size of 2048k per thread (default is 1024k for 64 bit). I added the following to lines to the neo4j-wrapper.conf.

wrapper.java.additional.1=-d64

wrapper.java.additional.1=-server

wrapper.java.additional.1=-Xss2048k (We use multiple threads in the application.)

Using the JVM in server mode will optimise the code. JIT used in server mode gathers more information about the running code before optimizing, and thus does a far better job in optimizing the code

Neo4J Database Transaction Log Autorotation

The next part is to improve the write performance of the Neo4j database system. To do this, we can go two ways.

  • Disable the transaction log autorotation
  • Increase the size of the transaction log,

Read more about this here: http://wiki.neo4j.org/content/Performance_Guide (Write Performance Section)

    Thus reducing the frequency of flushes from memory to the db disk subsystem, which will then reduce unresponsive Rest API responses.

Now, we a .Net client, so we will leverage the Rest API to execute a groovy script which will dynamically run the java code for us. However before we get all fancy with the Neo4jClient, lets first test this out, by bootstrapping the neo4j server and then using the embedded web server api to manually execute the java code in the performance guide to disable auto tx log rotation like this:

import org.neo4j.kernel.EmbeddedGraphDatabase.*

neo4j = g.getRawGraph()

txModule = neo4j.getConfig().getTxModule();

xaDsMgr = txModule.getXaDataSourceManager();

xaDs = xaDsMgr.getXaDataSource( "nioneodb" );

xaDs.setAutoRotate( false );

Here is a screenshot, of the commands executed via the console. I will be updating the NUGET package Neo4jClient to support disabling the TX logs shortly as well via rest api calls.

image

I now initiate an import of 35000 nodes witch also have full text lucene  indexes. Below are screen shots at various stages

+- 400 Nodes imported

image

+- 1000 Nodes Imported

image

image

After running for +- 50 minutes, the system ran out of memory (dispite the machine having over 8gb of free memory!)

image

What is interesting is that Java is only using 706 memory.

So the conclusion here is that by turning of the TX Log rollers, it did not cause any performance or responsive increase on the rest API.

Lucene Index Rest Calls

We then disabled all Full text index creation calls when the nodes are created, to see the performance, and try isolated where the issue is coming from, is it Neo4j, Lucene or a combination of both.

By disabling the Lucene index calls, we got a faster response time. Roughly 4.5 nodes per second as apposed to 3.9 nodes per second.

However, the real test will be to see if the REST API becomes unresponsive, the JVM did indeed become unresponsive with the index calls turned off, this occurred at around 20000 node creations. A Node Creation is two rest calls for us, a gremlin query to check the node exists and then a POST.

Scenario – Un-Optimised Gremlin Code (not parameterised )

With Lucene Index Rest Calls Off and Heap Size 512->1024

Attempt Load 37619 Nodes, each node with one relationship. Only +- 22000 Nodes made it. JAVA VM ran out of memory.

Below are the GC and Heap stats.  Note the Java VM crashed here, it also ran out of memory. Which does not make sense, as the heap as plenty of space available. This is rather concerning as each Create Node operation is 2 rest requests, one a gremlin query to check node does not exist and then another POST to create the node. I would not expect this to have become unstable.

image

image

image

 

Scenario – Optimised Gremlin Code (parameterised)

We thought that perhaps using un-parameterised queries was the cause of the instability due to allot of JIT compilations occurring. So we decided to update the Neo4jClient to use parameterised gremlin queries for JIT optimisation. We also updated Neo4j to 1.5.M01, so a combination of both might improve the issues we experiencing.

With Lucene Index Rest Calls Off and Heap Size 512->1024

Neo4jClient NuGet package is now using PARAMTERISED queries to reduce JIT compilation.

Loaded 37619 Nodes, each node with one relationship.

Note: This uses neo4j-community-1.5.M01-windows and not 1.4..M04

Below are the GC and Heap stats. Theoretically, the heap should be less used now, due to JIT compilation being reduced by passing in parameterised gremlin queries.

We noticed that with the parameterised queries, we got faster client loads, instead of 5 per second, it went to 6 per second.

We noticed immediately that the heap usage is allot less with parameterised queries. Notice this graph below, where the blue lines are allot less dense than all the previous graphs. The graph at the bottom in the image below is with the parameterised gremlin queries and Neo4j 1.5.M01.

image

At around 23000 nodes the Azure Worker Role on my local development machine failed with:

Unknown Hard Error. This is interesting as I did not get any JVM memory errors. This implies an issue in our Stress Test client, as we noticed over 27000 handles in our .Net client application. This raised a red flag for me on resource usage and possible thread management, lets get into this exciting part of the analysis…

Thread optimisation

We optimised the .Net client by ensuring no more than 70 thread call the rest API, I chose 70 threads as the Neo4j Server allocates 80 threads on the JVM, so we might as well be just below this value. This is absolutely amazing, by matching the number of simultaneous threads to call rest operations to the reserved threads neo4j has, we have a 5 times performance increase!!! We also noticed CPU utilisation is much more efficient now.

image

Now with the new thread optimised, we were able to do a full load into the system.  With no errors.

MyStory Welcome, Temporary from MyStory Administration. Logout?

Agency Import Job 301

Log output:

[01:44:58] [Thread   10] Migration message received at: 26/09/2011 1:44:58 AM +00:00

[01:44:59] [Thread   10] Migration message payload: JobUniqueId: 301, AgencyUniqueId: 201

[01:44:59] [Thread   10] Executing sql script: e:\AzureTemp\Resources\4bb24cfd-0b35-4c91-83de-97f335159a49\temp\temp\RoleTemp\634526342992784034\output.sql

[01:45:01] [Thread   10] Processing script command line 10000/37620

[01:45:03] [Thread   10] Processing script command line 20000/37620

[01:45:05] [Thread   10] Processing script command line 30000/37620

[01:45:06] [Thread   10] All sql script commands executed 37620/37620

[01:45:13] [Thread   10] Importing 37619 clients into the database

[01:45:44] [Thread   12] Processed 169/37619 clients, 5.62 clients per second, 01:51:06 remaining

[01:46:16] [Thread   29] Processed 360/37619 clients, 5.80 clients per second, 01:47:02 remaining

[01:46:29] [Thread   69] Processed 1000/37619 clients, 13.30 clients per second, 00:45:52 remaining

[01:46:50] [Thread   28] Processed 2000/37619 clients, 20.78 clients per second, 00:28:34 remaining

[01:47:11] [Thread   30] Processed 3000/37619 clients, 25.47 clients per second, 00:22:39 remaining

[01:47:33] [Thread   32] Processed 4000/37619 clients, 28.71 clients per second, 00:19:31 remaining

[01:47:55] [Thread   76] Processed 5000/37619 clients, 30.95 clients per second, 00:17:33 remaining

[01:48:18] [Thread   87] Processed 6000/37619 clients, 32.52 clients per second, 00:16:12 remaining

[01:48:46] [Thread   13] Processed 7000/37619 clients, 32.95 clients per second, 00:15:29 remaining

[01:49:10] [Thread   70] Processed 8000/37619 clients, 33.84 clients per second, 00:14:35 remaining

[01:49:36] [Thread   54] Processed 9000/37619 clients, 34.25 clients per second, 00:13:55 remaining

[01:50:02] [Thread   64] Processed 10000/37619 clients, 34.69 clients per second, 00:13:16 remaining

[01:50:29] [Thread   50] Processed 11000/37619 clients, 34.85 clients per second, 00:12:43 remaining

[01:50:57] [Thread   82] Processed 12000/37619 clients, 34.97 clients per second, 00:12:12 remaining

[01:51:25] [Thread   27] Processed 13000/37619 clients, 35.02 clients per second, 00:11:42 remaining

[01:51:54] [Thread   10] Processed 14000/37619 clients, 34.99 clients per second, 00:11:15 remaining

[01:52:24] [Thread   76] Processed 15000/37619 clients, 34.89 clients per second, 00:10:48 remaining

[01:52:54] [Thread   68] Processed 15970/37619 clients, 34.70 clients per second, 00:10:23 remaining

[01:52:55] [Thread   17] Processed 16000/37619 clients, 34.69 clients per second, 00:10:23 remaining

[01:53:25] [Thread   59] Processed 16918/37619 clients, 34.43 clients per second, 00:10:01 remaining

[01:53:27] [Thread   46] Processed 17000/37619 clients, 34.42 clients per second, 00:09:59 remaining

[01:53:58] [Thread   58] Processed 17998/37619 clients, 34.33 clients per second, 00:09:31 remaining

[01:53:58] [Thread   34] Processed 18000/37619 clients, 34.32 clients per second, 00:09:31 remaining

[01:54:28] [Thread   21] Processed 18900/37619 clients, 34.07 clients per second, 00:09:09 remaining

[01:54:34] [Thread   13] Processed 19000/37619 clients, 33.90 clients per second, 00:09:09 remaining

[01:55:04] [Thread   35] Processed 19973/37619 clients, 33.81 clients per second, 00:08:41 remaining

[01:55:05] [Thread   86] Processed 20000/37619 clients, 33.80 clients per second, 00:08:41 remaining

[01:55:36] [Thread   93] Processed 20910/37619 clients, 33.61 clients per second, 00:08:17 remaining

[01:55:40] [Thread   42] Processed 21000/37619 clients, 33.54 clients per second, 00:08:15 remaining

[01:56:10] [Thread   31] Processed 21886/37619 clients, 33.35 clients per second, 00:07:51 remaining

[01:56:14] [Thread   81] Processed 22000/37619 clients, 33.32 clients per second, 00:07:48 remaining

[01:56:44] [Thread   17] Processed 22809/37619 clients, 33.02 clients per second, 00:07:28 remaining

[01:56:51] [Thread   77] Processed 23000/37619 clients, 32.96 clients per second, 00:07:23 remaining

[01:57:22] [Thread   42] Processed 23770/37619 clients, 32.63 clients per second, 00:07:04 remaining

[01:57:30] [Thread   71] Processed 24000/37619 clients, 32.57 clients per second, 00:06:58 remaining

[01:58:01] [Thread   44] Processed 24652/37619 clients, 32.13 clients per second, 00:06:43 remaining

[01:58:16] [Thread   42] Processed 25000/37619 clients, 31.94 clients per second, 00:06:35 remaining

[01:58:47] [Thread    9] Processed 25691/37619 clients, 31.60 clients per second, 00:06:17 remaining

[01:59:03] [Thread   84] Processed 26000/37619 clients, 31.33 clients per second, 00:06:10 remaining

[01:59:36] [Thread   91] Processed 26625/37619 clients, 30.88 clients per second, 00:05:56 remaining

[01:59:57] [Thread   74] Processed 27000/37619 clients, 30.57 clients per second, 00:05:47 remaining

[02:00:27] [Thread   79] Processed 27583/37619 clients, 30.20 clients per second, 00:05:32 remaining

[02:00:47] [Thread   82] Processed 28000/37619 clients, 30.01 clients per second, 00:05:20 remaining

[02:01:17] [Thread   64] Processed 28591/37619 clients, 29.67 clients per second, 00:05:04 remaining

[02:01:38] [Thread   17] Processed 29000/37619 clients, 29.46 clients per second, 00:04:52 remaining

[02:02:08] [Thread   24] Processed 29610/37619 clients, 29.18 clients per second, 00:04:34 remaining

[02:02:29] [Thread   58] Processed 30000/37619 clients, 28.98 clients per second, 00:04:22 remaining

[02:02:59] [Thread   69] Processed 30566/37619 clients, 28.68 clients per second, 00:04:05 remaining

[02:03:23] [Thread   89] Processed 31000/37619 clients, 28.46 clients per second, 00:03:52 remaining

[02:03:23] [Thread   88] Processed 31000/37619 clients, 28.46 clients per second, 00:03:52 remaining

[02:03:53] [Thread   30] Processed 31556/37619 clients, 28.18 clients per second, 00:03:35 remaining

[02:04:16] [Thread   61] Processed 32000/37619 clients, 28.00 clients per second, 00:03:20 remaining

[02:04:48] [Thread   66] Processed 32568/37619 clients, 27.73 clients per second, 00:03:02 remaining

[02:05:18] [Thread   20] Processed 33000/37619 clients, 27.41 clients per second, 00:02:48 remaining

[02:05:48] [Thread   13] Processed 33529/37619 clients, 27.16 clients per second, 00:02:30 remaining

[02:06:15] [Thread   56] Processed 34000/37619 clients, 26.95 clients per second, 00:02:14 remaining

[02:06:45] [Thread   92] Processed 34442/37619 clients, 26.66 clients per second, 00:01:59 remaining

[02:07:16] [Thread   95] Processed 34959/37619 clients, 26.44 clients per second, 00:01:40 remaining

[02:07:17] [Thread   91] Processed 35000/37619 clients, 26.44 clients per second, 00:01:39 remaining

[02:07:49] [Thread   95] Processed 35369/37619 clients, 26.09 clients per second, 00:01:26 remaining

[02:08:19] [Thread   41] Processed 35867/37619 clients, 25.88 clients per second, 00:01:07 remaining

[02:08:28] [Thread   66] Processed 36000/37619 clients, 25.81 clients per second, 00:01:02 remaining

[02:08:59] [Thread   45] Processed 36485/37619 clients, 25.60 clients per second, 00:00:44 remaining

[02:09:29] [Thread   78] Processed 36922/37619 clients, 25.37 clients per second, 00:00:27 remaining

[02:09:34] [Thread   81] Processed 37000/37619 clients, 25.34 clients per second, 00:00:24 remaining

[02:10:04] [Thread   12] Processed 37287/37619 clients, 25.01 clients per second, 00:00:13 remaining

[02:10:27] [Thread   10] All 37619 clients imported

Threads on .Net Client

By configuring the .Net client to use a similar number of threads that Neo4j uses, we were able to achieve a 5 times performance boost.

The processor utilization also became allot more efficient. Notice Neo4j has 80 threads, so we limit the rest calls to roughly this amount, I chose 70 threads.

So in .Net, we match the threads like so:

var processorCount = Environment.ProcessorCount;

var threadsToAllocate = (int)Math.Ceiling(processorCount*10 * 0.9);

var options = new ParallelOptions { MaxDegreeOfParallelism = threadsToAllocate };

Parallel.ForEach(clients, options, client =>{…

 

image

 

Note: My machine has 8 cores, Neo4j allocated 10 threads per core, therefore your code should detect how many cores there are and then allocate the threads of 10 threads per core!!

e,g if you run it on a dual core, Neo4j will only have 20 threads.

Batching Rest Requests

Once we fixed the threading issue, by matching the threads on the consumer to Neo4j, we then decided to test batching rest requests.

We implemented batching in the Neo4jClient NuGet package, this will reduce the amount of REST calls to the server for each node it needs to create, so if a node needed two relationships, instead of doing 3 rest calls, we do one rest call.

Test Run (Without Indexes)

The batching did not introduce any significant performance improvement when it only batched on average two rest calls.  However, we will do another test run  with indexing rest calls as perhaps you only notice this for a certain amount of rest calls batched together.

Average Bach Size (Node creation + Relationship creation) = 2 rest requests

[02:37:04] [Thread   34] Processed 17000/37619 clients, 34.51 clients per second, 00:09:57 remaining

Test Run (With Indexes)

We now included the indexes in the batch request. We noticed that sometimes web calls would timeout, but since we use the CIRCUIT BREAKER pattern, the service level always stayed above 80% and never tripped.

[04:52:38] [Thread    9] Importing 37592 clients into the database

[04:53:09] [Thread   46] Processed 169/37592 clients, 5.55 clients per second, 01:52:19 remaining

[04:53:40] [Thread   62] Processed 422/37592 clients, 6.76 clients per second, 01:31:35 remaining

[04:53:55] [Thread   49] Processed 1000/37592 clients, 13.03 clients per second, 00:46:48 remaining

[04:53:55] [Thread   54] Processed 1000/37592 clients, 13.03 clients per second, 00:46:48 remaining

[04:54:19] [Thread   10] Processed 2000/37592 clients, 19.89 clients per second, 00:29:49 remaining

[04:54:19] [Thread   50] Processed 2000/37592 clients, 19.88 clients per second, 00:29:49 remaining

[04:54:43] [Thread   32] Processed 3000/37592 clients, 23.96 clients per second, 00:24:03 remaining

[04:54:43] [Thread   11] Processed 3000/37592 clients, 23.96 clients per second, 00:24:03 remaining

[04:55:09] [Thread   64] Processed 4000/37592 clients, 26.51 clients per second, 00:21:07 remaining

[04:55:09] [Thread   23] Processed 4000/37592 clients, 26.50 clients per second, 00:21:07 remaining

[04:55:36] [Thread   70] Processed 5000/37592 clients, 28.13 clients per second, 00:19:18 remaining

[04:55:36] [Thread   57] Processed 5000/37592 clients, 28.13 clients per second, 00:19:18 remaining

[04:56:02] [Thread   25] Processed 6000/37592 clients, 29.41 clients per second, 00:17:54 remaining

[04:56:02] [Thread   85] Processed 6000/37592 clients, 29.41 clients per second, 00:17:54 remaining

[04:56:30] [Thread  102] Processed 7000/37592 clients, 30.13 clients per second, 00:16:55 remaining

[04:56:30] [Thread   51] Processed 7000/37592 clients, 30.13 clients per second, 00:16:55 remaining

[04:57:01] [Thread  102] Processed 7995/37592 clients, 30.46 clients per second, 00:16:11 remaining

[04:57:01] [Thread   96] Processed 8000/37592 clients, 30.45 clients per second, 00:16:11 remaining

[04:57:01] [Thread   70] Processed 8000/37592 clients, 30.45 clients per second, 00:16:11 remaining

[04:57:31] [Thread   65] Processed 8988/37592 clients, 30.68 clients per second, 00:15:32 remaining

[04:57:31] [Thread   84] Processed 9000/37592 clients, 30.68 clients per second, 00:15:31 remaining

[04:57:32] [Thread   46] Processed 9000/37592 clients, 30.68 clients per second, 00:15:31 remaining

[04:58:02] [Thread  109] Processed 10000/37592 clients, 30.89 clients per second, 00:14:53 remaining

[04:58:32] [Thread   12] Processed 10950/37592 clients, 30.93 clients per second, 00:14:21 remaining

[04:58:34] [Thread   11] Processed 11000/37592 clients, 30.94 clients per second, 00:14:19 remaining

[04:58:34] [Thread   16] Processed 11000/37592 clients, 30.94 clients per second, 00:14:19 remaining

[04:58:39] [Thread   91] Error occured importing client EAW2000203-Child4128. Started this attempt at 26/09/2011 4:58:37 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:58:37 AM +00:00.

[04:58:39] [Thread   91] Circuit breaker now reports the service level as 80.

[04:58:39] [Thread  101] Circuit breaker now reports the service level as 100.

[04:58:42] [Thread   69] Error occured importing client EAW2000002-Child3994. Started this attempt at 26/09/2011 4:58:40 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:58:40 AM +00:00.

[04:58:42] [Thread   69] Circuit breaker now reports the service level as 80.

[04:58:42] [Thread   24] Circuit breaker now reports the service level as 100.

[04:59:04] [Thread   25] Processed 11963/37592 clients, 31.01 clients per second, 00:13:46 remaining

[04:59:05] [Thread   89] Processed 12000/37592 clients, 31.02 clients per second, 00:13:45 remaining

[04:59:05] [Thread   21] Processed 12000/37592 clients, 31.02 clients per second, 00:13:45 remaining

[04:59:13] [Thread   22] Error occured importing client EAW3000118. Started this attempt at 26/09/2011 4:59:11 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:59:11 AM +00:00.

[04:59:13] [Thread   22] Circuit breaker now reports the service level as 80.

[04:59:13] [Thread   58] Circuit breaker now reports the service level as 100.

[04:59:28] [Thread   99] Error occured importing client EAW3000105-Child4273. Started this attempt at 26/09/2011 4:59:26 AM +00:00. Started the very first attempt to import this client at 26/09/2011 4:59:26 AM +00:00.

[04:59:28] [Thread   99] Circuit breaker now reports the service level as 80.

[04:59:28] [Thread   89] Circuit breaker now reports the service level as 100.

[04:59:35] [Thread   43] Processed 12956/37592 clients, 31.06 clients per second, 00:13:13 remaining

[04:59:37] [Thread   49] Processed 13000/37592 clients, 31.06 clients per second, 00:13:11 remaining

[04:59:37] [Thread  102] Processed 13000/37592 clients, 31.06 clients per second, 00:13:11 remaining

[05:00:07] [Thread  106] Processed 13966/37592 clients, 31.11 clients per second, 00:12:39 remaining

[05:00:08] [Thread   25] Processed 14000/37592 clients, 31.12 clients per second, 00:12:38 remaining

[05:00:08] [Thread   86] Processed 14000/37592 clients, 31.12 clients per second, 00:12:38 remaining

[05:00:38] [Thread   78] Processed 14926/37592 clients, 31.08 clients per second, 00:12:09 remaining

[05:00:41] [Thread   83] Processed 15000/37592 clients, 31.09 clients per second, 00:12:06 remaining

I wanted to also ensure indexing via Neo4j to Lucene did not affect the heap usage and frequency is a negative way,, that could possible cause the heap to grow, below is a image showing that the indexing is keeping the heap size and usage within normal range (blue lines)

image

Also, CPU Utilisation was high with the indexing, proving efficient use of CPU.

image

Below is a graph of heap usage importing 37000 clients, with all the optimisation and tweaks. This run in around 30 minutes.

image

Desired throughput achieved Smile

Note, heap size did not need to grow beyond 512, as gremlin queries are parameterised.

Summary

Increasing Heap Size to 512m –> 1024m was sufficient to reduce GC collection.

Increasing Stack size from 1024 –> 2048k improves multiple thread operations.

Switching on GC logging is definitely a good way to get a view of how your heap is being used.

Disabling neo4j transaction roll over logging did not improve performance.

Disabling the Lucene index creations via the REST API solved the instability issues with the Rest API. optimising the threads on the client, and using parameterised queries removed the instability issue.

The REST API calls are causing the system to become unstable (Out Of memory errors). If the threads are  optimised on the client with the use of parameterised gremlin queries, upgrade to Neo4j1.5.01M, incorporate batching, then Lucene indexing is also optimised.

CPU utilization is much more efficient after thread optimisation.

Parameterised queries and upgrading to Neo4j1.5.M01 increased performance and DRASTICALLY reduced the frequency of the heap size usage thus stabilising the heap usage.

*** By configuring the .Net client that sent REST calls on different threads to limit the thread count to 70 threads, we were able to improve performance 5 fold. This is the most significant improvement. 70 threads were chosen to match the similar number (80) that Neo4j reserves in the JVM. +- 35 nodes per second as compared with 5-6 nodes per second.

We now implemented batching in the Neo4Client NUGet package to further increase performance.

Batching improved performance.

Basically in our scenario, a node created between 4 to 8 index entries, this with the current release of Neo4j 1.4.1, means 4-8 rest calls. An issue has been logged to improve the rest calls to just one, where you can then parse in a dictionary of key/val pairs in the request body of the POST. The issue is located here:

https://github.com/neo4j/community/issues/25

A separate issue has been created to investigate why the REST API for indexes causes the system to become unstable.

https://github.com/neo4j/community/issues/28

In Short:

Optimise Threads from your client to be below 80 as Neo4j Server allocated 80 threads to the JVM, so no point in sending rest calls on more than 80 threads. (This is for a machine with 8 cores (Neo4j allocated 10 threads per core)).

So if you neo4j server is a dual core (10 * 2) = 20 threads. Quad Core = 40 Threads.

Use the Rest batching API.

If using Gremlin, use parameterised queries.

Use Circuit Breaker pattern to implement retry logic if calls fail (Optional)

Purity

Where is purity in our lives?

We marry, we divorce. We do not care who we hurt . We think loyalty is a cool but meaningless virtue. We sacrifice the norms and values of our youth to purchase the glory of our latest years. Worst of all we enforce this on the next generation, the young and innocent.

We think if we triumph in one pinnacle point in our lives, like an athlete breaking the next record that it will dissolve all the other filth we preoccupy ourselves with.