gRPC service logging bugfix #363

oschaaf · 2020-06-16T14:51:44Z

This makes the gRPC service log more then one ExecutionStream requests.
The log level used will be controlled by the options associated to
ExecutionStream requests (possible candidate for improvement later on).

This change also incorporates a change to avoid creating multiple instances
of Envoy::ProcessWide in the Nighthawk gRPC service flow.
This doesn't seem to address any know issues, but it seems to be more along
the way Envoy::ProcessWide was intended to be used.

Fixes #289

Signed-off-by: Otto van der Schaaf oschaaf@we-amp.com

This makes the gRPC service log more then one ExecutionStream requests. The log level used will be controlled by the options associated to ExecutionStream requests. This change also incorporates a change to avoid creating multiple instances of Envoy::ProcessWide in the Nighthawk gRPC service flow. This doesn't seem to address any know issues, but it seems to be more along the way Envoy::ProcessWide was intended to be used. Fixes envoyproxy#289 Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

oschaaf · 2020-06-16T14:54:18Z

source/client/service_impl.cc

@@ -33,11 +33,7 @@ void ServiceImpl::handleExecutionRequest(const nighthawk::client::ExecutionReque
    return;
  }

-  ProcessImpl process(*options, time_system_);


Note to reviewers: the fix is to not do this here. We do this once now at construction time, and hold on to the logging context throughout the lifetime of the ServiceImpl.
Note that ProcessImpl instantiations will change the log level per inbound configured options. We only allow one ProcessImpl instantiation at a time today, so this might be allright for now.

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

mum4k · 2020-06-17T20:36:45Z

source/client/process_impl.cc

-    : time_system_(time_system), stats_allocator_(symbol_table_), store_root_(stats_allocator_),
+ProcessImpl::ProcessImpl(const Options& options, Envoy::Event::TimeSystem& time_system,
+                         const std::shared_ptr<Envoy::ProcessWide>& process_wide)
+    : process_wide_(process_wide == nullptr ? std::make_shared<Envoy::ProcessWide>()


Unsure about the context - do we need to worry about thread safety here or is ProcessImpl guaranteed to be constructed from a single thread?

All ProcessImpl clients should ensure there's only a single active instance at any given time. We don't have to worry about it.

mum4k · 2020-06-17T20:37:49Z

source/client/process_impl.cc

@@ -92,8 +92,11 @@ class ClusterManagerFactory : public Envoy::Upstream::ProdClusterManagerFactory
  bool prefetch_connections_{};
 };

-ProcessImpl::ProcessImpl(const Options& options, Envoy::Event::TimeSystem& time_system)
-    : time_system_(time_system), stats_allocator_(symbol_table_), store_root_(stats_allocator_),
+ProcessImpl::ProcessImpl(const Options& options, Envoy::Event::TimeSystem& time_system,


Is there any way how we can add test coverage for this change to keep the fixed functionality working?

Actually, yes. Lacking C++ mocks for the logging, we can't easily unit-test this issue.
But I could add an end-to-end integration test for this, see 619c05e

mum4k · 2020-06-17T20:38:29Z

source/client/process_impl.h

@@ -46,7 +46,8 @@ class ClusterManagerFactory;
 */
 class ProcessImpl : public Process, public Envoy::Logger::Loggable<Envoy::Logger::Id::main> {
 public:
-  ProcessImpl(const Options& options, Envoy::Event::TimeSystem& time_system);
+  ProcessImpl(const Options& options, Envoy::Event::TimeSystem& time_system,


Can we add a doc comment? We could also explain the optional process_wide argument and say what happens if it isn't provided.

mum4k · 2020-06-17T20:38:54Z

source/client/service_impl.h

@@ -26,6 +28,10 @@ class ServiceImpl final : public nighthawk::client::NighthawkService::Service,
                          public Envoy::Logger::Loggable<Envoy::Logger::Id::main> {

 public:
+  ServiceImpl() : process_wide_(std::make_shared<Envoy::ProcessWide>()) {


Can we add a doc comment for the public constructor?

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

oschaaf · 2020-06-18T09:42:13Z

@mum4k thanks for the review; comments addressed!

mum4k

Thank you. One remaining nit.

mum4k · 2020-06-18T20:50:52Z

test/integration/nighthawk_grpc_service.py

@@ -39,6 +39,7 @@ def __init__(self,
    assert ip_version != IpVersion.UNKNOWN
    self.server_port = 0
    self.server_ip = server_ip
+    self.log_lines = None


(nit) Does this need to be public or would self._log_lines do? If public, can we document it above in the Attributes: section of the class docstring?

Well, it gets consumed over at https://github.com/envoyproxy/nighthawk/pull/363/files#diff-9620177d1b84e578a841abdc925dcdf4R33. So it needs to be public, and documented. I'll add that.

Done in 593fe3c (also moved the line that resets the log to None to a better place).

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

oschaaf added P1 waiting-for-review A PR waiting for a review. labels Jun 16, 2020

oschaaf commented Jun 16, 2020

View reviewed changes

Fix clang-tidy issue

afebe8c

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

mum4k requested changes Jun 17, 2020

View reviewed changes

mum4k added waiting-for-changes A PR waiting for comments to be resolved and changes to be applied. and removed waiting-for-review A PR waiting for a review. labels Jun 17, 2020

oschaaf added 2 commits June 18, 2020 11:20

Review feedback: regression test for gRPC service log behavior

619c05e

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

Review: add doc comments

da26a80

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

oschaaf added waiting-for-review A PR waiting for a review. and removed waiting-for-changes A PR waiting for comments to be resolved and changes to be applied. labels Jun 18, 2020

mum4k requested changes Jun 18, 2020

View reviewed changes

mum4k added waiting-for-changes A PR waiting for comments to be resolved and changes to be applied. and removed waiting-for-review A PR waiting for a review. labels Jun 18, 2020

oschaaf added 2 commits June 18, 2020 23:39

Merge remote-tracking branch 'upstream/master' into fix-service-logging

a63396b

Review feedback

593fe3c

Signed-off-by: Otto van der Schaaf <oschaaf@we-amp.com>

oschaaf added waiting-for-review A PR waiting for a review. and removed waiting-for-changes A PR waiting for comments to be resolved and changes to be applied. labels Jun 18, 2020

mum4k approved these changes Jun 19, 2020

View reviewed changes

mum4k merged commit 39aaab2 into envoyproxy:master Jun 19, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

gRPC service logging bugfix #363

gRPC service logging bugfix #363

oschaaf commented Jun 16, 2020

oschaaf Jun 16, 2020

mum4k Jun 17, 2020

oschaaf Jun 18, 2020

mum4k Jun 17, 2020

oschaaf Jun 18, 2020

mum4k Jun 17, 2020

mum4k Jun 17, 2020

oschaaf commented Jun 18, 2020

mum4k left a comment

mum4k Jun 18, 2020

oschaaf Jun 18, 2020

oschaaf Jun 18, 2020

gRPC service logging bugfix #363

gRPC service logging bugfix #363

Conversation

oschaaf commented Jun 16, 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

oschaaf commented Jun 18, 2020

mum4k left a 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