You are viewing a plain text version of this content. The canonical link for it is here.
Posted to bugs@httpd.apache.org by bu...@apache.org on 2018/04/20 12:18:56 UTC

[Bug 62318] New: healthcheck executed more often than configured in hcinterval

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: bugs@httpd.apache.org
          Reporter: andreas.herold@web.de
  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: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

Jim Jagielski <ji...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEW                         |NEEDINFO

--- Comment #6 from Jim Jagielski <ji...@apache.org> ---
According to my testing, the below patch seems to fix this. Can you test as
well?

    http://svn.apache.org/viewvc?rev=1838937&view=rev

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #2 from Jim Jagielski <ji...@apache.org> ---
The issue appears to be one of, mainly, interpretation of what an interval is.
As seen in the code and the documentation, the value of the interval determines
when a health check *is performed*. It does not define the time *between*
health checks, which is a separate timing entirely.

It is also assumes that the sysadmin matches the interval time with the time
taken to perform said health check and avoids such nonsense as kicking off a
check every 100ms if the health check itself takes 250ms.

Personally, I don't consider this a bug but rather expected behavior and
behavior as designed. Admittedly, the docs could make this clearer and should
be updated.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

Graham Leggett <mi...@apache.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
         Resolution|---                         |FIXED
             Status|NEW                         |RESOLVED

