[
http://jira.qos.ch/browse/LBCORE-63?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=10900#action_10900
]
Paweł Paprota commented on LBCORE-63:
-------------------------------------
What is the current status of this issue? I think I got hit by this one, at
least that's what I'm seeing right now in Eclipse when I suspend all threads in
my application - one thread has callAppenders in its stack trace and it hanged
(yesterday) on socketWrite. Some of the other threads seem to be waiting on a
lock in callAppenders. As a result, I don't see any more logging appended to my
log file and the console.
I'm using logback-core/classic 0.9.9 with slf4j 1.5.3.
Did the Ralph's patch make it to any of the newer logback releases? I was not
able to find any change log or release announcement for releases newer than
0.9.9...
I would really appreciate some feedback, thank you.
Below is the stack trace of the "offending" thread (only relevant calls
included):
Thread [Thread-12] (Suspended)
SocketOutputStream.socketWrite0(FileDescriptor, byte[], int, int) line:
not available [native method]
SocketOutputStream.socketWrite(byte[], int, int) line: 92
SocketOutputStream.write(byte[], int, int) line: 136
ObjectOutputStream$BlockDataOutputStream.drain() line: 1685
ObjectOutputStream$BlockDataOutputStream.write(byte[], int, int,
boolean) line: 1649
ObjectOutputStream.defaultWriteFields(Object, ObjectStreamClass) line:
1368
ObjectOutputStream.writeSerialData(Object, ObjectStreamClass) line:
1347
ObjectOutputStream.writeOrdinaryObject(Object, ObjectStreamClass,
boolean) line: 1290
ObjectOutputStream.writeObject0(Object, boolean) line: 1079
ObjectOutputStream.writeArray(Object, ObjectStreamClass, boolean) line:
1251
ObjectOutputStream.writeObject0(Object, boolean) line: 1075
ObjectOutputStream.defaultWriteFields(Object, ObjectStreamClass) line:
1375
ObjectOutputStream.defaultWriteObject() line: 391
LoggingEvent.writeObject(ObjectOutputStream) line: 288
GeneratedMethodAccessor1118.invoke(Object, Object[]) line: not
available
DelegatingMethodAccessorImpl.invoke(Object, Object[]) line: 25
Method.invoke(Object, Object...) line: 585
ObjectStreamClass.invokeWriteObject(Object, ObjectOutputStream) line:
917
ObjectOutputStream.writeSerialData(Object, ObjectStreamClass) line:
1339
ObjectOutputStream.writeOrdinaryObject(Object, ObjectStreamClass,
boolean) line: 1290
ObjectOutputStream.writeObject0(Object, boolean) line: 1079
ObjectOutputStream.writeObject(Object) line: 302
SocketAppender(SocketAppenderBase<E>).append(E) line: 163
SocketAppender(AppenderBase<E>).doAppend(E) line: 81
AppenderAttachableImpl<E>.appendLoopOnAppenders(E) line: 51
Logger.appendLoopOnAppenders(LoggingEvent) line: 282
Logger.callAppenders(LoggingEvent) line: 266
Logger.buildLoggingEventAndAppend(String, Marker, Level, String,
Object[], Throwable) line: 487
Logger.filterAndLog(String, Marker, Level, String, Object, Object,
Throwable) line: 460
Logger.debug(String, Object, Object) line: 406
And those are the ones being blocked:
Thread [Thread-4] (Suspended)
Logger.callAppenders(LoggingEvent) line: 265
Logger.buildLoggingEventAndAppend(String, Marker, Level, String,
Object[], Throwable) line: 487
Logger.filterAndLog(String, Marker, Level, String, Object[], Throwable)
line: 479
Logger.debug(String, Throwable) line: 414
Daemon Thread [ActiveMQ Connection Worker: tcp://localhost/127.0.0.1:61616]
(Suspended)
Logger.callAppenders(LoggingEvent) line: 265
Logger.buildLoggingEventAndAppend(String, Marker, Level, String,
Object[], Throwable) line: 487
Logger.filterAndLog(String, Marker, Level, String, Object[], Throwable)
line: 479
Logger.log(Marker, String, int, String, Throwable) line: 818
SLF4JLocationAwareLog.info(Object, Throwable) line: 152
AdvisoryConsumer.dispose() line: 58
ActiveMQConnection.close() line: 563
CachingConnectionFactory(SingleConnectionFactory).closeConnection(Connection)
line: 364
CachingConnectionFactory(SingleConnectionFactory).resetConnection()
line: 302
CachingConnectionFactory.resetConnection() line: 120
CachingConnectionFactory(SingleConnectionFactory).onException(JMSException)
line: 283
SingleConnectionFactory$InternalChainedExceptionListener(ChainedExceptionListener).onException(JMSException)
line: 60
ActiveMQConnection$3.run() line: 1690
ThreadPoolExecutor$Worker.runTask(Runnable) line: 650
ThreadPoolExecutor$Worker.run() line: 675
Thread.run() line: 595
> Deadlock when running on multiple core processors
> -------------------------------------------------
>
> Key: LBCORE-63
> URL: http://jira.qos.ch/browse/LBCORE-63
> Project: logback-core
> Issue Type: Sub-task
> Affects Versions: 0.9.9
> Environment: Operating System: Windows
> Platform: PC
> Reporter: Toni Heimala
> Assignee: Ceki Gulcu
> Priority: Blocker
> Attachments: 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
_______________________________________________
logback-dev mailing list
[email protected]
http://qos.ch/mailman/listinfo/logback-dev
