add config to autoformat stackdriver trace #260

StevenYCChou · 2018-09-25T23:23:49Z

No description provided.

igorpeshansky · 2018-09-25T23:45:23Z

lib/fluent/plugin/out_google_cloud.rb

@@ -393,6 +399,10 @@ module InternalConstants
    config_param :monitoring_type, :string,
                 :default => Monitoring::PrometheusMonitoringRegistry.name

+    # Whether to autoformat value of "logging.googleapis.com/trace" to
+    # LogEntry.Trace.
+    config_param :enable_stackdriver_trace_autoformat, :bool, :default => true


Let's use the imperative form: autoformat_stackdriver_trace.

makes sense. updated.

igorpeshansky · 2018-09-25T23:47:43Z

lib/fluent/plugin/out_google_cloud.rb

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          if trace
+            if @enable_stackdriver_trace_autoformat &&


Let's extract this into a compute_trace method and leave this line as:

entry.trace = compute_trace(trace) if trace

igorpeshansky · 2018-09-25T23:49:35Z

test/plugin/base_test.rb

+        config: APPLICATION_DEFAULT_CONFIG
+      },
+      {
+        config: 'enable_stackdriver_trace_autoformat true'


Please extract this and the next config string into constants, and define them in terms of APPLICATION_DEFAULT_CONFIG.

+1. Similar to https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/test/plugin/constants.rb#L235.

added configs into constant.

igorpeshansky · 2018-09-25T23:53:25Z

test/plugin/base_test.rb

+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}" \


This is a change detector test (it replicates the code under test). Please use the literal value. Better yet, define two constants, one for the compliant trace, and one for the non-compliant trace.

Yeah, instead of d.instance.project_id, we could just use PROJECT, which is defined in the constants.rb file.

I was proposing the FULL_STACKDRIVER_TRACE and NON_STACKDRIVER_TRACE, same as you... If we define one in terms of the other, we can even use FULL_STACKDRIVER_TRACE as the expected value here...

The full trace here depends on the project_id of driver. If we change the whole trace into constant, It's unclear how that project_id in full trace comes from. I think it's hiding details into constant.

I think this project_id is local to this scope under the driver here. WDYT?

The point is that the tests should be checking complete expected values. If you expect the resulting trace to have a particular project id, the constant should have that. I was suggesting defining the FULL_STACKDRIVER_TRACE as:

NON_STACKDRIVER_TRACE = "1234567890abcdef1234567890abcdef".freeze FULL_STACKDRIVER_TRACE = "projects/#{PROJECT_ID}/traces/#{NON_STACKDRIVER_TRACE}".freeze

in constants.rb.

qingling128 · 2018-09-26T01:11:35Z

test/plugin/base_test.rb

