Author: fdesbois Date: 2010-04-21 18:06:34 +0200 (Wed, 21 Apr 2010) New Revision: 407 Log: Stop execution after 1 hour (not nbExecutions which is not efficient). Locks method is added but not used anymore -> error #546 in ToPIA resolve issue on ConcurrentModificationException. Modified: testTopiaPostgresError/trunk/pom.xml testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/AbstractThread.java testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/ReadThread.java testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/WriteThread.java testTopiaPostgresError/trunk/src/main/resources/log4j.properties Modified: testTopiaPostgresError/trunk/pom.xml =================================================================== --- testTopiaPostgresError/trunk/pom.xml 2010-04-21 09:27:50 UTC (rev 406) +++ testTopiaPostgresError/trunk/pom.xml 2010-04-21 16:06:34 UTC (rev 407) @@ -141,7 +141,7 @@ <!-- libraries version --> <i18n.version>1.2.1</i18n.version> <nuitonutils.version>1.2.2</nuitonutils.version> - <topia.version>2.3.3-SNAPSHOT</topia.version> + <topia.version>2.4-SNAPSHOT</topia.version> </properties> <!-- ************************************************************* --> Modified: testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/AbstractThread.java =================================================================== --- testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/AbstractThread.java 2010-04-21 09:27:50 UTC (rev 406) +++ testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/AbstractThread.java 2010-04-21 16:06:34 UTC (rev 407) @@ -1,9 +1,10 @@ package org.nuiton.test.topia; +import java.util.ConcurrentModificationException; import java.util.TimerTask; -import java.util.logging.Level; import org.apache.commons.lang.time.DurationFormatUtils; +import org.nuiton.topia.TopiaContext; import org.nuiton.topia.TopiaException; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -31,18 +32,21 @@ protected String name; - protected int currentExecution; + protected int nbHours; - public int nbExecutions; +// protected int currentExecution; +// public int nbExecutions; + protected static long globalStart = System.currentTimeMillis(); protected static final Object lock = new Object(); protected static Boolean token = false; - public AbstractThread(int nbExecutions, String name) { + public AbstractThread(String name) { this.name = name; - this.nbExecutions = nbExecutions * 1000; + this.nbHours = 1; +// this.nbExecutions = nbExecutions * 1000; } @Override @@ -51,54 +55,40 @@ startTime = System.currentTimeMillis(); if (logger.isInfoEnabled()) { - logger.info("Start " + name + " for " + nbExecutions + - " executions after " + + logger.info("Start " + name + " for " + nbHours + " hour(s) after " + DurationFormatUtils.formatDurationHMS( startTime - globalStart)); } - for (currentExecution = 0; currentExecution < nbExecutions; - currentExecution ++) { + while(true) { if (!manager.isStopped()) { try { - synchronized (lock) { - // Do not stop waiting until token is free - while (token) { - if (logger.isDebugEnabled()) { - logger.debug(name + " waiting..."); - } - lock.wait(); - if (logger.isDebugEnabled()) { - logger.debug(name + " no longer waiting"); - } + // Execute + String message = execute(); + + // Check message to display it and may stop execution + // depends on current time + if (message != null) { + long duration = System.currentTimeMillis() - startTime; + if (logger.isInfoEnabled()) { + logger.info(name + " : " + message + " after " + + DurationFormatUtils.formatDurationHMS(duration)); } - // Take the token to lock other thread - if (logger.isDebugEnabled()) { - logger.debug(name + " take the token"); + + int hour = Integer.parseInt( + DurationFormatUtils.formatDuration(duration, "H")); + + if (hour == nbHours) { + break; } - token = true; } - if (logger.isDebugEnabled()) { - logger.debug(name + " execute..."); + + } catch (ConcurrentModificationException eee) { + if (logger.isErrorEnabled()) { + logger.error("Concurrent error", eee); } - // Execute - execute(); - synchronized (lock) { - if (logger.isDebugEnabled()) { - logger.debug(name + " release the token"); - } - // Release the token and notify other that the token - // is free - token = false; - lock.notifyAll(); - } - // Sleep to permit the unlocked Thread to have time to take - // the token - if (logger.isDebugEnabled()) { - logger.debug(name + " go to sleep a while"); - } - Thread.sleep(200); - + // Will stop the application + manager.stopTest(); } catch (InterruptedException eee) { if (logger.isErrorEnabled()) { logger.error("Interrupted during sleep or wait", eee); @@ -121,6 +111,47 @@ } } - protected abstract void execute() + public void lock() throws InterruptedException { + synchronized (lock) { + // Do not stop waiting until token is free + while (token) { + if (logger.isDebugEnabled()) { + logger.debug(name + " waiting..."); + } + lock.wait(); + if (logger.isDebugEnabled()) { + logger.debug(name + " no longer waiting"); + } + } + // Take the token to lock other thread + if (logger.isDebugEnabled()) { + logger.debug(name + " take the token"); + } + token = true; + } + } + + public void unlock() throws InterruptedException { + synchronized (lock) { + if (logger.isDebugEnabled()) { + logger.debug(name + " release the token"); + } + // Release the token and notify other that the token + // is free + token = false; + lock.notifyAll(); + } + } + + public void pause() throws InterruptedException { + // Pause the thread a while (not essential but avoid doing lots of + // actions in a few time) + if (logger.isDebugEnabled()) { + logger.debug(name + " go to sleep a while"); + } + Thread.sleep(200); + } + + protected abstract String execute() throws TopiaException, InterruptedException; } Modified: testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/ReadThread.java =================================================================== --- testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/ReadThread.java 2010-04-21 09:27:50 UTC (rev 406) +++ testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/ReadThread.java 2010-04-21 16:06:34 UTC (rev 407) @@ -26,14 +26,14 @@ protected int tic; public ReadThread() { - // 15 executions during approximatively 1 hour - super(15, ReadThread.class.getName()); + super(ReadThread.class.getName()); } @Override - protected synchronized void execute() + protected synchronized String execute() throws TopiaException, InterruptedException { TopiaContext transaction = null; + String message = null; try { transaction = manager.getRootContext().beginTransaction(); @@ -48,19 +48,15 @@ tic++; - if ((tic % 300 == 0) && logger.isInfoEnabled()) { - long stopTime = System.currentTimeMillis(); - long time = stopTime - startTime; - - logger.info(versions.size() + " values read after " + - DurationFormatUtils.formatDurationHMS(time) + - " (exec " + currentExecution + ")"); + if (tic % 300 == 0) { + message = versions.size() + " values read"; } } finally { if (transaction != null) { transaction.closeContext(); } } + return message; } } Modified: testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/WriteThread.java =================================================================== --- testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/WriteThread.java 2010-04-21 09:27:50 UTC (rev 406) +++ testTopiaPostgresError/trunk/src/main/java/org/nuiton/test/topia/WriteThread.java 2010-04-21 16:06:34 UTC (rev 407) @@ -29,8 +29,7 @@ protected int tic; public WriteThread() { - // 15 executions during approximatively 1 hour - super(15, WriteThread.class.getName()); + super(WriteThread.class.getName()); } /** @@ -39,12 +38,14 @@ * The field version is used to save the increment global (total number * of saved). * + * @return message each 300 executions * @throws TopiaException * @throws InterruptedException */ @Override - protected synchronized void execute() + protected synchronized String execute() throws TopiaException, InterruptedException { + String message = null; TopiaContext transaction = null; try { transaction = manager.getRootContext().beginTransaction(); @@ -76,6 +77,7 @@ dao.delete(exist); increment++; transaction.commitTransaction(); + pause(); } // UPDATE if alea is divided by 20 } else if (alea % 20 == 0) { @@ -98,10 +100,10 @@ exist.setVersion(String.valueOf(increment)); increment++; transaction.commitTransaction(); + pause(); } // CREATE if alea is divided by 10 } else if (alea % 10 == 0) { - TMSVersion create = dao.create(TMSVersion.VERSION, String.valueOf(increment)); @@ -109,26 +111,26 @@ logger.debug("create the " + increment + " entry id = " + create.getTopiaId()); } - increment ++; transaction.commitTransaction(); + pause(); + } else { + if (logger.isDebugEnabled()) { + logger.debug("do nothing"); + } } tic++; - if ((tic % 300 == 0) && logger.isInfoEnabled()) { - long stopTime = System.currentTimeMillis(); - long time = stopTime - startTime; - - logger.info(increment + " create/update or delete actions" + - " after " + DurationFormatUtils.formatDurationHMS(time) + - " (exec " + currentExecution + ")"); + if (tic % 300 == 0) { + message = increment + " create/update or delete actions"; } } finally { if (transaction != null) { transaction.closeContext(); } } + return message; } } Modified: testTopiaPostgresError/trunk/src/main/resources/log4j.properties =================================================================== --- testTopiaPostgresError/trunk/src/main/resources/log4j.properties 2010-04-21 09:27:50 UTC (rev 406) +++ testTopiaPostgresError/trunk/src/main/resources/log4j.properties 2010-04-21 16:06:34 UTC (rev 407) @@ -13,4 +13,6 @@ log4j.appender.file.Threshold=DEBUG log4j.appender.file.MaxBackupIndex=10 log4j.appender.file.layout=org.apache.log4j.PatternLayout -log4j.appender.file.layout.ConversionPattern=%d{dd MMM yyyy HH:mm:ss} %5p [%t] (%c:%L) %M - %m%n \ No newline at end of file +log4j.appender.file.layout.ConversionPattern=%d{dd MMM yyyy HH:mm:ss} %5p [%t] (%c:%L) %M - %m%n + +log4j.logger.org.nuiton.test.topia=DEBUG \ No newline at end of file