☰

Apache httpd cria novas sessões sempre (2.2.16 e 2.4.6)

tag-icon • tag-icon apache-2.2 proxy httpd session sticky-sessions
Apache httpd cria novas sessões sempre (2.2.16 e 2.4.6)

Eu tenho um servidor rodando Apahce httpd 2.2.16 no Debian 6.0.7

Eu uso a diretiva proxy balanceador para reverter o tráfego de proxy usando o protocolo ajp para back-ends do Tomcat

<Proxy balancer://tomcatapp-cluster>
    BalancerMember ajp://server-01.siminn.is:8000 route=tomcatapp-01 loadfactor=50 connectiontimeout=10
    BalancerMember ajp://server-02.siminn.is:8000 route=tomcatapp-02 loadfactor=50 connectiontimeout=10
</Proxy>
ProxyPass /app balancer://tomcatapp-cluster/app stickysession=JSESSIONID|jsessionid
ProxyPassReverse /app balancer://tomcatapp-cluster/app stickysession=JSESSIONID|jsessionid

Solicitações feitas ao aplicativo durante o tempo de vida de uma sessão em que uma nova sessão é iniciada em outro back-end

GET /app/gsm/prepaid/buy HTTP/1.1
Cookie: JSESSIONID=C20AE8FC06F2A9A7136179FCAA7043FD.tomcatapp-02; _ga=GA1.2.1159250103.1389354702; __utma=159157733.1159250103.1389354702.1389606393.1389609120.7; __utmz=159157733.1389362294.3.2.utmcsr=siminn.is|utmccn=(referral)|utmcmd=referral|utmcct=/; userstyles=off; __utmc=159157733; __utmmobile=0xd4b5e4e4320505f5; __utmb=159157733.21.10.1389609120; is_returning=1; autoLogin.disabled=true; s_cc=true; s_sq=siminnliveinnri%3D%2526pid%253Dfors%2525u00ED%2525F0a%2526pidt%253D1%2526oid%253DInnskr%2525u00E1%2526oidt%253D3%2526ot%253DSUBMIT; USER_CACHE_KEY=D6D0DCFD773406CA8EE5D690A4AF1368.tomcattf-02
Set-Cookie: JSESSIONID=A95480808617EA3ABB3C1A4FB079DD99.tomcatapp-01; Path=/app/; Secure; HttpOnly

GET /app/site.jsp&guid=ON HTTP/1.1
Cookie: JSESSIONID=A95480808617EA3ABB3C1A4FB079DD99.tomcatapp-01; _ga=GA1.2.1159250103.1389354702; __utma=159157733.1159250103.1389354702.1389606393.1389609120.7; __utmz=159157733.1389362294.3.2.utmcsr=siminn.is|utmccn=(referral)|utmcmd=referral|utmcct=/; userstyles=off; __utmc=159157733; __utmmobile=0xd4b5e4e4320505f5; __utmb=159157733.21.10.1389609120; is_returning=1; autoLogin.disabled=true; s_cc=true; s_sq=siminnliveinnri%3D%2526pid%253Dfors%2525u00ED%2525F0a%2526pidt%253D1%2526oid%253DInnskr%2525u00E1%2526oidt%253D3%2526ot%253DSUBMIT; USER_CACHE_KEY=D6D0DCFD773406CA8EE5D690A4AF1368.tomcattf-02
Set-Cookie: JSESSIONID=26097E35B6B0C9B6652A7A6F8FF77992.tomcatapp-02; Path=/app/; Secure; HttpOnly
Set-Cookie: __utmmobile=x; Expires=Wed, 13-Jan-2016 11:34:06 GMT; Path=/

GET /app/gsm/prepaid/buy HTTP/1.1
Cookie: JSESSIONID=26097E35B6B0C9B6652A7A6F8FF77992.tomcatapp-02; _ga=GA1.2.1159250103.1389354702; __utma=159157733.1159250103.1389354702.1389606393.1389609120.7; __utmz=159157733.1389362294.3.2.utmcsr=siminn.is|utmccn=(referral)|utmcmd=referral|utmcct=/; userstyles=off; __utmc=159157733; __utmmobile=0xd4b5e4e4320505f5; __utmb=159157733.21.10.1389609120; is_returning=1; autoLogin.disabled=true; s_cc=true; s_sq=siminnliveinnri%3D%2526pid%253Dfors%2525u00ED%2525F0a%2526pidt%253D1%2526oid%253DInnskr%2525u00E1%2526oidt%253D3%2526ot%253DSUBMIT; USER_CACHE_KEY=D6D0DCFD773406CA8EE5D690A4AF1368.tomcattf-02
Set-Cookie: JSESSIONID=1C5A65534437F3F3E4D252B8671650A6.tomcatapp-01; Path=/app/; Secure; HttpOnly

