Bug 62120 - Cannot work mod_proxy when BalancerMember in httpd-vhshots.conf use hcheck module have context root '/' .
Summary: Cannot work mod_proxy when BalancerMember in httpd-vhshots.conf use hcheck mo...
Status: NEW
Alias: None
Product: Apache httpd-2
Classification: Unclassified
Component: mod_proxy (show other bugs)
Version: 2.4.28
Hardware: PC Linux
: P2 normal (vote)
Target Milestone: ---
Assignee: Apache HTTPD Bugs Mailing List
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2018-02-21 07:19 UTC by yui
Modified: 2020-01-25 18:04 UTC (History)
1 user (show)



Attachments

Note You need to log in before you can comment on or make changes to this bug.
Description yui 2018-02-21 07:19:28 UTC
Hi.
There are two problems when configuring hcheck with mod_proxy.


1. I just added "/welcome" and solved mod_proxy.
When the proxy fails, the error is "AH01170: balancer: // mycluster: All workers are in error state".
And we succeeded when we added the /welcome location.
I think it's a bug.

2. set to mod_proxy_ajp does not work. 
ex)
BalancerMember ajp://192.168.11.10:8009/welcome route=worker2 redirect=worker1 loadfactor=1 hcmethod=HEAD hcexpr=ok234 hcinterval=10
        BalancerMember ajp://192.168.11.18:8009/welcome route=worker1 redirect=worker2 loadfactor=1 hcmethod=HEAD hcexpr=ok234 hcinterval=10




Environment
os : rhel 7 or 6
apache : 2.4.28
configuration : mod_proxy, mod_hcheck, mod_watchdog 
tomcat : 8.5 or 7
configuration : unicast, session clustering 




1. Failure config file
ProxyHCTPsize 400
<VirtualHost *:80>
    ServerAdmin webmaster@dummy-host.example.com
#    DocumentRoot "/home/testweb/apache2428/docs/dummy-host.example.com"
    ServerName 192.168.11.10
#    ServerAlias www.dummy-host.example.com
    ErrorLog "logs/192.168.11.10-error_log"
    CustomLog "logs/192.168.11.10-access_log" common

        ProxyRequests Off
    ProxyPass /bmanager !

    ProxyPass / balancer://mycluster stickysession=JSESSIONID|jsessionid nofailover=Off

    ProxyPassReverse / balanacer://mycluster
    ProxyPreserveHost On

    ProxyHCExpr ok234 {%{REQUEST_STATUS} =~ /^[234]/}
    #ProxyHCExpr ok234 {%{REQUEST_STATUS} =~ /^[234]/}
    #ProxyHCExpr gdown {%{REQUEST_STATUS} =~ /^[5]/}
    #ProxyHCExpr in_maint {hc('body') !~ /Under maintenance/}

    <Proxy balancer://mycluster>
        #BalancerMember http://192.168.11.10:8080 route=worker2 redirect=worker1 loadfactor=1  hcmethod=HEAD hcexpr=ok234 hcinterval=10
        #BalancerMember http://192.168.11.18:8080 route=worker1 redirect=worker2 loadfactor=1  hcmethod=HEAD hcexpr=ok234 hcinterval=10
        BalancerMember http://192.168.11.10:8080 route=worker2 redirect=worker1 loadfactor=1 hcmethod=HEAD hcexpr=ok234 hcinterval=10
        BalancerMember http://192.168.11.18:8080 route=worker1 redirect=worker2 loadfactor=1 hcmethod=HEAD hcexpr=ok234 hcinterval=10
        ProxySet lbmethod=byrequests
        ProxySet stickysession=JSESSIONID|jsessionid
    </Proxy>

    <Proxy *>
        Order deny,allow
        Allow from all
    </Proxy>

    <Location "/bmanager">
        SetHandler balancer-manager
        Order deny,allow
        Allow from all
        # Allow from local subnet only
        #         # Allow from 192.168.11
                     </Location>
</VirtualHost>


   error_log :
