fixes

Signed-off-by: Greg Greenway <[email protected]>

Author: ggreenway

api/envoy/extensions/access_loggers/stats/v3/stats.proto

@@ -16,7 +16,7 @@ option go_package = "github.com/envoyproxy/go-control-plane/envoy/extensions/acc
 option (udpa.annotations.file_status).package_version_status = ACTIVE;
 
 // [#protodoc-title: Stats logger]
-// Configuration for an access logger that emits customEnvoy stats according to its
+// Configuration for an access logger that emits custom Envoy stats according to its
 // configuration. The stats can have tags and values derived from
 // :ref:`command operators <config_access_log_command_operators>`.
 // [#extension: envoy.access_loggers.stats]
@@ -91,7 +91,7 @@ message Config {
     google.protobuf.UInt64Value value_fixed = 3 [(validate.rules).uint64 = {gt: 0}];
   }
 
-  // The stat prefix for all stats in this logger.
+  // The stat prefix for the generated stats.
   string stat_prefix = 1 [(validate.rules).string = {min_len: 1}];
 
   // The histograms this logger will emit.

source/extensions/access_loggers/stats/stats.cc

@@ -92,7 +92,7 @@ StatsAccessLog::DynamicTag::DynamicTag(
     Stats::StatNamePool& pool, const std::vector<Formatter::CommandParserPtr>& commands)
     : name_(pool.add(tag_cfg.name())),
       value_formatter_(THROW_OR_RETURN_VALUE(
-          Formatter::FormatterImpl::create(tag_cfg.value_format(), false, commands),
+          Formatter::FormatterImpl::create(tag_cfg.value_format(), true, commands),
           Formatter::FormatterPtr)) {}
 
 std::pair<Stats::StatNameTagVector, std::vector<Stats::StatNameDynamicStorage>>
