Introduce separate GCInspector thresholds for concurrent GC events.

For GC like ShenandoahGC/ZGC etc., there are GC events that do not have STW pauses (Concurrent phases).
Operator might find it reasonable to use lower thresholds for events require STW pauses and higher thresholds for concurrent phases.
gc_concurrent_phase_log_threshold and gc_concurrent_phase_warn_threshold configuration options are introduced in cassandra.yaml

Patch by Yuqi Yan; reviewed by Dmitry Konstantinov, Stefan Miklosovic for CASSANDRA-20980
Co-authored-by: Stefan Miklosovic
This commit is contained in:
Yuqi Yan 2025-10-17 13:50:16 -07:00 committed by Dmitry Konstantinov
parent 6b57acc7f4
commit e621d8a6c1
8 changed files with 252 additions and 48 deletions

View File

@ -1,4 +1,5 @@
5.1
* Introduce separate GCInspector thresholds for concurrent GC events (CASSANDRA-20980)
* Reduce contention in MemtableAllocator.allocate (CASSANDRA-20226)
* Add export, list, import sub-commands for nodetool compressiondictionary (CASSANDRA-20941)
* Add support in the binary protocol to allow transactions to have multiple conditions (CASSANDRA-20883)

View File

@ -2048,6 +2048,11 @@ batch_size_fail_threshold: 50KiB
# Log WARN on any batches not of type LOGGED than span across more partitions than this limit
unlogged_batch_across_partitions_warn_threshold: 10
# GCInspector configs:
# For GC like ShenandoahGC/ZGC etc., there are GC events that do not have STW pauses (Concurrent phases)
# Operator might find it reasonable to use lower thresholds for events require STW pauses and higher thresholds
# for concurrent phases.
#
# GC Pauses greater than 200 ms will be logged at INFO level
# This threshold can be adjusted to minimize logging if necessary
# Min unit: ms
@ -2059,6 +2064,17 @@ unlogged_batch_across_partitions_warn_threshold: 10
# Min unit: ms
# gc_warn_threshold: 1000ms
# GC Concurrent phase greater than 1000 ms will be logged at INFO level
# This threshold can be adjusted to minimize logging if necessary
# Min unit: ms
# gc_concurrent_phase_log_threshold: 1000ms
# GC Concurrent phase than gc_concurrent_phase_warn_threshold will be logged at WARN level
# Adjust the threshold based on your application throughput requirement. Setting to 0
# will deactivate the feature.
# Min unit: ms
# gc_concurrent_phase_warn_threshold: 2000ms
# Maximum size of any value in SSTables. Safety measure to detect SSTable corruption
# early. Any value size larger than this threshold will result into marking an SSTable
# as corrupted. This should be positive and less than 2GiB.

View File

@ -1913,6 +1913,11 @@ batch_size_fail_threshold: 50KiB
# Log WARN on any batches not of type LOGGED than span across more partitions than this limit
unlogged_batch_across_partitions_warn_threshold: 10
# GCInspector configs:
# For GC like ShenandoahGC/ZGC etc., there are GC events that do not have STW pauses.
# Such events are called Concurrent phases. Operator might find it reasonable to use lower thresholds
# for events require STW pauses and higher thresholds for concurrent phases.
#
# GC Pauses greater than 200 ms will be logged at INFO level
# This threshold can be adjusted to minimize logging if necessary
# Min unit: ms
@ -1924,6 +1929,17 @@ unlogged_batch_across_partitions_warn_threshold: 10
# Min unit: ms
# gc_warn_threshold: 1000ms
# GC Concurrent phase greater than 1000 ms will be logged at INFO level
# This threshold can be adjusted to minimize logging if necessary
# Min unit: ms
# gc_concurrent_phase_log_threshold: 1000ms
# GC Concurrent phase than gc_concurrent_phase_warn_threshold will be logged at WARN level
# Adjust the threshold based on your application throughput requirement. Setting to 0
# will deactivate the feature.
# Min unit: ms
# gc_concurrent_phase_warn_threshold: 2000ms
# Maximum size of any value in SSTables. Safety measure to detect SSTable corruption
# early. Any value size larger than this threshold will result into marking an SSTable
# as corrupted. This should be positive and less than 2GiB.

