Java Garbage Collection : Unexpected Full GC

I've been digging garbage collection logs these days. We have a production server which suffers long pauses of garbage collection. According to garbage collection log file, there are three different cases that force the JVM to do a StopTheWorld collection:

1. Full GC after a promotion failure: This is the evidence of not enough contiguous space in the old (tenured) generation. The simplest solution to this is increasing heap size. (I am glad it worked for us.)

2. Full GC after a concurrent mode failure (in other words; full promotion guarantee failure) : CMS collector can not catch up with the object allocation speed of the application. If this is the case try setting CMSInitiatingOccupancyFraction to a lower value. CMS will start early but will finish its job on-time.

3. The third one was very difficult for me to figure out. Here is what it looks like: Everything seems to work fine but suddenly Full GC kicks in and 37 seconds of break for application threads.

216066.711: [GC 216066.713: [ParNew: 911554K->71428K(943744K), 0.0860545 secs] 2346321K->1508264K(4089472K), 0.0878449 secs] [Times: user=3.63 sys=0.32, real=0.09 secs]
216066.896: [Full GC 216066.897: [CMS: 1436836K->1003062K(3145728K), 37.8691646 secs] 1527124K->1003062K(4089472K), [CMS Perm : 86016K->31249K(86016K)], 37.8707796 secs] [Times: u
ser=37.64 sys=0.35, real=37.87 secs]
216106.398: [GC 216106.399: [ParNew: 838912K->46337K(943744K), 0.0555625 secs] 1841974K->1049399K(4089472K), 0.0573404 secs] [Times: user=1.33 sys=0.45, real=0.06 secs]

The above log says that in order to clean permanent generation a full collection occured and (86016 - 31249) kilobytes of space freed in permanent generation.

What I've learned today is : The garbage of the permanent generation is only collected by a Full GC. If you see unexpected full collections try expanding permanent generation.

Load Test Whatever You Want With Apache JMeter

This is the second post about load testing with Apache JMeter, read the first post here: A step by step tutorial about load testing relational databases.

JMeter has lots of Samplers. If you need a sampler that is not provided by JMeter you can write your custom sampler. (custom samplers are called "Java Request" in JMeter terminology)
This post will show you, step by step, how to write a JMeter Java Request.

Step 1: Preparing the development environment

Add these two jar files to the java classpath.

1. $JMETER_HOME/lib/ext/ApacheJMeter_core.jar
   
2. $JMETER_HOME/lib/ext/ApacheJMeter_java.jar
   

(If you are using Eclipse, add these files as external jar files to the java build path.)

Step 2: Extending AbstractJavaSamplerClient

After setting up the classpath, create a custom sampler by extending AbstractJavaSamplerClient and override the following methods.

public Arguments getDefaultParameters() {...}
public void setupTest(JavaSamplerContext context) {...}
public void teardownTest(JavaSamplerContext context) {...}
public SampleResult runTest(JavaSamplerContext context) {...}

getDefaultParameters
Implement getDefaultParameters if you want initial values for test paramters. JMeter will display the parameters in its Java Request configuration GUI. (See the contents of the red rectangle in the picture below.) Here's an example implementation:

public Arguments getDefaultParameters() {
    Arguments defaultParameters = new Arguments();
    defaultParameters.addArgument("memcached_servers", "localhost:11211");
    defaultParameters.addArgument("username", "testuser");
    defaultParameters.addArgument("password", "testpasswd");
    return defaultParameters;
}

setupTest
This is where you read test parameters and initialize your test client. JMeter calls this method only once for each test thread.

teardownTest
Clean up the mess.

runTest
Write your test logic in this method. JMeter will call runTest method for every execution of test threads. Here is a typical runTest implementation:

@Override
public SampleResult runTest(JavaSamplerContext context) {
    SampleResult result = new SampleResult();
    boolean success = true;
    result.sampleStart();
    //
    // Write your test code here.
    //
    result.sampleEnd();
    result.setSuccessful(success);
    return result;
}

The time elapsed betweed result.sampleStart() and result.sampleEnd() is used to calculate average response time of the application under test.

Step 3: Deploy your custom sampler

