Skip to content
Open
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
Expand Up @@ -406,6 +406,7 @@ public enum CassandraRelevantProperties
MEMTABLE_OVERHEAD_SIZE("cassandra.memtable.row_overhead_size", "-1"),
MEMTABLE_SHARD_COUNT("cassandra.memtable.shard.count"),
MEMTABLE_TRIE_SIZE_LIMIT("cassandra.trie_size_limit_mb"),

METRICS_REPORTER_CONFIG_FILE("cassandra.metricsReporterConfigFile"),
/** Defines the maximum number of unique timed out queries that will be reported in the logs. Use a negative number to remove any limit. */
MONITORING_MAX_OPERATIONS("cassandra.monitoring_max_operations", "50"),
Expand All @@ -428,6 +429,12 @@ public enum CassandraRelevantProperties
* This is an optimization used in unit tests becuase we never restart a node there. The only node is stopoped
* when the JVM terminates. Therefore, we can use such optimization and not wait unnecessarily. */
NON_GRACEFUL_SHUTDOWN("cassandra.test.messagingService.nonGracefulShutdown"),
/**
* Maximum number of log statements cached per NoSpamLogger instance.
* This prevents unbounded memory growth when log messages contain dynamic content.
* Defaults to MAX_VALUE as a default behavior since we rely on the cache time-based expiration.
*/
NOSPAM_LOGGER_MAX_STATEMENTS_PER_LOGGER("cassandra.nospam_logger.max_statements_per_logger", String.valueOf(Long.MAX_VALUE)),
/** for specific tests */
/** This property indicates whether disable_mbean_registration is true */
ORG_APACHE_CASSANDRA_DISABLE_MBEAN_REGISTRATION("org.apache.cassandra.disable_mbean_registration"),
Expand Down
90 changes: 78 additions & 12 deletions src/java/org/apache/cassandra/utils/NoSpamLogger.java
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,7 @@
*/
package org.apache.cassandra.utils;

import java.util.concurrent.ForkJoinPool;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.atomic.AtomicLong;
import java.util.function.Supplier;
Expand All @@ -27,6 +28,12 @@
import org.slf4j.Logger;

import static org.apache.cassandra.utils.Clock.Global;
import com.github.benmanes.caffeine.cache.Cache;
import com.github.benmanes.caffeine.cache.Caffeine;
import com.github.benmanes.caffeine.cache.Expiry;
import com.github.benmanes.caffeine.cache.Ticker;

import static org.apache.cassandra.config.CassandraRelevantProperties.NOSPAM_LOGGER_MAX_STATEMENTS_PER_LOGGER;

/**
* Logging that limits each log statement to firing based on time since the statement last fired.
Expand All @@ -36,8 +43,11 @@
* result in the original time being used. No warning is provided if there is a mismatch.
*
* If the statement is cached and used to log directly then only a volatile read will be required in the common case.
* If the Logger is cached then there is a single concurrent hash map lookup + the volatile read.
* If neither the logger nor the statement is cached then it is two concurrent hash map lookups + the volatile read.
* If the Logger is cached then there is a single Caffeine cache lookup + the volatile read.
* If neither the logger nor the statement is cached then it is a NonBlockingHashMap lookup + a Caffeine cache lookup + the volatile read.
*
* The implementation uses Caffeine cache with time-based expiration to automatically evict log statements
* after their minimum interval has passed, preventing unbounded memory growth from dynamic log messages.
*
*/
public class NoSpamLogger
Expand All @@ -64,6 +74,9 @@ public static void unsafeSetClock(Clock clock)
CLOCK = clock;
}

@VisibleForTesting
static Ticker TICKER = Ticker.systemTicker();

public class NoSpamLogStatement extends AtomicLong
{
private static final long serialVersionUID = 1L;
Expand Down Expand Up @@ -157,6 +170,11 @@ public boolean error(Object... objects)
{
return NoSpamLogStatement.this.error(CLOCK.nanoTime(), objects);
}

public long expiry()
{
return minIntervalNanos;
}
}

private static final NonBlockingHashMap<Logger, NoSpamLogger> wrappedLoggers = new NonBlockingHashMap<>();
Expand All @@ -167,6 +185,28 @@ static void clearWrappedLoggersForTest()
wrappedLoggers.clear();
}

/**
* Forces eviction of entries from the {@link NoSpamLogStatement} cache for this logger instance.
* This is useful for testing to ensure cache size limits are enforced immediately.
*/
@VisibleForTesting
void cleanUpStatementsForTest()
{
lastMessage.cleanUp();
}