+        config: APPLICATION_DEFAULT_CONFIG
+      },
+      {
+        config: 'enable_stackdriver_trace_autoformat true'


+1. Similar to https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/test/plugin/constants.rb#L235.

qingling128 · 2018-09-26T01:19:48Z

test/plugin/base_test.rb

@@ -338,6 +338,81 @@ def test_structured_payload_log
    end
  end

+  def test_stackdriver_trace_format_compliant_trace
+    full_stackdriver_trace = \


Constant FULL_STACKDRIVER_TRACE?

ditto - I think the full trace is project-dependent, not constant value.

The project we feed into the tests is a constant, though... So we could construct the full expected value as a constant.

qingling128 · 2018-09-26T01:20:27Z

test/plugin/base_test.rb

+  end
+
+  def test_autoformat_enabled_with_stackdriver_trace_format_noncompliant_trace
+    non_stackdriver_trace_compliant_trace = '1234567890abcdef1234567890abcdef'


Constant NON_STACKDRIVER_TRACE?

Change this value into constant, but use the name as NON_STACKDRIVER_TRACE_COMPLIANT_TRACE as this value can be a "Stackdriver Trace", but it is just not compliant to enable cross reference between Stackdriver Logging & Trace.

qingling128 · 2018-09-26T01:23:02Z

test/plugin/base_test.rb

+          d.run
+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            assert_equal full_stackdriver_trace, entry['trace']


assert_equal can take a third parameter as the error message when the assertion fails. In order to help with debugging, we could something like:

assert_equal full_stackdriver_trace, entry['trace'], "test_params #{test_params} failed with entry #{entry}."

Same for below.

added more informative error messages.

qingling128 · 2018-09-26T01:24:36Z

test/plugin/base_test.rb

+  end
+
+  def test_autoformat_disabled_with_stackdriver_trace_format_noncompliant_trace
+    config = 'enable_stackdriver_trace_autoformat false'


Constant AUTOFORMAT_STACKDRIVER_TRACE_DISABLED_CONFIG?

qingling128 · 2018-09-26T01:25:01Z

test/plugin/base_test.rb

+
+  def test_autoformat_disabled_with_stackdriver_trace_format_noncompliant_trace
+    config = 'enable_stackdriver_trace_autoformat false'
+    non_stackdriver_trace_compliant_trace = '1234567890abcdef1234567890abcdef'


Constant NON_STACKDRIVER_TRACE?

updated - see comment above

qingling128 · 2018-09-26T01:43:05Z

lib/fluent/plugin/out_google_cloud.rb

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          if trace


We probably wanna check against empty strings as well? I'm leaning towards not formatting the field if it comes as an empty string. WDYT?

BTW, Ruby will take if <empty_string> as true.

$ irb 2.4.3 :001 > empty_string = "" => "" 2.4.3 :002 > if empty_string then true else false end => true

https://gist.github.com/jfarmer/2647362

Fun read. Oh Ruby... shoot me:

$ irb 2.4.3 :001 > if 0 then true else false end => true

will consider it with regexp topic https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/pull/260/files#r220408736 as they are related.

qingling128 · 2018-09-26T01:52:18Z

test/plugin/base_test.rb

@@ -338,6 +338,81 @@ def test_structured_payload_log
    end
  end

+  def test_stackdriver_trace_format_compliant_trace


The logic in these three tests are almost identical. They could be combined and use something like:

{ config: APPLICATION_DEFAULT_CONFIG, input_trace: XXX, expected_trace: XXX },

This way, it's easier to maintain the shared logic and also execute all tests related to trace with a single command. It also makes it easier to add more test cases.

BTW, we should also test cases like below in combination of different config values:

There's no logging.googleapis.com/trace field in payload.

logging.googleapis.com/trace field in payload is an empty string.

A custom trace_key is used instead of the default trace key. (Reference: trace_key is configurable: https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/lib/fluent/plugin/out_google_cloud.rb#L284)

to the first suggestion, I still maintain existing way to write test because the error message for each one is different - and the reason to make error message different is: 1) group similar testcases in a single unit and 2) provide more informative error message when the test fails.

Will add other 3 testcases, and consider reorganize testcases to whatever makes sense.

qingling128 · 2018-09-26T01:54:50Z

test/plugin/base_test.rb

+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}" \


Yeah, instead of d.instance.project_id, we could just use PROJECT, which is defined in the constants.rb file.

igorpeshansky

One more comment.

igorpeshansky · 2018-09-26T02:04:17Z

lib/fluent/plugin/out_google_cloud.rb

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          if trace


https://gist.github.com/jfarmer/2647362

igorpeshansky · 2018-09-26T02:07:03Z

test/plugin/base_test.rb

+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}" \


I was proposing the FULL_STACKDRIVER_TRACE and NON_STACKDRIVER_TRACE, same as you... If we define one in terms of the other, we can even use FULL_STACKDRIVER_TRACE as the expected value here...

igorpeshansky · 2018-09-26T02:13:36Z

lib/fluent/plugin/out_google_cloud.rb

-          entry.trace = trace if trace
+          if trace
+            if @enable_stackdriver_trace_autoformat &&
+               !STACKDRIVER_TRACE_REGEXP.match(trace)


Just realized that a trace value that isn't in the right format but does have a slash will probably produce a log entry that will fail validation. If we adjust it unconditionally, then the resulting error might not make sense to the customers (e.g., "too many slashes" instead of "too few slashes"). We should confirm this behavior and, if my hunch is right, change this to a positive regexp match instead (i.e., only adjust if it has a certain form). WDYT?

That's a valid concern. Agreed we should confirm the behavior.

that trace-value fail validation seems like a deal breaker - agree that if the format is not correct, autoformat should not be conducted.
Even that said, it sounds hard to setup a rule on agent side. There is no official trace-ID format available in public document I can see - so it's hard for me to set a rule to match the [TRACE-ID] part, and append prefix projects/[PROJECT-ID]/traces/ to it. Do you know who should I confirm with, and is there any service-client contract I can rely on @igorpeshansky ?

I found format of TraceID is documented and fully supported under Trace API v1 (REST), and Trace API (rpc) - google.devtools.cloudtrace - so I will rely on that to write the regexp matching.

