I would assume that your CA files are not set correctly for ATS to verify
the origin certificates sent to it.
proxy.config.ssl.client.CA.cert.filename and
proxy.config.ssl.client.CA.cert.path.  If you don't care about having ATS
verify the origin certificates, you can leave the
proxy.config.ssl.client.verify.server set to 0.

On Thu, Feb 22, 2018 at 5:46 AM, salil GK <gksa...@gmail.com> wrote:

> I have set client server verification to 'no'
>
> CONFIG proxy.config.ssl.client.verify.server INT 0
>
> and this time things went fie and ATS worked as forward proxy.
> So looks like client verification failure in server side only I guess ?
>
> Thanks
> ~S
>
> On 22 February 2018 at 01:14, Susan Hinrichs <shinr...@oath.com> wrote:
>
>> 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 <solidwallofc...@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 <shinr...@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.a...@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.a...@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 <
>>>>> gksa...@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.a...@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 <
>>>>> solidwallofc...@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.
>>>>>
>>>>>
>>>>>
>>>>>
>>>>
>>>
>>
>

Reply via email to