--- Comment #10 from Graham Leggett <mi...@apache.org> ---
Backported to v2.4.36.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #14 from John Harper <vi...@gmail.com> ---
I get a kick out of coming by your blog website. You are definitely clever and
create so well. Thanks for striving on this specific wordpress blog.
http://www.plerb.com/jerry0111

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #12 from ava james <av...@tutanota.com> ---
Your work is just excellent. I really love your work and thanks for sharing
these resources. 
https://doubleyourlineoffer.com/doubleyourline/
https://www.peryourhealthonline.com/peryourhealth/
https://www.getmyoffersonline.com/getmyoffers-capital-one/
https://mymedicalpaymentsonline.com/mymedicalpayments/
https://myaarpmedicareonline.xyz/myaarpmedicare/
https://indigo-apply.com/www-indigoapply-com/
https://www.indi-apply-go.com/indigoapply-com/

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #3 from Eric Covener <co...@gmail.com> ---
(In reply to Jim Jagielski from comment #2)
> The issue appears to be one of, mainly, interpretation of what an interval
> is. As seen in the code and the documentation, the value of the interval
> determines when a health check *is performed*. It does not define the time
> *between* health checks, which is a separate timing entirely.
> 
> It is also assumes that the sysadmin matches the interval time with the time
> taken to perform said health check and avoids such nonsense as kicking off a
> check every 100ms if the health check itself takes 250ms.

I don't think increasing the interval helps with a slow health check, since we
check every AP_WD_TM_SLICE to see if a health check has completed in the
desired interval.

If my health check takes 1 second and the interval is 10 seconds, we will still
kick off 10 health checks in rapid succession just after 10 seconds has
elapsed.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

WJCarpenter <bi...@carpenter.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
             Status|NEEDINFO                    |NEW

--- Comment #9 from WJCarpenter <bi...@carpenter.org> ---
I confirm that the patch fixed the problem in my test environment. NOTE: My
environment is 2.4.33 to which I manually made the change from the patch.

Thanks for the fix.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

WJCarpenter <bi...@carpenter.org> changed:

           What    |Removed                     |Added
----------------------------------------------------------------------------
                 CC|                            |bill-apache@carpenter.org

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #13 from jimmyjoe <3a...@emailmonkey.club> ---
Great work man. its wonderful and always pleasure to work with you. thank you. 

https://getmyoffer.live/

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #1 from WJCarpenter <bi...@carpenter.org> ---
I recently hit this problem, and I think I understand why it happens. I did a
simple proof-of-concept change to validate my theory. Although I was also
working with 2.4.33, I don't see any recent changes to suggest it's a new bug.
BTW, I saw this on a Windows 10 Enterprise machine.

The health checks are done via callbacks from the watchdog timer module. The
callback is scheduled to run every AP_WD_TM_SLICE interval. On my server,
that's 100 milliseconds (I didn't investigate whether it's 100ms for everyone).
When triggered, the callback iterates over all of the configured health checks
to see which need attention. And, for any that are "due", the health check is
performed.

In mod_proxy_hchceck.c, in function hc_watchdog_callback(), near line 928 (in
2.4.33), there is this "if" condition:

if (!PROXY_WORKER_IS(worker, PROXY_WORKER_STOPPED) &&
   (worker->s->method != NONE) &&
   (now > worker->s->updated + worker->s->interval)) {

The last part is intended to mean "if the HC interval has passed since the last
time we checked, then do a health check".

If it is "due", according to that "if" condition, the actual health check is
kicked off in function hc_check(), near line 811 (in 2.4.33). It makes the TCP
or HTTP health check call made, the results evaluated, and the "updated"
timestamp is updated.

====================

That's what the code does. Now, here is a description of the problem as I
understand it:

1. It's kind of icky to be polling every 100 ms compared to what would be a
normal health check interval [default is 60 s]. But I don't know if there is a
wiser way to do it in httpd.

2. The "if" condition and surrounding logic don't keep track of whether there
is already a health check in progress for a given target. I suppose there could
be a reason to allow multiple requests (hung connections?), but in any case it
at least contributes to this problem.

3. The "update" timestamp is updated after the health check is completed, but
it is updated with a timestamp from when the health check began. In other
words, if it takes 1000 ms for a health check call, the "updated" timestamp
will eventually be updated with a time 1000 ms in the past.

The points just mentioned conspire to keep the health check "due" on every 100
ms watchdog callback if the individual health checks take longer than 100 ms to
complete. Suppose, for example, each health check for a given target takes 1000
ms. Then there will be 9 or 10 in-progress health checks for that target. As
each finishes, it will mark the "updated" timestamp to 1000 ms in the past. The
situation will never resolve until the elapsed time for the health checks drops
below 100 ms. That's made less likely by the additional health checks
contributing to the load.

====================

To test the theory, I locally modified the hc_check() function to modify the
"updated" timestamp with the time the health check finishes instead of the time
it started. That produced the desired behavior. I have not examined that
solution for unexpected consequences.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #7 from WJCarpenter <bi...@carpenter.org> ---
The change is one of the things I tried, and it does solve the problem of
having multiple outstanding health checks for the same target. 

One of the things I was not sure about (and am still not sure about) is whether
it's better to set "updated" to the time of the beginning of the health check
or the time of the end of the health check. It's a design decision that could
go either way, depending on what you think "interval" should mean, as you
commented earlier.

I previously gave this kind of change a quick sanity test. I should be able to
do more thorough testing next week. I'll report back with the results either
way.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #11 from sandy45 <sa...@allmtr.com> ---
Companies must have the necessary computer applications to issue and receive
invoices.
There must be compatibility between the formats of the company that issues the
invoice and who receives it.
Sometimes, the system can cause delays if the staff does not know it well.
Adapting systems translates into costs for the company.
Electronic failures can cause the loss of information.

https://raizofsuccess.com/www-quickpayportal-com-29/

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #8 from Jim Jagielski <ji...@apache.org> ---
Thx. Awaiting your check. I can confirm that the patch passes my tests which
recreated the original problem

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #4 from WJCarpenter <bi...@carpenter.org> ---
Jim Jagielski, I don't understand what you are trying to say. No amount of
changing the configured interval for the health checks will alter the fact that
the watchdog timer does the callback every 100ms. In fact, the default for
hcinterval is 60s, which suggests what the module author had in mind for the
order of magnitude of that parameter.

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org


[Bug 62318] healthcheck executed more often than configured in hcinterval

Posted by bu...@apache.org.
https://bz.apache.org/bugzilla/show_bug.cgi?id=62318

--- Comment #5 from WJCarpenter <bi...@carpenter.org> ---
(sorry) I meant "the watchdog timer will consider doing the callback every
100ms"

-- 
You are receiving this mail because:
You are the assignee for the bug.
---------------------------------------------------------------------
To unsubscribe, e-mail: bugs-unsubscribe@httpd.apache.org
For additional commands, e-mail: bugs-help@httpd.apache.org