qingling128 · 2018-09-26T16:36:35Z

lib/fluent/plugin/out_google_cloud.rb

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          if trace


Fun read. Oh Ruby... shoot me:

$ irb 2.4.3 :001 > if 0 then true else false end => true

qingling128 · 2018-09-26T16:42:42Z

lib/fluent/plugin/out_google_cloud.rb

-          entry.trace = trace if trace
+          if trace
+            if @enable_stackdriver_trace_autoformat &&
+               !STACKDRIVER_TRACE_REGEXP.match(trace)


That's a valid concern. Agreed we should confirm the behavior.

qingling128 · 2018-09-26T16:43:13Z

lib/fluent/plugin/out_google_cloud.rb

+      # will match the regexp is:
+      # "projects/my-project/traces/1234567890abcdef1234567890abcdef"
+      STACKDRIVER_TRACE_REGEXP = Regexp.new(
+        '^projects\/[^\/]*\/traces\/[^\/]*$').freeze


We probably wanna change the * to + in the Regexp, right?

changed the way autoformat works, so we don't need to have complex regexp anymore

StevenYCChou

Updated couple things based on feedback, but not fully resolved yet.
Still need to:

change implementation on regex matching part so it won't confuse user
add more edge testcases @qingling128 mentioned.

StevenYCChou · 2018-09-26T15:36:07Z

lib/fluent/plugin/out_google_cloud.rb

@@ -393,6 +399,10 @@ module InternalConstants
    config_param :monitoring_type, :string,
                 :default => Monitoring::PrometheusMonitoringRegistry.name

+    # Whether to autoformat value of "logging.googleapis.com/trace" to
+    # LogEntry.Trace.
+    config_param :enable_stackdriver_trace_autoformat, :bool, :default => true


makes sense. updated.

StevenYCChou · 2018-09-26T16:03:23Z

test/plugin/base_test.rb

+        config: APPLICATION_DEFAULT_CONFIG
+      },
+      {
+        config: 'enable_stackdriver_trace_autoformat true'


added configs into constant.

StevenYCChou · 2018-09-26T16:23:16Z

test/plugin/base_test.rb

+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}" \


The full trace here depends on the project_id of driver. If we change the whole trace into constant, It's unclear how that project_id in full trace comes from. I think it's hiding details into constant.

I think this project_id is local to this scope under the driver here. WDYT?

StevenYCChou · 2018-09-26T16:23:26Z

test/plugin/base_test.rb

+  end
+
+  def test_autoformat_disabled_with_stackdriver_trace_format_noncompliant_trace
+    config = 'enable_stackdriver_trace_autoformat false'


StevenYCChou · 2018-09-26T16:25:05Z

test/plugin/base_test.rb

@@ -338,6 +338,81 @@ def test_structured_payload_log
    end
  end

+  def test_stackdriver_trace_format_compliant_trace
+    full_stackdriver_trace = \


ditto - I think the full trace is project-dependent, not constant value.

StevenYCChou · 2018-09-26T17:03:36Z

test/plugin/base_test.rb

+          d.run
+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            assert_equal full_stackdriver_trace, entry['trace']


added more informative error messages.

StevenYCChou · 2018-09-26T18:05:52Z

test/plugin/base_test.rb

@@ -338,6 +338,81 @@ def test_structured_payload_log
    end
  end

+  def test_stackdriver_trace_format_compliant_trace


to the first suggestion, I still maintain existing way to write test because the error message for each one is different - and the reason to make error message different is: 1) group similar testcases in a single unit and 2) provide more informative error message when the test fails.

Will add other 3 testcases, and consider reorganize testcases to whatever makes sense.

StevenYCChou · 2018-09-26T18:21:31Z

lib/fluent/plugin/out_google_cloud.rb

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          if trace
+            if @enable_stackdriver_trace_autoformat &&


StevenYCChou · 2018-09-26T18:54:44Z

lib/fluent/plugin/out_google_cloud.rb

-          entry.trace = trace if trace
+          if trace
+            if @enable_stackdriver_trace_autoformat &&
+               !STACKDRIVER_TRACE_REGEXP.match(trace)


that trace-value fail validation seems like a deal breaker - agree that if the format is not correct, autoformat should not be conducted.
Even that said, it sounds hard to setup a rule on agent side. There is no official trace-ID format available in public document I can see - so it's hard for me to set a rule to match the [TRACE-ID] part, and append prefix projects/[PROJECT-ID]/traces/ to it. Do you know who should I confirm with, and is there any service-client contract I can rely on @igorpeshansky ?

