Added simple logging abstraction so mixer client logs can be relayed to envoy logs. #2116

duderino · 2019-02-14T02:17:11Z

When running outside of envoy, mixer client logs will go to stderr.

It also reduces log spam from failed reports and remote policy checks by logging one out of every 100 messages per @mandarjog and @douglas-reid request.

What this PR does / why we need it:

This is a breakout PR of #2107.

Which issue this PR fixes

This will help find future issues related to istio/istio#8224

…to envoy logs when running inside envoy, stderr when running standalone.

qiwzhang · 2019-02-14T02:30:35Z

src/istio/control/client_context_base.cc

-  // TODO: add debug message
-  // GOOGLE_LOG(INFO) << "Check attributes: " <<
-  // request->attributes->DebugString();
+  if (MIXER_DEBUG_ENABLED) {


Each MIXER_DEBUG has this "if MIXER_DEBUG_ENABLE" check. Can they be combined?

Put the isEnabled() check inside MIXER_DEBUG macro?

Wonderful idea if I can make it work. I'll do it if I can ensure that log arguments won't be serialized into nice pretty printed messages, etc when the log threshold wouldn't log them.

Done. src/istio/utils/logger_test.cc shows that arguments to the logging macros will not be needlessly invoked if the log message is under the logging threshold.

…rguments are now embedded in the log macros.

lambdai

LGTM. Thank you for split the logger logic!

Not sure if my approval matter

lambdai · 2019-02-14T18:00:21Z

src/istio/utils/logger.h

+
+#define STRINGLIT2(x) #x
+#define STRINGLIT(x) STRINGLIT2(x)
+#define FILE_LINE "[" __FILE__ ":" STRINGLIT(__LINE__) "] "


lambdai · 2019-02-14T18:00:27Z

src/istio/utils/logger.h

+                                FILE_LINE FORMAT, ##__VA_ARGS__)
+
+#define MIXER_TRACE(FORMAT, ...)            \
+  if (MIXER_TRACE_ENABLED) {                \


The below else will match the if (MIXER_TRACE_ENABLED).

if (condition) MIXER_TRACE else foo()

Consider we have the if w/o parentheses everywhere, I would suggest below

Suggested change

if (MIXER_TRACE_ENABLED) { \

do { \

if (MIXER_TRACE_ENABLED) { \

MIXER_TRACE_INT(FORMAT, ##__VA_ARGS__); \

} \

} while(0);

I saw a lot of macro codes like this. I still don't know why. But I think it is a right way to do.

In my suggestion the last semicolon is not nessesary. Acutally it would better not to append the semicolon.

@qiwzhang do{}while(0); and foo(bar) are statements while if ... w/o else is not. The point is just to make the MIXER_TRACE close to a function call.

lambdai · 2019-02-14T18:08:03Z

src/istio/utils/logger_test.cc

+  // TRACE and DEBUG shouldn't be logged and shouldn't have any affect on the
+  // arguments to be logged.
+
+  MIXER_TRACE("%s", entity.toString());


nit: I was wondering why this doesn't need c_str(). Maybe rename this method name to c_str() ?

Yep will do

douglas-reid · 2019-02-14T21:51:06Z

src/istio/mixerclient/report_batch.cc

-      GOOGLE_LOG(ERROR) << "Mixer Report failed with: " << status.ToString();
+      if (MIXER_WARN_ENABLED &&
+          0 == REPORT_FAIL_LOG_MESSAGES++ % REPORT_FAIL_LOG_MODULUS) {
+        MIXER_WARN("Mixer Report failed with: %s", status.ToString().c_str());


my only question here is whether or not we also want to track (via stats) the number of times this is happening to make monitoring easier.

if so, we can do that in a follow-up PR if it is going to slow down this PR.

Yep, that's coming in a separate PR. Already done and tested, just trying to create smaller PRs

duderino · 2019-02-15T00:31:56Z

@qiwzhang could you give me an LGTM here conditional on automated checks passing?

duderino · 2019-02-15T15:10:24Z

@JimmyCYJ this has been reviewed pretty thoroughly but needs an LGTM from an OWNER. Can you help?

JimmyCYJ · 2019-02-15T18:24:39Z

/lgtm

/approve

istio-testing · 2019-02-15T18:24:43Z

[APPROVALNOTIFIER] This PR is APPROVED

This pull-request has been approved by: duderino, JimmyCYJ

The full list of commands accepted by this bot can be found here.

The pull request process is described here

Needs approval from an approver in each of these files:

~~OWNERS~~ [JimmyCYJ]

Approvers can indicate their approval by writing /approve in a comment
Approvers can cancel approval by writing /approve cancel in a comment

@PiotrSikora

* Forwarded attributes override statically configured Local Attributes (#2097) * WIP * add local and override tests * revert attributes_builder * white list forward attributes * add tests with whitelist * fix builder test for white listed attributes * ignore istio.mixer in report (#2098) Signed-off-by: Lizan Zhou <[email protected]> * whitelist kSourceNamespace attribute (#2100) * Update software in the build image used by CircleCI. (#2110) Signed-off-by: Piotr Sikora <[email protected]> * Add flag indicating current semantics of report batch (#2111) * Add flag indicating current semantics of report batch * Fix Unit Test * Update Envoy SHA to latest with deterministic hash (master). (#2108) * Update Envoy SHA to latest with deterministic hash (master). Signed-off-by: Piotr Sikora <[email protected]> * review: use lld linker for clang-asan and clang-tsan. Signed-off-by: Piotr Sikora <[email protected]> * review: export PATH. Signed-off-by: Piotr Sikora <[email protected]> * Update Envoy SHA to latest with deterministic hash (release-1.1). (#2109) * Update Envoy SHA to latest with deterministic hash (release-1.1). Signed-off-by: Piotr Sikora <[email protected]> * review: use lld linker for clang-asan and clang-tsan. Signed-off-by: Piotr Sikora <[email protected]> * review: export PATH. Signed-off-by: Piotr Sikora <[email protected]> * remove unused bytestring include from sni_verifier for openssl (#2112) * Added client/server load test framework to find mixer faults. (#2105) This is a load generator client + origin server I created to test the Mixer filter under various fault conditions using Envoy's client and server stacks. This work falls under [istio/istio#8224](istio/istio#8224) @PiotrSikora @jplevyak would love your feedback because it could be used for the wasm work and especially because this is the first >=C++11 code I've written See test/integration/int_client_server_test.cc if you want to start with an example for context. Another example that uses this framework to sandwich Envoy+Mixer filter between the load generator and multiple origin servers simulating Mixer servers can be found in [istio/istio#8224](istio/istio#8224) * Warn user of using mTLS PERMISSIVE mode and suggest to upgrade to STRICT mode (#2114) * Warn user of using mTLS PERMISSIVE mode and suggest to upgrade to STRICT mode. Signed-off-by: Yangmin Zhu <[email protected]> * fix format * check in constructor * Update to latest istio/api on release-1.1 branch (#2115) * Update to latest istio/api on release-1.1 branch * Update istio/api to latest release-1.1 * Added simple logging abstraction so mixer client logs can be relayed to envoy logs. (#2116) * Added simple logging abstraction so mixer client logs can be relayed to envoy logs when running inside envoy, stderr when running standalone. * Log threshold guards that prevent needless serialization of logging arguments are now embedded in the log macros. * Format * Added do/while guards around logging statements. * Coalesce all memory for checks and reports into shared pointers (#2117) * Coalesce all memory for policy check requests and telemetry reports into shared pointers that live as long as a request's mixer filter instance. * A few small fixups for the code review. * Address some minor nits from code review. * Additional counters for mixer policy check (#2118) * Coalesce all memory for policy check requests and telemetry reports into shared pointers that live as long as a request's mixer filter instance. * A few small fixups for the code review. * Added finer-grained counters to mixer policy check * Add retries to policy checks on failed transport error (#2113) * Add configurable retry to policy/quota checks that failed due to transport error. * Added assertions on mixer filter stats to mixer fault test. * Reformat * Fix inaccurate comment. ` * Fix asan warning (thanks @silentdai!) and exclude mixer_fault_test from the asan and tsan sanitizers since it always times out. * Fix bad prefix check * Pull in latest istio/api from release-1.1 branch (#2120) * Add Joshua into proxy OWNER (#2121) * log authn permissive mode only when config is received (#2125) * log authn permissive mode only when config is received Signed-off-by: Yangmin Zhu <[email protected]> * fix format * fix build * clang-6/gcc: compiler barking fix (#2123) * compiler barking Signed-off-by: Kuat Yessenov <[email protected]> * piotrs fix Signed-off-by: Kuat Yessenov <[email protected]> * Add additional telemetry report counters (#2128) * Added counters to track telemetry report result. * reformat * replace tabs with spaces * Replace more tab with spaces. * New api sha for proxy (#2130) * API sha just changed, chanign it again for proxy (#2131) * Remove myself from owners add utka instead (#2129) * implement upstream secure bit (#2133) Signed-off-by: Kuat Yessenov <[email protected]> * Deflake macos MixerFaultTest by broadening assertion ranges. (#2126) * Deflake macos MixerFaultTest by broadening assertion ranges. Fix flake in macos tests that was introduced by #2113 * Cleanup a few readability issues and add an assertion. * More redability changes. * API sha for proxy (#2136) * Revert "implement upstream secure bit (#2133)" (#2135) This reverts commit d857bdd. * Add the support of bypassing JWT authn for CORS requests (#2139) * Add the support of bypassing JWT authn for CORS requests * Bail out earlier for CORS preflight requests * Use OPTIONS constant value from Envoy * Remove changing to lowercase * Add more checks for CORS preflight requests (#2140) * Rc3. new API sha for proxy. (#2146) * API sha for proxy * API sha for proxy * update envoy with latest build fixes (#2147) * update envoy with latest build fixes Signed-off-by: Lizan Zhou <[email protected]> * update protobuf to match envoy Signed-off-by: Lizan Zhou <[email protected]> * timeSystem -> timeSource Signed-off-by: Lizan Zhou <[email protected]> * requesting to add myself as a reviewer/approver (#2148) I have 39 commits in this repo. * update envoy to pick up TLS logging for HTTP upstream (#2149) Signed-off-by: Lizan Zhou <[email protected]> * Building 1.1rc4 (#2150) * fix build Signed-off-by: Lizan Zhou <[email protected]> * fix format Signed-off-by: Lizan Zhou <[email protected]> * fix status match Signed-off-by: Lizan Zhou <[email protected]> * Fixes environment-dependent failures in MixerFaultTest (#2156) * Removed explicit log-level setting from tests, as it was interfering with cli '-l' option (#2155) * Update_Dependencies (#2178) * Update envoy sha and fix bulid break (#2179) * update envoy sha * fix build * Remove bazel shutdown from make deb * Ignore error code returned from bazel shutdown

Added simple logging abstraction so mixer client logs can be relayed …

0813b19

…to envoy logs when running inside envoy, stderr when running standalone.

istio-testing requested review from linsun and qiwzhang February 14, 2019 02:17

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

qiwzhang reviewed Feb 14, 2019

View reviewed changes

duderino mentioned this pull request Feb 14, 2019

Fix a SIGSEGV when circuit breaker to upstream policy server is hit, fix a memory leak when client disconnects during upstream policy check, expose mixer client logging to Envoy, and add more mixer client counters. #2107

Closed

Joshua Blatt added 2 commits February 14, 2019 06:30

Log threshold guards that prevent needless serialization of logging a…

0ad321e

…rguments are now embedded in the log macros.

Format

a0a9ea0

lambdai reviewed Feb 14, 2019

View reviewed changes

douglas-reid reviewed Feb 14, 2019

View reviewed changes

Added do/while guards around logging statements.

0c261b2

duderino mentioned this pull request Feb 15, 2019

Additional counters for mixer policy check #2118

Merged

istio-testing assigned JimmyCYJ Feb 15, 2019

istio-testing added the lgtm label Feb 15, 2019

istio-testing added the approved label Feb 15, 2019

JimmyCYJ approved these changes Feb 15, 2019

View reviewed changes

duderino merged commit f93cee6 into istio:release-1.1 Feb 15, 2019

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Added simple logging abstraction so mixer client logs can be relayed to envoy logs. #2116

Added simple logging abstraction so mixer client logs can be relayed to envoy logs. #2116

duderino commented Feb 14, 2019

qiwzhang Feb 14, 2019 •

edited

Loading

duderino Feb 14, 2019

duderino Feb 14, 2019

lambdai left a comment

lambdai Feb 14, 2019

lambdai Feb 14, 2019

qiwzhang Feb 14, 2019

duderino Feb 14, 2019

lambdai Feb 14, 2019

duderino Feb 15, 2019

lambdai Feb 14, 2019

duderino Feb 14, 2019

duderino Feb 15, 2019

douglas-reid Feb 14, 2019

duderino Feb 15, 2019

duderino commented Feb 15, 2019

duderino commented Feb 15, 2019

JimmyCYJ commented Feb 15, 2019

istio-testing commented Feb 15, 2019

Added simple logging abstraction so mixer client logs can be relayed to envoy logs. #2116

Added simple logging abstraction so mixer client logs can be relayed to envoy logs. #2116

Conversation

duderino commented Feb 14, 2019

qiwzhang Feb 14, 2019 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

lambdai 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

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

duderino commented Feb 15, 2019

duderino commented Feb 15, 2019

JimmyCYJ commented Feb 15, 2019

istio-testing commented Feb 15, 2019

qiwzhang Feb 14, 2019 •

edited

Loading