View File

@ -593,6 +593,8 @@ public class Config
public volatile DurationSpec.IntMillisecondsBound gc_log_threshold = new DurationSpec.IntMillisecondsBound("200ms");
@Replaces(oldName = "gc_warn_threshold_in_ms", converter = Converters.MILLIS_DURATION_INT, deprecated = true)
public volatile DurationSpec.IntMillisecondsBound gc_warn_threshold = new DurationSpec.IntMillisecondsBound("1s");
public volatile DurationSpec.IntMillisecondsBound gc_concurrent_phase_log_threshold = new DurationSpec.IntMillisecondsBound("1s");
public volatile DurationSpec.IntMillisecondsBound gc_concurrent_phase_warn_threshold = new DurationSpec.IntMillisecondsBound("2s");
// TTL for different types of trace events.
@Replaces(oldName = "tracetype_query_ttl", converter = Converters.SECONDS_DURATION, deprecated=true)

View File

@ -1220,6 +1220,22 @@ public class DatabaseDescriptor
// run audit logging options through sanitation and validation
if (conf.audit_logging_options != null)
setAuditLoggingOptions(conf.audit_logging_options);
try
{
// Run through the validation by setting current values back to their setters, so we are sure that their values are valid.
// We are catching IllegalArgumentException and translating it to ConfigurationException to comply with
// rest of the logic in this method. These setters are also called in GCInspectorMXBean were IllegalArgumentException
// is thrown when arguments are invalid instead ConfigurationException, on purpose.
DatabaseDescriptor.setGCLogThreshold((int) DatabaseDescriptor.getGCLogThreshold());
DatabaseDescriptor.setGCWarnThreshold((int) DatabaseDescriptor.getGCWarnThreshold());
DatabaseDescriptor.setGCConcurrentPhaseLogThreshold(DatabaseDescriptor.getGCConcurrentPhaseLogThreshold());
DatabaseDescriptor.setGCConcurrentPhaseWarnThreshold(DatabaseDescriptor.getGCConcurrentPhaseWarnThreshold());
}
catch (IllegalArgumentException ex)
{
throw new ConfigurationException(ex.getMessage());
}
}
@VisibleForTesting
@ -4719,14 +4735,17 @@ public class DatabaseDescriptor
return conf.gc_log_threshold.toMilliseconds();
}
public static void setGCLogThreshold(int gcLogThreshold)
public static void setGCLogThreshold(int threshold)
{
conf.gc_log_threshold = new DurationSpec.IntMillisecondsBound(gcLogThreshold);
}
if (threshold <= 0)
throw new IllegalArgumentException("Threshold value for gc_log_threshold must be greater than 0");
public static EncryptionContext getEncryptionContext()
{
return encryptionContext;
long gcWarnThresholdInMs = getGCWarnThreshold();
if (gcWarnThresholdInMs != 0 && threshold > gcWarnThresholdInMs)
throw new IllegalArgumentException("Threshold value for gc_log_threshold (" + threshold + ") must be less than gc_warn_threshold which is currently "
+ gcWarnThresholdInMs);
conf.gc_log_threshold = new DurationSpec.IntMillisecondsBound(threshold);
}
public static long getGCWarnThreshold()
@ -4736,9 +4755,58 @@ public class DatabaseDescriptor
public static void setGCWarnThreshold(int threshold)
{
if (threshold < 0)
throw new IllegalArgumentException("Threshold value for gc_warn_threshold must be greater than or equal to 0");
long gcLogThresholdInMs = getGCLogThreshold();
if (threshold != 0 && threshold <= gcLogThresholdInMs)
throw new IllegalArgumentException("Threshold value for gc_warn_threshold (" + threshold + ") must be greater than gc_log_threshold which is currently "
+ gcLogThresholdInMs);
conf.gc_warn_threshold = new DurationSpec.IntMillisecondsBound(threshold);
}
public static int getGCConcurrentPhaseLogThreshold()
{
return conf.gc_concurrent_phase_log_threshold.toMilliseconds();
}
public static void setGCConcurrentPhaseLogThreshold(int threshold)
{
if (threshold <= 0)
throw new IllegalArgumentException("Threshold must be greater than 0");
long gcConcurrentPhaseWarnThresholdInMs = getGCConcurrentPhaseWarnThreshold();
if (gcConcurrentPhaseWarnThresholdInMs != 0 && threshold > gcConcurrentPhaseWarnThresholdInMs)
throw new IllegalArgumentException("Threshold value for gc_concurrent_phase_log_threshold (" + threshold + ") must be less than gc_concurrent_phase_warn_threshold which is currently "
+ gcConcurrentPhaseWarnThresholdInMs);
conf.gc_concurrent_phase_log_threshold = new DurationSpec.IntMillisecondsBound(threshold);
}
public static int getGCConcurrentPhaseWarnThreshold()
{
return conf.gc_concurrent_phase_warn_threshold.toMilliseconds();
}
public static void setGCConcurrentPhaseWarnThreshold(int threshold)
{
if (threshold < 0)
throw new IllegalArgumentException("Threshold value for gc_concurrent_phase_warn_threshold must be greater than or equal to 0");
long gcConcurrentPhaseLogThresholdInMs = getGCConcurrentPhaseLogThreshold();
if (threshold != 0 && threshold <= gcConcurrentPhaseLogThresholdInMs)
throw new IllegalArgumentException("Threshold value for gc_concurrent_phase_warn_threshold (" + threshold + ") must be greater than gc_concurrent_phase_log_threshold which is currently "
+ gcConcurrentPhaseLogThresholdInMs);
conf.gc_concurrent_phase_warn_threshold = new DurationSpec.IntMillisecondsBound(threshold);
}
public static EncryptionContext getEncryptionContext()
{
return encryptionContext;
}
public static boolean isCDCEnabled()
{
return conf.cdc_enabled;

View File

@ -173,6 +173,7 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
ObjectName gcName = new ObjectName(ManagementFactory.GARBAGE_COLLECTOR_MXBEAN_DOMAIN_TYPE + ",*");
for (ObjectName name : server.queryNames(gcName, null))
{
logger.info("Notification listener is added for: {}", name);
server.addNotificationListener(name, inspector, null, null);
}
}
@ -261,6 +262,11 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
duration = total - previousTotal; // may be zero for a really fast collection
}
logger.trace("Received GarbageCollectionNotificationInfo with gcId: {}, gcName: {}, " +
"gcCause: {}, gcAction: {}, event duration: {} ms, calculated duration: {} ms",
gcInfo.getId(), info.getGcName(), info.getGcCause(), info.getGcAction(),
gcInfo.getDuration(), duration);
StringBuilder sb = new StringBuilder();
sb.append(info.getGcName()).append(" GC in ").append(duration).append("ms. ");
long bytes = 0;
@ -288,15 +294,30 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
break;
}
if (getGcWarnThresholdInMs() != 0 && duration > getGcWarnThresholdInMs())
logger.warn(sb.toString());
else if (duration > getGcLogThresholdInMs())
logger.info(sb.toString());
else if (logger.isTraceEnabled())
logger.trace(sb.toString());
if (isConcurrentPhase(info.getGcCause(), info.getGcName()))
{
if (getGcConcurrentPhaseWarnThresholdInMs() != 0 && duration > getGcConcurrentPhaseWarnThresholdInMs())
logger.warn(sb.toString());
else if (duration > getGcConcurrentPhaseLogThresholdInMs())
logger.info(sb.toString());
else if (logger.isTraceEnabled())
logger.trace(sb.toString());
if (duration > this.getStatusThresholdInMs())
StatusLogger.log();
if (duration > this.getConcurrentStatusThresholdInMs())
StatusLogger.log();
}
else
{
if (getGcWarnThresholdInMs() != 0 && duration > getGcWarnThresholdInMs())
logger.warn(sb.toString());
else if (duration > getGcLogThresholdInMs())
logger.info(sb.toString());
else if (logger.isTraceEnabled())
logger.trace(sb.toString());
if (duration > this.getStatusThresholdInMs())
StatusLogger.log();
}
// if we just finished an old gen collection and we're still using a lot of memory, try to reduce the pressure
if (gcState.assumeGCIsOldGen)
@ -304,6 +325,24 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
}
}
static boolean isConcurrentPhase(String cause, String name) {
// Mostly taken from: https://github.com/Netflix/spectator/blob/v1.7.x/spectator-ext-gc/src/main/java/com/netflix/spectator/gc/GcLogger.java
// So far the only indicator known is that the cause will be reported as "No GC"
// when using CMS.
//
// For ZGC, behavior was changed in JDK17: https://bugs.openjdk.java.net/browse/JDK-8265136
// For ZGC in older versions, there is no way to accurately get the amount of time
// in STW pauses.
//
// For G1, a new bean is added in JDK20 to indicate time spent in concurrent phases:
// https://bugs.openjdk.org/browse/JDK-8297247
return "No GC".equals(cause) // CMS
|| "G1 Concurrent GC".equals(name) // G1 in JDK20+
|| name.endsWith(" Cycles"); // Shenandoah, ZGC
}
public State getTotalSinceLastCheck()
{
return state.getAndSet(new State());
@ -378,14 +417,6 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
public void setGcWarnThresholdInMs(long threshold)
{
long gcLogThresholdInMs = getGcLogThresholdInMs();
if (threshold < 0)
throw new IllegalArgumentException("Threshold must be greater than or equal to 0");
if (threshold != 0 && threshold <= gcLogThresholdInMs)
throw new IllegalArgumentException("Threshold must be greater than gcLogThresholdInMs which is currently "
+ gcLogThresholdInMs);
if (threshold > Integer.MAX_VALUE)
throw new IllegalArgumentException("Threshold must be less than Integer.MAX_VALUE");
DatabaseDescriptor.setGCWarnThreshold((int)threshold);
}
@ -396,17 +427,29 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
public void setGcLogThresholdInMs(long threshold)
{
if (threshold <= 0)
throw new IllegalArgumentException("Threshold must be greater than 0");
long gcWarnThresholdInMs = getGcWarnThresholdInMs();
if (gcWarnThresholdInMs != 0 && threshold > gcWarnThresholdInMs)
throw new IllegalArgumentException("Threshold must be less than gcWarnThresholdInMs which is currently "
+ gcWarnThresholdInMs);
DatabaseDescriptor.setGCLogThreshold((int) threshold);
}
public int getGcConcurrentPhaseWarnThresholdInMs()
{
return DatabaseDescriptor.getGCConcurrentPhaseWarnThreshold();
}
public void setGcConcurrentPhaseWarnThresholdInMs(int threshold)
{
DatabaseDescriptor.setGCConcurrentPhaseWarnThreshold(threshold);
}
public int getGcConcurrentPhaseLogThresholdInMs()
{
return DatabaseDescriptor.getGCConcurrentPhaseLogThreshold();
}
public void setGcConcurrentPhaseLogThresholdInMs(int threshold)
{
DatabaseDescriptor.setGCConcurrentPhaseLogThreshold(threshold);
}
public long getGcLogThresholdInMs()
{
return DatabaseDescriptor.getGCLogThreshold();
@ -417,4 +460,8 @@ public class GCInspector implements NotificationListener, GCInspectorMXBean
return getGcWarnThresholdInMs() != 0 ? getGcWarnThresholdInMs() : getGcLogThresholdInMs();
}
public long getConcurrentStatusThresholdInMs()
{
return getGcConcurrentPhaseWarnThresholdInMs() != 0 ? getGcConcurrentPhaseWarnThresholdInMs() : getGcConcurrentPhaseLogThresholdInMs();
}
}

