add response code details to stream info by eziskind · Pull Request #6530 · envoyproxy/envoy

eziskind · 2019-04-09T21:02:30Z

Description: add a response code field to the StreamInfo object with a helper class to hold well-known constants. For now this just has 1 value which lets access logs tell if the response is coming from the upstream vs from the envoy itself (in the case of a sendLocalReply), but many more values will added in future PRs. Making this a string rather than an enum so that 3rd parties can extend it.
Risk Level: low
Testing: unit tests

Signed-off-by: Elisha Ziskind eziskind@google.com

Signed-off-by: Elisha Ziskind <eziskind@google.com>

eziskind · 2019-04-09T23:33:51Z

@alyssawilk, could you take a look?

alyssawilk

Awesome, thanks for tackling this!

alyssawilk · 2019-04-10T14:17:34Z

include/envoy/stream_info/stream_info.h

+  /**
+   * @param rc_details the response code details string to set for this request.
+   */
+  virtual void setResponseCodeDetails(const std::string& rc_details) PURE;


How about absl::string_view?

Some of the details I'd like to see in future include things like passing the http_errno_name from the H1 codec, and those come as char*s, so it'd be nice to avoid stringifying and then copying.

Ok, changed the signature but I left the StreamInfo field as absl::optionalstd::string so there's still going to be a copy. Do you think I should change the field to absl::string_view as well? For that to be safe we'd need to be sure that the actual storage of the string will outlive the StreamInfo object.

alyssawilk · 2019-04-10T14:18:48Z

include/envoy/stream_info/stream_info.h

  virtual void setResponseFlag(ResponseFlag response_flag) PURE;