@@ -143,7 +143,12 @@ absl::optional<uint64_t> getFormatValue(const Formatter::FormatterProvider& form
 
 void StatsAccessLog::emitLog(const Formatter::Context& context,
                              const StreamInfo::StreamInfo& stream_info) {
-  for (auto& histogram : histograms_) {
+  emitLogConst(context, stream_info);
+}
+
+void StatsAccessLog::emitLogConst(const Formatter::Context& context,
+                                  const StreamInfo::StreamInfo& stream_info) const {
+  for (const auto& histogram : histograms_) {
     absl::optional<uint64_t> computed_value_opt =
         getFormatValue(*histogram.value_formatter_, context, stream_info,
                        histogram.unit_ == Stats::Histogram::Unit::Percent);
@@ -159,7 +164,7 @@ void StatsAccessLog::emitLog(const Formatter::Context& context,
     histogram_stat.recordValue(value);
   }
 
-  for (auto& counter : counters_) {
+  for (const auto& counter : counters_) {
     uint64_t value;
     if (counter.value_formatter_ != nullptr) {
       absl::optional<uint64_t> computed_value_opt =

source/extensions/access_loggers/stats/stats.h

@@ -22,6 +22,11 @@ class StatsAccessLog : public Common::ImplBase {
   void emitLog(const Formatter::Context& context,
                const StreamInfo::StreamInfo& stream_info) override;
 
+  // `emitLog` is called concurrently from different works. Move all the logic into a const function
+  // to ensure there are no data races in mutation of class members.
+  void emitLogConst(const Formatter::Context& context,
+                    const StreamInfo::StreamInfo& stream_info) const;
+
   class DynamicTag {
   public:
     DynamicTag(const envoy::extensions::access_loggers::stats::v3::Config::Tag& tag_cfg,

test/extensions/access_loggers/stats/integration_test.cc

@@ -82,6 +82,53 @@ TEST_P(StatsAccessLogIntegrationTest, Basic) {
                    TestUtility::readSampleSum(test_server_->server().dispatcher(), *histogram)));
 }
 
+// Trigger simultaneous logs on multiple workers to trigger TSAN errors if present.
+TEST_P(StatsAccessLogIntegrationTest, Concurrency) {
+  concurrency_ = 2;
+  const std::string config_yaml = R"EOF(
+              name: envoy.access_loggers.stats
+              typed_config:
+                "@type": type.googleapis.com/envoy.extensions.access_loggers.stats.v3.Config
+                stat_prefix: test_stat_prefix
+                counters:
+                  - stat:
+                      name: formatcounter
+                    value_format: '%RESPONSE_CODE%'
+                histograms:
+                  - stat:
+                      name: testhistogram
+                      tags:
+                        - name: tag
+                          value_format: '%REQUEST_HEADER(tag-value)%'
+                    value_format: '%REQUEST_HEADER(histogram-value)%'
+
+)EOF";
+
+  init(config_yaml);
+
+  const Http::TestRequestHeaderMapImpl request_headers{
+      {":method", "GET"},       {":authority", "envoyproxy.io"}, {":path", "/test/long/url"},
+      {":scheme", "http"},      {"tag-value", "mytagvalue"},     {"counter-value", "7"},
+      {"histogram-value", "2"},
+  };
+
+  std::vector<std::thread> threads;
+  for (uint32_t i = 0; i < 10; i++) {
+    threads.emplace_back([&]() {
+      for (uint32_t requests = 0; requests < 10; requests++) {
+        BufferingStreamDecoderPtr response = IntegrationUtil::makeSingleRequest(
+            lookupPort("http"), "GET", "/", "", downstream_protocol_, version_, "envoyproxy.io");
+        ASSERT_TRUE(response->complete());
+        EXPECT_EQ("200", response->headers().getStatusValue());
+      }
+    });
+  }
+
+  for (auto& t : threads) {
+    t.join();
+  }
+}
+
 TEST_P(StatsAccessLogIntegrationTest, PercentHistogram) {
   const std::string config_yaml = R"EOF(
               name: envoy.access_loggers.stats

test/extensions/access_loggers/stats/stats_test.cc

@@ -43,12 +43,11 @@ class StatsAccessLoggerTest : public testing::Test {
   }
 
   void initialize(const envoy::extensions::access_loggers::stats::v3::Config& config) {
-    // ON_CALL(context_, statsScope()).WillByDefault(testing::ReturnRef(root_scope_));
     ON_CALL(context_, statsScope()).WillByDefault(testing::ReturnRef(store_.mockScope()));
     EXPECT_CALL(store_.mockScope(), createScope_(_))
         .WillOnce(Invoke([this](const std::string& name) {
           Stats::StatNameDynamicStorage storage(name, context_.store_.symbolTable());
-          scope_ = std::make_shared<Stats::MockScope>(storage.statName(), store_);
+          scope_ = std::make_shared<NiceMock<Stats::MockScope>>(storage.statName(), store_);
           return scope_;
         }));
 
@@ -217,6 +216,24 @@ TEST_F(StatsAccessLoggerTest, NumberStringValueFormatted) {
   logger_->log(formatter_context_, stream_info_);
 }
 
+TEST_F(StatsAccessLoggerTest, CounterValueFixed) {
+  const std::string yaml = R"EOF(
+    stat_prefix: test_stat_prefix
+    counters:
+      - stat:
+          name: counter
+        value_fixed: 42
+)EOF";
+
+  initialize(yaml);
+
+  absl::optional<std::string> a_number{"42"};
+  EXPECT_CALL(stream_info_, responseCodeDetails()).WillRepeatedly(testing::ReturnRef(a_number));
+  EXPECT_CALL(store_, counter(_));
+  EXPECT_CALL(store_.counter_, add(42));
+  logger_->log(formatter_context_, stream_info_);
+}
+
 // Histogram values are in the range 0-1.0, so ensure that fractional values work.
 TEST_F(StatsAccessLoggerTest, HistogramPercent) {
   const std::string yaml = R"EOF(
@@ -248,6 +265,38 @@ TEST_F(StatsAccessLoggerTest, HistogramPercent) {
   logger_->log(formatter_context_, stream_info_);
 }
 
+// Test that a tag formatter that doesn't have a value becomes an empty string.
+TEST_F(StatsAccessLoggerTest, EmptyTagFormatter) {
+  const std::string yaml = R"EOF(
+    stat_prefix: test_stat_prefix
+    counters:
+      - stat:
+          name: counter
+          tags:
+            - name: tag
+              value_format: '%RESPONSE_CODE_DETAILS%:%RESPONSE_CODE%'
+        value_fixed: 1
+)EOF";
+
+  initialize(yaml);
+
+  absl::optional<std::string> nullopt{absl::nullopt};
+  EXPECT_CALL(stream_info_, responseCodeDetails()).WillRepeatedly(testing::ReturnRef(nullopt));
+  EXPECT_CALL(stream_info_, responseCode())
+      .WillRepeatedly(testing::Return(absl::optional<uint32_t>{200}));
+  EXPECT_CALL(*scope_, counterFromStatNameWithTags(_, _))
+      .WillOnce(
+          testing::Invoke([this](const Stats::StatName& name,
+                                 Stats::StatNameTagVectorOptConstRef tags) -> Stats::Counter& {
+            EXPECT_EQ("counter", scope_->symbolTable().toString(name));
+            EXPECT_EQ(1, tags->get().size());
+            EXPECT_EQ(":200", scope_->symbolTable().toString(tags->get().front().second));
+
+            return scope_->counterFromStatNameWithTags_(name, tags);
+          }));
+  logger_->log(formatter_context_, stream_info_);
+}
+
 } // namespace StatsAccessLog
 } // namespace AccessLoggers
 } // namespace Extensions

test/mocks/stats/mocks.cc

@@ -82,10 +82,16 @@ MockSinkPredicates::MockSinkPredicates() = default;
 MockSinkPredicates::~MockSinkPredicates() = default;
 
 MockScope::MockScope(StatName prefix, MockStore& store)
-    : TestUtil::TestScope(prefix, store), mock_store_(store) {}
+    : TestUtil::TestScope(prefix, store), mock_store_(store) {
+  ON_CALL(*this, counterFromStatNameWithTags(_, _))
+      .WillByDefault(
+          Invoke([this](const StatName& name, StatNameTagVectorOptConstRef tags) -> Counter& {
+            return counterFromStatNameWithTags_(name, tags);
+          }));
+}
 
-Counter& MockScope::counterFromStatNameWithTags(const StatName& name,
-                                                StatNameTagVectorOptConstRef) {
+Counter& MockScope::counterFromStatNameWithTags_(const StatName& name,
+                                                 StatNameTagVectorOptConstRef) {
   // We always just respond with the mocked counter, so the tags don't matter.
   return mock_store_.counter(symbolTable().toString(name));
 }
@@ -121,7 +127,7 @@ MockStore::MockStore() {
 MockStore::~MockStore() = default;
 
 ScopeSharedPtr MockStore::makeScope(StatName prefix) {
-  return std::make_shared<MockScope>(prefix, *this);
+  return std::make_shared<NiceMock<MockScope>>(prefix, *this);
 }
 
 MockIsolatedStatsStore::MockIsolatedStatsStore() = default;

test/mocks/stats/mocks.h

@@ -312,7 +312,10 @@ class MockScope : public TestUtil::TestScope {
   // Override the lowest level of stat creation based on StatName to redirect
   // back to the old string-based mechanisms still on the MockStore object
   // to allow tests to inject EXPECT_CALL hooks for those.
-  Counter& counterFromStatNameWithTags(const StatName& name, StatNameTagVectorOptConstRef) override;
+  MOCK_METHOD(Counter&, counterFromStatNameWithTags,
+              (const StatName&, StatNameTagVectorOptConstRef));
+  Counter& counterFromStatNameWithTags_(const StatName& name, StatNameTagVectorOptConstRef);
+
   Gauge& gaugeFromStatNameWithTags(const StatName& name, StatNameTagVectorOptConstRef,
                                    Gauge::ImportMode import_mode) override;
   Histogram& histogramFromStatNameWithTags(const StatName& name, StatNameTagVectorOptConstRef,