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 ? config.type.value() : "[no 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::DBG, db.getCategory("foo.test")->getLevel());
 105   EXPECT_EQ(LogLevel::DBG, db.getCategory("foo.test")->getEffectiveLevel());
 106   EXPECT_EQ(LogLevel::WARN, db.getCategory("foo.test.stuff")->getLevel());
 107   EXPECT_EQ(
 108       LogLevel::DBG, 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   // Update the options for the h2 handler using partial options
 249   db.updateConfig(parseLogConfig("; h2:abc=def"));
 250   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 251   EXPECT_THAT(
 252       db.getCategory("")->getHandlers(),
 253       UnorderedElementsAre(
 254           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 255   EXPECT_EQ(LogLevel::WARN, db.getCategory("bar")->getLevel());
 256   EXPECT_THAT(
 257       db.getCategory("bar")->getHandlers(),
 258       UnorderedElementsAre(
 259           MatchLogHandler("handlerB", {{"newkey", "newvalue"}}),
 260           MatchLogHandler(
 261               "handlerA",
 262               {{"abc", "def"}, {"foo", "xyz"}, {"reuse_handler", "1"}})));
 263   EXPECT_EQ(LogLevel::INFO, db.getCategory("test.foo")->getLevel());
 264   EXPECT_THAT(
 265       db.getCategory("test.foo")->getHandlers(),
 266       UnorderedElementsAre(MatchLogHandler(
 267           "handlerA",
 268           {{"abc", "def"}, {"foo", "xyz"}, {"reuse_handler", "1"}})));
 269   EXPECT_EQ(
 270       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=WARN:new:h2, "
 271                      "test.foo=INFO:h2; "
 272                      "stderr=handlerA: stream=stderr; "
 273                      "new=handlerB: newkey=newvalue; "
 274                      "h2=handlerA: reuse_handler=1,abc=def,foo=xyz"),
 275       db.getConfig());
 276
 277   // Update the options for the "new" handler using partial options
 278   db.updateConfig(parseLogConfig("; new:opt1=value1"));
 279   EXPECT_EQ(LogLevel::WARN, db.getCategory("bar")->getLevel());
 280   EXPECT_THAT(
 281       db.getCategory("bar")->getHandlers(),
 282       UnorderedElementsAre(
 283           MatchLogHandler(
 284               "handlerB", {{"opt1", "value1"}, {"newkey", "newvalue"}}),
 285           MatchLogHandler(
 286               "handlerA",
 287               {{"abc", "def"}, {"foo", "xyz"}, {"reuse_handler", "1"}})));
 288   EXPECT_EQ(LogLevel::INFO, db.getCategory("test.foo")->getLevel());
 289   EXPECT_THAT(
 290       db.getCategory("test.foo")->getHandlers(),
 291       UnorderedElementsAre(MatchLogHandler(
 292           "handlerA",
 293           {{"abc", "def"}, {"foo", "xyz"}, {"reuse_handler", "1"}})));
 294   EXPECT_EQ(
 295       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=WARN:new:h2, "
 296                      "test.foo=INFO:h2; "
 297                      "stderr=handlerA: stream=stderr; "
 298                      "new=handlerB: newkey=newvalue,opt1=value1; "
 299                      "h2=handlerA: reuse_handler=1,abc=def,foo=xyz"),
 300       db.getConfig());
 301
 302   // Supplying partial options for a non-existent log handler should fail
 303   EXPECT_THROW_RE(
 304       db.updateConfig(parseLogConfig("; no_such_handler:foo=bar")),
 305       std::invalid_argument,
 306       R"(cannot update unknown log handler "no_such_handler")");
 307
 308   // Explicitly clear the handlers for the "bar" category
 309   // This should remove the "new" handler from the LoggerDB since bar was the
 310   // only category referring to it.
 311   db.updateConfig(parseLogConfig("bar=WARN:"));
 312   EXPECT_EQ(LogLevel::INFO, db.getCategory("")->getLevel());
 313   EXPECT_THAT(
 314       db.getCategory("")->getHandlers(),
 315       UnorderedElementsAre(
 316           MatchLogHandler("handlerA", {{"stream", "stderr"}})));
 317   EXPECT_EQ(LogLevel::WARN, db.getCategory("bar")->getLevel());
 318   EXPECT_THAT(db.getCategory("bar")->getHandlers(), UnorderedElementsAre());
 319   EXPECT_EQ(
 320       parseLogConfig(".:=INFO:stderr, foo:=DBG2:, bar=WARN:, "
 321                      "test.foo=INFO:h2; "
 322                      "stderr=handlerA: stream=stderr; "
 323                      "h2=handlerA: reuse_handler=1,abc=def,foo=xyz"),
 324       db.getConfig());
 325
 326   // Now test resetConfig()
 327   db.resetConfig(
 328       parseLogConfig("bar=INFO:h2, test.abc=DBG3; "
 329                      "h2=handlerB: abc=xyz"));
 330   EXPECT_EQ(
 331       parseLogConfig(".:=ERR:, bar=INFO:h2, test.abc=DBG3:; "
 332                      "h2=handlerB: abc=xyz"),
 333       db.getConfig());
 334 }
 335
 336 TEST(ConfigUpdate, getConfigAnonymousHandlers) {
 337   LoggerDB db{LoggerDB::TESTING};
 338   db.registerHandlerFactory(
 339       std::make_unique<TestLogHandlerFactory>("handlerA"));
 340   db.registerHandlerFactory(
 341       std::make_unique<TestLogHandlerFactory>("handlerB"));
 342   EXPECT_EQ(parseLogConfig(".:=ERROR:"), db.getConfig());
 343
 344   // Manually attach a handler to a category.
 345   // It should be reported as "anonymousHandler1"
 346   auto handlerFoo = std::make_shared<TestLogHandler>(
 347       LogHandlerConfig{"foo", {{"abc", "xyz"}}});
 348   db.setLevel("x.y.z", LogLevel::DBG2);
 349   db.getCategory("x.y.z")->addHandler(handlerFoo);
 350   EXPECT_EQ(
 351       parseLogConfig(".:=ERR:, x.y.z=DBG2:anonymousHandler1; "
 352                      "anonymousHandler1=foo:abc=xyz"),
 353       db.getConfig());
 354
 355   // If we attach the same handler to another category it should still only be
 356   // reported once.
 357   db.setLevel("test.category", LogLevel::DBG1);
 358   db.getCategory("test.category")->addHandler(handlerFoo);
 359   EXPECT_EQ(
 360       parseLogConfig(".:=ERR:, "
 361                      "x.y.z=DBG2:anonymousHandler1, "
 362                      "test.category=DBG1:anonymousHandler1; "
 363                      "anonymousHandler1=foo:abc=xyz"),
 364       db.getConfig());
 365
 366   // If we use updateConfig() to explicitly define a handler named
 367   // "anonymousHandler1", the unnamed handler will be reported as
 368   // "anonymousHandler2" instead now.
 369   db.updateConfig(parseLogConfig(
 370       "a.b.c=INFO:anonymousHandler1; anonymousHandler1=handlerA:key=value"));
 371   EXPECT_EQ(
 372       parseLogConfig(".:=ERR:, "
 373                      "a.b.c=INFO:anonymousHandler1, "
 374                      "x.y.z=DBG2:anonymousHandler2, "
 375                      "test.category=DBG1:anonymousHandler2; "
 376                      "anonymousHandler1=handlerA: key=value; "
 377                      "anonymousHandler2=foo: abc=xyz"),
 378       db.getConfig());
 379 }