[prev in list] [next in list] [prev in thread] [next in thread]
List: logback-user
Subject: Re: [logback-user] Logback Lock causing the app to lock up
From: Greg Nitro <gregnitro225 () gmail ! com>
Date: 2016-04-13 17:57:49
Message-ID: CAMMuz2zO=eWrQWqR=Ud2=qqzAbqQngQubzXvHv-GFUXkGin=MQ () mail ! gmail ! com
[Download RAW message or body]
[Attachment #2 (multipart/alternative)]
To follow up for others' sake who may be experiencing:
We've added an async appender around the stdout appender. We found some
issue with the docker containers hosting the apps with the issue I reported
where Heka (which forwards logs from STDOUT to our logging aggregators) was
queueing up and not flushing
So we are investigating that issue further but it's clearly not a problem
with Logback itself.. or at least as far as I can tell.
-greg
On Mon, Apr 11, 2016 at 2:56 PM, Greg Nitro <gregnitro225@gmail.com> wrote:
> Hi Ceki,
>
> Thanks for the quick response. Attached is the xml file with the
> configuration.
>
> -greg
>
>
>
> On Mon, Apr 11, 2016 at 12:48 PM, Ceki Gulcu <ceki@qos.ch> wrote:
>
>>
>> Can you please post your configuration file as well?
>>
>>
>> On 4/11/2016 19:59, Greg Nitro wrote:
>>
>>> Hi,
>>>
>>> We are using Logback 1.1.3, and observed through jstack that quite a few
>>> threads were blocked in OutputStreamAppender.subAppend waiting to obtain
>>> the lock.
>>>
>>> This is a Play Framework app running in a dockerized environment,
>>> configured to log to STDOUT and papertrail.
>>>
>>> Stack trace:
>>>
>>> "New I/O worker #23" #75 prio=5 os_prio=0 tid=0x00007f6fc9764000
>>> nid=0xaa waiting for monitor entry [0x00007f6edd3e7000]
>>> java.lang.Thread.State: BLOCKED (on object monitor)
>>> at
>>>
>>> ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:211)
>>> - waiting to lock <0x00000000ab0f8f50> (a
>>> ch.qos.logback.core.spi.LogbackLock)
>>> at
>>>
>>> ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103)
>>> at
>>>
>>> ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)
>>> at
>>>
>>> ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)
>>> at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:273)
>>> at ch.qos.logback.classic.Logger.callAppenders(Logger.java:260)
>>> at
>>> ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:442)
>>> at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)
>>> at ch.qos.logback.classic.Logger.info
>>> <http://ch.qos.logback.classic.Logger.info>(Logger.java:600)
>>> at play.api.LoggerLike$class.info <http://class.info>(Logger.scala:93)
>>> at play.api.Logger$.info(Logger.scala:167)
>>>
>>> Any suggestions on what may be going on here?
>>>
>>> Thanks
>>> -greg
>>>
>>>
>>> _______________________________________________
>>> logback-user mailing list
>>> logback-user@qos.ch
>>> http://mailman.qos.ch/mailman/listinfo/logback-user
>>>
>>> _______________________________________________
>> logback-user mailing list
>> logback-user@qos.ch
>> http://mailman.qos.ch/mailman/listinfo/logback-user
>
>
>
[Attachment #5 (text/html)]
<div dir="ltr">To follow up for others' sake who may be \
experiencing:<div><br></div><div>We've added an async appender around the stdout \
appender. We found some issue with the docker containers hosting the apps with the \
issue I reported where Heka (which forwards logs from STDOUT to our logging \
aggregators) was queueing up and not flushing</div><div><br></div><div>So we are \
investigating that issue further but it's clearly not a problem with Logback \
itself.. or at least as far as I can \
tell.</div><div><br></div><div>-greg</div></div><div class="gmail_extra"><br><div \
class="gmail_quote">On Mon, Apr 11, 2016 at 2:56 PM, Greg Nitro <span \
dir="ltr"><<a href="mailto:gregnitro225@gmail.com" \
target="_blank">gregnitro225@gmail.com</a>></span> wrote:<br><blockquote \
class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc \
solid;padding-left:1ex"><div dir="ltr">Hi Ceki,<div><br></div><div>Thanks for the \
quick response. Attached is the xml file with the configuration.</div><span \
class="HOEnZb"><font \
color="#888888"><div><br></div><div>-greg</div><div><br></div><div><br></div></font></span></div><div \
class="HOEnZb"><div class="h5"><div class="gmail_extra"><br><div \
class="gmail_quote">On Mon, Apr 11, 2016 at 12:48 PM, Ceki Gulcu <span \
dir="ltr"><<a href="mailto:ceki@qos.ch" target="_blank">ceki@qos.ch</a>></span> \
wrote:<br><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px \
#ccc solid;padding-left:1ex"><br> Can you please post your configuration file as \
well?<div><div><br> <br>
On 4/11/2016 19:59, Greg Nitro wrote:<br>
</div></div><blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px \
#ccc solid;padding-left:1ex"><div><div> Hi,<br>
<br>
We are using Logback 1.1.3, and observed through jstack that quite a few<br>
threads were blocked in OutputStreamAppender.subAppend waiting to obtain<br>
the lock.<br>
<br>
This is a Play Framework app running in a dockerized environment,<br>
configured to log to STDOUT and papertrail.<br>
<br>
Stack trace:<br>
<br>
"New I/O worker #23" #75 prio=5 os_prio=0 tid=0x00007f6fc9764000<br>
nid=0xaa waiting for monitor entry [0x00007f6edd3e7000]<br>
java.lang.Thread.State: BLOCKED (on object monitor)<br>
at<br>
ch.qos.logback.core.OutputStreamAppender.subAppend(OutputStreamAppender.java:211)<br>
- waiting to lock <0x00000000ab0f8f50> (a<br>
ch.qos.logback.core.spi.LogbackLock)<br>
at<br>
ch.qos.logback.core.OutputStreamAppender.append(OutputStreamAppender.java:103)<br>
at<br>
ch.qos.logback.core.UnsynchronizedAppenderBase.doAppend(UnsynchronizedAppenderBase.java:88)<br>
at<br>
ch.qos.logback.core.spi.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:48)<br>
at ch.qos.logback.classic.Logger.appendLoopOnAppenders(Logger.java:273)<br>
at ch.qos.logback.classic.Logger.callAppenders(Logger.java:260)<br>
at ch.qos.logback.classic.Logger.buildLoggingEventAndAppend(Logger.java:442)<br>
at ch.qos.logback.classic.Logger.filterAndLog_0_Or3Plus(Logger.java:396)<br>
at <a href="http://ch.qos.logback.classic.Logger.info" rel="noreferrer" \
target="_blank">ch.qos.logback.classic.Logger.info</a><br></div></div> <<a \
href="http://ch.qos.logback.classic.Logger.info" rel="noreferrer" \
target="_blank">http://ch.qos.logback.classic.Logger.info</a>>(Logger.java:600)<br>
at play.api.LoggerLike$<a href="http://class.info" rel="noreferrer" \
target="_blank">class.info</a> <<a href="http://class.info" rel="noreferrer" \
target="_blank">http://class.info</a>>(Logger.scala:93)<span><br> at \
play.api.Logger$.info(Logger.scala:167)<br> <br>
Any suggestions on what may be going on here?<br>
<br>
Thanks<br>
-greg<br>
<br>
<br></span>
_______________________________________________<br>
logback-user mailing list<br>
<a href="mailto:logback-user@qos.ch" target="_blank">logback-user@qos.ch</a><br>
<a href="http://mailman.qos.ch/mailman/listinfo/logback-user" rel="noreferrer" \
target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a><br> <br>
</blockquote>
_______________________________________________<br>
logback-user mailing list<br>
<a href="mailto:logback-user@qos.ch" target="_blank">logback-user@qos.ch</a><br>
<a href="http://mailman.qos.ch/mailman/listinfo/logback-user" rel="noreferrer" \
target="_blank">http://mailman.qos.ch/mailman/listinfo/logback-user</a></blockquote></div><br></div>
</div></div></blockquote></div><br></div>
[Attachment #6 (text/plain)]
_______________________________________________
logback-user mailing list
logback-user@qos.ch
http://mailman.qos.ch/mailman/listinfo/logback-user
[prev in list] [next in list] [prev in thread] [next in thread]
Configure |
About |
News |
Add a list |
Sponsored by KoreLogic