Re: [mod-security-users] Apache reverse proxy timeout value
Brought to you by:
victorhora,
zimmerletw
From: homesh j. <ho...@gm...> - 2024-02-03 04:46:21
|
Dear All, This is resolved. found issue with the Backend web server not responding intermittently. No issues with apache or modsec. Thanks for all the help. Thanks, Homesh On Mon, Jan 29, 2024 at 1:18 PM Christian Folini < chr...@ne...> wrote: > Hey Homesh, > > This is very much an Apache question. Please address it to the Apache > user's mailinglist or some other Apache forum. > > With that being said, it's a very odd behavior, I have never see. > > Best, > > Christian > > On Mon, Jan 29, 2024 at 12:31:13PM +0530, homesh joshi wrote: > > Hi All, > > > > I am not sure if this is a modsec issue as I have tested it by disabling > > the modsec still I face this issue. > > I have apache setup in reverse proxy configuration with proxy timeout set > > as 20 sec. > > for one website request for /favicon.ico takes 20 sec. if I reduce the > > proxy timeout to 2 sec then request for favicon.ico takes 2 sec. I put > the > > proxy module log level to trace 8 and apache log level to debug. but > still > > i am not able to find why apache waits for timeout. Attached are the logs > > for your reference. > > > > Thanks in advance. > > Homesh > > > [Thu Jan 25 15:47:22.967833 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store > (0x61 -> subcache 1) > > [Thu Jan 25 15:47:22.967900 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(862): AH00847: insert happened at > idx=29, data=(6525:6557) > > [Thu Jan 25 15:47:22.967923 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(865): AH00848: finished insert, > subcache: idx_pos/idx_used=25/5, > > data_pos/data_used=5638/1084 > > [Thu Jan 25 15:47:22.967927 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(530): AH00834: leaving > socache_shmcb_store successfully > > [Thu Jan 25 15:47:22.968048 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(508): AH00831: socache_shmcb_store > (0xab -> subcache 11) > > [Thu Jan 25 15:47:22.968062 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(862): AH00847: insert happened at > idx=26, data=(5857:5889) > > [Thu Jan 25 15:47:22.968067 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(865): AH00848: finished insert, > subcache: idx_pos/idx_used=22/5, > > data_pos/data_used=4954/1099 > > [Thu Jan 25 15:47:22.968071 2024] [socache_shmcb:debug] [pid 5731:tid > 140199434626624] mod_socache_shmcb.c(530): AH00834: leaving > socache_shmcb_store successfully > > [Thu Jan 25 15:47:22.969591 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_kernel.c(415): [remote 1.2.3.4:58139] > AH02034: Subsequent (No.2) HTTPS request > > received for child 5394 (server play.lvu:443) > > [Thu Jan 25 15:47:22.971124 2024] [proxy:trace2] [pid 5731:tid > 140200633919040] mod_proxy.c(881): [remote 1.2.3.4:58139] AH03461: > attempting to match URI path '/favic > > on.ico' against prefix '/error/' for proxying > > [Thu Jan 25 15:47:22.971161 2024] [proxy:trace2] [pid 5731:tid > 140200633919040] mod_proxy.c(881): [remote 1.2.3.4:58139] AH03461: > attempting to match URI path '/favic > > on.ico' against prefix '/' for proxying > > [Thu Jan 25 15:47:22.971167 2024] [proxy:trace1] [pid 5731:tid > 140200633919040] mod_proxy.c(998): [remote 1.2.3.4:58139] AH03464: URI > path '/favicon.ico' matches prox > > y handler 'proxy: > https://play-lvu-205133111.ap-south-1.elb.amazonaws.com:443/favicon.ico' > > [Thu Jan 25 15:47:22.971190 2024] [authz_core:debug] [pid 5731:tid > 140200633919040] mod_authz_core.c(843): [remote 1.2.3.4:58139] AH01628: > authorization result: grant > > ed (no directives) > > [Thu Jan 25 15:47:22.975603 2024] [proxy:trace2] [pid 5731:tid > 140200633919040] proxy_util.c(2335): [remote 1.2.3.4:58139] https: found > worker https://play-lvu-20510 > > 2675.ap-south-1.elb.amazonaws.com/ for > https://play-lvu-205133111.ap-south-1.elb.amazonaws.com/favicon.ico > > [Thu Jan 25 15:47:22.975651 2024] [proxy:debug] [pid 5731:tid > 140200633919040] mod_proxy.c(1503): [remote 1.2.3.4:58139] AH01143: > Running scheme https handler (attemp > > t 0) > > [Thu Jan 25 15:47:22.975660 2024] [proxy_fcgi:debug] [pid 5731:tid > 140200633919040] mod_proxy_fcgi.c(1054): [remote 1.2.3.4:58139] AH01076: > url: https://play-lvu-205 > > 102675.ap-south-1.elb.amazonaws.com/favicon.ico proxyname: (null) > proxyport: 0 > > [Thu Jan 25 15:47:22.975666 2024] [proxy_fcgi:debug] [pid 5731:tid > 140200633919040] mod_proxy_fcgi.c(1059): [remote 1.2.3.4:58139] AH01077: > declining URL https://play > > -lvu-205133111.ap-south-1.elb.amazonaws.com/favicon.ico > > [Thu Jan 25 15:47:22.975682 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(2531): AH00942: https: has acquired > connection for (play-lvu-205133111.ap-south > > -1.elb.amazonaws.com) > > [Thu Jan 25 15:47:22.975694 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(2587): [remote 1.2.3.4:58139] AH00944: > connecting https://play-lvu-205102 > > 675.ap-south-1.elb.amazonaws.com/favicon.ico to > play-lvu-205133111.ap-south-1.elb.amazonaws.com:443 > > [Thu Jan 25 15:47:23.019184 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(2810): [remote 1.2.3.4:58139] AH00947: > connected /favicon.ico to play-lvu > > -205133111.ap-south-1.elb.amazonaws.com:443 > > [Thu Jan 25 15:47:23.019277 2024] [proxy:trace2] [pid 5731:tid > 140200633919040] proxy_util.c(3244): https: fam 2 socket created to connect > to play-lvu-205133111.ap-south-1 > > .elb.amazonaws.com > > [Thu Jan 25 15:47:43.039441 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(3267): (70007)The timeout specified has > expired: AH00957: https: attempt to conn > > ect to 3.111.227.162:443 ( > play-lvu-205133111.ap-south-1.elb.amazonaws.com) failed > > [Thu Jan 25 15:47:43.039558 2024] [proxy:trace2] [pid 5731:tid > 140200633919040] proxy_util.c(3244): https: fam 2 socket created to connect > to play-lvu-205133111.ap-south-1 > > .elb.amazonaws.com > > [Thu Jan 25 15:47:43.057570 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(3276): AH02824: https: connection established > with 3.109.6.57:443 (play-lvu-205 > > 102675.ap-south-1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.057649 2024] [proxy:trace1] [pid 5731:tid > 140200633919040] proxy_util.c(3450): [remote 3.109.6.57:443] https: set > SNI to play.lvu for (play-lvu-20510 > > 2675.ap-south-1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.057655 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(3462): AH00962: https: connection complete to > 3.111.227.162:443 (play-lvu-20510 > > 2675.ap-south-1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.057663 2024] [qos:debug] [pid 5731:tid > 140200633919040] apache2/mod_qos.c(8587): mod_qos(): skip processing of > outgoing connection 3.109.6.57<->165.232 > > .187.180 > > [Thu Jan 25 15:47:43.057669 2024] [ssl:info] [pid 5731:tid > 140200633919040] [remote 3.109.6.57:443] AH01964: Connection to child 0 > established (server play.lvu:443) > > [Thu Jan 25 15:47:43.078549 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_kernel.c(1764): [remote 3.109.6.57:443] > AH02275: Certificate Verification, depth 3, > > CRL checking mode: none (0) [subject: CN=Starfield Services Root > Certificate Authority - G2,O=Starfield Technologies\\, > Inc.,L=Scottsdale,ST=Arizona,C=US / issuer: OU=Starf > > ield Class 2 Certification Authority,O=Starfield Technologies\\, > Inc.,C=US / serial: A70E4A4C3482B77F / notbefore: Sep 2 00:00:00 2009 GMT > / notafter: Jun 28 17:39:16 2034 > > GMT] > > [Thu Jan 25 15:47:43.078695 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_kernel.c(1764): [remote 3.109.6.57:443] > AH02275: Certificate Verification, depth 2, > > CRL checking mode: none (0) [subject: CN=Amazon Root CA 1,O=Amazon,C=US > / issuer: CN=Starfield Services Root Certificate Authority - G2,O=Starfield > Technologies\\, Inc.,L=S > > cottsdale,ST=Arizona,C=US / serial: > 067F944A2A27CDF3FAC2AE2B01F908EEB9C4C6 / notbefore: May 25 12:00:00 2015 > GMT / notafter: Dec 31 01:00:00 2037 GMT] > > [Thu Jan 25 15:47:43.078779 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_kernel.c(1764): [remote 3.109.6.57:443] > AH02275: Certificate Verification, depth 1, > > CRL checking mode: none (0) [subject: CN=Amazon RSA 2048 > M01,O=Amazon,C=US / issuer: CN=Amazon Root CA 1,O=Amazon,C=US / serial: > 077312380B9D6688A33B1ED9BF9CCDA68E0E0F / no > > tbefore: Aug 23 22:21:28 2022 GMT / notafter: Aug 23 22:21:28 2030 GMT] > > [Thu Jan 25 15:47:43.078863 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_kernel.c(1764): [remote 3.109.6.57:443] > AH02275: Certificate Verification, depth 0, > > CRL checking mode: none (0) [subject: CN=play.lvu / issuer: CN=Amazon > RSA 2048 M01,O=Amazon,C=US / serial: 088DB8B2694138D3A4624BF0EEFF3856 / > notbefore: Oct 11 00:00:00 20 > > 23 GMT / notafter: Nov 8 23:59:59 2024 GMT] > > [Thu Jan 25 15:47:43.079137 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_kernel.c(2254): [remote 3.109.6.57:443] > AH02041: Protocol: TLSv1.3, Cipher: TLS_AES_ > > 128_GCM_SHA256 (128/128 bits) > > [Thu Jan 25 15:47:43.079199 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_util_ssl.c(451): AH02412: [play.lvu:443] Cert matches > for name 'play.lvu' [subject: CN=kl > > ay.lvu / issuer: CN=Amazon RSA 2048 M01,O=Amazon,C=US / serial: > 088DB8B2694138D3A4624BF0EEFF3856 / notbefore: Oct 11 00:00:00 2023 GMT / > notafter: Nov 8 23:59:59 2024 GMT > > ] > > [Thu Jan 25 15:47:43.100903 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(2546): AH00943: https: has released > connection for (play-lvu-205133111.ap-south > > -1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.100989 2024] [ssl:debug] [pid 5731:tid > 140200633919040] ssl_engine_io.c(1147): [remote 3.109.6.57:443] AH02001: > Connection closed to child 0 with stand > > ard shutdown (server play.lvu:443) > > [Thu Jan 25 15:47:43.101088 2024] [proxy:debug] [pid 5731:tid > 140200633919040] proxy_util.c(3386): [remote 3.109.6.57:443] AH02642: > proxy: connection shutdown > > [Thu Jan 25 15:47:43.863505 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_kernel.c(415): [remote 1.2.3.4:58139] > AH02034: Subsequent (No.2) HTTPS request > > received for child 1808 (server play.lvu:443), referer: > https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.865077 2024] [proxy:trace2] [pid 5731:tid > 140200650737216] mod_proxy.c(881): [remote 1.2.3.4:58139] AH03461: > attempting to match URI path '/favic > > on.ico' against prefix '/error/' for proxying, referer: > https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.865165 2024] [proxy:trace2] [pid 5731:tid > 140200650737216] mod_proxy.c(881): [remote 1.2.3.4:58139] AH03461: > attempting to match URI path '/favic > > on.ico' against prefix '/' for proxying, referer: > https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.865192 2024] [proxy:trace1] [pid 5731:tid > 140200650737216] mod_proxy.c(998): [remote 1.2.3.4:58139] AH03464: URI > path '/favicon.ico' matches prox > > y handler 'proxy: > https://play-lvu-205133111.ap-south-1.elb.amazonaws.com:443/favicon.ico', > referer: https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.865231 2024] [authz_core:debug] [pid 5731:tid > 140200650737216] mod_authz_core.c(843): [remote 1.2.3.4:58139] AH01628: > authorization result: grant > > ed (no directives), referer: https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868082 2024] [proxy:trace2] [pid 5731:tid > 140200650737216] proxy_util.c(2335): [remote 1.2.3.4:58139] https: found > worker https://play-lvu-20510 > > 2675.ap-south-1.elb.amazonaws.com/ for > https://play-lvu-205133111.ap-south-1.elb.amazonaws.com/favicon.ico, > referer: https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868164 2024] [proxy:debug] [pid 5731:tid > 140200650737216] mod_proxy.c(1503): [remote 1.2.3.4:58139] AH01143: > Running scheme https handler (attemp > > t 0), referer: https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868198 2024] [proxy_fcgi:debug] [pid 5731:tid > 140200650737216] mod_proxy_fcgi.c(1054): [remote 1.2.3.4:58139] AH01076: > url: https://play-lvu-205 > > 102675.ap-south-1.elb.amazonaws.com/favicon.ico proxyname: (null) > proxyport: 0, referer: https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868223 2024] [proxy_fcgi:debug] [pid 5731:tid > 140200650737216] mod_proxy_fcgi.c(1059): [remote 1.2.3.4:58139] AH01077: > declining URL https://play > > -lvu-205133111.ap-south-1.elb.amazonaws.com/favicon.ico, referer: > https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868248 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(2531): AH00942: https: has acquired > connection for (play-lvu-205133111.ap-south > > -1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.868273 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(2587): [remote 1.2.3.4:58139] AH00944: > connecting https://play-lvu-205102 > > 675.ap-south-1.elb.amazonaws.com/favicon.ico to > play-lvu-205133111.ap-south-1.elb.amazonaws.com:443, referer: > https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868630 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(2810): [remote 1.2.3.4:58139] AH00947: > connected /favicon.ico to play-lvu > > -205133111.ap-south-1.elb.amazonaws.com:443, referer: > https://play.lvu/favicon.ico > > [Thu Jan 25 15:47:43.868704 2024] [proxy:trace2] [pid 5731:tid > 140200650737216] proxy_util.c(3244): https: fam 2 socket created to connect > to play-lvu-205133111.ap-south-1 > > .elb.amazonaws.com > > [Thu Jan 25 15:47:43.894557 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(3276): AH02824: https: connection established > with 3.109.172.68:443 (play-lvu-2 > > 05102675.ap-south-1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.894681 2024] [proxy:trace1] [pid 5731:tid > 140200650737216] proxy_util.c(3450): [remote 3.109.172.68:443] https: set > SNI to play.lvu for (play-lvu-205 > > 102675.ap-south-1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.894708 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(3462): AH00962: https: connection complete to > 3.109.172.68:443 (play-lvu-205102 > > 675.ap-south-1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.894748 2024] [qos:debug] [pid 5731:tid > 140200650737216] apache2/mod_qos.c(8587): mod_qos(): skip processing of > outgoing connection 3.109.172.68<->165.2 > > 32.187.180 > > [Thu Jan 25 15:47:43.894770 2024] [ssl:info] [pid 5731:tid > 140200650737216] [remote 3.109.172.68:443] AH01964: Connection to child 0 > established (server play.lvu:443) > > [Thu Jan 25 15:47:43.923819 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_kernel.c(1764): [remote 3.109.172.68:443] > AH02275: Certificate Verification, depth 3 > > , CRL checking mode: none (0) [subject: CN=Starfield Services Root > Certificate Authority - G2,O=Starfield Technologies\\, > Inc.,L=Scottsdale,ST=Arizona,C=US / issuer: OU=Sta > > rfield Class 2 Certification Authority,O=Starfield Technologies\\, > Inc.,C=US / serial: A70E4A4C3482B77F / notbefore: Sep 2 00:00:00 2009 GMT > / notafter: Jun 28 17:39:16 20 > > 34 GMT] > > [Thu Jan 25 15:47:43.924033 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_kernel.c(1764): [remote 3.109.172.68:443] > AH02275: Certificate Verification, depth 2 > > , CRL checking mode: none (0) [subject: CN=Amazon Root CA > 1,O=Amazon,C=US / issuer: CN=Starfield Services Root Certificate Authority > - G2,O=Starfield Technologies\\, Inc.,L > > =Scottsdale,ST=Arizona,C=US / serial: > 067F944A2A27CDF3FAC2AE2B01F908EEB9C4C6 / notbefore: May 25 12:00:00 2015 > GMT / notafter: Dec 31 01:00:00 2037 GMT] > > [Thu Jan 25 15:47:43.924124 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_kernel.c(1764): [remote 3.109.172.68:443] > AH02275: Certificate Verification, depth 1 > > , CRL checking mode: none (0) [subject: CN=Amazon RSA 2048 > M01,O=Amazon,C=US / issuer: CN=Amazon Root CA 1,O=Amazon,C=US / serial: > 077312380B9D6688A33B1ED9BF9CCDA68E0E0F / > > notbefore: Aug 23 22:21:28 2022 GMT / notafter: Aug 23 22:21:28 2030 GMT] > > [Thu Jan 25 15:47:43.924208 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_kernel.c(1764): [remote 3.109.172.68:443] > AH02275: Certificate Verification, depth 0 > > , CRL checking mode: none (0) [subject: CN=play.lvu / issuer: CN=Amazon > RSA 2048 M01,O=Amazon,C=US / serial: 088DB8B2694138D3A4624BF0EEFF3856 / > notbefore: Oct 11 00:00:00 > > 2023 GMT / notafter: Nov 8 23:59:59 2024 GMT] > > [Thu Jan 25 15:47:43.924468 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_kernel.c(2254): [remote 3.109.172.68:443] > AH02041: Protocol: TLSv1.3, Cipher: TLS_AE > > S_128_GCM_SHA256 (128/128 bits) > > [Thu Jan 25 15:47:43.924535 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_util_ssl.c(451): AH02412: [play.lvu:443] Cert matches > for name 'play.lvu' [subject: CN=kl > > ay.lvu / issuer: CN=Amazon RSA 2048 M01,O=Amazon,C=US / serial: > 088DB8B2694138D3A4624BF0EEFF3856 / notbefore: Oct 11 00:00:00 2023 GMT / > notafter: Nov 8 23:59:59 2024 GMT > > ] > > [Thu Jan 25 15:47:43.959108 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(2546): AH00943: https: has released > connection for (play-lvu-205133111.ap-south > > -1.elb.amazonaws.com) > > [Thu Jan 25 15:47:43.959261 2024] [ssl:debug] [pid 5731:tid > 140200650737216] ssl_engine_io.c(1147): [remote 3.109.172.68:443] > AH02001: Connection closed to child 0 with sta > > ndard shutdown (server play.lvu:443) > > [Thu Jan 25 15:47:43.959361 2024] [proxy:debug] [pid 5731:tid > 140200650737216] proxy_util.c(3386): [remote 3.109.172.68:443] AH02642: > proxy: connection shutdown > > [Thu Jan 25 15:47:48.965114 2024] [ssl:debug] [pid 5731:tid > 140199476590144] ssl_engine_io.c(1147): [client 1.2.3.4:58139] AH02001: > Connection closed to child 16 with > > standard shutdown (server play.lvu:443) > > > > > > > > ▸ > > > > _______________________________________________ > > mod-security-users mailing list > > mod...@li... > > https://lists.sourceforge.net/lists/listinfo/mod-security-users > > Commercial ModSecurity Rules and Support from Trustwave's SpiderLabs: > > http://www.modsecurity.org/projects/commercial/rules/ > > http://www.modsecurity.org/projects/commercial/support/ > > > > _______________________________________________ > mod-security-users mailing list > mod...@li... > https://lists.sourceforge.net/lists/listinfo/mod-security-users > Commercial ModSecurity Rules and Support from Trustwave's SpiderLabs: > http://www.modsecurity.org/projects/commercial/rules/ > http://www.modsecurity.org/projects/commercial/support/ > |