From 8af397d5760a60bbd57f144b894bbc0f3443f262 Mon Sep 17 00:00:00 2001 From: Julian Ladisch Date: Tue, 22 Oct 2024 16:00:05 +0200 Subject: [PATCH 1/2] OKAPI-1193: Clearly log which user/tenant has invalid credentials Add logging to LoginClient and RefreshClient. --- .../refreshtoken/client/impl/LoginClient.java | 30 ++++++++++--- .../client/impl/RefreshClient.java | 29 +++++++++++-- .../client/impl/LoginClientTest.java | 13 +++--- .../client/impl/RefreshClientTest.java | 42 +++++++++++++++++-- 4 files changed, 96 insertions(+), 18 deletions(-) diff --git a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java index 7895dc4b0..d167ac898 100644 --- a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java +++ b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java @@ -8,6 +8,8 @@ import io.vertx.core.json.JsonObject; import io.vertx.ext.web.client.HttpRequest; import java.util.function.Supplier; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.okapi.common.Constants; import org.folio.okapi.common.XOkapiHeaders; import org.folio.okapi.common.refreshtoken.client.Client; @@ -18,6 +20,8 @@ @java.lang.SuppressWarnings({"squid:S1075"}) // URIs should not be hardcoded public class LoginClient implements Client { + private static final Logger logger = LogManager.getLogger(LoginClient.class); + private static final String LOGIN_EXPIRY_PATH = "/authn/login-with-expiry"; private static final String LOGIN_LEGACY_PATH = "/authn/login"; @@ -63,12 +67,19 @@ Future getTokenLegacy(JsonObject payload) { .putHeader(XOkapiHeaders.TENANT, tenant) .sendJsonObject(payload).map(res -> { if (res.statusCode() != 201) { - throw new ClientException("POST " + LOGIN_LEGACY_PATH + " returned status " - + res.statusCode() + ": " + res.bodyAsString()); + var msg = "Login failed. POST " + LOGIN_LEGACY_PATH + + " for tenant '" + tenant + "' and username '" + username + + "' returned status " + res.statusCode() + ": " + res.bodyAsString(); + logger.error("{}", msg); + throw new ClientException(msg); } String token = res.getHeader(XOkapiHeaders.TOKEN); if (token == null) { - throw new ClientException(LOGIN_LEGACY_PATH + " did not return token"); + var msg = "Login failed. POST " + LOGIN_LEGACY_PATH + + " for tenant '" + tenant + "' and username '" + username + + "' did not return token."; + logger.error("{}", msg); + throw new ClientException(msg); } if (cache != null) { cache.put(tenant, username, token, @@ -91,8 +102,11 @@ Future getTokenWithExpiry(JsonObject payload) { if (res.statusCode() == 404) { return null; } else if (res.statusCode() != 201) { - throw new ClientException("POST " + LOGIN_EXPIRY_PATH + " returned status " - + res.statusCode() + ": " + res.bodyAsString()); + var msg = "Login failed. POST " + LOGIN_EXPIRY_PATH + + " for tenant '" + tenant + "' and username '" + username + + "' returned status " + res.statusCode() + ": " + res.bodyAsString(); + logger.error("{}", msg); + throw new ClientException(msg); } for (String v : res.cookies()) { Cookie cookie = ClientCookieDecoder.STRICT.decode(v); @@ -105,7 +119,11 @@ Future getTokenWithExpiry(JsonObject payload) { return cookie.value(); } } - throw new ClientException(LOGIN_EXPIRY_PATH + " did not return access token"); + var msg = "Login failed. POST " + LOGIN_EXPIRY_PATH + + " for tenant '" + tenant + "' and username '" + username + + "' did not return access token"; + logger.error("{}", msg); + throw new ClientException(msg); }); } catch (Exception e) { return Future.failedFuture(e); diff --git a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java index 99eef2f50..21d252b92 100644 --- a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java +++ b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java @@ -7,7 +7,10 @@ import io.vertx.core.http.HttpHeaders; import io.vertx.ext.web.client.HttpRequest; import io.vertx.ext.web.client.HttpResponse; +import org.apache.logging.log4j.LogManager; +import org.apache.logging.log4j.Logger; import org.folio.okapi.common.Constants; +import org.folio.okapi.common.OkapiToken; import org.folio.okapi.common.XOkapiHeaders; import org.folio.okapi.common.refreshtoken.client.Client; import org.folio.okapi.common.refreshtoken.client.ClientException; @@ -17,6 +20,8 @@ @java.lang.SuppressWarnings({"squid:S1075"}) // URIs should not be hardcoded public class RefreshClient implements Client { + private static final Logger logger = LogManager.getLogger(RefreshClient.class); + private static final String REFRESH_PATH = "/authn/refresh"; private final ClientOptions clientOptions; @@ -75,8 +80,11 @@ public Future> getToken(HttpRequest request) { String tokenResponse(HttpResponse res) { if (res.statusCode() != 201) { - throw new ClientException("POST " + REFRESH_PATH + " returned status " - + res.statusCode() + ": " + res.bodyAsString()); + var msg = "Token refresh failed. POST " + REFRESH_PATH + + " for tenant '" + tenant + "' and refreshtoken '" + payload() + + "' returned status " + res.statusCode() + ": " + res.bodyAsString(); + logger.error("{}", msg); + throw new ClientException(msg); } for (String v: res.cookies()) { io.netty.handler.codec.http.cookie.Cookie cookie = ClientCookieDecoder.STRICT.decode(v); @@ -89,7 +97,22 @@ String tokenResponse(HttpResponse res) { return cookie.value(); } } - throw new ClientException(REFRESH_PATH + " did not return access token"); + var msg = "Token refresh failed. POST " + REFRESH_PATH + + " for tenant '" + tenant + "' and refreshtoken '" + payload() + + "' did not return access token"; + logger.error("{}", msg); + throw new ClientException(msg); } + String payload() { + final var maxlength = 200; + if (refreshToken != null && refreshToken.length() > maxlength) { + return "too long: " + refreshToken.substring(0, maxlength) + "..."; + } + try { + return new OkapiToken(refreshToken).getPayloadWithoutValidation().encode(); + } catch (Exception e) { + return "invalid: " + refreshToken; + } + } } diff --git a/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClientTest.java b/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClientTest.java index c4dfb6bdf..5cc660d52 100644 --- a/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClientTest.java +++ b/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClientTest.java @@ -212,7 +212,8 @@ public void nullPassword(TestContext context) { .putHeader("Content-Type", "text/xml") .expect(SC_BAD_REQUEST)) .onComplete(context.asyncAssertFailure(t -> { - assertThat(t.getMessage(), is("POST /authn/login returned status 400: " + assertThat(t.getMessage(), is("Login failed. POST /authn/login " + + "for tenant 'diku' and username 'dikuuser' returned status 400: " + "Bad tenant/username/password")); assertThat(countLoginWithExpiry, is(0)); })); @@ -252,7 +253,8 @@ public void legacyNoToken(TestContext context) { .putHeader("Content-Type", "text/xml") .expect(SC_CREATED)) .onComplete(context.asyncAssertFailure(cause -> - assertThat(cause.getMessage(), is("/authn/login did not return token")) + assertThat(cause.getMessage(), is("Login failed. POST /authn/login " + + "for tenant 'diku' and username 'dikuuser' did not return token.")) )); } @@ -301,7 +303,8 @@ public void withExpiryNoCookies(TestContext context) { .putHeader("Content-Type", "text/xml") .expect(SC_CREATED)) .onComplete(context.asyncAssertFailure(response -> { - assertThat(response.getMessage(), is("/authn/login-with-expiry did not return access token")); + assertThat(response.getMessage(), is("Login failed. POST /authn/login-with-expiry " + + "for tenant 'diku' and username 'dikuuser' did not return access token")); })); } @@ -338,8 +341,8 @@ public void badPasswordWithExpiry(TestContext context) { .onComplete(context.asyncAssertFailure(e -> { assertThat(countLoginWithExpiry, is(1)); assertThat(e, Matchers.instanceOf(ClientException.class)); - assertThat(e.getMessage(), is("POST /authn/login-with-expiry returned status 400: " - + "Bad tenant/username/password")); + assertThat(e.getMessage(), is("Login failed. POST /authn/login-with-expiry " + + "for tenant 'diku' and username 'dikuuser' returned status 400: Bad tenant/username/password")); })); } diff --git a/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClientTest.java b/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClientTest.java index 85a6d350d..6b80ce0fa 100644 --- a/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClientTest.java +++ b/okapi-common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClientTest.java @@ -2,15 +2,21 @@ import static org.folio.okapi.common.ChattyResponsePredicate.SC_BAD_REQUEST; import static org.folio.okapi.common.ChattyResponsePredicate.SC_CREATED; +import static org.hamcrest.CoreMatchers.endsWith; import static org.hamcrest.CoreMatchers.is; +import static org.hamcrest.CoreMatchers.startsWith; import static org.hamcrest.MatcherAssert.assertThat; +import java.nio.charset.StandardCharsets; +import java.util.Base64; + import io.vertx.core.Vertx; import io.vertx.core.buffer.Buffer; import io.vertx.core.http.Cookie; import io.vertx.core.http.CookieSameSite; import io.vertx.core.http.HttpServerRequest; import io.vertx.core.http.HttpServerResponse; +import io.vertx.core.json.JsonObject; import io.vertx.ext.unit.TestContext; import io.vertx.ext.unit.junit.VertxUnitRunner; import io.vertx.ext.web.Router; @@ -192,8 +198,8 @@ public void refreshInvalidToken(TestContext context) { .putHeader("Content-Type", "text/xml") .expect(SC_BAD_REQUEST)) .onComplete(context.asyncAssertFailure(response -> - assertThat(response.getMessage(), is("POST /authn/refresh returned status 400: " - + "Missing/bad refresh token")) + assertThat(response.getMessage(), is("Token refresh failed. POST /authn/refresh " + + "for tenant 'diku' and refreshtoken 'invalid: invalid_token' returned status 400: Missing/bad refresh token")) )); } @@ -238,7 +244,8 @@ public void refreshNotFound(TestContext context) { client.getToken(webClient.postAbs(OKAPI_URL + "/echo") .expect(SC_CREATED)) .onComplete(context.asyncAssertFailure(cause -> - assertThat(cause.getMessage(), is("POST /authn/refresh returned status 404: Not found")) + assertThat(cause.getMessage(), is("Token refresh failed. POST /authn/refresh " + + "for tenant 'diku' and refreshtoken 'invalid: diku' returned status 404: Not found")) )); } @@ -249,7 +256,8 @@ public void refreshNoCookiesReturned(TestContext context) { client.getToken(webClient.postAbs(OKAPI_URL + "/echo") .expect(SC_CREATED)) .onComplete(context.asyncAssertFailure(cause -> - assertThat(cause.getMessage(), is("/authn/refresh did not return access token")) + assertThat(cause.getMessage(), is("Token refresh failed. POST /authn/refresh " + + "for tenant 'diku' and refreshtoken 'invalid: diku' did not return access token")) )); } @@ -263,4 +271,30 @@ public void getTokenMalformedUrl(TestContext context) { assertThat(e.getMessage(), is("java.net.MalformedURLException: no protocol: x/authn/refresh") ))); } + + @Test + public void payload() { + var payload = new RefreshClient(null, null, "diku", "foo." + urlEncode("{}") + ".baz").payload(); + assertThat(payload, is("{}")); + } + + @Test + public void payloadTooLong() { + var json = new JsonObject().put("x", "s".repeat(200)).encode(); + var payload = new RefreshClient(null, null, "diku", "foo." + urlEncode(json) + ".baz").payload(); + assertThat(payload, startsWith("too long: foo.eyJ4Ijoic3Nz")); + assertThat(payload, endsWith("...")); + } + + @Test + public void payloadInvalid() { + var payload = new RefreshClient(null, null, "diku", "foo.bar.baz").payload(); + assertThat(payload, is("invalid: foo.bar.baz")); + } + + private String urlEncode(String s) { + return new String( + Base64.getUrlEncoder().encode(s.getBytes(StandardCharsets.UTF_8)), + StandardCharsets.UTF_8); + } } From 06e003020d75c657d1aab802e8c1b13030e81df5 Mon Sep 17 00:00:00 2001 From: Julian Ladisch Date: Tue, 22 Oct 2024 21:08:48 +0200 Subject: [PATCH 2/2] Sonar: fix names, duplicate strings, SuppressWarnings for exceptions --- .../refreshtoken/client/impl/LoginClient.java | 33 +++++++++---------- .../client/impl/RefreshClient.java | 18 ++++++---- 2 files changed, 27 insertions(+), 24 deletions(-) diff --git a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java index d167ac898..763cc5074 100644 --- a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java +++ b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java @@ -20,7 +20,7 @@ @java.lang.SuppressWarnings({"squid:S1075"}) // URIs should not be hardcoded public class LoginClient implements Client { - private static final Logger logger = LogManager.getLogger(LoginClient.class); + private static final Logger LOGGER = LogManager.getLogger(LoginClient.class); private static final String LOGIN_EXPIRY_PATH = "/authn/login-with-expiry"; @@ -67,18 +67,15 @@ Future getTokenLegacy(JsonObject payload) { .putHeader(XOkapiHeaders.TENANT, tenant) .sendJsonObject(payload).map(res -> { if (res.statusCode() != 201) { - var msg = "Login failed. POST " + LOGIN_LEGACY_PATH - + " for tenant '" + tenant + "' and username '" + username - + "' returned status " + res.statusCode() + ": " + res.bodyAsString(); - logger.error("{}", msg); + var msg = loginFailed(LOGIN_LEGACY_PATH) + + " returned status " + res.statusCode() + ": " + res.bodyAsString(); + LOGGER.error("{}", msg); throw new ClientException(msg); } String token = res.getHeader(XOkapiHeaders.TOKEN); if (token == null) { - var msg = "Login failed. POST " + LOGIN_LEGACY_PATH - + " for tenant '" + tenant + "' and username '" + username - + "' did not return token."; - logger.error("{}", msg); + var msg = loginFailed(LOGIN_LEGACY_PATH) + " did not return token."; + LOGGER.error("{}", msg); throw new ClientException(msg); } if (cache != null) { @@ -102,10 +99,9 @@ Future getTokenWithExpiry(JsonObject payload) { if (res.statusCode() == 404) { return null; } else if (res.statusCode() != 201) { - var msg = "Login failed. POST " + LOGIN_EXPIRY_PATH - + " for tenant '" + tenant + "' and username '" + username - + "' returned status " + res.statusCode() + ": " + res.bodyAsString(); - logger.error("{}", msg); + var msg = loginFailed(LOGIN_EXPIRY_PATH) + + " returned status " + res.statusCode() + ": " + res.bodyAsString(); + LOGGER.error("{}", msg); throw new ClientException(msg); } for (String v : res.cookies()) { @@ -119,10 +115,8 @@ Future getTokenWithExpiry(JsonObject payload) { return cookie.value(); } } - var msg = "Login failed. POST " + LOGIN_EXPIRY_PATH - + " for tenant '" + tenant + "' and username '" + username - + "' did not return access token"; - logger.error("{}", msg); + var msg = loginFailed(LOGIN_EXPIRY_PATH) + " did not return access token"; + LOGGER.error("{}", msg); throw new ClientException(msg); }); } catch (Exception e) { @@ -130,6 +124,11 @@ Future getTokenWithExpiry(JsonObject payload) { } } + private String loginFailed(String path) { + return "Login failed. POST " + path + + " for tenant '" + tenant + "' and username '" + username + "'"; + } + @Override public Future getToken() { if (cache != null) { diff --git a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java index 21d252b92..1ee51f495 100644 --- a/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java +++ b/okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java @@ -17,11 +17,12 @@ import org.folio.okapi.common.refreshtoken.client.ClientOptions; import org.folio.okapi.common.refreshtoken.tokencache.RefreshTokenCache; -@java.lang.SuppressWarnings({"squid:S1075"}) // URIs should not be hardcoded +@SuppressWarnings({"squid:S1075"}) // URIs should not be hardcoded public class RefreshClient implements Client { - private static final Logger logger = LogManager.getLogger(RefreshClient.class); + private static final Logger LOGGER = LogManager.getLogger(RefreshClient.class); + private static final int PAYLOAD_LOGGING_MAX_LENGTH = 200; private static final String REFRESH_PATH = "/authn/refresh"; private final ClientOptions clientOptions; @@ -83,7 +84,7 @@ String tokenResponse(HttpResponse res) { var msg = "Token refresh failed. POST " + REFRESH_PATH + " for tenant '" + tenant + "' and refreshtoken '" + payload() + "' returned status " + res.statusCode() + ": " + res.bodyAsString(); - logger.error("{}", msg); + LOGGER.error("{}", msg); throw new ClientException(msg); } for (String v: res.cookies()) { @@ -100,14 +101,17 @@ String tokenResponse(HttpResponse res) { var msg = "Token refresh failed. POST " + REFRESH_PATH + " for tenant '" + tenant + "' and refreshtoken '" + payload() + "' did not return access token"; - logger.error("{}", msg); + LOGGER.error("{}", msg); throw new ClientException(msg); } + @SuppressWarnings({ // don't throw exceptions while logging an error + "java:S1166", // suppress "Either log or rethrow this exception." + "java:S2221", // suppress "Catch a list of specific exception subtypes instead." + }) String payload() { - final var maxlength = 200; - if (refreshToken != null && refreshToken.length() > maxlength) { - return "too long: " + refreshToken.substring(0, maxlength) + "..."; + if (refreshToken != null && refreshToken.length() > PAYLOAD_LOGGING_MAX_LENGTH) { + return "too long: " + refreshToken.substring(0, PAYLOAD_LOGGING_MAX_LENGTH) + "..."; } try { return new OkapiToken(refreshToken).getPayloadWithoutValidation().encode();