StevenYCChou · 2018-09-26T18:55:44Z

lib/fluent/plugin/out_google_cloud.rb

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          if trace


will consider it with regexp topic https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/pull/260/files#r220408736 as they are related.

StevenYCChou

modified the regexp expression and added more testcases.

Didn't implement the customized trace_key though, because the customized trace_key is already captured in https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/test/plugin/base_test.rb#L1223-L1226 .

StevenYCChou · 2018-09-26T21:11:23Z

lib/fluent/plugin/out_google_cloud.rb

+      # will match the regexp is:
+      # "projects/my-project/traces/1234567890abcdef1234567890abcdef"
+      STACKDRIVER_TRACE_REGEXP = Regexp.new(
+        '^projects\/[^\/]*\/traces\/[^\/]*$').freeze


changed the way autoformat works, so we don't need to have complex regexp anymore

StevenYCChou · 2018-09-26T21:14:11Z

lib/fluent/plugin/out_google_cloud.rb

@@ -627,7 +637,8 @@ def write(chunk)
                                            ts_nanos)

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          entry.trace = compute_trace(trace) if trace


as if trace is existing behavior, I won't change the logic in this PR because it's out of the original scope.

I think @qingling128 was suggesting that an empty trace should not match the regexp that causes it to be rewritten...

if trace is fine now since we are using positive regex match

qingling128 · 2018-09-26T23:16:50Z

lib/fluent/plugin/out_google_cloud.rb

@@ -393,6 +398,10 @@ module InternalConstants
    config_param :monitoring_type, :string,
                 :default => Monitoring::PrometheusMonitoringRegistry.name

+    # Whether to autoformat value of "logging.googleapis.com/trace" to


It would be nice to provide more informative description on what this configuration does to help guide users. How about:

Whether to autoformat value of "logging.googleapis.com/trace" to comply with Stackdriver Trace format ("projects/[PROJECT-ID]/traces/[TRACE-ID]") when setting the trace field of the LogEntry object.

BTW, once this is released, we can update the public documentation to add this new config.

updated the comment to clarify the config!

qingling128 · 2018-09-26T23:20:31Z

lib/fluent/plugin/out_google_cloud.rb

@@ -627,7 +637,8 @@ def write(chunk)
                                            ts_nanos)

          trace = record.delete(@trace_key)
-          entry.trace = trace if trace
+          entry.trace = compute_trace(trace) if trace


if trace is fine now since we are using positive regex match

qingling128 · 2018-09-26T23:25:10Z

test/plugin/base_test.rb

+      NO_AUTOFORMAT_STACKDRIVER_TRACE_CONFIG
+    ]
+    traces = [
+      '',


Hmm... The empty string case seems to have failed the unit test for gRPC. Travis build.

It's probably due to https://github.com/GoogleCloudPlatform/fluent-plugin-google-cloud/blob/master/test/plugin/test_out_google_cloud_grpc.rb#L439.

use the function assert_equal_with_default to be able to verify even it's an empty string ''

qingling128 · 2018-09-26T23:28:50Z

test/plugin/base_test.rb

+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}/traces/#{STACKDRIVER_TRACE_ID}"
+            assert_equal expected_trace, entry['trace'], 'stackdriver trace ' \


Great message!

qingling128

LGTM

This commit enables OpenCensus log correlation using opencensus-contrib-log-correlation-log4j2 (https://github.com/census-instrumentation/opencensus-java/tree/master/contrib/log_correlation/log4j2). The library inserts the trace ID, span ID, and sampling decision into every Log4j log event. This commit includes other changes to make the tracing data available in the logs, in a format that can be interpreted by the StackDriver Logging agent: - Convert all adservice log statements from java.util.logging to Log4j. - Specify a JSON format for Log4j output. This is related to issue GoogleCloudPlatform#47. - Add the trace ID, span ID, and sampling decision to the JSON format. Trace ID and span ID use special keys that the Stackdriver Logging agent uses to populate the tracing data fields in the LogEntry uploaded to Stackdriver (https://cloud.google.com/logging/docs/agent/configuration#special_fields_in_structured_payloads). However, Stackdriver won't be able to link the traces and log entries until fluent-plugin-google-cloud can automatically format the trace ID with the format expected by Stackdriver (GoogleCloudPlatform/fluent-plugin-google-cloud#239, GoogleCloudPlatform/fluent-plugin-google-cloud#260). This commit also upgrades OpenCensus to 0.16.1 in order to use opencensus-contrib-log-correlation-log4j2.

igorpeshansky

A few more.

igorpeshansky · 2018-09-26T22:48:50Z

lib/fluent/plugin/out_google_cloud.rb

@@ -393,6 +398,10 @@ module InternalConstants
    config_param :monitoring_type, :string,
                 :default => Monitoring::PrometheusMonitoringRegistry.name

+    # Whether to autoformat value of "logging.googleapis.com/trace" to
+    # LogEntry.Trace.
+    config_param :autoformat_stackdriver_trace, :bool, :default => true


I would suggest moving this down, after adjust_invalid_timestamps.

igorpeshansky · 2018-09-26T22:51:34Z

test/plugin/constants.rb

@@ -265,6 +267,14 @@ module Constants
    enable_metadata_agent false
  ).freeze

