LinuxQuestions.org - apache2 mod_proxy failing with ssl

Hi all,

I seem to be having a problem with mod_proxy and https websites. A simple connection to port 80 works fine but all calls to 443 fail.

I had a look at my firewall but can't see anything that would block port 443, although I get no tcpdump traffic on that port on the deb01 client when I try and connect to it. I disabled the firewall but still no luck.

My configuration consists of 3 VMs (KVM) each running a different website.

deb01 (https)
deb02 (http)
deb03 (https)

I get the following error when connecting to ssl deb01

Code:

An error occurred during a connection to deb03.example.com.



SSL received a record that exceeded the maximum permissible length.



(Error code: ssl_error_rx_record_too_long)

The following is what can be found on the host

Code:

# cat /etc/apache2/sites-enabled/000-deb01 

NameVirtualHost *:443

<VirtualHost *:443>

        ServerName deb01.example.com

        DocumentRoot /var/www/



        LogLevel debug

        ErrorLog /var/log/apache2/deb01_error.log

        CustomLog /var/log/apache2/deb01_access.log combined



        ProxyRequests Off

        SSLProxyEngine On



        <Proxy *>

          Order deny,allow

          Allow from all

        </Proxy>



        ProxyPass / https://deb01.example.com/

        ProxyPassReverse / https://deb01.example.com/

</VirtualHost>

Code:

# cat /etc/apache2/sites-enabled/001-deb02 

<VirtualHost *:80>

        ServerName deb02.example.com

        DocumentRoot /var/www/

        ProxyRequests Off



        <Proxy *>

          Order deny,allow

          Allow from all

        </Proxy>



        ProxyPreserveHost On

        ProxyStatus On



        ProxyPass / http://deb02.example.com/

        ProxyPassReverse / http://deb02.example.com/

</VirtualHost>

The modules I am running

Code:

# apache2ctl -SM

VirtualHost configuration:

wildcard NameVirtualHosts and _default_ servers:

*:443                  is a NameVirtualHost

        default server deb01.example.com (/etc/apache2/sites-enabled/000-deb01:2)

        port 443 namevhost deb01.example.com (/etc/apache2/sites-enabled/000-deb01:2)

        port 443 namevhost deb03.example.com (/etc/apache2/sites-enabled/002-deb03:1)

*:80                  is a NameVirtualHost

        default server deb02.example.com (/etc/apache2/sites-enabled/001-deb02:1)

        port 80 namevhost deb02.example.com (/etc/apache2/sites-enabled/001-deb02:1)

Loaded Modules:

 core_module (static)

 log_config_module (static)

 logio_module (static)

 mpm_worker_module (static)

 http_module (static)

 so_module (static)

 alias_module (shared)

 auth_basic_module (shared)

 authn_file_module (shared)

 authz_default_module (shared)

 authz_groupfile_module (shared)

 authz_host_module (shared)

 authz_user_module (shared)

 autoindex_module (shared)

 cgid_module (shared)

 deflate_module (shared)

 dir_module (shared)

 env_module (shared)

 mime_module (shared)

 negotiation_module (shared)

 proxy_module (shared)

 proxy_connect_module (shared)

 proxy_http_module (shared)

 setenvif_module (shared)

 ssl_module (shared)

 status_module (shared)

Syntax OK

This is for client deb01 (ssl)

Code:

# cat /etc/apache2/sites-enabled/deb03 

<VirtualHost *:443>

        ServerName deb03.example.com

        ServerAdmin webmaster@example.com



        ServerAdmin webmaster@localhost

        DocumentRoot /var/www/

        <Directory />

                Options FollowSymLinks

                AllowOverride None

        </Directory>

        <Directory /var/www/>

                Options Indexes FollowSymLinks MultiViews

                AllowOverride None

                Order allow,deny

                allow from all

        </Directory>

        

        ErrorLog /var/log/apache2/error.log

        LogLevel warn

        CustomLog /var/log/apache2/ssl_access.log combined

        

        SSLEngine on

        SSLCertificateFile    /etc/ssl/certs/ssl-cert-snakeoil.pem

        SSLCertificateKeyFile /etc/ssl/private/ssl-cert-snakeoil.key