Mas de vez em quando o servidor Apache inicia novas sessões sempre que uma solicitação chega com um novo JSESSIONID, esse problema é resolvido temporariamente reiniciando o servidor web.

O mesmo comportamento acontece com o httpd 2.4.6. Log de erros LogLevel Debugpara um único cliente solicitante:

[client IP:56456] AH01964: Connection to child 714 established (server www.x.com:443)
[client IP:56456] AH02043: SSL virtual host for servername www.x.com found
[client IP:56456] AH02041: Protocol: TLSv1, Cipher: ECDHE-RSA-AES256-SHA (256/256 bits)

[client IP:56456] AH02034: Initial (No.1) HTTPS request received for child 714 (server www.x.com:443), referer: http://www.x.com/
[client IP:56456] AH01628: authorization result: granted (no directives), referer: http://www.x.com/
[client IP:56456] AH01160: Found value (J2EE4847100)ID1435349250DBfa8033a3ce4db1f64ba8d682cf8c5736533dc780End for stickysession JSESSIONID, referer: http://www.x.com/
[client IP:56456] AH01172: balancer://ssl-cluster: worker (ajp://tomcat1.x.com:9108) rewritten to ajp://tomcat1.x.com:9108/vefsms/, referer: http://www.x.com/
[client IP:56456] AH01143: Running scheme balancer handler (attempt 0), referer: http://www.x.com/
[client IP:56456] AH01113: HTTP: declining URL ajp://tomcat1.x.com:9108/vefsms/, referer: http://www.x.com/
[client IP:56456] AH00895: serving URL ajp://tomcat1.x.com:9108/vefsms/, referer: http://www.x.com/
[client IP:56456] AH00944: connecting ajp://tomcat1.x.com:9108/vefsms/ to tomcat1.x.com:9108, referer: http://www.x.com/
[client IP:56456] AH00947: connected /vefsms/ to tomcat1.x.com:9108, referer: http://www.x.com/
[client IP:56456] AH00872: APR_BUCKET_IS_EOS, referer: http://www.x.com/
[client IP:56456] AH00873: data to read (max 8186 at 4), referer: http://www.x.com/
[client IP:56456] AH00875: got 0 bytes of data, referer: http://www.x.com/
[client IP:56456] AH01384: Zlib: Compressed 2299 to 988 : URL /vefsms/, referer: http://www.x.com/
[client IP:56456] AH00892: got response from x.15:9108 (tomcat1.x.com), referer: http://www.x.com/
[client IP:56456] AH01176: proxy_balancer_post_request for (balancer://ssl-cluster), referer: http://www.x.com/

[client IP:56457] AH01964: Connection to child 707 established (server www.x.com:443)

[client IP:56456] AH02034: Subsequent (No.2) HTTPS request received for child 714 (server www.x.com:443), referer: https://www.x.com/vefsms/
[client IP:56456] AH01628: authorization result: granted (no directives), referer: https://www.x.com/vefsms/

[client IP:56457] AH02043: SSL virtual host for servername www.x.com found
[client IP:56457] AH02041: Protocol: TLSv1, Cipher: ECDHE-RSA-AES256-SHA (256/256 bits)

[client IP:56457] AH02034: Initial (No.1) HTTPS request received for child 707 (server www.x.com:443), referer: https://www.x.com/vefsms/
[client IP:56457] AH01628: authorization result: granted (no directives), referer: https://www.x.com/vefsms/

[client IP:56456] AH01160: Found value 4A0775A9DDFBFB1FE2B6AE14F62C5904.tomcat2 for stickysession JSESSIONID, referer: https://www.x.com/vefsms/
[client IP:56456] AH01161: Found route tomcat2, referer: https://www.x.com/vefsms/
[client IP:56456] AH01172: balancer://ssl-cluster: worker (ajp://tomcat2.x.com:9108) rewritten to ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/interface/Controller.js, referer: https://www.x.com/vefsms/
[client IP:56456] AH01143: Running scheme balancer handler (attempt 0), referer: https://www.x.com/vefsms/
[client IP:56456] AH01113: HTTP: declining URL ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/interface/Controller.js, referer: https://www.x.com/vefsms/
[client IP:56456] AH00895: serving URL ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/interface/Controller.js, referer: https://www.x.com/vefsms/
[client IP:56456] AH00944: connecting ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/interface/Controller.js to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/
[client IP:56456] AH00947: connected /vefsms-portlets/dwr/interface/Controller.js to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/
[client IP:56456] AH00872: APR_BUCKET_IS_EOS, referer: https://www.x.com/vefsms/
[client IP:56456] AH00873: data to read (max 8186 at 4), referer: https://www.x.com/vefsms/
[client IP:56456] AH00875: got 0 bytes of data, referer: https://www.x.com/vefsms/

[client IP:56457] AH01160: Found value 4A0775A9DDFBFB1FE2B6AE14F62C5904.tomcat2 for stickysession JSESSIONID, referer: https://www.x.com/vefsms/
[client IP:56457] AH01161: Found route tomcat2, referer: https://www.x.com/vefsms/
[client IP:56457] AH01172: balancer://ssl-cluster: worker (ajp://tomcat2.x.com:9108) rewritten to ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/
[client IP:56457] AH01143: Running scheme balancer handler (attempt 0), referer: https://www.x.com/vefsms/
[client IP:56457] AH01113: HTTP: declining URL ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/
[client IP:56457] AH00895: serving URL ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/
[client IP:56457] AH00944: connecting ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/
[client IP:56456] AH01384: Zlib: Compressed 1999 to 349 : URL /vefsms-portlets/dwr/interface/Controller.js, referer: https://www.x.com/vefsms/

[client IP:56457] AH00947: connected /vefsms-portlets/dwr/engine.js to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/

[client IP:56456] AH00892: got response from x.16:9108 (tomcat2.x.com), referer: https://www.x.com/vefsms/
[client IP:56456] AH01176: proxy_balancer_post_request for (balancer://ssl-cluster), referer: https://www.x.com/vefsms/

[client IP:56457] AH00872: APR_BUCKET_IS_EOS, referer: https://www.x.com/vefsms/
[client IP:56457] AH00873: data to read (max 8186 at 4), referer: https://www.x.com/vefsms/
[client IP:56457] AH00875: got 0 bytes of data, referer: https://www.x.com/vefsms/
[client IP:56457] AH01384: Zlib: Compressed 45758 to 11910 : URL /vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/
[client IP:56457] AH00892: got response from x.16:9108 (tomcat2.x.com), referer: https://www.x.com/vefsms/
[client IP:56457] AH01176: proxy_balancer_post_request for (balancer://ssl-cluster), referer: https://www.x.com/vefsms/
[client IP:56457] AH02034: Subsequent (No.2) HTTPS request received for child 707 (server www.x.com:443)
[client IP:56457] AH01628: authorization result: granted (no directives)
[client IP:56457] AH01160: Found value (J2EE4847100)ID1435349250DBfa8033a3ce4db1f64ba8d682cf8c5736533dc780End for stickysession JSESSIONID
[client IP:56457] AH01172: balancer://ssl-cluster: worker (ajp://tomcat1.x.com:9108) rewritten to ajp://tomcat1.x.com:9108/favicon.ico
[client IP:56457] AH01143: Running scheme balancer handler (attempt 0)
[client IP:56457] AH01113: HTTP: declining URL ajp://tomcat1.x.com:9108/favicon.ico
[client IP:56457] AH00895: serving URL ajp://tomcat1.x.com:9108/favicon.ico
[client IP:56457] AH00944: connecting ajp://tomcat1.x.com:9108/favicon.ico to tomcat1.x.com:9108
[client IP:56457] AH00947: connected /favicon.ico to tomcat1.x.com:9108
[client IP:56457] AH00872: APR_BUCKET_IS_EOS
[client IP:56457] AH00873: data to read (max 8186 at 4)
[client IP:56457] AH00875: got 0 bytes of data
[client IP:56457] AH00892: got response from x.15:9108 (tomcat1.x.com)
[client IP:56457] AH01176: proxy_balancer_post_request for (balancer://ssl-cluster)
[client IP:56457] AH02034: Subsequent (No.3) HTTPS request received for child 707 (server www.x.com:443), referer: https://www.x.com/vefsms/
[client IP:56457] AH01628: authorization result: granted (no directives), referer: https://www.x.com/vefsms/
[client IP:56457] AH01160: Found value (J2EE4847100)ID1435349250DBfa8033a3ce4db1f64ba8d682cf8c5736533dc780End for stickysession JSESSIONID, referer: https://www.x.com/vefsms/
[client IP:56457] AH01172: balancer://ssl-cluster: worker (ajp://tomcat2.x.com:9108) rewritten to ajp://tomcat2.x.com:9108/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber, referer: https://www.x.com/vefsms/
[client IP:56457] AH01143: Running scheme balancer handler (attempt 0), referer: https://www.x.com/vefsms/
[client IP:56457] AH01113: HTTP: declining URL ajp://tomcat2.x.com:9108/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber, referer: https://www.x.com/vefsms/
[client IP:56457] AH00895: serving URL ajp://tomcat2.x.com:9108/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber, referer: https://www.x.com/vefsms/
[client IP:56457] AH00944: connecting ajp://tomcat2.x.com:9108/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/
[client IP:56457] AH00947: connected /vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/
[client IP:56457] AH00873: data to read (max 8186 at 4), referer: https://www.x.com/vefsms/
[client IP:56457] AH00875: got 1 bytes of data, referer: https://www.x.com/vefsms/
[client IP:56457] AH01384: Zlib: Compressed 3032 to 1232 : URL /vefsms/, referer: https://www.x.com/vefsms/
[client IP:56457] AH00892: got response from x.16:9108 (tomcat2.x.com), referer: https://www.x.com/vefsms/
[client IP:56457] AH01176: proxy_balancer_post_request for (balancer://ssl-cluster), referer: https://www.x.com/vefsms/

[client IP:56456] AH02034: Subsequent (No.3) HTTPS request received for child 714 (server www.x.com:443), referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH01628: authorization result: granted (no directives), referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH01160: Found value 4A0775A9DDFBFB1FE2B6AE14F62C5904.tomcat2 for stickysession JSESSIONID, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH01161: Found route tomcat2, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH01172: balancer://ssl-cluster: worker (ajp://tomcat2.x.com:9108) rewritten to ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH01143: Running scheme balancer handler (attempt 0), referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH01113: HTTP: declining URL ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH00895: serving URL ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH00944: connecting ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/engine.js to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber
[client IP:56456] AH00947: connected /vefsms-portlets/dwr/engine.js to tomcat2.x.com:9108, referer: https://www.x.com/vefsms/?portal:componentId=1529&portal:type=action&portal:isSecure=false&portal:portletMode=view&action=phonenumber

Alguém viu problemas semelhantes com o uso do balanceador de proxy?

Responder1

Na verdade, parece muito difícil que o que você descreve aconteça. A rota é analisada a partir do cookie/parâmetro recebido, o que parece bastante simples, e então a rota é pesquisada nos membros do saldo. Só então ele entra na seleção de membros baseada em carga mais complexa se a rota não puder ser encontrada. Então, talvez os membros estejam caindo, causando falha na pesquisa ou o httpd perca o conhecimento dos membros do equilíbrio. Isso envolve dados compartilhados entre threads httpd, portanto é sempre uma possível causa de problemas.

Talvez tente o padrão2.2.26lançamento, para ser justo, não muito dobalanceadoroucódigo proxytemalterado desde 2.2.16. O Debian tem partes portadas, principalmente coisas de segurança, então pode haver algo estranho acontecendo lá.

Veja se você consegue reiniciar normalmente httpdenquanto LogLevel debugo problema está ocorrendo. Se o estado de erro persistir, você obterá muitos detalhes em seu log de erros sobre as seleções de membros do balanceador, o que deve lhe dar uma ideia melhor do que está acontecendo por baixo.

Falhando no registro, tente adicionar as variáveis ​​de ambiente do balanceador a uma LogFormatdefinição para obtê-las em seu arquivo access.log. Você pode rastrear melhor o que está acontecendo com eles:

\"%{BALANCER_NAME}e\"
\"%{BALANCER_WORKER_NAME}e\"
\"%{BALANCER_WORKER_ROUTE}e\"
\"%{BALANCER_SESSION_STICKY}e\"
\"%{BALANCER_SESSION_ROUTE}e\"
\"%{BALANCER_ROUTE_CHANGED}e\"

Responder2

Com base nos seus comentários, o problema real é que às vezes a sessão fixa não funciona para um cliente.

Aqui funciona:

[client IP:56456] AH01160: Found value 4A0775A9DDFBFB1FE2B6AE14F62C5904.tomcat2 for stickysession JSESSIONID, referer: https://www.x.com/vefsms/
[client IP:56456] AH01161: Found route tomcat2, referer: https://www.x.com/vefsms/
[client IP:56456] AH01172: balancer://ssl-cluster: worker (ajp://tomcat2.x.com:9108) rewritten to ajp://tomcat2.x.com:9108/vefsms-portlets/dwr/interface/Controller.js, referer: https://www.x.com/vefsms/

Aqui não funciona (nota não Found route)

[client IP:56456] AH01160: Found value (J2EE4847100)ID1435349250DBfa8033a3ce4db1f64ba8d682cf8c5736533dc780End for stickysession JSESSIONID, referer: http://www.x.com/
<------ no Found route here, so balancing decision happens instead ----->
[client IP:56456] AH01172: balancer://ssl-cluster: worker (ajp://tomcat1.x.com:9108) rewritten to ajp://tomcat1.x.com:9108/vefsms/, referer: http://www.x.com/

Evidentemente, a causa é um cookie conflitante (J2EE4847100)ID1435349250DBfa8033a3ce4db1f64ba8d682cf8c5736533dc780Endque provavelmente foi inserido no servidor do aplicativo.

informação relacionada