Login | Register For Free | Help
Search for: (Advanced)

Mailing List Archive: Apache: Users

"proxy_balancer" | stickysession

 

 

Apache users RSS feed   Index | Next | Previous | View Threaded


Holger.King at de

Sep 29, 2010, 7:53 AM

Post #1 of 13 (3590 views)
Permalink
"proxy_balancer" | stickysession

Dear mailing list,

currently, we use the Apache2 version:
- Apache2 2.2.16 64bit
- standard "mod_proxy_balancer" module

with the following V-HOST configuration including a proxy balancer directive (with two Apache Tomcat instances behind):
<Proxy balancer://fs4server>
BalancerMember ajp://rb-wcmstc1.xx.xxxxx.xxx:8009 loadfactor=100 retry=10 route=rb-wcmstc1
BalancerMember ajp://rb-wcmstc2.xx.xxxxx.xxx:8009 loadfactor=100 retry=10 route=rb-wcmstc2

ProxySet stickysession=JSESSIONID
ProxySet lbmethod=byrequests
#ProxySet nofailover=On
ProxySet timeout=30
</Proxy>

In production environment, we discover connection switches from "rb-wcmstc1" to "rb-wcmstc2" and vice versa (documented in the Tomcat-Logs) for the same Session-ID:

"rb-wcmstc1"
tomcat@<rb-wcmstc1>:/opt/tomcat/logs $ grep -i "5893975846599935313" *
log4j-catalina.log.13:TRACE 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): Opening connection to 10.35.32.123, id=5893975846599935313
log4j-catalina.log.13:TRACE 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): Server call from 10.35.32.123, id=5893975846599935313, clientLength=82, serverLength=79, serverResponseLength=1, 455 ms

"rb-wcmstc2"
DEBUG 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): IO error with 10.35.32.123, port=1088, host=rb-wcmsfs4.de.bosch.com - java.
lang.IllegalStateException: Connection '5893975846599935313' not found
java.lang.IllegalStateException: Connection '5893975846599935313' not found
at de.espirit.firstspirit.io.servlet.ClientIOServlet.callServer(ClientIOServlet.java:194)
at de.espirit.firstspirit.io.servlet.ClientIOServlet.doPost(ClientIOServlet.java:117)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)

Although, the "stickysession" attribute is set properly using the "JSESSIONID" cookie name and the Apache-Tomcat instances are up and running, the connection SWITCHES. Why?

---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


apache.org-lists at darkwhole

Sep 29, 2010, 2:31 PM

Post #2 of 13 (3498 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

Hi Holger,

On 09/29/2010 04:53 PM, King Holger (CI/AFP2) wrote:
> In production environment, we discover connection switches from
> "rb-wcmstc1" to "rb-wcmstc2" and vice versa (documented in the
> Tomcat-Logs) for the same Session-ID:
[...]
> Although, the "stickysession" attribute is set properly using the
> "JSESSIONID" cookie name and the Apache-Tomcat instances are up and
> running, the connection SWITCHES. Why?

It looks like you did not set the jvmRoute-Attribute of the Engine tag
in your Tomcat configuration to "rb-wcmstc1" on the first and
"rb-wcmstc2" on the second server.

mod_proxy_ajp (used by mod_proxy_balancer) identifies the Tomcat-backend
holding the session by looking up a suffix added to the JSESSIONID
cookie value. You can easily check whether the suffix is set or not by
logging the session id in the Tomcat access log (%S) or by logging
Cookie and Set-Cookie HTTP headers (logpattern: %{Cookie}i and
%{Set-Cookie}o) in your httpd access log.

Regards,
Thomas

---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


Holger.King at de

Sep 30, 2010, 12:54 AM

Post #3 of 13 (3494 views)
Permalink
RE: "proxy_balancer" | stickysession [In reply to]

Hi Thomas,

I had to disappoint you, because the relevant excerpt of the Tomcat configuration below shows "jvmRoute" setup properly on EACH Tomcat instance:

"rb-wcmstc1"
<Engine name="Standalone" defaultHost="localhost" jvmRoute="rb-wcmstc1">

"rb-wcmstc2"
<Engine name="Standalone" defaultHost="localhost" jvmRoute="rb-wcmstc2">

So, might it be a BUG in Apache2 2.2.16? Is it possible to identify the reason, why that happens on Apache2-side? How?

Kind regards,
Holger


-----Original Message-----
From: Thomas [mailto:apache.org-lists [at] darkwhole]
Sent: Mittwoch, 29. September 2010 23:31
To: users [at] httpd
Subject: Re: [users [at] http] "proxy_balancer" | stickysession

Hi Holger,