+  AUTOFORMAT_STACKDRIVER_TRACE_CONFIG = %(


ENABLE_TRACE_AUTOFORMAT_CONFIG. We started this pattern with the metadata_agent configs — I think it's a bit more readable.

I thought you recommended using imperative form for config - and my original config is called enable_stackdriver_trace_autoformat , which matches what you suggested here.

I will modify this constant to ENABLE_AUTOFORMAT_STACKDRIVER_TRACE as logging agent will format to stackdriver trace format specifically, not other trace format.

Sorry to be unclear. The names for the config constants don't necessarily have to include the full config option name — they just need to be identifiable with that option. We have this pattern elsewhere. I was suggesting that we change <FULL_NAME>_CONFIG and NO_<FULL_NAME>_CONFIG to ENABLE_<SHORT_NAME>_CONFIG and DISABLE_<SHORT_NAME>_CONFIG. Does this make sense?

make seonse. still decide to use the ENABLE/DISABLE_FULL_NAME_CONFIG.

igorpeshansky · 2018-09-26T22:53:02Z

test/plugin/constants.rb

+    autoformat_stackdriver_trace true
+  ).freeze
+
+  NO_AUTOFORMAT_STACKDRIVER_TRACE_CONFIG = %(


DISABLE_TRACE_AUTOFORMAT_CONFIG...

ditto as above

igorpeshansky · 2018-09-26T22:59:13Z

test/plugin/base_test.rb

+
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}" \


The point is that the tests should be checking complete expected values. If you expect the resulting trace to have a particular project id, the constant should have that. I was suggesting defining the FULL_STACKDRIVER_TRACE as:

NON_STACKDRIVER_TRACE = "1234567890abcdef1234567890abcdef".freeze FULL_STACKDRIVER_TRACE = "projects/#{PROJECT_ID}/traces/#{NON_STACKDRIVER_TRACE}".freeze

in constants.rb.

igorpeshansky · 2018-09-26T23:01:09Z

test/plugin/base_test.rb

+      "projects/#{PROJECT_ID}/traces/",
+      "projects/#{PROJECT_ID}/traces/#{NON_STACKDRIVER_TRACE_ID}",
+      "projects//traces/#{STACKDRIVER_TRACE_ID}",
+      TRACE # full trace won't be modified either


Nit: missing trailing ..

igorpeshansky · 2018-09-27T15:56:09Z

test/plugin/base_test.rb

+      "projects//traces/#{STACKDRIVER_TRACE_ID}",
+      TRACE # full trace won't be modified either
+    ]
+    configs.product(traces).collect do |config, trace|


You're throwing away the collect result, so I'd use each instead.

agree - thanks for catching it!

igorpeshansky · 2018-09-27T15:59:12Z

test/plugin/base_test.rb

@@ -338,6 +338,98 @@ def test_structured_payload_log
    end
  end

+  def test_autoformat_enabled_with_stackdriver_trace_id_as_trace
+    configs = [


I wouldn't bother with just the configs local variable — just use the array literal. Also below.

what do you mean? isn't [] literal constructor? https://docs.ruby-lang.org/en/2.4.0/Array.html#class-Array-label-Creating+Arrays

I meant:

[ APPLICATION_DEFAULT_CONFIG, AUTOFORMAT_STACKDRIVER_TRACE_CONFIG ENABLE_AUTOFORMAT_STACKDRIVER_TRACE_CONFIG ].each do |config| ... end

updated - to make it consistent with rest of the tests if there is only single list to iterate through.

igorpeshansky · 2018-09-27T16:01:27Z

test/plugin/base_test.rb

+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            assert_equal trace, entry['trace'], 'trace as non stackdriver' \
+                         'trace id should not be autoformatted with ' \
+	                 "config #{config}."


Indentation.

igorpeshansky · 2018-09-27T16:02:52Z

test/plugin/base_test.rb

+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}/traces/#{STACKDRIVER_TRACE_ID}"
+            assert_equal expected_trace, entry['trace'], 'stackdriver trace ' \


