From 2272bf33b7606162c7b2006910b8ccd975232601 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Tue, 8 Sep 2020 17:11:10 +0100 Subject: [PATCH 1/9] KAFKA-10469: Resolve logger levels hierarchically Previous to root logger level was used, ignoring intervening loggers with different levels. --- .../scala/kafka/utils/Log4jController.scala | 23 ++++++++-- .../kafka/utils/Log4jControllerTest.scala | 43 +++++++++++++++++++ 2 files changed, 63 insertions(+), 3 deletions(-) create mode 100644 core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala diff --git a/core/src/main/scala/kafka/utils/Log4jController.scala b/core/src/main/scala/kafka/utils/Log4jController.scala index a7a72e78447a9..d48c14f95e144 100755 --- a/core/src/main/scala/kafka/utils/Log4jController.scala +++ b/core/src/main/scala/kafka/utils/Log4jController.scala @@ -29,6 +29,24 @@ import scala.jdk.CollectionConverters._ object Log4jController { val ROOT_LOGGER = "root" + def resolveLevel(logger: Logger): String = { + var name = logger.getName + var level = logger.getLevel + while (level == null) { + val index = name.lastIndexOf(".") + if (index != -1) { + name = name.substring(0, index) + val ancestor = existingLogger(name) + if (ancestor != null) { + level = ancestor.getLevel + } + } else { + existingLogger(ROOT_LOGGER).getLevel + } + } + level.toString + } + /** * Returns a map of the log4j loggers and their assigned log level. * If a logger does not have a log level assigned, we return the root logger's log level @@ -42,8 +60,7 @@ object Log4jController { while (loggers.hasMoreElements) { val logger = loggers.nextElement().asInstanceOf[Logger] if (logger != null) { - val level = if (logger.getLevel != null) logger.getLevel.toString else rootLoggerLvl - logs.put(logger.getName, level) + logs.put(logger.getName, resolveLevel(logger)) } } logs @@ -101,7 +118,7 @@ class Log4jController extends Log4jControllerMBean { if (level != null) log.getLevel.toString else - Log4jController.existingLogger(Log4jController.ROOT_LOGGER).getLevel.toString + Log4jController.resolveLevel(log) } else "No such logger." } diff --git a/core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala b/core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala new file mode 100644 index 0000000000000..734e3c54bb76b --- /dev/null +++ b/core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala @@ -0,0 +1,43 @@ +/* + * Licensed to the Apache Software Foundation (ASF) under one or more + * contributor license agreements. See the NOTICE file distributed with + * this work for additional information regarding copyright ownership. + * The ASF licenses this file to You under the Apache License, Version 2.0 + * (the "License"); you may not use this file except in compliance with + * the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package kafka.utils + +import com.typesafe.scalalogging.Logger +import org.junit.{Assert, Test} +import org.slf4j.LoggerFactory + + +class Log4jControllerTest { + + @Test + def testLoggerLevelIsResolved(): Unit = { + val controller = new Log4jController() + val previousLevel = controller.getLogLevel("kafka") + try { + controller.setLogLevel("kafka", "TRACE") + Logger(LoggerFactory.getLogger("kafka.utils.Log4jControllerTest")).trace("test") + Assert.assertEquals("TRACE", controller.getLogLevel("kafka")) + Assert.assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) + Assert.assertTrue(controller.getLoggers.contains("kafka=TRACE")) + Assert.assertTrue(controller.getLoggers.contains("kafka.utils.Log4jControllerTest=TRACE")) + } finally { + controller.setLogLevel("kafka", previousLevel) + } + + } +} From 3b75b0b69e8d70a97716ccb3e3dfdb5fca31b691 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Tue, 8 Sep 2020 18:02:53 +0100 Subject: [PATCH 2/9] Fix logic & move test --- .../scala/kafka/utils/Log4jController.scala | 2 +- .../test/scala/kafka/utils/LoggingTest.scala | 22 +++++++++- .../kafka/utils/Log4jControllerTest.scala | 43 ------------------- 3 files changed, 21 insertions(+), 46 deletions(-) delete mode 100644 core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala diff --git a/core/src/main/scala/kafka/utils/Log4jController.scala b/core/src/main/scala/kafka/utils/Log4jController.scala index d48c14f95e144..436985923bf58 100755 --- a/core/src/main/scala/kafka/utils/Log4jController.scala +++ b/core/src/main/scala/kafka/utils/Log4jController.scala @@ -34,7 +34,7 @@ object Log4jController { var level = logger.getLevel while (level == null) { val index = name.lastIndexOf(".") - if (index != -1) { + if (index > 0) { name = name.substring(0, index) val ancestor = existingLogger(name) if (ancestor != null) { diff --git a/core/src/test/scala/kafka/utils/LoggingTest.scala b/core/src/test/scala/kafka/utils/LoggingTest.scala index 7b36d12a46f19..734e305d3747c 100644 --- a/core/src/test/scala/kafka/utils/LoggingTest.scala +++ b/core/src/test/scala/kafka/utils/LoggingTest.scala @@ -18,10 +18,12 @@ package kafka.utils import java.lang.management.ManagementFactory -import javax.management.ObjectName -import org.junit.Test +import com.typesafe.scalalogging.Logger +import javax.management.ObjectName +import org.junit.{Assert, Test} import org.junit.Assert.{assertEquals, assertTrue} +import org.slf4j.LoggerFactory class LoggingTest extends Logging { @@ -66,4 +68,20 @@ class LoggingTest extends Logging { assertEquals(logging.getClass.getName, logging.log.underlying.getName) } + + @Test + def testLoggerLevelIsResolved(): Unit = { + val controller = new Log4jController() + val previousLevel = controller.getLogLevel("kafka") + try { + controller.setLogLevel("kafka", "TRACE") + Logger(LoggerFactory.getLogger("kafka.utils.Log4jControllerTest")).trace("test") + Assert.assertEquals("TRACE", controller.getLogLevel("kafka")) + Assert.assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) + Assert.assertTrue(controller.getLoggers.contains("kafka=TRACE")) + Assert.assertTrue(controller.getLoggers.contains("kafka.utils.Log4jControllerTest=TRACE")) + } finally { + controller.setLogLevel("kafka", previousLevel) + } + } } diff --git a/core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala b/core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala deleted file mode 100644 index 734e3c54bb76b..0000000000000 --- a/core/src/test/scala/unit/kafka/utils/Log4jControllerTest.scala +++ /dev/null @@ -1,43 +0,0 @@ -/* - * Licensed to the Apache Software Foundation (ASF) under one or more - * contributor license agreements. See the NOTICE file distributed with - * this work for additional information regarding copyright ownership. - * The ASF licenses this file to You under the Apache License, Version 2.0 - * (the "License"); you may not use this file except in compliance with - * the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -package kafka.utils - -import com.typesafe.scalalogging.Logger -import org.junit.{Assert, Test} -import org.slf4j.LoggerFactory - - -class Log4jControllerTest { - - @Test - def testLoggerLevelIsResolved(): Unit = { - val controller = new Log4jController() - val previousLevel = controller.getLogLevel("kafka") - try { - controller.setLogLevel("kafka", "TRACE") - Logger(LoggerFactory.getLogger("kafka.utils.Log4jControllerTest")).trace("test") - Assert.assertEquals("TRACE", controller.getLogLevel("kafka")) - Assert.assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) - Assert.assertTrue(controller.getLoggers.contains("kafka=TRACE")) - Assert.assertTrue(controller.getLoggers.contains("kafka.utils.Log4jControllerTest=TRACE")) - } finally { - controller.setLogLevel("kafka", previousLevel) - } - - } -} From 9fe8c465a8b0253237250930b59fff9eb5429b4b Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Thu, 17 Sep 2020 14:47:17 +0100 Subject: [PATCH 3/9] comment --- core/src/test/scala/kafka/utils/LoggingTest.scala | 2 ++ 1 file changed, 2 insertions(+) diff --git a/core/src/test/scala/kafka/utils/LoggingTest.scala b/core/src/test/scala/kafka/utils/LoggingTest.scala index 734e305d3747c..87b18180ed3cc 100644 --- a/core/src/test/scala/kafka/utils/LoggingTest.scala +++ b/core/src/test/scala/kafka/utils/LoggingTest.scala @@ -75,6 +75,8 @@ class LoggingTest extends Logging { val previousLevel = controller.getLogLevel("kafka") try { controller.setLogLevel("kafka", "TRACE") + // Do some logging so that the Logger is created within the hierarchy + // (until loggers are used only loggers in the config file exist) Logger(LoggerFactory.getLogger("kafka.utils.Log4jControllerTest")).trace("test") Assert.assertEquals("TRACE", controller.getLogLevel("kafka")) Assert.assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) From 814431e048668486ad145f6f92e30d31e54d6e55 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Thu, 17 Sep 2020 14:54:42 +0100 Subject: [PATCH 4/9] make private --- core/src/main/scala/kafka/utils/Log4jController.scala | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/src/main/scala/kafka/utils/Log4jController.scala b/core/src/main/scala/kafka/utils/Log4jController.scala index 436985923bf58..b9dc550ee202c 100755 --- a/core/src/main/scala/kafka/utils/Log4jController.scala +++ b/core/src/main/scala/kafka/utils/Log4jController.scala @@ -29,7 +29,7 @@ import scala.jdk.CollectionConverters._ object Log4jController { val ROOT_LOGGER = "root" - def resolveLevel(logger: Logger): String = { + private def resolveLevel(logger: Logger): String = { var name = logger.getName var level = logger.getLevel while (level == null) { From dbeead90e038f463445e84efd387aa083378d554 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Thu, 17 Sep 2020 14:59:02 +0100 Subject: [PATCH 5/9] Assert --- core/src/test/scala/kafka/utils/LoggingTest.scala | 10 +++++----- 1 file changed, 5 insertions(+), 5 deletions(-) diff --git a/core/src/test/scala/kafka/utils/LoggingTest.scala b/core/src/test/scala/kafka/utils/LoggingTest.scala index 87b18180ed3cc..6d782d8d2e6d3 100644 --- a/core/src/test/scala/kafka/utils/LoggingTest.scala +++ b/core/src/test/scala/kafka/utils/LoggingTest.scala @@ -21,7 +21,7 @@ import java.lang.management.ManagementFactory import com.typesafe.scalalogging.Logger import javax.management.ObjectName -import org.junit.{Assert, Test} +import org.junit.Test import org.junit.Assert.{assertEquals, assertTrue} import org.slf4j.LoggerFactory @@ -78,10 +78,10 @@ class LoggingTest extends Logging { // Do some logging so that the Logger is created within the hierarchy // (until loggers are used only loggers in the config file exist) Logger(LoggerFactory.getLogger("kafka.utils.Log4jControllerTest")).trace("test") - Assert.assertEquals("TRACE", controller.getLogLevel("kafka")) - Assert.assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) - Assert.assertTrue(controller.getLoggers.contains("kafka=TRACE")) - Assert.assertTrue(controller.getLoggers.contains("kafka.utils.Log4jControllerTest=TRACE")) + assertEquals("TRACE", controller.getLogLevel("kafka")) + assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) + assertTrue(controller.getLoggers.contains("kafka=TRACE")) + assertTrue(controller.getLoggers.contains("kafka.utils.Log4jControllerTest=TRACE")) } finally { controller.setLogLevel("kafka", previousLevel) } From 9110d76ec416907a3f75478d5d2b77777cc31f13 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Thu, 17 Sep 2020 18:17:44 +0100 Subject: [PATCH 6/9] Remove com.typesafe.scalalogging.Logger --- core/src/test/scala/kafka/utils/LoggingTest.scala | 3 +-- 1 file changed, 1 insertion(+), 2 deletions(-) diff --git a/core/src/test/scala/kafka/utils/LoggingTest.scala b/core/src/test/scala/kafka/utils/LoggingTest.scala index 6d782d8d2e6d3..e339b15593a89 100644 --- a/core/src/test/scala/kafka/utils/LoggingTest.scala +++ b/core/src/test/scala/kafka/utils/LoggingTest.scala @@ -19,7 +19,6 @@ package kafka.utils import java.lang.management.ManagementFactory -import com.typesafe.scalalogging.Logger import javax.management.ObjectName import org.junit.Test import org.junit.Assert.{assertEquals, assertTrue} @@ -77,7 +76,7 @@ class LoggingTest extends Logging { controller.setLogLevel("kafka", "TRACE") // Do some logging so that the Logger is created within the hierarchy // (until loggers are used only loggers in the config file exist) - Logger(LoggerFactory.getLogger("kafka.utils.Log4jControllerTest")).trace("test") + LoggerFactory.getLogger("kafka.utils.Log4jControllerTest").trace("test") assertEquals("TRACE", controller.getLogLevel("kafka")) assertEquals("TRACE", controller.getLogLevel("kafka.utils.Log4jControllerTest")) assertTrue(controller.getLoggers.contains("kafka=TRACE")) From 6310c039f94e10eb9f219acd16f946c27b4fa711 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Tue, 22 Sep 2020 10:55:23 +0100 Subject: [PATCH 7/9] Fix infinite loop --- core/src/main/scala/kafka/utils/Log4jController.scala | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/src/main/scala/kafka/utils/Log4jController.scala b/core/src/main/scala/kafka/utils/Log4jController.scala index b9dc550ee202c..a02fdb69e14d1 100755 --- a/core/src/main/scala/kafka/utils/Log4jController.scala +++ b/core/src/main/scala/kafka/utils/Log4jController.scala @@ -41,7 +41,7 @@ object Log4jController { level = ancestor.getLevel } } else { - existingLogger(ROOT_LOGGER).getLevel + level = existingLogger(ROOT_LOGGER).getLevel } } level.toString From 42ddf73d99da8f47489af13016172b3151eec618 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Tue, 22 Sep 2020 16:43:49 +0100 Subject: [PATCH 8/9] Fix test --- .../kafka/api/PlaintextAdminIntegrationTest.scala | 8 +++++--- 1 file changed, 5 insertions(+), 3 deletions(-) diff --git a/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala b/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala index ebe8ff27da20c..77d3e37183456 100644 --- a/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala +++ b/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala @@ -44,6 +44,7 @@ import org.apache.kafka.common.{ConsumerGroupState, ElectionType, TopicPartition import org.junit.Assert._ import org.junit.{After, Before, Ignore, Test} import org.scalatest.Assertions.intercept +import org.slf4j.LoggerFactory import scala.annotation.nowarn import scala.jdk.CollectionConverters._ @@ -2061,11 +2062,12 @@ class PlaintextAdminIntegrationTest extends BaseAdminIntegrationTest { @Test def testDescribeConfigsForLog4jLogLevels(): Unit = { client = Admin.create(createConfig) - + LoggerFactory.getLogger("kafka.cluster.Replica").trace("Message to create the logger") val loggerConfig = describeBrokerLoggers() - val rootLogLevel = loggerConfig.get(Log4jController.ROOT_LOGGER).value() + val kafkaLogLevel = loggerConfig.get("kafka").value() val logCleanerLogLevelConfig = loggerConfig.get("kafka.cluster.Replica") - assertEquals(rootLogLevel, logCleanerLogLevelConfig.value()) // we expect an undefined log level to be the same as the root logger + // we expect an undefined log level to be the same as its first ancestor logger + assertEquals(kafkaLogLevel, logCleanerLogLevelConfig.value()) assertEquals("kafka.cluster.Replica", logCleanerLogLevelConfig.name()) assertEquals(ConfigEntry.ConfigSource.DYNAMIC_BROKER_LOGGER_CONFIG, logCleanerLogLevelConfig.source()) assertEquals(false, logCleanerLogLevelConfig.isReadOnly) From a4ec8437a361a289bc2da2f15f44df1fa69595a1 Mon Sep 17 00:00:00 2001 From: Tom Bentley Date: Mon, 28 Sep 2020 16:41:17 +0100 Subject: [PATCH 9/9] Review comment --- .../integration/kafka/api/PlaintextAdminIntegrationTest.scala | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala b/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala index 77d3e37183456..1ea0c04d2f88e 100644 --- a/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala +++ b/core/src/test/scala/integration/kafka/api/PlaintextAdminIntegrationTest.scala @@ -2066,7 +2066,7 @@ class PlaintextAdminIntegrationTest extends BaseAdminIntegrationTest { val loggerConfig = describeBrokerLoggers() val kafkaLogLevel = loggerConfig.get("kafka").value() val logCleanerLogLevelConfig = loggerConfig.get("kafka.cluster.Replica") - // we expect an undefined log level to be the same as its first ancestor logger + // we expect the log level to be inherited from the first ancestor with a level configured assertEquals(kafkaLogLevel, logCleanerLogLevelConfig.value()) assertEquals("kafka.cluster.Replica", logCleanerLogLevelConfig.name()) assertEquals(ConfigEntry.ConfigSource.DYNAMIC_BROKER_LOGGER_CONFIG, logCleanerLogLevelConfig.source())