On 09/29/2010 04:53 PM, King Holger (CI/AFP2) wrote:
> In production environment, we discover connection switches from
> "rb-wcmstc1" to "rb-wcmstc2" and vice versa (documented in the
> Tomcat-Logs) for the same Session-ID:
[...]
> Although, the "stickysession" attribute is set properly using the
> "JSESSIONID" cookie name and the Apache-Tomcat instances are up and
> running, the connection SWITCHES. Why?

It looks like you did not set the jvmRoute-Attribute of the Engine tag
in your Tomcat configuration to "rb-wcmstc1" on the first and
"rb-wcmstc2" on the second server.

mod_proxy_ajp (used by mod_proxy_balancer) identifies the Tomcat-backend
holding the session by looking up a suffix added to the JSESSIONID
cookie value. You can easily check whether the suffix is set or not by
logging the session id in the Tomcat access log (%S) or by logging
Cookie and Set-Cookie HTTP headers (logpattern: %{Cookie}i and
%{Set-Cookie}o) in your httpd access log.

Regards,
Thomas

---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


rainer.frey at inxmail

Sep 30, 2010, 1:11 AM

Post #4 of 13 (3507 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

On Thursday 30 September 2010 09:54:11 King Holger (CI/AFP2) wrote:

Not only top posting, but also no quoting characters. Please fix that!

> Hi Thomas,
>
> I had to disappoint you, because the relevant excerpt of the Tomcat
> configuration below shows "jvmRoute" setup properly on EACH Tomcat
> instance:
>
> "rb-wcmstc1"
> <Engine name="Standalone" defaultHost="localhost" jvmRoute="rb-wcmstc1">
>
> "rb-wcmstc2"
> <Engine name="Standalone" defaultHost="localhost" jvmRoute="rb-wcmstc2">
>
> So, might it be a BUG in Apache2 2.2.16? Is it possible to identify the
> reason, why that happens on Apache2-side? How?

Do as Thomas recommended and capture the cookies and session ids. The IDs you
have in your first message look a bit unusual for tomcat generated session
IDs.

Additionally, you can set the Apache loglevel to debug for the VirtualHost
that does the loadbalancing. mod_proxy will log details about selecting the
backend worker.

Rainer

>
> Kind regards,
> Holger
>
>
> -----Original Message-----
> From: Thomas [mailto:apache.org-lists [at] darkwhole]
> Sent: Mittwoch, 29. September 2010 23:31
> To: users [at] httpd
> Subject: Re: [users [at] http] "proxy_balancer" | stickysession
>
> Hi Holger,
>
> On 09/29/2010 04:53 PM, King Holger (CI/AFP2) wrote:
> > In production environment, we discover connection switches from
> > "rb-wcmstc1" to "rb-wcmstc2" and vice versa (documented in the
>
> > Tomcat-Logs) for the same Session-ID:
> [...]
>
> > Although, the "stickysession" attribute is set properly using the
> > "JSESSIONID" cookie name and the Apache-Tomcat instances are up and
> > running, the connection SWITCHES. Why?
>
> It looks like you did not set the jvmRoute-Attribute of the Engine tag
> in your Tomcat configuration to "rb-wcmstc1" on the first and
> "rb-wcmstc2" on the second server.
>
> mod_proxy_ajp (used by mod_proxy_balancer) identifies the Tomcat-backend
> holding the session by looking up a suffix added to the JSESSIONID
> cookie value. You can easily check whether the suffix is set or not by
> logging the session id in the Tomcat access log (%S) or by logging
> Cookie and Set-Cookie HTTP headers (logpattern: %{Cookie}i and
> %{Set-Cookie}o) in your httpd access log.
>
> Regards,
> Thomas
>
> ---------------------------------------------------------------------
> 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 [at] httpd
> " from the digest: users-digest-unsubscribe [at] httpd
> For additional commands, e-mail: users-help [at] httpd
>
>
> ---------------------------------------------------------------------
> 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 [at] httpd
> " from the digest: users-digest-unsubscribe [at] httpd
> For additional commands, e-mail: users-help [at] httpd

---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


rainer.jung at kippdata

Sep 30, 2010, 1:37 AM

Post #5 of 13 (3503 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