When you are done create a jar file (containing your custom sampler) in the $JMETER_HOME/lib/ext/ directory. JMeter will display your java request in the java request configuration page.

You can see the results of your test by adding listeners to your test plan. "A step by step tutorial about load testing relational databases" post shows how to add listeners to test plans.

Java IntegerCache

Şirkette yazdığımız bir kodu Eclipse FindBugs plugini ile incelerken kodun sarı renkli böcekler tarafından istila edildiğini gördük. Integer sınıfını kullandığımız hemen hemen her sınıf içinde FindBugs bize aşağıdaki uyarıyı veriyordu:

Method invokes inefficient Number constructor; use static valueOf instead

"Yav bırak allah aşkına, alt tarafı bir Integer yaratacaksın" deyip FindBugs uyarısını görmezden gelme varsayılan davranışımdır fakat bugün can sıkıntısının da etkisi ile Java SDK içindeki Integer sınıfının koduna baktım. "new Integer(5)" ile "Integer.valueOf(5)" arasında ne gibi bir fark olabilir çok merak ediyordum. Integer.java sınıfı içerisinde fark yaratan kod aşağıdaki IntegerCache sınıfıymış. JVM sizin için 256 adet tam sayıyı önbelleğe alıyor. -128'den +127'ye kadar olan tam sayılar için Integer.valueOf size hep aynı Integer instance'ını veriyor.

private static class IntegerCache {
private IntegerCache(){}

static final Integer cache[] = new Integer[-(-128) + 127 + 1];

static {
for(int i = 0; i < cache.length; i++)
cache[i] = new Integer(i - 128);
}
}

/**
* Returns a Integer instance representing the specified
* int value.
* If a new Integer instance is not required, this method
* should generally be used in preference to the constructor
* {@link #Integer(int)}, as this method is likely to yield
* significantly better space and time performance by caching
* frequently requested values.
*
* @param  i an int value.
* @return a Integer instance representing i.
* @since  1.5
*/
public static Integer valueOf(int i) {
final int offset = 128;
if (i >= -128 && i <= 127) { // must cache 
return IntegerCache.cache[i + offset];
}
return new Integer(i);
}

Küçük bir örnekle konuya nokta koymak istiyorum. Bğyle ufak tefek performans optimizasyonları ile işim olmaz fakat java 1.5'ten beri aktif olan bu özelliği daha yeni öğrendiğim için ilgimi çekti sizinle de paylaşmak istedim.

public class IntegerCacheTest {
public static void main(String[] args) {
Integer int1 = Integer.valueOf(5);
Integer int2 = Integer.valueOf(5);
Integer int3 = new Integer(5);
Integer int4 = 5; 
if ( int1 == int2) {
System.out.println("int1 ve int2 ayni instance.");
} 
if( int1!= int3) {
System.out.println("Fakat int1 ve int3 farkli instance'lar");
} 
if (int1 == int4) {
System.out.println("int1 ve int4 de aynı instance");
} 
if (int1.equals(int2) && int2.equals(int3) && int3.equals(int4)) {
System.out.println("ve son olarak hepsinin değeri aynı :)");
}
}
}

Yukarıdaki kod parçasını çalıştırırsanız aşağıdaki gibi bir çıktı alırsınız.

int1 ve int2 ayni instance.
Fakat int1 ve int3 farkli instance'lar
int1 ve int4 de aynı instance
ve son olarak hepsinin değeri aynı :)

Fakat bu sonuç sizi beni şaşırttığı kadar şaşırtmayabilir :)

Monetary Calculations In Java

float and double types are not suitable for monetary calculations in Java. If this is the first time you hear this you are in trouble.

Floating point arithmetic which is used to represent float/double variables is inappropriate for exact results calculations. For example it is impossible to represent 0.1 (or any other negative power of ten) as a float or double exactly. Here is an example:

float s1 = 0;
for (int i = 0; i < 10; i++) {
s1 += 0.10;
System.out.println(s1);
}

This code prints:

0.1
0.2
0.3
0.4
0.5
0.6
0.70000005
0.8000001
0.9000001
1.0000001

