Tuesday, August 6, 2013

Memory Usage of Oracle 10 & 11 JDBC Drivers - Mysterious OutOfMemoryErrors

A client of mine recently had a problem where they were seeing OutOfMemoryError errors despite the fact they had a web application application that should have a small memory footprint, and despite the fact they had allocated a heap size of just over a gig (which was massive considering the type of application).

Taking a look at the nature of the application and how it was doing things did not raise any particular alarm bells - the most likely culprit was a high read/high object creation/high write batch job that could be run from within the application. The rest of the code was by and large (baring business logic) a standard CRUD application.

I intially took some heap dumps and analysed them using the standard jmap/jhat tools to get a feel of what was going on. I also added additional garbage collection tracing:

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -verbose:gc 
 
This verified that a large number of objects were indeed being created and held for the duration of the job,  but curiously there were two massive arrays that could not be explained: a large char[] and an equally large SoftReference[].

Investigating further I discovered that the root of both of these seemed to be the BasicDataSource (configured using Spring) - this was surprising and equally confusing.  What was the DataSource doing creating these arrays?  And more significantly, why was it maintaining what must be a strong reference to them (as they were not being garbage collected)?

Ultimate the problem came down to two things:

The application had:
  • Set the defaultFetchSize to 10000
  • Set the write batch size to 10000
After drilling down into the  created objects and much investigation it turns out that the JDBC drivers from Oracle 10 onwards created char[] and byte[] for use in reading and writing out data. The size of these arrays were dependant on both the types of queries ("select * from my_table" would allocate a larger array than just "select id from my_table", for example) as well as on the defaultFetchSize.

I've put together a simple test class that illustrates this behaviour - it does two things:
  • For 3 simple queries prints the char[] and byte[] allocated by the jdbc driver (using reflection) for fetch sizes from 10 to 10000
  • Creates a connection & statement for a fetch size of 10000 and waits (it also creates 200000 integers per second which is then discards) - for use in watching the heap using VisualVM.
The first test, on my particular PC, yields the following results:

For the following query: select * from TAB:
batch size:     10, defineBytes       4096 long, defineChars       4096 long
batch size:    100, defineBytes       4096 long, defineChars       8192 long
batch size:   1000, defineBytes      32768 long, defineChars      65536 long
batch size:  10000, defineBytes     524288 long, defineChars     524288 long
For the following query: select id from TAB:
batch size:     10, defineBytes       4096 long, defineChars            null
batch size:    100, defineBytes       4096 long, defineChars            null
batch size:   1000, defineBytes      32768 long, defineChars            null
batch size:  10000, defineBytes     262144 long, defineChars            null
For the following query: select * from student:
batch size:     10, defineBytes       4096 long, defineChars       4096 long
batch size:    100, defineBytes       8192 long, defineChars      32768 long
batch size:   1000, defineBytes      65536 long, defineChars     262144 long
batch size:  10000, defineBytes     524288 long, defineChars    4194304 long


As you can see from above, arrays are dependant on both the query as well as on the fetch size.

Within the Statement  (Oracles implementation of it) I can see the following lookup table:

4096
8192
16384
32768
65536
131072
262144
524288
1048576
2097152
4194304

You can see that these values to the power of 2, starting at 12.  It would appear that dependant on the combination of query and the fetch size a value from the above is chosen.

If the query has no character data then the char[] will remain unallocated (as in the 2nd query above), and if the query has no numeric/binary data then the byte[] array will remain unallocated.

In other words, the Oracle JDBC will allocate char[] and byte[] when the statements are created and keep hold of them until the statement is closed, which can a very long time in certain scenarios (as with PreparedStatements for example).

The following screenshots from VisualVM show the heap for a fetch size of 10:







You can see a normal, healthy sawtooth here, which the expected Integer taking the largest slice of memory.

Lets compare the same code, but with a fetch size of 10000:






Here you can see a fairly flat heap with very small effective garbage collections, and the largest occupant is now a char[].

The solution was ultimately to compare fetch sizes to the actual performance gains made - it turned out that a fetch size of 100 was more than sufficient and the memory footprint dropped down to less than 512m, with no more OOM errors.

The oracle documentation around this suggests that the default fetch size of 10 is typically more than sufficient and fetch sizes of 100 are only to be used with great care - given the above memory considerations I can see why.

