HADOOP-19272. S3A: AWS SDK 2.25.53 warnings logged by transfer manager (#7048)

Disables all logging below error in the AWS SDK Transfer Manager.

This is done in ClientManagerImpl construction so is automatically done
during S3A FS initialization.

ITests verify that
* It is possible to restore the warning log. This verifies the validity of
  the test suite, and will identify when an SDK update fixes this regression.
* Constructing an S3A FS instance will disable the logging.

The log manipulation code is lifted from Cloudstore, where it was used to
dynamically enable logging. It uses reflection to load the Log4J binding;
all uses of the API catch and swallow exceptions.
This is needed to avoid failures when running against different log backends

This is an emergency fix -we could come up with a better design for
the reflection based code using the new DynMethods classes.
But this is based on working code, which is always good.

Contributed by Steve Loughran
This commit is contained in:
Steve Loughran 2024-09-19 13:50:06 +01:00 committed by GitHub
parent d1311e52f7
commit ee2e5ac4e4
No known key found for this signature in database
GPG Key ID: B5690EEEBB952194
8 changed files with 707 additions and 0 deletions

View File

@ -0,0 +1,59 @@
/*
* 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.fs.s3a.impl;
import org.apache.hadoop.classification.VisibleForTesting;
import org.apache.hadoop.fs.s3a.impl.logging.LogControl;
import org.apache.hadoop.fs.s3a.impl.logging.LogControllerFactory;
/**
* This class exists to support workarounds for parts of the AWS SDK
* which have caused problems.
*/
public final class AwsSdkWorkarounds {
/**
* Transfer manager log name. See HADOOP-19272.
* {@value}.
*/
public static final String TRANSFER_MANAGER =
"software.amazon.awssdk.transfer.s3.S3TransferManager";
private AwsSdkWorkarounds() {
}
/**
* Prepare logging before creating AWS clients.
* @return true if the log tuning operation took place.
*/
public static boolean prepareLogging() {
return LogControllerFactory.createController().
setLogLevel(TRANSFER_MANAGER, LogControl.LogLevel.ERROR);
}
/**
* Restore all noisy logs to INFO.
* @return true if the restoration operation took place.
*/
@VisibleForTesting
static boolean restoreNoisyLogging() {
return LogControllerFactory.createController().
setLogLevel(TRANSFER_MANAGER, LogControl.LogLevel.INFO);
}
}

View File

@ -90,7 +90,10 @@ public class ClientManagerImpl implements ClientManager {
/**
* Constructor.
* <p>
* This does not create any clients.
* <p>
* It does disable noisy logging from the S3 Transfer Manager.
* @param clientFactory client factory to invoke
* @param clientCreationParameters creation parameters.
* @param durationTrackerFactory duration tracker.
@ -105,6 +108,9 @@ public ClientManagerImpl(
this.s3Client = new LazyAutoCloseableReference<>(createS3Client());
this.s3AsyncClient = new LazyAutoCloseableReference<>(createAyncClient());
this.transferManager = new LazyAutoCloseableReference<>(createTransferManager());
// fix up SDK logging.
AwsSdkWorkarounds.prepareLogging();
}
/**

View File

@ -0,0 +1,52 @@
/*
* 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.fs.s3a.impl.logging;
import org.apache.log4j.Level;
import org.apache.log4j.Logger;
/**
* Something to control logging levels in Log4j.
* <p>
* Package private to avoid any direct instantiation.
* <p>
* Important: this must never be instantiated exception through
* reflection code which can catch and swallow exceptions related
* to not finding Log4J on the classpath.
* The Hadoop libraries can and are used with other logging
* back ends and we MUST NOT break that.
*/
class Log4JController extends LogControl {
/**
* Set the log4J level, ignoring all exceptions raised.
* {@inheritDoc}
*/
@Override
protected boolean setLevel(final String logName, final LogLevel level) {
try {
Logger logger = Logger.getLogger(logName);
logger.setLevel(Level.toLevel(level.getLog4Jname()));
return true;
} catch (Exception ignored) {
// ignored.
return false;
}
}
}

View File

@ -0,0 +1,92 @@
/*
* 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.fs.s3a.impl.logging;
/**
* class to assist reflection-based control of logger back ends.
* <p>
* An instance of LogControl is able to control the log levels of
* loggers for log libraries such as Log4j, yet can be created in
* code designed to support multiple back end loggers behind
* SLF4J.
*/
public abstract class LogControl {
/**
* Enumeration of log levels.
* <p>
* The list is in descending order.
*/
public enum LogLevel {
ALL("ALL"),
FATAL("FATAL"),
ERROR("ERROR"),
WARN("WARN"),
INFO("INFO"),
DEBUG("DEBUG"),
TRACE("TRACE"),
OFF("OFF");
/**
* Level name as used in Log4J.
*/
private final String log4Jname;
LogLevel(final String log4Jname) {
this.log4Jname = log4Jname;
}
/**
* Get the log4j name of this level.
* @return the log name for use in configuring Log4J.
*/
public String getLog4Jname() {
return log4Jname;
}
}
/**
* Sets a log level for a class/package.
* @param log log to set
* @param level level to set
* @return true if the log was set
*/
public final boolean setLogLevel(String log, LogLevel level) {
try {
return setLevel(log, level);
} catch (Exception ignored) {
// ignored.
return false;
}
}
/**
* Sets a log level for a class/package.
* Exceptions may be raised; they will be caught in
* {@link #setLogLevel(String, LogLevel)} and ignored.
* @param log log to set
* @param level level to set
* @return true if the log was set
* @throws Exception any problem loading/updating the log
*/
protected abstract boolean setLevel(String log, LogLevel level) throws Exception;
}

View File

@ -0,0 +1,98 @@
/*
* 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.fs.s3a.impl.logging;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.apache.hadoop.fs.store.LogExactlyOnce;
/**
* Factory for creating controllers.
* <p>
* It currently only supports Log4J as a back end.
*/
public final class LogControllerFactory {
private static final Logger LOG = LoggerFactory.getLogger(LogControllerFactory.class);
/**
* Log once: when there are logging issues, logging lots just
* makes it worse.
*/
private static final LogExactlyOnce LOG_ONCE = new LogExactlyOnce(LOG);
/**
* Class name of log controller implementation to be loaded
* through reflection.
* {@value}.
*/
private static final String LOG4J_CONTROLLER =
"org.apache.hadoop.fs.s3a.impl.logging.Log4JController";
private LogControllerFactory() {
}
/**
* Create a controller. Failure to load is logged at debug
* and null is returned.
* @param classname name of controller to load and create.
* @return the instantiated controller or null if it failed to load
*/
public static LogControl createController(String classname) {
try {
Class<?> clazz = Class.forName(classname);
return (LogControl) clazz.newInstance();
} catch (Exception e) {
LOG_ONCE.debug("Failed to create controller {}: {}", classname, e, e);
return null;
}
}
/**
* Create a Log4J controller.
* @return the instantiated controller or null if the class can't be instantiated.
*/
public static LogControl createLog4JController() {
return createController(LOG4J_CONTROLLER);
}
/**
* Create a controller, Log4j or falling back to a stub implementation.
* @return the instantiated controller or empty() if the class can't be instantiated.
*/
public static LogControl createController() {
final LogControl controller = createLog4JController();
return controller != null
? controller
: new StubLogControl();
}
/**
* Stub controller which always reports false.
*/
private static final class StubLogControl extends LogControl {
@Override
protected boolean setLevel(final String log, final LogLevel level) {
return false;
}
}
}

View File

@ -0,0 +1,26 @@
/*
* 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.
*/
/**
* This package contains reflection-based code to manipulate logging
* levels in external libraries.
*/
@InterfaceAudience.Private
package org.apache.hadoop.fs.s3a.impl.logging;
import org.apache.hadoop.classification.InterfaceAudience;

View File

@ -0,0 +1,160 @@
/*
* 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.fs.s3a.impl;
import java.io.IOException;
import org.assertj.core.api.Assertions;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.apache.hadoop.fs.s3a.AbstractS3ATestBase;
import org.apache.hadoop.fs.s3a.S3AFileSystem;
import org.apache.hadoop.test.GenericTestUtils;
import static org.apache.hadoop.test.GenericTestUtils.LogCapturer.captureLogs;
/**
* Verify that noisy transfer manager logs are turned off.
* <p>
* This is done by creating new FS instances and then
* requesting an on-demand transfer manager from the store.
* As this is only done once per FS instance, a new FS is
* required per test case.
*/
public class ITestAwsSdkWorkarounds extends AbstractS3ATestBase {
/**
* Test logger.
*/
private static final Logger LOG =
LoggerFactory.getLogger(ITestAwsSdkWorkarounds.class);
/**
* Transfer Manager log.
*/
private static final Logger XFER_LOG =
LoggerFactory.getLogger(AwsSdkWorkarounds.TRANSFER_MANAGER);
/**
* This is the string which keeps being printed.
* {@value}.
*/
private static final String FORBIDDEN =
"The provided S3AsyncClient is an instance of MultipartS3AsyncClient";
/**
* Marginal test run speedup by skipping needless test dir cleanup.
* @throws IOException failure
*/
@Override
protected void deleteTestDirInTeardown() throws IOException {
/* no-op */
}
/**
* Test instantiation with logging disabled.
*/
@Test
public void testQuietLogging() throws Throwable {
// simulate the base state of logging
noisyLogging();
// creating a new FS switches to quiet logging
try (S3AFileSystem newFs = newFileSystem()) {
String output = createAndLogTransferManager(newFs);
Assertions.assertThat(output)
.describedAs("LOG output")
.doesNotContain(FORBIDDEN);
}
}
/**
* Test instantiation with logging disabled.
*/
@Test
public void testNoisyLogging() throws Throwable {
try (S3AFileSystem newFs = newFileSystem()) {
noisyLogging();
String output = createAndLogTransferManager(newFs);
Assertions.assertThat(output)
.describedAs("LOG output does not contain the forbidden text."
+ " Has the SDK been fixed?")
.contains(FORBIDDEN);
}
}
/**
* Create a new filesystem using the configuration
* of the base test fs.
* @return the new FS.
* @throws IOException failure.
*/
private S3AFileSystem newFileSystem() throws IOException {
S3AFileSystem newFs = new S3AFileSystem();
try {
newFs.initialize(getFileSystem().getUri(), getFileSystem().getConf());
return newFs;
} catch (IOException e) {
newFs.close();
throw e;
}
}
/**
* Instantiate the transfer manager, if one is not already
* created for this FS instance.
* <p>
* Does not create one if it has already been called on this fs.
* @param fs filesystem.
* @return the log for the creation.
* @throws IOException failure to instantiate.
*/
private String createAndLogTransferManager(final S3AFileSystem fs)
throws IOException {
LOG.info("====== Creating transfer manager =====");
GenericTestUtils.LogCapturer capturer = captureXferManagerLogs();
try {
fs.getS3AInternals().getStore()
.getOrCreateTransferManager();
LOG.info("====== Created transfer manager ======");
return capturer.getOutput();
} finally {
capturer.stopCapturing();
}
}
/**
* turn on noisy logging.
*/
private static void noisyLogging() {
Assertions.assertThat(AwsSdkWorkarounds.restoreNoisyLogging())
.describedAs("Enabled Log4J logging")
.isTrue();
}
/**
* Start capturing the logs.
* Stop this afterwards.
* @return a capturer.
*/
private GenericTestUtils.LogCapturer captureXferManagerLogs() {
return captureLogs(XFER_LOG);
}
}

View File

@ -0,0 +1,214 @@
/*
* 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.fs.s3a.impl.logging;
import org.assertj.core.api.AbstractStringAssert;
import org.assertj.core.api.Assertions;
import org.junit.After;
import org.junit.Before;
import org.junit.Test;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.apache.hadoop.classification.VisibleForTesting;
import org.apache.hadoop.test.AbstractHadoopTestBase;
import org.apache.hadoop.test.GenericTestUtils;
import static java.util.Objects.requireNonNull;
import static org.apache.hadoop.fs.s3a.impl.logging.LogControllerFactory.createController;
import static org.apache.hadoop.fs.s3a.impl.logging.LogControllerFactory.createLog4JController;
import static org.apache.hadoop.test.GenericTestUtils.LogCapturer.captureLogs;
import static org.apache.hadoop.test.LambdaTestUtils.intercept;
/**
* Unit test for log controller factory.
*/
public class TestLogControllerFactory extends AbstractHadoopTestBase {
private static final Logger LOG =
LoggerFactory.getLogger(TestLogControllerFactory.class);
/**
* Classname of this class.
*/
public static final String CLASSNAME =
"org.apache.hadoop.fs.s3a.impl.logging.TestLogControllerFactory";
public static final String DEBUG = "Debug Message";
public static final String INFO = "Info Message";
public static final String WARN = "Warn Message";
public static final String ERROR = "Error Message";
public static final String FATAL = "Fatal Message";
/**
* Log4J controller for this test case's log.
*/
private LogControl controller;
/**
* Log capturer; stops capturing in teardown.
*/
private GenericTestUtils.LogCapturer capturer;
/**
* Setup: create the contract then init it.
*/
@Before
public void setup() {
controller = requireNonNull(createLog4JController());
capturer = captureLogs(LOG);
}
/**
* Teardown.
*/
@After
public void teardown() {
if (capturer != null) {
capturer.stopCapturing();
}
}
/**
* A class that is of the wrong type downgrades to null.
*/
@Test
public void testInstantationWrongClass() throws Throwable {
Assertions.assertThat(createController(CLASSNAME))
.describedAs("controller of wrong type")
.isNull();
}
/**
* A class that is of the wrong type downgrades to null.
*/
@Test
public void testInstantationNoClass() throws Throwable {
Assertions.assertThat(createController("not.a.class"))
.describedAs("missing class")
.isNull();
}
/**
* If the controller's implementation of
* {@link LogControl#setLevel(String, LogControl.LogLevel)} raises an exception,
* this is caught and downgraded to a "false" return code.
*/
@Test
public void testExceptionsDowngraded() throws Throwable {
final LogControl failing = createController(LevelFailingLogController.class.getName());
// inner method raises an exception
intercept(NoSuchMethodException.class, "Simulated", () ->
failing.setLevel(CLASSNAME, LogControl.LogLevel.DEBUG));
// outer one doesn't
Assertions.assertThat(failing.setLogLevel(CLASSNAME, LogControl.LogLevel.DEBUG))
.describedAs("Invocation of setLogLevel()")
.isFalse();
}
@Test
public void testLogAllLevels() throws Throwable {
assertLogsAtLevel(LogControl.LogLevel.ALL,
DEBUG, INFO, WARN, ERROR);
}
@Test
public void testLogAtInfo() throws Throwable {
assertLogsAtLevel(LogControl.LogLevel.INFO,
INFO, WARN, ERROR)
.doesNotContain(DEBUG);
}
@Test
public void testLogAtWarn() throws Throwable {
assertLogsAtLevel(LogControl.LogLevel.WARN, WARN, ERROR)
.doesNotContain(DEBUG, INFO);
}
@Test
public void testLogAtError() throws Throwable {
assertLogsAtLevel(LogControl.LogLevel.ERROR, ERROR)
.doesNotContain(DEBUG, INFO, WARN);
}
@Test
public void testLogAtNone() throws Throwable {
assertLogsAtLevel(LogControl.LogLevel.OFF, "")
.doesNotContain(DEBUG, INFO, WARN, ERROR);
}
/**
* generate output at a given logging level, print messages at different levels
* then assert what the final values are.
* @param level log level
* @param contains expected contained strings
* @return the ongoing assertion.
*/
private AbstractStringAssert<?> assertLogsAtLevel(
final LogControl.LogLevel level, CharSequence... contains) {
capturer.clearOutput();
setLogLevel(level);
logMessages();
return Assertions.assertThat(capturer.getOutput())
.describedAs("captured output")
.contains(contains);
}
/**
* Set the local log level.
* @param level level to set to.
*/
private void setLogLevel(final LogControl.LogLevel level) {
Assertions.assertThat(controller.setLogLevel(CLASSNAME, level))
.describedAs("Set log level %s", level)
.isTrue();
}
/**
* Log at all levels from debug to fatal.
*/
private static void logMessages() {
LOG.debug(DEBUG);
LOG.info(INFO);
LOG.warn(WARN);
LOG.error(ERROR);
LOG.error(FATAL);
}
@VisibleForTesting
static class LevelFailingLogController extends LogControl {
@Override
protected boolean setLevel(final String log, final LogLevel level)
throws Exception {
throw new NoSuchMethodException("Simulated");
}
}
}