Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

HBASE-26947 Implement a special TestAppender to limit the size of tes… #4340

Merged
merged 1 commit into from
Apr 21, 2022
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
@@ -0,0 +1,166 @@
/*
* 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.hadoop.hbase.logging;

import java.io.Serializable;
import java.nio.charset.StandardCharsets;
import java.util.concurrent.atomic.AtomicBoolean;
import java.util.concurrent.atomic.AtomicLong;
import org.apache.logging.log4j.core.Appender;
import org.apache.logging.log4j.core.Core;
import org.apache.logging.log4j.core.Filter;
import org.apache.logging.log4j.core.Layout;
import org.apache.logging.log4j.core.LogEvent;
import org.apache.logging.log4j.core.appender.AbstractOutputStreamAppender;
import org.apache.logging.log4j.core.appender.ManagerFactory;
import org.apache.logging.log4j.core.appender.OutputStreamManager;
import org.apache.logging.log4j.core.appender.rolling.FileSize;
import org.apache.logging.log4j.core.config.Property;
import org.apache.logging.log4j.core.config.plugins.Plugin;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderAttribute;
import org.apache.logging.log4j.core.config.plugins.PluginBuilderFactory;
import org.apache.logging.log4j.core.config.plugins.validation.constraints.Required;

/**
* Log4j2 appender to be used when running UTs.
* <p/>
* The main point here is to limit the total output size to prevent eating all the space of our ci
* system when something wrong in our code.
* <p/>
* See HBASE-26947 for more details.
*/
@Plugin(name = HBaseTestAppender.PLUGIN_NAME, category = Core.CATEGORY_NAME,
elementType = Appender.ELEMENT_TYPE, printObject = true)
public final class HBaseTestAppender extends AbstractOutputStreamAppender<OutputStreamManager> {

public static final String PLUGIN_NAME = "HBaseTest";
private static final HBaseTestManagerFactory FACTORY = new HBaseTestManagerFactory();

public static class Builder<B extends Builder<B>> extends AbstractOutputStreamAppender.Builder<B>
implements org.apache.logging.log4j.core.util.Builder<HBaseTestAppender> {

@PluginBuilderAttribute
@Required
private Target target;

@PluginBuilderAttribute
@Required
private String maxSize;

public B setTarget(Target target) {
this.target = target;
return asBuilder();
}

public B setMaxSize(String maxSize) {
this.maxSize = maxSize;
return asBuilder();
}

@Override
public HBaseTestAppender build() {
long size = FileSize.parse(maxSize, -1);
if (size <= 0) {
LOGGER.error("Invalid maxSize {}", size);
}
Layout<? extends Serializable> layout = getOrCreateLayout(StandardCharsets.UTF_8);
OutputStreamManager manager =
OutputStreamManager.getManager(target.name(), FACTORY, new FactoryData(target, layout));
return new HBaseTestAppender(getName(),
layout,
getFilter(),
isIgnoreExceptions(),
isImmediateFlush(),
getPropertyArray(),
manager,
size);
}
}

/**
* Data to pass to factory method.Unable to instantiate
*/
private static class FactoryData {
private final Target target;
private final Layout<? extends Serializable> layout;

public FactoryData(Target target, Layout<? extends Serializable> layout) {
this.target = target;
this.layout = layout;
}
}

/**
* Factory to create the Appender.
*/
private static class HBaseTestManagerFactory
implements ManagerFactory<HBaseTestOutputStreamManager, FactoryData> {

/**
* Create an OutputStreamManager.
* @param name The name of the entity to manage.
* @param data The data required to create the entity.
* @return The OutputStreamManager
*/
@Override
public HBaseTestOutputStreamManager createManager(final String name, final FactoryData data) {
return new HBaseTestOutputStreamManager(data.target, data.layout);
}
}

@PluginBuilderFactory
public static <B extends Builder<B>> B newBuilder() {
return new Builder<B>().asBuilder();
}

private final long maxSize;

private final AtomicLong size = new AtomicLong(0);

private final AtomicBoolean stop = new AtomicBoolean(false);

private HBaseTestAppender(String name, Layout<? extends Serializable> layout, Filter filter,
boolean ignoreExceptions, boolean immediateFlush, Property[] properties,
OutputStreamManager manager, long maxSize) {
super(name, layout, filter, ignoreExceptions, immediateFlush, properties, manager);
this.maxSize = maxSize;
}

@Override
public void append(LogEvent event) {
if (stop.get()) {
return;
}
// for accounting, here we always convert the event to byte array first
// this will effect performance a bit but it is OK since this is for UT only
byte[] bytes = getLayout().toByteArray(event);
if (bytes == null || bytes.length == 0) {
return;
}
long sizeAfterAppend = size.addAndGet(bytes.length);
if (sizeAfterAppend >= maxSize) {
// stop logging if the log size exceeded the limit
if (stop.compareAndSet(false, true)) {
LOGGER.error("Log size exceeded the limit {}, will stop logging to prevent eating"
+ " too much disk space", maxSize);
}
return;
}
super.append(event);
}
}
Comment on lines +145 to +166
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Can we abort the test in this case rather than having the test continue without logs?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Throw an Error out maybe? In general I'm not sure if this could work, because it could be a thread other than the main thread which enters here and exceeds the limit, fail this thread can not abort the test?

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've done this in another logging framework but not log4j2. This is appending events to a single log line, building it up, is that correct? I think it's fine if we truncate log lines at a certain length, no need to error or whatever, just terminate the message. I'm a little surprised that this not available to use as a configuration option.

