trafficserver-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Susan Hinrichs <shinr...@oath.com>
Subject Re: Connection rejected for MTLS forward proxy
Date Wed, 21 Feb 2018 19:44:13 GMT
It looks like in this exchange the client did not send a client
certificate.  But the other exchanges in the log file don't have the "
ssl3_get_client_certificate:peer did not return a certificate" message.  So
perhaps one test exchange had the client certificate missing.

The server certificate is being selected, so I assume the server
certificate message is being sent back to the client.

On Wed, Feb 21, 2018 at 1:11 PM, Alan Carroll <solidwallofcode@oath.com>
wrote:

> This looks like the important part of the logs (you can drop by my desk
> for further detail if you want, Susan & Persia). AFAICT this covers an
> entire transaction. I checked the start up messages and saw no errors, but
> I did not see any mention of 'ca.pem'. Is there some typo in his
> configuration? Is the ATS version too old to support client certificate
> verification? I'm beginning to suspect that.
>
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNextProtocolAccept.cc:129 (mainEvent)> (ssl)
> [SSLNextProtocolAccept:mainEvent] event 202 netvc 0x5567d9e4aca0
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:978 (sslStartHandShake)>
> (ssl) IP context is (nil) for [XXX.XXX.XXX.33:34686] ->
> [XXX.XXX.XXX.XXX:8445], default context 0x5567d9bcf430
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 16 ret: 1
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:284 (set_context_cert)> (ssl)
> set_context_cert ssl=0x5567d9a86d30 server=gmt-dvor-vcsc1.cisco.com
> handshake_complete=0
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:336 (set_context_cert)> (ssl)
> ssl_cert_callback found SSL context 0x5567d9bcf430 for requested name '
> gmt-dvor-vcsc1.cisco.com'
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1459 (callHooks)> (ssl)
> callHooks sslHandshakeHookState=0
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.661+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8193 ret: 1
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8194 ret: -1
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8194 ret: -1
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1102
> (sslServerHandShakeEvent)> (ssl) trace=FALSE
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1106
> (sslServerHandShakeEvent)> (ssl) SSL handshake error: SSL_ERROR_WANT_READ
> (2), errno=0
> 2018-02-21T10:21:42.681+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:514 (net_read_io)> (ssl) ssl
> handshake for vc 0x5567d9e4aca0, took 0.018 seconds, configured
> handshake_timer: 20
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 16392 ret: 552
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1687 (ssl_callback_info)> (ssl)
> ssl_callback_info ssl: 0x5567d9a86d30 where: 8194 ret: -1
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:2154 (SSLAccept)> (ssl.error.accept)
> SSL accept returned -1, ssl_error=1, ERR_get_error=336105671
> (error:140890C7:SSL routines:ssl3_get_client_certificate:peer did not
> return a certificate)
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1102
> (sslServerHandShakeEvent)> (ssl) trace=FALSE
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1106
> (sslServerHandShakeEvent)> (ssl) SSL::140565060720448:error:140890C7:SSL
> routines:ssl3_get_client_certificate:peer did not return a
> certificate:s3_srvr.c:3413: peer address is XXX.XXX.XXX.33
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1106
> (sslServerHandShakeEvent)> (ssl) SSL handshake error: SSL_ERROR_SSL (1),
> errno=0
> 2018-02-21T10:21:42.749+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLNetVConnection.cc:1234
> (sslServerHandShakeEvent)> (ssl) SSLNetVConnection::sslServerHandShakeEvent,
> SSL_ERROR_SSL errno=0
>
> Here's a bit more from process start, which is the only certificate I see
> loaded:
>
> 2018-02-21T08:32:50.209+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1835 (ssl_store_ssl_context)> (ssl)
> importing SNI names from server.pem
> 2018-02-21T08:32:50.209+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLUtils.cc:1649 (ssl_index_certificate)> (ssl)
> mapping 'gmt-dvor-vcsc1.cisco.com' to certificate server.pem
> 2018-02-21T08:32:50.209+00:00 gmt-dvor-vcsc1 traffic_server[10353]:
> {0x7fd7da831740} DEBUG: <SSLCertLookup.cc:380 (insert)> (ssl) indexed '
> gmt-dvor-vcsc1.cisco.com' with SSL_CTX 0x5567d9bcf430 [1]
>
>
> On Wed, Feb 21, 2018 at 12:22 PM, Susan Hinrichs <shinrich@oath.com>
> wrote:
>
>> If you are in a test environment where you can share your wireshark pcap
>> file that might also be interesting.
>>
>> On Wed, Feb 21, 2018 at 11:58 AM, Persia Aziz <persia.aziz@yahoo.com>
>> wrote:
>>
>>> Do you see this EOF if you have client verification disabled?
>>>
>>> Syeda Persia Aziz
>>> Software Developer
>>> Yahoo! Inc.
>>> Champaign, Illinois
>>>
>>>
>>> On Wednesday, February 21, 2018, 11:48:40 AM CST, Persia Aziz <
>>> persia.aziz@yahoo.com> wrote:
>>>
>>>
>>>
>>> Hmm interesting. From  your debug log, looks like ATS wants to read more
>>> data from the buffer which it can not find. Hence, throwing an EOF.
>>>
>>> Syeda Persia Aziz
>>> Software Developer
>>> Yahoo! Inc.
>>> Champaign, Illinois
>>>
>>>
>>> On Wednesday, February 21, 2018, 11:35:11 AM CST, salil GK <
>>> gksalil@gmail.com> wrote:
>>>
>>>
>>> I have assigned these variables also the same values -
>>>
>>> CONFIG proxy.config.ssl.CA.cert.filename STRING ca.pem
>>>
>>> CONFIG proxy.config.ssl.CA.cert.path STRING /directory/where/ca.pem
>>>
>>>
>>> # and
>>>
>>>
>>> CONFIG proxy.config.ssl.client.CA.cert.filename STRING ca.pem
>>>
>>> CONFIG proxy.config.ssl.client.CA.cert.path STRING
>>> /directory/where/ca.pem
>>>
>>> On 21 February 2018 at 22:48, Persia Aziz <persia.aziz@yahoo.com> wrote:
>>>
>>> Hi,
>>>
>>> What you want is 'proxy.config.ssl.CA.cert. filename' and proxy.config.ssl.CA.cert.
>>> path not the client.CA configs. I know it is a bit confusing. The
>>> client.CA ones are used to verify origin server certificates. Try the
>>> configs and see if that works.
>>>
>>> Docs for the configs:
>>>
>>> records.config — Apache Traffic Server 8.0.0 documentation
>>> <https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.config.en.html?highlight=proxy%20config%20ssl%20ca%20cert%20filename#proxy.config.ssl.CA.cert.filename>
>>>
>>> records.config — Apache Traffic Server 8.0.0 documentation
>>>
>>>
>>> <https://docs.trafficserver.apache.org/en/latest/admin-guide/files/records.config.en.html?highlight=proxy%20config%20ssl%20ca%20cert%20filename#proxy.config.ssl.CA.cert.filename>
>>>
>>>
>>>
>>> - Sincerely
>>> Syeda Persia Aziz
>>> Software Developer
>>> Yahoo! Inc.
>>> Champaign, Illinois
>>>
>>>
>>> On Wednesday, February 21, 2018, 10:41:32 AM CST, Alan Carroll <
>>> solidwallofcode@oath.com> wrote:
>>>
>>>
>>> I meant more what *units* the handshake_timer is. Looking at the code,
>>> it seems to be in seconds meaning it is unlikely that is the problem (if
>>> the handshake took .5s with a 20s timeout).
>>>
>>> I'd recommend having any configuration value at most once, although I
>>> don't think it would break anything.
>>>
>>> Looking at the code, it appears the client cert verify callback was hit
>>> (SSLUtils.cc:1687) with a failure reported by openSSL. I'd look at debug
>>> messages much earlier, during process start, to see if the certs are
>>> getting loaded correctly.
>>>
>>>
>>>
>>>
>>
>

Mime
View raw message