Yet another story about high cpu utilization…

by perfstories

I’m going to tell you one more story about high cpu utilization.

First, I’ll tell you the background information, how the problem was localized. Then we will think how HashMap can prove high cpu utilization.

The background information

There was high cpu utilization even after test ending. We found pretty quickly that the reason of high cpu utilization is HashMap.get. There was just a classic situation, when we had a thread hanging in a RUNNABLE state with a stack trace like this (Unfortunately, I lost the exact stack trace, that was more than 2 years ago, found the profile picture only, i.e. without line numbers):

 
at java.util.HashMap.get(Object)
at com.sun.identity.delegation.plugins.DelegationPolicyImpl.getResultFromCache(String, String, Map)
at com.sun.identity.delegation.plugins.DelegationPolicyImpl.isAllowed(SSOToken, DelegationPermission, Map)
…
at com.sun.identity.idm.AMIdentityRepository.searchIdentities(IdType, String, IdSearchControl)
….

Moreover, as we had 4 logical processors, cpu utilization increased as a number of the threads spinning on the thread stack mentioned above increased. The correspondence was as follows: 1 thread – 25% cpu utilization, 2 threads – 50%, 3 threads – 75%, 4 threads and so on 100%. I mean after the load ending.

If you look into com.sun.identity.delegation.plugins.DelegationPolicyImpl code you can discover easily non thread safe usage of non thread safe class (java.util.HashMap).

We replaced HashMap with HashTable there (delegationCache is just a static field) and failed to reproduce high cpu utilization:

private static void putResultIntoCache(String tokenIdStr, 
                                       String resource, 
                                       Map envParams, 
                                       PolicyDecision pd) 
                                           throws SSOException, DelegationException { 
    if (resource != null) {
        ArrayList al = new ArrayList(2); 
        al.add(0, envParams); al.add(1, pd); 
        Map items = (Map)delegationCache.get(tokenIdStr); 
        if (items == null) { 
            items = new HashMap() new HashTable(); 
        } 
        items.put(resource, al); delegationCache.put(tokenIdStr, items); 
    } 
}

Actually you could look into the current version of OpenSSO to understand why the usage is not thread safe, etc (fortunately, the bug is still there :)): http://sources.forgerock.org/browse/~br=trunk/openam/trunk/opensso/products/amserver/source/com/sun/identity/delegation/plugins/DelegationPolicyImpl.java?r=2879.

Okey, the problem is non thread safe usage of HashMap. Our fix is ready.

But WHY does non thread safe usage of HashMap cause high cpu utilization?

Actually, I’m not the only one who faced with this issue. You can easily find in the Internet a lot of discussions. For, instance:

  1. http://lightbody.net/blog/?p=307(In particular, see the comment from August 16, 2010 at 9:51 pm at Genry B. He wrote a simple reproducer, which reproduces indeed);
  2. http://geek.starbean.net/?p=343(In particular, see the comment from February 23, 2011 at 11:03 pm by Jun Xu).

Actually, it’s interesting how many people interpret “Note that this implementation is not synchronized. If multiple threads access a hash map concurrently, and
at least one of the threads modifies the map structurally, it must be synchronized externally.” (HashMap API) as a data consistency (not loop counter but data consistency) warning. These are very strange assumptions out of API. Because of this I like very much a heading of (2) mentioned above: “When they say HashMap is not thread-safe, it means it is not” :).

Let me also talk about HashMap… 😉

So the situation is very simple indeed. Endless loops we can have easily in a lot of methods of HashMap, where there are cycles like this:

for (Entry<K,V> e = table[indexFor(hash, table.length)]; 
     e != null; e = e.next) {
    …
 }

You can find such cycles in methods: get, put… They just iterate through the lists. The only things we need to prove is: if HashMap is used in a non thread safe manner, there could be endless loops:

For me it’s just obvious, if two or more threads perform HashMap modifications simultaneously. You can look at transfer method, see [1]. You can see there is a lot of logic with list pointers, so if 2 or more threads will execute this method simultaneously, there will be no logic. We can get any unpredictable lists structure. In particular, there are could be cyclic lists.

