https://bz.apache.org/bugzilla/show_bug.cgi?id=62318
Bug ID: 62318
Summary: healthcheck executed more often than configured in
hcinterval
Product: Apache httpd-2
Version: 2.4.33
Hardware: PC
OS: Linux
Status: NEW
Severity: normal
Priority: P2
Component: mod_proxy_hcheck
Assignee: [email protected]
Reporter: [email protected]
Target Milestone: ---
I'm using following configuration, expecting that one health-check will be
executed every 10 seconds on each balancer member.
#---------------
# make sure, not to act as forward proxy
ProxyRequests Off
# do not rewrite Host-Header when forwarding request
ProxyPreserveHost on
# define proxy with balancer-members and settings
<Proxy balancer://omscluster>
BalancerMember http://10.0.29.90:8180 max=5 timeout=70 retry=40
acquire=30000 route=jdevoms36.rnd.j.intershop.de_frontend hcmethod=GET
hcinterval=10 hcuri=/monitoring/services/health/status
BalancerMember http://10.0.29.96:8180 max=5 timeout=70 retry=40
acquire=30000 route=jdevoms37.rnd.j.intershop.de_frontend hcmethod=GET
hcinterval=10 hcuri=/monitoring/services/health/status
ProxySet lbmethod=bybusyness
</Proxy>
# enable balancer-manager, avoid proxying
<Location /balancer-manager>
SetHandler balancer-manager
ProxyPass !
AuthType Basic
AuthUserFile "/opt/httpd/conf/htpasswd"
AuthName "admin"
require valid-user
</Location>
# proxying everything else
ProxyPass / balancer://omscluster/ stickysession=JSESSIONID
ProxyPassReverse / balancer://omscluster/ stickysession=JSESSIONID
#------------------------
I have enabled tracing, resulting log looks like this.
[root@jdevoms29 httpd]# tail -f logs/error_log.2018-04-20_11_CET |grep
'mod_watchdog'
[Fri Apr 20 13:44:10.001381 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(454): AH010033: Watchdog: Running with
WatchdogInterval 1000ms
[Fri Apr 20 13:44:10.001393 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(462): AH02974: Watchdog: found parent
providers.
[Fri Apr 20 13:44:10.001407 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(508): AH02977: Watchdog: found child providers.
[Fri Apr 20 13:44:10.001415 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(516): AH02978: Watchdog: Looking for child
(_singleton_).
[Fri Apr 20 13:44:10.001425 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(516): AH02978: Watchdog: Looking for child
(_default_).
[Fri Apr 20 13:44:10.001435 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(516): AH02978: Watchdog: Looking for child
(_proxy_hcheck_).
[Fri Apr 20 13:44:10.001473 2018] [watchdog:debug] [pid 11386:tid
139841708402496] mod_watchdog.c(541): AH02979: Watchdog: Created child worker
thread (_proxy_hcheck_).
[Fri Apr 20 13:44:10.016816 2018] [watchdog:debug] [pid 11389:tid
139841598105344] mod_watchdog.c(158): AH02972: Singleton Watchdog
(_proxy_hcheck_) running
[Fri Apr 20 13:44:10.017861 2018] [watchdog:debug] [pid 11389:tid
139841708402496] mod_watchdog.c(588): AH02981: Watchdog: Created worker thread
(_proxy_hcheck_).
[Fri Apr 20 13:44:10.018537 2018] [watchdog:debug] [pid 11390:tid
139841708402496] mod_watchdog.c(588): AH02981: Watchdog: Created worker thread
(_proxy_hcheck_).
[Fri Apr 20 13:44:10.019052 2018] [watchdog:debug] [pid 11391:tid
139841708402496] mod_watchdog.c(588): AH02981: Watchdog: Created worker thread
(_proxy_hcheck_).
[Fri Apr 20 13:44:15.014163 2018] [watchdog:debug] [pid 11493:tid
139841708402496] mod_watchdog.c(588): AH02981: Watchdog: Created worker thread
(_proxy_hcheck_).
^C
[root@jdevoms29 httpd]# tail -f logs/error_log.2018-04-20_11_CET |grep
'AH03256: Threaded Health checking'
[Fri Apr 20 13:45:30.208536 2018] [proxy_hcheck:debug] [pid 11389:tid
139841484338944] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:45:30.208813 2018] [proxy_hcheck:debug] [pid 11389:tid
139841475946240] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:45:30.308718 2018] [proxy_hcheck:debug] [pid 11389:tid
139841492731648] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:45:40.237689 2018] [proxy_hcheck:debug] [pid 11389:tid
139841450768128] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:45:40.237948 2018] [proxy_hcheck:debug] [pid 11389:tid
139841392019200] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:45:50.269505 2018] [proxy_hcheck:debug] [pid 11389:tid
139841517909760] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:45:50.269814 2018] [proxy_hcheck:debug] [pid 11389:tid
139841459160832] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:45:50.369765 2018] [proxy_hcheck:debug] [pid 11389:tid
139841425590016] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:00.330515 2018] [proxy_hcheck:debug] [pid 11389:tid
139841408804608] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:00.330745 2018] [proxy_hcheck:debug] [pid 11389:tid
139841442375424] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:00.430916 2018] [proxy_hcheck:debug] [pid 11389:tid
139841417197312] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:00.531037 2018] [proxy_hcheck:debug] [pid 11389:tid
139841467553536] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:10.368412 2018] [proxy_hcheck:debug] [pid 11389:tid
139841433982720] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:10.368601 2018] [proxy_hcheck:debug] [pid 11389:tid
139841501124352] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:20.416752 2018] [proxy_hcheck:debug] [pid 11389:tid
139841509517056] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:20.416934 2018] [proxy_hcheck:debug] [pid 11389:tid
139841400411904] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:20.516910 2018] [proxy_hcheck:debug] [pid 11389:tid
139841484338944] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:20.617105 2018] [proxy_hcheck:debug] [pid 11389:tid
139841492731648] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:20.717236 2018] [proxy_hcheck:debug] [pid 11389:tid
139841475946240] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:30.462732 2018] [proxy_hcheck:debug] [pid 11389:tid
139841450768128] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:30.463110 2018] [proxy_hcheck:debug] [pid 11389:tid
139841392019200] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:30.562857 2018] [proxy_hcheck:debug] [pid 11389:tid
139841459160832] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:40.499302 2018] [proxy_hcheck:debug] [pid 11389:tid
139841425590016] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:40.499494 2018] [proxy_hcheck:debug] [pid 11389:tid
139841517909760] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:50.530944 2018] [proxy_hcheck:debug] [pid 11389:tid
139841408804608] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:50.531195 2018] [proxy_hcheck:debug] [pid 11389:tid
139841417197312] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.96:8180
[Fri Apr 20 13:46:50.631150 2018] [proxy_hcheck:debug] [pid 11389:tid
139841467553536] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:50.731319 2018] [proxy_hcheck:debug] [pid 11389:tid
139841442375424] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:50.831512 2018] [proxy_hcheck:debug] [pid 11389:tid
139841433982720] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:50.931690 2018] [proxy_hcheck:debug] [pid 11389:tid
139841501124352] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
[Fri Apr 20 13:46:51.031958 2018] [proxy_hcheck:debug] [pid 11389:tid
139841400411904] mod_proxy_hcheck.c(822): AH03256: Threaded Health checking
http://10.0.29.90:8180
The tracing shows only few more health-checks than configured. But identical
configuration produced much more health-checks before. Unfortunately I have
only access-logs of balancer member.
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 48 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 967 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1229 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 792 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 41 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1104 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 81 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 833 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1062 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 43 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 54 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 53 application/json
10.0.29.32 - - [16/Mar/2018:17:02:47 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1076 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 639 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 386 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1638 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 191 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 83 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1121 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 597 application/json
10.0.29.32 - - [16/Mar/2018:17:02:48 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 373 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 386 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 2119 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 2144 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1781 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 2085 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 639 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1125 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1526 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 801 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 94 application/json
10.0.29.32 - - [16/Mar/2018:17:02:49 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 700 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 681 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 64 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 953 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 988 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 962 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1181 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1282 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1172 application/json
10.0.29.32 - - [16/Mar/2018:17:02:50 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 503 635 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1204 application/json
10.0.29.32 - - [16/Mar/2018:17:02:51 +0100] 'GET
/monitoring/services/health/status HTTP/1.0' 200 518 '-' '-' '10.0.29.90:8180'
'-' 10.0.29.90 8180 HTTP/1.0 1120 application/json
--
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: [email protected]
For additional commands, e-mail: [email protected]
