You are viewing a plain text version of this content. The canonical link for it is here.
Posted to commits@jackrabbit.apache.org by tr...@apache.org on 2015/07/16 23:25:03 UTC
svn commit: r1691453 - in /jackrabbit/branches/2.6: ./
jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/AuthorizableImpl.java
jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/MembershipCache.java
Author: tripod
Date: Thu Jul 16 21:25:03 2015
New Revision: 1691453
URL: http://svn.apache.org/r1691453
Log:
Add more timing debug information to memberOf() related calls
Modified:
jackrabbit/branches/2.6/ (props changed)
jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/AuthorizableImpl.java
jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/MembershipCache.java
Propchange: jackrabbit/branches/2.6/
------------------------------------------------------------------------------
--- svn:mergeinfo (original)
+++ svn:mergeinfo Thu Jul 16 21:25:03 2015
@@ -1,3 +1,3 @@
/jackrabbit/branches/JCR-2272:1173165-1176545
/jackrabbit/sandbox/JCR-2415-lucene-3.0:1060860-1064038
-/jackrabbit/trunk:1437334,1437374,1437384,1437618,1437928,1437933,1437963,1438158,1438541,1439296,1439312,1439346,1439768,1439797,1439927,1440059,1440336,1440456,1440908,1440917,1442061,1443652,1443876,1443885,1443943,1444501,1444515,1444654,1444666,1444683,1444755,1445122,1445134,1453907,1460995,1461064,1461137,1461613,1461646,1462115,1462153,1462205,1462211,1465974,1466060,1466085,1466938,1467255,1467363,1468965,1469312,1469799,1469892,1469940,1470573,1470957,1471286,1475718,1478684,1478719,1478757,1479518,1479527,1479533,1479536,1479691,1479809,1479908,1480574,1481964,1483276,1483286,1484440,1484442,1484444,1484727,1487803,1497243,1497492,1497787,1498840,1498850,1499285,1505795,1505907,1505942,1506594,1506877,1508053,1509101,1513144,1516281,1517602,1517627,1519376,1525629,1525633,1526928,1526945,1530005,1535539,1537027,1539030,1539045,1539050,1556248,1566668-1566669,1582373,1587619,1590030,1590733,1598035,1598058,1603934,1634584,1680757
+/jackrabbit/trunk:1437334,1437374,1437384,1437618,1437928,1437933,1437963,1438158,1438541,1439296,1439312,1439346,1439768,1439797,1439927,1440059,1440336,1440456,1440908,1440917,1442061,1443652,1443876,1443885,1443943,1444501,1444515,1444654,1444666,1444683,1444755,1445122,1445134,1453907,1460995,1461064,1461137,1461613,1461646,1462115,1462153,1462205,1462211,1465974,1466060,1466085,1466938,1467255,1467363,1468965,1469312,1469799,1469892,1469940,1470573,1470957,1471286,1475718,1478684,1478719,1478757,1479518,1479527,1479533,1479536,1479691,1479809,1479908,1480574,1481964,1483276,1483286,1484440,1484442,1484444,1484727,1487803,1497243,1497492,1497787,1498840,1498850,1499285,1505795,1505907,1505942,1506594,1506877,1508053,1509101,1513144,1516281,1517602,1517627,1517711,1519376,1525629,1525633,1526928,1526945,1530005,1535539,1537027,1539030,1539045,1539050,1556248,1566668-1566669,1582373,1587619,1590030,1590733,1598035,1598058,1603934,1634584,1680757
Modified: jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/AuthorizableImpl.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/AuthorizableImpl.java?rev=1691453&r1=1691452&r2=1691453&view=diff
==============================================================================
--- jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/AuthorizableImpl.java (original)
+++ jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/AuthorizableImpl.java Thu Jul 16 21:25:03 2015
@@ -347,7 +347,10 @@ abstract class AuthorizableImpl implemen
MembershipCache cache = userManager.getMembershipCache();
String nid = node.getIdentifier();
+ final long t0 = System.nanoTime();
+ boolean collect = false;
if (node.getSession().hasPendingChanges()) {
+ collect = true;
// avoid retrieving outdated cache entries or filling the cache with
// invalid data due to group-membership changes pending on the
// current session.
@@ -360,7 +363,7 @@ abstract class AuthorizableImpl implemen
// retrieve cached membership. there are no pending changes.
groupNodeIds = (includeIndirect) ? cache.getMemberOf(nid) : cache.getDeclaredMemberOf(nid);
}
-
+ final long t1 = System.nanoTime();
Set<Group> groups = new HashSet<Group>(groupNodeIds.size());
for (String identifier : groupNodeIds) {
try {
@@ -371,6 +374,19 @@ abstract class AuthorizableImpl implemen
// group node doesn't exist or cannot be read -> ignore.
}
}
+ final long t2 = System.nanoTime();
+ if (log.isDebugEnabled()) {
+ log.debug("Collected {} {} group ids for [{}] in {}us, loaded {} groups in {}us (collect={}, cachesize={})", new Object[]{
+ groupNodeIds.size(),
+ includeIndirect ? "all" : "declared",
+ getID(),
+ (t1-t0) / 1000,
+ groups.size(),
+ (t2-t1) / 1000,
+ collect,
+ cache.getSize()
+ });
+ }
return new RangeIteratorAdapter(groups.iterator(), groups.size());
}
Modified: jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/MembershipCache.java
URL: http://svn.apache.org/viewvc/jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/MembershipCache.java?rev=1691453&r1=1691452&r2=1691453&view=diff
==============================================================================
--- jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/MembershipCache.java (original)
+++ jackrabbit/branches/2.6/jackrabbit-core/src/main/java/org/apache/jackrabbit/core/security/user/MembershipCache.java Thu Jul 16 21:25:03 2015
@@ -94,6 +94,7 @@ public class MembershipCache implements
// make sure the membership cache is informed if the system session is
// logged out in order to stop listening to events.
systemSession.addListener(this);
+ log.debug("Membership cache initialized. Max Size = {}", MAX_CACHE_SIZE);
}
@@ -140,6 +141,7 @@ public class MembershipCache implements
if (clear) {
cache.clear();
+ log.debug("Membership cache cleared because of observation event.");
}
}
@@ -215,9 +217,30 @@ public class MembershipCache implements
* @throws RepositoryException If an error occurs.
*/
Collection<String> collectDeclaredMembership(String authorizableNodeIdentifier, Session session) throws RepositoryException {
+ final long t0 = System.nanoTime();
+
Collection<String> groupNodeIds = collectDeclaredMembershipFromReferences(authorizableNodeIdentifier, session);
+
+ final long t1 = System.nanoTime();
+ if (log.isDebugEnabled()) {
+ log.debug(" collected {} groups for {} via references in {}us", new Object[]{
+ groupNodeIds == null ? -1 : groupNodeIds.size(),
+ authorizableNodeIdentifier,
+ (t1-t0) / 1000
+ });
+ }
+
if (groupNodeIds == null) {
groupNodeIds = collectDeclaredMembershipFromTraversal(authorizableNodeIdentifier, session);
+
+ final long t2 = System.nanoTime();
+ if (log.isDebugEnabled()) {
+ log.debug(" collected {} groups for {} via traversal in {}us", new Object[]{
+ groupNodeIds == null ? -1 : groupNodeIds.size(),
+ authorizableNodeIdentifier,
+ (t2-t1) / 1000
+ });
+ }
}
return groupNodeIds;
}
@@ -249,8 +272,13 @@ public class MembershipCache implements
* @throws RepositoryException if an error occurs
*/
private Collection<String> declaredMemberOf(String authorizableNodeIdentifier) throws RepositoryException {
+ final long t0 = System.nanoTime();
+
Collection<String> groupNodeIds = cache.get(authorizableNodeIdentifier);
+
+ boolean wasCached = true;
if (groupNodeIds == null) {
+ wasCached = false;
// retrieve a new session with system-subject in order to avoid
// concurrent read operations using the system session of this workspace.
Session session = getSession();
@@ -266,6 +294,16 @@ public class MembershipCache implements
}
}
+ if (log.isDebugEnabled()) {
+ final long t1 = System.nanoTime();
+ log.debug("Membership cache {} {} declared memberships of {} in {}us. cache size = {}", new Object[]{
+ wasCached ? "returns" : "collected",
+ groupNodeIds.size(),
+ authorizableNodeIdentifier,
+ (t1-t0) / 1000,
+ cache.getElementCount()
+ });
+ }
return groupNodeIds;
}