[ http://jira.qos.ch/browse/LBCLASSIC-137?page=com.atlassian.jira.plugin.syste... ] Ceki Gulcu moved LBCORE-63 to LBCLASSIC-137: -------------------------------------------- Project: logback-classic (was: logback-core) Key: LBCLASSIC-137 (was: LBCORE-63)

Deadlock when running on multiple core processors -------------------------------------------------

Key: LBCLASSIC-137 URL: http://jira.qos.ch/browse/LBCLASSIC-137 Project: logback-classic Issue Type: Sub-task Affects Versions: 0.9.9 Environment: Operating System: Windows Platform: PC Reporter: Toni Heimala Assignee: Ceki Gulcu Priority: Blocker Attachments: AppenderBaseLock.patch, patch.txt, patch2.txt, patch3.txt

When you run logging into same file from many threads on a system that has more than one physical processor (Dual Core for example), a deadlock will occur after a while. This can not be reproduced on HyperThreading processors. Here's an example program that will demonstrate the behavior: ----------------------------- Main.java ----------------------------- 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; public class Main extends Thread { private final static String LOGGER_CONFIGURATION_FILE = "logger.xml"; private final Logger logger = LoggerFactory.getLogger(Main.class);

private final long start;

public Main() throws JoranException { start = new Date().getTime(); LoggerContext lc = (LoggerContext)LoggerFactory.getILoggerFactory(); JoranConfigurator configurator = new JoranConfigurator(); lc.shutdownAndReset(); configurator.setContext(lc); configurator.doConfigure(LOGGER_CONFIGURATION_FILE); }

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 { Main main = new Main(); main.start(); } catch (JoranException e) { System.out.println("Failed to load application: " + e.getMessage()); } } } ------------------------------- Task.java ------------------------------- import java.util.Date; import org.slf4j.Logger; import org.slf4j.LoggerFactory; public class Task implements Runnable { private final Logger logger = LoggerFactory.getLogger(Task.class); private final Logger logger_main = LoggerFactory.getLogger(Main.class); private final String name; private final long start;

public Task(final String name) { this.name = name; start = new Date().getTime(); } public void run() { logger.debug("[{}] {}", name, new Date().getTime() - start); logger_main.debug("[MAIN] - [{}] {}", name, new Date().getTime() - start); } }

-- This message is automatically generated by JIRA. - If you think it was sent incorrectly contact one of the administrators: http://jira.qos.ch/secure/Administrators.jspa - For more information on JIRA, see: http://www.atlassian.com/software/jira