FishEye and Crucible

I've been trying to execute the searchrate command, but the command so far always failed on the client side with the following exception:

From the access logs I can actually see several successful requests, and also the following kind of errors from the same attempts:

Searchrate is part of the SDK available here:

http://maven.forgerock.org/repo/snapshots/org/forgerock/opendj/opendj-ldap-toolkit/3.0.0-SNAPSHOT/opendj-ldap-toolkit-3.0.0-SNAPSHOT.zip

The exceptions are being generated in org.opends.server.extensions.TLSByteChannel.read(ByteBuffer). The code looks slightly dubious, for example it is not handling potential buffer size changes resulting from underflows and overflows.

Tcpdump output shows:

• [C,S] connect + SSL handshake
• [C] bind request
• [S] bind response
• [C] search request
• [S] search response
• [C] search request
• ... more searches
• [S] TCP RST/ACK

The client side traffic looks fine so this definitely looks like an issue in OpenDJ.

I've tried testing using OpenDJ SDK searchrate between a client and server on my laptop:

But I've not been able to trigger the issue. It looks like a non-loopback connection is important.

Hi Matt,

This has been a fun exercise!

I checked your changes today and they look pretty much spot on. As you said, we just need to clean up the logging a bit and allocate an LDAP OID for the new config property. I'd also recommend changing the property name so that it begins with "preload" and more aligned with the preload timeout property, making them easier to identify in dsconfig.

However...

I tested it pretty extensively today and had some surprising initial results:

1. like you, in nearly all of the tests that I performed I found that the old sequential "one DB at a time" approach was best, and that preloading the entire environment in a single "concurrent" pass was nearly always significantly slower
2. if I tried to load the environment in a single pass (I set concurrency = 100 for this) the JVM slowed to a halt pretty quickly and spent 100% of its time GCing

In light of (2) above I had a look at the preload config and saw that it had an option to limit the memory available to the preload (default: unlimited). Setting this option to 1MB prevented the poor GC behavior since beforehand clearly the preload was using more memory than was available. This seemed to align the fully concurrent preload (concurrency = 100) performance with the sequential performance as well (concurrency = 1) - clearly GCs were causing the performance regression.

By setting the preload memory to 10MB I managed to get significant performance improvements for the case where the FS cache is empty and the DB is too big to fit in both the FS cache and the DB cache at the same time (DB of 5GB on a machine with 8GB RAM): the concurrent preload took around 200s and sequential took around 300s.

At this point I was becoming pleased with this new functionality, but then I tried to test it on a "mature" database. The previous tests had been performed on new, immature, databases which have been freshly imported, whose log files are 100% utilized, and whose key order also matches disk order. But this is not the common case: most DBs are mature and have had many updates made to them causing their log files to become less utilized as well as records to become "shuffled" on the disk.

To test a "mature" DB I ran a modrate test for several minutes causing each one of the 3M entries to be rewritten. This only impacted the id2entry DB since the changes did not touch indexed attributes. After the modrate the DB had grown from around 4GB on disk to around 7GB (~50% utilized).

Further attempts to preload the DB had disastrous results. Instead of preloads taking between 3-5 minutes, they were now taking over 25 minutes. I never bothered to wait for them to finish in fact. I tried concurrent, sequential, and even reverted your changes, but no improvement.

It looks like the preload is looping through the DB log files over and over again which seems kind of strange since I expect preload to load everything in a single pass. Tomorrow I'm going to see if this is a regression from JE4 to JE5. Either way, I think that this is a defect of some sort in JE: a preload should just do a single pass of the log in my opinion.

I'll chase it up with the JE folk once I have enough data. The current terrible performance for mature DBs, with or without your changes, makes this enhancement more or less pointless unfortunately.

I'll keep you posted on my JE4 based tests and any responses I get from the JE devs.

Matt

Committed in the trunk.