https://bz.apache.org/bugzilla/show_bug.cgi?id=66290
Bug ID: 66290
Summary: ErrorDocument is not sent when mod_security changes
error code in phase 3/4
Product: Apache httpd-2
Version: 2.4.53
Hardware: PC
OS: Linux
Status: NEW
Severity: normal
Priority: P2
Component: Core
Assignee: bugs@httpd.apache.org
Reporter: aogburn@redhat.com
Target Milestone: ---
Using a simplified config like this with mod_security:
ProxyPass /helloworld http://unavailablesite/helloworld
ErrorDocument 403 /forbidden.html
SecRule RESPONSE_PROTOCOL "@contains HTTP"
"id:'4',phase:4,auditlog,log,deny,status:403,msg:'yay!'"
One would expect for mod_security to override the 503 with a 403 and provide
the custom 403 ErrorDocument. (More realistic scenarios are using the core
rule set, which will change a 5xx level response code to a 403 at paranoia
level 2)
The response code is changed to 403, but it suggests the ErrorDocument can't be
served:
<html><head>
<title>403 Forbidden</title>
</head><body>
<h1>Forbidden</h1>
<p>You don't have permission to access this resource.</p>
<p>Additionally, a 503 Service Unavailable
error was encountered while trying to use an ErrorDocument to handle the
request.</p>
</body></html>
If you do proxy through to the backend and that returns another error code like
500, then this reports that 500 (or whatever from the backend) was encountered
instead while serving the ErrorDocument. If you test a local page that would
return a 200, then mod_security can set the 403 and serve out the
ErrorDocument.
From logs and backtracking, I see no indication that the ErrorDocument is
attempted and no ap_internal_redirect call. So stepping through logs and
backtraces, the proxy connection fails and the processing steps into ap_die.
No ErrorDocument is set for this code so it falls through:
===
[Fri Sep 30 17:38:22.633786 2022] [proxy_fcgi:debug] [pid 73359]
mod_proxy_fcgi.c(1021): [client 127.0.0.1:32980] AH01076: url:
http://127.0.0.1:8080/helloworld/foo proxyname: (null) proxyport: 0
[Fri Sep 30 17:38:22.633794 2022] [proxy_fcgi:debug] [pid 73359]
mod_proxy_fcgi.c(1024): [client 127.0.0.1:32980] AH01077: declining URL
http://127.0.0.1:8080/helloworld/foo
[Fri Sep 30 17:38:22.633803 2022] [proxy_http:trace1] [pid 73359]
mod_proxy_http.c(1978): [client 127.0.0.1:32980] HTTP: serving URL
http://127.0.0.1:8080/helloworld/foo
[Fri Sep 30 17:38:22.633812 2022] [proxy:debug] [pid 73359] proxy_util.c(2353):
AH00942: HTTP: has acquired connection for (127.0.0.1)
[Fri Sep 30 17:38:22.633822 2022] [proxy:debug] [pid 73359] proxy_util.c(2408):
[client 127.0.0.1:32980] AH00944: connecting
http://127.0.0.1:8080/helloworld/foo to 127.0.0.1:8080
[Fri Sep 30 17:38:22.633833 2022] [proxy:debug] [pid 73359] proxy_util.c(2634):
[client 127.0.0.1:32980] AH00947: connected /helloworld/foo to 127.0.0.1:8080
[Fri Sep 30 17:38:22.633896 2022] [proxy:trace2] [pid 73359]
proxy_util.c(3070): HTTP: fam 2 socket created to connect to 127.0.0.1
[Fri Sep 30 17:38:22.634041 2022] [proxy:error] [pid 73359] (111)Connection
refused: AH00957: HTTP: attempt to connect to 127.0.0.1:8080 (127.0.0.1) failed
[Fri Sep 30 17:38:22.634062 2022] [proxy_http:error] [pid 73359] [client
127.0.0.1:32980] AH01114: HTTP: failed to make connection to backend: 127.0.0.1
[Fri Sep 30 17:38:22.634071 2022] [proxy:debug] [pid 73359] proxy_util.c(2368):
AH00943: HTTP: has released connection for (127.0.0.1)
(gdb) bt
#0 0x0000561b30a2db70 in ap_die_r ()
#1 0x0000561b30a2e627 in ap_process_async_request ()
#2 0x0000561b30a2e9c2 in ap_process_request ()
#3 0x0000561b30a2abe5 in ap_process_http_connection ()
#4 0x0000561b30a210c8 in ap_run_process_connection ()
#5 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#6 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#7 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#8 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#9 0x0000561b309f915e in ap_run_mpm ()
#10 0x0000561b309f1733 in main ()
#0 0x0000561b30a082c0 in ap_response_code_string ()
#1 0x0000561b30a2de26 in ap_die_r ()
#2 0x0000561b30a2e627 in ap_process_async_request ()
#3 0x0000561b30a2e9c2 in ap_process_request ()
#4 0x0000561b30a2abe5 in ap_process_http_connection ()
#5 0x0000561b30a210c8 in ap_run_process_connection ()
#6 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#7 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#8 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#9 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#10 0x0000561b309f915e in ap_run_mpm ()
#11 0x0000561b309f1733 in main ()
Thread 1 "httpd" hit Breakpoint 3, 0x0000561b30a082c0 in
ap_response_code_string ()
(gdb) bt
#0 0x0000561b30a082c0 in ap_response_code_string ()
#1 0x0000561b30a2c944 in ap_send_error_response ()
#2 0x0000561b30a2e627 in ap_process_async_request ()
#3 0x0000561b30a2e9c2 in ap_process_request ()
#4 0x0000561b30a2abe5 in ap_process_http_connection ()
#5 0x0000561b30a210c8 in ap_run_process_connection ()
#6 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#7 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#8 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#9 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#10 0x0000561b309f915e in ap_run_mpm ()
#11 0x0000561b309f1733 in main ()
===
After those points, mod_security sets its 403. ap_die_r is called again out of
ap_http_header_filter. It never hits ap_response_code_string in this ap_die_r
call though to fetch the ErrorDocument for this 403:
===
[Fri Sep 30 17:41:05.331091 2022] [:error] [pid 73359] [client 127.0.0.1:32980]
[client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 4). String
match "HTTP" at RESPONSE_PROTOCOL. [file "/etc/httpd/conf.d/mod_security.conf"]
[line "62"] [id "4"] [msg "yay!"] [hostname "localhost"] [uri
"/helloworld/foo"] [unique_id "AAAAAMGZhzPXJ45OHYQdKAAAAAA"]
#0 0x0000561b30a2db70 in ap_die_r ()
#1 0x0000561b30a31b74 in ap_http_header_filter ()
#2 0x0000561b309ff1b6 in ap_content_length_filter ()
#3 0x0000561b30a32e81 in ap_byterange_filter ()
#4 0x00007f3c0b475bae in send_error_bucket (msr=msr@entry=0x561b31e220a0,
f=f@entry=0x561b31e15210, status=status@entry=403) at apache2_util.c:43
#5 0x00007f3c0b4758a3 in output_filter (f=0x561b31e15210, bb_in=<optimized
out>) at apache2_io.c:999
#6 0x0000561b309fced2 in end_output_stream ()
#7 0x0000561b30a2ca30 in ap_send_error_response ()
#8 0x0000561b30a2e627 in ap_process_async_request ()
#9 0x0000561b30a2e9c2 in ap_process_request ()
#10 0x0000561b30a2abe5 in ap_process_http_connection ()
#11 0x0000561b30a210c8 in ap_run_process_connection ()
#12 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#13 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#14 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#15 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#16 0x0000561b309f915e in ap_run_mpm ()
#17 0x0000561b309f1733 in main ()
Thread 1 "httpd" hit Breakpoint 3, 0x0000561b30a082c0 in
ap_response_code_string ()
(gdb) bt
#0 0x0000561b30a082c0 in ap_response_code_string ()
#1 0x0000561b30a2c944 in ap_send_error_response ()
#2 0x0000561b30a31b74 in ap_http_header_filter ()
#3 0x0000561b309ff1b6 in ap_content_length_filter ()
#4 0x0000561b30a32e81 in ap_byterange_filter ()
#5 0x00007f3c0b475bae in send_error_bucket (msr=msr@entry=0x561b31e220a0,
f=f@entry=0x561b31e15210, status=status@entry=403) at apache2_util.c:43
#6 0x00007f3c0b4758a3 in output_filter (f=0x561b31e15210, bb_in=<optimized
out>) at apache2_io.c:999
#7 0x0000561b309fced2 in end_output_stream ()
#8 0x0000561b30a2ca30 in ap_send_error_response ()
#9 0x0000561b30a2e627 in ap_process_async_request ()
#10 0x0000561b30a2e9c2 in ap_process_request ()
#11 0x0000561b30a2abe5 in ap_process_http_connection ()
#12 0x0000561b30a210c8 in ap_run_process_connection ()
#13 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#14 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#15 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#16 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#17 0x0000561b309f915e in ap_run_mpm ()
#18 0x0000561b309f1733 in main ()
===
So it looks like mod_security through phase 3/4 will result in the 403 being
set in the course of ap_http_header_filter calls. That means this calls ap_die
here passing in the 403 and also 503 on the request originally:
https://github.com/apache/httpd/blob/2.4.37/modules/http/http_filters.c#L1374
That 503 is then picked up here in ap_die_r as a recursive_error so that it
skips the ap_response_code_string call in its else and the ErrorDocument is not
served as a result:
https://github.com/apache/httpd/blob/3ec0ffb9e1ac05622b97a7afd6992dd2bd41ce38/modules/http/http_request.c#L127
So the ErrorDocument works for a page that originally had a 200 since there is
not a recursive_error seen by ap_die_r in that case.
--
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 ID: 66290
Summary: ErrorDocument is not sent when mod_security changes
error code in phase 3/4
Product: Apache httpd-2
Version: 2.4.53
Hardware: PC
OS: Linux
Status: NEW
Severity: normal
Priority: P2
Component: Core
Assignee: bugs@httpd.apache.org
Reporter: aogburn@redhat.com
Target Milestone: ---
Using a simplified config like this with mod_security:
ProxyPass /helloworld http://unavailablesite/helloworld
ErrorDocument 403 /forbidden.html
SecRule RESPONSE_PROTOCOL "@contains HTTP"
"id:'4',phase:4,auditlog,log,deny,status:403,msg:'yay!'"
One would expect for mod_security to override the 503 with a 403 and provide
the custom 403 ErrorDocument. (More realistic scenarios are using the core
rule set, which will change a 5xx level response code to a 403 at paranoia
level 2)
The response code is changed to 403, but it suggests the ErrorDocument can't be
served:
<html><head>
<title>403 Forbidden</title>
</head><body>
<h1>Forbidden</h1>
<p>You don't have permission to access this resource.</p>
<p>Additionally, a 503 Service Unavailable
error was encountered while trying to use an ErrorDocument to handle the
request.</p>
</body></html>
If you do proxy through to the backend and that returns another error code like
500, then this reports that 500 (or whatever from the backend) was encountered
instead while serving the ErrorDocument. If you test a local page that would
return a 200, then mod_security can set the 403 and serve out the
ErrorDocument.
From logs and backtracking, I see no indication that the ErrorDocument is
attempted and no ap_internal_redirect call. So stepping through logs and
backtraces, the proxy connection fails and the processing steps into ap_die.
No ErrorDocument is set for this code so it falls through:
===
[Fri Sep 30 17:38:22.633786 2022] [proxy_fcgi:debug] [pid 73359]
mod_proxy_fcgi.c(1021): [client 127.0.0.1:32980] AH01076: url:
http://127.0.0.1:8080/helloworld/foo proxyname: (null) proxyport: 0
[Fri Sep 30 17:38:22.633794 2022] [proxy_fcgi:debug] [pid 73359]
mod_proxy_fcgi.c(1024): [client 127.0.0.1:32980] AH01077: declining URL
http://127.0.0.1:8080/helloworld/foo
[Fri Sep 30 17:38:22.633803 2022] [proxy_http:trace1] [pid 73359]
mod_proxy_http.c(1978): [client 127.0.0.1:32980] HTTP: serving URL
http://127.0.0.1:8080/helloworld/foo
[Fri Sep 30 17:38:22.633812 2022] [proxy:debug] [pid 73359] proxy_util.c(2353):
AH00942: HTTP: has acquired connection for (127.0.0.1)
[Fri Sep 30 17:38:22.633822 2022] [proxy:debug] [pid 73359] proxy_util.c(2408):
[client 127.0.0.1:32980] AH00944: connecting
http://127.0.0.1:8080/helloworld/foo to 127.0.0.1:8080
[Fri Sep 30 17:38:22.633833 2022] [proxy:debug] [pid 73359] proxy_util.c(2634):
[client 127.0.0.1:32980] AH00947: connected /helloworld/foo to 127.0.0.1:8080
[Fri Sep 30 17:38:22.633896 2022] [proxy:trace2] [pid 73359]
proxy_util.c(3070): HTTP: fam 2 socket created to connect to 127.0.0.1
[Fri Sep 30 17:38:22.634041 2022] [proxy:error] [pid 73359] (111)Connection
refused: AH00957: HTTP: attempt to connect to 127.0.0.1:8080 (127.0.0.1) failed
[Fri Sep 30 17:38:22.634062 2022] [proxy_http:error] [pid 73359] [client
127.0.0.1:32980] AH01114: HTTP: failed to make connection to backend: 127.0.0.1
[Fri Sep 30 17:38:22.634071 2022] [proxy:debug] [pid 73359] proxy_util.c(2368):
AH00943: HTTP: has released connection for (127.0.0.1)
(gdb) bt
#0 0x0000561b30a2db70 in ap_die_r ()
#1 0x0000561b30a2e627 in ap_process_async_request ()
#2 0x0000561b30a2e9c2 in ap_process_request ()
#3 0x0000561b30a2abe5 in ap_process_http_connection ()
#4 0x0000561b30a210c8 in ap_run_process_connection ()
#5 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#6 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#7 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#8 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#9 0x0000561b309f915e in ap_run_mpm ()
#10 0x0000561b309f1733 in main ()
#0 0x0000561b30a082c0 in ap_response_code_string ()
#1 0x0000561b30a2de26 in ap_die_r ()
#2 0x0000561b30a2e627 in ap_process_async_request ()
#3 0x0000561b30a2e9c2 in ap_process_request ()
#4 0x0000561b30a2abe5 in ap_process_http_connection ()
#5 0x0000561b30a210c8 in ap_run_process_connection ()
#6 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#7 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#8 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#9 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#10 0x0000561b309f915e in ap_run_mpm ()
#11 0x0000561b309f1733 in main ()
Thread 1 "httpd" hit Breakpoint 3, 0x0000561b30a082c0 in
ap_response_code_string ()
(gdb) bt
#0 0x0000561b30a082c0 in ap_response_code_string ()
#1 0x0000561b30a2c944 in ap_send_error_response ()
#2 0x0000561b30a2e627 in ap_process_async_request ()
#3 0x0000561b30a2e9c2 in ap_process_request ()
#4 0x0000561b30a2abe5 in ap_process_http_connection ()
#5 0x0000561b30a210c8 in ap_run_process_connection ()
#6 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#7 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#8 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#9 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#10 0x0000561b309f915e in ap_run_mpm ()
#11 0x0000561b309f1733 in main ()
===
After those points, mod_security sets its 403. ap_die_r is called again out of
ap_http_header_filter. It never hits ap_response_code_string in this ap_die_r
call though to fetch the ErrorDocument for this 403:
===
[Fri Sep 30 17:41:05.331091 2022] [:error] [pid 73359] [client 127.0.0.1:32980]
[client 127.0.0.1] ModSecurity: Access denied with code 403 (phase 4). String
match "HTTP" at RESPONSE_PROTOCOL. [file "/etc/httpd/conf.d/mod_security.conf"]
[line "62"] [id "4"] [msg "yay!"] [hostname "localhost"] [uri
"/helloworld/foo"] [unique_id "AAAAAMGZhzPXJ45OHYQdKAAAAAA"]
#0 0x0000561b30a2db70 in ap_die_r ()
#1 0x0000561b30a31b74 in ap_http_header_filter ()
#2 0x0000561b309ff1b6 in ap_content_length_filter ()
#3 0x0000561b30a32e81 in ap_byterange_filter ()
#4 0x00007f3c0b475bae in send_error_bucket (msr=msr@entry=0x561b31e220a0,
f=f@entry=0x561b31e15210, status=status@entry=403) at apache2_util.c:43
#5 0x00007f3c0b4758a3 in output_filter (f=0x561b31e15210, bb_in=<optimized
out>) at apache2_io.c:999
#6 0x0000561b309fced2 in end_output_stream ()
#7 0x0000561b30a2ca30 in ap_send_error_response ()
#8 0x0000561b30a2e627 in ap_process_async_request ()
#9 0x0000561b30a2e9c2 in ap_process_request ()
#10 0x0000561b30a2abe5 in ap_process_http_connection ()
#11 0x0000561b30a210c8 in ap_run_process_connection ()
#12 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#13 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#14 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#15 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#16 0x0000561b309f915e in ap_run_mpm ()
#17 0x0000561b309f1733 in main ()
Thread 1 "httpd" hit Breakpoint 3, 0x0000561b30a082c0 in
ap_response_code_string ()
(gdb) bt
#0 0x0000561b30a082c0 in ap_response_code_string ()
#1 0x0000561b30a2c944 in ap_send_error_response ()
#2 0x0000561b30a31b74 in ap_http_header_filter ()
#3 0x0000561b309ff1b6 in ap_content_length_filter ()
#4 0x0000561b30a32e81 in ap_byterange_filter ()
#5 0x00007f3c0b475bae in send_error_bucket (msr=msr@entry=0x561b31e220a0,
f=f@entry=0x561b31e15210, status=status@entry=403) at apache2_util.c:43
#6 0x00007f3c0b4758a3 in output_filter (f=0x561b31e15210, bb_in=<optimized
out>) at apache2_io.c:999
#7 0x0000561b309fced2 in end_output_stream ()
#8 0x0000561b30a2ca30 in ap_send_error_response ()
#9 0x0000561b30a2e627 in ap_process_async_request ()
#10 0x0000561b30a2e9c2 in ap_process_request ()
#11 0x0000561b30a2abe5 in ap_process_http_connection ()
#12 0x0000561b30a210c8 in ap_run_process_connection ()
#13 0x00007f3c11be6e71 in child_main () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#14 0x00007f3c11be7174 in make_child () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#15 0x00007f3c11be71cf in startup_children () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#16 0x00007f3c11be7db3 in prefork_run () from
target:/etc/httpd/modules/mod_mpm_prefork.so
#17 0x0000561b309f915e in ap_run_mpm ()
#18 0x0000561b309f1733 in main ()
===
So it looks like mod_security through phase 3/4 will result in the 403 being
set in the course of ap_http_header_filter calls. That means this calls ap_die
here passing in the 403 and also 503 on the request originally:
https://github.com/apache/httpd/blob/2.4.37/modules/http/http_filters.c#L1374
That 503 is then picked up here in ap_die_r as a recursive_error so that it
skips the ap_response_code_string call in its else and the ErrorDocument is not
served as a result:
https://github.com/apache/httpd/blob/3ec0ffb9e1ac05622b97a7afd6992dd2bd41ce38/modules/http/http_request.c#L127
So the ErrorDocument works for a page that originally had a 200 since there is
not a recursive_error seen by ap_die_r in that case.
--
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