25 мая 2011 г.

java: деградация пула строк

Наверняка многие java программисты знают о существовании пула строк, который хранится в PermGen.

Кроме всего прочего каждая строка, которая была получена через
new String(data);
можно привести к каноническому представлению посредством вызова метода intern().

Однако, доступ к полу строк может деградировать из-за большого кол-ва строк в пуле.

В своей статье вы уверены, что знаете про строки все? автор упоминает, что сложность intern() есть O(N), где N - размер пула строк.

Надо сказать меня сильно удивило - т.к. ещё в стародавние времена, когда стали доступны исходники sun hotspot jvm 1.4 (кстати, именно из них собирался blackdown-jdk) помню, что на уровне c++ пул строк сделан как Hashtable, у которого, как известно, сложность поиска O(1) - т.е константа.

Артём предоставил небольшой benchmark, который таки показывает линейность:
public class StringPoolTest {

static final int N = 1000000;
static int k;

static String TEST_STRING = "0123456789";


public static void main(String[] args) throws Exception{
final StringPoolTest stringPoolTest = new StringPoolTest();
stringPoolTest.m();
}

private void m() throws Exception {
for(final int i : new int[]{100, 1000, 
10 * 1000,
20 * 1000,
25 * 1000,
100 * 1000, 
500 * 1000, 
1000 * 1000
}){
cleanAndPopulate(i);
tripleCount(N);
}
}

private void tripleCount(int n) {
count(n);
count(n);
count(n);
}

private void cleanAndPopulate(int n) throws Exception{
clean();
populate(n);
}

private void gc() throws InterruptedException {
System.out.println(" gc begin");
Runtime.getRuntime().gc();
Runtime.getRuntime().gc();
Runtime.getRuntime().gc();
System.out.println(" gc finished.");
}

private void count(int n) {
int i, j;
long t = System.nanoTime();
for (i = 0; i < n; i++) {
i++;
}
long t1 = System.nanoTime();
for (j = 0; j < n; j++) {
access();
j++;
}
long t2 = System.nanoTime();
k = i - j;//prevent JIT from clashing loop
System.out.println(size() + ": " + (((t2 - t1) - (t1 - t)) / n / 1e3) + " us." );
}

private String[] a;// = new String[N];

protected void access() {
TEST_STRING.intern();
}

protected void populate(int n) {
a = new String[n];
for (int i = 0; i < n; i++) {
a[i] = Integer.toString(i).intern();
}
}

protected void clean() throws InterruptedException {
a = null;
gc();
}

protected int size() {
return a.length;
}
}

запускается на Sun JDK 1.6.0.25 / OpenJDK 1.6.0.22 всё с опциями
-verbose:gc 
-XX:+PrintGCTimeStamps 
-XX:+PrintGCDetails 
-XX:+PrintGCApplicationStoppedTime 
-XX:NewSize=144m 
-XX:MaxNewSize=144m 
-XX:PermSize=128m 
-XX:MaxPermSize=128m 
-XX:+UseParNewGC 
-XX:ParallelGCThreads=2 
-XX:MaxTenuringThreshold=1 
-XX:SurvivorRatio=8 
-XX:+UseConcMarkSweepGC 
-XX:+CMSParallelRemarkEnabled 
-XX:+CMSClassUnloadingEnabled 
-XX:+CMSPermGenSweepingEnabled 
-XX:CMSInitiatingOccupancyFraction=60 
-XX:+UseCMSInitiatingOccupancyOnly

и вот результаты, вызвавшие недоумение:

100: 0.101 us.
1000: 0.102 us.
10000: 0.117 us.
20000: 0.127 us.
25000: 0.136 us.
100000: 0.37 us.
500000: 2.96 us.
1000000: 7.725 us.

Легко заметить, что время отклика на участке до 25000 есть константа, после начинается рост.

