[Modules] proxy issue with mod_gnutls

[Guillaume Rousse]

Nikos Mavrogiannopoulos a écrit :
> I don't know how the mod_proxy is supposed to work and I've never tested
> it against mod_gnutls. If you run apache2ctl with -X and gdb where is
> the timeout occuring?
I didn't succeded  running apache in debug mode, as apachectl alone
complains about missing -D options. I tried to invoke httpd manually
with all proper -D options and -X switch, but it doesn't output
anything. And trying the 'debug' option of httpd init script doesn't
help either: apache initialisation occurs, but incoming traffic doesn't
trigger any output :/

However, here are two log trace of proxy connection. Here is a
successful attempt:
[Fri Feb 22 15:26:28 2008] [debug] mod_cache.c(131): Adding CACHE_SAVE
filter for /
[Fri Feb 22 15:26:28 2008] [debug] mod_cache.c(138): Adding
CACHE_REMOVE_URL filter for /
[Fri Feb 22 15:26:28 2008] [debug] mod_proxy_http.c(54): proxy: HTTP:
canonicalising URL //www.msr-inria.inria.fr/
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(1412): [client
195.83.212.52] proxy: http: found worker http://www.msr-inria.inria.fr/
for http://www.msr-inria.inria.fr/
[Fri Feb 22 15:26:28 2008] [debug] mod_proxy.c(819): Running scheme http
handler (attempt 0)
[Fri Feb 22 15:26:28 2008] [debug] mod_proxy_http.c(1693): proxy: HTTP:
serving URL http://www.msr-inria.inria.fr/
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(1852): proxy: HTTP: has
acquired connection for (www.msr-inria.inria.fr)
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(1913): proxy: connecting
http://www.msr-inria.inria.fr/ to www.msr-inria.inria.fr:80
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(2012): proxy: connected
/ to www.msr-inria.inria.fr:80
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(2169): proxy: HTTP: fam
2 socket created to connect to www.msr-inria.inria.fr
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(2266): proxy: HTTP:
connection complete to 193.55.250.161:80 (www.msr-inria.inria.fr)
[Fri Feb 22 15:26:28 2008] [debug] mod_proxy_http.c(1478): proxy: start
body send
[Fri Feb 22 15:26:28 2008] [debug] mod_cache.c(528): cache: / not
cached. Reason: Expires header already expired, not cacheable
[Fri Feb 22 15:26:28 2008] [debug] mod_proxy_http.c(1567): proxy: end
body send
[Fri Feb 22 15:26:28 2008] [debug] proxy_util.c(1870): proxy: HTTP: has
released connection for (www.msr-inria.inria.fr)

Here is an unsucessful one:
[Fri Feb 22 15:33:15 2008] [debug] mod_cache.c(131): Adding CACHE_SAVE
filter for /
[Fri Feb 22 15:33:15 2008] [debug] mod_cache.c(138): Adding
CACHE_REMOVE_URL filter for /
[Fri Feb 22 15:33:15 2008] [debug] mod_proxy_http.c(54): proxy: HTTP:
canonicalising URL //www.msr-inria.inria.fr/
[Fri Feb 22 15:33:15 2008] [debug] proxy_util.c(1412): [client
195.83.212.52] proxy: http: found worker http://www.msr-inria.inria.fr/
for http://www.msr-inria.inria.fr/
[Fri Feb 22 15:33:15 2008] [debug] mod_proxy.c(819): Running scheme http
handler (attempt 0)
[Fri Feb 22 15:33:15 2008] [debug] mod_proxy_http.c(1693): proxy: HTTP:
serving URL http://www.msr-inria.inria.fr/
[Fri Feb 22 15:33:15 2008] [debug] proxy_util.c(1852): proxy: HTTP: has
acquired connection for (www.msr-inria.inria.fr)
[Fri Feb 22 15:33:15 2008] [debug] proxy_util.c(1913): proxy: connecting
http://www.msr-inria.inria.fr/ to www.msr-inria.inria.fr:80
[Fri Feb 22 15:33:15 2008] [debug] proxy_util.c(2012): proxy: connected
/ to www.msr-inria.inria.fr:80
[Fri Feb 22 15:33:15 2008] [debug] proxy_util.c(2169): proxy: HTTP: fam
2 socket created to connect to www.msr-inria.inria.fr
[Fri Feb 22 15:33:15 2008] [debug] proxy_util.c(2266): proxy: HTTP:
connection complete to 193.55.250.161:80 (www.msr-inria.inria.fr)
[Fri Feb 22 15:34:56 2008] [error] [client 193.55.250.161] GnuTLS:
Handshake Failed. Hit Maximum Attempts
[Fri Feb 22 15:34:56 2008] [error] [client 193.55.250.161] GnuTLS:
Handshake Failed. Hit Maximum Attempts
[Fri Feb 22 15:34:56 2008] [error] [client 195.83.212.52]
(104)Connection reset by peer: proxy: error reading status line from
remote server www.msr-inria.inria.fr
[Fri Feb 22 15:34:56 2008] [error] [client 195.83.212.52]
(104)Connection reset by peer: proxy: error reading status line from
remote server www.msr-inria.inria.fr
[Fri Feb 22 15:34:56 2008] [error] [client 195.83.212.52] proxy: Error
reading from remote server returned by /error/HTTP_BAD_GATEWAY.html.var
[Fri Feb 22 15:34:56 2008] [error] [client 195.83.212.52] proxy: Error
reading from remote server returned by /error/HTTP_BAD_GATEWAY.html.var
[Fri Feb 22 15:34:56 2008] [debug] proxy_util.c(1870): proxy: HTTP: has
released connection for (*)
[Fri Feb 22 15:34:56 2008] [debug] proxy_util.c(1870): proxy: HTTP: has
released connection for (*)

The 'GnuTLS: Handshake Failed' make me think than mod_gnutls tries to
cypher outgoing connection too, and fails.

> As far as I can test when connecting to your site,
> the TLS negotiation is correctly performed and the correct certificate
> is returned.
Yes, that part is OK at least :)
-- 
Guillaume Rousse
Moyens Informatiques - INRIA Futurs
Tel: 01 69 35 69 62