A small footnote on this - I mentioned that the size of the array was also dependant on the query.

This is true, but is less important than the fetch size - it can however still be a consideration if the fetch size is small (say the default size of 10).

If you have a column that is varchar2(4000) then a char[] of at least 8000 will be allocated (2x4000 2 byte characters). If the same column was only varchar2(100) then the char[] would be at least 200 - considerably smaller.

By the same token a query of select * from table will result in larger buffers than select id from table.

The upshot of this is that if you find the jdbc memory consumption to be excessive in your application and the fetch size isnt large, then take a good look at both your table definition and your queries - fine tuning of both can make a difference.

The code for these tests can be found in GitHub - I used the Oracle 11.2.0.1.0 JDBC for these tests, but the results should be similar for any driver from 10.x onwards.

Wednesday, July 10, 2013

Performance Gotchas Using Guava Collections

We're using the Google Guava Collection Library in our current codebase - its a very nice set of APIs and utilities that greatly simplify the use of collections.

Amongst other things it allows for easy filtering of collections - this will feel very natural if you've used comparably built in functionality from languages like Ruby (or if like me you like functional languages).

There is one class though that can cause serious performance issues: Collections2

The problem is that this class maintains a "live view" onto the original collection and although can be useful, it can also introduce problems into in your application in surprising ways.

I was recently asked to look at a sudden decrease in responsiveness in our application. I started with memory first and found that we were at 99% use in our PermGen space. I initially thought that this was the problem but it only took a minute or so to realize that it was 99% of currently allocated space, not 99% of total allowed space (i.e. there was room for the JVM to allocate more if necessary).

I then investigated the problematic code paths and found that certain blocks of code, which looks completely innocuous, were incredibly slow - for example:

public void doSomething(Collection<Integer> someData) {
    Map<Integer, String> someOtherData = 
        new HashMap<Integer, String>(someData.size());
    
    ...more code...
}

I found that as soon as this method was stepped into (via a debugger or by watching logs) it would suddenly pause for a period of time before continuing.  This was especially surprising when the collection passed in appeared to be empty!

Working my way up the call chain I found that the collection passed in was created using Collections2.filter

Taking a look at the javadocs I soon realised what the problem was - although the collection passed in (someData in my example) appeared to be empty, most operations on it still iterated over every item in the original collection using the Predicate originally specified.

The problem is best shown with a simplified example:

public static void main(String[] args) {
    List<Integer> list = new ArrayList<Integer>();
    for (int i = 0; i < 1000000; i++) {
        list.add(i);
    }

    Collection<Integer> filtered = 
        Collections2.filter(list, new Predicate<Integer>() {
        @Override
        public boolean apply(Integer integer) {
            return integer < 5;
        }
    });

    long start = System.nanoTime();
    list.size();
    System.out.println(
        String.format("list.size(): %19d", (System.nanoTime() - start)));

    start = System.nanoTime();
    filtered.size();
    System.out.println(
        String.format("filtered.size(): %15d", (System.nanoTime() - start)));
}

Your output may vary, but on my PC I get:

list.size():                9817
filtered.size():        24157424

The problem here is that the filtered collection will iterate 1,000,000 (in this example) for each operation - even for a simply operation such as size.  If you placed trace statements in the apply method you would see that it would be called the same number of times as the number of elements in the original collection.

Now to be fair the javadocs do warn about using this class:

Many of the filtered collection's methods, such as size(), iterate across every element in the underlying collection and determine which elements satisfy the filter. When a live view is not needed, it may be faster to copy Iterables.filter(unfiltered, predicate) and use the copy.

It turned out that a colleague had innocently started using this instead of FluentIterable (or just Iterables as stated above) and this had caused the performance issues we were seeing.

Although you could say the javadocs should have been read more carefully I'd additionally argue that perhaps the name of Collections2 could have been improved upon to make its use/intent clearer.

Still, its a nice class to know about - just don't use it when a straight copy will be better.

Monday, July 8, 2013

Processing RSS Feeds and Sending the Results to Instapaper using Java

Back in March I wrote about a small Google App Engine (GAE) app I'd written that polled Google Reader for selected feeds and sent the resulting articles to Instapaper for later, offline, reading.

