You are viewing a plain text version of this content. The canonical link for it is here.
Posted to issues@sentry.apache.org by "Arjun Mishra (JIRA)" <ji...@apache.org> on 2018/12/07 23:28:00 UTC

[jira] [Comment Edited] (SENTRY-2476) Optimize deleting specific paths for objects

    [ https://issues.apache.org/jira/browse/SENTRY-2476?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=16713361#comment-16713361 ] 

Arjun Mishra edited comment on SENTRY-2476 at 12/7/18 11:27 PM:
----------------------------------------------------------------

Found a new solution that deletes paths and processes events in less than 10 ms. *_The optimization is aimed at not caching as many objects_*. This was primarily triggered by the *_paths_* attribute in MAuthsPathsMapping class. See below for breakdown of steps
# Get mapping objects for object name
{noformat}
2018-12-07 14:05:12,670 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start getAllMAuthzPathsMappingCore for object dbx.tbly
2018-12-07 14:05:12,670 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process started using ordered flush - 2 enlisted objects
2018-12-07 14:05:12,670 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process finished
2018-12-07 14:05:12,671 DEBUG DataNucleus.Connection: Connection found in the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1ad3c7d5 [conn=com.jolbox.bonecp.ConnectionHandle@16c2b4fe, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextThreadedImpl@50b469b4 in factory=ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@5d5d9e5]
2018-12-07 14:05:12,671 DEBUG DataNucleus.Datastore.Native: BATCH [INSERT INTO `SENTRY_HMS_NOTIFICATION_ID` (`NOTIFICATION_ID`) VALUES (<21958>)]
2018-12-07 14:05:12,671 DEBUG DataNucleus.Datastore: Execution Time = 0 ms (number of rows = [1]) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@496079d2"
2018-12-07 14:05:12,671 DEBUG DataNucleus.Datastore: Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@254a68f2"
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore.Native: SELECT 'org.apache.sentry.provider.db.service.model.MAuthzPathsMapping' AS NUCLEUS_TYPE,`A0`.`AUTHZ_OBJ_NAME`,`A0`.`AUTHZ_SNAPSHOT_ID`,`A0`.`CREATE_TIME_MS`,`A0`.`AUTHZ_OBJ_ID` FROM `AUTHZ_PATHS_MAPPING` `A0` WHERE `A0`.`AUTHZ_OBJ_NAME` = <'dbx.tbly'>
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore.Retrieve: Execution Time = 0 ms
2018-12-07 14:05:12,672 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End getAllMAuthzPathsMappingCore for object dbx.tbly
{noformat}
# Get MPath objects for path name 
{noformat}
2018-12-07 14:05:12,672 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start getMAuthzPathsCore for path [user/hive/warehouse/dbx.db/tbly/col10=1]
2018-12-07 14:05:12,672 DEBUG DataNucleus.Connection: Connection found in the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1ad3c7d5 [conn=com.jolbox.bonecp.ConnectionHandle@16c2b4fe, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextThreadedImpl@50b469b4 in factory=ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@5d5d9e5]
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore: Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@2be897c0"
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore.Native: SELECT 'org.apache.sentry.provider.db.service.model.MPath' AS NUCLEUS_TYPE,`A0`.`PATH_NAME`,`A0`.`PATH_ID` FROM `AUTHZ_PATH` `A0` WHERE `A0`.`PATH_NAME` = <'user/hive/warehouse/dbx.db/tbly/col10=1'>
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore.Retrieve: Execution Time = 4 ms
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Retrieved object with OID "11255[OID]org.apache.sentry.provider.db.service.model.MPath"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object with id "11255[OID]org.apache.sentry.provider.db.service.model.MPath" not found in Level 1 cache [cache size = 2]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") added to Level 1 cache (loadedFlags="[N]")
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End getMAuthzPathsCore for path [user/hive/warehouse/dbx.db/tbly/col10=1]. Size 1
{noformat}
# Delete the path objects
{noformat}
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start deleting all objects for path [user/hive/warehouse/dbx.db/tbly/col10=1]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Deleting object from persistence : "org.apache.sentry.provider.db.service.model.MPath@48707c3"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") has a lifecycle change : "HOLLOW"->"P_DELETED"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") enlisted in transactional cache
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process started using ordered flush - 1 enlisted objects
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process finished
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" being deleted from table "`AUTHZ_PATH`"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Connection: Connection found in the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1ad3c7d5 [conn=com.jolbox.bonecp.ConnectionHandle@16c2b4fe, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextThreadedImpl@50b469b4 in factory=ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@5d5d9e5]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore: Using PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@36ae185" for connection "com.jolbox.bonecp.ConnectionHandle@16c2b4fe"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore.Persist: The requested statement "DELETE FROM `AUTHZ_PATH` WHERE `PATH_ID`=?" has been made batchable
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore.Persist: Batch has been added to statement "DELETE FROM `AUTHZ_PATH` WHERE `PATH_ID`=?" for processing (batch size = 1)
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End deleting all objects for path [user/hive/warehouse/dbx.db/tbly/col10=1]
{noformat}
# Update mapping obejct
{noformat}
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start persisting mapping
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Retrieved object with OID "63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object with id "63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping" not found in Level 1 cache [cache size = 3]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MAuthzPathsMapping@6c5320bf" (id="63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping") added to Level 1 cache (loadedFlags="[NNNN]")
2018-12-07 14:05:12,677 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End persisting mapping
2018-12-07 14:05:12,677 DEBUG DataNucleus.Datastore.Native: BATCH [DELETE FROM `AUTHZ_PATH` WHERE `PATH_ID`=<11255>]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Datastore: Execution Time = 1 ms (number of rows = [1]) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@36ae185"
{noformat}
# Do reachability checks. THIS IS MUCH LESSER since the objects we have cached is VERY VERY small compared to before
{noformat}
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Performing check of objects for "persistence-by-reachability" (commit) ...
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") taken from Level 1 cache (loadedFlags="[Y]") [cache size = 4]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") lifecycle state "P_NEW" added to the list of reachables on commit.
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Performing reachability algorithm on object with id "21944"
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944") taken from Level 1 cache (loadedFlags="[YYYY]") [cache size = 4]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="21944") lifecycle state "P_NEW" added to the list of reachables on commit.
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Completed check of objects for "persistence-by-reachability" (commit).
{noformat}
# Update JDO lifecyle changes and disconnect
{noformat}
2018-12-07 14:05:12,678 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") has a lifecycle change : "P_DELETED"->""
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") being evicted from transactional cache
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MPath@48707c3 from StateManager[pc=org.apache.sentry.provider.db.service.model.MPath@48707c3, lifecycle=P_DELETED]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="11255[OID]org.apache.sentry.provider.db.service.model.MPath" being removed from Level 1 cache [current cache size = 4]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") has a lifecycle change : "P_NEW"->"HOLLOW"
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") being evicted from transactional cache
2018-12-07 14:05:12,678 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944") has a lifecycle change : "P_NEW"->"HOLLOW"
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944") being evicted from transactional cache
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Transaction committed in 1 ms
{noformat}
{noformat}
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MAuthzPathsMapping@6c5320bf from StateManager[pc=org.apache.sentry.provider.db.service.model.MAuthzPathsMapping@6c5320bf, lifecycle=HOLLOW]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping" being removed from Level 1 cache [current cache size = 3]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b from StateManager[pc=org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b, lifecycle=HOLLOW]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="org.datanucleus.identity.IdentityReference@4a63b56d" being removed from Level 1 cache [current cache size = 2]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349 from StateManager[pc=org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349, lifecycle=HOLLOW]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944" being removed from Level 1 cache [current cache size = 1]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Level 1 Cache cleared
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: ExecutionContext "org.datanucleus.ExecutionContextThreadedImpl@50b469b4" closed
{noformat}
# Wake up clients for sync
{noformat}
2018-12-07 14:05:12,678 DEBUG org.apache.sentry.service.thrift.HMSFollower: wakeUpWaitingClientsForSync: eventId = 21958, hmsImageId = 1
{noformat}


