diff --git a/CHANGES_NEXT_RELEASE b/CHANGES_NEXT_RELEASE index e69de29b..a5a06675 100644 --- a/CHANGES_NEXT_RELEASE +++ b/CHANGES_NEXT_RELEASE @@ -0,0 +1 @@ +- Error 503 in pep when many tokens are requested simultaneously #316 diff --git a/lib/services/cacheUtils.js b/lib/services/cacheUtils.js index 3356c64a..a623c887 100644 --- a/lib/services/cacheUtils.js +++ b/lib/services/cacheUtils.js @@ -26,6 +26,7 @@ var config = require('../../config'), async = require('async'), domainModule = require('domain'), + logger = require('logops'), NodeCache = require('node-cache'), EventEmitter = require('events').EventEmitter; @@ -48,7 +49,9 @@ function createCache() { }, channel: cacheChannel, updating: { - subservice: false + subservice: {}, + roles: {}, + user: {} } }; } @@ -66,11 +69,14 @@ function cleanCache(cache) { } function createDomainEnabledCacheHandler(domain, processValueFn, cache, cacheType, cacheKey, callback) { - return function(error) { + return function(error, value) { if (error) { + logger.debug('Error found creating cache domain handler'); callback(error); } else { domain.enter(); + logger.debug('Value found for cache type [%s] key [%s]: %s', cacheType, cacheKey, value); + logger.debug('Processing with value: %s', JSON.stringify(cache.data[cacheType].get(cacheKey)[cacheKey])); processValueFn(cache.data[cacheType].get(cacheKey)[cacheKey], callback); } }; @@ -91,10 +97,18 @@ function createDomainEnabledCacheHandler(domain, processValueFn, cache, cacheTyp function cacheAndHold(cache, cacheType, cacheKey, retrieveRequestFn, processValueFn, callback) { var cachedValue = cache.data[cacheType].get(cacheKey); + function getCacheEventId() { + return cacheType + ':' + cacheKey; + } + if (cachedValue[cacheKey]) { + logger.debug('Value found in the cache [%s] for key [%s]: %s', cacheType, cacheKey, cachedValue[cacheKey]); + processValueFn(cachedValue[cacheKey], callback); - } else if (cache.updating[cacheType]) { - cache.channel.on(cacheType, + } else if (cache.updating[cacheType][cacheKey]) { + logger.debug('Cache type [%s] updating for key [%s]. Waiting.', cacheType, cacheKey); + + cache.channel.on(getCacheEventId(), createDomainEnabledCacheHandler( domainModule.active, processValueFn, @@ -104,9 +118,10 @@ function cacheAndHold(cache, cacheType, cacheKey, retrieveRequestFn, processValu callback) ); } else { - cache.updating[cacheType] = true; + logger.debug('Value [%s] not found in cache. Retrieving new value.', cacheKey); + cache.updating[cacheType][cacheKey] = true; cache.channel.removeAllListeners(cacheType); - cache.channel.on(cacheType, function(error, value) { + cache.channel.on(getCacheEventId(), function(error, value) { callback(error, value); }); @@ -114,8 +129,10 @@ function cacheAndHold(cache, cacheType, cacheKey, retrieveRequestFn, processValu retrieveRequestFn, processValueFn ], function(error, value) { - cache.channel.emit(cacheType, error, value); - cache.channel.removeAllListeners(cacheType); + logger.debug('Value [%s] for type [%s] processed with value: %s.', cacheKey, cacheType, value); + + cache.channel.emit(getCacheEventId(), error, value); + cache.channel.removeAllListeners(getCacheEventId()); }); } } diff --git a/lib/services/keystoneAuth.js b/lib/services/keystoneAuth.js index ab69ea71..aa4ed00a 100644 --- a/lib/services/keystoneAuth.js +++ b/lib/services/keystoneAuth.js @@ -136,7 +136,7 @@ function retrieveRoles(req, callback) { logger.debug('Extracting roles for token: %j', options); request(options, function retrieveRolesHandler(error, response, body) { - cache.updating.roles = false; + cache.updating.roles[cacheKey] = false; if (body) { logger.debug('Keystone response retrieving roles:\n\n %j', body); @@ -189,6 +189,9 @@ function retrieveUser(req, callback) { req.serviceId = cachedValue.serviceId; req.domainName = cachedValue.domainName; req.userId = cachedValue.userId; + + logger.debug('User value processed with value: %j', cachedValue); + innerCb(null, req.userId); } else { logger.error('Undefined cache value retrieving user from Keystone for service [%s] and subservice [%s]', @@ -214,7 +217,7 @@ function retrieveUser(req, callback) { request(options, function(error, response, body) { /* jshint camelcase: false */ - cache.updating.user = false; + cache.updating.user[userToken] = false; if (body) { logger.debug('Keystone response retrieving user:\n\n %j', body); @@ -242,19 +245,32 @@ function retrieveUser(req, callback) { serviceId: body.token.project.domain.id, userId: body.token['OS-TRUST:trust'].trustor_user.id }; - } else { + + innerCb(null, cachedValue); + + } else if (body.token.user && body.token.user.domain && + body.token.user.domain.id && body.token.user.id) { + cachedValue = { domainName: body.token.user.domain.name, serviceId: body.token.user.domain.id, userId: body.token.user.id }; - } - req.userData = cachedValue; + req.userData = cachedValue; + + cache.data.user.set(userToken, cachedValue, function(error) { + logger.debug('Value [%j] saved in the cache for token [%s](%s)', cachedValue, userToken, error); - cache.data.user.set(userToken, cachedValue); + innerCb(null, cachedValue); + }); - innerCb(null, cachedValue); + } else { + logger.error('Right response from Keystone without all the needed data:\n%s', + JSON.stringify(body, null, 4)); + + innerCb(new errors.KeystoneAuthenticationError(500)); + } } else if (response.statusCode === 404) { currentToken = null; logger.error('Invalid user token: %s', currentToken); @@ -314,7 +330,7 @@ function retrieveSubserviceId(req, callback) { logger.debug('Retrieving subservice ID from keystone: %j', options); request(options, function(error, response, body) { - cache.updating.subservice = false; + cache.updating.subservice[cacheKey] = false; if (body) { logger.debug('Keystone response retrieving subservice ID:\n\n %j', body);