svn commit: r2272 - in logback/trunk: logback-classic/src/test/input/issue logback-classic/src/test/java/ch/qos/logback/classic/issue logback-core/src/test/java/ch/qos/logback/core/issue

Author: ceki Date: Tue Jun 9 15:36:00 2009 New Revision: 2272 Added: logback/trunk/logback-classic/src/test/input/issue/ logback/trunk/logback-classic/src/test/input/issue/lbcore63.xml logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/LBCORE63.java Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LBCORE97.java Log: Looking at LBCORE63 Added: logback/trunk/logback-classic/src/test/input/issue/lbcore63.xml ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/input/issue/lbcore63.xml Tue Jun 9 15:36:00 2009 @@ -0,0 +1,34 @@ +<?xml version="1.0" encoding="UTF-8" ?> + +<configuration> + + <appender name="STDOUT" class="ch.qos.logback.core.ConsoleAppender"> + <layout class="ch.qos.logback.classic.PatternLayout"> + <pattern>%d{HH:mm:ss.SSS} - %msg%n</pattern> + </layout> + </appender> + + <appender name="FILE-MAIN" + class="ch.qos.logback.core.rolling.RollingFileAppender"> + <file>logs/main.log</file> + <rollingPolicy + class="ch.qos.logback.core.rolling.FixedWindowRollingPolicy"> + <FileNamePattern>logs/main-%i.log</FileNamePattern> + <MinIndex>1</MinIndex> + <MaxIndex>3</MaxIndex> + </rollingPolicy> + <triggeringPolicy + class="ch.qos.logback.core.rolling.SizeBasedTriggeringPolicy"> + <MaxFileSize>500MB</MaxFileSize> + </triggeringPolicy> + <layout class="ch.qos.logback.classic.PatternLayout"> + <Pattern>%-25(%7r [%thread]) - %msg%n</Pattern> + </layout> + </appender> + + <root> + <appender-ref ref="FILE-MAIN" /> + <level value="DEBUG" /> + </root> + +</configuration> \ No newline at end of file Added: logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/LBCORE63.java ============================================================================== --- (empty file) +++ logback/trunk/logback-classic/src/test/java/ch/qos/logback/classic/issue/LBCORE63.java Tue Jun 9 15:36:00 2009 @@ -0,0 +1,87 @@ +package ch.qos.logback.classic.issue; + +import java.util.Date; +import java.util.concurrent.ScheduledThreadPoolExecutor; +import java.util.concurrent.TimeUnit; + +import org.slf4j.Logger; +import org.slf4j.LoggerFactory; + +import ch.qos.logback.classic.LoggerContext; +import ch.qos.logback.classic.joran.JoranConfigurator; +import ch.qos.logback.core.joran.spi.JoranException; +import ch.qos.logback.core.util.StatusPrinter; + +public class LBCORE63 extends Thread { + private final static String LOGGER_CONFIGURATION_FILE = "./src/test/input/issue/lbcore63.xml"; + private final Logger logger = LoggerFactory.getLogger(LBCORE63.class); + + private final long start; + + public LBCORE63() throws JoranException { + start = new Date().getTime(); + LoggerContext lc = (LoggerContext) LoggerFactory.getILoggerFactory(); + JoranConfigurator configurator = new JoranConfigurator(); + lc.reset(); + configurator.setContext(lc); + configurator.doConfigure(LOGGER_CONFIGURATION_FILE); + StatusPrinter.printInCaseOfErrorsOrWarnings(lc); + } + + public void start() { + ScheduledThreadPoolExecutor ex1 = new ScheduledThreadPoolExecutor(1); + ScheduledThreadPoolExecutor ex2 = new ScheduledThreadPoolExecutor(1); + ScheduledThreadPoolExecutor ex3 = new ScheduledThreadPoolExecutor(1); + ScheduledThreadPoolExecutor ex4 = new ScheduledThreadPoolExecutor(1); + ScheduledThreadPoolExecutor ex5 = new ScheduledThreadPoolExecutor(1); + ex1.scheduleAtFixedRate(new Task("EX1"), 10, 10, TimeUnit.MICROSECONDS); + ex2.scheduleAtFixedRate(new Task("EX2"), 10, 10, TimeUnit.MICROSECONDS); + ex3.scheduleAtFixedRate(new Task("EX3"), 10, 10, TimeUnit.MICROSECONDS); + ex4.scheduleAtFixedRate(new Task("EX4"), 10, 10, TimeUnit.MICROSECONDS); + ex5.scheduleAtFixedRate(new Task("EX5"), 10, 10, TimeUnit.MICROSECONDS); + + super.start(); + } + + public void run() { + try { + while (true) { + logger.debug("[MAIN] {}", new Date().getTime() - start); + Thread.sleep(10); + } + } catch (InterruptedException e) { + logger.info("[MAIN]: Interrupted: {}", e.getMessage()); + } + } + + public static void main(String[] args) { + try { + LBCORE63 main = new LBCORE63(); + main.start(); + } catch (JoranException e) { + System.out.println("Failed to load application: " + e.getMessage()); + } + } + + class Task implements Runnable { + private final Logger logger = LoggerFactory.getLogger(Task.class); + //private final Logger logger_main = LoggerFactory.getLogger(LBCORE63.class); + final String name; + private final long start; + + int counter = 0; + public long diff; + + public Task(final String name) { + this.name = name; + start = new Date().getTime(); + } + + public void run() { + counter++; + diff = new Date().getTime() - start; + logger.debug("counter={}", counter); + //logger_main.debug("[MAIN] - [{}] {}", name, new Date().getTime() - start); + } + } +} Modified: logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LBCORE97.java ============================================================================== --- logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LBCORE97.java (original) +++ logback/trunk/logback-core/src/test/java/ch/qos/logback/core/issue/LBCORE97.java Tue Jun 9 15:36:00 2009 @@ -1,6 +1,7 @@ package ch.qos.logback.core.issue; -import java.util.concurrent.locks.*; +import java.util.concurrent.locks.Lock; +import java.util.concurrent.locks.ReentrantLock; /** * Example code illustrating locking policies in the JDK. @@ -13,6 +14,7 @@ static int THREAD_COUNT = 10; public static void main(String args[]) throws InterruptedException { + System.out.println("Environment:"); System.out.println("java.runtime.name = " + System.getProperty("java.runtime.name"));

It's essentially the same situation as in my SynchronizedVs... app. It's just that the appender is the point of starvation in that case, not some Object.

Running LBCORE63 located in the ch.qos.logback.classic.issue package with JDK 1.6 seems to work nicely, at least so far according to tests performed on Windows and Linux. I can't see no starvation. Joern Huxhorn wrote:
It's essentially the same situation as in my SynchronizedVs... app. It's just that the appender is the point of starvation in that case, not some Object.
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch

In [1], the fact that threads are executed unevenly is just a corollary of the "no assumption about the scheduler" principle. It does not mean that threads are starved. Looking at the way each task advances when LBCORE63 application is run, I could not detect signs of starvation. [1] http://jira.qos.ch/browse/LBCORE-96?focusedCommentId=11116#action_11116 Ceki Gulcu wrote:
Running LBCORE63 located in the ch.qos.logback.classic.issue package with JDK 1.6 seems to work nicely, at least so far according to tests performed on Windows and Linux. I can't see no starvation.
Joern Huxhorn wrote:
It's essentially the same situation as in my SynchronizedVs... app. It's just that the appender is the point of starvation in that case, not some Object.
-- Ceki Gülcü Logback: The reliable, generic, fast and flexible logging framework for Java. http://logback.qos.ch
participants (3)
-
Ceki Gulcu
-
Joern Huxhorn
-
noreply.ceki@qos.ch