Re: [Resin-interest] Problems with rollover of logfile with log4j 1.2.16 and AsyncAppender
Bump? :)
Regards,
Jens Dueholm Christensen
Rambøll Survey IT
-Original Message-
From: resin-interest-boun...@caucho.com
[mailto:resin-interest-boun...@caucho.com] On Behalf Of Jens Dueholm
Christensen (JEDC)
Sent: Tuesday, February 21, 2012 9:01 PM
To: General Discussion for the Resin application server
Subject: Re: [Resin-interest] Problems with rollover of logfile with log4j
1.2.16 and AsyncAppender
Hi Scott
I'd really appreciate it, if you took the time to do that - I (and my
coworkers) really quite baffled.
We have had an increase of activity and load on the system during the last few
weeks (more users and utilization, so nothing alarming), and now this problem
has manifested itself, and I've never seen it before.
My understanding of what's happening is that the blocking thread is waiting for
an empty buffer so it can flush it's own full buffer, but that notification
never comes.
As the source for log4j shows the thread has called wait() on an ArrayList (the
full buffer), and something has gone wrong, but what?
We've seen it happen 3 or 4 times during the last week - always a few minutes
after midnight when Resin performs its logrotation.
In the stacktrace most of the threads that waits for the deadlocked thread is
just (as is the deadlocked thread) doing a simple logger.info(String), so it
might be possible to reproduce by spawning 10-20 threads that calls
logger.info() and then have Resin perform a rollover once a minute.
Regards,
Jens Dueholm Christensen
Rambøll Survey IT
From: resin-interest-boun...@caucho.com [resin-interest-boun...@caucho.com] On
Behalf Of Scott Ferguson [f...@cauchomail.com]
Sent: 21 February 2012 19:01
To: resin-interest@caucho.com
Subject: Re: [Resin-interest] Problems with rollover of logfile with log4j
1.2.16 and AsyncAppender
On 02/20/2012 12:56 PM, Jens Dueholm Christensen (JEDC) wrote:
Hi
Lately we are seeing increased blocking behaviour from log4j when Resin
performs the nightly rollover of logfiles.
We're running Resin Pro 3.1 (license #1013826) in a pre .11 snapshot
(resin-pro-3.1.s110225) (due to bug #4349 and a bit of waiting before 3.1.11
was released).
Updating to 3.1.12 is planned, but the changelog
(http://www.caucho.com/resin-3.1/changes/changes.xtp is the best I could find?)
does not mention any fix for our current problem, so I'm looking for any
insights or advise.
I'd need to look at the log4j code to understand what it's doing.
I don't think that wait() should be related to Resin (other than timing) but
I'd need to look at their code to be certain, and I can't think of any logging
that would help. (Logging the logging code is tricky :)
3.1.13 should be out next week, by the way.
-- Scott
We've configured resin to perform rollovers of this logfile:
stdout-log path=/usr/local/www/xact/logs/resin-web-stdout.log
timestamp=[%Y-%m-%d %H:%M:%S.%s] rollover-period=1D/
In our log4j configuration we log to stdout with:
appender name=CONSOLE class=org.apache.log4j.ConsoleAppender
param name=Target value=System.out/
layout class=org.apache.log4j.PatternLayout
param name=ConversionPattern value=%d{ISO8601} [%-20.20t] %5p
%c{1} - %m - %x%n/
/layout
/appender
appender name=ASYNC class=org.apache.log4j.AsyncAppender
appender-ref ref=CONSOLE/
/appender
root
priority value=warn/
appender-ref ref=ASYNC/
/root
loggers
Some time after midnight when Resin performs the rollover, the JVM becomes
unresponsive and a stacktrace shows multiple threads hanging, and we have to
manually restart (it doesn't get picked up by the watchdog, and can/will hang
for hours).
A complete JVM stacktrace is attached to this mail.
All threads that are attempting to log are waiting for access to the object
blocked by this thread:
http-172.27.80.36:8080-30$1663241944 daemon prio=10 tid=0x7f8804005800
nid=0x2a40 in Object.wait() [0x7f87a08ed000]
java.lang.Thread.State: WAITING (on object monitor)
at java.lang.Object.wait(Native Method)
at java.lang.Object.wait(Object.java:485)
at org.apache.log4j.AsyncAppender.append(AsyncAppender.java:195)
- locked 0x0005ba882928 (a java.util.ArrayList)
at
org.apache.log4j.AppenderSkeleton.doAppend(AppenderSkeleton.java:251)
- locked 0x0005b8d6db00 (a org.apache.log4j.AsyncAppender)
at
org.apache.log4j.helpers.AppenderAttachableImpl.appendLoopOnAppenders(AppenderAttachableImpl.java:66)
at org.apache.log4j.Category.callAppenders(Category.java:206)
- locked 0x0005ba6f9e38 (a org.apache.log4j.spi.RootLogger)
at org.apache.log4j.Category.forcedLog(Category.java:391)
at org.apache.log4j.Category.info(Category.java:666)
at
com.pls.popinhandler.PopinScriptHandler.handleRequest(PopinScriptHandler.java:65)
.
It seems like something
[Resin-interest] getting response header in load balancer access logs
Hi,
I'm having trouble getting the Set-Cookie response header into the access logs
on our load balancer. I've tested this exact same access-log configuration
locally with an instance of resin that is not behind any load balancer and it
seems to work, but this isn't working in our load balanced production
environment. It's currently just logging - at the end of the access log
line. Here's what our load balancer's configuration looks like:
access-log
path/var/log/resin/ariel/master-access.log/path
format
%{Host}i %h %l %u %t %r %s %b %{Referer}i %{User-Agent}i
%{X-Forwarded-For}i %{JSESSIONID}c %{ariel}c %{SSLB}c %D %{Cookie}i
%{Set-Cookie}o
/format
rollover-period1D/rollover-period
rollover-size-1/rollover-size
archive-formatmaster-access-%Y%m%d.log.gz/archive-format
/access-log
Any help is greatly appreciated.
Thanks,
Chris
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
Re: [Resin-interest] getting response header in load balancer access logs
Hi Chris,
I could't reproduce this on version 4.0.25. What version are you running?
Thanks,
Alex
On 2012-02-27, at 2:10 PM, Chris Hart wrote:
Hi,
I'm having trouble getting the Set-Cookie response header into the access
logs on our load balancer. I've tested this exact same access-log
configuration locally with an instance of resin that is not behind any load
balancer and it seems to work, but this isn't working in our load balanced
production environment. It's currently just logging - at the end of the
access log line. Here's what our load balancer's configuration looks like:
access-log
path/var/log/resin/ariel/master-access.log/path
format
%{Host}i %h %l %u %t %r %s %b %{Referer}i %{User-Agent}i
%{X-Forwarded-For}i %{JSESSIONID}c %{ariel}c %{SSLB}c %D %{Cookie}i
%{Set-Cookie}o
/format
rollover-period1D/rollover-period
rollover-size-1/rollover-size
archive-formatmaster-access-%Y%m%d.log.gz/archive-format
/access-log
Any help is greatly appreciated.
Thanks,
Chris
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
Re: [Resin-interest] getting response header in load balancer access logs
Hi Alex,
Thanks for the reply. I'm using resin-pro-3.1.3. Again, it seems to work when
I hit a single instance of resin that directly serves the requests, but when
there's a load balancer involved, the load balancer doesn't log it. Did you
try this access log line on a load balancer running 4.0.25?
Thanks,
Chris
- Original Message -
From: Alex Rojkov a...@caucho.com
To: General Discussion for the Resin application server
resin-interest@caucho.com
Sent: Monday, February 27, 2012 2:59:58 PM
Subject: Re: [Resin-interest] getting response header in load balancer access
logs
Hi Chris,
I could't reproduce this on version 4.0.25. What version are you running?
Thanks,
Alex
On 2012-02-27, at 2:10 PM, Chris Hart wrote:
Hi,
I'm having trouble getting the Set-Cookie response header into the access
logs on our load balancer. I've tested this exact same access-log
configuration locally with an instance of resin that is not behind any load
balancer and it seems to work, but this isn't working in our load balanced
production environment. It's currently just logging - at the end of the
access log line. Here's what our load balancer's configuration looks like:
access-log
path/var/log/resin/ariel/master-access.log/path
format
%{Host}i %h %l %u %t %r %s %b %{Referer}i %{User-Agent}i
%{X-Forwarded-For}i %{JSESSIONID}c %{ariel}c %{SSLB}c %D %{Cookie}i
%{Set-Cookie}o
/format
rollover-period1D/rollover-period
rollover-size-1/rollover-size
archive-formatmaster-access-%Y%m%d.log.gz/archive-format
/access-log
Any help is greatly appreciated.
Thanks,
Chris
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
Re: [Resin-interest] getting response header in load balancer access logs
Hi Alex,
Thanks for the reply. I'm using resin-pro-3.1.3. Again, it seems to work
when I hit a single instance of resin that directly serves the requests, but
when there's a load balancer involved, the load balancer doesn't log it. Did
you try this access log line on a load balancer running 4.0.25?
Hm... It looks like a bug actually and it affects 4.0 as well. Thanks for
reporting, my initial test was incorrect.
resin-3.1: http://bugs.caucho.com/view.php?id=4966
resin-4.0: http://bugs.caucho.com/view.php?id=4965
Alex
Thanks,
Chris
- Original Message -
From: Alex Rojkov a...@caucho.com
To: General Discussion for the Resin application server
resin-interest@caucho.com
Sent: Monday, February 27, 2012 2:59:58 PM
Subject: Re: [Resin-interest] getting response header in load balancer
access logs
Hi Chris,
I could't reproduce this on version 4.0.25. What version are you running?
Thanks,
Alex
On 2012-02-27, at 2:10 PM, Chris Hart wrote:
Hi,
I'm having trouble getting the Set-Cookie response header into the access
logs on our load balancer. I've tested this exact same access-log
configuration locally with an instance of resin that is not behind any load
balancer and it seems to work, but this isn't working in our load balanced
production environment. It's currently just logging - at the end of the
access log line. Here's what our load balancer's configuration looks like:
access-log
path/var/log/resin/ariel/master-access.log/path
format
%{Host}i %h %l %u %t %r %s %b %{Referer}i %{User-Agent}i
%{X-Forwarded-For}i %{JSESSIONID}c %{ariel}c %{SSLB}c %D %{Cookie}i
%{Set-Cookie}o
/format
rollover-period1D/rollover-period
rollover-size-1/rollover-size
archive-formatmaster-access-%Y%m%d.log.gz/archive-format
/access-log
Any help is greatly appreciated.
Thanks,
Chris
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
___
resin-interest mailing list
resin-interest@caucho.com
http://maillist.caucho.com/mailman/listinfo/resin-interest
