upstream: add transport socket failure reason to stream info and log by lizan · Pull Request #6018 · envoyproxy/envoy

lizan · 2019-02-21T06:05:15Z

Description:
Fixes #5603

Risk Level: Low (not changing flow, add more info)
Testing: unit test,
Docs Changes: Added
Release Notes: Added

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123

Thanks, a few high level questions before a full review.

/wait

docs/root/configuration/access_log.rst

mattklein123 · 2019-03-05T17:55:12Z

docs/root/configuration/access_log.rst


+%UPSTREAM_TRANSPORT_FAILURE_REASON%
+  HTTP
+    The reason of upstream transport failure, this is usually upstream TLS connection failure with 503 response code.


Can you make this a little more clear? Is the latter part of the sentence the actual error message? Should it be in quotes? Also, do we want a string here, or should we have well defined error codes like we do for other failures?

I considered well defined error codes but I chose a string here due to the transport socket extensibility and it is likely only used in logging purpose. We can make some well known errors as predefined strings though. No the latter part is not the actual message, will update the document.

mattklein123 · 2019-03-05T17:55:29Z

docs/root/configuration/access_log.rst

+    The reason of upstream transport failure, this is usually upstream TLS connection failure with 503 response code.
+
+  TCP
+    Not implemented ("-")


We could implement this, right? Is there a TODO somewhere?

Added a TODO, will look into this later to see if I can implement within this PR.

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123

Thanks generally looks good. I think I would prefer if we had some more documentation for the known messages that the built-in transport sockets emit. Can we add that?

Also, are there any relevant errors we should print for the non-TLS transport? I guess I'm wondering if we should do the equivalent of strerror to print out connection failure reasons, etc.? Might not be worth it in this PR but maybe a TODO somewhere if you think that would be relevant?

/wait

source/common/router/router.h

mattklein123 · 2019-03-06T00:22:31Z

