[logback-dev] [Bug 112] New: Deadlock when running on multiple core processors

[bugzilla-daemon at pixie.qos.ch]

http://bugzilla.qos.ch/show_bug.cgi?id=112

           Summary: Deadlock when running on multiple core processors
           Product: logback-classic
           Version: unspecified
          Platform: PC
        OS/Version: Windows
            Status: NEW
          Severity: blocker
          Priority: P1
         Component: Other
        AssignedTo: logback-dev at qos.ch
        ReportedBy: toni.heimala at imagesoft.fi


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);
    }
}


-- 
Configure bugmail: http://bugzilla.qos.ch/userprefs.cgi?tab=email
------- You are receiving this mail because: -------
You are the assignee for the bug, or are watching the assignee.