Here's another example: (0.1+0.1+0.1) == 0.3 What is the value of this statement true or false? since the sum (0.1+0.1+0.1) is not equal to 0.3 according to JVM, rounding up the sum would result in 4 which is not expected either. I think you got the point. We can not trust float or double variables if we want exact results. Applications that makes money/credit calculations needs exact results. To represent monetary values in Java you should use the BigDecimal class.

BigDecimal bd = new BigDecimal("0");
for (int i = 0; i < 10; i++) {
bd = bd.add(new BigDecimal("0.10"));
System.out.println(bd);
}

This java example prints (as expected):

0.10
0.20
0.30
0.40
0.50
0.60
0.70
0.80
0.90
1.00

ReadWriteLock example in Java

Writing multithreaded java applications is not a piece of cake. Extra care must be taken because bad synchronization can bring your application to its knees. The JVM heap is shared by all the threads. If multiple threads need to use the same objects or static class variables concurrently, thread access to shared data must be carefuly managed. Since version 1.5, utility classes commonly useful in concurrent programming is included in the JSDK.

In Java synchronized keyword is used to acquire a exclusive lock on an object. When a thread acquires a lock of an object either for reading or writing, other threads must wait until the lock on that object is released. Think of a scenerio that there are many reader threads that reads a shared data frequently and only one writer thread that updates shared data. It's not necessary to exclusively lock access to shared data while reading because multiple read operations can be done in parallel unless there is a write operation.

In this post i'll give an example usage of ReadWriteLock interface which is introduced in the Java 1.5 API Doc. In Java Api Documentation it says :

A ReadWriteLock maintains a pair of associated locks,
one for read-only operations and one for writing.
The read lock may be held simultaneously by multiple reader threads,
so long as there are no writers. The write lock is exclusive.

Reader threads can read shared data simultaneously. A read operation does not block other read operations. This is the case when you execute an SQL SELECT statement. But write operation is exclusive. This means all readers and other writers are blocked when a writer thread holds the lock for modifing shared data.

Writer.java This class represents a thread that updates shared data. Writer uses WriteLock of ReadWriteLock to exclusively lock access to dictionary.


01 package deneme.readwritelock;
02 
03 
04 public class Writer extends Thread{
05   private boolean runForestRun = true;
06   private Dictionary dictionary = null;
07   
08   public Writer(Dictionary d, String threadName) {
09     this.dictionary = d;
10     this.setName(threadName);
11   }
12   @Override
13   public void run() {
14     while (this.runForestRun) { 
15       String [] keys = dictionary.getKeys();
16       for (String key : keys) {
17         String newValue = getNewValueFromDatastore(key);
18         //updating dictionary with WRITE LOCK
19         dictionary.set(key, newValue);
20       }
21       
22       //update every seconds
23       try {
24         Thread.sleep(1000);
25       } catch (InterruptedException e) {
26         e.printStackTrace();
27       }
28     }
29   }
30   public void stopWriter(){
31     this.runForestRun = false;
32     this.interrupt();
33   }
34   public String getNewValueFromDatastore(String key){
35     //This part is not implemented. Out of scope of this artile
36     return "newValue";
37   }
38 }

Reader.java This class represents a thread that reads share data.


01 package deneme.readwritelock;
02 
03 public class Reader extends Thread{
04   
05   private Dictionary dictionary = null;
06   public Reader(Dictionary d, String threadName) {
07     this.dictionary = d;
08     this.setName(threadName);
09   }
10   
11   private boolean runForestRun = true;
12   @Override
13   public void run() {
14     while (runForestRun) {
15       String [] keys = dictionary.getKeys();
16       for (String key : keys) {
17         //reading from dictionary with READ LOCK
18         String value = dictionary.get(key);
19         
20         //make what ever you want with the value.
21         System.out.println(key + " : " + value);
22       }
23       
24       //update every seconds
25       try {
26         Thread.sleep(1000);
27       } catch (InterruptedException e) {
28         e.printStackTrace();
29       }
30     }
31   }
32   
33   public void stopReader(){
34     this.runForestRun = false;
35     this.interrupt();
36   }
37 }

