Repository: sentry Updated Branches: refs/heads/master a3a199995 -> 3dab053e1
SENTRY-2309: Add relevant full snapshot timeline messages to std.out. ( Arjun Mishra reviewed by Kalyan Kumar Kalvagadda and Lina li) Project: http://git-wip-us.apache.org/repos/asf/sentry/repo Commit: http://git-wip-us.apache.org/repos/asf/sentry/commit/3dab053e Tree: http://git-wip-us.apache.org/repos/asf/sentry/tree/3dab053e Diff: http://git-wip-us.apache.org/repos/asf/sentry/diff/3dab053e Branch: refs/heads/master Commit: 3dab053e18b4197e97f4a654e2707cb1eb673047 Parents: a3a1999 Author: Kalyan Kumar Kalvagadda <kkal...@cloudera.com> Authored: Wed Jul 25 16:18:20 2018 -0500 Committer: Kalyan Kumar Kalvagadda <kkal...@cloudera.com> Committed: Wed Jul 25 16:18:20 2018 -0500 ---------------------------------------------------------------------- .../sentry/hdfs/SentryAuthorizationInfo.java | 7 +++-- .../apache/sentry/hdfs/DBUpdateForwarder.java | 20 ++++++++++--- .../sentry/api/common/SentryServiceUtil.java | 12 ++++++++ .../db/service/persistent/HMSFollower.java | 30 +++++++++++++------- .../service/thrift/FullUpdateInitializer.java | 19 ++++++++----- .../sentry/service/thrift/SentryHMSClient.java | 10 +++++-- 6 files changed, 73 insertions(+), 25 deletions(-) ---------------------------------------------------------------------- http://git-wip-us.apache.org/repos/asf/sentry/blob/3dab053e/sentry-hdfs/sentry-hdfs-namenode-plugin/src/main/java/org/apache/sentry/hdfs/SentryAuthorizationInfo.java ---------------------------------------------------------------------- diff --git a/sentry-hdfs/sentry-hdfs-namenode-plugin/src/main/java/org/apache/sentry/hdfs/SentryAuthorizationInfo.java b/sentry-hdfs/sentry-hdfs-namenode-plugin/src/main/java/org/apache/sentry/hdfs/SentryAuthorizationInfo.java index 61b0d10..9dae035 100644 --- a/sentry-hdfs/sentry-hdfs-namenode-plugin/src/main/java/org/apache/sentry/hdfs/SentryAuthorizationInfo.java +++ b/sentry-hdfs/sentry-hdfs-namenode-plugin/src/main/java/org/apache/sentry/hdfs/SentryAuthorizationInfo.java @@ -31,6 +31,7 @@ import org.apache.hadoop.conf.Configuration; import org.apache.hadoop.fs.Path; import org.apache.hadoop.fs.permission.AclEntry; import org.apache.hadoop.util.StringUtils; +import org.apache.sentry.api.common.SentryServiceUtil; import org.apache.sentry.hdfs.Updateable.Update; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -195,10 +196,12 @@ public class SentryAuthorizationInfo implements Runnable { V newUpdateable = updateable; if (!updates.isEmpty()) { if (updates.get(0).hasFullImage()) { - LOG.debug(String.format("Process Update : FULL IMAGE [%s][%d][%d]", + String logMessage = String.format("Process Update : FULL IMAGE [%s][%d][%d]", newUpdateable.getClass().getSimpleName(), updates.get(0).getSeqNum(), - updates.get(0).getImgNum())); + updates.get(0).getImgNum()); + LOG.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); newUpdateable = (V)newUpdateable.updateFull(updates.remove(0)); } // Any more elements ? http://git-wip-us.apache.org/repos/asf/sentry/blob/3dab053e/sentry-hdfs/sentry-hdfs-service/src/main/java/org/apache/sentry/hdfs/DBUpdateForwarder.java ---------------------------------------------------------------------- diff --git a/sentry-hdfs/sentry-hdfs-service/src/main/java/org/apache/sentry/hdfs/DBUpdateForwarder.java b/sentry-hdfs/sentry-hdfs-service/src/main/java/org/apache/sentry/hdfs/DBUpdateForwarder.java index 065adb7..d47b9f7 100644 --- a/sentry-hdfs/sentry-hdfs-service/src/main/java/org/apache/sentry/hdfs/DBUpdateForwarder.java +++ b/sentry-hdfs/sentry-hdfs-service/src/main/java/org/apache/sentry/hdfs/DBUpdateForwarder.java @@ -25,6 +25,7 @@ import java.util.List; import java.util.Map; import javax.annotation.concurrent.ThreadSafe; +import org.apache.sentry.api.common.SentryServiceUtil; import org.apache.sentry.core.model.db.AccessConstants; import org.apache.sentry.hdfs.service.thrift.TPrivilegeEntity; import org.apache.sentry.service.thrift.SentryServiceState; @@ -93,11 +94,17 @@ class DBUpdateForwarder<K extends Updateable.Update> { if (curImgNum > imgNum) { // In case a new HMS snapshot has been processed, then return a full paths image. + String logMessage = String.format("(%s) Current image num %d is greater than requested " + + "image num %d. Request a full update", retrieverType, curImgNum, imgNum); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); List<K>fullImage = retrieveFullImage(); //Only log if we have received full image if( !fullImage.isEmpty()) { - LOGGER.info("({}) A newer full update with image number {} was found and being sent to HDFS", - retrieverType, curImgNum); + logMessage = String.format("(%s) A newer full update with image number %d " + + "is less than requested image number %d. Send full update to HDFS", retrieverType, curImgNum, imgNum); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); } return fullImage; } @@ -128,11 +135,16 @@ class DBUpdateForwarder<K extends Updateable.Update> { // If the sequence number is < 0 or the requested delta is not available, then we // return a full update. + String logMessage = String.format("(%s) Requested sequence number %d is less than 0 or " + + "requested deltas for that sequence number are not available. Fetch a full update", retrieverType, seqNum); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); List<K>fullImage = retrieveFullImage(); //Only log if we have received full image if( fullImage != null && !fullImage.isEmpty()) { - LOGGER.info("({}) A full update is returned due to an unavailable sequence number: {}", - retrieverType, seqNum); + logMessage = String.format("(%s) A full update is returned due to an unavailable sequence number: %d", retrieverType, seqNum); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); } return fullImage; } http://git-wip-us.apache.org/repos/asf/sentry/blob/3dab053e/sentry-service/sentry-service-api/src/main/java/org/apache/sentry/api/common/SentryServiceUtil.java ---------------------------------------------------------------------- diff --git a/sentry-service/sentry-service-api/src/main/java/org/apache/sentry/api/common/SentryServiceUtil.java b/sentry-service/sentry-service-api/src/main/java/org/apache/sentry/api/common/SentryServiceUtil.java index 719e616..8cdbde4 100644 --- a/sentry-service/sentry-service-api/src/main/java/org/apache/sentry/api/common/SentryServiceUtil.java +++ b/sentry-service/sentry-service-api/src/main/java/org/apache/sentry/api/common/SentryServiceUtil.java @@ -19,7 +19,9 @@ package org.apache.sentry.api.common; +import java.text.SimpleDateFormat; import java.util.Arrays; +import java.util.Date; import java.util.HashMap; import java.util.List; import java.util.Map; @@ -319,4 +321,14 @@ public final class SentryServiceUtil { private static boolean isNULL(String s) { return Strings.isNullOrEmpty(s) || s.equals("__NULL__"); } + + public static String getCurrentTimeStampWithMessage(String logMessage) { + String date = new SimpleDateFormat("yyyy.MM.dd.HH.mm.ss").format(new Date()); + + if(StringUtils.isBlank(logMessage)) { + return date; + } + + return String.format("%s: %s", date, logMessage); + } } http://git-wip-us.apache.org/repos/asf/sentry/blob/3dab053e/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/provider/db/service/persistent/HMSFollower.java ---------------------------------------------------------------------- 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 7667c47..fb826cf 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 @@ -273,16 +273,19 @@ public class HMSFollower implements Runnable, AutoCloseable, PubSub.Subscriber { */ private boolean isFullSnapshotRequired(long latestSentryNotificationId) throws Exception { if (sentryStore.isHmsNotificationEmpty()) { - LOGGER.debug("Sentry Store has no HMS Notifications. Create Full HMS Snapshot. " - + "latest sentry notification Id = {}", latestSentryNotificationId); + String logMessage = String.format("Sentry Store has no HMS Notifications. Create Full HMS Snapshot. " + + "latest sentry notification Id = %d", latestSentryNotificationId); + LOGGER.debug(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); return true; } // Once HDFS sync is enabled, and if MAuthzPathsMapping // table is still empty, we need to request a full snapshot if (sentryStore.isAuthzPathsSnapshotEmpty()) { - LOGGER.debug("HDFSSync is enabled and MAuthzPathsMapping table is empty." + - " Need to request a full snapshot"); + String logMessage = String.format("HDFSSync is enabled and MAuthzPathsMapping table is empty. Need to request a full snapshot", latestSentryNotificationId); + LOGGER.debug(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); return true; } @@ -293,10 +296,11 @@ public class HMSFollower implements Runnable, AutoCloseable, PubSub.Subscriber { // check if forced full update is required, reset update flag to false // to only do it once per forced full update request. if (fullUpdateHMS.compareAndSet(true, false)) { - LOGGER.info(FULL_UPDATE_TRIGGER + "initiating full HMS snapshot request"); + String logMessage = FULL_UPDATE_TRIGGER + "initiating full HMS snapshot request"; + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); return true; } - return false; } @@ -357,8 +361,10 @@ public class HMSFollower implements Runnable, AutoCloseable, PubSub.Subscriber { long firstNotificationId = eventList.get(0).getEventId(); if (firstNotificationId > (latestProcessedId + 1)) { - LOGGER.info("First HMS event notification Id = {} is greater than latest Sentry processed" - + "notification Id = {} + 1. Need to request a full HMS snapshot.", firstNotificationId, latestProcessedId); + String logMessage = String.format("First HMS event notification Id = %d is greater than latest Sentry processed" + + "notification Id = %d + 1. Need to request a full HMS snapshot.", firstNotificationId, latestProcessedId); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); return true; } @@ -395,7 +401,9 @@ public class HMSFollower implements Runnable, AutoCloseable, PubSub.Subscriber { } try { if (hdfsSyncEnabled) { - LOGGER.info("Persisting full snapshot for notification Id = {}", snapshotInfo.getId()); + String logMessage = String.format("Persisting full snapshot for notification Id = %d", snapshotInfo.getId()); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); sentryStore.persistFullPathsImage(snapshotInfo.getPathImage(), snapshotInfo.getId()); } else { // We need to persist latest notificationID for next poll @@ -412,7 +420,9 @@ public class HMSFollower implements Runnable, AutoCloseable, PubSub.Subscriber { wakeUpWaitingClientsForSync(snapshotInfo.getId()); // HMSFollower connected to HMS and it finished full snapshot if that was required // Log this message only once - LOGGER.info("Sentry HMS support is ready"); + String logMessage = String.format("Create full snapshot process is complete: snapshot Id %d", snapshotInfo.getId()); + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); return snapshotInfo.getId(); } catch(Exception failure) { LOGGER.error("Received exception while creating HMS path full snapshot "); http://git-wip-us.apache.org/repos/asf/sentry/blob/3dab053e/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/FullUpdateInitializer.java ---------------------------------------------------------------------- diff --git a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/FullUpdateInitializer.java b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/FullUpdateInitializer.java index 992d8ab..3e27d1b 100644 --- a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/FullUpdateInitializer.java +++ b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/FullUpdateInitializer.java @@ -299,15 +299,20 @@ public final class FullUpdateInitializer implements AutoCloseable { } LOGGER.debug("Fetched partitions for db = {}, table = {}", - dbName, tblName); - + dbName, tblName); Collection<String> partitionNames = new ArrayList<>(tblParts.size()); - for (Partition part : tblParts) { - String partPath = pathFromURI(part.getSd().getLocation()); - if (partPath != null) { - partitionNames.add(partPath.intern()); + + for (Partition part : tblParts) { + try { + String partPath = pathFromURI(part.getSd().getLocation()); + if (partPath != null) { + partitionNames.add(partPath.intern()); + } + } catch(Exception e) { + LOGGER.error("Exception while fetching partitions for db = {} table = {}", dbName, tblName); + throw e; + } } - } return new ObjectMapping(authName, partitionNames); } } http://git-wip-us.apache.org/repos/asf/sentry/blob/3dab053e/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/SentryHMSClient.java ---------------------------------------------------------------------- diff --git a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/SentryHMSClient.java b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/SentryHMSClient.java index 12266cb..cfb0d78 100644 --- a/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/SentryHMSClient.java +++ b/sentry-service/sentry-service-server/src/main/java/org/apache/sentry/service/thrift/SentryHMSClient.java @@ -30,6 +30,7 @@ import org.apache.hadoop.hive.metastore.api.MetaException; import org.apache.hadoop.hive.metastore.api.NotificationEvent; import org.apache.hadoop.hive.metastore.api.NotificationEventResponse; import org.apache.hadoop.hive.metastore.messaging.MessageDeserializer; +import org.apache.sentry.api.common.SentryServiceUtil; import org.apache.sentry.binding.metastore.messaging.json.SentryJSONMessageDeserializer; import org.apache.sentry.core.common.utils.SentryConstants; import org.apache.sentry.provider.db.service.persistent.PathsImage; @@ -242,12 +243,17 @@ public class SentryHMSClient implements AutoCloseable { * corresponding to that name. */ private Map<String, Collection<String>> fetchFullUpdate() throws Exception{ - LOGGER.info("Request full HMS snapshot"); + String logMessage = "Request full HMS snapshot"; + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); + try (FullUpdateInitializer updateInitializer = new FullUpdateInitializer(hiveConnectionFactory, conf); Context context = updateTimer.time()) { Map<String, Collection<String>> pathsUpdate = updateInitializer.getFullHMSSnapshot(); - LOGGER.info("Obtained full HMS snapshot"); + logMessage = "Obtained full HMS snapshot"; + LOGGER.info(logMessage); + System.out.println(SentryServiceUtil.getCurrentTimeStampWithMessage(logMessage)); return pathsUpdate; } catch (Exception exception) { failedSnapshotsCount.inc();