source/extensions/transport_sockets/tls/ssl_socket.cc


 namespace {
+
+constexpr absl::string_view NotReadyReason{"SSL error: secret is not ready"};


nit: What does this mean? Can you make the error message a bit better or potentially actually document all the potential errors for the built-in transport sockets somewhere?

I hope now it is better, when SDS is configured there are chances that Cluster are up but Secret is not ready.

test/extensions/transport_sockets/tls/ssl_socket_test.cc

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

lizan · 2019-03-07T06:01:15Z

I think I would prefer if we had some more documentation for the known messages that the built-in transport sockets emit. Can we add that?

Done.

Also, are there any relevant errors we should print for the non-TLS transport? I guess I'm wondering if we should do the equivalent of strerror to print out connection failure reasons, etc.? Might not be worth it in this PR but maybe a TODO somewhere if you think that would be relevant?

Yes that's one of the reason I put it into Connection interface, left a TODO there.

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123

Thanks for the extra docs, it makes the feature really clear and obviously useful to me. A few small additional doc/error thoughts.

/wait

mattklein123 · 2019-03-08T17:19:55Z

docs/root/intro/arch_overview/ssl.rst

+Trouble shooting
+----------------
+
+When Envoy originates TLS when making connections to upstream clusters, its error will be logged into


nit: "..., any errors will be logged into the ..."

mattklein123 · 2019-03-08T17:20:54Z

docs/root/intro/arch_overview/ssl.rst

+:ref:`UPSTREAM_TRANSPORT_FAILURE_REASON<config_access_log_format_upstream_transport_failure_reason>` field.
+Common errors are:
+
+* ``Secret is not delivered via SDS``: Envoy is still waiting SDS to deliver key/cert or root CA.


nit: I think I would call this error "Secret not supplied by SDS" WDYT?
nit: "still waiting for"

mattklein123 · 2019-03-08T17:22:10Z

docs/root/intro/version_history.rst

 * access log: added a new flag for upstream retry count exceeded.
 * access log: added a :ref:`gRPC filter <envoy_api_msg_config.filter.accesslog.v2.GrpcStatusFilter>` to allow filtering on gRPC status.
 * access log: added a new flag for stream idle timeout.
+* access log: added UPSTREAM_TRANSPORT_FAILURE_REASON for HTTP.


nit: can you ref link to both new proto field and text formatting docs?

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

lizan · 2019-03-08T20:35:13Z

@mattklein123 docs updated, let's merge #6142 first and I will update this PR. I believe they conflicts.

mattklein123

Agreed on merging the other one first. Thanks!

mattklein123 · 2019-03-08T20:54:54Z

source/extensions/transport_sockets/tls/ssl_socket.cc

 namespace {

-constexpr absl::string_view NotReadyReason{"TLS error: Secret is not delivered via SDS"};
+constexpr absl::string_view NotReadyReason{"TLS error: Secret is not supplied by SDS"};


Would be nice if there was a test that covers this?

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

* master: token bucket: several fixes (envoyproxy#6235) config: move logging of full response to trace logging (envoyproxy#6226) mysql_filter: add a warning about compatibility (envoyproxy#6234) upstream: add transport socket failure reason to stream info and log (envoyproxy#6018) IoHandle readv and writev (envoyproxy#6037) Signed-off-by: Michael Puncel <mpuncel@squareup.com>

This fixes a bug in the pre-tls_async_cert_validation codepath. The tls_async_cert_validation codepath is unaffected. Per both OpenSSL and BoringSSL documentation, if you use SSL_CTX_set_cert_verify_callback, the library expects to find the error code in X509_STORE_CTX. This error determines the TLS alert. X509_verify_cert does this for you, but Envoy's callback was not doing this when doSynchronousVerifyCertChain runs the extra checks in verifyCertAndUpdateStatus. This change fixes this and sets the generic X509_V_ERR_APPLICATION_VERIFICATION. Before this commit, the error would usually be X509_V_OK, but sometimes it would be something else. Envoy implements the allow_expired_certificate using the X509_STORE_CTX verify callback, via ignoreCertificateExpirationCallback. This callback, when it suppresses an error, will sometimes leave stray errors in X509_STORE_CTX. These are usually benign, *but* if Envoy then does extra checks, which fail, and then report some *other* failure, it will inadvertantly return the stray error to BoringSSL! That is why FailedClientCertAllowExpiredBadHashVerification expected a SSLV3_ALERT_CERTIFICATE_EXPIRED alert. The alert makes no sense because the connection sets allow_expired_certificate! Rather, the test actually caught an Envoy bug, but envoyproxy#6018 mistakenly codified it as expected behavior, rather than correctly diagnosing it as a bug. This commit fixes that bug. Unfortunately, OpenSSL/BoringSSL map X509_V_ERR_APPLICATION_VERIFICATION to handshake_failure rather than certificate_unknown, so this does change the alert returned by the pre-tls_async_cert_validation codepath in other cases. (certificate_unknown came from X509_V_OK hitting the default in a switch-case.) Arguably certificate_unknown is a better alert than handshake_failure, so I'm slightly inclined to fix BoringSSL to map that differently. But since Envoy needs to support an old BoringSSL, I've just updated the expectations for now. Either way, tls_async_cert_validation gives full control over the alert and will make this moot. Signed-off-by: David Benjamin <davidben@google.com>

This fixes a bug in the pre-tls_async_cert_validation codepath. The tls_async_cert_validation codepath is unaffected. Per both OpenSSL and BoringSSL documentation, if you use SSL_CTX_set_cert_verify_callback, the library expects to find the error code in X509_STORE_CTX. This error determines the TLS alert. X509_verify_cert does this for you, but Envoy's callback was not doing this when doSynchronousVerifyCertChain runs the extra checks in verifyCertAndUpdateStatus. This change fixes this and sets the generic X509_V_ERR_APPLICATION_VERIFICATION. Before this commit, the error would usually be X509_V_OK, but sometimes it would be something else. Envoy implements the allow_expired_certificate using the X509_STORE_CTX verify callback, via ignoreCertificateExpirationCallback. This callback, when it suppresses an error, will sometimes leave stray errors in X509_STORE_CTX. These are usually benign, *but* if Envoy then does extra checks, which fail, and then report some *other* failure, it will inadvertantly return the stray error to BoringSSL! That is why FailedClientCertAllowExpiredBadHashVerification expected a SSLV3_ALERT_CERTIFICATE_EXPIRED alert. The alert makes no sense because the connection sets allow_expired_certificate! Rather, the test actually caught an Envoy bug, but #6018 mistakenly codified it as expected behavior, rather than correctly diagnosing it as a bug. This commit fixes that bug. Unfortunately, OpenSSL/BoringSSL map X509_V_ERR_APPLICATION_VERIFICATION to handshake_failure rather than certificate_unknown, so this does change the alert returned by the pre-tls_async_cert_validation codepath in other cases. (certificate_unknown came from X509_V_OK hitting the default in a switch-case.) Arguably certificate_unknown is a better alert than handshake_failure, so I'm slightly inclined to fix BoringSSL to map that differently. But since Envoy needs to support an old BoringSSL, I've just updated the expectations for now. Either way, tls_async_cert_validation gives full control over the alert and will make this moot. Signed-off-by: David Benjamin <davidben@google.com>

lizan added 8 commits February 20, 2019 22:02

WIP: tls failure details

eab96e7

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

put upstream transport failure reason into StreamInfo

b3da417

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

log upstream transport failure reason

f2feb4d

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

spelling

b2525cd

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

fix test

7b772c7

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

fix format

a656610

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

Merge remote-tracking branch 'upstream/master' into tls_details

ce56340

plumbing all way down to log

b69ff02

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123 added the waiting label Feb 25, 2019

lizan added 2 commits March 3, 2019 00:06

Merge remote-tracking branch 'upstream/master' into tls_details

e300c92

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

fix test build

6d6599a

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

repokitteh-read-only bot removed the waiting label Mar 4, 2019

mattklein123 self-assigned this Mar 5, 2019

mattklein123 added the waiting label Mar 5, 2019

lizan added 2 commits March 4, 2019 19:37

more string_view

b7642b9

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

docs

2b040aa

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

repokitteh-read-only bot removed the waiting label Mar 5, 2019

lizan marked this pull request as ready for review March 5, 2019 08:20

lizan requested a review from htuch as a code owner March 5, 2019 08:20

mattklein123 requested changes Mar 5, 2019

View reviewed changes

repokitteh-read-only bot added the waiting label Mar 5, 2019

grpc als

741f384

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

repokitteh-read-only bot removed the waiting label Mar 5, 2019

TODO for TCP

989f20b

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123 requested changes Mar 6, 2019

View reviewed changes

repokitteh-read-only bot added the waiting label Mar 6, 2019

lizan added 3 commits March 6, 2019 00:31

Merge remote-tracking branch 'upstream/master' into tls_details

0562b75

test: expect failure reason

982562f

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

review comment, more docs

4bf7969

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

repokitteh-read-only bot removed the waiting label Mar 7, 2019

mattklein123 added the waiting label Mar 7, 2019

fix merge

06c53bf

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

repokitteh-read-only bot removed the waiting label Mar 7, 2019

fix

70e4b1e

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

lizan requested a review from mattklein123 March 7, 2019 21:41

fix gcc build

b59e80d

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123 requested changes Mar 8, 2019

View reviewed changes

repokitteh-read-only bot added the waiting label Mar 8, 2019

updated per review comments

4311066

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

repokitteh-read-only bot removed the waiting label Mar 8, 2019

link in tls doc as well

7c89f69

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

mattklein123 previously approved these changes Mar 8, 2019

View reviewed changes

mattklein123 added the waiting label Mar 8, 2019

lizan added 2 commits March 8, 2019 14:43

Merge remote-tracking branch 'upstream/master' into tls_details

7e7523f

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

add test for not ready reason

48da72b

Signed-off-by: Lizan Zhou <lizan@tetrate.io>

lizan dismissed mattklein123’s stale review via 48da72b March 8, 2019 22:44

repokitteh-read-only bot removed the waiting label Mar 8, 2019

mattklein123 approved these changes Mar 8, 2019

View reviewed changes

lizan merged commit b41ba59 into envoyproxy:master Mar 10, 2019

lizan deleted the tls_details branch March 10, 2019 07:50

davidben mentioned this pull request Sep 29, 2022

tls: fix error-reporting in doSynchronousVerifyCertChain #23319

Merged


		namespace {

		constexpr absl::string_view NotReadyReason{"SSL error: secret is not ready"};

Conversation

lizan commented Feb 21, 2019 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

mattklein123 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

mattklein123 left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Uh oh!

lizan commented Mar 7, 2019

Uh oh!

mattklein123 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

lizan commented Mar 8, 2019

Uh oh!

mattklein123 left a comment

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

2 participants

lizan commented Feb 21, 2019 •

edited

Loading