Want to start the message on the next line? That way it's obvious that it's a separate entity...

igorpeshansky · 2018-09-27T16:05:31Z

test/plugin/base_test.rb

+              "projects/#{d.instance.project_id}/traces/#{STACKDRIVER_TRACE_ID}"
+            assert_equal expected_trace, entry['trace'], 'stackdriver trace ' \
+                         'id should be autoformatted with config ' \
+                         "#{test_config}."


I would just say "should be autoformatted when autoformat_stackdriver_trace is enabled", rather than print the config (which could at some point become larger than that). Also note that APPLICATION_DEFAULT_CONFIG is empty, so it'd be confusing to see "with config ." in the output.

updated - sorry miss this part in the previous change.

Can we do the same in test_non_stackdriver_trace_id_compliant_trace_with_any_autoformat_config as well? I don't think we have any other tests that interpolate the full config in the message...

This commit enables OpenCensus log correlation using opencensus-contrib-log-correlation-log4j2 (https://github.com/census-instrumentation/opencensus-java/tree/master/contrib/log_correlation/log4j2). The library inserts the trace ID, span ID, and sampling decision into every Log4j log event. This commit includes other changes to make the tracing data available in the logs, in a format that can be interpreted by the Stackdriver Logging agent: - Convert all adservice log statements from java.util.logging to Log4j. - Specify a JSON format for Log4j output. This is related to issue GoogleCloudPlatform#47. - Add the trace ID, span ID, and sampling decision to the JSON format. Trace ID and span ID use special keys that the Stackdriver Logging agent uses to populate the tracing data fields in the LogEntry uploaded to Stackdriver (https://cloud.google.com/logging/docs/agent/configuration#special_fields_in_structured_payloads). However, Stackdriver won't be able to link the traces and log entries until fluent-plugin-google-cloud can automatically format the trace ID with the format expected by Stackdriver (GoogleCloudPlatform/fluent-plugin-google-cloud#239, GoogleCloudPlatform/fluent-plugin-google-cloud#260). This commit also upgrades OpenCensus to 0.16.1 in order to use opencensus-contrib-log-correlation-log4j2.

igorpeshansky

Mostly replying to your comments and pinging the ones you didn't respond to.

igorpeshansky · 2018-09-28T14:24:37Z

test/plugin/base_test.rb

@@ -338,6 +338,98 @@ def test_structured_payload_log
    end
  end

+  def test_autoformat_enabled_with_stackdriver_trace_id_as_trace
+    configs = [


I meant:

[ APPLICATION_DEFAULT_CONFIG, AUTOFORMAT_STACKDRIVER_TRACE_CONFIG ENABLE_AUTOFORMAT_STACKDRIVER_TRACE_CONFIG ].each do |config| ... end

igorpeshansky · 2018-09-28T14:27:46Z

test/plugin/constants.rb

@@ -265,6 +267,14 @@ module Constants
    enable_metadata_agent false
  ).freeze

+  AUTOFORMAT_STACKDRIVER_TRACE_CONFIG = %(


Sorry to be unclear. The names for the config constants don't necessarily have to include the full config option name — they just need to be identifiable with that option. We have this pattern elsewhere. I was suggesting that we change <FULL_NAME>_CONFIG and NO_<FULL_NAME>_CONFIG to ENABLE_<SHORT_NAME>_CONFIG and DISABLE_<SHORT_NAME>_CONFIG. Does this make sense?

igorpeshansky · 2018-09-28T14:29:08Z

test/plugin/base_test.rb

@@ -338,6 +338,81 @@ def test_structured_payload_log
    end
  end

+  def test_stackdriver_trace_format_compliant_trace
+    full_stackdriver_trace = \


The project we feed into the tests is a constant, though... So we could construct the full expected value as a constant.

igorpeshansky · 2018-09-28T14:35:35Z

lib/fluent/plugin/out_google_cloud.rb

@@ -676,6 +686,14 @@ def write(chunk)

    private

+    def compute_trace(trace)
+      if @autoformat_stackdriver_trace &&


The point here is that the important bit is the early return, not the clause. A reader, seeing return trace unless [...] will think: "Ah, this function will return one of two values — an untransformed one unless some condition holds true, and a transformed one otherwise". Then they can dig into the condition. In the code you're proposing, the logic goes the other way — the reader first has to get through a large condition to figure out how the value is transformed, and then look at the end of the function to see that it's returned.

Incidentally, even if we agree that your current structure is more readable, I think it's better to say return "projects/#{@project_id}/traces/#{trace}" instead of assigning it back to a parameter trace only to return it in the end.

igorpeshansky · 2018-09-28T14:37:16Z

test/plugin/base_test.rb

+          d.run
+          verify_log_entries(1, COMPUTE_PARAMS, 'jsonPayload') do |entry|
+            expected_trace = \
+              "projects/#{d.instance.project_id}/traces/#{STACKDRIVER_TRACE_ID}"


The interpolation happens before the freeze, so the resulting string is a constant. Plus, this would be consistent with the rest of the testing code.

igorpeshansky · 2018-09-28T14:38:38Z

test/plugin/base_test.rb

+              "projects/#{d.instance.project_id}/traces/#{STACKDRIVER_TRACE_ID}"
+            assert_equal expected_trace, entry['trace'], 'stackdriver trace ' \
+                         'id should be autoformatted with config ' \
+                         "#{test_config}."


igorpeshansky · 2018-09-28T18:29:09Z

test/plugin/base_test.rb

+              "projects/#{d.instance.project_id}/traces/#{STACKDRIVER_TRACE_ID}"
+            assert_equal expected_trace, entry['trace'], 'stackdriver trace ' \
+                         'id should be autoformatted with config ' \
+                         "#{test_config}."


Can we do the same in test_non_stackdriver_trace_id_compliant_trace_with_any_autoformat_config as well? I don't think we have any other tests that interpolate the full config in the message...

igorpeshansky

One comment.

igorpeshansky · 2018-09-28T19:17:39Z

test/plugin/constants.rb

+    "projects/#{PROJECT_ID}/traces/#{STACKDRIVER_TRACE_ID}".freeze
+
+  # Invalid trace id for stackdriver.
+  EMPTY_STRING = ''.freeze


Personally, I think this one is overkill, but I'll let @qingling128 make this call.

Haha, i'm fine with defining an empty string constant. It could be shared by others as well though, not necessarily Invalid trace id for stackdriver.

igorpeshansky

LGTM

) This commit enables OpenCensus log correlation using opencensus-contrib-log-correlation-log4j2 (https://github.com/census-instrumentation/opencensus-java/tree/master/contrib/log_correlation/log4j2). The library inserts the trace ID, span ID, and sampling decision into every Log4j log event. This commit includes other changes to make the tracing data available in the logs, in a format that can be interpreted by the Stackdriver Logging agent: - Convert all adservice log statements from java.util.logging to Log4j. - Specify a JSON format for Log4j output. This is related to issue #47. - Add the trace ID, span ID, and sampling decision to the JSON format. Trace ID and span ID use special keys that the Stackdriver Logging agent uses to populate the tracing data fields in the LogEntry uploaded to Stackdriver (https://cloud.google.com/logging/docs/agent/configuration#special_fields_in_structured_payloads). However, Stackdriver won't be able to link the traces and log entries until fluent-plugin-google-cloud can automatically format the trace ID with the format expected by Stackdriver (GoogleCloudPlatform/fluent-plugin-google-cloud#239, GoogleCloudPlatform/fluent-plugin-google-cloud#260). This commit also upgrades OpenCensus to 0.16.1 in order to use opencensus-contrib-log-correlation-log4j2.

This change is necessary for log correlation to work before GoogleCloudPlatform/fluent-plugin-google-cloud#260 is available.

…nfig. Formatting the trace ID in the logging configuration is no longer necessary now that fluent-plugin-google-cloud formats the trace ID (GoogleCloudPlatform/fluent-plugin-google-cloud#260).

…nfig. (#68) Formatting the trace ID in the logging configuration is no longer necessary now that fluent-plugin-google-cloud formats the trace ID (GoogleCloudPlatform/fluent-plugin-google-cloud#260).

…#59) This commit enables OpenCensus log correlation using opencensus-contrib-log-correlation-log4j2 (https://github.com/census-instrumentation/opencensus-java/tree/master/contrib/log_correlation/log4j2). The library inserts the trace ID, span ID, and sampling decision into every Log4j log event. This commit includes other changes to make the tracing data available in the logs, in a format that can be interpreted by the Stackdriver Logging agent: - Convert all adservice log statements from java.util.logging to Log4j. - Specify a JSON format for Log4j output. This is related to issue #47. - Add the trace ID, span ID, and sampling decision to the JSON format. Trace ID and span ID use special keys that the Stackdriver Logging agent uses to populate the tracing data fields in the LogEntry uploaded to Stackdriver (https://cloud.google.com/logging/docs/agent/configuration#special_fields_in_structured_payloads). However, Stackdriver won't be able to link the traces and log entries until fluent-plugin-google-cloud can automatically format the trace ID with the format expected by Stackdriver (GoogleCloudPlatform/fluent-plugin-google-cloud#239, GoogleCloudPlatform/fluent-plugin-google-cloud#260). This commit also upgrades OpenCensus to 0.16.1 in order to use opencensus-contrib-log-correlation-log4j2.

add config to autoformat stackdriver trace

22e556e

StevenYCChou requested a review from qingling128 September 25, 2018 23:23

googlebot added the cla: yes label Sep 25, 2018

igorpeshansky requested changes Sep 25, 2018

View reviewed changes

qingling128 requested changes Sep 26, 2018

View reviewed changes

igorpeshansky requested changes Sep 26, 2018

View reviewed changes

StevenYCChou added 3 commits September 26, 2018 15:35

update config name to imperative form

e4f5734

Make autoformat config string as constant

c490ffa

make non_stackdriver_trace_compliant_trace as constant

bd45945

qingling128 requested changes Sep 26, 2018

View reviewed changes

StevenYCChou added 2 commits September 26, 2018 19:02

reformat testcases and make error message informative

e0657ee

extract compute_trace function out

4637761

StevenYCChou commented Sep 26, 2018

View reviewed changes

StevenYCChou added 3 commits September 26, 2018 21:10

autoformat with stackdriver trace_id only

db1419c

modify trace testcases

135cc1f

modify testcase so it passes rubocop

c384731

StevenYCChou commented Sep 26, 2018

View reviewed changes

qingling128 requested changes Sep 26, 2018

View reviewed changes

StevenYCChou added 3 commits September 27, 2018 02:47

Use assert_equal_with_default to avoid empty string case

f94af60

make config setup consistent

c49093f

update comment for config autoformat_stackdriver_trace

54d8f55

qingling128 approved these changes Sep 27, 2018

View reviewed changes

igorpeshansky requested changes Sep 27, 2018

View reviewed changes

sebright mentioned this pull request Sep 28, 2018

adservice: enable structured logging and OpenCensus log correlation GoogleCloudPlatform/microservices-demo#59

Merged

StevenYCChou added 4 commits September 28, 2018 01:33

reorder config_param

5964634

reformat the code

58b3969

avoid 'collect' to avoid wasted result

70b75ba

update config naming

ff2be3a

igorpeshansky requested changes Sep 28, 2018

View reviewed changes

StevenYCChou added 2 commits September 28, 2018 16:01

refactor compute_trace

de81703

restructure tests

2dc768e

igorpeshansky requested changes Sep 28, 2018

View reviewed changes

make all strings for testcase as constant

a7715b4

igorpeshansky requested changes Sep 28, 2018

View reviewed changes

igorpeshansky approved these changes Sep 28, 2018

View reviewed changes

StevenYCChou merged commit b5a4a2a into master Sep 29, 2018

igorpeshansky deleted the ycchou-stackdriver-trace-autoformat branch September 29, 2018 13:07

igorpeshansky mentioned this pull request Sep 29, 2018

Option to automatically format the LogEntry "trace" field #239

Closed

sebright added a commit to sebright/microservices-demo that referenced this pull request Oct 2, 2018

Temporarily hardcode project ID.

94e5035

This change is necessary for log correlation to work before GoogleCloudPlatform/fluent-plugin-google-cloud#260 is available.

sebright mentioned this pull request Oct 25, 2018

Remove trace ID formatting from Log4j log correlation demo logging config. census-ecosystem/opencensus-experiments#68

Merged

add config to autoformat stackdriver trace #260

add config to autoformat stackdriver trace #260

Conversation

StevenYCChou commented Sep 25, 2018

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

Choose a reason for hiding this comment

igorpeshansky 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

StevenYCChou 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

StevenYCChou 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

Choose a reason for hiding this comment

qingling128 left a comment

Choose a reason for hiding this comment

igorpeshansky left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment