MySQLIntegrityConstraintViolationException with shared JDBC connection and Eviction with multithreaded app
Hi,
I'm creating a performance test to evaluate Infinispan, but I receive the following exceptions during heavy load:
13/07/25 16:51:12 ERROR stringbased.JdbcStringBasedCacheStore: ISPN008024: Error while storing string key to database; key: '1004577', buffer size of value: 35 bytes com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1004577' for key 'PRIMARY' at sun.reflect.GeneratedConstructorAccessor75.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:525) at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) at com.mysql.jdbc.Util.getInstance(Util.java:386) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1041) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4187) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4119) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2815) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2458) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359) at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105) at org.infinispan.loaders.jdbc.stringbased.JdbcStringBasedCacheStore.storeLockSafe(JdbcStringBasedCacheStore.java:250) at org.infinispan.loaders.jdbc.stringbased.JdbcStringBasedCacheStore.storeLockSafe(JdbcStringBasedCacheStore.java:87) at org.infinispan.loaders.LockSupportCacheStore.store(LockSupportCacheStore.java:213) at org.infinispan.eviction.PassivationManagerImpl.passivate(PassivationManagerImpl.java:98) at org.infinispan.container.DefaultDataContainer$DefaultEvictionListener.onEntryChosenForEviction(DefaultDataContainer.java:254) at org.infinispan.container.DefaultDataContainer$DefaultEvictionListener.onEntryChosenForEviction(DefaultDataContainer.java:245) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$Segment.remove(BoundedConcurrentHashMap.java:1719) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$LRU.removeEldestEntry(BoundedConcurrentHashMap.java:555) at java.util.LinkedHashMap.addEntry(LinkedHashMap.java:431) at java.util.HashMap.put(HashMap.java:484) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$LRU.onEntryMiss(BoundedConcurrentHashMap.java:496) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$Segment.put(BoundedConcurrentHashMap.java:1613) at org.infinispan.util.concurrent.BoundedConcurrentHashMap.put(BoundedConcurrentHashMap.java:2211) at org.infinispan.container.DefaultDataContainer.put(DefaultDataContainer.java:185) at org.infinispan.container.entries.ReadCommittedEntry.commit(ReadCommittedEntry.java:183) at org.infinispan.interceptors.locking.ClusteringDependentLogic$InvalidationLogic.commitEntry(ClusteringDependentLogic.java:283) at org.infinispan.interceptors.locking.ClusteringDependentLogic$ReplicationLogic.commitEntry(ClusteringDependentLogic.java:348) at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntry(EntryWrappingInterceptor.java:286) at org.infinispan.interceptors.EntryWrappingInterceptor.commitEntryIfNeeded(EntryWrappingInterceptor.java:422) at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntries(EntryWrappingInterceptor.java:272) at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:292) at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:157) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:68) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216) at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194) at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:160) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:122) at org.infinispan.remoting.InboundInvocationHandlerImpl.access$000(InboundInvocationHandlerImpl.java:68) at org.infinispan.remoting.InboundInvocationHandlerImpl$2.run(InboundInvocationHandlerImpl.java:194) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) 13/07/25 16:51:12 WARN eviction.PassivationManagerImpl: ISPN000028: Unable to passivate entry under 1004574 org.infinispan.loaders.CacheLoaderException: Error while storing string key to database; key: '1004574', buffer size of value: 35 bytes at org.infinispan.loaders.jdbc.stringbased.JdbcStringBasedCacheStore.storeLockSafe(JdbcStringBasedCacheStore.java:253) at org.infinispan.loaders.jdbc.stringbased.JdbcStringBasedCacheStore.storeLockSafe(JdbcStringBasedCacheStore.java:87) at org.infinispan.loaders.LockSupportCacheStore.store(LockSupportCacheStore.java:213) at org.infinispan.eviction.PassivationManagerImpl.passivate(PassivationManagerImpl.java:98) at org.infinispan.container.DefaultDataContainer$DefaultEvictionListener.onEntryChosenForEviction(DefaultDataContainer.java:254) at org.infinispan.container.DefaultDataContainer$DefaultEvictionListener.onEntryChosenForEviction(DefaultDataContainer.java:245) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$Segment.remove(BoundedConcurrentHashMap.java:1719) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$LRU.removeEldestEntry(BoundedConcurrentHashMap.java:555) at java.util.LinkedHashMap.addEntry(LinkedHashMap.java:431) at java.util.HashMap.put(HashMap.java:484) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$LRU.onEntryMiss(BoundedConcurrentHashMap.java:496) at org.infinispan.util.concurrent.BoundedConcurrentHashMap$Segment.put(BoundedConcurrentHashMap.java:1613) at org.infinispan.util.concurrent.BoundedConcurrentHashMap.put(BoundedConcurrentHashMap.java:2211) at org.infinispan.container.DefaultDataContainer.put(DefaultDataContainer.java:185) at org.infinispan.container.entries.ReadCommittedEntry.commit(ReadCommittedEntry.java:183) at org.infinispan.interceptors.locking.ClusteringDependentLogic$InvalidationLogic.commitEntry(ClusteringDependentLogic.java:283) at org.infinispan.interceptors.locking.ClusteringDependentLogic$ReplicationLogic.commitEntry(ClusteringDependentLogic.java:348) at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntry(EntryWrappingInterceptor.java:286) at org.infinispan.interceptors.EntryWrappingInterceptor.commitEntryIfNeeded(EntryWrappingInterceptor.java:422) at org.infinispan.interceptors.EntryWrappingInterceptor.commitContextEntries(EntryWrappingInterceptor.java:272) at org.infinispan.interceptors.EntryWrappingInterceptor.invokeNextAndApplyChanges(EntryWrappingInterceptor.java:292) at org.infinispan.interceptors.EntryWrappingInterceptor.visitPutKeyValueCommand(EntryWrappingInterceptor.java:157) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.locking.AbstractLockingInterceptor.visitPutKeyValueCommand(AbstractLockingInterceptor.java:68) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.base.CommandInterceptor.handleDefault(CommandInterceptor.java:134) at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.statetransfer.StateTransferInterceptor.handleTopologyAffectedCommand(StateTransferInterceptor.java:216) at org.infinispan.statetransfer.StateTransferInterceptor.handleWriteCommand(StateTransferInterceptor.java:194) at org.infinispan.statetransfer.StateTransferInterceptor.visitPutKeyValueCommand(StateTransferInterceptor.java:136) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.CacheMgmtInterceptor.visitPutKeyValueCommand(CacheMgmtInterceptor.java:160) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.base.CommandInterceptor.invokeNextInterceptor(CommandInterceptor.java:120) at org.infinispan.interceptors.InvocationContextInterceptor.handleAll(InvocationContextInterceptor.java:128) at org.infinispan.interceptors.InvocationContextInterceptor.handleDefault(InvocationContextInterceptor.java:92) at org.infinispan.commands.AbstractVisitor.visitPutKeyValueCommand(AbstractVisitor.java:54) at org.infinispan.commands.write.PutKeyValueCommand.acceptVisitor(PutKeyValueCommand.java:83) at org.infinispan.interceptors.InterceptorChain.invoke(InterceptorChain.java:343) at org.infinispan.commands.remote.BaseRpcInvokingCommand.processVisitableCommand(BaseRpcInvokingCommand.java:61) at org.infinispan.commands.remote.SingleRpcCommand.perform(SingleRpcCommand.java:70) at org.infinispan.remoting.InboundInvocationHandlerImpl.handleInternal(InboundInvocationHandlerImpl.java:122) at org.infinispan.remoting.InboundInvocationHandlerImpl.access$000(InboundInvocationHandlerImpl.java:68) at org.infinispan.remoting.InboundInvocationHandlerImpl$2.run(InboundInvocationHandlerImpl.java:194) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:722) Caused by: com.mysql.jdbc.exceptions.jdbc4.MySQLIntegrityConstraintViolationException: Duplicate entry '1004574' for key 'PRIMARY' at sun.reflect.GeneratedConstructorAccessor75.newInstance(Unknown Source) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:525) at com.mysql.jdbc.Util.handleNewInstance(Util.java:411) at com.mysql.jdbc.Util.getInstance(Util.java:386) at com.mysql.jdbc.SQLError.createSQLException(SQLError.java:1041) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4187) at com.mysql.jdbc.MysqlIO.checkErrorPacket(MysqlIO.java:4119) at com.mysql.jdbc.MysqlIO.sendCommand(MysqlIO.java:2570) at com.mysql.jdbc.MysqlIO.sqlQueryDirect(MysqlIO.java:2731) at com.mysql.jdbc.ConnectionImpl.execSQL(ConnectionImpl.java:2815) at com.mysql.jdbc.PreparedStatement.executeInternal(PreparedStatement.java:2155) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2458) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2375) at com.mysql.jdbc.PreparedStatement.executeUpdate(PreparedStatement.java:2359) at com.mchange.v2.c3p0.impl.NewProxyPreparedStatement.executeUpdate(NewProxyPreparedStatement.java:105) at org.infinispan.loaders.jdbc.stringbased.JdbcStringBasedCacheStore.storeLockSafe(JdbcStringBasedCacheStore.java:250) ... 55 more
Config:
<global> <globalJmxStatistics enabled="true" allowDuplicateDomains="true"/> <transport nodeName="Infinispan-Node1" clusterName="infinispan-cluster"> </transport> </global> <namedCache name="shared"> <clustering mode="replication"/> <eviction maxEntries="100" strategy="LRU"/> <loaders passivation="true" shared="true" preload="false"> <loader class="org.infinispan.loaders.jdbc.stringbased.JdbcStringBasedCacheStore" fetchPersistentState="true" ignoreModifications="false" purgeOnStartup="false"> <properties> <property name="stringsTableNamePrefix" value="ISPN_STRING_TABLE"/> <property name="idColumnName" value="ID_COLUMN"/> <property name="idColumnType" value="VARCHAR(255)"/> <property name="dataColumnName" value="DATA_COLUMN"/> <property name="dataColumnType" value="BLOB"/> <property name="timestampColumnName" value="TIMESTAMP_COLUMN"/> <property name="timestampColumnType" value="BIGINT"/> <property name="connectionFactoryClass" value="org.infinispan.loaders.jdbc.connectionfactory.PooledConnectionFactory"/> <property name="connectionUrl" value="jdbc:mysql://localhost/presence"/> <property name="userName" value="root"/> <property name="password" value="R"/> <property name="driverClass" value="com.mysql.jdbc.Driver"/> <property name="dropTableOnExit" value="true"/> <property name="createTableOnStart" value="true"/> </properties> </loader> </loaders> </namedCache>
The test creates 10 threads (with dedicated CacheManager) and issues concurrent writes to different key-regions.
Simplified Test code:
for (int i = 0; i < CLUSTER_SIZE; i++) {
final Cache<String, List<String>> e = newInfinispan();
_caches.add(e);
}
...
runWriterTest(writersFinished); // create writer threads
...
private void runWriterTest(final CountDownLatch writersFinished) {
for (int threadId = 1; threadId <= WRITE_THREAD_NUM; threadId++) {
final int id = threadId;
Runnable r = new Runnable() {
@Override
public void run() {
final Cache<String, List<String>> cache = _caches.get(id - 1);
int startIndex = ...
int endIndex = ...
for (int idx = startIndex; idx < endIndex; idx++) {
storeMap(cache, idx);
}
}
private void storeMap(final Cache<String, List<String>> map, final int idx) {
map.put("" + idx, new ArrayList<>(Arrays.asList("Value-1", "Value-2", "Value-3")));
}
};
new Thread(r).start();
}
}
private synchronized Cache<String, List<String>> newInfinispan() {
final DefaultCacheManager cacheManager = new DefaultCacheManager("config.xml");
final Cache<String, List<String>> cache = cacheManager.getCache("shared");
return cache;
}
It seems Infinispan tries to save the same entry from multiple threads. When I turn-off passivation it works, but that's unacceptably slow.
What I'd like to achive is to have a MySQL backed distributed key-value store that is read most of the time but need to handle infrequent bulk stores (==500 000 items) w/o blocking and within 2 minutes.
I'm running on:
- Core i7 8core
- 8 GB RAM
- Ubuntu 10.10
- Java 7
- Infinispan v5.3.0
- MySQL 5.1.62-0ubuntu0.10.04.1
Thanks for any comments.