On 29.09.2010 16:53, King Holger (CI/AFP2) wrote:
> Dear mailing list,
>
> currently, we use the Apache2 version:
> - Apache2 2.2.16 64bit
> - standard "mod_proxy_balancer" module
>
> with the following V-HOST configuration including a proxy balancer directive (with two Apache Tomcat instances behind):
> <Proxy balancer://fs4server>
> BalancerMember ajp://rb-wcmstc1.xx.xxxxx.xxx:8009 loadfactor=100 retry=10 route=rb-wcmstc1
> BalancerMember ajp://rb-wcmstc2.xx.xxxxx.xxx:8009 loadfactor=100 retry=10 route=rb-wcmstc2
>
> ProxySet stickysession=JSESSIONID
> ProxySet lbmethod=byrequests
> #ProxySet nofailover=On
> ProxySet timeout=30
> </Proxy>
>
> In production environment, we discover connection switches from "rb-wcmstc1" to "rb-wcmstc2" and vice versa (documented in the Tomcat-Logs) for the same Session-ID:
>
> "rb-wcmstc1"
> tomcat@<rb-wcmstc1>:/opt/tomcat/logs $ grep -i "5893975846599935313" *
> log4j-catalina.log.13:TRACE 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): Opening connection to 10.35.32.123, id=5893975846599935313
> log4j-catalina.log.13:TRACE 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): Server call from 10.35.32.123, id=5893975846599935313, clientLength=82, serverLength=79, serverResponseLength=1, 455 ms
>
> "rb-wcmstc2"
> DEBUG 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): IO error with 10.35.32.123, port=1088, host=rb-wcmsfs4.de.bosch.com - java.
> lang.IllegalStateException: Connection '5893975846599935313' not found
> java.lang.IllegalStateException: Connection '5893975846599935313' not found
> at de.espirit.firstspirit.io.servlet.ClientIOServlet.callServer(ClientIOServlet.java:194)
> at de.espirit.firstspirit.io.servlet.ClientIOServlet.doPost(ClientIOServlet.java:117)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
>
> Although, the "stickysession" attribute is set properly using the "JSESSIONID" cookie name and the Apache-Tomcat instances are up and running, the connection SWITCHES. Why?

How does stickyness work?
=========================

First it can use a cookie value or a value encoded in a URL. Java
webapps usually use a cookie named JSESSIONID, but when the client
doesn't support cookies, or if cookie usage is disabled on e.g. Tomcat,
it switches to URL encoding. Tomcat sometimes uses URL encoding when it
doesn't yet know, whether the client will support the cookie. URL
encoded session info is appended using ";jsessionid=...". Note the lower
case in the name of the id.

Since mod_proxy_balancer checks for the URL encoding and the cookie
using case sensitive strings, you need to configure both using the syntax:

stickysession=JSESSIONID|jsessionid

This is just to make sure, that an occasional URL encoded session info
is found as well.

Now by default mod_proxy_balancer looks for the URL encoded session info
as a parameter appended using "?" or "&", so as part of the query
string. Java Enterprise appends it using ";". To add that character to
the search list, you have to also set "scolonpathdelim On". Again this
is only necessary for occasional URL encoded sessions.

Now that mod_proxy_balancer can find the needed tokens (i.e. the value
of the JSESSIONID cookie, resp. the ;jsessionid URL encoded session
info), how does it detect the backend it should send the request to?

If there is a dot (".") in the token (session id), it only uses the part
after the dot as the "route", if not it uses the complete token.

Now it knows the "route" where it should send the request to it looks
for a balancer member, which has the same value set as its "route". In
the above example "rb-wcmstc1" respectively "rb-wcmstc2". This member
will handle the request - if the member is available, i.e. not broken or
disabled.

Finally: in order to let Tomcat attach the needed route to the end of
the session id you need to set the jvmRoute attribute in server.xml to
the respective route value.


How to track failures
=====================

1) Check whether your Tomcats send the correct route in the session id.

Look at the JSESSIONID cookie in the browser, whether it has
".rb-wcmstc1" resp. ".rb-wcmstc2" attached at the end of the id value.


2) Log the session ids send by the clients, and the session id set by
the server.

Activate the Tomcat access log and change the pattern to include

"%S &quot;%{Cookie}i&quot; &quot;%{Set-Cookie}o&quot;"

Change your log format for the Apache access log using CustomLog and add

"%{JSESSIONID}C" "%{Set-Cookie}o"

or even

"%{Cookie}i" "%{JSESSIONID}C" "%{Set-Cookie}o"

On the docs page

http://httpd.apache.org/docs/2.2/mod/mod_proxy_balancer.html#environment

you will also find a list of Apache environment variables useful for
debugging when adding to the log format, e.g.

%{BALANCER_SESSION_STICKY}e %{BALANCER_SESSION_ROUTE}e
%{BALANCER_WORKER_NAME}e %{BALANCER_WORKER_ROUTE}e
%{BALANCER_ROUTE_CHANGED}e


3) Switch Apache to debug log level

CAUTION: High log volume by mod_proxy and also mod_ssl if used.

It will log e.g.

proxy: BALANCER: Found value <TOKEN> for stickysession <IS_STICKY>