Google has unfortunately recently decommissioned Google Reader so I've been forced to find an alternative mechanism to do this.  After a bit of investigation I couldn't really find anything lightweight enough that supported this sort of API so decided to see if I could write something myself that would handle the RSS interaction directly.

This turned out to be a really easy job thanks to a 3rd party library called Rome - it made the retrieval and parsing of feeds a trivial exercise, as shown below:

    SyndFeedInput input = new SyndFeedInput();
    SyndFeed feed = input.build(new XmlReader(inputstream));

    List<SyndEntry> entries = (List<SyndEntry>) feed.getEntries();

    entries.get(0).getTitle()...
    entries.get(0).getAuthor()...
    entries.get(0).getLink()...


And so on.

Now that I had a way to retrieve what I needed from the feeds I was interested in, I then needed a way to remember which articles I'd already processed.  For this I used GAE's datastore mechanism:

    Key storeKey = KeyFactory.createKey("Store", "StoreKey");
    DatastoreService datastore = 
        DatastoreServiceFactory.getDatastoreService();

To write:

    entry = new Entity("Entry", storeKey);
    entry.setProperty("id", id);
    entry.setProperty("data", data);
    entry.setProperty("date", new Date());

    datastore.put(entry);

To read by a specific attribute (id in this example):

    Query query = new Query("Entry", storeKey)
        .setFilter(Query.FilterOperator.EQUAL.of("id", id));
    List<Entity> entries = datastore.prepare(query)
        .asList(FetchOptions.Builder.withLimit(1));

To query with an operator (less than a specified date in this example):

    Query query = new Query("Entry", storeKey)
        .setFilter(Query.FilterOperator.LESS_THAN.of("date", date));
    List<Entity> entries = datastore.prepare(query)
        .asList(FetchOptions.Builder.withDefaults());

Using the query above I  perform a housekeeping task that deleted entries older than 10 days old:

    for (Entity entry : entries) {
        datastore.delete(entry.getKey());
    }

The updated code (that no longer references Google Reader) is, as before, available on GitHub.

Sunday, June 9, 2013

IntelliJ IDEA Plugin - Guava based Generator for equals, hashCode andtoString

At my current role we've agreed on upon a team wide way to implement equals, hashCode and toString using some of the Guava utility libraries.

Pressing Alt+Ins (or Ctrl+N on the Mac) will bring up the Generate sub-menu (in the Java context only):





For a class with the following fields:

    private int field1, field2;
    private String field3, field4;


selecting Guava equals() and hashCode()... will generate the following code:

    @Override
    public boolean equals(Object o) {
        if (this == o) return true;
        if (o == null || getClass() != o.getClass()) return false;

        TestClass that = (TestClass) o;

        return Objects.equal(this.field1, that.field1) &&
                Objects.equal(this.field2, that.field2) &&
                Objects.equal(this.field3, that.field3) &&
                Objects.equal(this.field4, that.field4);
    }

    @Override
    public int hashCode() {
        return Objects.hashCode(field1, field2, field3, field4);
    }


and selecting Guava toString()... will generate the following code:

    @Override
    public String toString() {
        return Objects.toStringHelper(this)
                .addValue(field1)
                .addValue(field2)
                .addValue(field3)
                .addValue(field4)
                .toString();
    }


In both cases you'll be prompted to select the fields you wish to include in the generated methods.  Each time you use these generators the current implementations of equals & hashCode or toString (depending on your choice) will be replaced, if they exist.

The plugin can be found in the official Jetbrains IntelliJ plugin repository under "Guava equals, hashCode and toString generator".

The source code is available on GitHub


Sunday, March 3, 2013

Google Reader API (RSS) to Instapaper - Now on GitHub

I've been meaning on starting to use GitHub for my project and today I've finally commited my first project.

I wrote the Google Reader to Instapaper ages ago (see the original post for more details), but couldnt really make the full code available as my passwords etc were hard coded.

I spent a couple of hours refactoring the code yesterday and pushed it out to GitHub - if you're interested the full code can now be found at GitHub

Saturday, February 9, 2013

The Raspberry Pi and Wireless RF (XRF) Temperature Loggers

Remote Temperature Logging - Why?