Взглянем более детально на исходный код openjdk jvm:
openjdk/hotspot/src/share/vm/classfile/symbolTable.hpp:
class StringTable : public Hashtable {
friend class VMStructs;

private:
// The string table
static StringTable* _the_table;

static oop intern(Handle string_or_null, jchar* chars, int length, TRAPS);
oop basic_add(int index, Handle string_or_null, jchar* name, int len,
unsigned int hashValue, TRAPS);

// Table size
enum {
string_table_size = 1009
};

oop lookup(int index, jchar* chars, int length, unsigned int hashValue);

StringTable() : Hashtable(string_table_size, sizeof (HashtableEntry)) {}

StringTable(HashtableBucket* t, int number_of_entries)
: Hashtable(string_table_size, sizeof (HashtableEntry), t,
number_of_entries) {}

public:
// The string table
static StringTable* the_table() { return _the_table; }

static void create_table() {
assert(_the_table == NULL, "One string table allowed.");
_the_table = new StringTable();
}

static void create_table(HashtableBucket* t, int length,
int number_of_entries) {
assert(_the_table == NULL, "One string table allowed.");
assert(length == string_table_size * sizeof(HashtableBucket),
"bad shared string size.");
_the_table = new StringTable(t, number_of_entries);
}

///// cut 
};

openjdk/hotspot/src/share/vm/classfile/symbolTable.cpp:
oop StringTable::intern(Handle string_or_null, jchar* name,
int len, TRAPS) {
unsigned int hashValue = hash_string(name, len);
int index = the_table()->hash_to_index(hashValue);
oop string = the_table()->lookup(index, name, len, hashValue);

// Found
if (string != NULL) return string;

// Otherwise, add to symbol to table
return the_table()->basic_add(index, string_or_null, name, len,
hashValue, CHECK_NULL);
}


Всё выглядит вполне hash table, если бы не один момент:

symbolOop SymbolTable::basic_add(int index, u1 *name, int len,
unsigned int hashValue, TRAPS) {
assert(!Universe::heap()->is_in_reserved(name) || GC_locker::is_active(),
"proposed name of symbol must be stable");

// We assume that lookup() has been called already, that it failed,
// and symbol was not found.  We create the symbol here.
symbolKlass* sk  = (symbolKlass*) Universe::symbolKlassObj()->klass_part();
symbolOop s_oop = sk->allocate_symbol(name, len, CHECK_NULL);
symbolHandle sym (THREAD, s_oop);

// Allocation must be done before grapping the SymbolTable_lock lock
MutexLocker ml(SymbolTable_lock, THREAD);

assert(sym->equals((char*)name, len), "symbol must be properly initialized");

// Since look-up was done lock-free, we need to check if another
// thread beat us in the race to insert the symbol.

symbolOop test = lookup(index, (char*)name, len, hashValue);
if (test != NULL) {
// A race occurred and another thread introduced the symbol, this one
// will be dropped and collected.
return test;
}

HashtableEntry* entry = new_entry(hashValue, sym());
add_entry(index, entry);
return sym();
}

openjdk/hotspot/src/share/vm/utilities/hashtable.inline.hpp
inline void BasicHashtable::add_entry(int index, BasicHashtableEntry* entry) {
entry->set_next(bucket(index));
_buckets[index].set_entry(entry);
++_number_of_entries;
}

Кратко: при добавлении нового элемента не происходит масштабирование таблицы, таблица создана изначально с 1009 bucket'ов.

При значительном увеличении пула строк данная таблица вырождается - как следствие увеличивается число коллизий по hash коду, что мы и наблюдаем на benchmark'е.

Добавлено:
После было решено опробовать gcj 4.4.5:
$  gcj --version
gcj (Gentoo 4.4.5 p1.0, pie-0.4.5) 4.4.5
$ gcj --main=StringPoolTest StringPoolTest.java -o StringPoolTest && ./StringPoolTest 

результат стабильный на всём рассматриваемом отрезке и составляет ~0.13us.

По скольку на руках есть исходный код OpenJDK 1.6.0.22 не составило труда изменить размер пула строк
openjdk/hotspot/src/share/vm/classfile/symbolTable.hpp:
  // Table size
enum {
string_table_size = 20011
};


И выполнить опять тот же тест
100: 0.145 us.
1000: 0.153 us.
10000: 0.154 us.
20000: 0.154 us.
25000: 0.153 us.
100000: 0.155 us.
500000: 0.197 us.
1000000: 0.238 us.


Т.о. было найдено верное место в исходном коде jvm и результат изменений практически устранил деградации поиска строки в пуле.

Комментариев нет: