Add TCP Access Logging #2852

gargnupur · 2020-05-14T14:32:10Z

What this PR does / why we need it:
This is built on top of #2843

Signed-off-by: gargnupur <gargnupur@google.com> fix Signed-off-by: gargnupur <gargnupur@google.com> changes Signed-off-by: gargnupur <gargnupur@google.com> refactor Signed-off-by: gargnupur <gargnupur@google.com> fix test Add TCP Metrics in Stackdriver Signed-off-by: gargnupur <gargnupur@google.com> fix Signed-off-by: gargnupur <gargnupur@google.com> Add TCP access logging changes Signed-off-by: gargnupur <gargnupur@google.com> Remove local path from Makefile changes Signed-off-by: gargnupur <gargnupur@google.com> Add functions for queue fix build fix test remove debug time Signed-off-by: gargnupur <gargnupur@google.com> remove debug time Signed-off-by: gargnupur <gargnupur@google.com> Add protocol in http accesslog

Signed-off-by: gargnupur <gargnupur@google.com>

gargnupur · 2020-06-05T00:26:23Z

@bianpengyuan , @mandarjog , @douglas-reid : This is ready for review..

bianpengyuan · 2020-06-05T05:12:04Z

extensions/stackdriver/config/v1alpha1/stackdriver_plugin_config.proto

 message PluginConfig {
  // Optional. Controls whether to export server access log.
  bool disable_server_access_logging = 1;

+  // Optional. Controls whether to export TCP server access log.
+  bool disable_tcp_server_access_logging = 9;


Shall we just use disable_server_access_logging to control both tcp and http logging?

Good idea.. removing

bianpengyuan · 2020-06-05T05:19:10Z

extensions/stackdriver/log/logger.cc

+    const ::Wasm::Common::RequestInfo& request_info,
+    google::logging::v2::LogEntry* log_entry) {
+  auto label_map = log_entry->mutable_labels();
+  (*label_map)["tcp_remote_ip"] = request_info.source_address;


Do we need tcp prefix? What did we use in mixer v1?

Changed them to match mixer v1

bianpengyuan · 2020-06-05T05:23:29Z

extensions/stackdriver/stackdriver.cc

@@ -403,6 +404,12 @@ bool StackdriverRootContext::recordTCP(uint32_t id) {
  // Record TCP Metrics.
  ::Extensions::Stackdriver::Metric::recordTCP(outbound, local_node, peer_node,
                                               request_info);
+  // Add LogEntry to Logger. Log Entries are batched and sent on timer
+  // to Stackdriver Logging Service.
+  if (enableTCPServerAccessLog() && shouldLogThisRequest()) {


Does shouldLogThisRequest apply here? It only bases on http or grpc status right?

Removed for now.. but I was thinking more in terms of sampling successful connections too but will change accesslog sampling filter to select failed request based on presence of response flag.. will do in a separate PR

bianpengyuan · 2020-06-05T05:24:34Z

extensions/stackdriver/stackdriver.cc

+  // to Stackdriver Logging Service.
+  if (enableTCPServerAccessLog() && shouldLogThisRequest()) {
+    ::Wasm::Common::populateExtendedRequestInfo(&request_info);
+    logger_->addLogEntry(request_info, peer_node, true);


Suggested change

logger_->addLogEntry(request_info, peer_node, true);

logger_->addLogEntry(request_info, peer_node, /* is_tcp = */ true);

bianpengyuan · 2020-06-05T05:24:48Z

extensions/stackdriver/stackdriver.cc

@@ -351,7 +352,7 @@ void StackdriverRootContext::record() {
      !config_.disable_http_size_metrics());
  if (enableServerAccessLog() && shouldLogThisRequest()) {
    ::Wasm::Common::populateExtendedHTTPRequestInfo(&request_info);
-    logger_->addLogEntry(request_info, peer_node);
+    logger_->addLogEntry(request_info, peer_node, false);


Suggested change

logger_->addLogEntry(request_info, peer_node, false);

logger_->addLogEntry(request_info, peer_node, /* is_tcp = */ false);

bianpengyuan · 2020-06-05T05:26:03Z

extensions/stackdriver/stackdriver.h

@@ -80,7 +80,11 @@ class StackdriverRootContext : public RootContext {
  void deleteFromTCPRequestQueue(uint32_t id);
  void incrementReceivedBytes(uint32_t id, size_t size);
  void incrementSentBytes(uint32_t id, size_t size);
+  void incrementTotalReceivedBytes(uint32_t id, size_t size);


Why not reuse the existing functions?

Because the metrics are different... this is incrementing tcp_total_received_bytes...

You can increment total_x_bytes inside the existing function.

This is not fixed yet.

yup. thanks.. fixed

I don't see a new commit, did you push?

weird.. change was there in the branch bot not in PR.. I pushed again with a comment.. PTAL

bianpengyuan · 2020-06-05T05:43:12Z

extensions/stackdriver/stackdriver.h

@@ -155,6 +162,8 @@ class StackdriverContext : public Context {

    is_tcp_ = true;
    getRootContext()->addToTCPRequestQueue(context_id_);
+    getRootContext()->setConnectionState(


I think you will need to trigger log record in connection open, otherwise it will not be recorded. Also I think it is necessary to record log entry in open and close event, so that they could have correct time stamp.

And test make sure that all three types of connection states are covered.

Yes.. I was going to ping you offline about this :) I had exact same question in my other PR.. #2843 (comment) but reading it now, I think you were referring to Metrics and I was referring to calling Record method in general that does everything.

One of the things for TCP would be that metadata exchange doesn't happen until data comes so, connection open log won't have peer data. But it would be good to still get connection open logged.

Will add this change in a separate PR because of metadata exchange stuff..

Ok, I think time stamp is the only thing special with connection open. All other labels should have no difference from other state. You can keep an connection open time stamp somewhere and use that as a signal to record connection open event.

Are you planning to fix this in separated PR?

Yes, will do in a separate PR.. started a conversation about this with you, Mandar and Doug..

Signed-off-by: gargnupur <gargnupur@google.com>

bianpengyuan · 2020-06-07T21:54:12Z

extensions/stackdriver/stackdriver.cc

@@ -203,7 +204,7 @@ bool StackdriverRootContext::configure(size_t configuration_size) {
    }
  }

-  if (!logger_ && enableServerAccessLog()) {
+  if (!logger_ && (enableServerAccessLog())) {


Suggested change

if (!logger_ && (enableServerAccessLog())) {

if (!logger_ && enableServerAccessLog()) {

Thanks..Fixed

bianpengyuan · 2020-06-07T21:54:28Z

extensions/stackdriver/stackdriver.cc

@@ -313,7 +314,7 @@ bool StackdriverRootContext::onDone() {
  // called, but onConfigure is not triggered. onConfigure is only triggered in
  // thread local VM, which makes it possible that logger_ is empty ptr even
  // when logging is enabled.
-  if (logger_ && enableServerAccessLog() &&
+  if (logger_ && (enableServerAccessLog()) &&


Suggested change

if (logger_ && (enableServerAccessLog()) &&

if (logger_ && enableServerAccessLog() &&

Thanks..Fixed

bianpengyuan · 2020-06-07T22:25:19Z

extensions/stackdriver/stackdriver.h

@@ -155,6 +162,8 @@ class StackdriverContext : public Context {

    is_tcp_ = true;
    getRootContext()->addToTCPRequestQueue(context_id_);
+    getRootContext()->setConnectionState(


Are you planning to fix this in separated PR?

bianpengyuan · 2020-06-07T22:33:54Z

extensions/stackdriver/stackdriver.h

@@ -80,7 +80,11 @@ class StackdriverRootContext : public RootContext {
  void deleteFromTCPRequestQueue(uint32_t id);
  void incrementReceivedBytes(uint32_t id, size_t size);
  void incrementSentBytes(uint32_t id, size_t size);
+  void incrementTotalReceivedBytes(uint32_t id, size_t size);


This is not fixed yet.

Signed-off-by: gargnupur <gargnupur@google.com>

istio-testing added the do-not-merge/work-in-progress Block merging of a PR because it isn't ready yet. label May 14, 2020

googlebot added the cla: yes Set by the Google CLA bot to indicate the author of a PR has signed the Google CLA. label May 14, 2020

istio-testing added size/XL Denotes a PR that changes 500-999 lines, ignoring generated files. needs-rebase Indicates a PR needs to be rebased before being merged labels May 14, 2020

gargnupur force-pushed the nup_tcp_accesslog2 branch from 7dd3795 to 451e6a1 Compare May 25, 2020 14:42

istio-testing removed the needs-rebase Indicates a PR needs to be rebased before being merged label May 25, 2020

gargnupur force-pushed the nup_tcp_accesslog2 branch from 3f6511a to 374f0c0 Compare May 25, 2020 23:02

gargnupur changed the title ~~[WIP]: Add TCP Access Logging~~ Add TCP Access Logging May 25, 2020

gargnupur removed the do-not-merge/work-in-progress Block merging of a PR because it isn't ready yet. label May 25, 2020

gargnupur marked this pull request as ready for review May 25, 2020 23:03

gargnupur requested a review from a team May 25, 2020 23:03

gargnupur requested a review from a team as a code owner May 25, 2020 23:03

gargnupur requested review from mandarjog, kyessenov, bianpengyuan and douglas-reid May 25, 2020 23:04

gargnupur added 2 commits June 4, 2020 14:34

fix lint

da73c0b

Signed-off-by: gargnupur <gargnupur@google.com>

gargnupur force-pushed the nup_tcp_accesslog2 branch from e6ab245 to da73c0b Compare June 4, 2020 23:50

istio-testing added size/L Denotes a PR that changes 100-499 lines, ignoring generated files. and removed size/XL Denotes a PR that changes 500-999 lines, ignoring generated files. labels Jun 4, 2020

fix merge from master

56eb5d8

Signed-off-by: gargnupur <gargnupur@google.com>

bianpengyuan reviewed Jun 5, 2020

View reviewed changes

gargnupur added 2 commits June 5, 2020 08:16

fixed based on feedback

2b6bb60

Signed-off-by: gargnupur <gargnupur@google.com>

fix test

118064b

bianpengyuan reviewed Jun 7, 2020

View reviewed changes

gargnupur added 2 commits June 8, 2020 07:10

fixed based on feedback

789c722

Signed-off-by: gargnupur <gargnupur@google.com>

add comment

9666209

bianpengyuan approved these changes Jun 8, 2020

View reviewed changes

istio-testing merged commit ea0ce55 into istio:master Jun 8, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add TCP Access Logging #2852

Add TCP Access Logging #2852

gargnupur commented May 14, 2020 •

edited

gargnupur commented Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

bianpengyuan Jun 7, 2020

gargnupur Jun 8, 2020

bianpengyuan Jun 8, 2020

gargnupur Jun 8, 2020

bianpengyuan Jun 5, 2020

bianpengyuan Jun 5, 2020

gargnupur Jun 5, 2020

gargnupur Jun 5, 2020

bianpengyuan Jun 5, 2020

bianpengyuan Jun 7, 2020

gargnupur Jun 8, 2020

bianpengyuan Jun 7, 2020

gargnupur Jun 8, 2020

bianpengyuan Jun 7, 2020

gargnupur Jun 8, 2020

bianpengyuan Jun 7, 2020

bianpengyuan Jun 7, 2020

	logger_->addLogEntry(request_info, peer_node, true);
	logger_->addLogEntry(request_info, peer_node, /* is_tcp = */ true);

	if (!logger_ && (enableServerAccessLog())) {
	if (!logger_ && enableServerAccessLog()) {

	if (logger_ && (enableServerAccessLog()) &&
	if (logger_ && enableServerAccessLog() &&

Add TCP Access Logging #2852

Add TCP Access Logging #2852

Conversation

gargnupur commented May 14, 2020 • edited

gargnupur commented Jun 5, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

gargnupur commented May 14, 2020 •

edited