In our house one room has three exposed wall, as well as two double width windows fitted (one on each side of the room).  In the winter, this is a cold room. Very, very cold.

We're in the process of getting the central heating and double glazing replaced (they're both over 15-20 years old respectively) and are very ineffecient - I was however wondering what improvement we'd see once this work had been done. Really though what I wanted was an excuse to use as the basis for a project with my Pi, which I'd bought over 8 months ago and hadn't yet gotten aaround to playing with.

A Pi, wireless communication, python, Linux, soldering...now this sounded like fun!

First I searched for what I could use for this - what could I use that captured and could transmit temperature information - and most importantly, what could do this in a wireless way?

I found the answer using a combination of 1 Slice of Pi, a 2 Temperature XRF Sensor's and 3 XRF Wireless RF Radios, all of which I got from CISECO.

The documentation of the above is pretty decent, but there were still a number of threads you have to tie together to get all of this to work, so here we go:

The XRF that will sit on the Pi will act as a pass-thru receiver, where any data received from the Serial line will be broadcast on PANID, and for our purposes, any data received on PANID or PANID2 will be sent to the Serial line. (more on PANID later).

The remote sensors XRF will need to be configured as Thermistor "personality" - this will capture the temperator from the onboard thermistor and transmit it.

Out of the box the XRF modules will have the serial pass-through personality, so the first thing we have to is upload the thermistor firmare to the two XRF modules that will be used for temperature capture.

At a high level, you'll need to do the following:
  • Configure the Pi so that you can use the Serial Port
  • Install pySerial onto your Pi
  • Get the XRF Uploader downloaded and compiled onto your Pi
  • Download the latest XRF Thermistor firmware
  • Upload the Thermistor firmware to each of the remote modules
  • Configure the remote devices
  • Write software to read what's being sent!

Configure the Pi Serial Port

By default the stock raspbian (and debian I think) images use the UART for serial console communication - we need to change this so that we can use the serial port.

Note: For each of the system files modified here I suggest you back them up first, in case you need/want to roll the changes back

Modify /boot/cmdLine.txt to remove references to ttyAMA0 - this is the serial port

sudo vi /boot/cmdLine.txt

I needed to remove the following lines:

console=ttyAMA0,115200 kgdboc=ttyAMA0,115200  

and my cmdLine.txt now looks like this:

dwc_otg.lpm_enable=0 rpitestmode=1 console=tty1 root=/dev/mmcblk0p2 rootfstype=ext4 rootwait

Next we need to edit /etc/inittab:

sudo vi /etc/inittab

and comment our (or remove) the following line:

T0:23:respawn:/sbin/getty -L ttyAMA0 115200 vt100

Install pySerial 

I used pySerial for my final program, but I also found it useful to use the included miniterm.py serial terminal for configuration and debugging.

Navigate to where you'd like to install pySerial - I'll assume you're installing into your home directory for now (/home/pi or the shorthand ~)


Download pySerial 2.5 (and use Python 2.x, not Python 3) from here and copy it to /home/pi (or your preferred location)
 

cd ~
gunzip pyserial-2.5.tar.gz tar - xvf pyserial-2.5.tar
cd pyserial-2.5
sudo python setup.py install


You can test your installation by doing the following:

pi@raspberrypi ~ $ python
Python 2.7.3rc2 (default, May  6 2012, 20:02:25)
[GCC 4.6.3] on linux2
Type "help", "copyright", "credits" or "license" for more information.
>>> import serial
>>> ser=serial.Serial('/dev/ttyAMA0',9600)
>>> ser.inWaiting()
0


If you don't get any errors with this you're probably ok - your serial port is ready for your use and pySerial is install correctly.

Thermistor Firmware - Download and Prepare

You need to do this on the remote sensors.

You can, optionally, also do follow the same steps for the local XRF module if you want to upload the very latest serial pass-through firmware too.  The same steps, but you'll download/upload the serial pass-through firmware instead.

The official process can be found on the OpenMicro site, but here are my abbreviated steps:

Note: All of these steps are to be done on your Pi
  • Get the XRF Uploader from here: http://github.com/CisecoPlc/XRF-Uploader
  • Copy this to your PI and run the following on it  g++ xfr_uploader.cpp -o xrf_uploader
  • chmod +x xrf_uploader
  • Download the appropriate firmware - you want the latest llapThermistor-XXX version

