Bug 63176

Summary:	Wrong backend is used
Product:	Apache httpd-2	Reporter:	Lubos Uhliarik <luhliari>
Component:	mod_proxy	Assignee:	Apache HTTPD Bugs Mailing List <bugs>
Status:	NEW ---
Severity:	normal
Priority:	P2
Version:	2.4.38
Target Milestone:	---
Hardware:	PC
OS:	Linux

Description Lubos Uhliarik 2019-02-14 17:06:51 UTC

Hello all,

I'm experiencing following issue. Let's create two files:

echo HIT > /var/www/html/test-hit.html
echo MISS > /var/www/html/test-miss.html


Content of /etc/httpd/conf.d/test.conf:
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~
ProxyPass /test/ http://localhost/ 
ProxyRemoteMatch http://localhost/.*hit.html http://localhost:8080

Listen 8080

<VirtualHost *:8080>
  ProxyRequests on
  <Proxy "*">
     Require all denied
  </Proxy>
</VirtualHost>
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

And then start httpd. Depending on request order, I'm receiving different content:

[root@host-8-249-187 ~]# curl http://localhost/test/test-miss.html
MISS
[root@host-8-249-187 ~]# curl http://localhost/test/test-hit.html
HIT
[root@host-8-249-187 ~]# systemctl restart httpd
[root@host-8-249-187 ~]# curl http://localhost/test/test-hit.html
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>403 Forbidden</title>
</head><body>
<h1>Forbidden</h1>
<p>You don't have permission to access http://localhost/test-hit.html
on this server.<br />
</p>
</body></html>
[root@host-8-249-187 ~]# curl http://localhost/test/test-miss.html
MISS


I debugged it a bit and depending on request order, in ap_proxy_acquire_connection, function apr_reslist_acquire acquiring different values.

Correct case:

(gdb)                                                                                                                                                                        
2292        if (worker->s->hmax && worker->cp->res) {                                                                                                                        
2293            rv = apr_reslist_acquire(worker->cp->res, (void **)conn);                                                                                                    
2294        }    
(gdb) p **conn
$10 = {connection = 0x0, r = 0x0, worker = 0x55555586df58, pool = 0x55555594cb78,
  hostname = 0x0, addr = 0x0, scpool = 0x7fffb8007018, sock = 0x0, data = 0x0,
  forward = 0x0, flags = 0, port = 0, is_ssl = 0, close = 0, need_flush = 0,
  inreslist = 1, uds_path = 0x0, ssl_hostname = 0x0, tmp_bb = 0x0}

Whereas in wrong case:

(gdb) p **conn                                                                                                                                                               
$9 = {connection = 0x7fffb80072e0, r = 0x0, worker = 0x55555586df58,                                                                                                         
  pool = 0x55555594cb78, hostname = 0x55555594cc60 "localhost",                                                                                                              
  addr = 0x5555558e47c0, scpool = 0x7fffb8007018, sock = 0x7fffb8007090, data = 0x0,                                                                                         
  forward = 0x0, flags = 0, port = 80, is_ssl = 0, close = 0, need_flush = 0,                                                                                                
  inreslist = 1, uds_path = 0x0, ssl_hostname = 0x0, tmp_bb = 0x7fffb80072a0}   


Also found out, that this was working in 2.4.34 and stopped to work in 2.4.37.

Comment 1 Lubos Uhliarik 2019-02-18 16:26:05 UTC

OK, this bug is even present in 2.4.34, but it occurs less often:

