SENTRY-2419: Log where sentry stands in the process of persisting the snpashot (Arjun Mishra reviewed by Na Li and Sergio Pena)
Change-Id: I0fa1af7ab45a3a27d9c9984fa96634f89f28316c
diff --git a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/api/service/thrift/SentryMetrics.java b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/api/service/thrift/SentryMetrics.java
index d34340c..214d78c 100644
--- a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/api/service/thrift/SentryMetrics.java
+++ b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/api/service/thrift/SentryMetrics.java
@@ -175,8 +175,12 @@
sentryStore.getLastPathsSnapshotIdGauge());
addGauge(SentryStore.class, "hms.perm.change.id",
sentryStore.getPermChangeIdGauge());
- addGauge(SentryStore.class, "hms.psth.change.id",
+ addGauge(SentryStore.class, "hms.path.change.id",
sentryStore.getPathChangeIdGauge());
+ addGauge(SentryStore.class, "hms.authz_objects_count",
+ sentryStore.getAuthzObjectsCountGauge());
+ addGauge(SentryStore.class, "hms.authz_paths_count",
+ sentryStore.getAuthzPathsCountGauge());
gaugesAdded = true;
}
}
diff --git a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/HMSFollower.java b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/HMSFollower.java
index b6dca7a..e5cb5b0 100644
--- a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/HMSFollower.java
+++ b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/HMSFollower.java
@@ -419,7 +419,7 @@
}
try {
if (hdfsSyncEnabled) {
- String logMessage = String.format("Persisting full snapshot for notification Id = %d", snapshotInfo.getId());
+ String logMessage = String.format("Persisting full snapshot for notification Id = %d. Number of authorization objects = %d", snapshotInfo.getId(), snapshotInfo.getPathImage().size());
LOGGER.info(logMessage);
System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage));
sentryStore.persistFullPathsImage(snapshotInfo.getPathImage(), snapshotInfo.getId());
diff --git a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStore.java b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStore.java
index 7a736ca..29f83a8 100644
--- a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStore.java
+++ b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStore.java
@@ -189,6 +189,9 @@
*/
private final CounterWait counterWait;
+ // 5 min interval
+ private final long printSnapshotPersistTimeInterval = 300000;
+
private final boolean ownerPrivilegeWithGrant;
public static Properties getDataNucleusProperties(Configuration conf)
throws SentrySiteConfigurationException, IOException {
@@ -475,6 +478,34 @@
}
/**
+ * @return Number of authz objects persisted
+ */
+ public Gauge<Long> getAuthzObjectsCountGauge() {
+ return () -> {
+ try {
+ return getCount(MAuthzPathsMapping.class);
+ } catch (Exception e) {
+ LOGGER.error("Cannot read AUTHZ_PATHS_MAPPING table", e);
+ return NOTIFICATION_UNKNOWN;
+ }
+ };
+ }
+
+ /**
+ * @return Number of authz paths persisted
+ */
+ public Gauge<Long> getAuthzPathsCountGauge() {
+ return () -> {
+ try {
+ return getCount(MPath.class);
+ } catch (Exception e) {
+ LOGGER.error("Cannot read AUTHZ_PATH table", e);
+ return NOTIFICATION_UNKNOWN;
+ }
+ };
+ }
+
+ /**
* @return number of threads waiting for HMS notifications to be processed
*/
public Gauge<Integer> getHMSWaitersCountGauge() {
@@ -3390,6 +3421,14 @@
final long notificationID) throws Exception {
tm.executeTransactionWithRetry(
pm -> {
+
+ int totalNumberOfObjectsToPersist = authzPaths.size();
+ int totalNumberOfPathsToPersist = authzPaths.values().stream().mapToInt(Collection::size).sum();
+ int objectsPersistedCount = 0, pathsPersistedCount = 0;
+
+ logPersistingFullSnapshotState(totalNumberOfObjectsToPersist,
+ totalNumberOfPathsToPersist, objectsPersistedCount, pathsPersistedCount);
+
pm.setDetachAllOnCommit(false); // No need to detach objects
deleteNotificationsSince(pm, notificationID + 1);
@@ -3401,13 +3440,42 @@
long nextSnapshotID = snapshotID + 1;
pm.makePersistent(new MAuthzPathsSnapshotId(nextSnapshotID));
LOGGER.info("Attempting to commit new HMS snapshot with ID = {}", nextSnapshotID);
+
+ long lastProgressTime = System.currentTimeMillis();
+
for (Map.Entry<String, Collection<String>> authzPath : authzPaths.entrySet()) {
pm.makePersistent(new MAuthzPathsMapping(nextSnapshotID, authzPath.getKey(), authzPath.getValue()));
+
+ objectsPersistedCount++;
+ pathsPersistedCount = pathsPersistedCount + authzPath.getValue().size();
+
+ long currentTime = System.currentTimeMillis();
+ if ((currentTime - lastProgressTime) > printSnapshotPersistTimeInterval) {
+
+ logPersistingFullSnapshotState(totalNumberOfObjectsToPersist,
+ totalNumberOfPathsToPersist, objectsPersistedCount, pathsPersistedCount);
+
+ lastProgressTime = currentTime;
+ }
}
return null;
});
}
+ public void logPersistingFullSnapshotState(int totalNumberOfObjectsToPersist,
+ int totalNumberOfPathsToPersist, int objectsPersistedCount, int pathsPersistedCount) {
+
+ LOGGER.info(String.format("Persisting HMS Paths on Snapshot: "
+ + "authz_objs_persisted=%d(%.2f%%) authz_paths_persisted=%d(%.2f%%) "
+ + "authz_objs_total=%d authz_paths_total=%d",
+ objectsPersistedCount,
+ totalNumberOfObjectsToPersist > 0 ? 100 * ((double) objectsPersistedCount
+ / totalNumberOfObjectsToPersist) : 0,
+ pathsPersistedCount, totalNumberOfPathsToPersist > 0 ? 100 * ((double) pathsPersistedCount
+ / totalNumberOfPathsToPersist) : 0,
+ totalNumberOfObjectsToPersist, totalNumberOfPathsToPersist));
+ }
+
/**
* Get the last authorization path snapshot ID persisted.
* Always executed in the transaction context.
diff --git a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStoreInterface.java b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStoreInterface.java
index 3a68eb6..6217719 100644
--- a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStoreInterface.java
+++ b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/SentryStoreInterface.java
@@ -473,6 +473,16 @@
Gauge<Long> getPathChangeIdGauge();
/**
+ * @return Number of objects persisted
+ */
+ Gauge<Long> getAuthzObjectsCountGauge();
+
+ /**
+ * @return Number of objects persisted
+ */
+ Gauge<Long> getAuthzPathsCountGauge();
+
+ /**
* Assign a given role to a set of groups. As well as persist the corresponding
* permission change to MSentryPermChange table in a single transaction.
*
diff --git a/sentry-service/sentry-service-server/src/test/java/org/apache/sentry/api/service/thrift/TestSentryPolicyStoreProcessor.java b/sentry-service/sentry-service-server/src/test/java/org/apache/sentry/api/service/thrift/TestSentryPolicyStoreProcessor.java
index 059621a..16ff79e 100644
--- a/sentry-service/sentry-service-server/src/test/java/org/apache/sentry/api/service/thrift/TestSentryPolicyStoreProcessor.java
+++ b/sentry-service/sentry-service-server/src/test/java/org/apache/sentry/api/service/thrift/TestSentryPolicyStoreProcessor.java
@@ -137,6 +137,18 @@
return 0L;
}
});
+ Mockito.when(sentryStore.getAuthzObjectsCountGauge()).thenReturn(new Gauge< Long >() {
+ @Override
+ public Long getValue() {
+ return 0L;
+ }
+ });
+ Mockito.when(sentryStore.getAuthzPathsCountGauge()).thenReturn(new Gauge< Long >() {
+ @Override
+ public Long getValue() {
+ return 0L;
+ }
+ });
Mockito.doAnswer((invocation) -> {
long id = (long) invocation.getArguments()[0];