/**
* Returns the current size of the lastMessage cache for this logger instance.
* This is useful for testing cache eviction behavior.
*
* @return the number of log statements currently cached for this logger
*/
@VisibleForTesting
long getStatementsCount()
{
return lastMessage.estimatedSize();
}

public static NoSpamLogger getLogger(Logger logger, long minInterval, TimeUnit unit)
{
NoSpamLogger wrapped = wrappedLoggers.get(logger);
Expand Down Expand Up @@ -222,7 +262,41 @@ public static NoSpamLogStatement getStatement(Logger logger, String message, lon

private final Logger wrapped;
private final long minIntervalNanos;
private final NonBlockingHashMap<String, NoSpamLogStatement> lastMessage = new NonBlockingHashMap<>();

/**
* Cache of NoSpamLogStatement instances per NoSpamLogger instance.
* Bounded by size and time to prevent memory exhaustion from dynamic log messages.
* Uses Caffeine with W-TinyLFU eviction policy.
* Uses custom per-entry expiry based on each statement's minIntervalNanos.
*/
private final Cache<String, NoSpamLogStatement> lastMessage = Caffeine.newBuilder()
.maximumSize(NOSPAM_LOGGER_MAX_STATEMENTS_PER_LOGGER.getLong())
.expireAfter(new Expiry<String, NoSpamLogStatement>()
{
@Override
public long expireAfterCreate(String key, NoSpamLogStatement value, long currentTime)
{
return value.expiry();
}

@Override
public long expireAfterUpdate(String key, NoSpamLogStatement value,
long currentTime, long currentDuration)
{
return value.expiry();
}

@Override
public long expireAfterRead(String key, NoSpamLogStatement value,
long currentTime, long currentDuration)
{
return currentDuration;
}
})
Comment on lines +274 to +295

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

fwiw, you might prefer

expireAfter(Expiry.writing((String key, NoSpamLogStatement value) -> Duration.ofNanos(value.expiry()))

Copy link
Copy Markdown
Author

Choose a reason for hiding this comment

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

sure, but that might need upgrade to 3.2.2 first

.ticker(TICKER)
.executor(ForkJoinPool.commonPool())

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

@viktoriiakotovets I am not completely sure about this executor here. If you look what executors we use for Caffeine caches we never used this one. It would be appropriate if you did some basic research for the justification why we should use this executor specifically or change it to something more fitting.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

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

right, we don't want to use commonPool() (which can be limited in threads and easily starved).

@smiklosovic , which existing executor would you recommend ? or should we create a new one ?

@smiklosovic smiklosovic Aug 10, 2026

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

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

If we want a dedicated executor for this then I would go with org.apache.cassandra.concurrent.ExecutorFactory.Global.executorFactory().sequential("NoSpamLogger") otherwise I would go for ScheduledExecutors.optionalTasks or ImmediateExecutor.INSTANCE.

I lean towards a dedicated one because I do not like the fact that optionalTasks / INSTANCE would be used for executing stuff for a logger while that executor is used quite intensively for Cassandra itself and I do not want to mix it.

I would also most probably use executorFactory().withJmxInternal().sequential("NoSpamLogger"), withJMXInternal should give us the way how to query metrics of this executor via JMX so we have a visibility into what it is doing which is not a must but still a nice to have.

That being said, we would need to walk an extra mile here to be sure that we shutdown the executor upon shutdown of a node. AFAIK Caffeine is not shutting down the executor we hand it so we would need to be sure that we shut it down when not used anymore, likely in something like StorageService.drain() or similar.

btw isnt ForkJoinPool.commonPool() the default when we dont set it? So us setting it here is actually redundant. https://github.com/ben-manes/caffeine/blob/v3.1.8/caffeine/src/main/java/com/github/benmanes/caffeine/cache/Caffeine.java#L337

.recordStats()
.build();

private NoSpamLogger(Logger wrapped, long minInterval, TimeUnit timeUnit)
{
Expand Down Expand Up @@ -302,14 +376,6 @@ public NoSpamLogStatement getStatement(String s, long minIntervalNanos)

public NoSpamLogStatement getStatement(String key, String s, long minIntervalNanos)
{
NoSpamLogStatement statement = lastMessage.get(key);
if (statement == null)
{
statement = new NoSpamLogStatement(s, minIntervalNanos);
NoSpamLogStatement temp = lastMessage.putIfAbsent(key, statement);
if (temp != null)
statement = temp;
}
return statement;
return lastMessage.get(key, k -> new NoSpamLogStatement(s, minIntervalNanos));
}
}
Loading