Skip to content

Commit

Permalink
Merge pull request #1362 from folio-org/OKAPI-1193-log-failed-login-r…
Browse files Browse the repository at this point in the history 
…efresh

OKAPI-1193: Clearly log which user/tenant has invalid credentials
  • Loading branch information
@julianladisch
julianladisch authored Oct 22, 2024
2 parents 3af7d15 + 06e0030 commit 249a940
Show file tree
Hide file tree
Showing 4 changed files with 100 additions and 19 deletions.
29 changes: 23 additions & 6 deletions okapi-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClient.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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";
Expand Down Expand Up @@ -63,12 +67,16 @@ Future<String> 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 = 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) {
throw new ClientException(LOGIN_LEGACY_PATH + " did not return token");
var msg = loginFailed(LOGIN_LEGACY_PATH) + " did not return token.";
LOGGER.error("{}", msg);
throw new ClientException(msg);
}
if (cache != null) {
cache.put(tenant, username, token,
Expand All @@ -91,8 +99,10 @@ Future<String> 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 = loginFailed(LOGIN_EXPIRY_PATH)
+ " returned status " + res.statusCode() + ": " + res.bodyAsString();
LOGGER.error("{}", msg);
throw new ClientException(msg);
}
for (String v : res.cookies()) {
Cookie cookie = ClientCookieDecoder.STRICT.decode(v);
Expand All @@ -105,13 +115,20 @@ Future<String> getTokenWithExpiry(JsonObject payload) {
return cookie.value();
}
}
throw new ClientException(LOGIN_EXPIRY_PATH + " did not return access token");
var msg = loginFailed(LOGIN_EXPIRY_PATH) + " did not return access token";
LOGGER.error("{}", msg);
throw new ClientException(msg);
});
} catch (Exception e) {
return Future.failedFuture(e);
}
}

private String loginFailed(String path) {
return "Login failed. POST " + path
+ " for tenant '" + tenant + "' and username '" + username + "'";
}

@Override
public Future<String> getToken() {
if (cache != null) {
Expand Down
35 changes: 31 additions & 4 deletions ...i-common/src/main/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClient.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -7,16 +7,22 @@
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;
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 int PAYLOAD_LOGGING_MAX_LENGTH = 200;
private static final String REFRESH_PATH = "/authn/refresh";

private final ClientOptions clientOptions;
Expand Down Expand Up @@ -75,8 +81,11 @@ public Future<HttpRequest<Buffer>> getToken(HttpRequest<Buffer> request) {

String tokenResponse(HttpResponse<Buffer> 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);
Expand All @@ -89,7 +98,25 @@ String tokenResponse(HttpResponse<Buffer> 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);
}

@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() {
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();
} catch (Exception e) {
return "invalid: " + refreshToken;
}
}
}
13 changes: 8 additions & 5 deletions ...common/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/LoginClientTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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));
}));
Expand Down Expand Up @@ -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."))
));
}

Expand Down Expand Up @@ -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"));
}));
}

Expand Down Expand Up @@ -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"));
}));
}

Expand Down
42 changes: 38 additions & 4 deletions ...mmon/src/test/java/org/folio/okapi/common/refreshtoken/client/impl/RefreshClientTest.java
View file
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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"))
));
}

Expand Down Expand Up @@ -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"))
));
}

Expand All @@ -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"))
));
}

Expand All @@ -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);
}
}

0 comments on commit 249a940

Please sign in to comment.