diff --git a/src/main/java/org/gcube/portal/threadlocalexec/SmartGearsPortalValve.java b/src/main/java/org/gcube/portal/threadlocalexec/SmartGearsPortalValve.java index 08171dc..c4679a4 100644 --- a/src/main/java/org/gcube/portal/threadlocalexec/SmartGearsPortalValve.java +++ b/src/main/java/org/gcube/portal/threadlocalexec/SmartGearsPortalValve.java @@ -28,7 +28,6 @@ import org.gcube.oidc.rest.OpenIdConnectConfiguration; import org.gcube.oidc.rest.OpenIdConnectRESTHelper; import org.gcube.oidc.rest.OpenIdConnectRESTHelperException; import org.gcube.portal.oidc.lr62.JWTCacheProxy; -import org.gcube.portal.oidc.lr62.JWTTokenUtil; import org.gcube.portal.oidc.lr62.LiferayOpenIdConnectConfiguration; import org.slf4j.Logger; import org.slf4j.LoggerFactory; @@ -96,77 +95,72 @@ public class SmartGearsPortalValve extends ValveBase { _log.debug("Getting current user"); User user = getCurrentUser(request); if (user == null) { - // Almost impossible _log.error("Current user not found, cannot continue"); return; } + _log.debug("Current user is: {} [{}]", user.getScreenName(), user.getEmailAddress()); + HttpSession session = request.getSession(false); if (session == null) { _log.debug("Session is null, cannot continue"); return; } - synchronized (session) { - String urlEncodedScope = null; - try { - urlEncodedScope = URLEncoder.encode(scope, "UTF-8"); - } catch (UnsupportedEncodingException e) { - // Almost impossible - _log.error("Cannot URL encode scope", e); - return; - } - _log.debug("URL encoded scope is: {}", urlEncodedScope); + String sessionId = session.getId(); + _log.debug("Current session ID is {}", sessionId); + String urlEncodedScope = null; + try { + urlEncodedScope = URLEncoder.encode(scope, "UTF-8"); + } catch (UnsupportedEncodingException e) { + // Almost impossible + _log.error("Cannot URL encode scope", e); + return; + } + _log.debug("URL encoded scope is: {}", urlEncodedScope); - _log.trace("Getting UMA token from session: {}", session); - JWTToken umaToken = JWTTokenUtil.getUMAFromSession(session); - if (umaToken == null) { - _log.debug("UMA token not found in session. Trying to get it from cache proxy"); - umaToken = JWTCacheProxy.getInstance().getUMAToken(user, session); - } + JWTToken umaToken = null; + synchronized (JWTCacheProxy.getInstance().getMutexFor(user)) { + _log.trace("Getting UMA token for user {}, and session {}", user.getScreenName(), sessionId); + umaToken = JWTCacheProxy.getInstance().getUMAToken(user, sessionId); if (umaToken != null && !umaToken.isExpired() && umaToken.getAud().contains(urlEncodedScope)) { - _log.trace("Current UMA token is OK"); - if (JWTTokenUtil.getUMAFromSession(session) == null) { - _log.debug("Setting UMA token also in current session"); - JWTTokenUtil.putUMAInSession(umaToken, session); - } - } else if (JWTCacheProxy.getInstance().getUMAToken(user, session) != null - && !JWTCacheProxy.getInstance().getUMAToken(user, session).isExpired() - && JWTCacheProxy.getInstance().getUMAToken(user, session).getAud().contains(urlEncodedScope)) { - - _log.debug("Cache proxy already contains the suitable UMA token. Putting it also in session and using it"); - umaToken = JWTCacheProxy.getInstance().getUMAToken(user, session); - JWTTokenUtil.putUMAInSession(umaToken, session); + _log.trace("Current UMA token is OK {}", umaToken.getTokenEssentials()); } else { if (umaToken != null && umaToken.getAud().contains(urlEncodedScope) && umaToken.isExpired()) { - _log.debug("UMA token is expired, trying to refresh it"); - OpenIdConnectConfiguration configuration = LiferayOpenIdConnectConfiguration.getConfiguration(request); + _log.debug("Suitable UMA token found but is expired, trying to refresh it {}", + umaToken.getTokenEssentials()); + + OpenIdConnectConfiguration configuration = LiferayOpenIdConnectConfiguration + .getConfiguration(request); try { umaToken = OpenIdConnectRESTHelper.refreshToken(configuration.getTokenURL(), umaToken); - _log.debug("Setting refreshed UMA token in cache proxy"); - JWTCacheProxy.getInstance().setUMAToken(getCurrentUser(request), session, umaToken); - _log.debug("Setting refreshed UMA token in session"); - JWTTokenUtil.putUMAInSession(umaToken, session); + _log.debug("Got a refreshed UMA token {}", umaToken.getTokenEssentials()); + + _log.debug("Setting the refreshed UMA token in cache proxy for user {}, and session]", + user.getScreenName(), sessionId); + + JWTCacheProxy.getInstance().setUMAToken(user, sessionId, umaToken); } catch (OpenIdConnectRESTHelperException e) { if (e.hasJSONPayload()) { if (OpenIdConnectRESTHelper.isInvalidBearerTokenError(e.getResponseString())) { if (FORCE_LOGOUT_ON_INVALID_OIDC) { _log.warn("OIDC token is become invalid, forcing redirect to logout URI"); - forceLogout(session, response); + forceLogout(response); } else { _log.warn("OIDC token is become invalid, cannot continue"); } return; } else if (OpenIdConnectRESTHelper.isTokenNotActiveError(e.getResponseString())) { _log.info("UMA token is no more active, get new one"); + } else { + _log.error("Other UMA token refresh error", e); } } else { - _log.error("Refreshing UMA token on server", e); + _log.error("Refreshing UMA token on server " + umaToken.getTokenEssentials(), e); } umaToken = null; - _log.info("Removing probably inactive OIDC token from session"); - JWTTokenUtil.removeOIDCFromSession(session); - _log.info("Removing all inactive UMA token from session and from cache proxy if present"); - JWTTokenUtil.removeUMAFromSession(session); - JWTCacheProxy.getInstance().removeUMAToken(user, session); + _log.debug("Removing inactive UMA token from cache proxy if present for user {} and session {}", + user.getScreenName(), sessionId); + + JWTCacheProxy.getInstance().removeUMAToken(user, sessionId); } } if (umaToken == null || !umaToken.getAud().contains(urlEncodedScope)) { @@ -175,34 +169,30 @@ public class SmartGearsPortalValve extends ValveBase { _log.debug("Getting new UMA token for scope {}", urlEncodedScope); } else if (!umaToken.getAud().contains(urlEncodedScope)) { scopeIsChanged = true; - _log.info("UMA token has been issued for another scope ({}). Getting new one for scope: {}", - umaToken.getAud(), urlEncodedScope); + _log.info("Getting new UMA token for scope {} since it has been issued for another scope {}", + urlEncodedScope, umaToken.getTokenEssentials()); } - _log.debug("Getting OIDC token from session"); - JWTToken authToken = JWTTokenUtil.getOIDCFromSession(session); + _log.debug("Getting OIDC token from cache proxy for user {} and session {}", user.getScreenName(), + sessionId); + + JWTToken authToken = JWTCacheProxy.getInstance().getOIDCToken(user, sessionId); if (authToken == null) { - _log.debug("OIDC token not found in session. Trying to get it from cache proxy"); - authToken = JWTCacheProxy.getInstance().getOIDCToken(user, session); - if (authToken == null) { - _log.info("OIDC token is null also in cache proxy"); - if (FORCE_LOGOUT_ON_MISSING_OIDC) { - _log.warn("OIDC token is null also in cache proxy, force redirecting to logut URI"); - forceLogout(session, response); - return; - } else { - _log.error("OIDC token is null also in cache proxy, cannot continue!"); - return; - } + if (FORCE_LOGOUT_ON_MISSING_OIDC) { + _log.warn("OIDC token is null in cache proxy, force redirecting to logut URI"); + forceLogout(response); } else { - _log.debug("Setting OIDC token took from cache proxy in session"); - JWTTokenUtil.putOIDCInSession(authToken, session); + _log.error("OIDC token is null in cache proxy, cannot continue!"); } + return; + } else { + _log.debug("OIDC token is {}", authToken.getTokenEssentials()); } - OpenIdConnectConfiguration configuration = LiferayOpenIdConnectConfiguration.getConfiguration(request); - boolean OK = false; + OpenIdConnectConfiguration configuration = LiferayOpenIdConnectConfiguration + .getConfiguration(request); + boolean isNotAuthorized = false; int authorizationAttempts = 0; - while (!OK) { + do { try { if (isNotAuthorized || scopeIsChanged || authToken.isExpired()) { if (isNotAuthorized) { @@ -211,10 +201,15 @@ public class SmartGearsPortalValve extends ValveBase { + "refreshing it to be sure that new grants are present. " + "[attempts: {}]", authorizationAttempts); + + // Resetting the flag to be sure to have correct log message each loop + isNotAuthorized = false; } else if (scopeIsChanged) { - _log.info("Scope is changed, refreshing token to be sure that new grants are present"); + _log.info( + "Scope is changed, refreshing token to be sure that new grants are present"); } else if (authToken.isExpired()) { - _log.debug("OIDC token is expired, trying to refresh it"); + _log.debug("OIDC token is expired, trying to refresh it {}", + authToken.getTokenEssentials()); } try { authToken = OpenIdConnectRESTHelper.refreshToken(configuration.getTokenURL(), @@ -222,41 +217,41 @@ public class SmartGearsPortalValve extends ValveBase { } catch (OpenIdConnectRESTHelperException e) { if (FORCE_LOGOUT_ON_OIDC_REFRESH_ERROR) { _log.warn("Error refreshing OIDC token, force redirecting to logut URI"); - forceLogout(session, response); + forceLogout(response); } else { _log.error("Refreshing OIDC token on server", e); } return; } - _log.debug("Setting refreshed OIDC token in cache proxy and session"); - JWTCacheProxy.getInstance().setOIDCToken(user, session, authToken); - JWTTokenUtil.putOIDCInSession(authToken, session); + _log.debug("Setting refreshed OIDC token in cache proxy"); + JWTCacheProxy.getInstance().setOIDCToken(user, sessionId, authToken); } _log.info("Getting UMA token from OIDC endpoint for scope: " + urlEncodedScope); umaToken = OpenIdConnectRESTHelper.queryUMAToken(configuration.getTokenURL(), authToken.getAccessTokenAsBearer(), urlEncodedScope, null); - - OK = true; + + _log.debug("Got new UMA token {}", umaToken.getTokenEssentials()); } catch (OpenIdConnectRESTHelperException e) { if (e.hasJSONPayload()) { if (OpenIdConnectRESTHelper.isInvalidBearerTokenError(e.getResponseString())) { if (FORCE_LOGOUT_ON_INVALID_OIDC) { _log.warn("OIDC token is become invalid, forcing redirect to logout URI"); - forceLogout(session, response); + forceLogout(response); } else { _log.error("OIDC token is become invalid, cannot continue"); } return; } else if (OpenIdConnectRESTHelper .isAccessDeniedNotAuthorizedError(e.getResponseString())) { + _log.info("UMA token is" + (isNotAuthorized ? " still" : "") + " not authorized with actual OIDC token"); - + isNotAuthorized = true; authorizationAttempts += 1; if (authorizationAttempts <= MAX_AUTHORIZATION_RETRY_ATTEMPTS) { _log.debug("Sleeping " + AUTHORIZATION_RETRY_ATTEMPTS_DELAY - + " ms and refreshing the OIDC"); + + " ms and looping refreshing the OIDC"); try { Thread.sleep(AUTHORIZATION_RETRY_ATTEMPTS_DELAY); } catch (InterruptedException ie) { @@ -272,22 +267,29 @@ public class SmartGearsPortalValve extends ValveBase { return; } } - } + } while (isNotAuthorized); } - _log.debug("Setting UMA token in cache proxy and in session"); - JWTCacheProxy.getInstance().setUMAToken(user, session, umaToken); - JWTTokenUtil.putUMAInSession(umaToken, session); - } - _log.trace("Current UMA token audience is: {}", umaToken.getAud()); - _log.debug("Setting UMA token in UMA JWT provider"); - UmaJWTProvider.instance.set(umaToken.getRaw()); + _log.debug("Setting UMA token in cache proxy for user {} and session {}", user.getScreenName(), + sessionId); + + JWTCacheProxy.getInstance().setUMAToken(user, sessionId, umaToken); + } } + + _log.trace("Current UMA token in use is: {}", umaToken.getTokenEssentials()); + + _log.debug("Setting UMA token with jti {} in UMA JWT provider", umaToken.getJti()); + UmaJWTProvider.instance.set(umaToken.getRaw()); } - protected void forceLogout(HttpSession session, HttpServletResponse response) { + protected void forceLogout(HttpServletResponse response) { try { - response.sendRedirect(LOGOUT_URI); + if (!response.isCommitted()) { + response.sendRedirect(LOGOUT_URI); + } else { + _log.warn("Cannot redirect to logout URI since the response is already commited"); + } } catch (IOException e) { _log.error("Cannot redirect to logout URI: " + LOGOUT_URI, e); }