IGNITE-8426 Use IgniteLogger in long jvm pause detector - Fixes #4249. Signed-off-by: Alexey Goncharuk <alexey.goncha...@gmail.com>
Project: http://git-wip-us.apache.org/repos/asf/ignite/repo Commit: http://git-wip-us.apache.org/repos/asf/ignite/commit/f25289c8 Tree: http://git-wip-us.apache.org/repos/asf/ignite/tree/f25289c8 Diff: http://git-wip-us.apache.org/repos/asf/ignite/diff/f25289c8 Branch: refs/heads/ignite-8900-repro Commit: f25289c8776e7acc20568fb409395e543466a3e3 Parents: 81b6b2d Author: ezhuravl <ezhurav...@gridgain.com> Authored: Fri Jun 29 17:27:15 2018 +0300 Committer: Alexey Goncharuk <alexey.goncha...@gmail.com> Committed: Fri Jun 29 17:27:15 2018 +0300 ---------------------------------------------------------------------- .../apache/ignite/internal/IgniteKernal.java | 18 ++++-- .../ignite/internal/LongJVMPauseDetector.java | 56 +++++++++++-------- .../internal/LongJVMPauseDetectorTest.java | 58 ++++++++++++++++++++ .../testsuites/IgniteKernalSelfTestSuite.java | 2 + 4 files changed, 105 insertions(+), 29 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/ignite/blob/f25289c8/modules/core/src/main/java/org/apache/ignite/internal/IgniteKernal.java ---------------------------------------------------------------------- diff --git a/modules/core/src/main/java/org/apache/ignite/internal/IgniteKernal.java b/modules/core/src/main/java/org/apache/ignite/internal/IgniteKernal.java index cba55ab..270a014 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/IgniteKernal.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/IgniteKernal.java @@ -297,9 +297,8 @@ public class IgniteKernal implements IgniteEx, IgniteMXBean, Externalizable { /** Separator for formatted coordinator properties. */ public static final String COORDINATOR_PROPERTIES_SEPARATOR = ","; - static { - LongJVMPauseDetector.start(); - } + /** Long jvm pause detector. */ + private LongJVMPauseDetector longJVMPauseDetector; /** */ @GridToStringExclude @@ -472,17 +471,17 @@ public class IgniteKernal implements IgniteEx, IgniteMXBean, Externalizable { /** {@inheritDoc} */ @Override public long getLongJVMPausesCount() { - return LongJVMPauseDetector.longPausesCount(); + return longJVMPauseDetector != null ? longJVMPauseDetector.longPausesCount() : 0; } /** {@inheritDoc} */ @Override public long getLongJVMPausesTotalDuration() { - return LongJVMPauseDetector.longPausesTotalDuration(); + return longJVMPauseDetector != null ? longJVMPauseDetector.longPausesTotalDuration() : 0; } /** {@inheritDoc} */ @Override public Map<Long, Long> getLongJVMPauseLastEvents() { - return LongJVMPauseDetector.longPauseEvents(); + return longJVMPauseDetector != null ? longJVMPauseDetector.longPauseEvents() : Collections.emptyMap(); } /** {@inheritDoc} */ @@ -832,6 +831,10 @@ public class IgniteKernal implements IgniteEx, IgniteMXBean, Externalizable { log = (GridLoggerProxy)cfg.getGridLogger().getLogger( getClass().getName() + (igniteInstanceName != null ? '%' + igniteInstanceName : "")); + longJVMPauseDetector = new LongJVMPauseDetector(log); + + longJVMPauseDetector.start(); + RuntimeMXBean rtBean = ManagementFactory.getRuntimeMXBean(); // Ack various information. @@ -2142,6 +2145,9 @@ public class IgniteKernal implements IgniteEx, IgniteMXBean, Externalizable { if (longOpDumpTask != null) longOpDumpTask.close(); + if (longJVMPauseDetector != null) + longJVMPauseDetector.stop(); + boolean interrupted = false; while (true) { http://git-wip-us.apache.org/repos/asf/ignite/blob/f25289c8/modules/core/src/main/java/org/apache/ignite/internal/LongJVMPauseDetector.java ---------------------------------------------------------------------- diff --git a/modules/core/src/main/java/org/apache/ignite/internal/LongJVMPauseDetector.java b/modules/core/src/main/java/org/apache/ignite/internal/LongJVMPauseDetector.java index c10b6f9..8df04f9 100644 --- a/modules/core/src/main/java/org/apache/ignite/internal/LongJVMPauseDetector.java +++ b/modules/core/src/main/java/org/apache/ignite/internal/LongJVMPauseDetector.java @@ -40,12 +40,6 @@ import static org.apache.ignite.IgniteSystemProperties.getInteger; * IGNITE_JVM_PAUSE_DETECTOR_THRESHOLD and IGNITE_JVM_PAUSE_DETECTOR_LAST_EVENTS_COUNT accordingly. */ class LongJVMPauseDetector { - /** Logger. */ - private static final IgniteLogger LOG = new JavaLogger(); - - /** Worker reference. */ - private static final AtomicReference<Thread> workerRef = new AtomicReference<>(); - /** Precision. */ private static final int PRECISION = getInteger(IGNITE_JVM_PAUSE_DETECTOR_PRECISION, 50); @@ -55,25 +49,38 @@ class LongJVMPauseDetector { /** Event count. */ private static final int EVT_CNT = getInteger(IGNITE_JVM_PAUSE_DETECTOR_LAST_EVENTS_COUNT, 20); + /** Logger. */ + private final IgniteLogger log; + + /** Worker reference. */ + private final AtomicReference<Thread> workerRef = new AtomicReference<>(); + /** Long pause count. */ - private static long longPausesCnt; + private long longPausesCnt; /** Long pause total duration. */ - private static long longPausesTotalDuration; + private long longPausesTotalDuration; /** Long pauses timestamps. */ - private static final long[] longPausesTimestamps = new long[EVT_CNT]; + private final long[] longPausesTimestamps = new long[EVT_CNT]; /** Long pauses durations. */ - private static final long[] longPausesDurations = new long[EVT_CNT]; + private final long[] longPausesDurations = new long[EVT_CNT]; + + /** + * @param log Logger. + */ + public LongJVMPauseDetector(IgniteLogger log) { + this.log = log; + } /** * Starts worker if not started yet. */ - public static void start() { + public void start() { if (getBoolean(IGNITE_JVM_PAUSE_DETECTOR_DISABLED, false)) { - if (LOG.isDebugEnabled()) - LOG.debug("JVM Pause Detector is disabled."); + if (log.isDebugEnabled()) + log.debug("JVM Pause Detector is disabled."); return; } @@ -82,8 +89,8 @@ class LongJVMPauseDetector { private long prev = System.currentTimeMillis(); @Override public void run() { - if (LOG.isDebugEnabled()) - LOG.debug(getName() + " has been started."); + if (log.isDebugEnabled()) + log.debug(getName() + " has been started."); while (true) { try { @@ -95,9 +102,9 @@ class LongJVMPauseDetector { prev = now; if (pause >= THRESHOLD) { - LOG.warning("Possible too long JVM pause: " + pause + " milliseconds."); + log.warning("Possible too long JVM pause: " + pause + " milliseconds."); - synchronized (LongJVMPauseDetector.class) { + synchronized (LongJVMPauseDetector.this) { final int next = (int)(longPausesCnt % EVT_CNT); longPausesCnt++; @@ -111,7 +118,7 @@ class LongJVMPauseDetector { } } catch (InterruptedException e) { - LOG.error(getName() + " has been interrupted", e); + log.error(getName() + " has been interrupted", e); break; } @@ -120,19 +127,22 @@ class LongJVMPauseDetector { }; if (!workerRef.compareAndSet(null, worker)) { - LOG.warning(LongJVMPauseDetector.class.getSimpleName() + " already started!"); + log.warning(LongJVMPauseDetector.class.getSimpleName() + " already started!"); return; } worker.setDaemon(true); worker.start(); + + if (log.isDebugEnabled()) + log.debug("LongJVMPauseDetector was successfully started"); } /** * Stops the worker if one is created and running. */ - public static void stop() { + public void stop() { final Thread worker = workerRef.getAndSet(null); if (worker != null && worker.isAlive() && !worker.isInterrupted()) @@ -142,21 +152,21 @@ class LongJVMPauseDetector { /** * @return Long JVM pauses count. */ - synchronized static long longPausesCount() { + synchronized long longPausesCount() { return longPausesCnt; } /** * @return Long JVM pauses total duration. */ - synchronized static long longPausesTotalDuration() { + synchronized long longPausesTotalDuration() { return longPausesTotalDuration; } /** * @return Last long JVM pause events. */ - synchronized static Map<Long, Long> longPauseEvents() { + synchronized Map<Long, Long> longPauseEvents() { final Map<Long, Long> evts = new TreeMap<>(); for (int i = 0; i < longPausesTimestamps.length && longPausesTimestamps[i] != 0; i++) http://git-wip-us.apache.org/repos/asf/ignite/blob/f25289c8/modules/core/src/test/java/org/apache/ignite/internal/LongJVMPauseDetectorTest.java ---------------------------------------------------------------------- diff --git a/modules/core/src/test/java/org/apache/ignite/internal/LongJVMPauseDetectorTest.java b/modules/core/src/test/java/org/apache/ignite/internal/LongJVMPauseDetectorTest.java new file mode 100644 index 0000000..80761d1 --- /dev/null +++ b/modules/core/src/test/java/org/apache/ignite/internal/LongJVMPauseDetectorTest.java @@ -0,0 +1,58 @@ +/* + * 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; + +import org.apache.ignite.configuration.IgniteConfiguration; +import org.apache.ignite.testframework.GridStringLogger; +import org.apache.ignite.testframework.junits.common.GridCommonAbstractTest; + +/** + * Tests if LongJVMPauseDetector starts properly. + */ +public class LongJVMPauseDetectorTest extends GridCommonAbstractTest { + /** */ + private GridStringLogger strLog; + + /** {@inheritDoc} */ + @Override protected IgniteConfiguration getConfiguration(String gridName) throws Exception { + IgniteConfiguration cfg = super.getConfiguration(gridName); + + if (strLog != null) + cfg.setGridLogger(strLog); + + return cfg; + } + + /** {@inheritDoc} */ + @Override protected void afterTest() throws Exception { + stopAllGrids(); + } + + /** + * @throws Exception If failed. + */ + public void testJulMessage() throws Exception { + this.strLog = new GridStringLogger(true); + + strLog.logLength(300000); + + startGrid(0); + + assertTrue(strLog.toString().contains("LongJVMPauseDetector was successfully started")); + } +} http://git-wip-us.apache.org/repos/asf/ignite/blob/f25289c8/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteKernalSelfTestSuite.java ---------------------------------------------------------------------- diff --git a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteKernalSelfTestSuite.java b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteKernalSelfTestSuite.java index f2fbe04..0b7d2d2 100644 --- a/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteKernalSelfTestSuite.java +++ b/modules/core/src/test/java/org/apache/ignite/testsuites/IgniteKernalSelfTestSuite.java @@ -38,6 +38,7 @@ import org.apache.ignite.internal.GridVersionSelfTest; import org.apache.ignite.internal.IgniteConcurrentEntryProcessorAccessStopTest; import org.apache.ignite.internal.IgniteConnectionConcurrentReserveAndRemoveTest; import org.apache.ignite.internal.IgniteUpdateNotifierPerClusterSettingSelfTest; +import org.apache.ignite.internal.LongJVMPauseDetectorTest; import org.apache.ignite.internal.managers.GridManagerStopSelfTest; import org.apache.ignite.internal.managers.communication.GridCommunicationSendMessageSelfTest; import org.apache.ignite.internal.managers.deployment.GridDeploymentManagerStopSelfTest; @@ -130,6 +131,7 @@ public class IgniteKernalSelfTestSuite extends TestSuite { suite.addTestSuite(IgniteTopologyPrintFormatSelfTest.class); suite.addTestSuite(ComputeJobCancelWithServiceSelfTest.class); suite.addTestSuite(IgniteConnectionConcurrentReserveAndRemoveTest.class); + suite.addTestSuite(LongJVMPauseDetectorTest.class); // Managed Services. suite.addTestSuite(GridServiceProcessorSingleNodeSelfTest.class);