+  /**
+   * @param rc_details the response code details string to set for this request.


Maybe some details here about what response code details are?

alyssawilk · 2019-04-10T14:25:57Z

source/common/router/router.cc

  }

+  callbacks_->streamInfo().setResponseCodeDetails(
+      StreamInfo::ResponseCodeDetails::get().RC_SET_BY_UPSTREAM);


I think this PR would be a bit more correct if you also did the work to set the string to nothing in sendLocalReply.

I don't think we have any response filters that pause on encodeHeaders, but if we did it could be the case that while that encoder filter were doing its RPC, it took too long and for example triggered an idle timeout where the HCM would sendLocalReply. Because that could transform, say, a 200 from upstream to a 408 where the details would eventually be "stream timeout" but for today would be "" rather than "response_code_set_by_upstream"

Signed-off-by: Elisha Ziskind <eziskind@google.com>

eziskind · 2019-04-10T17:57:17Z

/retest

repokitteh-read-only · 2019-04-10T17:57:20Z

🔨 rebuilding ci/circleci: api (failed build)

🐱

Caused by: a #6530 (comment) was created by @eziskind.

see: more, trace.

alyssawilk

LGTM modulo one final nit. @junr03 up for doing the cross company pass since I think you have more context?

alyssawilk · 2019-04-10T18:00:46Z

include/envoy/stream_info/stream_info.h

+/**
+ * Constants for the response code details field of StreamInfo.
+ *
+ * These provide details about the stream state such as whether the


One other minor nit - do you think it's worth clarifying what's done now vs what this will do?
These will provide such details, but right now they only do rc_set_by_upstream

I'd be fine with a tracking issue assigned my way for actually setting values in sendLocalReply and referencing the issue here?

Filed #6542 to track this. I'll add a reference to this in the code.

Signed-off-by: Elisha Ziskind <eziskind@google.com>

eziskind · 2019-04-10T19:11:17Z

/retest

repokitteh-read-only · 2019-04-10T19:11:22Z

🔨 rebuilding ci/circleci: build_image (failed build)
🔨 rebuilding ci/circleci: ipv6_tests (failed build)

🐱

Caused by: a #6530 (comment) was created by @eziskind.

see: more, trace.

eziskind · 2019-04-10T20:23:00Z

/retest

repokitteh-read-only · 2019-04-10T20:23:17Z

🔨 rebuilding ci/circleci: build_image (failed build)
🔨 rebuilding ci/circleci: ipv6_tests (failed build)
🔨 rebuilding ci/circleci: docker (failed build)

🐱

Caused by: a #6530 (comment) was created by @eziskind.

see: more, trace.

junr03

@eziskind are you also going to have subsequent PRs to surface this information out, e.g to make this accessible in access logs?

junr03 · 2019-04-10T21:05:32Z

source/common/stream_info/stream_info_impl.h

+    return response_code_details_;
+  }
+
+  void setResponseCodeDetails(absl::string_view rc_details) override {


Is it up to the caller on how to enrich this information? Or do you imagine codifying this somehow, i.e a comma delimited list of details?

My thinking was that this will be just one of the string constants defined in ResponseCodeDetailValues. That currently only has 1 value but that will change soon (#6542). Also, since this is a string, 3rd party extensions can add additional values if it doesn't make sense to add it to OSS envoy. I don't see a need for making this an array (or comma-separated list). @alyssawilk wdyt?

Just to add another point - I think the idea is that there should be enough distinct strings available to uniquely specify why envoy is returning an error code (more or less one for each time sendLocalReply is called). So a list of strings should not be necessary.

I'm fine with it as-is.

For single-hop responses we only need one rc-details. It might be useful to have a full trace of what happened somewhere (500-retried, timeout-retries, gave up and sent 500) but I think that's better off via some other trace mechanism where we can put arbitrary information about how much time was spent in each filter etc. etc.

For multi-hop responses while we might want both layers captured in access logs (e.g. layer-2 envoy had timeout, layer-1 envoy proxied response code sent by upstream) I think that the information from prior hops would be transmitted via headers, and could be sent to access logs via logging the proxy-status header. SG?

Sounds good, thanks!

junr03 · 2019-04-10T21:09:01Z

include/envoy/stream_info/stream_info.h

+ * scoped to avoid collisions.
+ */
+struct ResponseCodeDetailValues {
+  const std::string RC_SET_BY_UPSTREAM = "response_code_set_by_upstream";


nit: I wonder if we have to prefix RC here given the structs name?

Removed the RC_ prefix

eziskind · 2019-04-10T23:32:16Z

@eziskind are you also going to have subsequent PRs to surface this information out, e.g to make this accessible in access logs?

Access logs already get a reference to the StreamInfo object so they will be able to get the response code details from that.

junr03 · 2019-04-11T00:22:31Z

@eziskind are you also going to have subsequent PRs to surface this information out, e.g to make this accessible in access logs?

Access logs already get a reference to the StreamInfo object so they will be able to get the response code details from that.

Right, I know that the access log already has a reference. I am just wondering if you are also going to add functionality to be able to write this new information the stream info has. So for instance in the access log case are you planning on adding it to the formatter:

envoy/source/common/access_log/access_log_formatter.cc

Line 257 in de03926

StreamInfoFormatter::StreamInfoFormatter(const std::string& field_name) {

Just wondering how you are planning to surface the additional info we are adding, the access log just being a concrete place where it could happen.

eziskind · 2019-04-11T00:45:43Z

Just wondering how you are planning to surface the additional info we are adding, the access log just being a concrete place where it could happen.

Thanks for the pointer - I'll add support for logging this field to access_log_formatter.cc

junr03 · 2019-04-11T02:28:53Z

Yep! No need to add in this PR if that wasn't the plan. I think this PR stands on itself functionally. I was just wondering how you were thinking about surfacing this information to the system's observability layer.

Signed-off-by: Elisha Ziskind <eziskind@google.com>

eziskind · 2019-04-11T13:25:51Z

Yep! No need to add in this PR if that wasn't the plan. I think this PR stands on itself functionally. I was just wondering how you were thinking about surfacing this information to the system's observability layer.

Sounds good - I'll add this change in a followup PR.

eziskind · 2019-04-11T23:59:35Z

@junr03 can you take another look? Thanks!

junr03

lgtm, thanks!

mattklein123

Thanks, looks good with small nit. Looking forward to seeing this info exposed in access logs and eventually optionally in the actual response body if configured to do so.

/wait

mattklein123 · 2019-04-15T16:13:54Z

include/envoy/stream_info/stream_info.h

+ * scoped to avoid collisions.
+ */
+struct ResponseCodeDetailValues {
+  const std::string SET_BY_UPSTREAM = "set_by_upstream";


nit: "set_by_upstream" is a bit vague to me in terms of what it means given we have lots of info in stream info. Perhaps "via_upstream" ? Any other ideas? Also nit, SetByUpstream (trying to avoid capitals for new constants).

"proxied_from_upstream" or "forwarded_from_upstream"? "via_upstream" is fine too and shorter so I'll go with that :)

Signed-off-by: Elisha Ziskind <eziskind@google.com>

mattklein123

Thank you!

) Description: add formatting for the "response code details" string recently added to the StreamInfo (#6530) Risk Level: low Testing: unit tests Docs Changes: updated Release Notes: updated Signed-off-by: Elisha Ziskind <eziskind@google.com>

add response code details to stream info

dd85834

Signed-off-by: Elisha Ziskind <eziskind@google.com>

mattklein123 assigned junr03 Apr 10, 2019

alyssawilk reviewed Apr 10, 2019

View reviewed changes

review feedback

e501be4

Signed-off-by: Elisha Ziskind <eziskind@google.com>

alyssawilk reviewed Apr 10, 2019

View reviewed changes

add references to envoyproxy#6542

61928bd

Signed-off-by: Elisha Ziskind <eziskind@google.com>

alyssawilk previously approved these changes Apr 10, 2019

View reviewed changes

junr03 reviewed Apr 10, 2019

View reviewed changes

remove RC_ prefix from constant

adfe3d8

Signed-off-by: Elisha Ziskind <eziskind@google.com>

eziskind dismissed alyssawilk’s stale review via adfe3d8 April 11, 2019 13:24

junr03 previously approved these changes Apr 12, 2019

View reviewed changes

mattklein123 requested changes Apr 15, 2019

View reviewed changes

repokitteh-read-only bot added the waiting label Apr 15, 2019

mattklein123 self-assigned this Apr 15, 2019

rename SET_BY_UPSTREAM to ViaUpstream

978c859

Signed-off-by: Elisha Ziskind <eziskind@google.com>

eziskind dismissed junr03’s stale review via 978c859 April 15, 2019 16:33

repokitteh-read-only bot removed the waiting label Apr 15, 2019

mattklein123 approved these changes Apr 15, 2019

View reviewed changes

mattklein123 merged commit d0f992c into envoyproxy:master Apr 15, 2019

eziskind deleted the rcdetails branch April 15, 2019 21:01

eziskind mentioned this pull request Apr 17, 2019

access log: add response code details to the access log formatter #6626

Merged

dio mentioned this pull request Nov 9, 2019

ext_authz: Make sure injectContext is called #8961

Merged

Conversation

eziskind commented Apr 9, 2019

Uh oh!

eziskind commented Apr 9, 2019

Uh oh!

alyssawilk 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!

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!

eziskind commented Apr 10, 2019

Uh oh!

repokitteh-read-only bot commented Apr 10, 2019

Uh oh!

alyssawilk 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!

eziskind commented Apr 10, 2019

Uh oh!

repokitteh-read-only bot commented Apr 10, 2019

Uh oh!

eziskind commented Apr 10, 2019

Uh oh!

repokitteh-read-only bot commented Apr 10, 2019

Uh oh!

junr03 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!

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!

eziskind commented Apr 10, 2019

Uh oh!

junr03 commented Apr 11, 2019

Uh oh!

eziskind commented Apr 11, 2019

Uh oh!

junr03 commented Apr 11, 2019

Uh oh!

eziskind commented Apr 11, 2019

Uh oh!

eziskind commented Apr 11, 2019

Uh oh!

junr03 left a comment

Choose a reason for hiding this comment

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!

mattklein123 left a comment

Choose a reason for hiding this comment