Merge pull request #99 from strongloop/refactor/acl

Improve debug statements for access control

lib/models/access-context.js

@@ -1,5 +1,6 @@
 var loopback = require('../loopback');
 var AccessToken = require('./access-token');
+var debug = require('debug')('loopback:security:access-context');
 
 /**
  * Access context represents the context for a request to access protected
@@ -95,6 +96,8 @@ AccessContext.prototype.addPrincipal = function (principalType, principalId, pri
     }
   }
   this.principals.push(principal);
+
+  debug('adding principal %j', principal);
   return true;
 };
 
@@ -135,6 +138,36 @@ AccessContext.prototype.isAuthenticated = function() {
   return !!(this.getUserId() || this.getAppId());
 };
 
+/**
+ * Print debug info for access context.
+ */
+
+AccessContext.prototype.debug = function() {
+  if(debug.enabled) {
+    debug('---AccessContext---');
+    if(this.principals && this.principals.length) {
+      debug('principals:')
+      this.principals.forEach(function(principal) {
+        debug('principal: %j', principal)
+      });
+    } else {
+      debug('principals: %j', this.principals);
+    }
+    debug('modelName %s', this.modelName);
+    debug('modelId %s', this.modelId);
+    debug('property %s', this.property);
+    debug('method %s', this.method);
+    debug('accessType %s', this.accessType);
+    if(this.accessToken) {
+      debug('accessToken:')
+      debug('  id %j', this.accessToken.id);
+      debug('  ttl %j', this.accessToken.ttl);
+    }
+    debug('getUserId() %s', this.getUserId());
+    debug('isAuthenticated() %s', this.isAuthenticated());
+  }
+}
+
 /**
  * This class represents the abstract notion of a principal, which can be used
  * to represent any entity, such as an individual, a corporation, and a login id
@@ -188,6 +221,15 @@ function AccessRequest(model, property, accessType, permission) {
   this.property = property || AccessContext.ALL;
   this.accessType = accessType || AccessContext.ALL;
   this.permission = permission || AccessContext.DEFAULT;
+
+  if(debug.enabled) {
+    debug('---AccessRequest---');
+    debug(' model %s', this.model);
+    debug(' property %s', this.property);
+    debug(' accessType %s', this.accessType);
+    debug(' permission %s', this.permission);
+    debug(' isWildcard() %s', this.isWildcard());
+  }
 }
 
 /**

lib/models/acl.js

@@ -163,7 +163,6 @@ ACL.getMatchingScore = function getMatchingScore(rule, req) {
  * @returns {Object} The effective ACL
  */
 ACL.resolvePermission = function resolvePermission(acls, req) {
-  debug('resolvePermission(): %j %j', acls, req);
   // Sort by the matching score in descending order
   acls = acls.sort(function (rule1, rule2) {
     return ACL.getMatchingScore(rule2, req) - ACL.getMatchingScore(rule1, req);
@@ -198,7 +197,6 @@ ACL.resolvePermission = function resolvePermission(acls, req) {
 
   var res = new AccessRequest(req.model, req.property, req.accessType,
     permission || ACL.DEFAULT);
-  debug('resolvePermission() returns: %j', res);
   return res;
 };
 
@@ -210,7 +208,6 @@ ACL.resolvePermission = function resolvePermission(acls, req) {
  * @return {Object[]} An array of ACLs
  */
 ACL.getStaticACLs = function getStaticACLs(model, property) {
-  debug('getStaticACLs(): %s %s', model, property);
   var modelClass = loopback.getModel(model);
   var staticACLs = [];
   if (modelClass && modelClass.settings.acls) {
@@ -223,6 +220,8 @@ ACL.getStaticACLs = function getStaticACLs(model, property) {
         accessType: acl.accessType,
         permission: acl.permission
       }));
+
+      staticACLs[staticACLs.length - 1].debug('Adding ACL');
     });
   }
   var prop = modelClass &&
@@ -242,7 +241,6 @@ ACL.getStaticACLs = function getStaticACLs(model, property) {
       }));
     });
   }
-  debug('getStaticACLs() returns: %j', staticACLs);
   return staticACLs;
 };
 
@@ -262,8 +260,6 @@ ACL.getStaticACLs = function getStaticACLs(model, property) {
 ACL.checkPermission = function checkPermission(principalType, principalId,
                                                model, property, accessType,
                                                callback) {
-  debug('checkPermission(): %s %s %s %s %s', principalType, principalId, model,
-    property, accessType);
   property = property || ACL.ALL;
   var propertyQuery = (property === ACL.ALL) ? undefined : {inq: [property, ACL.ALL]};
   accessType = accessType || ACL.ALL;
@@ -276,8 +272,8 @@ ACL.checkPermission = function checkPermission(principalType, principalId,
   var resolved = ACL.resolvePermission(acls, req);
 
   if(resolved && resolved.permission === ACL.DENY) {
-    // Fail fast
+    debug('Permission denied by statically resolved permission');
-    debug('checkPermission(): %j', resolved);
+    debug(' Resolved Permission: %j', resolved);
     process.nextTick(function() {
       callback && callback(null, resolved);
     });
@@ -297,11 +293,22 @@ ACL.checkPermission = function checkPermission(principalType, principalId,
         var modelClass = loopback.getModel(model);
         resolved.permission = (modelClass && modelClass.settings.defaultPermission) || ACL.ALLOW;
       }
-      debug('checkPermission(): %j', resolved);
       callback && callback(null, resolved);
     });
 };
 
+ACL.prototype.debug = function() {
+  if(debug.enabled) {
+    debug('---ACL---')
+    debug('model %s', this.model);
+    debug('property %s', this.property);
+    debug('principalType %s', this.principalType);
+    debug('principalId %s', this.principalId);
+    debug('accessType %s', this.accessType);
+    debug('permission %s', this.permission);
+  }
+}
+
 /**
  * Check if the given scope is allowed to access the model/property
  * @param {String} scope The scope name
@@ -335,8 +342,6 @@ Scope.checkPermission = function (scope, model, property, accessType, callback)
  * @param {Function} callback
  */
 ACL.checkAccess = function (context, callback) {
-  debug('checkAccess(): %j', context);
-
   if(!(context instanceof AccessContext)) {
     context = new AccessContext(context);
   }
@@ -414,7 +419,6 @@ ACL.checkAccess = function (context, callback) {
  * @param {Boolean} allowed is the request allowed
  */
 ACL.checkAccessForToken = function (token, model, modelId, method, callback) {
-  debug('checkAccessForToken(): %j %s %s %s', token, model, modelId, method);
   assert(token, 'Access token is required');
 
   var context = new AccessContext({
@@ -427,12 +431,13 @@ ACL.checkAccessForToken = function (token, model, modelId, method, callback) {
 
   context.accessType = context.model._getAccessTypeForMethod(method);
 
+  context.debug();
+
   ACL.checkAccess(context, function (err, access) {
     if (err) {
       callback && callback(err);
       return;
     }
-    debug('checkAccessForToken(): %j', access);
     callback && callback(null, access.permission !== ACL.DENY);
   });
 };