Skip to content

Add new field to access log#3907

Merged
zuercher merged 4 commits intoenvoyproxy:masterfrom
rgs1:time-to-last-byte
Jul 24, 2018
Merged

Add new field to access log#3907
zuercher merged 4 commits intoenvoyproxy:masterfrom
rgs1:time-to-last-byte

Conversation

@rgs1
Copy link
Member

@rgs1 rgs1 commented Jul 19, 2018

This new field, RESPONSE_TX_DURATION, represents the duration
between the first upstream byte received and the last downstream
byte sent. Similarly to RESPONSE_DURATION, we can leave it undocumented
for now until it proofs to be generally useful.

For context, we rely on this metric heavily internally. We tried to implemented
from a regular filter but it's harder to get right.

Signed-off-by: Raul Gutierrez Segales rgs@pinterest.com

This new field, `TIME_TO_LAST_BYTE_DURATION`, represents the duration
between the first upstream byte received and the last downstream
byte sent. Similarly to RESPONSE_DURATION, we can leave it undocumented
for now until it proofs generally useful.

Signed-off-by: Raul Gutierrez Segales <rgs@pinterest.com>
@mattklein123
Copy link
Member

@zuercher mind taking a look?

Copy link
Member

@zuercher zuercher left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think the change itself is fine, but I think the field name should more clearly identify what the value represents.

field_extractor_ = [](const RequestInfo::RequestInfo& request_info) {
return AccessLogFormatUtils::durationToString(request_info.firstUpstreamRxByteReceived());
};
} else if (field_name == "TIME_TO_LAST_BYTE_DURATION") {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Shouldn't "time to last byte" report the time from the start of the downstream request until the last tx byte? (Which is just DURATION.) This is measuring how long the response takes to transit through Envoy, so more like RESPONSE_TRANSIT_DURATION or RESPONSE_TX_DURATION or something?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I like RESPONSE_TX_DURATION — I think it's the closes one to "the time between the first upstream byte and the last downstream byte sent".

cc: @derekargueta

Signed-off-by: Raul Gutierrez Segales <rgs@pinterest.com>
@rgs1
Copy link
Member Author

rgs1 commented Jul 20, 2018

Note for when merging: the commit message needs update to replace TIME_TO_LAST_BYTE_DURATION with RESPONSE_TX_DURATION.

zuercher
zuercher previously approved these changes Jul 23, 2018
Copy link
Member

@zuercher zuercher left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks. Looks good!

field_extractor_ = [](const RequestInfo::RequestInfo& request_info) {
return AccessLogFormatUtils::durationToString(request_info.firstUpstreamRxByteReceived());
};
} else if (field_name == "RESPONSE_TX_DURATION") {
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think this needs a doc update and a release note? https://www.envoyproxy.io/docs/envoy/latest/configuration/access_log?

Copy link
Member Author

@rgs1 rgs1 Jul 23, 2018

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@mattklein123 %RESPONSE_DURATION% isn't public either... so my thinking was lets have it be private for now and then promote it as publicly available interface/variable? I am happy either way though.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

What do you mean not public? I think if it's not documented that's a doc bug. Can you fix both? :)

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Haha, sure — diff coming up.

Signed-off-by: Raul Gutierrez Segales <rgs@pinterest.com>
zuercher
zuercher previously approved these changes Jul 23, 2018
@mattklein123
Copy link
Member

Can we add a release note for both options since they were never "released" previously?

Signed-off-by: Raul Gutierrez Segales <rgs@pinterest.com>
@rgs1
Copy link
Member Author

rgs1 commented Jul 23, 2018

@mattklein123 ah yes, sorry about that — done now. Is that only done in docs/root/intro/version_history.rst?

@zuercher zuercher merged commit eefd06d into envoyproxy:master Jul 24, 2018
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants