Bug 58854

Summary: RewriteRule in .htaccess ignores 'Require all denied' when 403 ErrorDocument is missing
Product: Apache httpd-2 Reporter: Kurt Newman <kurt.newman>
Component: mod_rewriteAssignee: Apache HTTPD Bugs Mailing List <bugs>
Status: RESOLVED INVALID    
Severity: regression CC: jacob.perkins
Priority: P2 Keywords: FixedInTrunk
Version: 2.4.18   
Target Milestone: ---   
Hardware: PC   
OS: Linux   
Attachments: Apache configuration file
Logging output when RewriteRule ignores Require directive
Logging output when RewriteRule obeys Require directive

Description Kurt Newman 2016-01-13 23:58:26 UTC
Note
 Some of the examples below may be "expected", but the results seem incorrect in a couple of the cases.

Synopsis:
 1. Apache 2.2 used to treat "RewriteRule .* goodbye.txt" and "RewriteRule .* /goodbye.txt" identically by treating goodbye.txt as a file in the docroot (even beginning / was missing).
 2. Apache 2.2 used to correctly forbid access to a goodbye.txt when a directive above it prevented access (e.g. Order deny,allow\nDeny from all)
 3. This no longer works in Apache 2.4

Example of Apache 2.4.18 working correctly:
 1. Create /home/cgihw/public_html/.htaccess:
    Require all denied
    RewriteEngine on
    RewriteRule .* /goodbye.txt [L]
 2. Remove file: rm -f /home/cgihw/public_html/403.shtml
 3. Remove file: rm -f /home/cgihw/public_html/missing.txt
 4. Create file: echo "goodbye world" > /home/cgihw/public_html/goodbye.txt
 5. Navigate to http://cgihw.loc/missing.txt
 6. Observe that Apache 2.4.18 gives a 403 Forbidden response
 7. Observe the default LimitInternalRecursion limit of 10 is hit
 8. Observe that no Internal server error is presented to user user

Example of Apache 2.4.18 working incorrectly:
 1. Create /home/cgihw/public_html/.htaccess:
    Require all denied
    RewriteEngine on
    RewriteRule .* goodbye.txt [L]
 2. Remove file: rm -f /home/cgihw/public_html/403.shtml
 3. Remove file: rm -f /home/cgihw/public_html/missing.txt
 4. Create file: echo "goodbye world" > /home/cgihw/public_html/goodbye.txt
 5. Navigate to http://cgihw.loc/missing.txt
 6. Observe that you are incorrectly presented with the contents of goodbye.txt
 7. Observe that the LimitInternalRecursion limit is never compared against
 8. Observe that no Internal server error is presented to the user

Example of Apache 2.4.18 erroneously present Internal server error
 1. Create /home/cgihw/public_html/.htaccess:
    Require all granted
    RewriteEngine on
    RewriteRule .* /goodbye.txt [L]
 2. Remove file: rm -f /home/cgihw/public_html/403.shtml
 3. Remove file: rm -f /home/cgihw/public_html/missing.txt
 4. Create file: echo "goodbye world" > /home/cgihw/public_html/goodbye.txt
 5. Navigate to http://cgihw.loc/missing.txt
 6. Observe that you are now presented with an Internal server error, instead
    of a forbidden message
 7. Observe the default LimitInternalRecursion limit of 10 is hit

Background Notes
 - This seems to be a problem within mod_rewrite not setting the redirect-handler correctly for the generated sub request when the 403 ErrorDocument is missing.  The log indicates that the request is denied, yet the web server still presents the user with content.
 - This used to work in Apache 2.2, but no longer works in Apache 2.4.18.  The difference being, Apache 2.2 used the 'Order' directive, and not 'Require' directive.

I've attached the following files:
 - Example httpd.conf (file: broken.conf)
 - Configure line used to compile Apache 2.4.18
 - Log output for success
 - Log output for regression