(that's the token contained in the request)

proxy: BALANCER: Found route <ROUTE>

(that's the route info from the token, e.g. stripping everything in
front of a dot)

proxy: BALANCER: Route changed from <NEEDED> to <USED>

(if there is no worker available for the route <NEEDED>, the worker
which will be used instead is <USED>).


Final remarks
=============

You look for the string "5893975846599935313" in your above log
snippets. That does not look like a Tomcat session id. It doesn't have
the trailing route and it is purely decimal numeric, whereas a Tomcat
session id is hexadecimal. It is very unlikely that there are no [A-F]
digits in it.

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


Holger.King at de

Oct 14, 2010, 7:16 AM

Post #6 of 13 (3483 views)
Permalink
RE: "proxy_balancer" | stickysession [In reply to]

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?

Any ideas?


-----Original Message-----
From: Rainer Jung [mailto:rainer.jung [at] kippdata]
Sent: Donnerstag, 30. September 2010 10:38
To: users [at] httpd
Subject: Re: [users [at] http] "proxy_balancer" | stickysession

On 29.09.2010 16:53, King Holger (CI/AFP2) wrote:
> Dear mailing list,
>
> currently, we use the Apache2 version:
> - Apache2 2.2.16 64bit
> - standard "mod_proxy_balancer" module
>
> with the following V-HOST configuration including a proxy balancer directive (with two Apache Tomcat instances behind):
> <Proxy balancer://fs4server>
> BalancerMember ajp://rb-wcmstc1.xx.xxxxx.xxx:8009 loadfactor=100 retry=10 route=rb-wcmstc1
> BalancerMember ajp://rb-wcmstc2.xx.xxxxx.xxx:8009 loadfactor=100 retry=10 route=rb-wcmstc2
>
> ProxySet stickysession=JSESSIONID
> ProxySet lbmethod=byrequests
> #ProxySet nofailover=On
> ProxySet timeout=30
> </Proxy>
>
> In production environment, we discover connection switches from "rb-wcmstc1" to "rb-wcmstc2" and vice versa (documented in the Tomcat-Logs) for the same Session-ID:
>
> "rb-wcmstc1"
> tomcat@<rb-wcmstc1>:/opt/tomcat/logs $ grep -i "5893975846599935313" *
> log4j-catalina.log.13:TRACE 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): Opening connection to 10.35.32.123, id=5893975846599935313
> log4j-catalina.log.13:TRACE 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): Server call from 10.35.32.123, id=5893975846599935313, clientLength=82, serverLength=79, serverResponseLength=1, 455 ms
>
> "rb-wcmstc2"
> DEBUG 29.09.2010 14:16:58 (de.espirit.firstspirit.io.servlet.ClientIOServlet): IO error with 10.35.32.123, port=1088, host=rb-wcmsfs4.de.bosch.com - java.
> lang.IllegalStateException: Connection '5893975846599935313' not found
> java.lang.IllegalStateException: Connection '5893975846599935313' not found
> at de.espirit.firstspirit.io.servlet.ClientIOServlet.callServer(ClientIOServlet.java:194)
> at de.espirit.firstspirit.io.servlet.ClientIOServlet.doPost(ClientIOServlet.java:117)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
>
> Although, the "stickysession" attribute is set properly using the "JSESSIONID" cookie name and the Apache-Tomcat instances are up and running, the connection SWITCHES. Why?

How does stickyness work?
=========================

First it can use a cookie value or a value encoded in a URL. Java
webapps usually use a cookie named JSESSIONID, but when the client
doesn't support cookies, or if cookie usage is disabled on e.g. Tomcat,
it switches to URL encoding. Tomcat sometimes uses URL encoding when it
doesn't yet know, whether the client will support the cookie. URL
encoded session info is appended using ";jsessionid=...". Note the lower
case in the name of the id.

Since mod_proxy_balancer checks for the URL encoding and the cookie
using case sensitive strings, you need to configure both using the syntax:

stickysession=JSESSIONID|jsessionid

This is just to make sure, that an occasional URL encoded session info
is found as well.

Now by default mod_proxy_balancer looks for the URL encoded session info
as a parameter appended using "?" or "&", so as part of the query
string. Java Enterprise appends it using ";". To add that character to
the search list, you have to also set "scolonpathdelim On". Again this
is only necessary for occasional URL encoded sessions.

Now that mod_proxy_balancer can find the needed tokens (i.e. the value
of the JSESSIONID cookie, resp. the ;jsessionid URL encoded session
info), how does it detect the backend it should send the request to?

If there is a dot (".") in the token (session id), it only uses the part
after the dot as the "route", if not it uses the complete token.

