From 96b2489fbe1640c4787da6919fd6be3e65043b5a Mon Sep 17 00:00:00 2001 From: Mauro Mugnaini Date: Tue, 12 Nov 2024 12:14:35 +0100 Subject: [PATCH] Moved to liferay's portal `Log` class from `slf4j` to be configurable from portal admin --- .../gcube/portal/oidc/lr62/OIDCUmaUtil.java | 175 ++++++++++++------ 1 file changed, 117 insertions(+), 58 deletions(-) diff --git a/src/main/java/org/gcube/portal/oidc/lr62/OIDCUmaUtil.java b/src/main/java/org/gcube/portal/oidc/lr62/OIDCUmaUtil.java index 78c5f41..24674a7 100644 --- a/src/main/java/org/gcube/portal/oidc/lr62/OIDCUmaUtil.java +++ b/src/main/java/org/gcube/portal/oidc/lr62/OIDCUmaUtil.java @@ -14,18 +14,18 @@ import org.gcube.oidc.rest.JWTToken; import org.gcube.oidc.rest.OpenIdConnectConfiguration; import org.gcube.oidc.rest.OpenIdConnectRESTHelper; import org.gcube.oidc.rest.OpenIdConnectRESTHelperException; -import org.slf4j.Logger; -import org.slf4j.LoggerFactory; import com.liferay.portal.kernel.exception.PortalException; import com.liferay.portal.kernel.exception.SystemException; +import com.liferay.portal.kernel.log.Log; +import com.liferay.portal.kernel.log.LogFactoryUtil; import com.liferay.portal.model.User; import com.liferay.portal.service.UserLocalServiceUtil; import com.liferay.portal.util.PortalUtil; public class OIDCUmaUtil { - private static final Logger log = LoggerFactory.getLogger(OIDCUmaUtil.class); + private static final Log log = LogFactoryUtil.getLog(OIDCUmaUtil.class); private static final boolean REFRESH_UMA_TOKEN = false; private static final String LOGOUT_URI = "/c/portal/logout"; @@ -48,7 +48,9 @@ public class OIDCUmaUtil { String infraContext) { try { - log.debug("Getting client token from server"); + if (log.isDebugEnabled()) { + log.debug("Getting client token from server"); + } JWTToken clientToken = OpenIdConnectRESTHelper.queryClientToken(clientId, clientSecret, tokenURL); provideClientUMATokenInThreadLocal(clientToken.getAccessTokenAsBearer(), tokenURL, infraContext); } catch (Exception e) { @@ -67,9 +69,13 @@ public class OIDCUmaUtil { log.error("Cannot URL encode context", e); return; } - log.debug("URL encoded context is: {}", encodedContext); + if (log.isDebugEnabled()) { + log.debug("URL encoded context is: " + encodedContext); + } try { - log.debug("Getting UMA token from server"); + if (log.isDebugEnabled()) { + log.debug("Getting UMA token from server"); + } JWTToken umaToken = OpenIdConnectRESTHelper.queryUMAToken(tokenURL, clientAuthorizationBearer, encodedContext, null); @@ -146,7 +152,8 @@ public class OIDCUmaUtil { try { return getUMAToken(request, - UserLocalServiceUtil.getUserByScreenName(PortalUtil.getCompanyId(request), screenName), scope, temporary); + UserLocalServiceUtil.getUserByScreenName(PortalUtil.getCompanyId(request), screenName), scope, + temporary); } catch (PortalException | SystemException e) { throw new UMAException("Cannot get liferay user from companyId and screenName", e); @@ -167,12 +174,12 @@ public class OIDCUmaUtil { return getUMAToken(request, user, request.getSession(false), scope, temporary); } -// public static JWTToken getUMAToken(HttpServletRequest request, User user, HttpSession session, String scope) -// throws InvalidTokenException, MissingTokenException, RefreshException, NotAuthorizedException, -// UMAException { -// -// return getUMAToken(request, user, session, scope, true); -// } + // public static JWTToken getUMAToken(HttpServletRequest request, User user, HttpSession session, String scope) + // throws InvalidTokenException, MissingTokenException, RefreshException, NotAuthorizedException, + // UMAException { + // + // return getUMAToken(request, user, session, scope, true); + // } private static JWTToken getUMAToken(HttpServletRequest request, User user, HttpSession session, String scope, boolean temporary) throws InvalidTokenException, MissingTokenException, MissingRefreshTokenException, @@ -182,14 +189,20 @@ public class OIDCUmaUtil { log.error("User is null, cannot continue"); return null; } - log.debug("Current user is: {} [{}]", user.getScreenName(), user.getEmailAddress()); + if (log.isDebugEnabled()) { + log.debug("Current user is: " + user.getScreenName() + " [" + user.getEmailAddress() + "]"); + } if (session == null) { - log.debug("Session is null, cannot continue"); + if (log.isDebugEnabled()) { + log.debug("Session is null, cannot continue"); + } throw new UMAException("Session is null"); } String sessionId = session.getId(); - log.debug("Current session ID is {}", sessionId); + if (log.isDebugEnabled()) { + log.debug("Current session ID is " + sessionId); + } String urlEncodedScope = null; try { @@ -199,29 +212,39 @@ public class OIDCUmaUtil { log.error("Cannot URL encode scope", e); return null; } - log.debug("URL encoded scope is: {}", urlEncodedScope); + if (log.isDebugEnabled()) { + log.debug("URL encoded scope is: " + urlEncodedScope); + } JWTToken umaToken = null; JWTCacheProxy jwtCacheProxy = JWTCacheProxy.getInstance(); synchronized (jwtCacheProxy.getMutexFor(user)) { - log.trace("Getting UMA token for user {}, and session {}", user.getScreenName(), sessionId); + if (log.isTraceEnabled()) { + log.trace("Getting UMA token for user " + user.getScreenName() + ", and session " + sessionId); + } umaToken = jwtCacheProxy.getUMAToken(user, sessionId); if (umaToken != null && !umaToken.isExpired() && umaToken.getAud().contains(urlEncodedScope)) { - log.trace("Current UMA token is OK {}", umaToken.getTokenEssentials()); + if (log.isTraceEnabled()) { + log.trace("Current UMA token is OK " + umaToken.getTokenEssentials()); + } } else { if (umaToken != null && umaToken.getAud().contains(urlEncodedScope) && umaToken.isExpired()) { if (REFRESH_UMA_TOKEN) { - log.debug("Suitable UMA token found but is expired, trying to refresh it {}", - umaToken.getTokenEssentials()); + if (log.isDebugEnabled()) { + 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("Got a refreshed UMA token {}", umaToken.getTokenEssentials()); + if (log.isDebugEnabled()) { + 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); + log.debug("Setting the refreshed UMA token in cache proxy for user " + + user.getScreenName() + ", and session " + sessionId); + } // This is independent from "temporary" setting since is a refresh of an expired token // issued for the same context @@ -236,23 +259,30 @@ public class OIDCUmaUtil { log.error("Other unexpected UMA token refresh error", e); } } else { - log.warn("Refreshing UMA token on server for {}: {}", umaToken.getTokenEssentials(), e.getMessage()); + log.warn("Refreshing UMA token on server for " + umaToken.getTokenEssentials() + ": " + + e.getMessage()); } umaToken = null; - log.debug( - "Removing inactive UMA token from cache proxy if present for user {} and session {}", - user.getScreenName(), sessionId); + if (log.isDebugEnabled()) { + log.debug( + "Removing inactive UMA token from cache proxy if present for user " + + user.getScreenName() + " and session " + sessionId); + } jwtCacheProxy.removeUMAToken(user, sessionId); } } else { - log.debug("Suitable UMA token found but it is expired." - + "It will be replaced with new one according to settings {}", - umaToken.getTokenEssentials()); + if (log.isDebugEnabled()) { + log.debug("Suitable UMA token found but it is expired." + + "It will be replaced with new one according to settings " + + umaToken.getTokenEssentials()); + } umaToken = null; - log.debug("Removing inactive UMA token from cache proxy if present for user {} and session {}", - user.getScreenName(), sessionId); + if (log.isDebugEnabled()) { + log.debug("Removing inactive UMA token from cache proxy if present for user " + + user.getScreenName() + " and session " + sessionId); + } jwtCacheProxy.removeUMAToken(user, sessionId); } @@ -260,14 +290,19 @@ public class OIDCUmaUtil { if (umaToken == null || !umaToken.getAud().contains(urlEncodedScope)) { boolean scopeIsChanged = false; if (umaToken == null) { - log.debug("Getting new UMA token for scope {}", urlEncodedScope); + if (log.isDebugEnabled()) { + log.debug("Getting new UMA token for scope " + urlEncodedScope); + } } else if (!umaToken.getAud().contains(urlEncodedScope)) { scopeIsChanged = true; - log.info("Getting new UMA token for scope {} since it has been issued for another scope {}", - urlEncodedScope, umaToken.getTokenEssentials()); + log.info("Getting new UMA token for scope " + urlEncodedScope + + " since it has been issued for another scope " + umaToken.getTokenEssentials()); + } + if (log.isDebugEnabled()) { + log.debug( + "Getting OIDC token from cache proxy for user " + user.getScreenName() + " and session " + + sessionId); } - log.debug("Getting OIDC token from cache proxy for user {} and session {}", user.getScreenName(), - sessionId); JWTToken authToken = jwtCacheProxy.getOIDCToken(user, sessionId); if (authToken == null) { @@ -275,7 +310,9 @@ public class OIDCUmaUtil { } else if (!authToken.hasRefreshToken()) { throw new MissingRefreshTokenException("Missing refresh token in OIDC access token"); } else { - log.debug("OIDC token is {}", authToken.getTokenEssentials()); + if (log.isDebugEnabled()) { + log.debug("OIDC token is " + authToken.getTokenEssentials()); + } } OpenIdConnectConfiguration configuration = LiferayOpenIdConnectConfiguration .getConfiguration(request); @@ -289,8 +326,7 @@ public class OIDCUmaUtil { log.info( "UMA token is not authorized with current OIDC token, " + "refreshing it to be sure that new grants are present. " - + "[attempts: {}]", - authorizationAttempts); + + "[attempts: " + authorizationAttempts + "]"); // Resetting the flag to be sure to have correct log message each loop isNotAuthorized = false; @@ -302,8 +338,10 @@ public class OIDCUmaUtil { 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 {}", - authToken.getTokenEssentials()); + if (log.isDebugEnabled()) { + log.debug("OIDC token is expired, trying to refresh it " + + authToken.getTokenEssentials()); + } } try { authToken = OpenIdConnectRESTHelper.refreshToken(configuration.getTokenURL(), @@ -318,7 +356,9 @@ public class OIDCUmaUtil { umaToken = OpenIdConnectRESTHelper.queryUMAToken(configuration.getTokenURL(), authToken.getAccessTokenAsBearer(), urlEncodedScope, null); - log.debug("Got new UMA token {}", umaToken.getTokenEssentials()); + if (log.isDebugEnabled()) { + log.debug("Got new UMA token " + umaToken.getTokenEssentials()); + } } catch (OpenIdConnectRESTHelperException e) { if (e.hasJSONPayload()) { if (OpenIdConnectRESTHelper.isInvalidBearerTokenError(e.getResponseString())) { @@ -332,8 +372,10 @@ public class OIDCUmaUtil { isNotAuthorized = true; authorizationAttempts += 1; if (authorizationAttempts <= MAX_AUTHORIZATION_RETRY_ATTEMPTS) { - log.debug("Sleeping " + AUTHORIZATION_RETRY_ATTEMPTS_DELAY - + " ms and looping refreshing the OIDC"); + if (log.isDebugEnabled()) { + log.debug("Sleeping " + AUTHORIZATION_RETRY_ATTEMPTS_DELAY + + " ms and looping refreshing the OIDC"); + } try { Thread.sleep(AUTHORIZATION_RETRY_ATTEMPTS_DELAY); } catch (InterruptedException ie) { @@ -351,8 +393,10 @@ public class OIDCUmaUtil { } if (!temporary) { - log.debug("Setting UMA token in cache proxy for user {} and session {}", user.getScreenName(), - sessionId); + if (log.isDebugEnabled()) { + log.debug("Setting UMA token in cache proxy for user " + user.getScreenName() + " and session " + + sessionId); + } jwtCacheProxy.setUMAToken(user, sessionId, umaToken); } @@ -366,22 +410,30 @@ public class OIDCUmaUtil { try { JWTToken umaToken = getUMAToken(request, user, session, scope, false); - log.trace("Current UMA token in use is: {}", umaToken.getTokenEssentials()); + if (log.isTraceEnabled()) { + log.trace("Current UMA token in use is: " + umaToken.getTokenEssentials()); + } provideTokensInThreadlocal(umaToken); } catch (MissingTokenException e) { if (FORCE_LOGOUT_ON_MISSING_OIDC) { - log.debug("OIDC token is null in cache proxy, force redirecting to logout URI"); + if (log.isDebugEnabled()) { + log.debug("OIDC token is null in cache proxy, force redirecting to logout URI"); + } forceLogout(response); } else { - log.debug("OIDC token is null in cache proxy, cannot continue"); + if (log.isDebugEnabled()) { + log.debug("OIDC token is null in cache proxy, cannot continue"); + } } log.debug("Removing UMA ticket from proxy"); JWTCacheProxy.getInstance().removeUMAToken(user, session.getId()); return; } catch (MissingRefreshTokenException e) { if (FORCE_LOGOUT_ON_MISSING_OIDC_REFRESH_TOKEN) { - log.debug("Force redirecting to logout URI: {}", e.getMessage()); + if (log.isDebugEnabled()) { + log.debug("Force redirecting to logout URI: " + e.getMessage()); + } forceLogout(response); } else { log.info(e.getMessage()); @@ -394,7 +446,7 @@ public class OIDCUmaUtil { return; } catch (RefreshTokenExpiredException e) { if (FORCE_LOGOUT_ON_OIDC_REFRESH_ERROR) { - log.info("Force redirecting to logout URI for {}: {}", user.getScreenName(), e.getMessage()); + log.info("Force redirecting to logout URI for " + user.getScreenName() + ": " + e.getMessage()); forceLogout(response); } else { log.info(e.getMessage()); @@ -407,17 +459,22 @@ public class OIDCUmaUtil { return; } catch (RefreshException e) { if (FORCE_LOGOUT_ON_OIDC_REFRESH_ERROR) { - log.debug("Cannot refresh OIDC token, force redirect for {} to logout URI: {}", user.getScreenName(), - e.getCause().getMessage()); + if (log.isDebugEnabled()) { + log.debug( + "Cannot refresh OIDC token, force redirect for " + user.getScreenName() + " to logout URI: " + + e.getCause().getMessage()); + } forceLogout(response); } else { - log.warn("Error refreshing OIDC token: {}", e.getCause().getMessage()); + log.warn("Error refreshing OIDC token: " + e.getCause().getMessage()); } return; } catch (InvalidTokenException e) { if (FORCE_LOGOUT_ON_INVALID_TOKEN) { - log.debug("OIDC token is become invalid, forcing redirect to logout URI"); + if (log.isDebugEnabled()) { + log.debug("OIDC token is become invalid, forcing redirect to logout URI"); + } forceLogout(response); } else { log.warn("OIDC token is become invalid, cannot continue"); @@ -432,7 +489,9 @@ public class OIDCUmaUtil { } public static void provideTokensInThreadlocal(JWTToken umaTokens) { - log.debug("Setting UMA token with jti {} in AccessToken provider", umaTokens.getJti()); + if (log.isDebugEnabled()) { + log.debug("Setting UMA token with jti " + umaTokens.getJti() + " in AccessToken provider"); + } AccessTokenProvider.instance.set(JWTTokenUtil.getAccessTokenString(umaTokens)); }