View File

@ -27,6 +27,10 @@ public interface GCInspectorMXBean
void setGcWarnThresholdInMs(long threshold);
long getGcWarnThresholdInMs();
void setGcLogThresholdInMs(long threshold);
int getGcConcurrentPhaseLogThresholdInMs();
void setGcConcurrentPhaseWarnThresholdInMs(int threshold);
int getGcConcurrentPhaseWarnThresholdInMs();
void setGcConcurrentPhaseLogThresholdInMs(int threshold);
long getGcLogThresholdInMs();
long getStatusThresholdInMs();
}

View File

@ -18,11 +18,16 @@
package org.apache.cassandra.service;
import org.apache.cassandra.config.DatabaseDescriptor;
import org.junit.Assert;
import org.junit.Before;
import org.junit.BeforeClass;
import org.junit.Test;
import static org.assertj.core.api.Assertions.assertThatThrownBy;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertFalse;
import static org.junit.Assert.assertTrue;
public class GCInspectorTest
{
@ -43,38 +48,61 @@ public class GCInspectorTest
@Test
public void ensureStaticFieldsHydrateFromConfig()
{
Assert.assertEquals(DatabaseDescriptor.getGCLogThreshold(), gcInspector.getGcLogThresholdInMs());
Assert.assertEquals(DatabaseDescriptor.getGCWarnThreshold(), gcInspector.getGcWarnThresholdInMs());
assertEquals(DatabaseDescriptor.getGCLogThreshold(), gcInspector.getGcLogThresholdInMs());
assertEquals(DatabaseDescriptor.getGCWarnThreshold(), gcInspector.getGcWarnThresholdInMs());
assertEquals(DatabaseDescriptor.getGCConcurrentPhaseLogThreshold(), gcInspector.getGcConcurrentPhaseLogThresholdInMs());
assertEquals(DatabaseDescriptor.getGCConcurrentPhaseWarnThreshold(), gcInspector.getGcConcurrentPhaseWarnThresholdInMs());
}
@Test
public void ensureStatusIsCalculated()
{
Assert.assertTrue(gcInspector.getStatusThresholdInMs() > 0);
assertTrue(gcInspector.getStatusThresholdInMs() > 0);
}
@Test(expected=IllegalArgumentException.class)
@Test
public void ensureWarnGreaterThanLog()
{
gcInspector.setGcWarnThresholdInMs(gcInspector.getGcLogThresholdInMs());
assertThatThrownBy(() -> gcInspector.setGcWarnThresholdInMs(gcInspector.getGcLogThresholdInMs()))
.isInstanceOf(IllegalArgumentException.class)
.hasMessage("Threshold value for gc_warn_threshold (200) must be greater than gc_log_threshold which is currently 200");
assertThatThrownBy(() -> gcInspector.setGcConcurrentPhaseWarnThresholdInMs(gcInspector.getGcConcurrentPhaseLogThresholdInMs()))
.isInstanceOf(IllegalArgumentException.class)
.hasMessage("Threshold value for gc_concurrent_phase_warn_threshold (1000) must be greater than gc_concurrent_phase_log_threshold which is currently 1000");
}
@Test
public void ensureZeroIsOk()
{
gcInspector.setGcWarnThresholdInMs(0);
Assert.assertEquals(gcInspector.getStatusThresholdInMs(), gcInspector.getGcLogThresholdInMs());
Assert.assertEquals(0, DatabaseDescriptor.getGCWarnThreshold());
Assert.assertEquals(200, DatabaseDescriptor.getGCLogThreshold());
assertEquals(gcInspector.getStatusThresholdInMs(), gcInspector.getGcLogThresholdInMs());
assertEquals(0, DatabaseDescriptor.getGCWarnThreshold());
assertEquals(200, DatabaseDescriptor.getGCLogThreshold());
gcInspector.setGcConcurrentPhaseWarnThresholdInMs(0);
assertEquals(0, DatabaseDescriptor.getGCConcurrentPhaseWarnThreshold());
assertEquals(1000, DatabaseDescriptor.getGCConcurrentPhaseLogThreshold());
}
@Test(expected=IllegalArgumentException.class)
@Test
public void ensureLogLessThanWarn()
{
Assert.assertEquals(200, gcInspector.getGcLogThresholdInMs());
assertEquals(200, gcInspector.getGcLogThresholdInMs());
gcInspector.setGcWarnThresholdInMs(1000);
Assert.assertEquals(1000, gcInspector.getGcWarnThresholdInMs());
gcInspector.setGcLogThresholdInMs(gcInspector.getGcWarnThresholdInMs() + 1);
assertEquals(1000, gcInspector.getGcWarnThresholdInMs());
assertThatThrownBy(() -> gcInspector.setGcLogThresholdInMs(gcInspector.getGcWarnThresholdInMs() + 1))
.isInstanceOf(IllegalArgumentException.class)
.hasMessage("Threshold value for gc_log_threshold (1001) must be less than gc_warn_threshold which is currently 1000");
assertEquals(1000, gcInspector.getGcConcurrentPhaseLogThresholdInMs());
gcInspector.setGcConcurrentPhaseWarnThresholdInMs(2000);
assertEquals(2000, gcInspector.getGcConcurrentPhaseWarnThresholdInMs());
assertThatThrownBy(() -> gcInspector.setGcConcurrentPhaseLogThresholdInMs(gcInspector.getGcConcurrentPhaseWarnThresholdInMs() + 1))
.isInstanceOf(IllegalArgumentException.class)
.hasMessage("Threshold value for gc_concurrent_phase_log_threshold (2001) must be less than gc_concurrent_phase_warn_threshold which is currently 2000");
}
@Test
@ -82,10 +110,16 @@ public class GCInspectorTest
{
gcInspector.setGcLogThresholdInMs(200);
gcInspector.setGcWarnThresholdInMs(1000);
Assert.assertEquals(200, DatabaseDescriptor.getGCLogThreshold());
Assert.assertEquals(200, gcInspector.getGcLogThresholdInMs());
Assert.assertEquals(1000, DatabaseDescriptor.getGCWarnThreshold());
Assert.assertEquals(1000, gcInspector.getGcWarnThresholdInMs());
gcInspector.setGcConcurrentPhaseLogThresholdInMs(1000);
gcInspector.setGcConcurrentPhaseWarnThresholdInMs(2000);
assertEquals(200, DatabaseDescriptor.getGCLogThreshold());
assertEquals(200, gcInspector.getGcLogThresholdInMs());
assertEquals(1000, DatabaseDescriptor.getGCWarnThreshold());
assertEquals(1000, gcInspector.getGcWarnThresholdInMs());
assertEquals(1000, DatabaseDescriptor.getGCConcurrentPhaseLogThreshold());
assertEquals(1000, gcInspector.getGcConcurrentPhaseLogThresholdInMs());
assertEquals(2000, DatabaseDescriptor.getGCConcurrentPhaseWarnThreshold());
assertEquals(2000, gcInspector.getGcConcurrentPhaseWarnThresholdInMs());
}
@Test(expected=IllegalArgumentException.class)
@ -94,4 +128,20 @@ public class GCInspectorTest
gcInspector.setGcLogThresholdInMs(200);
gcInspector.setGcWarnThresholdInMs(Integer.MAX_VALUE+1L);
}
@Test
public void testIsConcurrentPhase()
{
assertTrue("No GC cause should be considered concurrent",
GCInspector.isConcurrentPhase("No GC", "SomeGCName"));
assertTrue("Shenandoah Cycles should be considered concurrent",
GCInspector.isConcurrentPhase("SomeCause", "Shenandoah Cycles"));
assertTrue("ZGC Cycles should be considered concurrent",
GCInspector.isConcurrentPhase("SomeCause", "ZGC Cycles"));
assertFalse("ParallelGC should not be considered concurrent",
GCInspector.isConcurrentPhase("Allocation Failure", "PS Scavenge"));
assertFalse("G1 Young Generation should not be considered concurrent",
GCInspector.isConcurrentPhase("G1 Evacuation Pause", "G1 Young Generation"));
}
}