Please see logs, configure line, and example Apache configuration for more detailed information.
Comment 1 Kurt Newman 2016-01-13 23:58:56 UTC
Created attachment 33436 [details]
Apache configuration file
Comment 2 Kurt Newman 2016-01-13 23:59:27 UTC
Created attachment 33437 [details]
Logging output when RewriteRule ignores Require directive
Comment 3 Kurt Newman 2016-01-13 23:59:43 UTC
Created attachment 33438 [details]
Logging output when RewriteRule obeys Require directive
Comment 4 Kurt Newman 2016-01-14 00:00:38 UTC
Configure Line:
./configure --enable-info=static --disable-v4-mapped --enable-access-compat=static --enable-actions=static --enable-alias=static --enable-asis=static --enable-auth_basic=static --enable-authn_core=static --enable-authn_file=static --enable-authz_core=static --enable-authz_groupfile=static --enable-authz_host=static --enable-authz_user=static --enable-autoindex=static --enable-cgi=static --enable-deflate=static --enable-dir=static --enable-env=static --enable-expires=static --enable-filter=static --enable-headers=static --enable-include=static --enable-log_config=static --enable-logio=static --enable-maintainer-mode --enable-mime=static --enable-modules=none --enable-negotiation=static --enable-proxy=static --enable-proxy-connect=static --enable-proxy-http=static --enable-rewrite=static --enable-setenvif=static --enable-slotmem_shm=static --enable-socache_dbm=static --enable-socache_shmcb=static --enable-ssl=static --enable-status=static --enable-suexec=static --enable-unique-id=static --enable-unixd=static --enable-userdir=static --enable-version=static --prefix=/usr/local/apache --with-crypto --with-included-apr --with-mpm=prefork --with-pcre=/opt/pcre --with-ssl=/usr --with-suexec-caller=nobody --with-suexec-docroot=/ --with-suexec-gidmin=100 --with-suexec-logfile=/usr/local/apache/logs/suexec_log --with-suexec-uidmin=100 --with-suexec-userdir=public_html
Comment 5 Eric Covener 2016-01-14 13:21:35 UTC
Are you able to rebuild mod_rewrite?

http://people.apache.org/~covener/patches/rewrite-deadloop.diff

This should resolve a difference between the relative and absolute substitutions and detecting the looping.
Comment 6 Kurt Newman 2016-01-14 15:55:38 UTC
Hi Eric,

Your patch corrects the issue and lets relative and absolute paths work identically.

Thanks for the response!

Kurt
Comment 7 Alexey Melezhik 2016-02-01 09:23:38 UTC
Hi!