Firmware Upload

Ensure your Slice of Pi is fitted to your Pi first.

A Raspberry Pi, a Slice of Pi and an XRF module
A Raspberry Pi, a Slice of Pi and an XRF module

For each of the XRF modules you want to update (the remote modules and optionally the local one, if you want to update the serial pass-through firmware), do the following:
  • Switch off your Pi (you can do this by hot-swapping I've heard, but I wouldn't recommend it )
  • Plug in your XRF module into your Slice of Pi
  • Switch your Pi back on
  • ./xrf_uploader -d /dev/ttyAMA0 -f llapThermistor-XXX
If you see something along the lines of:

pi@raspberrypi ~/xrf_loader $ ./xrf_uploader -d /dev/ttyAMA0 -f llapThermistor-V0.50-24MHz.bin
Writing new firmware file llapThermistor-V0.50-24MHz.bin to device /dev/ttyAMA0 with baud rate 9600...
Reading firmware file...
Read 1162 lines from firmware file
Opening device...
Setting serial parameters...
Waiting for device to settle...

<> Entering command modus
Timeout, no data received within 10 seconds


Either retry again, or switch off and reseat the XRF, and retry the process again.

A successful upload should look as follows:

pi@raspberrypi ~/xrf_loader $ ./xrf_uploader -d /dev/ttyAMA0 -f llapThermistor-V0.50-24MHz.bin
Writing new firmware file llapThermistor-V0.50-24MHz.bin to device /dev/ttyAMA0 with baud rate 9600...
Reading firmware file...
Read 1162 lines from firmware file
Opening device...
Setting serial parameters...
Waiting for device to settle...

<> Entering command modus
<- OK
-> ATVR
<- 0.63B XRF
<- OK
-> ATPG
<- OK
<> Sent 1162 of 1162 lines...


All OK, XRF successfully reprogrammed!

Waiting for device to settle...

<> Entering command modus
<- OK
-> ATVR
<- 0.50B APTHERM
<- OK

Optional! Set the PANID

The PANID is the ID that the XRF network will communicate on - if you leave it do the default everything will work just fine - I've changed mine mostly for security.  I'm probably just being over cautious - if you leave yours on the default PANID every else documented here will still work.

Note: If you do decide to set the PANID then the best time do to this is probably immediately after the firmware upload, and note too that you'll need to set the same PANID for every XRF module in your network

I'm using miniterm.py (included with pySerial, found under /pyserial-2.5/examples/miniterm.py) for these steps:

pi@raspberrypi ~ $ python ~/pyserial-2.5/examples/miniterm.py /dev/ttyAMA0
--- Miniterm on /dev/ttyAMA0: 9600,8,N,1 ---
--- Quit: Ctrl+]  |  Menu: Ctrl+T | Help: Ctrl+T followed by Ctrl+H ---


(Note: Entering Ctrl+T and then Ctrl+E will enable local echo, which can be useful when debugging)

The XRF should to each command with respond with "OK":

+++<no return>
ATID[4 hex chars, up to a max of EFFF]<return>
ATAC<return>
ATWR<return>


To Check the ID (but note, the output may be partly overwritten with OK):

Wait for 5 seconds
+++
ATID<return>

Test our new XRF network!

First a note on the two type of communication protocols available with the XRF modules - one is the the one we've used up until now, which the AT command mechanism and is the "direct", plugged in protocol.

The second is the over the air LLAP protocol - this is what we'll use to communicate between the XRF modules.

See here for the AT command reference and here for the LLAP command reference documentation.

Plug your remote XRF modules into the Thermistor boards - below are mine, one bare and one in the included enclosure (with holes drilled in by me for the XRF aerial and thermistor):

XRF Thermistor Modules
XRF Thermistor Modules

Ensure your Pi is setup with the Slice of Pi and your "local" XRF module plugged in.