Now it knows the "route" where it should send the request to it looks
for a balancer member, which has the same value set as its "route". In
the above example "rb-wcmstc1" respectively "rb-wcmstc2". This member
will handle the request - if the member is available, i.e. not broken or
disabled.

Finally: in order to let Tomcat attach the needed route to the end of
the session id you need to set the jvmRoute attribute in server.xml to
the respective route value.


How to track failures
=====================

1) Check whether your Tomcats send the correct route in the session id.

Look at the JSESSIONID cookie in the browser, whether it has
".rb-wcmstc1" resp. ".rb-wcmstc2" attached at the end of the id value.


2) Log the session ids send by the clients, and the session id set by
the server.

Activate the Tomcat access log and change the pattern to include

"%S &quot;%{Cookie}i&quot; &quot;%{Set-Cookie}o&quot;"

Change your log format for the Apache access log using CustomLog and add

"%{JSESSIONID}C" "%{Set-Cookie}o"

or even

"%{Cookie}i" "%{JSESSIONID}C" "%{Set-Cookie}o"

On the docs page

http://httpd.apache.org/docs/2.2/mod/mod_proxy_balancer.html#environment

you will also find a list of Apache environment variables useful for
debugging when adding to the log format, e.g.

%{BALANCER_SESSION_STICKY}e %{BALANCER_SESSION_ROUTE}e
%{BALANCER_WORKER_NAME}e %{BALANCER_WORKER_ROUTE}e
%{BALANCER_ROUTE_CHANGED}e


3) Switch Apache to debug log level

CAUTION: High log volume by mod_proxy and also mod_ssl if used.

It will log e.g.

proxy: BALANCER: Found value <TOKEN> for stickysession <IS_STICKY>