Actually, I wrote a very simple reproducer (see [2]). No HashMap is required. There are only several methods of HashMap, like hash, indexFor and transfer. The probability of reproduction is more than 0,85 on my machine. Actually, it depends on your hardware (you can increase CAPACITY, EXPERIMENTS_NUM, a number of threads).

[1]

void resize(int newCapacity) {
    Entry[] oldTable = table;
    int oldCapacity = oldTable.length;
    if (oldCapacity == MAXIMUM_CAPACITY) {
        threshold = Integer.MAX_VALUE;
        return;
    }

    Entry[] newTable = new Entry[newCapacity];
    transfer(newTable);
    table = newTable;
    threshold = (int)(newCapacity * loadFactor);
}
void transfer(Entry[] newTable) {
    Entry[] src = table;
    int newCapacity = newTable.length;
    for (int j = 0; j < src.length; j++) {
        Entry<K,V> e = src[j];
        if (e != null) {
            src[j] = null;
            do {
                Entry<K,V> next = e.next;
                int i = indexFor(e.hash, newCapacity);
                e.next = newTable[i];
                newTable[i] = e;
                e = next;
            } while (e != null);
        }
    }
}

[2]

public class Test {
    static final int CAPACITY = 10000;
    static final int EXPERIMENTS_NUM = 10000;
    static Entry[] array = new Entry[CAPACITY];
    static volatile int endlessLoopInsideTransfer = 0;
    static volatile int endlessLoopInsideCheck = 0;

    static class Entry {
        Entry next;
    }

    public static class Worker extends Thread {
        public void run() {
            Entry[] newArray = new Entry[CAPACITY * 2];
            transfer(array, newArray);
            array = newArray;
        }
    }

    //copied from HashMap 1.6.0 u20 sources
    static int hash(int h) {
        h ^= (h >>> 20) ^ (h >>> 12);
        return h ^ (h >>> 7) ^ (h >>> 4);
    }

    //copied from HashMap 1.6.0 u20 sources
    static int indexFor(int h, int length) {
        return h & (length-1);
    }

    //copied from HashMap 1.6.0 u20 sources, except lines marked by *
    static void transfer(Entry[] table, Entry[] newTable) {
        Entry[] src = table;
        int newCapacity = newTable.length;
        for (int j = 0; j < src.length; j++) {
            Entry e = src[j];
            if (e != null) {
                src[j] = null;
                int count = 0; //*
                do {
                    Entry next = e.next;
                    int i = indexFor(hash(e.hashCode()), newCapacity);
                    e.next = newTable[i];
                    newTable[i] = e;
                    e = next;
                    if (count > CAPACITY) { //*
                        endlessLoopInsideTransfer++; //*
                        break;//*
                    }
                    count++; //*
                } while (e != null);
            }
        }
    }

    static int check(Entry[] array) {
        int result = 0;
        for (Entry e: array) {
            int count = 0;
            while (e != null) {
                count ++;
                e = e.next;
                if (count > CAPACITY) {
                    endlessLoopInsideCheck++;
                    result ++;
                    break;
                }
            }
        }
        return result;
    }

     public static boolean isReproduced() throws Exception {
         for (int i = 0; i < CAPACITY; i++) {
                array[i] = new Entry();
            }
            Thread t1 = new Worker();
            Thread t2 = new Worker();
            t1.start();
            t2.start();

            t1.join();
            t2.join();

            return check(array) > 0;
    }

    public static void main(String[] args) throws Exception {
        int successNum = 0;
        for (int i = 0; i < EXPERIMENTS_NUM; i ++ ) {
            if (isReproduced()) {
                successNum++;
            }
        }
        System.out.println((double)successNum/(double)EXPERIMENTS_NUM);
        System.out.println(endlessLoopInsideCheck);
        System.out.println(endlessLoopInsideTransfer);
    }
}




Advertisements