Log into your Pi and using the serial terminal of your choice (I'm using miniterm.py) hop onto the serial port:

python ~/pyserial/pyserial-2.5/examples/miniterm.py /dev/ttyAMA0

Now plug the battery into one of your remote sensors (note: you probably want to hook up to a 3.3V power supply while testing as permanently on use while testing will drain the small 3V cells included in the remote modules really quickly)

You should see the following in your terminal:

a--STARTED--a--STARTED--a--STARTED--a--STARTED--a--STARTED--a--STARTED--

A quick note on the LLAP protocol (please see the command reference above for the full documentation), taken from the OpenMicro site:

The message is 12 characters long and in 3 distinct sections. To illustrate the 3 separate parts to the message, see this example:

aXXDDDDDDDD

1.  "a" is lower case and shows the start of the message
2.  XX is the device identifier (address A-Z & A-Z)
3.  DDDDDDDDDD is the data being exchanged.


So the a--STARTED message above is letting us know that the remote XRF module is talking to our local one - yay! Now lets see if we can communicate back to the remote XRF module:

Enter a--HELLO---- into your terminal - the remote XRF module should respond with HELLO - you can now communicate both way - fantastic.

Lets set the device ID of the remote XRF module - this is optional but if you're planning on more than 1 remote module I'd recommend it as you'll then be able to identify which module is talking.

In your serial terminal, issue the following commands:

a--CHDEVID[A-Z][A-Z]     (for example, a--CHDEVIDZZ will set the device ID to ZZ)
a--REBOOT---

The device should respond with the started messages again, but with the new ID:

aZZSTARTED--aZZSTARTED--aZZSTARTED--aZZSTARTED--aZZSTARTED--aZZSTARTED--

(assuming you used ZZ as your device ID)

Lets test it again:

Enter aZZHELLO---- into your terminal - the remote XRF module should respond with HELLO once more - you can now communicate using the new ID.

Finally, lets test that we can get a temperate reading back (which after all is what we're really after here!):

Enter the following command into your serial terminal:

aZZTEMP-----

You should get the temperature in Celcius back, along the lines of:

aZZTMPA18.78

You can get the thermistor module to send this periodically too, which is useful while testing:

aZZINTVL005S - this will get the device to send the temperature every 5 seconds

(the interval is 1 to 999 and the periods can be S(seconds), M(minutes), H(hours), D(days))

Once you're finished testing you can save the interval setting and make the device sleep between intervals by issuing the following command:

aZZCYCLE----

In addition to sending out the temperature at the set frequency, it will also send out the battery level every 10 cycles, which is useful.

Note however, that once you do this you'll be unable to communicate to the device while its sleeping, so only do this once you're happy that your network is working as desired (if you do however get it into a cycle and you decide you want to change the interval you can (again from the OpenMicro site) Ground pin 6 - this will force the device to be awake, you can then issue commands to change to interval or other settings. Note that unless you tell the device to stay awake (axxWAKE-----) then it will resume sleep as soon as you remove the ground from pin 6.)

Repeat the above exercise for each remote device - one at a time.

 

Write software to read what's being sent!

Below is a small program that will poll the serial port every minute for new messages (for this example I've set the XRF modules to send out a response once every 5 minutes):

import serial
from time import sleep, gmtime, strftime

DEVICE = '/dev/ttyAMA0'
BAUD = 9600

print (strftime("%a, %d %b %Y %H:%M:%S: Starting\n", gmtime()))

ser = serial.Serial(DEVICE, BAUD)
while True:
    print("%s: Checking..." % strftime("%a, %d %b %Y %H:%M:%S", gmtime()))
    n = ser.inWaiting()
    if n != 0:
        msg = ser.read(n)
        print("%s: %s" % (strftime("%a, %d %b %Y %H:%M:%S", gmtime()), msg))
    sleep(1 * 60)


An example of the output I get is:

Sat, 09 Feb 2013 21:00:14: Checking...
Sat, 09 Feb 2013 21:01:14: Checking...
Sat, 09 Feb 2013 21:01:14: aAATMPA3.242aABTMPA12.45
Sat, 09 Feb 2013 21:02:14: Checking...
Sat, 09 Feb 2013 21:03:14: Checking...


Note that I have two devices sending me data here, AA and AB.

That's it - I hope you find this useful!

Thursday, November 29, 2012

iTunes blows

I've never really liked iTunes but I'm increasingly growing to loathe it.

This months issues:

  • books dont fully sync to my iPad (some do, others get a black bar across the bottom and thats that - the book cant be opened)

  • certains movies are copied across...every...single...time...
Sigh.