(that's the token contained in the request)

proxy: BALANCER: Found route <ROUTE>

(that's the route info from the token, e.g. stripping everything in
front of a dot)

proxy: BALANCER: Route changed from <NEEDED> to <USED>

(if there is no worker available for the route <NEEDED>, the worker
which will be used instead is <USED>).


Final remarks
=============

You look for the string "5893975846599935313" in your above log
snippets. That does not look like a Tomcat session id. It doesn't have
the trailing route and it is purely decimal numeric, whereas a Tomcat
session id is hexadecimal. It is very unlikely that there are no [A-F]
digits in it.

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


rainer.jung at kippdata

Oct 15, 2010, 1:58 AM

Post #7 of 13 (3439 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


Holger.King at de

Oct 15, 2010, 3:32 AM

Post #8 of 13 (3452 views)
Permalink
RE: "proxy_balancer" | stickysession [In reply to]

Hello Rainer,

it's a pity - but the clocks are in sync (using NTP). On both Tomcats and the Apache2 instances.

According to the following command output:
grep -i "52C326B80A73EFF19CEE49B013533F06" localhost_access_log.2010-10-14.log

the last pattern match for the JSessionID mentioned below is:
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

So, I cannot find any further request logged further down in Tomcat "rb-wcmstc2".

Due to an already overwritten error.log (log-rotation), I do not have any more access to the Apache2 error-log. :(

We will add the "%D" to the log format string on both Apache2 and Tomcat.

Any more hints to identify the problem? The problematik POST request seems to be:
> 10.35.32.123 - - [14/Oct/2010:11:45:03 +0200] "POST /servlet/ClientIO/90i8dcztq97l/s6/21j HTTP/1.1" 500 1258
> "-" "Jakarta Commons-HttpClient/3.1" "JSESSIONID=52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2"
> "52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2" "JSESSIONID=B3C4AABB5F983A0E9D6478C42C88A5C4.rb-wcmstc1; Path=/"

This POST throws a 500 status code.



-----Original Message-----
From: Rainer Jung [mailto:rainer.jung [at] kippdata]
Sent: Freitag, 15. Oktober 2010 10:58
To: users [at] httpd
Subject: Re: [users [at] http] "proxy_balancer" | stickysession

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


rainer.jung at kippdata

Oct 15, 2010, 6:26 AM

Post #9 of 13 (3423 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

On 15.10.2010 12:32, King Holger (CI/AFP2) wrote:
> it's a pity - but the clocks are in sync (using NTP). On both Tomcats and the Apache2 instances.

Good to know.

> According to the following command output:
> grep -i "52C326B80A73EFF19CEE49B013533F06" localhost_access_log.2010-10-14.log
>
> the last pattern match for the JSessionID mentioned below is:
> 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
>
> So, I cannot find any further request logged further down in Tomcat "rb-wcmstc2".

So we deduce, that either the request is still hanging inside Tomcat or
it never reached Tomcat. Although the latter is more likely, you can
check: if you have the Tomcat manager webapp deployed, you can look at
the status page, which shows a list of all in-flight requests.

> Due to an already overwritten error.log (log-rotation), I do not have any more access to the Apache2 error-log. :(

Then there's likely no way forward for this incident. We would nee dto
wait for the next one :(

> We will add the "%D" to the log format string on both Apache2 and Tomcat.

Good, it's helpful in a lot of situations anyhows.

> Any more hints to identify the problem? The problematik POST request seems to be:
>> 10.35.32.123 - - [14/Oct/2010:11:45:03 +0200] "POST /servlet/ClientIO/90i8dcztq97l/s6/21j HTTP/1.1" 500 1258
>> "-" "Jakarta Commons-HttpClient/3.1" "JSESSIONID=52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2"
>> "52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2" "JSESSIONID=B3C4AABB5F983A0E9D6478C42C88A5C4.rb-wcmstc1; Path=/"
>
> This POST throws a 500 status code.

Sorry, to many possible reasons in the proxy for that. You need the
error log.

You can try to make your setup a bit more robust by looking at the
parameter table given at

http://httpd.apache.org/docs/current/mod/mod_proxy.html#proxypass

For the ajp workers, the following parameters come to mind:

- ping (e.g. ping=10s)
- connectiontimeout (e.g. connectiontimeout=10s)
- timeout (e.g. timeout=120s)
- keepalive=On

The 10 second timeouts could also be lowered to e.g. 5 or 2 seconds if
you are reasonably sure that you don't have any longer GC pauses on the
Java back-ends. A good value for the general timeout depends on your
expectation of response times the back-end will be able to support as
long as it is running well. The "%D" in the access log will help you get
some real numbers.

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


Holger.King at de

Oct 25, 2010, 6:11 AM

Post #10 of 13 (3357 views)
Permalink
RE: "proxy_balancer" | stickysession [In reply to]

Hi Rainer,

we discovered the same Tomcat-"connection-switch" problem again. This time with the Apache2 ERROR-LOG, containing:

Apache2-ERROR-Log Output:
[Mon Oct 25 10:18:58 2010] [error] server is within MinSpareThreads of MaxClients, consider raising the MaxClients setting
[Mon Oct 25 11:46:35 2010] [error] server reached MaxClients setting, consider raising the MaxClients setting
[Mon Oct 25 11:50:02 2010] [error] (70007)The timeout specified has expired: ajp_ilink_receive() can't receive header

Apache2-ACCESS-Log Output:
10.35.32.123 - - [25/Oct/2010:11:50:04 +0200] "POST /servlet/ClientIO/1ojgw1th835ue/s6/y1 HTTP/1.1" 500 1258 "-" "Jakarta Commons-HttpClient/3.1" "JSESSIONID=A62BCC2B1054CA532C68CA409F41548C.rb-wcmstc1" "A62BCC2B1054CA532C68CA409F41548C.rb-wcmstc1" "JSESSIONID=56DB518EDE4EFED6337349F3478A4863.rb-wcmstc2; Path=/" 2795

When checking the configuration file for the MPM ("httpd-mpm.conf"), the central Apache2-configuration does not include that file:
# Server-pool management (MPM specific)
#Include conf/extra/httpd-mpm.conf

Currently, we use the "worker"-MPM as shown in the "apachectl"-output (AND NOT WORKER):
<hostname>:/opt/wcms/apache/bin $ ./apachectl -M | grep -i "worker"
Syntax OK
mpm_worker_module (static)

When monitoring the Apache2 via the "/server-status" resource, the following information is shown (see screenshot enclosed):

As you can see:
- the total amount of requests possibly being handled in parallel: 400
- the amount of idle workers sometimes reaches the critical value: 0 (not documented in the screenshot enclosed)

Our questions:
- why 400? We assumed a default value of 150 for "MaxClients" (see "httpd-mpm.conf")
- should we increase the "MaxClients"-value by explicitly defining it in "httpd-mpm.conf" (as mentioned in the "error.log" above)?

When monitoring one of the Tomcats below "/manager/status" (here: "rb-wcmstc2"), the screenshot enclosed shows the following information:
- MaxThreads: 500
- ThreadCount: 252
- Current Thread Busy: 239

The configuration for the Tomcats (here "rb-wcmstc2"):
<!-- Define an AJP 1.3 Connector on port 8009 -->
<Connector port="8009" protocol="AJP/1.3" redirectPort="8443" allowTrace="true" maxThreads="500" />

Consequence:
- it seems to be clear, that Apache2 is the bottleneck (the amount of connections available within the "connection-pool" does sporadically reach the value of "0")

What are your suggestions?

Kind regards,
Holger King



-----Original Message-----
From: Rainer Jung [mailto:rainer.jung [at] kippdata]
Sent: Freitag, 15. Oktober 2010 15:26
To: users [at] httpd
Subject: Re: [users [at] http] "proxy_balancer" | stickysession

On 15.10.2010 12:32, King Holger (CI/AFP2) wrote:
> it's a pity - but the clocks are in sync (using NTP). On both Tomcats and the Apache2 instances.

Good to know.

> According to the following command output:
> grep -i "52C326B80A73EFF19CEE49B013533F06" localhost_access_log.2010-10-14.log
>
> the last pattern match for the JSessionID mentioned below is:
> 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
>
> So, I cannot find any further request logged further down in Tomcat "rb-wcmstc2".

So we deduce, that either the request is still hanging inside Tomcat or
it never reached Tomcat. Although the latter is more likely, you can
check: if you have the Tomcat manager webapp deployed, you can look at
the status page, which shows a list of all in-flight requests.

> Due to an already overwritten error.log (log-rotation), I do not have any more access to the Apache2 error-log. :(

Then there's likely no way forward for this incident. We would nee dto
wait for the next one :(

> We will add the "%D" to the log format string on both Apache2 and Tomcat.

Good, it's helpful in a lot of situations anyhows.

> Any more hints to identify the problem? The problematik POST request seems to be:
>> 10.35.32.123 - - [14/Oct/2010:11:45:03 +0200] "POST /servlet/ClientIO/90i8dcztq97l/s6/21j HTTP/1.1" 500 1258
>> "-" "Jakarta Commons-HttpClient/3.1" "JSESSIONID=52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2"
>> "52C326B80A73EFF19CEE49B013533F06.rb-wcmstc2" "JSESSIONID=B3C4AABB5F983A0E9D6478C42C88A5C4.rb-wcmstc1; Path=/"
>
> This POST throws a 500 status code.

Sorry, to many possible reasons in the proxy for that. You need the
error log.

You can try to make your setup a bit more robust by looking at the
parameter table given at

http://httpd.apache.org/docs/current/mod/mod_proxy.html#proxypass

For the ajp workers, the following parameters come to mind:

- ping (e.g. ping=10s)
- connectiontimeout (e.g. connectiontimeout=10s)
- timeout (e.g. timeout=120s)
- keepalive=On

The 10 second timeouts could also be lowered to e.g. 5 or 2 seconds if
you are reasonably sure that you don't have any longer GC pauses on the
Java back-ends. A good value for the general timeout depends on your
expectation of response times the back-end will be able to support as
long as it is running well. The "%D" in the access log will help you get
some real numbers.

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd
Attachments: tomcat6_status.jpg (76.5 KB)
  apache2_status.jpg (205 KB)


jim at jaguNET

Oct 27, 2010, 8:02 AM

Post #11 of 13 (3336 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

Ideally, you would have Apache and Tomcat setup so that both
have the exact same number of potential connections to each
other.

Also, what is the KeepAliveTimeout setting? From what I
can see it must be high. Consider dropping it down to
like 2 or 3 (max) or even disabling depending on how much
it really buys you, performance-wise.

---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


rainer.jung at kippdata

Oct 27, 2010, 8:12 AM

Post #12 of 13 (3334 views)
Permalink
Re: "proxy_balancer" | stickysession [In reply to]

On 27.10.2010 16:10, King Holger (CI/AFP2) wrote:
> we need your help :) We re-discovered a Tomcat-connection switch problem in combination with Apache2 2.2.16 and "mod_proxy_balancer". This time, we saved the Apache2 ERROR-LOG!
>
> The Apache2-ACCESS log documents the connection switch from one Tomcat named "rb-wcmstc1" to the other one "rb-wcmstc2":
> 10.35.32.123 - - [25/Oct/2010:11:50:04 +0200] "POST /servlet/ClientIO/1ojgw1th835ue/s6/y1 HTTP/1.1" 500 1258 "-" "Jakarta Commons-HttpClient/3.1" "JSESSIONID=A62BCC2B1054CA532C68CA409F41548C.rb-wcmstc1" "A62BCC2B1054CA532C68CA409F41548C.rb-wcmstc1" "JSESSIONID=56DB518EDE4EFED6337349F3478A4863.rb-wcmstc2; Path=/" 2795
>
> Apache2-ERROR-Log Output:
> [Mon Oct 25 10:18:58 2010] [error] server is within MinSpareThreads of MaxClients, consider raising the MaxClients setting
> [Mon Oct 25 11:46:35 2010] [error] server reached MaxClients setting, consider raising the MaxClients setting
> [Mon Oct 25 11:50:02 2010] [error] (70007)The timeout specified has expired: ajp_ilink_receive() can't receive header

OK, here the last line is relevant. So the failover is happening,
because Apache doesn't get the answer from wcmstc1.

Since we see, that Apache created all its allowed processes shortly
before, it is likely that all threads in Tomcat are busy.

> Our assumption: a bottleneck within the Apache2 connection pool (http://www.gossamer-threads.com/lists/apache/users/343190)???
>
> When monitoring the Apache2 via the "/server-status" resource, the following information is shown (see screenshot enclosed). As you can see:
> - the total amount of requests (sum of requests and idle workers) possibly being handled in parallel: 400
> - the amount of idle workers sometimes reaches the critical value: 0 (not documented in the screenshot enclosed)
>
> After checking the Apache2 central configuration file for the Apache2-MPM ("httpd-mpm.conf"), it does NOT include that resource:
> # Server-pool management (MPM specific)
> #Include conf/extra/httpd-mpm.conf
>
> Currently, we use the "worker"-MPM as shown in the "apachectl"-output (AND NOT PREFORK).
> <hostname>:/opt/wcms/apache/bin $ ./apachectl -M | grep -i "worker"
> Syntax OK
> mpm_worker_module (static)
>
> Our questions:
> - when not including the "httpd-mpm.conf" (containg configurations for different MPMs), which values are used?

Maximum 16 processes, each 25 threads.

> - why 400 requests? We assumed a default value of 150 for "MaxClients" (see "httpd-mpm.conf")

Unfortunately the values in httpd-mpm.conf do not reflect the defaults
set in the code.

> - should we increase the "MaxClients"-value by explicitly defining it in "httpd-mpm.conf" (as mentioned in the "error.log" above)?

You could, but make sure that you remove the comment sign before the
Include statement.

> When monitoring one of the Tomcats below "/manager/status" (here: "rb-wcmstc2"), the screenshot enclosed shows the following information:
> - MaxThreads: 500
> - ThreadCount: 252
> - Current Thread Busy: 239
>
> The configuration for the Tomcats (here "rb-wcmstc2"):
> <!-- Define an AJP 1.3 Connector on port 8009 -->
> <Connector port="8009" protocol="AJP/1.3" redirectPort="8443" allowTrace="true" maxThreads="500" />
>
> Consequence:
> - it seems to be clear, that Apache2 is the bottleneck (the amount of connections available within the "connection-pool" does sporadically reach the value of "0")

You could increase the allowed concurrency for Apache. But: often the
problem is not the limited concurrency, but that some application is to
slow. As a rule of thumb:

Needed concurrency = Throughput * Response Time

So if you want to handle 100 requests per second and assume an average
response time of 0.5 seconds, you would experience a typical needed
concurrency of 50. As always you should add some headroom to the numbers
you calculate.

Typically if you run into a performance problem, the response times
explode, and the number of incoming requests stays high. That means the
needed concurrency also explodes. It doesn't make sense in this case to
increase the available concurrency by e.g. a factor of 10. Instead you
need to find out, why things are getting slow.

So: Monitor your Apache Usage (server-status). If you are typically e.g.
in the range between 300 and 400 and only sometimes you hit the 400.
increasing the available concurrency might be OK (remember that Tomcat
also needs enough threads). If your typical concurrancy is about 10 or
50 and only sometimes it hits 400, then increasing will not help.
Instead you will need to find out what happens when the numbers get to big.

First check in your acess log using "%D", that in fact the response
times get bigger and not really the load (requests per second). Do the
check for Apache and Tomcat and compare the numbers.

Then once you know that growing response times are the problem, the best
approach is using Java thread dumps for Tomcat to analyze, why the app
gets slow.

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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


Holger.King at de

Oct 27, 2010, 9:39 AM

Post #13 of 13 (3337 views)
Permalink
RE: "proxy_balancer" | stickysession [In reply to]

Tell me details ;)

-----Original Message-----
From: Jim Jagielski [mailto:jim [at] jaguNET]
Sent: Mittwoch, 27. Oktober 2010 17:02
To: users [at] httpd
Subject: Re: [users [at] http] "proxy_balancer" | stickysession

Ideally, you would have Apache and Tomcat setup so that both
have the exact same number of potential connections to each
other.

Also, what is the KeepAliveTimeout setting? From what I
can see it must be high. Consider dropping it down to
like 2 or 3 (max) or even disabling depending on how much
it really buys you, performance-wise.

---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd


---------------------------------------------------------------------
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 [at] httpd
" from the digest: users-digest-unsubscribe [at] httpd
For additional commands, e-mail: users-help [at] httpd

Apache users RSS feed   Index | Next | Previous | View Threaded
 
 


Interested in having your list archived? Contact Gossamer Threads
 
  Web Applications & Managed Hosting Powered by Gossamer Threads Inc.