</VirtualHost>

Code:

# apache2ctl -SM

[Fri May 14 14:54:35 2010] [warn] NameVirtualHost *:80 has no VirtualHosts

VirtualHost configuration:

wildcard NameVirtualHosts and _default_ servers:

*:443                  deb03.example.com (/etc/apache2/sites-enabled/deb03:1)

Loaded Modules:

 core_module (static)

 log_config_module (static)

 logio_module (static)

 mpm_worker_module (static)

 http_module (static)

 so_module (static)

 alias_module (shared)

 auth_basic_module (shared)

 authn_file_module (shared)

 authz_default_module (shared)

 authz_groupfile_module (shared)

 authz_host_module (shared)

 authz_user_module (shared)

 autoindex_module (shared)

 cgid_module (shared)

 deflate_module (shared)

 dir_module (shared)

 env_module (shared)

 mime_module (shared)

 negotiation_module (shared)

 setenvif_module (shared)

 ssl_module (shared)

 status_module (shared)

Syntax OK

Log dump

Code:

==> /var/log/apache2/deb01_access.log <==

192.168.1.10 - - [14/May/2010:14:58:21 +0200] "\x16\x03\x01" 501 329 "-" "-"





[Fri May 14 14:58:13 2010] [debug] ssl_engine_init.c(384): Creating new SSL context (protocols: SSLv2, SSLv3, TLSv1)

[Fri May 14 14:58:13 2010] [debug] ssl_engine_init.c(384): Creating new SSL context (protocols: SSLv2, SSLv3, TLSv1)

[Fri May 14 14:58:13 2010] [debug] proxy_util.c(1800): proxy: grabbed scoreboard slot 0 in child 23411 for worker https://deb01.example.com/

[Fri May 14 14:58:13 2010] [debug] proxy_util.c(1896): proxy: initialized worker 0 in child 23411 for (deb01.example.com) min=0 max=25 smax=25

[Fri May 14 14:58:13 2010] [debug] proxy_util.c(1800): proxy: grabbed scoreboard slot 0 in child 23412 for worker https://deb01.example.com/

[Fri May 14 14:58:13 2010] [debug] proxy_util.c(1819): proxy: worker https://deb01.example.com/ already initialized

[Fri May 14 14:58:13 2010] [debug] proxy_util.c(1896): proxy: initialized worker 0 in child 23412 for (deb01.example.com) min=0 max=25 smax=25

[Fri May 14 14:58:21 2010] [debug] mod_proxy_http.c(60): proxy: HTTP: canonicalising URL //deb01.example.com/

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(1488): [client 192.168.1.10] proxy: https: found worker https://deb01.example.com/ for https://deb01.example.com/

[Fri May 14 14:58:21 2010] [debug] mod_proxy.c(966): Running scheme https handler (attempt 0)

[Fri May 14 14:58:21 2010] [debug] mod_proxy_http.c(1937): proxy: HTTP: serving URL https://deb01.example.com/

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(1990): proxy: HTTPS: has acquired connection for (deb01.example.com)

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(2046): proxy: connecting https://deb01.example.com/ to deb01.example.com:443

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(2139): proxy: connected / to deb01.example.com:443

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(2291): proxy: HTTPS: fam 2 socket created to connect to deb01.example.com

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(2386): proxy: HTTPS: connection complete to 192.168.122.11:443 (deb01.example.com)

[Fri May 14 14:58:21 2010] [info] [client 192.168.122.11] Connection to child 0 established (server deb01.example.com:80)

