It would be a big task to change the ATS to 7.x in my server and do the
test. And this particular issue actually happened in our production
environment.

Thanks
~S

On 22 February 2018 at 22:16, Susan Hinrichs <shinr...@oath.com> wrote:

> Alan also pointed out that you are running ATS 6.x.  Could you try your
> test scenario on ATS 7.1.2?  We've made considerable cleanup on the TLS
> handshake and more debugging in the client cert verification.
>
> Looking at your pcap file and your logs, it appears that the certs are
> being exchanged.  Both the server and the client certs are signed by the
> same entities so setting the same CA files makes sense.
>
>
>
> On Thu, Feb 22, 2018 at 10:17 AM, Persia Aziz <persia.a...@yahoo.com>
> wrote:
>
>> ``CONFIG proxy.config.ssl.client.verify.server INT 0'' is disabling
>> origin server certificate verification(i.e., when ATS initiates handshake
>> to the origin server). From the configs you specified in this email, looks
>> like you want the client cert to be verified by ATS. I have attached a
>> screenshot of wireshark and ATS logs capturing ssl handshake where the
>> client cert verification fails.
>> Syeda Persia Aziz
>> Software Developer
>> Yahoo! Inc.
>> Champaign, Illinois
>>
>>
>> On Thursday, February 22, 2018, 9:05:27 AM CST, salil GK <
>> gksa...@gmail.com> wrote:
>>
>>
>> I wanted to have MTLS proxy. Hence we have to have client cert
>> verification in server side. So  proxy.config.ssl.client.CA.cert.filename
>> and proxy.config.ssl.client.CA.cert.path are set
>> I have verified tomcat certificate ( which is what client is using for
>> connection ) using ca.pem in the server and they are good.
>>
>>
>>
>> On Feb 22, 2018 7:49 PM, "Susan Hinrichs" <shinr...@oath.com> wrote:
>>
>> 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:p eer 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:mainEve nt] 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.co m
>> <http://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_certi ficate: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:140 890C7:SSL
>> routines:ssl3_get_client_certi ficate: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::sslServerHa
>> ndShakeEvent, 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.filen ame STRING ca.pem
>>
>> CONFIG proxy.config.ssl.CA.cert.path STRING /directory/where/ca.pem
>>
>>
>> # and
>>
>>
>> CONFIG proxy.config.ssl.client.CA.cer t.filename STRING ca.pem
>>
>> CONFIG proxy.config.ssl.client.CA.cer t.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