( https://github.com/melezhik/apache-swat - easy way to verify existed apache issues  against your environment  )

Confirming this issue is resolved against my environment:

vagrant@Debian-jessie-vagrant@Debian-jessie-amd64-netboot:~/my/apache-swat$ swat -t 58854/
/home/vagrant/.swat/.cache/9277/prove/58854/granted2/missing.txt/00.GET.t ..
ok 1 - GET 127.0.0.1/58854/granted2/missing.txt succeeded
# http headers saved to /home/vagrant/.swat/.cache/9277/prove/zCQKWtpYir.hdr
# body saved to /home/vagrant/.swat/.cache/9277/prove/zCQKWtpYir
ok 2 - output match '200 OK'
ok 3 - output match 'goodbye world from root'
1..3
ok
/home/vagrant/.swat/.cache/9277/prove/58854/denied/missing.txt/00.GET.t ....
ok 1 - GET 127.0.0.1/58854/denied/missing.txt succeeded
# http headers saved to /home/vagrant/.swat/.cache/9277/prove/tj_HdkKgk5.hdr
# body saved to /home/vagrant/.swat/.cache/9277/prove/tj_HdkKgk5
ok 2 - output match '403 Forbidden'
1..2
ok
/home/vagrant/.swat/.cache/9277/prove/58854/granted/missing.txt/00.GET.t ...
ok 1 - GET 127.0.0.1/58854/granted/missing.txt succeeded
# http headers saved to /home/vagrant/.swat/.cache/9277/prove/Cmkh6umQP9.hdr
# body saved to /home/vagrant/.swat/.cache/9277/prove/Cmkh6umQP9
ok 2 - output match '200 OK'
ok 3 - output match 'goodbye world from 58854/granted'
1..3
ok
All tests successful.
Files=3, Tests=8,  1 wallclock secs ( 0.03 usr  0.00 sys +  0.14 cusr  0.01 csys =  0.18 CPU)
Result: PASS



amd64-netboot:~/my/apache-swat$ sudo ~/apache/bin/apachectl -V
Server version: Apache/2.4.18 (Unix)
Server built:   Jan 30 2016 10:17:37
Server's Module Magic Number: 20120211:52
Server loaded:  APR 1.5.1, APR-UTIL 1.5.4
Compiled using: APR 1.5.1, APR-UTIL 1.5.4
Architecture:   64-bit
Server MPM:     event
  threaded:     yes (fixed thread count)
    forked:     yes (variable process count)
Server compiled with....
 -D APR_HAS_SENDFILE
 -D APR_HAS_MMAP
 -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
 -D APR_USE_SYSVSEM_SERIALIZE
 -D APR_USE_PTHREAD_SERIALIZE
 -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
 -D APR_HAS_OTHER_CHILD
 -D AP_HAVE_RELIABLE_PIPED_LOGS
 -D DYNAMIC_MODULE_LIMIT=256
 -D HTTPD_ROOT="/home/vagrant/apache/"
 -D SUEXEC_BIN="/home/vagrant/apache//bin/suexec"
 -D DEFAULT_PIDLOG="logs/httpd.pid"
 -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
 -D DEFAULT_ERRORLOG="logs/error_log"
 -D AP_TYPES_CONFIG_FILE="conf/mime.types"
 -D SERVER_CONFIG_FILE="conf/httpd.conf"


Alexey Melezhik
Comment 8 Jacob P 2016-02-26 14:40:18 UTC
Hi Eric,

We've noticed a spike in tickets about RewriteRules no longer working after this patch. Granted, these rewrite rules look conspicuous, as in, they shouldn't work, or will result in looping, however we have enough reports of them that we think this might be a regression in behavior. We've verified these rewrites work before this patch, and now results in a ISE 500 / Max10Redirects after the patch.

Example of some rewrites that are now dead looping when they didn't previously:

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

<IfModule mod_rewrite.c>
	RewriteEngine Off
	RewriteBase /blogg/
 
	RewriteCond %{REQUEST_FILENAME} -f [OR]
	RewriteCond %{REQUEST_FILENAME} -d
	RewriteRule ^(.+) - [PT,L]
 
	RewriteCond %{REQUEST_URI} !=/favicon.ico
	RewriteRule ^(.*) index.php
 
	RewriteCond %{HTTP:Authorization}  !^$
	RewriteRule .* - [E=REMOTE_USER:%{HTTP:Authorization}]
</IfModule>
 
 
==================================================
 
<IfModule mod_rewrite.c>
    RewriteEngine On
    RewriteRule ^.*$ htaccess_tester.php
</IfModule>
 
==================================================
 
RewriteRule ^$ ?lang=IT        [L]
 
==================================================
 
RewriteRule ^public public.php [L]
RewriteRule ^js.php js.php [L]
 
==================================================

RewriteRule ^(.+) - [PT,L]

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

RewriteRule ^(.*) index.php

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

Any thoughts on this?
Comment 9 Eric Covener 2016-02-26 16:01:18 UTC
(In reply to Jacob P from comment #8)
> We've noticed a spike in tickets about RewriteRules no longer working after
> this patch. Granted, these rewrite rules look conspicuous, as in, they
> shouldn't work, or will result in looping, however we have enough reports of
> them that we think this might be a regression in behavior. We've verified
> these rewrites work before this patch, and now results in a ISE 500 /
> Max10Redirects after the patch.

Sorry and thanks for the report. I think I now see what went wrong in the patch -- all different permutations of URLs, paths, and converted paths are handled in this block.

Here is a followup that restores the original check and uses a slightly different check at the last moment:

http://people.apache.org/~covener/patches/trunk-rewrite-deadloop2.diff

I am hoping you can try some of those failing ones.
Comment 10 Eric Covener 2016-02-29 14:00:03 UTC
(In reply to Alexey Melezhik from comment #7)
> Hi!
> 
> ( https://github.com/melezhik/apache-swat - easy way to verify existed
> apache issues  against your environment  )
> 
> Confirming this issue is resolved against my environment:
> 
> vagrant@Debian-jessie-vagrant@Debian-jessie-amd64-netboot:~/my/apache-swat$
> swat -t 58854/
> /home/vagrant/.swat/.cache/9277/prove/58854/granted2/missing.txt/00.GET.t ..
> ok 1 - GET 127.0.0.1/58854/granted2/missing.txt succeeded
> # http headers saved to /home/vagrant/.swat/.cache/9277/prove/zCQKWtpYir.hdr
> # body saved to /home/vagrant/.swat/.cache/9277/prove/zCQKWtpYir
> ok 2 - output match '200 OK'
> ok 3 - output match 'goodbye world from root'
> 1..3
> ok
> /home/vagrant/.swat/.cache/9277/prove/58854/denied/missing.txt/00.GET.t ....
> ok 1 - GET 127.0.0.1/58854/denied/missing.txt succeeded
> # http headers saved to /home/vagrant/.swat/.cache/9277/prove/tj_HdkKgk5.hdr
> # body saved to /home/vagrant/.swat/.cache/9277/prove/tj_HdkKgk5
> ok 2 - output match '403 Forbidden'
> 1..2
> ok
> /home/vagrant/.swat/.cache/9277/prove/58854/granted/missing.txt/00.GET.t ...
> ok 1 - GET 127.0.0.1/58854/granted/missing.txt succeeded
> # http headers saved to /home/vagrant/.swat/.cache/9277/prove/Cmkh6umQP9.hdr
> # body saved to /home/vagrant/.swat/.cache/9277/prove/Cmkh6umQP9
> ok 2 - output match '200 OK'
> ok 3 - output match 'goodbye world from 58854/granted'
> 1..3
> ok
> All tests successful.
> Files=3, Tests=8,  1 wallclock secs ( 0.03 usr  0.00 sys +  0.14 cusr  0.01
> csys =  0.18 CPU)
> Result: PASS
> 
> 
> 
> amd64-netboot:~/my/apache-swat$ sudo ~/apache/bin/apachectl -V
> Server version: Apache/2.4.18 (Unix)
> Server built:   Jan 30 2016 10:17:37
> Server's Module Magic Number: 20120211:52
> Server loaded:  APR 1.5.1, APR-UTIL 1.5.4
> Compiled using: APR 1.5.1, APR-UTIL 1.5.4
> Architecture:   64-bit
> Server MPM:     event
>   threaded:     yes (fixed thread count)
>     forked:     yes (variable process count)
> Server compiled with....
>  -D APR_HAS_SENDFILE
>  -D APR_HAS_MMAP
>  -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
>  -D APR_USE_SYSVSEM_SERIALIZE
>  -D APR_USE_PTHREAD_SERIALIZE
>  -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
>  -D APR_HAS_OTHER_CHILD
>  -D AP_HAVE_RELIABLE_PIPED_LOGS
>  -D DYNAMIC_MODULE_LIMIT=256
>  -D HTTPD_ROOT="/home/vagrant/apache/"
>  -D SUEXEC_BIN="/home/vagrant/apache//bin/suexec"
>  -D DEFAULT_PIDLOG="logs/httpd.pid"
>  -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
>  -D DEFAULT_ERRORLOG="logs/error_log"
>  -D AP_TYPES_CONFIG_FILE="conf/mime.types"
>  -D SERVER_CONFIG_FILE="conf/httpd.conf"
> 
> 
> Alexey Melezhik

I think this particular test might be questionable. It doesn't fail when I revert the fix.
Comment 11 Eric Covener 2016-02-29 14:22:55 UTC
(In reply to Eric Covener from comment #10)
> (In reply to Alexey Melezhik from comment #7)
> > Hi!
> > 
> > ( https://github.com/melezhik/apache-swat - easy way to verify existed
> > apache issues  against your environment  )
> > 
> > Confirming this issue is resolved against my environment:
> > 
> > vagrant@Debian-jessie-vagrant@Debian-jessie-amd64-netboot:~/my/apache-swat$
> > swat -t 58854/
> > /home/vagrant/.swat/.cache/9277/prove/58854/granted2/missing.txt/00.GET.t ..
> > ok 1 - GET 127.0.0.1/58854/granted2/missing.txt succeeded
> > # http headers saved to /home/vagrant/.swat/.cache/9277/prove/zCQKWtpYir.hdr
> > # body saved to /home/vagrant/.swat/.cache/9277/prove/zCQKWtpYir
> > ok 2 - output match '200 OK'
> > ok 3 - output match 'goodbye world from root'
> > 1..3
> > ok
> > /home/vagrant/.swat/.cache/9277/prove/58854/denied/missing.txt/00.GET.t ....
> > ok 1 - GET 127.0.0.1/58854/denied/missing.txt succeeded
> > # http headers saved to /home/vagrant/.swat/.cache/9277/prove/tj_HdkKgk5.hdr
> > # body saved to /home/vagrant/.swat/.cache/9277/prove/tj_HdkKgk5
> > ok 2 - output match '403 Forbidden'
> > 1..2
> > ok
> > /home/vagrant/.swat/.cache/9277/prove/58854/granted/missing.txt/00.GET.t ...
> > ok 1 - GET 127.0.0.1/58854/granted/missing.txt succeeded
> > # http headers saved to /home/vagrant/.swat/.cache/9277/prove/Cmkh6umQP9.hdr
> > # body saved to /home/vagrant/.swat/.cache/9277/prove/Cmkh6umQP9
> > ok 2 - output match '200 OK'
> > ok 3 - output match 'goodbye world from 58854/granted'
> > 1..3
> > ok
> > All tests successful.
> > Files=3, Tests=8,  1 wallclock secs ( 0.03 usr  0.00 sys +  0.14 cusr  0.01
> > csys =  0.18 CPU)
> > Result: PASS
> > 
> > 
> > 
> > amd64-netboot:~/my/apache-swat$ sudo ~/apache/bin/apachectl -V
> > Server version: Apache/2.4.18 (Unix)
> > Server built:   Jan 30 2016 10:17:37
> > Server's Module Magic Number: 20120211:52
> > Server loaded:  APR 1.5.1, APR-UTIL 1.5.4
> > Compiled using: APR 1.5.1, APR-UTIL 1.5.4
> > Architecture:   64-bit
> > Server MPM:     event
> >   threaded:     yes (fixed thread count)
> >     forked:     yes (variable process count)
> > Server compiled with....
> >  -D APR_HAS_SENDFILE
> >  -D APR_HAS_MMAP
> >  -D APR_HAVE_IPV6 (IPv4-mapped addresses enabled)
> >  -D APR_USE_SYSVSEM_SERIALIZE
> >  -D APR_USE_PTHREAD_SERIALIZE
> >  -D SINGLE_LISTEN_UNSERIALIZED_ACCEPT
> >  -D APR_HAS_OTHER_CHILD
> >  -D AP_HAVE_RELIABLE_PIPED_LOGS
> >  -D DYNAMIC_MODULE_LIMIT=256
> >  -D HTTPD_ROOT="/home/vagrant/apache/"
> >  -D SUEXEC_BIN="/home/vagrant/apache//bin/suexec"
> >  -D DEFAULT_PIDLOG="logs/httpd.pid"
> >  -D DEFAULT_SCOREBOARD="logs/apache_runtime_status"
> >  -D DEFAULT_ERRORLOG="logs/error_log"
> >  -D AP_TYPES_CONFIG_FILE="conf/mime.types"
> >  -D SERVER_CONFIG_FILE="conf/httpd.conf"
> > 
> > 
> > Alexey Melezhik
> 
> I think this particular test might be questionable. It doesn't fail when I
> revert the fix.

I think the problem is likely the "absolute" paths, which are / in the PR, need to be /58854/granted/...
Comment 12 Jacob P 2016-02-29 14:55:46 UTC
(In reply to Eric Covener from comment #9)
> (In reply to Jacob P from comment #8)
> > We've noticed a spike in tickets about RewriteRules no longer working after
> > this patch. Granted, these rewrite rules look conspicuous, as in, they
> > shouldn't work, or will result in looping, however we have enough reports of
> > them that we think this might be a regression in behavior. We've verified
> > these rewrites work before this patch, and now results in a ISE 500 /
> > Max10Redirects after the patch.
> 
> Sorry and thanks for the report. I think I now see what went wrong in the
> patch -- all different permutations of URLs, paths, and converted paths are
> handled in this block.
> 
> Here is a followup that restores the original check and uses a slightly
> different check at the last moment:
> 
> http://people.apache.org/~covener/patches/trunk-rewrite-deadloop2.diff
> 
> I am hoping you can try some of those failing ones.


Our initial testing advises that the fix for rewrites looping works, but the original issue persists, that the RewriteRule ignores any Requires.
Comment 13 Eric Covener 2016-02-29 15:54:54 UTC
> Our initial testing advises that the fix for rewrites looping works, but the
> original issue persists, that the RewriteRule ignores any Requires.

I'm fairly sure I originally tested that case, with the regressing patch, but I can no longer get it to fail even with a vanilla 2.4.18.  But I am now questioning whether I really did.

mod_rewrite specified in htaccess doesn't even run in the 'require all denied' case.  Must be missing something.
Comment 14 Eric Covener 2016-02-29 15:57:31 UTC
(In reply to Eric Covener from comment #13)
> > Our initial testing advises that the fix for rewrites looping works, but the
> > original issue persists, that the RewriteRule ignores any Requires.
> 
> I'm fairly sure I originally tested that case, with the regressing patch,
> but I can no longer get it to fail even with a vanilla 2.4.18.  But I am now
> questioning whether I really did.
> 
> mod_rewrite specified in htaccess doesn't even run in the 'require all
> denied' case.  Must be missing something.

Something that fuels my doubts is how I worded the fix, wrt looping only.  Can anyone share trace8 output for  this failure on 2418:

Example of Apache 2.4.18 working incorrectly:
 1. Create /home/cgihw/public_html/.htaccess:
    Require all denied
    RewriteEngine on
    RewriteRule .* goodbye.txt [L]
 2. Remove file: rm -f /home/cgihw/public_html/403.shtml
 3. Remove file: rm -f /home/cgihw/public_html/missing.txt
 4. Create file: echo "goodbye world" > /home/cgihw/public_html/goodbye.txt
 5. Navigate to http://cgihw.loc/missing.txt
 6. Observe that you are incorrectly presented with the contents of goodbye.txt
 7. Observe that the LimitInternalRecursion limit is never compared against
 8. Observe that no Internal server error is presented to the user
Comment 15 Jacob P 2016-02-29 16:10:56 UTC
(In reply to Eric Covener from comment #14)
> (In reply to Eric Covener from comment #13)
> > > Our initial testing advises that the fix for rewrites looping works, but the
> > > original issue persists, that the RewriteRule ignores any Requires.
> > 
> > I'm fairly sure I originally tested that case, with the regressing patch,
> > but I can no longer get it to fail even with a vanilla 2.4.18.  But I am now
> > questioning whether I really did.
> > 
> > mod_rewrite specified in htaccess doesn't even run in the 'require all
> > denied' case.  Must be missing something.
> 
> Something that fuels my doubts is how I worded the fix, wrt looping only. 
> Can anyone share trace8 output for  this failure on 2418:
> 
> Example of Apache 2.4.18 working incorrectly:
>  1. Create /home/cgihw/public_html/.htaccess:
>     Require all denied
>     RewriteEngine on
>     RewriteRule .* goodbye.txt [L]
>  2. Remove file: rm -f /home/cgihw/public_html/403.shtml
>  3. Remove file: rm -f /home/cgihw/public_html/missing.txt
>  4. Create file: echo "goodbye world" > /home/cgihw/public_html/goodbye.txt
>  5. Navigate to http://cgihw.loc/missing.txt
>  6. Observe that you are incorrectly presented with the contents of
> goodbye.txt
>  7. Observe that the LimitInternalRecursion limit is never compared against
>  8. Observe that no Internal server error is presented to the user

Here's trace8 with a patched 2.4.18 (original patch provided by Eric, not the second):

[Mon Feb 29 16:09:18.805864 2016] [core:trace5] [pid 8692] protocol.c(616): [client 192.168.122.236:42428] Request received from client: GET /missing.txt HTTP/1.1
[Mon Feb 29 16:09:18.806118 2016] [http:trace4] [pid 8692] http_request.c(394): [client 192.168.122.236:42428] Headers received from client:
[Mon Feb 29 16:09:18.806135 2016] [http:trace4] [pid 8692] http_request.c(398): [client 192.168.122.236:42428]   User-Agent: curl/7.29.0
[Mon Feb 29 16:09:18.806143 2016] [http:trace4] [pid 8692] http_request.c(398): [client 192.168.122.236:42428]   Host: cgihw.tld
[Mon Feb 29 16:09:18.806150 2016] [http:trace4] [pid 8692] http_request.c(398): [client 192.168.122.236:42428]   Accept: */*
[Mon Feb 29 16:09:18.806422 2016] [authz_core:debug] [pid 8692] mod_authz_core.c(809): [client 192.168.122.236:42428] AH01626: authorization result of Require all denied: denied
[Mon Feb 29 16:09:18.806447 2016] [authz_core:debug] [pid 8692] mod_authz_core.c(809): [client 192.168.122.236:42428] AH01626: authorization result of <RequireAny>: denied
[Mon Feb 29 16:09:18.806457 2016] [authz_core:error] [pid 8692] [client 192.168.122.236:42428] AH01630: client denied by server configuration: /home/cgihw/public_html/missing.txt
[Mon Feb 29 16:09:18.806478 2016] [core:trace3] [pid 8692] request.c(119): [client 192.168.122.236:42428] auth phase 'check access' gave status 403: /missing.txt
[Mon Feb 29 16:09:18.806560 2016] [rewrite:trace3] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e570d8/initial/redir#1] [perdir /home/cgihw/public_html/] strip per-dir prefix: /home/cgihw/public_html/403.shtm
l -> 403.shtml
[Mon Feb 29 16:09:18.806578 2016] [rewrite:trace3] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e570d8/initial/redir#1] [perdir /home/cgihw/public_html/] applying pattern '.*' to uri '403.shtml'
[Mon Feb 29 16:09:18.806599 2016] [rewrite:trace2] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e570d8/initial/redir#1] [perdir /home/cgihw/public_html/] rewrite '403.shtml' -> 'goodbye.txt'
[Mon Feb 29 16:09:18.806626 2016] [rewrite:trace3] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e570d8/initial/redir#1] [perdir /home/cgihw/public_html/] add per-dir prefix: goodbye.txt -> /home/cgihw/public_
html/goodbye.txt
[Mon Feb 29 16:09:18.806642 2016] [rewrite:trace2] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e570d8/initial/redir#1] [perdir /home/cgihw/public_html/] strip document_root prefix: /home/cgihw/public_html/go
odbye.txt -> /goodbye.txt
[Mon Feb 29 16:09:18.806654 2016] [rewrite:trace1] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e570d8/initial/redir#1] [perdir /home/cgihw/public_html/] internal redirect with /goodbye.txt [INTERNAL REDIRECT
]
[Mon Feb 29 16:09:18.806742 2016] [rewrite:trace3] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e5ac30/initial/redir#2] [perdir /home/cgihw/public_html/] strip per-dir prefix: /home/cgihw/public_html/goodbye.
txt -> goodbye.txt
[Mon Feb 29 16:09:18.806757 2016] [rewrite:trace3] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e5ac30/initial/redir#2] [perdir /home/cgihw/public_html/] applying pattern '.*' to uri 'goodbye.txt'
[Mon Feb 29 16:09:18.806770 2016] [rewrite:trace2] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e5ac30/initial/redir#2] [perdir /home/cgihw/public_html/] rewrite 'goodbye.txt' -> 'goodbye.txt'
[Mon Feb 29 16:09:18.806781 2016] [rewrite:trace3] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e5ac30/initial/redir#2] [perdir /home/cgihw/public_html/] add per-dir prefix: goodbye.txt -> /home/cgihw/public_
html/goodbye.txt
[Mon Feb 29 16:09:18.806795 2016] [rewrite:trace1] [pid 8692] mod_rewrite.c(476): [client 192.168.122.236:42428] 192.168.122.236 - - [cgihw.tld/sid#d9f9b8][rid#e5ac30/initial/redir#2] [perdir /home/cgihw/public_html/] initial URL equal rewritten URL: /home/cgihw/public_ht
ml/goodbye.txt [IGNORING REWRITE]
[Mon Feb 29 16:09:18.806885 2016] [http:trace3] [pid 8692] http_filters.c(1006): [client 192.168.122.236:42428] Response sent with status 403, headers:
[Mon Feb 29 16:09:18.806898 2016] [http:trace5] [pid 8692] http_filters.c(1013): [client 192.168.122.236:42428]   Date: Mon, 29 Feb 2016 16:09:18 GMT
[Mon Feb 29 16:09:18.806908 2016] [http:trace5] [pid 8692] http_filters.c(1016): [client 192.168.122.236:42428]   Server: Apache
[Mon Feb 29 16:09:18.806917 2016] [http:trace4] [pid 8692] http_filters.c(835): [client 192.168.122.236:42428]   Last-Modified: Mon, 29 Feb 2016 16:06:33 GMT
[Mon Feb 29 16:09:18.806925 2016] [http:trace4] [pid 8692] http_filters.c(835): [client 192.168.122.236:42428]   Accept-Ranges: bytes
[Mon Feb 29 16:09:18.806931 2016] [http:trace4] [pid 8692] http_filters.c(835): [client 192.168.122.236:42428]   Content-Length: 14
[Mon Feb 29 16:09:18.806938 2016] [http:trace4] [pid 8692] http_filters.c(835): [client 192.168.122.236:42428]   Connection: close
[Mon Feb 29 16:09:18.806944 2016] [http:trace4] [pid 8692] http_filters.c(835): [client 192.168.122.236:42428]   Content-Type: text/plain
[Mon Feb 29 16:09:18.806979 2016] [core:trace6] [pid 8692] core_filters.c(525): [client 192.168.122.236:42428] core_output_filter: flushing because of FLUSH bucket
[Mon Feb 29 16:09:18.807233 2016] [core:trace6] [pid 8692] core_filters.c(525): [client 192.168.122.236:42428] core_output_filter: flushing because of FLUSH bucket
Comment 16 Jacob P 2016-02-29 16:28:29 UTC
Trace8 after new patch:

[Mon Feb 29 16:27:48.520428 2016] [core:trace5] [pid 18816] protocol.c(616): [client 192.168.122.236:42816] Request received from client: GET /missing.txt HTTP/1.1
[Mon Feb 29 16:27:48.520744 2016] [http:trace4] [pid 18816] http_request.c(394): [client 192.168.122.236:42816] Headers received from client:
[Mon Feb 29 16:27:48.520764 2016] [http:trace4] [pid 18816] http_request.c(398): [client 192.168.122.236:42816]   User-Agent: curl/7.29.0
[Mon Feb 29 16:27:48.520773 2016] [http:trace4] [pid 18816] http_request.c(398): [client 192.168.122.236:42816]   Host: cgihw.tld
[Mon Feb 29 16:27:48.520781 2016] [http:trace4] [pid 18816] http_request.c(398): [client 192.168.122.236:42816]   Accept: */*
[Mon Feb 29 16:27:48.521090 2016] [authz_core:debug] [pid 18816] mod_authz_core.c(809): [client 192.168.122.236:42816] AH01626: authorization result of Require all denied: denied
[Mon Feb 29 16:27:48.521110 2016] [authz_core:debug] [pid 18816] mod_authz_core.c(809): [client 192.168.122.236:42816] AH01626: authorization result of <RequireAny>: denied
[Mon Feb 29 16:27:48.521118 2016] [authz_core:error] [pid 18816] [client 192.168.122.236:42816] AH01630: client denied by server configuration: /home/cgihw/public_html/missing.txt
[Mon Feb 29 16:27:48.521127 2016] [core:trace3] [pid 18816] request.c(119): [client 192.168.122.236:42816] auth phase 'check access' gave status 403: /missing.txt
[Mon Feb 29 16:27:48.521212 2016] [rewrite:trace3] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c3f058/initial/redir#1] [perdir /home/cgihw/public_html/] strip per-dir prefix: /home/cgihw/public_html/403.shtml -> 403.shtml
[Mon Feb 29 16:27:48.521240 2016] [rewrite:trace3] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c3f058/initial/redir#1] [perdir /home/cgihw/public_html/] applying pattern '.*' to uri '403.shtml'
[Mon Feb 29 16:27:48.521264 2016] [rewrite:trace2] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c3f058/initial/redir#1] [perdir /home/cgihw/public_html/] rewrite '403.shtml' -> 'goodbye.txt'
[Mon Feb 29 16:27:48.521279 2016] [rewrite:trace3] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c3f058/initial/redir#1] [perdir /home/cgihw/public_html/] add per-dir prefix: goodbye.txt -> /home/cgihw/public_html/goodbye.txt
[Mon Feb 29 16:27:48.521296 2016] [rewrite:trace2] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c3f058/initial/redir#1] [perdir /home/cgihw/public_html/] strip document_root prefix: /home/cgihw/public_html/goodbye.txt -> /goodbye.txt
[Mon Feb 29 16:27:48.521310 2016] [rewrite:trace1] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c3f058/initial/redir#1] [perdir /home/cgihw/public_html/] internal redirect with /goodbye.txt [INTERNAL REDIRECT]
[Mon Feb 29 16:27:48.521420 2016] [rewrite:trace3] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c42bb0/initial/redir#2] [perdir /home/cgihw/public_html/] strip per-dir prefix: /home/cgihw/public_html/goodbye.txt -> goodbye.txt
[Mon Feb 29 16:27:48.521437 2016] [rewrite:trace3] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c42bb0/initial/redir#2] [perdir /home/cgihw/public_html/] applying pattern '.*' to uri 'goodbye.txt'
[Mon Feb 29 16:27:48.521451 2016] [rewrite:trace2] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c42bb0/initial/redir#2] [perdir /home/cgihw/public_html/] rewrite 'goodbye.txt' -> 'goodbye.txt'
[Mon Feb 29 16:27:48.521464 2016] [rewrite:trace3] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c42bb0/initial/redir#2] [perdir /home/cgihw/public_html/] add per-dir prefix: goodbye.txt -> /home/cgihw/public_html/goodbye.txt
[Mon Feb 29 16:27:48.521479 2016] [rewrite:trace1] [pid 18816] mod_rewrite.c(476): [client 192.168.122.236:42816] 192.168.122.236 - - [cgihw.tld/sid#1c22af8][rid#1c42bb0/initial/redir#2] [perdir /home/cgihw/public_html/] initial URL equal rewritten URL: /home/cgihw/public_html/goodbye.txt [IGNORING REWRITE]
[Mon Feb 29 16:27:48.521561 2016] [http:trace3] [pid 18816] http_filters.c(1006): [client 192.168.122.236:42816] Response sent with status 403, headers:
[Mon Feb 29 16:27:48.521572 2016] [http:trace5] [pid 18816] http_filters.c(1013): [client 192.168.122.236:42816]   Date: Mon, 29 Feb 2016 16:27:48 GMT
[Mon Feb 29 16:27:48.521581 2016] [http:trace5] [pid 18816] http_filters.c(1016): [client 192.168.122.236:42816]   Server: Apache
[Mon Feb 29 16:27:48.521590 2016] [http:trace4] [pid 18816] http_filters.c(835): [client 192.168.122.236:42816]   Last-Modified: Mon, 29 Feb 2016 16:06:33 GMT
[Mon Feb 29 16:27:48.521600 2016] [http:trace4] [pid 18816] http_filters.c(835): [client 192.168.122.236:42816]   Accept-Ranges: bytes
[Mon Feb 29 16:27:48.521608 2016] [http:trace4] [pid 18816] http_filters.c(835): [client 192.168.122.236:42816]   Content-Length: 14
[Mon Feb 29 16:27:48.521615 2016] [http:trace4] [pid 18816] http_filters.c(835): [client 192.168.122.236:42816]   Connection: close
[Mon Feb 29 16:27:48.521622 2016] [http:trace4] [pid 18816] http_filters.c(835): [client 192.168.122.236:42816]   Content-Type: text/plain
[Mon Feb 29 16:27:48.521662 2016] [core:trace6] [pid 18816] core_filters.c(525): [client 192.168.122.236:42816] core_output_filter: flushing because of FLUSH bucket
[Mon Feb 29 16:27:48.521934 2016] [core:trace6] [pid 18816] core_filters.c(525): [client 192.168.122.236:42816] core_output_filter: flushing because of FLUSH bucket
Comment 17 Kurt Newman 2016-03-16 15:26:12 UTC
Since we're having a difficult time duplicating the secondary issues, I am closing this bug.

Thanks for your help Eric