folly/experimental/logging/test/ConfigUpdateTest.cpp

   1 /*
   2  * Copyright 2004-present Facebook, Inc.
   3  *
   4  * Licensed under the Apache License, Version 2.0 (the "License");
   5  * you may not use this file except in compliance with the License.
   6  * You may obtain a copy of the License at
   7  *
   8  *   http://www.apache.org/licenses/LICENSE-2.0
   9  *
  10  * Unless required by applicable law or agreed to in writing, software
  11  * distributed under the License is distributed on an "AS IS" BASIS,
  12  * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
  13  * See the License for the specific language governing permissions and
  14  * limitations under the License.
  15  */
  16 #include <folly/dynamic.h>
  17 #include <folly/experimental/logging/LogCategory.h>
  18 #include <folly/experimental/logging/LogConfig.h>
  19 #include <folly/experimental/logging/LogConfigParser.h>
  20 #include <folly/experimental/logging/LogHandlerFactory.h>
  21 #include <folly/experimental/logging/LoggerDB.h>
  22 #include <folly/experimental/logging/test/TestLogHandler.h>
  23 #include <folly/json.h>
  24 #include <folly/portability/GMock.h>
  25 #include <folly/portability/GTest.h>
  26 #include <folly/test/TestUtils.h>
  27
  28 using namespace folly;
  29 using ::testing::Pair;
  30 using ::testing::UnorderedElementsAre;
  31
  32 namespace {
  33
  34 MATCHER_P(LogHandlerMatcherImpl, config, "") {
  35   return arg->getConfig() == config;
  36 }
  37
  38 /**
  39  * A helper function to use in EXPECT_THAT() for matching a TestLogHandler
  40  * with the specified type and options.
  41  */
  42 auto MatchLogHandler(
  43     StringPiece type,
  44     std::unordered_map<std::string, std::string> options) {
  45   return LogHandlerMatcherImpl(LogHandlerConfig{type, std::move(options)});
  46 }
  47 auto MatchLogHandler(const LogHandlerConfig& config) {
  48   return LogHandlerMatcherImpl(config);
  49 }
  50
  51 } // namespace
  52
  53 namespace folly {
  54 /**
  55  * Print TestLogHandler objects nicely in test failure messages
  56  */
  57 std::ostream& operator<<(
  58     std::ostream& os,
  59     const std::shared_ptr<LogHandler>& handler) {
  60   auto configHandler = std::dynamic_pointer_cast<TestLogHandler>(handler);
  61   if (!configHandler) {
  62     os << "unknown handler type";
  63     return os;
  64   }
  65
  66   auto config = configHandler->getConfig();
  67   os << "ConfigHandler(" << config.type;
  68   for (const auto& entry : config.options) {
  69     os << ", " << entry.first << "=" << entry.second;
  70   }
  71   os << ")";
  72   return os;
  73 }
  74
  75 std::ostream& operator<<(std::ostream& os, const LogConfig& config) {
  76   os << toPrettyJson(logConfigToDynamic(config));
  77   return os;
  78 }
  79
  80 std::ostream& operator<<(std::ostream& os, const LogHandlerConfig& config) {
  81   os << toPrettyJson(logConfigToDynamic(config));
  82   return os;
  83 }
  84 } // namespace folly
  85
  86 TEST(ConfigUpdate, updateLogLevels) {
  87   LoggerDB db{LoggerDB::TESTING};
  88   db.updateConfig(parseLogConfig("foo.bar=dbg5"));
  89   EXPECT_EQ(LogLevel::DBG5, db.getCategory("foo.bar")->getLevel());
  90   EXPECT_EQ(LogLevel::DBG5, db.getCategory("foo.bar")->getEffectiveLevel());
  91   EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo")->getLevel());
  92   EXPECT_EQ(LogLevel::ERR, db.getCategory("foo")->getEffectiveLevel());
  93   EXPECT_EQ(LogLevel::ERR, db.getCategory("")->getLevel());
  94   EXPECT_EQ(LogLevel::ERR, db.getCategory("")->getEffectiveLevel());
  95
  96   EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo.bar.test")->getLevel());
  97   EXPECT_EQ(
  98       LogLevel::DBG5, db.getCategory("foo.bar.test")->getEffectiveLevel());
  99
 100   db.updateConfig(
 101       parseLogConfig("sys=warn,foo.test=debug,foo.test.stuff=warn"));
 102   EXPECT_EQ(LogLevel::WARN, db.getCategory("sys")->getLevel());
 103   EXPECT_EQ(LogLevel::WARN, db.getCategory("sys")->getEffectiveLevel());
 104   EXPECT_EQ(LogLevel::DEBUG, db.getCategory("foo.test")->getLevel());
 105   EXPECT_EQ(LogLevel::DEBUG, db.getCategory("foo.test")->getEffectiveLevel());
 106   EXPECT_EQ(LogLevel::WARN, db.getCategory("foo.test.stuff")->getLevel());
 107   EXPECT_EQ(
 108       LogLevel::DEBUG, db.getCategory("foo.test.stuff")->getEffectiveLevel());
 109   EXPECT_EQ(LogLevel::DBG5, db.getCategory("foo.bar")->getEffectiveLevel());
 110 }
 111
 112 TEST(ConfigUpdate, updateConfig) {
 113   LoggerDB db{LoggerDB::TESTING};
 114   db.registerHandlerFactory(
 115       std::make_unique<TestLogHandlerFactory>("handlerA"));
 116   db.registerHandlerFactory(
 117       std::make_unique<TestLogHandlerFactory>("handlerB"));
 118   EXPECT_EQ(parseLogConfig(".:=ERROR:"), db.getConfig());
 119
 120   // Create some categories that aren't affected by our config updates below,
 121   // just to ensure that they don't show up in getConfig() results since they
 122   // have the default config settings.
 123   db.getCategory("test.category1");
 124   db.getCategory("test.category2");
 125   EXPECT_EQ(parseLogConfig(".:=ERROR:"), db.getConfig());
 126
 127   // Apply an update
 128   db.updateConfig(parseLogConfig("INFO:stderr; stderr=handlerA,stream=stderr"));
 129   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 130   EXPECT_THAT(
 131       db.getCategory("")->getHandlers(),
 132       UnorderedElementsAre(
 133           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 134   EXPECT_EQ(
 135       parseLogConfig(".:=INFO:stderr; stderr=handlerA,stream=stderr"),
 136       db.getConfig());
 137
 138   // Update the log level for category "foo"
 139   // This should not affect the existing settings for the root category
 140   EXPECT_EQ(LogLevel::MAX_LEVEL, db.getCategory("foo")->getLevel());
 141   EXPECT_EQ(true, db.getCategory("foo")->getLevelInfo().second);
 142   db.updateConfig(parseLogConfig("foo:=DBG2"));
 143   EXPECT_EQ(LogLevel::DBG2, db.getCategory("foo")->getLevel());
 144   EXPECT_EQ(false, db.getCategory("foo")->getLevelInfo().second);
 145   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 146   EXPECT_EQ(1, db.getCategory("")->getHandlers().size());
 147   EXPECT_EQ(
 148       parseLogConfig(
 149           ".:=INFO:stderr, foo:=DBG2:; stderr=handlerA,stream=stderr"),
 150       db.getConfig());
 151
 152   // Add 2 log handlers to the "bar" log category.
 153   db.updateConfig(
 154       parseLogConfig("bar=ERROR:new:h2; "
 155                      "new=handlerB,key=value; "
 156                      "h2=handlerA,foo=bar"));
 157   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 158   EXPECT_THAT(
 159       db.getCategory("")->getHandlers(),
 160       UnorderedElementsAre(
 161           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 162   EXPECT_EQ(LogLevel::ERR, db.getCategory("bar")->getLevel());
 163   EXPECT_THAT(
 164       db.getCategory("bar")->getHandlers(),
 165       UnorderedElementsAre(
 166           MatchLogHandler("handlerB", {{"key", "value"}}),
 167           MatchLogHandler("handlerA", {{"foo", "bar"}})));
 168   EXPECT_EQ(
 169       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=ERROR:new:h2; "
 170                      "stderr=handlerA,stream=stderr; "
 171                      "new=handlerB,key=value; "
 172                      "h2=handlerA,foo=bar"),
 173       db.getConfig());
 174
 175   // Updating the "new" log handler settings should automatically update
 176   // the settings we see on the "bar" category, even if we don't explicitly
 177   // list "bar" in the config update
 178   db.updateConfig(parseLogConfig("; new=handlerB,newkey=newvalue"));
 179   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 180   EXPECT_THAT(
 181       db.getCategory("")->getHandlers(),
 182       UnorderedElementsAre(
 183           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 184   EXPECT_EQ(LogLevel::ERR, db.getCategory("bar")->getLevel());
 185   EXPECT_THAT(
 186       db.getCategory("bar")->getHandlers(),
 187       UnorderedElementsAre(
 188           MatchLogHandler("handlerB", {{"newkey", "newvalue"}}),
 189           MatchLogHandler("handlerA", {{"foo", "bar"}})));
 190   EXPECT_EQ(
 191       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=ERROR:new:h2; "
 192                      "stderr=handlerA,stream=stderr; "
 193                      "new=handlerB,newkey=newvalue; "
 194                      "h2=handlerA,foo=bar"),
 195       db.getConfig());
 196
 197   // Updating the level settings for the "bar" handler should leave its
 198   // handlers unchanged.
 199   db.updateConfig(parseLogConfig("bar=WARN"));
 200   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 201   EXPECT_THAT(
 202       db.getCategory("")->getHandlers(),
 203       UnorderedElementsAre(
 204           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 205   EXPECT_EQ(LogLevel::WARN, db.getCategory("bar")->getLevel());
 206   EXPECT_THAT(
 207       db.getCategory("bar")->getHandlers(),
 208       UnorderedElementsAre(
 209           MatchLogHandler("handlerB", {{"newkey", "newvalue"}}),
 210           MatchLogHandler("handlerA", {{"foo", "bar"}})));
 211   EXPECT_EQ(
 212       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=WARN:new:h2; "
 213                      "stderr=handlerA,stream=stderr; "
 214                      "new=handlerB,newkey=newvalue; "
 215                      "h2=handlerA,foo=bar"),
 216       db.getConfig());
 217
 218   // Update the options for the h2 handler in place, and also add it to the
 219   // "test.foo" category.  The changes should also be reflected on the "bar"
 220   // category.
 221   db.updateConfig(
 222       parseLogConfig("test.foo=INFO:h2; h2=handlerA,reuse_handler=1,foo=xyz"));
 223   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 224   EXPECT_THAT(
 225       db.getCategory("")->getHandlers(),
 226       UnorderedElementsAre(
 227           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 228   EXPECT_EQ(LogLevel::WARN, db.getCategory("bar")->getLevel());
 229   EXPECT_THAT(
 230       db.getCategory("bar")->getHandlers(),
 231       UnorderedElementsAre(
 232           MatchLogHandler("handlerB", {{"newkey", "newvalue"}}),
 233           MatchLogHandler(
 234               "handlerA", {{"foo", "xyz"}, {"reuse_handler", "1"}})));
 235   EXPECT_EQ(LogLevel::INFO, db.getCategory("test.foo")->getLevel());
 236   EXPECT_THAT(
 237       db.getCategory("test.foo")->getHandlers(),
 238       UnorderedElementsAre(MatchLogHandler(
 239           "handlerA", {{"foo", "xyz"}, {"reuse_handler", "1"}})));
 240   EXPECT_EQ(
 241       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=WARN:new:h2, "
 242                      "test.foo=INFO:h2; "
 243                      "stderr=handlerA,stream=stderr; "
 244                      "new=handlerB,newkey=newvalue; "
 245                      "h2=handlerA,reuse_handler=1,foo=xyz"),
 246       db.getConfig());
 247
 248   // Explicitly clear the handlers for the "bar" category
 249   // This should remove the "new" handler from the LoggerDB since bar was the
 250   // only category referring to it.
 251   db.updateConfig(parseLogConfig("bar=WARN:"));
 252   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 253   EXPECT_THAT(
 254       db.getCategory("")->getHandlers(),
 255       UnorderedElementsAre(
 256           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 257   EXPECT_EQ(LogLevel::WARN, db.getCategory("bar")->getLevel());
 258   EXPECT_THAT(db.getCategory("bar")->getHandlers(), UnorderedElementsAre());
 259   EXPECT_EQ(
 260       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=WARN:, "
 261                      "test.foo=INFO:h2; "
 262                      "stderr=handlerA,stream=stderr; "
 263                      "h2=handlerA,reuse_handler=1,foo=xyz"),
 264       db.getConfig());
 265
 266   // Now test resetConfig()
 267   db.resetConfig(
 268       parseLogConfig("bar=INFO:h2, test.abc=DBG3; "
 269                      "h2=handlerB,abc=xyz"));
 270   EXPECT_EQ(
 271       parseLogConfig(".:=ERR:, bar=INFO:h2, test.abc=DBG3:; "
 272                      "h2=handlerB,abc=xyz"),
 273       db.getConfig());
 274 }
 275
 276 TEST(ConfigUpdate, getConfigAnonymousHandlers) {
 277   LoggerDB db{LoggerDB::TESTING};
 278   db.registerHandlerFactory(
 279       std::make_unique<TestLogHandlerFactory>("handlerA"));
 280   db.registerHandlerFactory(
 281       std::make_unique<TestLogHandlerFactory>("handlerB"));
 282   EXPECT_EQ(parseLogConfig(".:=ERROR:"), db.getConfig());
 283
 284   // Manually attach a handler to a category.
 285   // It should be reported as "anonymousHandler1"
 286   auto handlerFoo = std::make_shared<TestLogHandler>(
 287       LogHandlerConfig{"foo", {{"abc", "xyz"}}});
 288   db.setLevel("x.y.z", LogLevel::DBG2);
 289   db.getCategory("x.y.z")->addHandler(handlerFoo);
 290   EXPECT_EQ(
 291       parseLogConfig(".:=ERR:, x.y.z=DBG2:anonymousHandler1; "
 292                      "anonymousHandler1=foo,abc=xyz"),
 293       db.getConfig());
 294
 295   // If we attach the same handler to another category it should still only be
 296   // reported once.
 297   db.setLevel("test.category", LogLevel::DBG1);
 298   db.getCategory("test.category")->addHandler(handlerFoo);
 299   EXPECT_EQ(
 300       parseLogConfig(".:=ERR:, "
 301                      "x.y.z=DBG2:anonymousHandler1, "
 302                      "test.category=DBG1:anonymousHandler1; "
 303                      "anonymousHandler1=foo,abc=xyz"),
 304       db.getConfig());
 305
 306   // If we use updateConfig() to explicitly define a handler named
 307   // "anonymousHandler1", the unnamed handler will be reported as
 308   // "anonymousHandler2" instead now.
 309   db.updateConfig(parseLogConfig(
 310       "a.b.c=INFO:anonymousHandler1; anonymousHandler1=handlerA,key=value"));
 311   EXPECT_EQ(
 312       parseLogConfig(".:=ERR:, "
 313                      "a.b.c=INFO:anonymousHandler1, "
 314                      "x.y.z=DBG2:anonymousHandler2, "
 315                      "test.category=DBG1:anonymousHandler2; "
 316                      "anonymousHandler1=handlerA,key=value; "
 317                      "anonymousHandler2=foo,abc=xyz"),
 318       db.getConfig());
 319 }