# curl -v http://localhost/test/test-miss.html; curl -v http://localhost/test/test-hit.html 
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-miss.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Mon, 18 Feb 2019 16:23:45 GMT
< Server: Apache/2.4.34 (Fedora)
< Last-Modified: Mon, 18 Feb 2019 12:14:31 GMT
< ETag: "5-5822a1126202f"
< Accept-Ranges: bytes
< Content-Length: 5
< Content-Type: text/html; charset=UTF-8
< 
MISS
* Connection #0 to host localhost left intact
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-hit.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 403 Forbidden
< Date: Mon, 18 Feb 2019 16:23:45 GMT
< Server: Apache/2.4.34 (Fedora)
< Content-Length: 238
< Content-Type: text/html; charset=iso-8859-1
< 
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>403 Forbidden</title>
</head><body>
<h1>Forbidden</h1>
<p>You don't have permission to access http://localhost/test-hit.html
on this server.<br />
</p>
</body></html>
* Connection #0 to host localhost left intact
[root@host-8-248-205 ~]# curl -v http://localhost/test/test-miss.html; curl -v http://localhost/test/test-hit.html 
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-miss.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Mon, 18 Feb 2019 16:23:46 GMT
< Server: Apache/2.4.34 (Fedora)
< Last-Modified: Mon, 18 Feb 2019 12:14:31 GMT
< ETag: "5-5822a1126202f"
< Accept-Ranges: bytes
< Content-Length: 5
< Content-Type: text/html; charset=UTF-8
< 
MISS
* Connection #0 to host localhost left intact
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-hit.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 403 Forbidden
< Date: Mon, 18 Feb 2019 16:23:47 GMT
< Server: Apache/2.4.34 (Fedora)
< Content-Length: 238
< Content-Type: text/html; charset=iso-8859-1
< 
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>403 Forbidden</title>
</head><body>
<h1>Forbidden</h1>
<p>You don't have permission to access http://localhost/test-hit.html
on this server.<br />
</p>
</body></html>
* Connection #0 to host localhost left intact
[root@host-8-248-205 ~]# curl -v http://localhost/test/test-miss.html; curl -v http://localhost/test/test-hit.html 
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-miss.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Mon, 18 Feb 2019 16:23:48 GMT
< Server: Apache/2.4.34 (Fedora)
< Last-Modified: Mon, 18 Feb 2019 12:14:31 GMT
< ETag: "5-5822a1126202f"
< Accept-Ranges: bytes
< Content-Length: 5
< Content-Type: text/html; charset=UTF-8
< 
MISS
* Connection #0 to host localhost left intact
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-hit.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 403 Forbidden
< Date: Mon, 18 Feb 2019 16:23:48 GMT
< Server: Apache/2.4.34 (Fedora)
< Content-Length: 238
< Content-Type: text/html; charset=iso-8859-1
< 
<!DOCTYPE HTML PUBLIC "-//IETF//DTD HTML 2.0//EN">
<html><head>
<title>403 Forbidden</title>
</head><body>
<h1>Forbidden</h1>
<p>You don't have permission to access http://localhost/test-hit.html
on this server.<br />
</p>
</body></html>
* Connection #0 to host localhost left intact
[root@host-8-248-205 ~]# curl -v http://localhost/test/test-miss.html; curl -v http://localhost/test/test-hit.html 
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-miss.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Mon, 18 Feb 2019 16:23:49 GMT
< Server: Apache/2.4.34 (Fedora)
< Last-Modified: Mon, 18 Feb 2019 12:14:31 GMT
< ETag: "5-5822a1126202f"
< Accept-Ranges: bytes
< Content-Length: 5
< Content-Type: text/html; charset=UTF-8
< 
MISS
* Connection #0 to host localhost left intact
*   Trying ::1...
* TCP_NODELAY set
* Connected to localhost (::1) port 80 (#0)
> GET /test/test-hit.html HTTP/1.1
> Host: localhost
> User-Agent: curl/7.61.1
> Accept: */*
> 
< HTTP/1.1 200 OK
< Date: Mon, 18 Feb 2019 16:23:49 GMT
< Server: Apache/2.4.34 (Fedora)
< Last-Modified: Mon, 18 Feb 2019 12:14:26 GMT
< ETag: "4-5822a10df9597"
< Accept-Ranges: bytes
< Content-Length: 4
< Content-Type: text/html; charset=UTF-8
< 
HIT
* Connection #0 to host localhost left intact

Comment 2 Lubos Uhliarik 2019-02-18 18:46:01 UTC

In 2.4.18, it is still failing. In 2.4.16, it passed 100 iterations (so probably, it is working here).

Comment 3 Yann Ylavic 2019-02-18 21:06:52 UTC

> ProxyPass /test/ http://localhost/ 
> ProxyRemoteMatch http://localhost/.*hit.html http://localhost:8080
> 
> Listen 8080
> 
> <VirtualHost *:8080>
>   ProxyRequests on
>   <Proxy "*">
>      Require all denied
>   </Proxy>
> </VirtualHost>

What is this configuration supposed to achieve, reverse-proxying to a forward-proxy? What is "Listen"ing on port 80?

Comment 4 Ruediger Pluem 2019-02-19 07:50:34 UTC

(In reply to Yann Ylavic from comment #3)
> > ProxyPass /test/ http://localhost/ 
> > ProxyRemoteMatch http://localhost/.*hit.html http://localhost:8080
> > 
> > Listen 8080
> > 
> > <VirtualHost *:8080>
> >   ProxyRequests on
> >   <Proxy "*">
> >      Require all denied
> >   </Proxy>
> > </VirtualHost>
> 
> What is this configuration supposed to achieve, reverse-proxying to a
> forward-proxy? What is "Listen"ing on port 80?

Apart from the weird setup which purpose I struggle to understand as well I guess I know what is happening. As the configuration uses a remote proxy for certain URL's of the backend and not for others (.*hit.html on the backend requires the usage of a remote proxy all other URL's do not) we get into trouble with our connection reusing. Once the worker for a backend returns a a usable connection for a backend we no longer check whether this particular URL should go directly or via a proxy. We just take what we have and use it. Currently the above could be fixed by either disabling the reuse of connections or by having a separate ProxyPassMatch ^(/test/.*hit.html)$ http://localhost$1 that is configured before the ProxyPass.

Comment 5 Joe Orton 2019-02-19 08:21:58 UTC

The config is perhaps a bit artificial, it is an internal test case we had for bug 33170; the point is merely to test that the ProxyRemoteMatch is applied correctly for some URLs and not others.

I figured this was a connection re-use issue, but wasn't sure where.  Maybe ProxyRemoteMatch shouldn't allow a URL path segment other than "/" if it cannot reliably be applied differently to different paths?  (Or we should warn for this case?)

Comment 6 Yann Ylavic 2019-02-19 13:49:41 UTC

The alternative would be to (re-)validate the reused URL (from the reused proxy_conn_rec) against the ProxyRemoteMatch (if any involved for the new request). Not sure how to do this though, since we don't really store the path segment in proxy_conn_rec for now (only the hostname/port AFAICT), but should be possible..