In fact, the pattern layout does support it. https://stackoverflow.com/questions/27502536/limit-max-message-size-in-log4j2-pattern

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Or maybe it's one log line per Event object. I see.

I'm fine with this. I think it's better to let the test finish than to kill the build when the log limit is exceeded. In my experience, it's relatively rare that logs from CI are used by anyone. This strategy for logging once max log volume for a test is exceeded is fine by me.

What happens when the appender is for some class that's used over and over in test? There's no way to reset this counter to be a per-test-class accumulator, right?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do not use reuseForks so this is not a problem. Every test will have its own process.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

We do not use reuseForks so this is not a problem. Every test will have its own process.

In that case, it would be better to add an assertion that this invariant is held. With that, I'm +1.

Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

If asserting on the invariant is impossible, I'm okay with adding a comment here so that at least a future change to test execution will have a breadcrumb to follow.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I do not know how to add the assertion in code to test a pom config :(
But anyway, we could add a comment about this, both in the appender code and also in pom.

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I've tried to use RunListener to reset the counter when starting a new test but failed... The behavior is really confusing, I mean when will the methods in the RunListener be called, and when will the surefire plugin rotate the output tests when reuseForks is true...

So I just add some comments to pom.xml to say that why we can not set reuseForks to true.

PTAL. @ndimiduk

Original file line number Diff line number Diff line change
@@ -0,0 +1,27 @@
/*
* 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.hadoop.hbase.logging;

public class HBaseTestOutputStreamManager
extends org.apache.logging.log4j.core.appender.OutputStreamManager {

public HBaseTestOutputStreamManager(Target target,
org.apache.logging.log4j.core.Layout<?> layout) {
super(target.output(), target.name(), layout, true);
}
}
Original file line number Diff line number Diff line change
@@ -0,0 +1,35 @@
/*
* 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.hadoop.hbase.logging;

import java.io.PrintStream;

public enum Target {
SYSTEM_OUT(System.out),
SYSTEM_ERR(System.err);

private final PrintStream output;

private Target(PrintStream output) {
this.output = output;
}

public PrintStream output() {
return output;
}
}
4 changes: 3 additions & 1 deletion hbase-logging/src/test/resources/log4j2.properties
Original file line number Diff line number Diff line change
Expand Up @@ -19,10 +19,12 @@
status = debug
dest = err
name = PropertiesConfig
packages = org.apache.hadoop.hbase.logging

appender.console.type = Console
appender.console.type = HBaseTest
appender.console.target = SYSTEM_ERR
appender.console.name = Console
appender.console.maxSize = 1G
appender.console.layout.type = PatternLayout
appender.console.layout.pattern = %d{ISO8601} %-5p [%t] %C{2}(%L): %m%n

Expand Down
12 changes: 12 additions & 0 deletions pom.xml
Original file line number Diff line number Diff line change
Expand Up @@ -1781,6 +1781,10 @@
<trimStackTrace>false</trimStackTrace>
<skip>${surefire.skipFirstPart}</skip>
<forkCount>${surefire.firstPartForkCount}</forkCount>
<!--
The counter in HBaseTestAppender will be broken if we set reuseForks to true, be
careful when you want to change this value. See HBASE-26947 for more details.
-->
<reuseForks>false</reuseForks>
<reportsDirectory>${surefire.reportsDirectory}</reportsDirectory>
<tempDir>${surefire.tempDir}</tempDir>
Expand Down Expand Up @@ -1825,6 +1829,10 @@
<configuration>
<skip>${surefire.skipSecondPart}</skip>
<testFailureIgnore>${surefire.testFailureIgnore}</testFailureIgnore>
<!--
The counter in HBaseTestAppender will be broken if we set reuseForks to true, be
careful when you want to change this value. See HBASE-26947 for more details.
-->
<reuseForks>false</reuseForks>
<forkCount>${surefire.secondPartForkCount}</forkCount>
<groups>${surefire.secondPartGroups}</groups>
Expand Down Expand Up @@ -2331,6 +2339,10 @@
<bannedImport>org.apache.log4j.**</bannedImport>
<bannedImport>org.apache.logging.log4j.**</bannedImport>
</bannedImports>
<exclusions>
<!-- Exclude this one as it is a log4j2 appender implementation -->
<exclusion>org.apache.hadoop.hbase.logging.HBaseTestAppender</exclusion>
</exclusions>
</restrictImports>
<restrictImports implementation="de.skuzzle.enforcer.restrictimports.rule.RestrictImports">
<includeTestCode>false</includeTestCode>
Expand Down