Enforce console logging for peon process (#12067)

Currently all Druid processes share the same log4j2 configuration file located in _common directory. Since peon processes are spawned by middle manager process, they derivate the environment variables from the middle manager. These variables include those in the log4j2.xml controlling to which file the logger writes the log.

But current task logging mechanism requires the peon processes to output the log to console so that the middle manager can redirect the console output to a file and upload this file to task log storage.

So, this PR imposes this requirement to peon processes, whatever the configuration is in the shared log4j2.xml, peon processes always write the log to console.
This commit is contained in:
Frank Chen 2022-05-16 17:37:21 +08:00 committed by GitHub
parent ff253fd8a3
commit c33ff1c745
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
5 changed files with 431 additions and 2 deletions

View File

@ -23,9 +23,12 @@ title: "Logging"
-->
Apache Druid processes will emit logs that are useful for debugging to the console. Druid processes also emit periodic metrics about their state. For more about metrics, see [Configuration](../configuration/index.md#enabling-metrics). Metric logs are printed to the console by default, and can be disabled with `-Ddruid.emitter.logging.logLevel=debug`.
Apache Druid processes will emit logs that are useful for debugging to log files.
These processes also emit periodic [metrics](../configuration/index.md#enabling-metrics) about their state.
Metric info logs can be disabled with `-Ddruid.emitter.logging.logLevel=debug`.
Druid uses [log4j2](http://logging.apache.org/log4j/2.x/) for logging. The default configuration file log4j2.xml ships with Druid under conf/druid/{config}/_common/log4j2.xml .
Druid uses [log4j2](http://logging.apache.org/log4j/2.x/) for logging.
The default configuration file log4j2.xml ships with Druid under conf/druid/{config}/_common/log4j2.xml .
By default, Druid uses `RollingRandomAccessFile` for rollover daily, and keeps log files up to 7 days.
If that's not suitable in your case, you could modify the log4j2.xml to meet your need.
@ -67,6 +70,15 @@ An example log4j2.xml file is shown below:
</Configuration>
```
> NOTE:
> Although the log4j configuration file is shared with Druid's peon processes,
> the appenders in this file DO NOT take effect for peon processes for they always output logs to console.
> And middle managers are responsible to redirect the console output to task log files.
>
> But the logging levels settings take effect for these peon processes
> which means you can still configure loggers at different logging level for peon processes in this file.
>
## How to change log directory
By default, Druid outputs the logs to a directory `log` under the directory where Druid is launched from.
For example, if Druid is started from its `bin` directory, there will be a subdirectory `log` generated under `bin` directory to hold the log files.

View File

@ -0,0 +1,152 @@
/*
* 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 org.apache.druid.indexing.common.tasklogs;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.Filter;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.appender.ConsoleAppender;
import org.apache.logging.log4j.core.config.AppenderRef;
import org.apache.logging.log4j.core.config.Configuration;
import org.apache.logging.log4j.core.config.ConfigurationFactory;
import org.apache.logging.log4j.core.config.ConfigurationSource;
import org.apache.logging.log4j.core.config.LoggerConfig;
import org.apache.logging.log4j.core.config.xml.XmlConfiguration;
import org.apache.logging.log4j.core.layout.PatternLayout;
import javax.annotation.Nullable;
import java.util.ArrayList;
import java.util.List;
import java.util.Map;
import java.util.stream.Collectors;
/**
* This class enforces console logging based on a user defined configuration.
* <p>
* For all loggers, this class ensure that only {@link ConsoleAppender} is applied for each of them.
* <p>
* The reason why this configuration is still based on a user's configuration is that
* user can still configure different logging levels for different loggers in that file.
*/
public class ConsoleLoggingEnforcementConfigurationFactory extends ConfigurationFactory
{
/**
* Valid file extensions for XML files.
*/
public static final String[] SUFFIXES = new String[]{".xml", "*"};
@Override
public String[] getSupportedTypes()
{
return SUFFIXES;
}
@Override
public Configuration getConfiguration(LoggerContext loggerContext, ConfigurationSource source)
{
return new OverrideConfiguration(loggerContext, source);
}
/**
* override the original configuration source to ensure only console appender is applied
*/
static class OverrideConfiguration extends XmlConfiguration
{
public OverrideConfiguration(final LoggerContext loggerContext, final ConfigurationSource configSource)
{
super(loggerContext, configSource);
}
@Override
protected void doConfigure()
{
super.doConfigure();
Appender consoleAppender = findConsoleAppender();
if (consoleAppender == null) {
// create a ConsoleAppender with default pattern if no console appender is configured in the configuration file
consoleAppender = ConsoleAppender.newBuilder()
.setName("_Injected_Console_Appender_")
.setLayout(PatternLayout.newBuilder()
.withPattern("%d{ISO8601} %p [%t] %c - %m%n")
.build())
.build();
}
List<LoggerConfig> loggerConfigList = new ArrayList<>();
loggerConfigList.add(this.getRootLogger());
loggerConfigList.addAll(this.getLoggers().values());
//
// For all logger configuration, check if its appender is ConsoleAppender.
// If not, replace it's appender to ConsoleAppender.
//
for (LoggerConfig logger : loggerConfigList) {
applyConsoleAppender(logger, consoleAppender);
}
}
@Nullable
private Appender findConsoleAppender()
{
for (Map.Entry<String, Appender> entry : this.getAppenders().entrySet()) {
Appender appender = entry.getValue();
if (appender instanceof ConsoleAppender) {
return appender;
}
}
return null;
}
/**
* remove all appenders from a logger and append a console appender to it
*/
private void applyConsoleAppender(LoggerConfig logger, Appender consoleAppender)
{
if (logger.getAppenderRefs().size() == 1
&& logger.getAppenderRefs().get(0).getRef().equals(consoleAppender.getName())) {
// this logger has only one appender and its the console appender
return;
}
Level level = Level.INFO;
Filter filter = null;
if (!logger.getAppenderRefs().isEmpty()) {
AppenderRef appenderRef = logger.getAppenderRefs().get(0);
// clear all appenders first
List<String> appendRefs = logger.getAppenderRefs()
.stream()
.map(AppenderRef::getRef)
.collect(Collectors.toList());
appendRefs.forEach(logger::removeAppender);
// use the first appender's definition
level = appenderRef.getLevel();
filter = appenderRef.getFilter();
}
// add ConsoleAppender to this logger
logger.addAppender(consoleAppender, level, filter);
}
}
}

View File

@ -47,6 +47,7 @@ import org.apache.druid.indexer.TaskLocation;
import org.apache.druid.indexer.TaskStatus;
import org.apache.druid.indexing.common.config.TaskConfig;
import org.apache.druid.indexing.common.task.Task;
import org.apache.druid.indexing.common.tasklogs.ConsoleLoggingEnforcementConfigurationFactory;
import org.apache.druid.indexing.common.tasklogs.LogUtils;
import org.apache.druid.indexing.overlord.autoscaling.ScalingStats;
import org.apache.druid.indexing.overlord.config.ForkingTaskRunnerConfig;
@ -339,6 +340,7 @@ public class ForkingTaskRunner
command.add(
StringUtils.format("-Ddruid.task.executor.enableTlsPort=%s", node.isEnableTlsPort())
);
command.add(StringUtils.format("-Dlog4j2.configurationFactory=%s", ConsoleLoggingEnforcementConfigurationFactory.class.getName()));
// These are not enabled per default to allow the user to either set or not set them
// Users are highly suggested to be set in druid.indexer.runner.javaOpts

View File

@ -0,0 +1,262 @@
/*
* 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 org.apache.druid.indexing.common.tasklogs;
import org.apache.logging.log4j.Level;
import org.apache.logging.log4j.LogManager;
import org.apache.logging.log4j.core.Logger;
import org.apache.logging.log4j.core.LoggerContext;
import org.apache.logging.log4j.core.appender.ConsoleAppender;
import org.apache.logging.log4j.core.config.ConfigurationSource;
import org.apache.logging.log4j.core.layout.PatternLayout;
import org.junit.Assert;
import org.junit.Test;
import java.io.ByteArrayInputStream;
import java.io.IOException;
import java.nio.charset.StandardCharsets;
public class ConsoleLoggingEnforcementTest
{
private static final String ROOT = "ROOT";
@Test
public void testConsoleConfiguration() throws IOException
{
// the loggers in configuration already uses Console appender
String log4jConfiguration = "<Configuration status=\"WARN\">\n"
+ " <Appenders>\n"
+ " <Console name=\"Console\" target=\"SYSTEM_OUT\">\n"
+ " <PatternLayout pattern=\"%m\"/>\n"
+ " </Console>\n"
+ " </Appenders>\n"
+ " <Loggers>\n"
+ " <Root level=\"info\">\n"
+ " <AppenderRef ref=\"Console\"/>\n"
+ " </Root>\n"
+ " <Logger level=\"debug\" name=\"org.apache.druid\" additivity=\"false\">\n"
+ " <AppenderRef ref=\"Console\"/>\n"
+ " </Logger>\n"
+ " </Loggers>\n"
+ "</Configuration>";
LoggerContext context = enforceConsoleLogger(log4jConfiguration);
// this logger is not defined in configuration, it derivates ROOT logger configuration
assertHasOnlyOneConsoleAppender(getLogger(context, "name_not_in_config"), Level.INFO);
assertHasOnlyOneConsoleAppender(getLogger(context, "org.apache.druid"), Level.DEBUG);
assertHasOnlyOneConsoleAppender(getLogger(context, ROOT), Level.INFO);
PatternLayout layout = (PatternLayout) getLogger(context, "anything").getAppenders()
.values()
.stream()
.findFirst()
.get()
.getLayout();
Assert.assertEquals("%m", layout.getConversionPattern());
}
@Test
public void testNoConsoleAppender() throws IOException
{
// this logger configuration has no console logger appender, a default one will be created
String log4jConfiguration = "<Configuration status=\"WARN\">\n"
+ " <Appenders>\n"
+ " <RollingRandomAccessFile name=\"FileAppender\" fileName=\"a.log\">\n"
+ " <PatternLayout pattern=\"%d{ISO8601} %p [%t] %c - %m%n\"/>\n"
+ " </RollingRandomAccessFile>\n"
+ " </Appenders>\n"
+ " <Loggers>\n"
+ " <Root level=\"info\">\n"
+ " <AppenderRef ref=\"FileAppender\"/>\n"
+ " </Root>\n"
+ " </Loggers>\n"
+ "</Configuration>";
LoggerContext context = enforceConsoleLogger(log4jConfiguration);
// this logger is not defined in configuration, it derivates ROOT logger configuration
assertHasOnlyOneConsoleAppender(getLogger(context, "name_not_in_config"), Level.INFO);
assertHasOnlyOneConsoleAppender(getLogger(context, ROOT), Level.INFO);
String defaultPattern = "%d{ISO8601} %p [%t] %c - %m%n";
PatternLayout layout = (PatternLayout) getLogger(context, "anything").getAppenders()
.values()
.stream()
.findFirst()
.get()
.getLayout();
Assert.assertEquals(defaultPattern, layout.getConversionPattern());
}
@Test
public void testHasConsoleAppenderButNotUsed() throws IOException
{
// this logger has a console appender, but is not referenced by any logger
String log4jConfiguration = "<Configuration status=\"WARN\">\n"
+ " <Appenders>\n"
+ " <Console name=\"Console\" target=\"SYSTEM_OUT\">\n"
+ " <PatternLayout pattern=\"%m\"/>\n"
+ " </Console>\n"
+ " <RollingRandomAccessFile name=\"FileAppender\" fileName=\"a.log\">\n"
+ " <PatternLayout pattern=\"%d{ISO8601} %p [%t] %c - %m%n\"/>\n"
+ " </RollingRandomAccessFile>\n"
+ " </Appenders>\n"
+ " <Loggers>\n"
+ " <Root level=\"info\">\n"
+ " <AppenderRef ref=\"FileAppender\"/>\n"
+ " </Root>\n"
+ " </Loggers>\n"
+ "</Configuration>";
LoggerContext context = enforceConsoleLogger(log4jConfiguration);
// this logger is not defined in configuration, it derivates ROOT logger configuration
assertHasOnlyOneConsoleAppender(getLogger(context, "name_not_in_config"), Level.INFO);
assertHasOnlyOneConsoleAppender(getLogger(context, ROOT), Level.INFO);
// the ConsoleAppender should be exactly the same as it's in the configuration
PatternLayout layout = (PatternLayout) getLogger(context, "anything").getAppenders()
.values()
.stream()
.findFirst()
.get()
.getLayout();
Assert.assertEquals("%m", layout.getConversionPattern());
}
@Test
public void testMultipleAppender() throws IOException
{
// this logger configuration contains multiple appenders and appender refers
String log4jConfiguration = "<Configuration status=\"WARN\">\n"
+ " <Appenders>\n"
+ " <Console name=\"Console\" target=\"SYSTEM_OUT\">\n"
+ " <PatternLayout pattern=\"%m\"/>\n"
+ " </Console>\n"
+ " <RollingRandomAccessFile name=\"FileAppender\" fileName=\"a.log\">\n"
+ " <PatternLayout pattern=\"%d{ISO8601} %p [%t] %c - %m%n\"/>\n"
+ " </RollingRandomAccessFile>\n"
+ " </Appenders>\n"
+ " <Loggers>\n"
+ " <Root level=\"info\">\n"
+ " <AppenderRef ref=\"FileAppender\"/>\n"
+ " <AppenderRef ref=\"Console\"/>\n"
+ " </Root>\n"
+ " <Logger level=\"debug\" name=\"org.apache.druid\" additivity=\"false\">\n"
+ " <AppenderRef ref=\"FileAppender\"/>\n"
+ " <AppenderRef ref=\"Console\"/>\n"
+ " </Logger>\n"
+ " </Loggers>\n"
+ "</Configuration>";
LoggerContext context = enforceConsoleLogger(log4jConfiguration);
// this logger is not defined in configuration, it derivates ROOT logger configuration
assertHasOnlyOneConsoleAppender(getLogger(context, "name_not_in_config"), Level.INFO);
assertHasOnlyOneConsoleAppender(getLogger(context, "org.apache.druid"), Level.DEBUG);
assertHasOnlyOneConsoleAppender(getLogger(context, ROOT), Level.INFO);
// the ConsoleAppender should be exactly the same as it's in the configuration
PatternLayout layout = (PatternLayout) getLogger(context, "anything").getAppenders()
.values()
.stream()
.findFirst()
.get()
.getLayout();
Assert.assertEquals("%m", layout.getConversionPattern());
}
@Test
public void testEmptyAppender() throws IOException
{
// the ROOT logger has no appender in this configuration
String log4jConfiguration = "<Configuration status=\"WARN\">\n"
+ " <Appenders>\n"
+ " <Console name=\"Console\" target=\"SYSTEM_OUT\">\n"
+ " <PatternLayout pattern=\"%m\"/>\n"
+ " </Console>\n"
+ " <RollingRandomAccessFile name=\"FileAppender\" fileName=\"a.log\">\n"
+ " <PatternLayout pattern=\"%d{ISO8601} %p [%t] %c - %m%n\"/>\n"
+ " </RollingRandomAccessFile>\n"
+ " </Appenders>\n"
+ " <Loggers>\n"
+ " <Root level=\"info\">\n"
+ " </Root>\n"
+ " <Logger level=\"debug\" name=\"org.apache.druid\" additivity=\"false\">\n"
+ " <AppenderRef ref=\"FileAppender\"/>\n"
+ " <AppenderRef ref=\"Console\"/>\n"
+ " </Logger>\n"
+ " </Loggers>\n"
+ "</Configuration>";
LoggerContext context = enforceConsoleLogger(log4jConfiguration);
// this logger is not defined in configuration, it derivates ROOT logger configuration
assertHasOnlyOneConsoleAppender(getLogger(context, "name_not_in_config"), Level.INFO);
assertHasOnlyOneConsoleAppender(getLogger(context, "org.apache.druid"), Level.DEBUG);
assertHasOnlyOneConsoleAppender(getLogger(context, ROOT), Level.INFO);
// the ConsoleAppender should be exactly the same as it's in the configuration
PatternLayout layout = (PatternLayout) getLogger(context, "anything").getAppenders()
.values()
.stream()
.findFirst()
.get()
.getLayout();
Assert.assertEquals("%m", layout.getConversionPattern());
}
private LoggerContext enforceConsoleLogger(String configuration) throws IOException
{
LoggerContext context = new LoggerContext("test");
ConfigurationSource source = new ConfigurationSource(new ByteArrayInputStream(configuration.getBytes(StandardCharsets.UTF_8)));
// enforce the console logging for current configuration
context.reconfigure(new ConsoleLoggingEnforcementConfigurationFactory().getConfiguration(context, source));
return context;
}
private void assertHasOnlyOneConsoleAppender(Logger logger, Level level)
{
// there's only one appender
Assert.assertEquals(1, logger.getAppenders().size());
// and this appender must be ConsoleAppender
Assert.assertEquals(ConsoleAppender.class, logger.getAppenders()
.values()
.stream()
.findFirst()
.get()
.getClass());
if (level != null) {
Assert.assertEquals(level, logger.getLevel());
}
}
private Logger getLogger(LoggerContext context, String name)
{
final String key = ROOT.equals(name) ? LogManager.ROOT_LOGGER_NAME : name;
return context.getLogger(key);
}
}

View File

@ -571,6 +571,7 @@ IEC
100x
- ../docs/configuration/logging.md
_common
appenders
- ../docs/dependencies/deep-storage.md
druid-hdfs-storage
druid-s3-extensions