was (Author: arjunmishra13):
Found a new solution that deletes paths and processes events in less than 10 ms. The optimization is aimed at not caching objects. This was primarily triggered by the *_paths_* attribute in MAuthsPathsMapping class. See below for breakdown of steps
# Get mapping objects for object name
{noformat}
2018-12-07 14:05:12,670 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start getAllMAuthzPathsMappingCore for object dbx.tbly
2018-12-07 14:05:12,670 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process started using ordered flush - 2 enlisted objects
2018-12-07 14:05:12,670 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process finished
2018-12-07 14:05:12,671 DEBUG DataNucleus.Connection: Connection found in the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1ad3c7d5 [conn=com.jolbox.bonecp.ConnectionHandle@16c2b4fe, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextThreadedImpl@50b469b4 in factory=ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@5d5d9e5]
2018-12-07 14:05:12,671 DEBUG DataNucleus.Datastore.Native: BATCH [INSERT INTO `SENTRY_HMS_NOTIFICATION_ID` (`NOTIFICATION_ID`) VALUES (<21958>)]
2018-12-07 14:05:12,671 DEBUG DataNucleus.Datastore: Execution Time = 0 ms (number of rows = [1]) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@496079d2"
2018-12-07 14:05:12,671 DEBUG DataNucleus.Datastore: Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@254a68f2"
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore.Native: SELECT 'org.apache.sentry.provider.db.service.model.MAuthzPathsMapping' AS NUCLEUS_TYPE,`A0`.`AUTHZ_OBJ_NAME`,`A0`.`AUTHZ_SNAPSHOT_ID`,`A0`.`CREATE_TIME_MS`,`A0`.`AUTHZ_OBJ_ID` FROM `AUTHZ_PATHS_MAPPING` `A0` WHERE `A0`.`AUTHZ_OBJ_NAME` = <'dbx.tbly'>
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore.Retrieve: Execution Time = 0 ms
2018-12-07 14:05:12,672 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End getAllMAuthzPathsMappingCore for object dbx.tbly
{noformat}
# Get MPath objects for path name 
{noformat}
2018-12-07 14:05:12,672 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start getMAuthzPathsCore for path [user/hive/warehouse/dbx.db/tbly/col10=1]
2018-12-07 14:05:12,672 DEBUG DataNucleus.Connection: Connection found in the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1ad3c7d5 [conn=com.jolbox.bonecp.ConnectionHandle@16c2b4fe, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextThreadedImpl@50b469b4 in factory=ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@5d5d9e5]
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore: Closing PreparedStatement "com.jolbox.bonecp.PreparedStatementHandle@2be897c0"
2018-12-07 14:05:12,672 DEBUG DataNucleus.Datastore.Native: SELECT 'org.apache.sentry.provider.db.service.model.MPath' AS NUCLEUS_TYPE,`A0`.`PATH_NAME`,`A0`.`PATH_ID` FROM `AUTHZ_PATH` `A0` WHERE `A0`.`PATH_NAME` = <'user/hive/warehouse/dbx.db/tbly/col10=1'>
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore.Retrieve: Execution Time = 4 ms
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Retrieved object with OID "11255[OID]org.apache.sentry.provider.db.service.model.MPath"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object with id "11255[OID]org.apache.sentry.provider.db.service.model.MPath" not found in Level 1 cache [cache size = 2]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") added to Level 1 cache (loadedFlags="[N]")
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End getMAuthzPathsCore for path [user/hive/warehouse/dbx.db/tbly/col10=1]. Size 1
{noformat}
# Delete the path objects
{noformat}
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start deleting all objects for path [user/hive/warehouse/dbx.db/tbly/col10=1]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Deleting object from persistence : "org.apache.sentry.provider.db.service.model.MPath@48707c3"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") has a lifecycle change : "HOLLOW"->"P_DELETED"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") enlisted in transactional cache
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process started using ordered flush - 1 enlisted objects
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: ExecutionContext.internalFlush() process finished
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" being deleted from table "`AUTHZ_PATH`"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Connection: Connection found in the pool : org.datanucleus.store.rdbms.ConnectionFactoryImpl$ManagedConnectionImpl@1ad3c7d5 [conn=com.jolbox.bonecp.ConnectionHandle@16c2b4fe, commitOnRelease=false, closeOnRelease=false, closeOnTxnEnd=true] for key=org.datanucleus.ExecutionContextThreadedImpl@50b469b4 in factory=ConnectionFactory:tx[org.datanucleus.store.rdbms.ConnectionFactoryImpl@5d5d9e5]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore: Using PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@36ae185" for connection "com.jolbox.bonecp.ConnectionHandle@16c2b4fe"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore.Persist: The requested statement "DELETE FROM `AUTHZ_PATH` WHERE `PATH_ID`=?" has been made batchable
2018-12-07 14:05:12,676 DEBUG DataNucleus.Datastore.Persist: Batch has been added to statement "DELETE FROM `AUTHZ_PATH` WHERE `PATH_ID`=?" for processing (batch size = 1)
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End deleting all objects for path [user/hive/warehouse/dbx.db/tbly/col10=1]
{noformat}
# Update mapping obejct
{noformat}
2018-12-07 14:05:12,676 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: Start persisting mapping
2018-12-07 14:05:12,676 DEBUG DataNucleus.Persistence: Retrieved object with OID "63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping"
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object with id "63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping" not found in Level 1 cache [cache size = 3]
2018-12-07 14:05:12,676 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MAuthzPathsMapping@6c5320bf" (id="63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping") added to Level 1 cache (loadedFlags="[NNNN]")
2018-12-07 14:05:12,677 INFO org.apache.sentry.provider.db.service.persistent.SentryStore: End persisting mapping
2018-12-07 14:05:12,677 DEBUG DataNucleus.Datastore.Native: BATCH [DELETE FROM `AUTHZ_PATH` WHERE `PATH_ID`=<11255>]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Datastore: Execution Time = 1 ms (number of rows = [1]) on PreparedStatement "org.datanucleus.store.rdbms.ParamLoggingPreparedStatement@36ae185"
{noformat}
# Do reachability checks. THIS IS MUCH LESSER since the objects we have cached is VERY VERY small compared to before
{noformat}
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Performing check of objects for "persistence-by-reachability" (commit) ...
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") taken from Level 1 cache (loadedFlags="[Y]") [cache size = 4]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") lifecycle state "P_NEW" added to the list of reachables on commit.
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Performing reachability algorithm on object with id "21944"
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944") taken from Level 1 cache (loadedFlags="[YYYY]") [cache size = 4]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="21944") lifecycle state "P_NEW" added to the list of reachables on commit.
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Completed check of objects for "persistence-by-reachability" (commit).
{noformat}
# Update JDO lifecyle changes and disconnect
{noformat}
2018-12-07 14:05:12,678 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") has a lifecycle change : "P_DELETED"->""
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MPath@48707c3" (id="11255[OID]org.apache.sentry.provider.db.service.model.MPath") being evicted from transactional cache
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MPath@48707c3 from StateManager[pc=org.apache.sentry.provider.db.service.model.MPath@48707c3, lifecycle=P_DELETED]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="11255[OID]org.apache.sentry.provider.db.service.model.MPath" being removed from Level 1 cache [current cache size = 4]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") has a lifecycle change : "P_NEW"->"HOLLOW"
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b" (id="org.datanucleus.identity.IdentityReference@4a63b56d") being evicted from transactional cache
2018-12-07 14:05:12,678 DEBUG DataNucleus.Lifecycle: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944") has a lifecycle change : "P_NEW"->"HOLLOW"
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Object "org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349" (id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944") being evicted from transactional cache
2018-12-07 14:05:12,678 DEBUG DataNucleus.Transaction: Transaction committed in 1 ms
{noformat}
{noformat}
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MAuthzPathsMapping@6c5320bf from StateManager[pc=org.apache.sentry.provider.db.service.model.MAuthzPathsMapping@6c5320bf, lifecycle=HOLLOW]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="63[OID]org.apache.sentry.provider.db.service.model.MAuthzPathsMapping" being removed from Level 1 cache [current cache size = 3]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b from StateManager[pc=org.apache.sentry.provider.db.service.model.MSentryHmsNotification@15a5c56b, lifecycle=HOLLOW]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="org.datanucleus.identity.IdentityReference@4a63b56d" being removed from Level 1 cache [current cache size = 2]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: Disconnecting org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349 from StateManager[pc=org.apache.sentry.provider.db.service.model.MSentryPathChange@4203b349, lifecycle=HOLLOW]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Object with id="org.apache.sentry.provider.db.service.model.MSentryPathChange:21944" being removed from Level 1 cache [current cache size = 1]
2018-12-07 14:05:12,678 DEBUG DataNucleus.Cache: Level 1 Cache cleared
2018-12-07 14:05:12,678 DEBUG DataNucleus.Persistence: ExecutionContext "org.datanucleus.ExecutionContextThreadedImpl@50b469b4" closed
{noformat}
# Wake up clients for sync
{noformat}
2018-12-07 14:05:12,678 DEBUG org.apache.sentry.service.thrift.HMSFollower: wakeUpWaitingClientsForSync: eventId = 21958, hmsImageId = 1
{noformat}

> Optimize deleting specific paths for objects
> --------------------------------------------
>
>                 Key: SENTRY-2476
>                 URL: https://issues.apache.org/jira/browse/SENTRY-2476
>             Project: Sentry
>          Issue Type: Bug
>            Reporter: Arjun Mishra
>            Assignee: Arjun Mishra
>            Priority: Major
>         Attachments: SENTRY-2476.01.patch, SENTRY-2476.02.patch
>
>
> Right now when we process a drop partition event, we fetch each path object for paths_mapping object then find the one we want to delete and then delete it. We should avoid fetching all objects and directly delete the path that needs to be deleted



--
This message was sent by Atlassian JIRA
(v7.6.3#76005)