[ http://jira.qos.ch/browse/LBCLASSIC-35?page=com.atlassian.jira.plugin.system... ] Ralph Goers edited comment on LBCLASSIC-35 at 10/13/08 12:26 AM: ----------------------------------------------------------------- This bug needs to be fixed as does the bug in AppenderBase. I have a patch that fixes this issue but I don't seem to have permission to attach it to this issue. FWIW, in some cases slow appenders wouldn't be as much of a problem if it weren't for these synchronization points. I have a custom appender that is slow, but is thread safe so many of them can be run in parallel. With these two synchronization points however, Logback ends up showing up as a system wide bottleneck. was (Author: rgoers@apache.org): This bug needs to be fixed as does the bug in AppenderBase. I have attached the fix for this issue and will open a second issue for AppenderBase. FWIW, in some cases slow appenders wouldn't be as much of a problem if it weren't for these synchronization points. I have a custom appender that is slow, but is thread safe so many of them can be run in parallel. With these two synchronization points however, Logback ends up showing up as a system wide bottleneck.

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

Key: LBCLASSIC-35 URL: http://jira.qos.ch/browse/LBCLASSIC-35 Project: logback-classic Issue Type: Bug Components: Other Affects Versions: unspecified Environment: Operating System: Windows Platform: PC Reporter: Toni Heimala Assignee: Ceki Gulcu Priority: Blocker

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