This is an automated email from the ASF dual-hosted git repository.
diqiu50 pushed a commit to branch main
in repository https://gitbox.apache.org/repos/asf/gravitino.git
The following commit(s) were added to refs/heads/main by this push:
new 6842f00b74 [MINOR] improvement(cache): Add logs for Caffeine cache
removals (#12043)
6842f00b74 is described below
commit 6842f00b74dc69434059aec2e4f4e34f08f6f6c2
Author: Qi Yu <[email protected]>
AuthorDate: Mon Jul 20 09:47:43 2026 +0800
[MINOR] improvement(cache): Add logs for Caffeine cache removals (#12043)
### What changes were proposed in this pull request?
Add DEBUG-level removal logs to all production Caffeine removal
listeners. The logs include cache-specific keys or identifiers and the
removal cause, while avoiding cached values that may be sensitive or
large.
### Why are the changes needed?
Cache expiration, eviction, replacement, and explicit invalidation were
not consistently observable across modules. Consistent DEBUG-level logs
make cache lifecycle and resource cleanup easier to diagnose.
Fix: N/A
### Does this PR introduce _any_ user-facing change?
Yes. Cache removal logs now consistently use DEBUG level and include
cache keys or identifiers and removal causes. There are no API or
configuration changes.
### How was this patch tested?
- Ran `./gradlew spotlessApply`.
- Ran targeted unit tests for the affected core, server-common,
catalog-fileset, hive-metastore-common, filesystem-hadoop3,
iceberg-common, and iceberg-rest-server modules.
- After standardizing the log level, reran targeted tests for core,
server-common, catalog-fileset, and filesystem-hadoop3.
- Attempted `./gradlew test -PskipITs`; an unrelated
`TestJDBCBackendBatchGet` PostgreSQL case failed because the container
reported `No space left on device`.
---
.../catalog/fileset/FilesetCatalogOperations.java | 9 ++++++++-
.../org/apache/gravitino/hive/CachedClientPool.java | 10 +++++++++-
.../filesystem/hadoop/BaseGVFSOperations.java | 20 ++++++++++++++++++--
.../apache/gravitino/cache/CaffeineEntityCache.java | 4 ++--
.../org/apache/gravitino/catalog/CatalogManager.java | 2 +-
.../apache/gravitino/credential/CredentialCache.java | 5 +++--
.../storage/LancePartitionStatisticStorage.java | 4 ++++
.../common/utils/IcebergHiveCachedClientPool.java | 9 +++++----
.../service/IcebergCatalogWrapperManager.java | 5 ++++-
.../jcasbin/JcasbinLoadedRolesCache.java | 8 ++++++++
10 files changed, 62 insertions(+), 14 deletions(-)
diff --git
a/catalogs/catalog-fileset/src/main/java/org/apache/gravitino/catalog/fileset/FilesetCatalogOperations.java
b/catalogs/catalog-fileset/src/main/java/org/apache/gravitino/catalog/fileset/FilesetCatalogOperations.java
index 4b86c37fd6..329acf7495 100644
---
a/catalogs/catalog-fileset/src/main/java/org/apache/gravitino/catalog/fileset/FilesetCatalogOperations.java
+++
b/catalogs/catalog-fileset/src/main/java/org/apache/gravitino/catalog/fileset/FilesetCatalogOperations.java
@@ -280,7 +280,14 @@ public class FilesetCatalogOperations extends
ManagedSchemaOperations
Caffeine.newBuilder()
.expireAfterAccess(1, TimeUnit.HOURS)
.removalListener(
- (ignored, value, cause) -> {
+ (key, value, cause) -> {
+ FileSystemCacheKey cacheKey = (FileSystemCacheKey) key;
+ LOG.debug(
+ "Removing FileSystem from cache: scheme={},
authority={}, user={}, cause={}",
+ cacheKey == null ? null : cacheKey.scheme,
+ cacheKey == null ? null : cacheKey.authority,
+ cacheKey == null ? null : cacheKey.currentUser,
+ cause);
try {
((FileSystem) value).close();
} catch (IOException e) {
diff --git
a/catalogs/hive-metastore-common/src/main/java/org/apache/gravitino/hive/CachedClientPool.java
b/catalogs/hive-metastore-common/src/main/java/org/apache/gravitino/hive/CachedClientPool.java
index 62a38819e1..7d93a25de7 100644
---
a/catalogs/hive-metastore-common/src/main/java/org/apache/gravitino/hive/CachedClientPool.java
+++
b/catalogs/hive-metastore-common/src/main/java/org/apache/gravitino/hive/CachedClientPool.java
@@ -37,6 +37,8 @@ import org.apache.gravitino.hive.client.HiveClient;
import org.apache.gravitino.utils.ClientPool;
import org.apache.gravitino.utils.PrincipalUtils;
import org.immutables.value.Value;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
/**
* Referred from Apache Iceberg's CachedClientPool implementation
@@ -49,6 +51,8 @@ import org.immutables.value.Value;
* <p>A ClientPool that caches the underlying HiveClientPool instances.
*/
public class CachedClientPool implements ClientPool<HiveClient,
GravitinoRuntimeException> {
+ private static final Logger LOG =
LoggerFactory.getLogger(CachedClientPool.class);
+
private static final ClientPropertiesMetadata PROPERTIES_METADATA =
new ClientPropertiesMetadata();
@@ -76,7 +80,11 @@ public class CachedClientPool implements
ClientPool<HiveClient, GravitinoRuntime
this.clientPoolCache =
Caffeine.newBuilder()
.expireAfterAccess(evictionInterval, TimeUnit.MILLISECONDS)
- .removalListener((ignored, value, cause) -> ((HiveClientPool)
value).close())
+ .removalListener(
+ (key, value, cause) -> {
+ LOG.debug("Removing HiveClientPool from cache: key={},
cause={}", key, cause);
+ ((HiveClientPool) value).close();
+ })
.scheduler(Scheduler.forScheduledExecutorService(scheduler))
.build();
}
diff --git
a/clients/filesystem-hadoop3/src/main/java/org/apache/gravitino/filesystem/hadoop/BaseGVFSOperations.java
b/clients/filesystem-hadoop3/src/main/java/org/apache/gravitino/filesystem/hadoop/BaseGVFSOperations.java
index 06368c04c4..bece7047f5 100644
---
a/clients/filesystem-hadoop3/src/main/java/org/apache/gravitino/filesystem/hadoop/BaseGVFSOperations.java
+++
b/clients/filesystem-hadoop3/src/main/java/org/apache/gravitino/filesystem/hadoop/BaseGVFSOperations.java
@@ -925,6 +925,17 @@ public abstract class BaseGVFSOperations implements
Closeable {
1,
newDaemonThreadFactory("gvfs-filesystem-cache-cleaner"))))
.removalListener(
(key, value, cause) -> {
+ FileSystemCacheKey cacheKey = (FileSystemCacheKey) key;
+ String user =
+ cacheKey == null || cacheKey.ugi() == null
+ ? null
+ : cacheKey.ugi().getUserName();
+ LOG.debug(
+ "Removing FileSystem from cache: scheme={},
authority={}, user={}, cause={}",
+ cacheKey == null ? null : cacheKey.scheme(),
+ cacheKey == null ? null : cacheKey.authority(),
+ user,
+ cause);
if (closeOnEviction) {
FileSystem fs = (FileSystem) value;
if (fs != null) {
@@ -933,13 +944,18 @@ public abstract class BaseGVFSOperations implements
Closeable {
try {
fs.close();
} catch (IOException e) {
- LOG.error("Cannot close the file system for fileset:
{}", key, e);
+ LOG.error(
+ "Failed to close cached FileSystem: scheme={},
authority={}, user={}, cause={}",
+ cacheKey == null ? null : cacheKey.scheme(),
+ cacheKey == null ? null : cacheKey.authority(),
+ user,
+ cause,
+ e);
}
}
return;
}
// Default: do not close on eviction; close is deferred to
GVFS shutdown.
- LOG.debug("FileSystem evicted from cache (key={},
cause={})", key, cause);
});
cacheBuilder.expireAfterAccess(evictionMillsAfterAccess,
TimeUnit.MILLISECONDS);
return cacheBuilder.build();
diff --git
a/core/src/main/java/org/apache/gravitino/cache/CaffeineEntityCache.java
b/core/src/main/java/org/apache/gravitino/cache/CaffeineEntityCache.java
index fd785edf5a..7d9ba181b7 100644
--- a/core/src/main/java/org/apache/gravitino/cache/CaffeineEntityCache.java
+++ b/core/src/main/java/org/apache/gravitino/cache/CaffeineEntityCache.java
@@ -127,6 +127,7 @@ public class CaffeineEntityCache extends BaseEntityCache {
.executor(CLEANUP_EXECUTOR)
.removalListener(
(key, value, cause) -> {
+ LOG.debug("Removed entity cache entry, key={}, cause={}", key,
cause);
if (cause == RemovalCause.EXPLICIT || cause ==
RemovalCause.REPLACED) {
return;
}
@@ -134,9 +135,8 @@ public class CaffeineEntityCache extends BaseEntityCache {
invalidateExpiredItem(key);
} catch (Throwable t) {
LOG.error(
- "Failed to remove entity key={} value={} from cache
asynchronously, cause={}",
+ "Failed to remove entity key={} from cache asynchronously,
cause={}",
key,
- value,
cause,
t);
}
diff --git
a/core/src/main/java/org/apache/gravitino/catalog/CatalogManager.java
b/core/src/main/java/org/apache/gravitino/catalog/CatalogManager.java
index e26e28d3a9..75a8c0f72a 100644
--- a/core/src/main/java/org/apache/gravitino/catalog/CatalogManager.java
+++ b/core/src/main/java/org/apache/gravitino/catalog/CatalogManager.java
@@ -325,12 +325,12 @@ public class CatalogManager implements CatalogDispatcher,
Closeable {
.expireAfterAccess(cacheEvictionIntervalInMs,
TimeUnit.MILLISECONDS)
.removalListener(
(k, v, c) -> {
+ LOG.debug("Removed catalog cache entry, identifier={},
cause={}", k, c);
for (Consumer<NameIdentifier> listener : removalListeners) {
if (k != null) {
listener.accept((NameIdentifier) k);
}
}
- LOG.info("Closing catalog {}.", k);
((CatalogWrapper) v).close();
})
.scheduler(
diff --git
a/core/src/main/java/org/apache/gravitino/credential/CredentialCache.java
b/core/src/main/java/org/apache/gravitino/credential/CredentialCache.java
index 976a50b0f0..08c4d2d47a 100644
--- a/core/src/main/java/org/apache/gravitino/credential/CredentialCache.java
+++ b/core/src/main/java/org/apache/gravitino/credential/CredentialCache.java
@@ -90,8 +90,9 @@ public class CredentialCache<T> implements Closeable {
.expireAfter(new CredentialExpireTimeCalculator(cacheExpireRatio))
.maximumSize(cacheSize)
.removalListener(
- (cacheKey, credential, c) ->
- LOG.debug("Credential expire, cache key: {}.", cacheKey))
+ (cacheKey, credential, cause) ->
+ LOG.debug(
+ "Removed credential cache entry, cacheKey={},
cause={}", cacheKey, cause))
.build();
}
diff --git
a/core/src/main/java/org/apache/gravitino/stats/storage/LancePartitionStatisticStorage.java
b/core/src/main/java/org/apache/gravitino/stats/storage/LancePartitionStatisticStorage.java
index 5755d1bd56..98a4d91559 100644
---
a/core/src/main/java/org/apache/gravitino/stats/storage/LancePartitionStatisticStorage.java
+++
b/core/src/main/java/org/apache/gravitino/stats/storage/LancePartitionStatisticStorage.java
@@ -208,6 +208,10 @@ public class LancePartitionStatisticStorage implements
PartitionStatisticStorage
.removalListener(
(RemovalListener<Long, DatasetHolder>)
(key, value, cause) -> {
+ LOG.debug(
+ "Removed Lance dataset cache entry,
tableId={}, cause={}",
+ key,
+ cause);
if (value != null && cause !=
RemovalCause.EXPLICIT) {
closeDatasetHolder(value);
}
diff --git
a/iceberg/iceberg-common/src/main/java/org/apache/gravitino/iceberg/common/utils/IcebergHiveCachedClientPool.java
b/iceberg/iceberg-common/src/main/java/org/apache/gravitino/iceberg/common/utils/IcebergHiveCachedClientPool.java
index 9c15639d1d..cefbdffaca 100644
---
a/iceberg/iceberg-common/src/main/java/org/apache/gravitino/iceberg/common/utils/IcebergHiveCachedClientPool.java
+++
b/iceberg/iceberg-common/src/main/java/org/apache/gravitino/iceberg/common/utils/IcebergHiveCachedClientPool.java
@@ -131,12 +131,13 @@ public class IcebergHiveCachedClientPool
.expireAfterAccess(evictionInterval, TimeUnit.MILLISECONDS)
.removalListener(
(key, value, cause) -> {
+ Key cacheKey = (Key) key;
+ LOG.debug(
+ "Removing HiveClientPool from cache: key={}, cause={}",
+ cacheKey == null ? null : cacheKey.elements(),
+ cause);
HiveClientPool hiveClientPool = (HiveClientPool) value;
if (hiveClientPool != null) {
- LOG.info(
- "Removing an expired HiveClientPool instance: {} for
Key: {}",
- hiveClientPool,
- key);
hiveClientPool.close();
}
})
diff --git
a/iceberg/iceberg-rest-server/src/main/java/org/apache/gravitino/iceberg/service/IcebergCatalogWrapperManager.java
b/iceberg/iceberg-rest-server/src/main/java/org/apache/gravitino/iceberg/service/IcebergCatalogWrapperManager.java
index f9561e3f8f..c524d074fa 100644
---
a/iceberg/iceberg-rest-server/src/main/java/org/apache/gravitino/iceberg/service/IcebergCatalogWrapperManager.java
+++
b/iceberg/iceberg-rest-server/src/main/java/org/apache/gravitino/iceberg/service/IcebergCatalogWrapperManager.java
@@ -65,7 +65,10 @@ public class IcebergCatalogWrapperManager implements
AutoCloseable {
.removalListener(
(k, v, c) -> {
String catalogName = (String) k;
- LOG.info("Remove IcebergCatalogWrapper cache {}.",
catalogName);
+ LOG.debug(
+ "Removing IcebergCatalogWrapper from cache: catalog={},
cause={}",
+ catalogName,
+ c);
closeIcebergCatalogWrapper((IcebergCatalogWrapper) v);
})
.scheduler(
diff --git
a/server-common/src/main/java/org/apache/gravitino/server/authorization/jcasbin/JcasbinLoadedRolesCache.java
b/server-common/src/main/java/org/apache/gravitino/server/authorization/jcasbin/JcasbinLoadedRolesCache.java
index 0205ec1608..6799fe7dcc 100644
---
a/server-common/src/main/java/org/apache/gravitino/server/authorization/jcasbin/JcasbinLoadedRolesCache.java
+++
b/server-common/src/main/java/org/apache/gravitino/server/authorization/jcasbin/JcasbinLoadedRolesCache.java
@@ -25,6 +25,8 @@ import java.util.Optional;
import java.util.concurrent.TimeUnit;
import org.apache.gravitino.cache.GravitinoCache;
import org.casbin.jcasbin.main.Enforcer;
+import org.slf4j.Logger;
+import org.slf4j.LoggerFactory;
/**
* A {@link GravitinoCache} of {@code roleId -> updated_at} that synchronously
deletes the role's
@@ -37,6 +39,8 @@ import org.casbin.jcasbin.main.Enforcer;
*/
class JcasbinLoadedRolesCache implements GravitinoCache<Long, Long> {
+ private static final Logger LOG =
LoggerFactory.getLogger(JcasbinLoadedRolesCache.class);
+
private final Cache<Long, Long> cache;
JcasbinLoadedRolesCache(long ttlMs, long maxSize, Enforcer allowEnforcer,
Enforcer denyEnforcer) {
@@ -47,6 +51,10 @@ class JcasbinLoadedRolesCache implements
GravitinoCache<Long, Long> {
.executor(Runnable::run)
.removalListener(
(Long roleId, Long value, RemovalCause cause) -> {
+ LOG.debug(
+ "Removed JCasbin loaded role cache entry, roleId={},
cause={}",
+ roleId,
+ cause);
if (roleId != null && cause != RemovalCause.REPLACED) {
allowEnforcer.deleteRole(String.valueOf(roleId));
denyEnforcer.deleteRole(String.valueOf(roleId));
