This is an automated email from the ASF dual-hosted git repository. agura pushed a commit to branch apache-master in repository https://gitbox.apache.org/repos/asf/ignite.git
commit c426564ecc6e26f655ef5e1d1b3ea1eac65eeb1e Author: Mirza Aliev <[email protected]> AuthorDate: Wed Nov 27 15:05:27 2019 +0300 IGNITE-12394 Fix log level for messages and thread dumps for ignored failures Signed-off-by: Andrey Gura <[email protected]> --- .../processors/failure/FailureProcessor.java | 35 ++- .../apache/ignite/internal/util/IgniteUtils.java | 54 ++++- .../failure/FailureProcessorLoggingTest.java | 270 +++++++++++++++++++++ .../ignite/testsuites/IgniteBasicTestSuite.java | 2 + 4 files changed, 349 insertions(+), 12 deletions(-) diff --git a/modules/core/src/main/java/org/apache/ignite/internal/processors/failure/FailureProcessor.java b/modules/core/src/main/java/org/apache/ignite/internal/processors/failure/FailureProcessor.java index b0e1772..19495eb 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/processors/failure/FailureProcessor.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/processors/failure/FailureProcessor.java @@ -21,6 +21,7 @@ import org.apache.ignite.Ignite; import org.apache.ignite.IgniteCheckedException; import org.apache.ignite.IgniteSystemProperties; import org.apache.ignite.configuration.IgniteConfiguration; +import org.apache.ignite.failure.AbstractFailureHandler; import org.apache.ignite.failure.FailureContext; import org.apache.ignite.failure.FailureHandler; import org.apache.ignite.failure.NoOpFailureHandler; @@ -37,8 +38,15 @@ import org.apache.ignite.internal.util.typedef.internal.U; */ public class FailureProcessor extends GridProcessorAdapter { /** Value of the system property that enables threads dumping on failure. */ - private static final boolean IGNITE_DUMP_THREADS_ON_FAILURE = - IgniteSystemProperties.getBoolean(IgniteSystemProperties.IGNITE_DUMP_THREADS_ON_FAILURE, true); + private final boolean igniteDumpThreadsOnFailure = + IgniteSystemProperties.getBoolean(IgniteSystemProperties.IGNITE_DUMP_THREADS_ON_FAILURE, false); + + /** Ignored failure log message. */ + static final String IGNORED_FAILURE_LOG_MSG = "Possible failure suppressed accordingly to a configured handler "; + + /** Failure log message. */ + static final String FAILURE_LOG_MSG = "Critical system error detected. " + + "Will be handled accordingly to configured handler "; /** Ignite. */ private final Ignite ignite; @@ -125,8 +133,14 @@ public class FailureProcessor extends GridProcessorAdapter { if (this.failureCtx != null) // Node already terminating, no reason to process more errors. return false; - U.error(ignite.log(), "Critical system error detected. Will be handled accordingly to configured handler " + - "[hnd=" + hnd + ", failureCtx=" + failureCtx + ']', failureCtx.error()); + if (failureTypeIgnored(failureCtx, hnd)) { + U.quietAndWarn(ignite.log(), IGNORED_FAILURE_LOG_MSG + + "[hnd=" + hnd + ", failureCtx=" + failureCtx + ']', failureCtx.error()); + } + else { + U.error(ignite.log(), FAILURE_LOG_MSG + + "[hnd=" + hnd + ", failureCtx=" + failureCtx + ']', failureCtx.error()); + } if (reserveBuf != null && X.hasCause(failureCtx.error(), OutOfMemoryError.class)) reserveBuf = null; @@ -138,8 +152,8 @@ public class FailureProcessor extends GridProcessorAdapter { " WAL path: " + ctx.config().getDataStorageConfiguration().getWalPath() + " WAL archive path: " + ctx.config().getDataStorageConfiguration().getWalArchivePath()); - if (IGNITE_DUMP_THREADS_ON_FAILURE) - U.dumpThreads(log); + if (igniteDumpThreadsOnFailure) + U.dumpThreads(log, !failureTypeIgnored(failureCtx, hnd)); DiagnosticProcessor diagnosticProcessor = ctx.diagnostic(); @@ -156,4 +170,13 @@ public class FailureProcessor extends GridProcessorAdapter { return invalidated; } + + /** + * @param failureCtx Failure context. + * @param hnd Handler. + */ + private static boolean failureTypeIgnored(FailureContext failureCtx, FailureHandler hnd) { + return hnd instanceof AbstractFailureHandler && + ((AbstractFailureHandler)hnd).getIgnoredFailureTypes().contains(failureCtx.type()); + } } diff --git a/modules/core/src/main/java/org/apache/ignite/internal/util/IgniteUtils.java b/modules/core/src/main/java/org/apache/ignite/internal/util/IgniteUtils.java index 68ab912..f6d9150 100755 --- a/modules/core/src/main/java/org/apache/ignite/internal/util/IgniteUtils.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/util/IgniteUtils.java @@ -349,6 +349,9 @@ public abstract class IgniteUtils { /** Default working directory name. */ private static final String DEFAULT_WORK_DIR = "work"; + /** Thread dump message. */ + public static final String THREAD_DUMP_MSG = "Thread dump at "; + /** Correct Mbean cache name pattern. */ private static Pattern MBEAN_CACHE_NAME_PATTERN = Pattern.compile("^[a-zA-Z_0-9]+$"); @@ -1407,25 +1410,37 @@ public abstract class IgniteUtils { } /** - * Performs thread dump and prints all available info to the given log. + * Performs thread dump and prints all available info to the given log with WARN logging level. * * @param log Logger. */ public static void dumpThreads(@Nullable IgniteLogger log) { + dumpThreads(log, false); + } + + /** + * Performs thread dump and prints all available info to the given log + * with WARN or ERROR logging level depending on {@code isErrorLevel} parameter. + * + * @param log Logger. + * @param isErrorLevel {@code true} if thread dump must be printed with ERROR logging level, + * {@code false} if thread dump must be printed with WARN logging level. + */ + public static void dumpThreads(@Nullable IgniteLogger log, boolean isErrorLevel) { ThreadMXBean mxBean = ManagementFactory.getThreadMXBean(); final Set<Long> deadlockedThreadsIds = getDeadlockedThreadIds(mxBean); if (deadlockedThreadsIds.isEmpty()) - warn(log, "No deadlocked threads detected."); + logMessage(log, "No deadlocked threads detected.", isErrorLevel); else - warn(log, "Deadlocked threads detected (see thread dump below) " + - "[deadlockedThreadsCnt=" + deadlockedThreadsIds.size() + ']'); + logMessage(log, "Deadlocked threads detected (see thread dump below) " + + "[deadlockedThreadsCnt=" + deadlockedThreadsIds.size() + ']', isErrorLevel); ThreadInfo[] threadInfos = mxBean.dumpAllThreads(mxBean.isObjectMonitorUsageSupported(), mxBean.isSynchronizerUsageSupported()); - GridStringBuilder sb = new GridStringBuilder("Thread dump at ") + GridStringBuilder sb = new GridStringBuilder(THREAD_DUMP_MSG) .a(new SimpleDateFormat("yyyy/MM/dd HH:mm:ss z").format(new Date(U.currentTimeMillis()))).a(NL); for (ThreadInfo info : threadInfos) { @@ -1442,7 +1457,20 @@ public abstract class IgniteUtils { sb.a(NL); - warn(log, sb.toString()); + logMessage(log, sb.toString(), isErrorLevel); + } + + /** + * @param log Logger. + * @param msg Message. + * @param isErrorLevel {@code true} if message must be printed with ERROR logging level, + * {@code false} if message must be printed with WARN logging level. + */ + private static void logMessage(@Nullable IgniteLogger log, String msg, boolean isErrorLevel) { + if (isErrorLevel) + error(log, msg); + else + warn(log, msg); } /** @@ -4435,6 +4463,20 @@ public abstract class IgniteUtils { } /** + * Logs warning message in both verbose and quiet modes. + * + * @param log Logger to use. + * @param msg Message to log. + * @param e Optional exception. + */ + public static void quietAndWarn(IgniteLogger log, Object msg, @Nullable Throwable e) { + warn(log, msg, e); + + if (log.isQuiet()) + quiet(false, msg); + } + + /** * Depending on whether or not log is provided and quiet mode is enabled logs given * messages as quiet message or normal log ERROR message. If {@code log} is {@code null} * or in QUIET mode it will add {@code (err)} prefix to the message. diff --git a/modules/core/src/test/java/org/apache/ignite/internal/processors/failure/FailureProcessorLoggingTest.java b/modules/core/src/test/java/org/apache/ignite/internal/processors/failure/FailureProcessorLoggingTest.java new file mode 100644 index 0000000..0cbc08e --- /dev/null +++ b/modules/core/src/test/java/org/apache/ignite/internal/processors/failure/FailureProcessorLoggingTest.java @@ -0,0 +1,270 @@ +/* + * 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.ignite.internal.processors.failure; + +import com.google.common.collect.ImmutableSet; +import java.util.concurrent.atomic.AtomicBoolean; +import org.apache.ignite.IgniteLogger; +import org.apache.ignite.IgniteSystemProperties; +import org.apache.ignite.configuration.IgniteConfiguration; +import org.apache.ignite.failure.FailureContext; +import org.apache.ignite.failure.FailureType; +import org.apache.ignite.failure.TestFailureHandler; +import org.apache.ignite.internal.IgniteEx; +import org.apache.ignite.testframework.ListeningTestLogger; +import org.apache.ignite.testframework.junits.WithSystemProperty; +import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; +import org.jetbrains.annotations.Nullable; +import org.junit.Test; + +import static org.apache.ignite.internal.processors.failure.FailureProcessor.FAILURE_LOG_MSG; +import static org.apache.ignite.internal.processors.failure.FailureProcessor.IGNORED_FAILURE_LOG_MSG; +import static org.apache.ignite.internal.util.IgniteUtils.THREAD_DUMP_MSG; + +/** + * Tests log messages of failure processor. + */ +@WithSystemProperty(key = IgniteSystemProperties.IGNITE_DUMP_THREADS_ON_FAILURE, value = "true") +public class FailureProcessorLoggingTest extends GridCommonAbstractTest { + /** Test logger. */ + private static CustomTestLogger testLog; + + /** {@inheritDoc} */ + @Override protected IgniteConfiguration getConfiguration(String igniteInstanceName) throws Exception { + IgniteConfiguration cfg = super.getConfiguration(igniteInstanceName); + + TestFailureHandler hnd = new TestFailureHandler(false); + + testLog = new CustomTestLogger(false, log); + + hnd.setIgnoredFailureTypes(ImmutableSet.of(FailureType.SYSTEM_CRITICAL_OPERATION_TIMEOUT, FailureType.SYSTEM_WORKER_BLOCKED)); + + cfg.setFailureHandler(hnd); + + cfg.setGridLogger(testLog); + + return cfg; + } + + /** {@inheritDoc} */ + @Override protected void beforeTestsStarted() throws Exception { + super.beforeTestsStarted(); + + startGrid(0); + + testLog.expectedThreadDumpMessage(THREAD_DUMP_MSG); + } + + /** {@inheritDoc} */ + @Override protected void afterTestsStopped() throws Exception { + super.afterTestsStopped(); + + stopAllGrids(); + } + + /** {@inheritDoc} */ + @Override protected void beforeTest() throws Exception { + super.beforeTest(); + + testLog.resetAllFlags(); + } + + /** {@inheritDoc} */ + @Override protected void afterTest() throws Exception { + super.afterTest(); + + testLog.resetAllFlags(); + } + + /** + * Tests log message for ignored failure types. + */ + @Test + public void testFailureProcessorLoggedIgnoredFailureTest() throws Exception { + IgniteEx ignite = grid(0); + + testLog.expectedWarnMessage(IGNORED_FAILURE_LOG_MSG); + + ignite.context().failure().process(new FailureContext(FailureType.SYSTEM_CRITICAL_OPERATION_TIMEOUT, new Throwable("Failure context error"))); + + assertTrue(testLog.warnFlag().get()); + + assertTrue(testLog.threadDumpWarnFlag().get()); + } + + /** + * Tests log message for not ingnored failure types. + */ + @Test + public void testFailureProcessorLoggedFailureTest() throws Exception { + IgniteEx ignite = grid(0); + + testLog.expectedErrorMessage(FAILURE_LOG_MSG); + + ignite.context().failure().process(new FailureContext(FailureType.SEGMENTATION, new Throwable("Failure context error"))); + + assertTrue(testLog.errorFlag().get()); + + assertTrue(testLog.threadDumpErrorFlag().get()); + } + + /** + * Custom logger for checking if specified message and thread dump appeared at WARN and ERROR logging level. + */ + private static class CustomTestLogger extends ListeningTestLogger { + + /** Warn flag. */ + private AtomicBoolean warnFlag = new AtomicBoolean(false); + + /** Error flag. */ + private AtomicBoolean errorFlag = new AtomicBoolean(false); + + /** Thread dump warn flag. */ + private AtomicBoolean threadDumpWarnFlag = new AtomicBoolean(false); + + /** Thread dump error flag. */ + private AtomicBoolean threadDumpErrorFlag = new AtomicBoolean(false); + + /** Expected warn message. */ + private String expWarnMsg; + + /** Expected error message. */ + private String expErrorMsg; + + /** Thread dump message. */ + private String expThreadDumpMsg; + + /** + * @param dbg Dbg. + * @param echo Echo. + */ + public CustomTestLogger(boolean dbg, @Nullable IgniteLogger echo) { + super(dbg, echo); + } + + /** {@inheritDoc} */ + @Override public void warning(String msg, @Nullable Throwable t) { + super.warning(msg, t); + + if (expWarnMsg != null && msg.contains(expWarnMsg)) + warnFlag.set(true); + + if (expThreadDumpMsg != null && msg.contains(expThreadDumpMsg)) + threadDumpWarnFlag.set(true); + } + + /** {@inheritDoc} */ + @Override public void error(String msg, @Nullable Throwable t) { + super.error(msg, t); + + if (expErrorMsg != null && msg.contains(expErrorMsg)) + errorFlag.set(true); + + if (expThreadDumpMsg != null && msg.contains(expThreadDumpMsg)) + threadDumpErrorFlag.set(true); + } + + /** + * Reset warn flag. + */ + public void resetWarnFlag() { + warnFlag.set(false); + } + + /** + * Reset error flag. + */ + public void resetErrorFlag() { + errorFlag.set(false); + } + + /** + * Reset thread dump warn flag. + */ + public void resetThreadDumpWarnFlag() { + threadDumpWarnFlag.set(false); + } + + /** + * Reset thread dump error flag. + */ + public void resetThreadDumpErrorFlag() { + threadDumpErrorFlag.set(false); + } + + /** + * Reset all flags. + */ + public void resetAllFlags() { + resetWarnFlag(); + resetErrorFlag(); + resetThreadDumpWarnFlag(); + resetThreadDumpErrorFlag(); + } + + /** + * @param expWarnMsg New expected warn message. + */ + public void expectedWarnMessage(String expWarnMsg) { + this.expWarnMsg = expWarnMsg; + } + + /** + * @param expErrorMsg New expected error message. + */ + public void expectedErrorMessage(String expErrorMsg) { + this.expErrorMsg = expErrorMsg; + } + + /** + * @param expThreadDumpMsg New expected thread dump message. + */ + public void expectedThreadDumpMessage(String expThreadDumpMsg) { + this.expThreadDumpMsg = expThreadDumpMsg; + } + + /** + * @return Warn flag. + */ + public AtomicBoolean warnFlag() { + return warnFlag; + } + + /** + * @return Error flag. + */ + public AtomicBoolean errorFlag() { + return errorFlag; + } + + /** + * @return Thread dump warn flag. + */ + public AtomicBoolean threadDumpWarnFlag() { + return threadDumpWarnFlag; + } + + /** + * @return Thread dump error flag. + */ + public AtomicBoolean threadDumpErrorFlag() { + return threadDumpErrorFlag; + } + } + +} diff --git a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteBasicTestSuite.java b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteBasicTestSuite.java index 5c287be..3ad1402 100644 --- a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteBasicTestSuite.java +++ b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteBasicTestSuite.java @@ -19,6 +19,7 @@ package org.apache.ignite.testsuites; import org.apache.ignite.ClassPathContentLoggingTest; import org.apache.ignite.GridSuppressedExceptionSelfTest; +import org.apache.ignite.internal.processors.failure.FailureProcessorLoggingTest; import org.apache.ignite.failure.FailureHandlerTriggeredTest; import org.apache.ignite.failure.OomFailureHandlerTest; import org.apache.ignite.failure.StopNodeFailureHandlerTest; @@ -238,6 +239,7 @@ import org.junit.runners.Suite; StopNodeOrHaltFailureHandlerTest.class, OomFailureHandlerTest.class, TransactionIntegrityWithSystemWorkerDeathTest.class, + FailureProcessorLoggingTest.class, AtomicOperationsInTxTest.class,