[Wed Feb 21 15:26:56.437120 2018] [proxy_hcheck:debug] [pid 22271:tid 140462530627328] mod_proxy_hcheck.c(821): AH03256: Health checking http://192.168.11.10:8080
[Wed Feb 21 15:26:56.437195 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(2156): AH00942: HCOH: has acquired connection for (192.168.11.10)
[Wed Feb 21 15:26:56.437400 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(2887): AH02824: HCOH: connection established with 192.168.11.10:8080 (192.168.11.10)
[Wed Feb 21 15:26:56.437441 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(3054): AH00962: HCOH: connection complete to 192.168.11.10:8080 (192.168.11.10)
[Wed Feb 21 15:26:56.438177 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(2171): AH00943: HCOH: has released connection for (192.168.11.10)
[Wed Feb 21 15:26:56.438320 2018] [proxy_hcheck:debug] [pid 22271:tid 140462530627328] mod_proxy_hcheck.c(567): AH03251: Health check HEAD Status (1) for 2551670.
[Wed Feb 21 15:26:56.438386 2018] [proxy_hcheck:debug] [pid 22271:tid 140462530627328] mod_proxy_hcheck.c(821): AH03256: Health checking http://192.168.11.18:8080
[Wed Feb 21 15:26:56.438410 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(2156): AH00942: HCOH: has acquired connection for (192.168.11.18)
[Wed Feb 21 15:26:56.438860 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(2887): AH02824: HCOH: connection established with 192.168.11.18:8080 (192.168.11.18)
[Wed Feb 21 15:26:56.438904 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(3054): AH00962: HCOH: connection complete to 192.168.11.18:8080 (192.168.11.18)
[Wed Feb 21 15:26:56.439850 2018] [proxy:debug] [pid 22271:tid 140462530627328] proxy_util.c(2171): AH00943: HCOH: has released connection for (192.168.11.18)
[Wed Feb 21 15:26:56.440093 2018] [proxy_hcheck:debug] [pid 22271:tid 140462530627328] mod_proxy_hcheck.c(567): AH03251: Health check HEAD Status (1) for 2551d40.



[Wed Feb 21 15:27:00.564146 2018] [authz_core:debug] [pid 22271:tid 140461454542592] mod_authz_core.c(835): [client 192.168.11.25:12922] AH01628: authorization result: granted (no directives)
[Wed Feb 21 15:27:00.564226 2018] [lbmethod_byrequests:debug] [pid 22271:tid 140461454542592] mod_lbmethod_byrequests.c(97): AH01207: proxy: Entering byrequests for BALANCER (balancer://mycluster)
[Wed Feb 21 15:27:00.564232 2018] [proxy_balancer:error] [pid 22271:tid 140461454542592] [client 192.168.11.25:12922] AH01170: balancer://mycluster: All workers are in error state




2. Success config file
ProxyHCTPsize 400
<VirtualHost *:80>
    ServerAdmin webmaster@dummy-host.example.com
#    DocumentRoot "/home/testweb/apache2428/docs/dummy-host.example.com"
    ServerName 192.168.11.10
#    ServerAlias www.dummy-host.example.com
    ErrorLog "logs/192.168.11.10-error_log"
    CustomLog "logs/192.168.11.10-access_log" common

        ProxyRequests Off
    ProxyPass /bmanager !

    ProxyPass /welcome balancer://mycluster stickysession=JSESSIONID|jsessionid nofailover=Off

    ProxyPassReverse /welcome balanacer://mycluster
    ProxyPreserveHost On

    ProxyHCExpr ok234 {%{REQUEST_STATUS} =~ /^[234]/}
    #ProxyHCExpr ok234 {%{REQUEST_STATUS} =~ /^[234]/}
    #ProxyHCExpr gdown {%{REQUEST_STATUS} =~ /^[5]/}
    #ProxyHCExpr in_maint {hc('body') !~ /Under maintenance/}

    <Proxy balancer://mycluster>
        #BalancerMember http://192.168.11.10:8080 route=worker2 redirect=worker1 loadfactor=1  hcmethod=HEAD hcexpr=ok234 hcinterval=10
        #BalancerMember http://192.168.11.18:8080 route=worker1 redirect=worker2 loadfactor=1  hcmethod=HEAD hcexpr=ok234 hcinterval=10
        BalancerMember http://192.168.11.10:8080/welcome route=worker2 redirect=worker1 loadfactor=1 hcmethod=HEAD hcexpr=ok234 hcinterval=10
        BalancerMember http://192.168.11.18:8080/welcome route=worker1 redirect=worker2 loadfactor=1 hcmethod=HEAD hcexpr=ok234 hcinterval=10
        ProxySet lbmethod=byrequests
        ProxySet stickysession=JSESSIONID|jsessionid
    </Proxy>

    <Proxy *>
        Order deny,allow
        Allow from all
    </Proxy>

    <Location "/bmanager">
        SetHandler balancer-manager
        Order deny,allow
        Allow from all
        # Allow from local subnet only
        #         # Allow from 192.168.11
                     </Location>
</VirtualHost>


    error_log :
[Wed Feb 21 15:30:12.500053 2018] [proxy_hcheck:debug] [pid 23790:tid 139697309124352] mod_proxy_hcheck.c(821): AH03256: Health checking http://192.168.11.10:8080/welcome
[Wed Feb 21 15:30:12.500213 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(2156): AH00942: HCOH: has acquired connection for (192.168.11.10)
[Wed Feb 21 15:30:12.501238 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(2887): AH02824: HCOH: connection established with 192.168.11.10:8080 (192.168.11.10)
[Wed Feb 21 15:30:12.501363 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(3054): AH00962: HCOH: connection complete to 192.168.11.10:8080 (192.168.11.10)
[Wed Feb 21 15:30:12.504004 2018] [proxy_hcheck:debug] [pid 23790:tid 139697309124352] mod_proxy_hcheck.c(636): AH03254: HTTP/1.1 302
[Wed Feb 21 15:30:12.504134 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(2171): AH00943: HCOH: has released connection for (192.168.11.10)
[Wed Feb 21 15:30:12.504303 2018] [proxy_hcheck:debug] [pid 23790:tid 139697309124352] mod_proxy_hcheck.c(567): AH03251: Health check HEAD Status (0) for af9698.
[Wed Feb 21 15:30:12.504367 2018] [proxy_hcheck:debug] [pid 23790:tid 139697309124352] mod_proxy_hcheck.c(821): AH03256: Health checking http://192.168.11.18:8080/welcome
[Wed Feb 21 15:30:12.504393 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(2156): AH00942: HCOH: has acquired connection for (192.168.11.18)
[Wed Feb 21 15:30:12.505235 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(2887): AH02824: HCOH: connection established with 192.168.11.18:8080 (192.168.11.18)
[Wed Feb 21 15:30:12.505335 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(3054): AH00962: HCOH: connection complete to 192.168.11.18:8080 (192.168.11.18)
[Wed Feb 21 15:30:12.509433 2018] [proxy_hcheck:debug] [pid 23790:tid 139697309124352] mod_proxy_hcheck.c(636): AH03254: HTTP/1.1 302
[Wed Feb 21 15:30:12.509638 2018] [proxy:debug] [pid 23790:tid 139697309124352] proxy_util.c(2171): AH00943: HCOH: has released connection for (192.168.11.18)
[Wed Feb 21 15:30:12.509888 2018] [proxy_hcheck:debug] [pid 23790:tid 139697309124352] mod_proxy_hcheck.c(567): AH03251: Health check HEAD Status (0) for af9d88.
[Wed Feb 21 15:30:16.396804 2018] [authz_core:debug] [pid 23790:tid 139696778618624] mod_authz_core.c(835): [client 192.168.11.25:12962] AH01628: authorization result: granted (no directives)
[Wed Feb 21 15:30:16.396917 2018] [proxy_balancer:debug] [pid 23790:tid 139696778618624] mod_proxy_balancer.c(310): [client 192.168.11.25:12962] AH01160: Found value 75BCEA80BBADD2F2CC97E1B64CA9F4C4.worker2 for stickysession JSESSIONID
[Wed Feb 21 15:30:16.396939 2018] [proxy_balancer:debug] [pid 23790:tid 139696778618624] mod_proxy_balancer.c(321): [client 192.168.11.25:12962] AH01161: Found route worker2
[Wed Feb 21 15:30:16.396973 2018] [proxy_balancer:debug] [pid 23790:tid 139696778618624] mod_proxy_balancer.c(633): [client 192.168.11.25:12962] AH01172: balancer://mycluster: worker (http://192.168.11.10:8080/welcome) rewritten to http://192.168.11.10:8080/welcome/
[Wed Feb 21 15:30:16.396988 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(1774): AH00924: worker http://192.168.11.10:8080/welcome shared already initialized
[Wed Feb 21 15:30:16.397000 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(1816): AH00926: worker http://192.168.11.10:8080/welcome local already initialized
[Wed Feb 21 15:30:16.397011 2018] [proxy:debug] [pid 23790:tid 139696778618624] mod_proxy.c(1228): [client 192.168.11.25:12962] AH01143: Running scheme balancer handler (attempt 0)
[Wed Feb 21 15:30:16.397133 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(2156): AH00942: HTTP: has acquired connection for (192.168.11.10)
[Wed Feb 21 15:30:16.397158 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(2209): [client 192.168.11.25:12962] AH00944: connecting http://192.168.11.10:8080/welcome/ to 192.168.11.10:8080
[Wed Feb 21 15:30:16.397174 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(2418): [client 192.168.11.25:12962] AH00947: connected /welcome/ to 192.168.11.10:8080
[Wed Feb 21 15:30:16.397280 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(2719): AH00951: HTTP: backend socket is disconnected.
[Wed Feb 21 15:30:16.397413 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(2887): AH02824: HTTP: connection established with 192.168.11.10:8080 (192.168.11.10)
[Wed Feb 21 15:30:16.397446 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(3054): AH00962: HTTP: connection complete to 192.168.11.10:8080 (192.168.11.10)
[Wed Feb 21 15:30:16.403970 2018] [proxy:debug] [pid 23790:tid 139696778618624] proxy_util.c(2171): AH00943: http: has released connection for (192.168.11.10)
[Wed Feb 21 15:30:16.404030 2018] [proxy_balancer:debug] [pid 23790:tid 139696778618624] mod_proxy_balancer.c(689): [client 192.168.11.25:12962] AH01176: proxy_balancer_post_request for (balancer://mycluster)




3. tomcat webapps
[root@yui ROOT]# pwd
/home/WASB/apache-tomcat-8.5.24/webapps/ROOT
[root@yui ROOT]# ls -lrt
total 196
-rw-r----- 1 WASB WASB  2376 Nov 27 22:31 tomcat-power.gif
-rw-r----- 1 WASB WASB  5103 Nov 27 22:31 tomcat.png
-rw-r----- 1 WASB WASB  2066 Nov 27 22:31 tomcat.gif
-rw-r----- 1 WASB WASB 21630 Nov 27 22:31 favicon.ico
-rw-r----- 1 WASB WASB  3103 Nov 27 22:31 bg-upper.png
-rw-r----- 1 WASB WASB  1401 Nov 27 22:31 bg-nav.png
-rw-r----- 1 WASB WASB  1392 Nov 27 22:31 bg-nav-item.png
-rw-r----- 1 WASB WASB  1918 Nov 27 22:31 bg-middle.png
-rw-r----- 1 WASB WASB   713 Nov 27 22:31 bg-button.png
-rw-r----- 1 WASB WASB 67795 Nov 27 22:33 tomcat.svg
-rw-r----- 1 WASB WASB  5581 Nov 27 22:33 tomcat.css
-rw-r----- 1 WASB WASB  7138 Nov 27 22:33 RELEASE-NOTES.txt
-rw-r----- 1 WASB WASB 12279 Nov 27 22:33 index.jsp_back
-rw-r----- 1 WASB WASB 27235 Nov 27 22:33 asf-logo-wide.svg
drwxrwxr-x 3 WASB WASB  4096 Feb 21 10:32 welcome
-rw-r--r-- 1 WASB WASB   858 Feb 21 14:19 index.jsp
drwxr-x--- 2 WASB WASB  4096 Feb 21 14:19 WEB-INF
[root@yui ROOT]# ls -lrt welcome
total 8
drwxr-x--- 2 WASB WASB 4096 Feb 21 10:21 WEB-INF
-rw-rw-r-- 1 WASB WASB  857 Feb 21 10:23 index.jsp
Comment 1 Yann Ylavic 2018-03-11 11:22:40 UTC
(In reply to yui from comment #0)
> 
> 1. I just added "/welcome" and solved mod_proxy.
> When the proxy fails, the error is "AH01170: balancer: // mycluster: All
> workers are in error state".
> And we succeeded when we added the /welcome location.
> I think it's a bug.

We lack context here, "/welcome" is application specific, what does not work?

> 
> 2. set to mod_proxy_ajp does not work. 

AJP is not HTTP (it's a binary protocol, no "HEAD" method, ...).
As of now, hcheck is not meant/expected to work with AJP.

> 
>    error_log :

Could you pease set LogLevel to trace8?