[Fri May 14 14:58:21 2010] [info] Seeding PRNG with 656 bytes of entropy

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1738): OpenSSL: Handshake: start

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: before/connect initialization

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv2/v3 write client hello A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 7/7 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 16 03 01 00 4a 02                                ....J.          |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1808): | 0007 - <SPACES/NULS>

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 72/72 bytes from BIO#851fd0 [mem: 859867] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 00 46 03 01 4b ed 48 ec-d2 4e 8d 67 95 9a f0 ec  .F..K.H..N.g.... |

...

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0040: f8 f1 24 4e ae 00 39                            ..$N..9          |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1808): | 0072 - <SPACES/NULS>

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 read server hello A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 16 03 01 01 c1                                  .....            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 449/449 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 0b 00 01 bd 00 01 ba 00-01 b7 30 82 01 b3 30 82  ..........0...0. |

...

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 01c0: 68                                              h                |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1196): Certificate Verification: depth: 0, subject: /CN=deb01.example.com, issuer: /CN=deb01.example.com

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1196): Certificate Verification: depth: 0, subject: /CN=deb01.example.com, issuer: /CN=deb01.example.com

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 read server certificate A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 16 03 01 01 8d                                  .....            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 397/397 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 0c 00 01 89 00 80 d6 7d-e4 40 cb bb dc 19 36 d6  .......}.@....6. |

...

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0180: d5 54 bc 53 c9 60 bb 47-d8 d1 73 36 67          .T.S.`.G..s6g    |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 read server key exchange A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 16 03 01 00 04                                  .....            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 4/4 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 0e                                              .                |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1808): | 0004 - <SPACES/NULS>

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 read server done A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 write client key exchange A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 write change cipher spec A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 write finished A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 flush data

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 14 03 01 00 01                                  .....            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 1/1 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 01                                              .                |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 16 03 01 00 30                                  ....0            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 48/48 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: e2 83 e5 af d6 60 5f 3f-f4 10 f9 30 f7 1a ef 58  .....`_?...0...X |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0010: cc ee 5b 7b 9d e2 5a a8-57 8f b6 76 f4 5a 65 79  ..[{..Z.W..v.Zey |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0020: 6f c8 69 7e 96 6b f7 66-74 74 1e 28 81 3b be 90  o.i~.k.ftt.(.;.. |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1746): OpenSSL: Loop: SSLv3 read finished A

[Fri May 14 14:58:21 2010] [debug] ssl_engine_kernel.c(1742): OpenSSL: Handshake: done

[Fri May 14 14:58:21 2010] [info] Connection: Client IP: 192.168.122.11, Protocol: TLSv1, Cipher: DHE-RSA-AES256-SHA (256/256 bits)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 17 03 01 01 30                                  ....0            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 304/304 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: fe e2 18 52 1e a8 1b fe-95 66 71 ae 15 59 13 5b  ...R.....fq..Y.[ |

...

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0120: 78 d2 70 dd c8 2f 2e 98-64 81 c1 83 0f 48 a1 69  x.p../..d....H.i |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] mod_proxy_http.c(1710): proxy: start body send

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 5/5 bytes from BIO#851fd0 [mem: 859860] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 17 03 01 01 60                                  ....`            |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1832): OpenSSL: read 352/352 bytes from BIO#851fd0 [mem: 859865] (BIO dump follows)

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1765): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0000: 04 2e 17 1d e4 03 ed 61-6b 58 4c 83 02 e9 6c 60  .......akXL...l` |

...

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1804): | 0150: f2 63 99 75 f9 af 44 c2-6b d8 66 88 16 41 86 dd  .c.u..D.k.f..A.. |

[Fri May 14 14:58:21 2010] [debug] ssl_engine_io.c(1810): +-------------------------------------------------------------------------+

[Fri May 14 14:58:21 2010] [debug] mod_proxy_http.c(1803): proxy: end body send

[Fri May 14 14:58:21 2010] [debug] proxy_util.c(2008): proxy: HTTPS: has released connection for (deb01.example.com)

Can anyone point me into the right direction? This is driving me nuts ;)

Thanks!