You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@httpd.apache.org by "Jens-U. Mozdzen" <jm...@nde.ag> on 2013/02/17 17:56:51 UTC
[users@httpd] SSL session problem
Hi list,
I could use a helping hand with a SSL problem. And my excuses for the
lengthy message... I've been doing plenty of tests so far, these are
my current results...
It's about a web mail site (running Horde5 on SLES11SP2 with latest
Novell updates, that's i.e. apache2-2.2.12-1.10.1 and
openssl-0.9.8j-0.44.1). Client-side certificates are one of the
elements to secure access to the server.
Users reported that sometimes access to the site stalls - one specific
case, 100% reproducible in our test environment, is uploading files
that exceed a specific size limit.
Symptoms on the client side is that the upload never seems to finish.
On the server side, we then see in Apache's error log "Re-negotiation
handshake failed: Not accepted by client!?" (and no other errors).
This is *not* the problem of a standard reneg buffer overflow - we
have "SSLRenegBufferSize 50486000" in the according <Location> section
(and the log message would have been different... been there ;) ).
Generally, access to the https server works nicely, even with the
client-side certificates. It are just some very specific "POST
request" situations that trigger the symptoms.
As this is perfectly reproducible in our test environment, I've had a
look at the trace from both server and client side and can hopefully
provide any required details to follow-up questions.
My test case is attaching files to a new email message, which is
implemented as an HTML form with POST action. When I attach a file
below some limit (3714 bytes) it works, 4480 bytes don't. HTML-wise,
the POST contains multiple MIME elements (text email body plus current
file attachment), I don't know if it's just that extra size or the
multi-part situation - but when I have no body, then larger files
work, too.
Client is i.e. Firefox from OpenSUSE (MozillaFirefox-18.0-2.29.2) or
via MS Windows (at least version 18.0, if not newer).
I could track things down to the POST request (HTTP content-length:
7795), which (according to the Wireshark traces) simply aborts,
meaning the server side seems to just shut down the connection. To
limit any side-effects, I restart httpd right before submitting each
POST request.
Looking at the traces, what catches the eye is the ordering of the
packet flow, which might "contribute to the problem":
client view:
... session setup, incl. TLS certificates exchange, session ticket...
c>s HTTP POST request (7 TCP segments, seq 9909 ack 3993)
s>c TCP ACK (seq 3393 ack 5773)
s>c TCP ACK (seq 3393 ack 8513)
s>c TCP ACK (seq 3393 ack 11253)
s>c TLSv1 Hello request
c>s TLSv1 Client Hello
s>c TCP FIN,ACK (seq 4022 ack 11636)
c>s TLSv1 Alert (warn/close notify)
c>s TCP FIN,ACK (seq 11871 ack 4023)
s>c TCP RST (seq 4022)
s>c TCP RST (seq 4023)
s>c TCP RST (seq 4023)
server view:
... session setup, incl. TLS certificates exchange, session ticket...
s>c: TCP ACK (seq 3993 ack 11253)
c>s: HTTP POST request (7 TCP segments, seq 11253 ack 3993)
s>c: TLSv1 Hello request
s>c: TCP FIN,ACK (seq 4022 ack 11636)
c>s: TLSv1 Client hello
s>c: TCP RST (seq 4022)
c>s: TLSv1 Alert (warn/close notify)
s>c: TCP RST (seq 4023)
c>s: TCP FIN,ACK (seq 11871 ack 4023)
s>c: TCP RST (seq 4023)
So the server immediately shuts down the TCP connection after starting
the hello sequence, without even giving the client a chance to respond.
When I look at the POST request that works (HTTP content-length:
7042), from the server side it's
c>s HTTP POST
s>c TCP ACK
s>c TLSv1 Hello Request
c>s TLSv1 Client Hello
s>c TLSv1 Server Hello
s>c TLSv1 Certificate request, Server hello done
...
just as one would expect it.
When I set up mod_ssl tracing, I see i.e. the following messages
during such an exchange:
--- cut here: error_log.ssl ---
[Sun Feb 17 17:39:09 2013] [info] Initial (No.1) HTTPS request
received for child 0 (server testserver.hh.nde.ag:443)
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(487): [client
192.168.101.26] Changed client verification type will force
renegotiation, referer:
https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1532): [client
192.168.101.26] filling buffer, max size 50486000 bytes
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1584): [client
192.168.101.26] total of 7813 bytes in buffer, eos=1
[Sun Feb 17 17:39:09 2013] [info] [client 192.168.101.26] Requesting
connection re-negotiation, referer:
https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(724): [client
192.168.101.26] Performing full renegotiation: complete handshake
protocol, referer:
https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1861): OpenSSL:
Handshake: start
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869): OpenSSL:
Loop: SSL renegotiate ciphers
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869): OpenSSL:
Loop: SSLv3 write hello request A
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869): OpenSSL:
Loop: SSLv3 flush data
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869): OpenSSL:
Loop: SSLv3 write hello request C
[Sun Feb 17 17:39:09 2013] [info] [client 192.168.101.26] Awaiting
re-negotiation handshake, referer:
https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1861): OpenSSL:
Handshake: start
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869): OpenSSL:
Loop: before accept initialization
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1886): OpenSSL: I/O
error, 5 bytes expected to read on BIO#7fcf89e1ca20 [mem: 7fcf89e220e0]
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1898): OpenSSL:
Exit: error in SSLv3 read client hello B
[Sun Feb 17 17:39:09 2013] [error] [client 192.168.101.26]
Re-negotiation handshake failed: Not accepted by client!?, referer:
https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1628): [client
192.168.101.26] read from buffered SSL brigade, mode 0, 8192 bytes
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1703): [client
192.168.101.26] buffered SSL brigade exhausted
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1628): [client
192.168.101.26] read from buffered SSL brigade, mode 0, 8192 bytes
[Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1628): [client
192.168.101.26] read from buffered SSL brigade, mode 2, 0 bytes
--- cut here ---
Somehow, it again seems, that the server isn't "waiting" for the
client's "TLS Client Hello" but immediately aborts (OpenSSL: I/O
error, 5 bytes expected to read on BIO#7fcf89e1ca20).
Since everything else works, including accessing the
certificate-protected areas of the server (and I see the completed
initial negotiation of the TLS session including the certificates),
I'm lost. Can somebody give me a helping hand on how to find the root
cause of this?
With regards,
Jens
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] SSL session problem
Posted by Jens-Uwe Mozdzen <jm...@nde.ag>.
Hi Tom,
Zitat von Tom Evans <te...@googlemail.com>:
> On Sun, Mar 3, 2013 at 10:36 PM, Jens-U. Mozdzen <jm...@nde.ag> wrote:
>> Zitat von Jens-Uwe Mozdzen <jm...@nde.ag>:
>>>
>>> Zitat von "Jens-U. Mozdzen" <jm...@nde.ag>:
>>>>
>>>> Hi list,
>>>>
>>>> I could use a helping hand with a SSL problem.
>>>
>>> [...]
>>
>>
>> Anything I should do differently to get at least an ack from this list? Or
>> is there some other, more appropriate list? I'd then be grateful for some
>> pointer...
>>
>
> ack. This is the appropriate list, but I haven't a clue about your
> in-depth SSL issue.
thank you for the response :)
> [...]
> If it doesn't, at least you can tell the list a stock apache and stock
> SSL experienced this error, which may be more enticing than having to
> setup a vendor's old stack to find (potentially) old bugs.
As I was able to show that a current Apache/openssl combo works, I'm
taking this to the vendor support channels to get resolved.
As this is a rather complicated issue indeed, in a code area which had
stirred some dust earlier and the SuSE server is rather common, I
wanted to get a first opinion from the list. Now that I have, I know
whom to bug ;)
With regards,
Jens
--
Jens-U. Mozdzen voice : +49-40-559 51 75
NDE Netzdesign und -entwicklung AG fax : +49-40-559 51 77
Postfach 61 03 15 mobile : +49-179-4 98 21 98
D-22423 Hamburg e-mail : jmozdzen@nde.ag
Vorsitzende des Aufsichtsrates: Angelika Mozdzen
Sitz und Registergericht: Hamburg, HRB 90934
Vorstand: Jens-U. Mozdzen
USt-IdNr. DE 814 013 983
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] SSL session problem
Posted by Tom Evans <te...@googlemail.com>.
On Sun, Mar 3, 2013 at 10:36 PM, Jens-U. Mozdzen <jm...@nde.ag> wrote:
> Zitat von Jens-Uwe Mozdzen <jm...@nde.ag>:
>>
>> Zitat von "Jens-U. Mozdzen" <jm...@nde.ag>:
>>>
>>> Hi list,
>>>
>>> I could use a helping hand with a SSL problem.
>>
>> [...]
>
>
> Anything I should do differently to get at least an ack from this list? Or
> is there some other, more appropriate list? I'd then be grateful for some
> pointer...
>
ack. This is the appropriate list, but I haven't a clue about your
in-depth SSL issue.
> It's about a web mail site (running Horde5 on SLES11SP2 with latest Novell updates, that's i.e. apache2-2.2.12-1.10.1 and openssl-0.9.8j-0.44.1)
So, big companies love to stick on various versions of open source
software. They may even go back and fold security fixes in to these
older versions, but they are unlikely to fold new features or bug
fixes back in.
The very first thing that you should do is to uninstall those
versions, install the latest versions of apache 2.2, and your choice
of latest SSL version - either 0.9.8y or 1.0.1e, not some arbitrary
choice - and see if that does fix your problem. If it does, go back to
Novell and tell them.
If it doesn't, at least you can tell the list a stock apache and stock
SSL experienced this error, which may be more enticing than having to
setup a vendor's old stack to find (potentially) old bugs.
Cheers
Tom
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] SSL session problem
Posted by "Jens-U. Mozdzen" <jm...@nde.ag>.
Zitat von Jens-Uwe Mozdzen <jm...@nde.ag>:
> Zitat von "Jens-U. Mozdzen" <jm...@nde.ag>:
>> Hi list,
>>
>> I could use a helping hand with a SSL problem.
> [...]
Anything I should do differently to get at least an ack from this
list? Or is there some other, more appropriate list? I'd then be
grateful for some pointer...
Regards,
Jens
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org
Re: [users@httpd] SSL session problem
Posted by Jens-Uwe Mozdzen <jm...@nde.ag>.
Zitat von "Jens-U. Mozdzen" <jm...@nde.ag>:
> Hi list,
>
> I could use a helping hand with a SSL problem. And my excuses for
> the lengthy message... I've been doing plenty of tests so far, these
> are my current results...
>
> It's about a web mail site (running Horde5 on SLES11SP2 with latest
> Novell updates, that's i.e. apache2-2.2.12-1.10.1 and
> openssl-0.9.8j-0.44.1). Client-side certificates are one of the
> elements to secure access to the server.
>
> Users reported that sometimes access to the site stalls - one
> specific case, 100% reproducible in our test environment, is
> uploading files that exceed a specific size limit.
>
> Symptoms on the client side is that the upload never seems to
> finish. On the server side, we then see in Apache's error log
> "Re-negotiation handshake failed: Not accepted by client!?" (and no
> other errors).
>
> This is *not* the problem of a standard reneg buffer overflow - we
> have "SSLRenegBufferSize 50486000" in the according <Location>
> section (and the log message would have been different... been there
> ;) ).
>
> Generally, access to the https server works nicely, even with the
> client-side certificates. It are just some very specific "POST
> request" situations that trigger the symptoms.
>
> As this is perfectly reproducible in our test environment, I've had
> a look at the trace from both server and client side and can
> hopefully provide any required details to follow-up questions.
>
> My test case is attaching files to a new email message, which is
> implemented as an HTML form with POST action. When I attach a file
> below some limit (3714 bytes) it works, 4480 bytes don't. HTML-wise,
> the POST contains multiple MIME elements (text email body plus
> current file attachment), I don't know if it's just that extra size
> or the multi-part situation - but when I have no body, then larger
> files work, too.
>
> Client is i.e. Firefox from OpenSUSE (MozillaFirefox-18.0-2.29.2) or
> via MS Windows (at least version 18.0, if not newer).
>
> I could track things down to the POST request (HTTP content-length:
> 7795), which (according to the Wireshark traces) simply aborts,
> meaning the server side seems to just shut down the connection. To
> limit any side-effects, I restart httpd right before submitting each
> POST request.
>
> Looking at the traces, what catches the eye is the ordering of the
> packet flow, which might "contribute to the problem":
>
> client view:
> ... session setup, incl. TLS certificates exchange, session ticket...
> c>s HTTP POST request (7 TCP segments, seq 9909 ack 3993)
> s>c TCP ACK (seq 3393 ack 5773)
> s>c TCP ACK (seq 3393 ack 8513)
> s>c TCP ACK (seq 3393 ack 11253)
> s>c TLSv1 Hello request
> c>s TLSv1 Client Hello
> s>c TCP FIN,ACK (seq 4022 ack 11636)
> c>s TLSv1 Alert (warn/close notify)
> c>s TCP FIN,ACK (seq 11871 ack 4023)
> s>c TCP RST (seq 4022)
> s>c TCP RST (seq 4023)
> s>c TCP RST (seq 4023)
>
> server view:
> ... session setup, incl. TLS certificates exchange, session ticket...
> s>c: TCP ACK (seq 3993 ack 11253)
> c>s: HTTP POST request (7 TCP segments, seq 11253 ack 3993)
> s>c: TLSv1 Hello request
> s>c: TCP FIN,ACK (seq 4022 ack 11636)
> c>s: TLSv1 Client hello
> s>c: TCP RST (seq 4022)
> c>s: TLSv1 Alert (warn/close notify)
> s>c: TCP RST (seq 4023)
> c>s: TCP FIN,ACK (seq 11871 ack 4023)
> s>c: TCP RST (seq 4023)
>
> So the server immediately shuts down the TCP connection after
> starting the hello sequence, without even giving the client a chance
> to respond.
>
> When I look at the POST request that works (HTTP content-length:
> 7042), from the server side it's
> c>s HTTP POST
> s>c TCP ACK
> s>c TLSv1 Hello Request
> c>s TLSv1 Client Hello
> s>c TLSv1 Server Hello
> s>c TLSv1 Certificate request, Server hello done
> ...
> just as one would expect it.
>
> When I set up mod_ssl tracing, I see i.e. the following messages
> during such an exchange:
>
> --- cut here: error_log.ssl ---
> [Sun Feb 17 17:39:09 2013] [info] Initial (No.1) HTTPS request
> received for child 0 (server testserver.hh.nde.ag:443)
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(487): [client
> 192.168.101.26] Changed client verification type will force
> renegotiation, referer:
> https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1532): [client
> 192.168.101.26] filling buffer, max size 50486000 bytes
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1584): [client
> 192.168.101.26] total of 7813 bytes in buffer, eos=1
> [Sun Feb 17 17:39:09 2013] [info] [client 192.168.101.26] Requesting
> connection re-negotiation, referer:
> https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(724): [client
> 192.168.101.26] Performing full renegotiation: complete handshake
> protocol, referer:
> https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1861):
> OpenSSL: Handshake: start
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869):
> OpenSSL: Loop: SSL renegotiate ciphers
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869):
> OpenSSL: Loop: SSLv3 write hello request A
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869):
> OpenSSL: Loop: SSLv3 flush data
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869):
> OpenSSL: Loop: SSLv3 write hello request C
> [Sun Feb 17 17:39:09 2013] [info] [client 192.168.101.26] Awaiting
> re-negotiation handshake, referer:
> https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1861):
> OpenSSL: Handshake: start
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1869):
> OpenSSL: Loop: before accept initialization
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1886): OpenSSL:
> I/O error, 5 bytes expected to read on BIO#7fcf89e1ca20 [mem:
> 7fcf89e220e0]
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_kernel.c(1898):
> OpenSSL: Exit: error in SSLv3 read client hello B
> [Sun Feb 17 17:39:09 2013] [error] [client 192.168.101.26]
> Re-negotiation handshake failed: Not accepted by client!?, referer:
> https://testserver.hh.nde.ag/horde5/imp/dynamic.php?page=compose&type=template&mailbox=SU5CT1gvVGVtcGxhdGVz&uid=4&token=SToMqgkSgG6XH-dspiQTJA1&uniq=1361109712088
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1628): [client
> 192.168.101.26] read from buffered SSL brigade, mode 0, 8192 bytes
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1703): [client
> 192.168.101.26] buffered SSL brigade exhausted
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1628): [client
> 192.168.101.26] read from buffered SSL brigade, mode 0, 8192 bytes
> [Sun Feb 17 17:39:09 2013] [debug] ssl_engine_io.c(1628): [client
> 192.168.101.26] read from buffered SSL brigade, mode 2, 0 bytes
> --- cut here ---
>
> Somehow, it again seems, that the server isn't "waiting" for the
> client's "TLS Client Hello" but immediately aborts (OpenSSL: I/O
> error, 5 bytes expected to read on BIO#7fcf89e1ca20).
>
> Since everything else works, including accessing the
> certificate-protected areas of the server (and I see the completed
> initial negotiation of the TLS session including the certificates),
> I'm lost. Can somebody give me a helping hand on how to find the
> root cause of this?
>
> With regards,
> Jens
I re-tested the environment with an updated client system (firefox 19,
openssl 1.0.1e), same results.
In parallel, we've set up a different apache environment on the same
SLES11SP2 server:
www:/opt/lampp # bin/httpd -V
Server version: Apache/2.4.3 (Unix)
Server built: Aug 28 2012 06:58:02
Server's Module Magic Number: 20120211:6
Server loaded: APR 1.4.6, APR-UTIL 1.4.1
Compiled using: APR 1.4.6, APR-UTIL 1.4.1
and openssl 1.0.1c - and that software combo works like a charm. So I
believe I can say it's not client-specific, but a software problem on
the server side.
As production servers are affected, I'd like to know whether the root
cause lies within openssl or within Apache's mod_ssl, so I can ask the
distribution folks to update appropriately.
Any help out there?
Regards,
Jens
>
>
> ---------------------------------------------------------------------
> To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
> For additional commands, e-mail: users-help@httpd.apache.org
--
Jens-U. Mozdzen voice : +49-40-559 51 75
NDE Netzdesign und -entwicklung AG fax : +49-40-559 51 77
Postfach 61 03 15 mobile : +49-179-4 98 21 98
D-22423 Hamburg e-mail : jmozdzen@nde.ag
Vorsitzende des Aufsichtsrates: Angelika Mozdzen
Sitz und Registergericht: Hamburg, HRB 90934
Vorstand: Jens-U. Mozdzen
USt-IdNr. DE 814 013 983
---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@httpd.apache.org
For additional commands, e-mail: users-help@httpd.apache.org