Hi Holger, On 14.10.2010 16:16, King Holger (CI/AFP2) wrote:
Unfortunately, after having activated the:
- Tomcat-AccessLog
- custom-LogFormat using Cookie-OutPut in Apache2 2.2.16
LogFormat "%h %l %u %t \"%r\" %>s %b \"%{Referer}i\" \"%{User-agent}i\" \"%{Cookie}i\" \"%{JSESSIONID}C\" \"%{Set-Cookie}o\""
- "stickysession=JSESSIONID|jsessionid" and "scolonpathdelim On" for the "proxy_balancer" module in Apache2 2.2.16
we re-discovered a connection switch from one to the other Tomcat (here: from "rb-wcmstc2" to "rb-wcmstc1") instances.
Below you can see how Apache2 switches (recording a 500-HTTP-StatusCode) and tries to set a new JSESSIONID-Cookie containe "rb-wcmstc1":
10.35.32.123 - - [14/Oct/2010:11:45:03 +0200] "POST /servlet/ClientIO/90i8dcztq97l/s6/21j HTTP/1.1" 500 1258 "-" "Jakarta Commons-H
ttpClient/3.1" "JSESSIONID=52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2" "52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2" "JSESSIONID=B
3C4AABB5F983A0E9D6478C42C88A5C4.rb-wcmstc1; Path=/"
Here the Tomcat-AccessLog of "rb-wcmstc2" recorded during the connection-switch around "14/Oct/2010:11:45:03":
10.35.32.123 - - [14/Oct/2010:11:44:59 +0200] GET /fs4webedit/do.MessageEventServlet HTTP/1.1 200 55 CB41BCFB1D44C27047137CF9DED7A088.rb-wcmstc2
10.35.32.123 - - [14/Oct/2010:11:45:00 +0200] GET /fs4webedit/do.MessageEventServlet HTTP/1.1 200 55 40198501CD70083C31AAFD862923E4AA.rb-wcmstc2
10.35.32.123 - - [14/Oct/2010:11:45:01 +0200] POST /servlet/ClientIO/1nttjvwlaiwyl/s6/2gb HTTP/1.1 200 197 2FBA856A4DF56B2CA6F61C67E5411E0B.rb-wcmstc2
10.35.32.123 - - [14/Oct/2010:11:45:01 +0200] POST /servlet/ClientIO/90i8dcztq97l/s6/21i HTTP/1.1 200 197 52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2
10.35.32.123 - - [14/Oct/2010:11:45:01 +0200] GET /fs4webedit/preview/6719107/site/DE/current/6719288/8617824/mode=2 HTTP/1.1 200 1248 D29A5CD8F3C60AFAC5
684F4BA49282EC.rb-wcmstc2
10.35.32.123 - - [14/Oct/2010:11:45:01 +0200] GET /favicon.ico HTTP/1.1 304 - -
10.35.32.123 - - [14/Oct/2010:11:45:02 +0200] GET /fs4webedit/preview/6719107/site/DE/current/6719288/8617824/pagestoreId=8617816/contentFrame=1/WEBedit=
1/mode=2 HTTP/1.1 200 70998 D29A5CD8F3C60AFAC5684F4BA49282EC.rb-wcmstc2
10.35.32.123 - - [14/Oct/2010:11:45:12 +0200] GET /fs4webedit/do.MessageEventServlet HTTP/1.1 200 55 EF67E8AB7E1C2FAAE548623479CF0BDE.rb-
Hints: the above mentioned JSESSIONID "52C326B80A73EFF19CEE49B013533F06" can just be found on "rb-wcmstc2", of course. A blocking garbage collection run on "rb-wcmstc2" can be excluded (according to the tomcat GC-logs)!
The whole proxy balancer configuration you can see below.
We wonder:
- why does it happen, although "rb-wcmstc2" seems to be physically available?
- how to determine the root-cause?
I assume the clocks on the Apache and Tomcat servers are in sync? In the Apache access log the timestamp is "11:45:03". Apache uses as timestamp the time when the request arrived. Tomcat logs using the time when the request finished. In the access log snippet for the Tomcat access log you provided, we can see no POST for this session id at or after "11:45:03". The only entry that fits the URL is already two seconds before. I hope the clocks are right ...
So either the request is logged further down, which would indicate that it took quite long, or it didn't actually reach Tomcat, or it is still stuck in it. I would hope and expect, that your Apache error log does contain an indication for the failure. Remember that it could be logged in the error log later than "11:45:03", because the timestamp in the error log will be when the actual error happened, the timestamp in the Apache access log when the request came in.
Anything in the error log? Any corresponding POST with the right session id further down in the Tomcat access log?
If we suspect, that some kind of timeout is happening, then we would want to add "%D" to the access log formats in Apache and Tomcat. %D logs the duration of the request, for Apache in microseconds, for Tomcat in milliseconds.
Regards, Rainer --------------------------------------------------------------------- The official User-To-User support forum of the Apache HTTP Server Project. See <URL:http://httpd.apache.org/userslist.html> for more info. To unsubscribe, e-mail: users-unsubscribe@xxxxxxxxxxxxxxxx " from the digest: users-digest-unsubscribe@xxxxxxxxxxxxxxxx For additional commands, e-mail: users-help@xxxxxxxxxxxxxxxx
|