Dictionary.java This is a simple and thread safe dictionary. Read operations are managed through ReadLock and write operations (updates) are managed throuh WriteLock.


01 package deneme.readwritelock;
02 
03 import java.util.HashMap;
04 import java.util.concurrent.locks.Lock;
05 import java.util.concurrent.locks.ReentrantReadWriteLock;
06 
07 public class Dictionary {
08   
09   private final ReentrantReadWriteLock readWriteLock = 
10     new ReentrantReadWriteLock();
11 
12   private final Lock read  = readWriteLock.readLock();
13   
14   private final Lock write = readWriteLock.writeLock();
15   
16   private HashMap<String, String> dictionary = new HashMap<String, String>();
17   
18   public void set(String key, String value) {
19     write.lock();
20     try {
21       dictionary.put(key, value);
22     } finally {
23       write.unlock();
24     }
25   }
26   
27   public String get(String key) {
28     read.lock();
29     try{
30       return dictionary.get(key);
31     } finally {
32       read.unlock();
33     }
34   }
35 
36   public String[] getKeys(){
37     read.lock();
38     try{
39       String keys[] = new String[dictionary.size()];
40       return dictionary.keySet().toArray(keys);
41     } finally {
42       read.unlock();
43     }
44   }
45   
46   public static void main(String[] args) {
47     Dictionary dictionary = new Dictionary();
48     dictionary.set("java",  "object oriented");
49     dictionary.set("linux", "rulez");
50     Writer writer  = new Writer(dictionary, "Mr. Writer");
51     Reader reader1 = new Reader(dictionary ,"Mrs Reader 1");
52     Reader reader2 = new Reader(dictionary ,"Mrs Reader 2");
53     Reader reader3 = new Reader(dictionary ,"Mrs Reader 3");
54     Reader reader4 = new Reader(dictionary ,"Mrs Reader 4");
55     Reader reader5 = new Reader(dictionary ,"Mrs Reader 5");
56     writer.start();
57     reader1.start();
58     reader2.start();
59     reader3.start();
60     reader4.start();
61     reader5.start();
62   }
63   
64 }

Generating unique strings with JAVA

If you need randomly generated Strings in your java code you can use the below functions.

01  public String generateRandomString(String s) { 02   try { 03    SecureRandom prng = SecureRandom.getInstance("SHA1PRNG"); 04    String randomNum = new Integer(prng.nextInt()).toString(); 05    randomNum += s; 06    MessageDigest sha = MessageDigest.getInstance("SHA-1"); 07    byte[] result = sha.digest(randomNum.getBytes()); 08    return hexEncode(result); 09   } catch (NoSuchAlgorithmException e) { 10    return  System.currentTimeMillis()+"_"+username; 11   } 12  }

The classical hexEncode method:

01 protected String hexEncode(byte[] aInput) { 02   StringBuffer result = new StringBuffer(); 03   char[] digits = { '0', '1', '2', '3', '4', '5', '6', '7', '8', '9', 04     'a', 'b', 'c', 'd', 'e', 'f' }; 05   for (int idx = 0; idx < aInput.length; ++idx) { 06    byte b = aInput[idx]; 07    result.append(digits[(b & 0xf0) >> 4]); 08    result.append(digits[b & 0x0f]); 09   } 10   return result.toString(); 11  }

Suppose that you need to generate unique random session ids for your logged in users. You can use the above function as follows :

       String sessionId = generateRandomString(username);

10 consecutive calls to generateRandomString("ilkinulas") generates the following strings:

38aca43c835888bc38fbb2d431f537489d637427
8c9fec7eb1309cd60a9548a11b16a30c2cf277a4
d495e83405704d38bfdf1bc3e2a38b31a5b52243
e3f15b900a3b80936596dc4471c0e42889dbf00c
83a4c869593af633a97b3b68433fac19bac7937d
f7573e8fdb4ecf6f58062570b66943b08d87fab8
c19bfdf75abbafbb5d9ca0ce37b90e97f08fccfa
41f0d9cd01ff814f8879bbff4b06642fc01a4624
aae1a792389239ca8db35a1ff9b16856c9921845
c2c9041ab5039b38c79a125c57a10cc6a3eabad9