[java-idp-oidc] branch main updated: JOIDC-194 - Logging improvements for message tracing
Henri Mikkonen
henri.mikkonen at iki.fi
Thu Mar 14 12:04:15 UTC 2024
This is an automated email from the git hooks/post-receive script.
hjmikkon pushed a commit to branch main
in repository java-idp-oidc.
View the commit online:
http://git.shibboleth.net/view/?p=java-idp-oidc.git;a=commit;h=fb6fb4b2f7b59910cc2a43ae3f48538066d36e48
The following commit(s) were added to refs/heads/main by this push:
new fb6fb4b2 JOIDC-194 - Logging improvements for message tracing
fb6fb4b2 is described below
commit fb6fb4b2f7b59910cc2a43ae3f48538066d36e48
Author: Henri Mikkonen <henri.mikkonen at iki.fi>
AuthorDate: Thu Mar 14 14:00:33 2024 +0200
JOIDC-194 - Logging improvements for message tracing
https://shibboleth.atlassian.net/browse/JOIDC-194
Exploit Jackson ObjectMapper's writerWithDefaultPrettyPrinter when logging
JSON response messages and dynamic registration request. By default, the
shibboleth.oidc.JSONObjectMapper bean is exploited, but a custom ObjectMapper
bean may be wired via 'idp.oidc.logging.objectMapper' -property.
---
.../impl/OIDCClientRegistrationRequestDecoder.java | 30 +++++++++++++-
.../plugin/oidc/op/decoding/impl/RequestUtil.java | 46 ++++++++++++++++++++++
.../op/encoding/impl/NimbusResponseEncoder.java | 26 +++++++++---
.../plugin/oidc/op/encoding/impl/ResponseUtil.java | 31 ++++++++++++++-
.../issue-registration-access-token-beans.xml | 3 +-
.../flows/oidc/abstract/oidc-abstract-beans.xml | 3 +-
.../idp/flows/oidc/register/register-beans.xml | 4 +-
.../idp/plugin/oidc/op/conf/oidc.properties | 3 ++
.../OIDCClientRegistrationRequestDecoderTest.java | 19 +++++++++
9 files changed, 154 insertions(+), 11 deletions(-)
diff --git a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoder.java b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoder.java
index f0a9fa63..cf7a9557 100644
--- a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoder.java
+++ b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoder.java
@@ -23,6 +23,7 @@ import org.opensaml.messaging.decoder.MessageDecodingException;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+import com.fasterxml.jackson.databind.ObjectMapper;
import com.google.common.base.MoreObjects;
import com.nimbusds.oauth2.sdk.ParseException;
import com.nimbusds.oauth2.sdk.client.ClientRegistrationRequest;
@@ -32,6 +33,9 @@ import com.nimbusds.openid.connect.sdk.rp.OIDCClientRegistrationRequest;
import net.minidev.json.JSONObject;
import net.shibboleth.idp.plugin.oidc.op.oauth2.decoding.impl.BaseOAuth2RequestDecoder;
+import net.shibboleth.shared.annotation.constraint.NonnullAfterInit;
+import net.shibboleth.shared.component.ComponentInitializationException;
+import net.shibboleth.shared.logic.Constraint;
/**
* Message decoder decoding OpenID Connect {@link ClientRegistrationRequest}s.
@@ -42,12 +46,36 @@ public class OIDCClientRegistrationRequestDecoder extends BaseOAuth2RequestDecod
@Nonnull
private final Logger log = LoggerFactory.getLogger(OIDCClientRegistrationRequestDecoder.class);
+ /** Object mapper used for pretty-printing JSON in the request. */
+ @NonnullAfterInit private ObjectMapper objectMapper;
+
+ /**
+ * Set the object mapper used for pretty-printing JSON in the request.
+ *
+ * @param mapper What to set.
+ *
+ * @since 4.1.0
+ */
+ public void setObjectMapper(@Nonnull final ObjectMapper mapper) {
+ checkSetterPreconditions();
+ objectMapper = Constraint.isNotNull(mapper, "Object mapper cannot be null");
+ }
+
+ /** {@inheritDoc} */
+ protected void doInitialize() throws ComponentInitializationException {
+ super.doInitialize();
+
+ if (objectMapper == null) {
+ throw new ComponentInitializationException("Object mapper cannot be null");
+ }
+ }
+
/** {@inheritDoc} */
@Override
protected OIDCClientRegistrationRequest parseMessage() throws MessageDecodingException {
try {
final HTTPRequest httpRequest = JakartaServletUtils.createHTTPRequest(getHttpServletRequest());
- getProtocolMessageLogger().trace("Inbound request {}", RequestUtil.toString(httpRequest));
+ getProtocolMessageLogger().trace("Inbound request {}", RequestUtil.toString(httpRequest, objectMapper));
final JSONObject requestJson = httpRequest.getQueryAsJSONObject();
//TODO: Nimbus seems to be interpreting scope in different way as many RPs, currently the scope
//is removed in this phase, better solution TODO.
diff --git a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/RequestUtil.java b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/RequestUtil.java
index 5c6b6def..4a83b43b 100644
--- a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/RequestUtil.java
+++ b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/RequestUtil.java
@@ -20,6 +20,8 @@ import java.util.Map.Entry;
import javax.annotation.Nullable;
+import com.fasterxml.jackson.core.JsonProcessingException;
+import com.fasterxml.jackson.databind.ObjectMapper;
import com.google.common.base.MoreObjects;
import com.nimbusds.oauth2.sdk.AuthorizationCodeGrant;
import com.nimbusds.oauth2.sdk.AuthorizationGrant;
@@ -67,6 +69,50 @@ public final class RequestUtil {
return ret;
}
+ /**
+ * Helper method to print request to string for logging.
+ *
+ * @param httpReq request to be printed
+ * @param objectMapper object mapper used for pretty printing JSON content
+ * @return request as formatted string.
+ *
+ * @since 4.1.0
+ */
+ @Nullable public static String toString(@Nullable final HTTPRequest httpReq,
+ @Nullable final ObjectMapper objectMapper) {
+ if (httpReq == null) {
+ return null;
+ }
+ final String nl = System.lineSeparator();
+ String ret = httpReq.getMethod().toString() + nl;
+ final Map<String, List<String>> headers = httpReq.getHeaderMap();
+ if (headers != null) {
+ ret += "Headers:" + nl;
+ for (final Entry<String, List<String>> entry : headers.entrySet()) {
+ ret += "\t" + entry.getKey() + ":" + entry.getValue() + nl;
+ }
+ }
+ final Map<String, List<String>> parameters = httpReq.getQueryParameters();
+ if (parameters != null) {
+ if (objectMapper != null && !parameters.isEmpty()) {
+ final String rawValue = parameters.keySet().iterator().next();
+ try {
+ final Object jsonObject = objectMapper.readValue(rawValue, Object.class);
+ final String content = objectMapper.writerWithDefaultPrettyPrinter().writeValueAsString(jsonObject);
+ return ret + "Content:" + content.replace("\n", "\n\t");
+ } catch (JsonProcessingException e) {
+ // fall-back into not using object mapper
+ }
+
+ }
+ ret += "Parameters:" + nl;
+ for (final Entry<String, List<String>> entry : parameters.entrySet()) {
+ ret += "\t" + entry.getKey() + ":" + entry.getValue().get(0) + nl;
+ }
+ }
+ return ret;
+ }
+
/**
* Helper method for getting protocol log message for client authentication object.
*
diff --git a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/NimbusResponseEncoder.java b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/NimbusResponseEncoder.java
index 0d6b43c9..ac255841 100644
--- a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/NimbusResponseEncoder.java
+++ b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/NimbusResponseEncoder.java
@@ -29,6 +29,8 @@ import org.opensaml.messaging.encoder.MessageEncodingException;
import org.opensaml.messaging.encoder.servlet.AbstractHttpServletResponseMessageEncoder;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
+
+import com.fasterxml.jackson.databind.ObjectMapper;
import com.nimbusds.oauth2.sdk.AuthorizationResponse;
import com.nimbusds.oauth2.sdk.Response;
import com.nimbusds.oauth2.sdk.ResponseMode;
@@ -36,6 +38,7 @@ import com.nimbusds.oauth2.sdk.http.HTTPResponse;
import com.nimbusds.oauth2.sdk.http.JakartaServletUtils;
import jakarta.servlet.http.HttpServletResponse;
+import net.shibboleth.shared.annotation.constraint.NonnullAfterInit;
import net.shibboleth.shared.annotation.constraint.NotEmpty;
import net.shibboleth.shared.codec.HTMLEncoder;
import net.shibboleth.shared.logic.Constraint;
@@ -59,6 +62,9 @@ public class NimbusResponseEncoder extends AbstractHttpServletResponseMessageEnc
/** ID of the Velocity template used when using FORM POST response mode. */
@Nonnull @NotEmpty private String velocityTemplateId = DEFAULT_TEMPLATE_ID;
+ /** Object mapper used for pretty-printing JSON response. */
+ @NonnullAfterInit private ObjectMapper objectMapper;
+
/** Constructor. */
public NimbusResponseEncoder() {
super();
@@ -75,8 +81,7 @@ public class NimbusResponseEncoder extends AbstractHttpServletResponseMessageEnc
* @param newVelocityTemplateId the new Velocity template id
*/
public void setVelocityTemplateId(final String newVelocityTemplateId) {
- ifInitializedThrowUnmodifiabledComponentException();
- ifDestroyedThrowDestroyedComponentException();
+ checkSetterPreconditions();
Constraint.isNotEmpty(newVelocityTemplateId, "Velocity template id must not not be null or empty");
velocityTemplateId = newVelocityTemplateId;
}
@@ -87,11 +92,22 @@ public class NimbusResponseEncoder extends AbstractHttpServletResponseMessageEnc
* @param newVelocityEngine the new VelocityEngine instane
*/
public void setVelocityEngine(final VelocityEngine newVelocityEngine) {
- ifInitializedThrowUnmodifiabledComponentException();
- ifDestroyedThrowDestroyedComponentException();
+ checkSetterPreconditions();
velocityEngine = newVelocityEngine;
}
+ /**
+ * Set the object mapper used for pretty-printing JSON in the request.
+ *
+ * @param mapper What to set.
+ *
+ * @since 4.1.0
+ */
+ public void setObjectMapper(@Nonnull final ObjectMapper mapper) {
+ checkSetterPreconditions();
+ objectMapper = Constraint.isNotNull(mapper, "Object mapper cannot be null");
+ }
+
/**
* Whether we should use FORM POST response encoding.
*
@@ -146,7 +162,7 @@ public class NimbusResponseEncoder extends AbstractHttpServletResponseMessageEnc
return;
}
final HTTPResponse resp = ((Response) getMessageContext().getMessage()).toHTTPResponse();
- getProtocolMessageLogger().trace("Outbound response {}", ResponseUtil.toString(resp));
+ getProtocolMessageLogger().trace("Outbound response {}", ResponseUtil.toString(resp, objectMapper));
JakartaServletUtils.applyHTTPResponse(resp, response);
} catch (final IOException e) {
throw new MessageEncodingException("Problem encoding response", e);
diff --git a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/ResponseUtil.java b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/ResponseUtil.java
index 9771e56c..bb77eac4 100644
--- a/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/ResponseUtil.java
+++ b/idp-oidc-extension-impl/src/main/java/net/shibboleth/idp/plugin/oidc/op/encoding/impl/ResponseUtil.java
@@ -22,6 +22,8 @@ import java.util.Map.Entry;
import javax.annotation.Nonnull;
import javax.annotation.Nullable;
+import com.fasterxml.jackson.core.JsonProcessingException;
+import com.fasterxml.jackson.databind.ObjectMapper;
import com.google.common.base.MoreObjects;
import com.nimbusds.oauth2.sdk.AccessTokenResponse;
import com.nimbusds.oauth2.sdk.AuthorizationErrorResponse;
@@ -70,6 +72,20 @@ public final class ResponseUtil {
* @return response as formatted string.
*/
protected static String toString(@Nullable final HTTPResponse httpResponse) {
+ return toString(httpResponse, null);
+ }
+
+ /**
+ * Helper method to print response to string for logging.
+ *
+ * @param httpResponse response to be printed
+ * @param objectMapper object mapper used for pretty printing JSON content
+ * @return response as formatted string
+ *
+ * @since 4.1.0
+ */
+ protected static String toString(@Nullable final HTTPResponse httpResponse,
+ @Nullable final ObjectMapper objectMapper) {
if (httpResponse == null) {
return null;
}
@@ -82,8 +98,19 @@ public final class ResponseUtil {
ret += "\t" + entry.getKey() + ":" + entry.getValue().get(0) + nl;
}
}
- if (httpResponse.getContent() != null) {
- ret += "Content:" + httpResponse.getContent();
+ final String rawContent = httpResponse.getContent();
+ if (rawContent != null) {
+ if (objectMapper != null) {
+ try {
+ final Object jsonObject = objectMapper.readValue(rawContent, Object.class);
+ final String content = objectMapper.writerWithDefaultPrettyPrinter().writeValueAsString(jsonObject);
+ ret += "Content:" + content.replace("\n", "\n\t");
+ return ret;
+ } catch (JsonProcessingException e) {
+ // fall-back into not using object mapper
+ }
+ }
+ ret += "Content:" + rawContent;
}
return ret;
}
diff --git a/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/admin/oidc/issue-registration-access-token/issue-registration-access-token-beans.xml b/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/admin/oidc/issue-registration-access-token/issue-registration-access-token-beans.xml
index 4b3b7813..6d3d64ee 100644
--- a/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/admin/oidc/issue-registration-access-token/issue-registration-access-token-beans.xml
+++ b/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/admin/oidc/issue-registration-access-token/issue-registration-access-token-beans.xml
@@ -104,7 +104,8 @@
<bean id="oidc.nimbusEncoder" class="net.shibboleth.idp.plugin.oidc.op.encoding.impl.NimbusResponseEncoder"
scope="prototype" p:httpServletResponseSupplier-ref="shibboleth.HttpServletResponseSupplier" init-method=""
- p:velocityEngine-ref="shibboleth.VelocityEngine" />
+ p:velocityEngine-ref="shibboleth.VelocityEngine"
+ p:objectMapper-ref="#{'%{idp.oidc.logging.objectMapper:shibboleth.oidc.JSONObjectMapper}'.trim()}"/>
<bean id="EncodeMessage" class="org.opensaml.profile.action.impl.EncodeMessage" scope="prototype"
p:messageEncoderFactory-ref="oidc.messageEncoderFactory"
diff --git a/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/abstract/oidc-abstract-beans.xml b/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/abstract/oidc-abstract-beans.xml
index 50e4d496..8b55525c 100644
--- a/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/abstract/oidc-abstract-beans.xml
+++ b/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/abstract/oidc-abstract-beans.xml
@@ -53,7 +53,8 @@
<bean id="oidc.nimbusEncoder" class="net.shibboleth.idp.plugin.oidc.op.encoding.impl.NimbusResponseEncoder"
scope="prototype" p:httpServletResponseSupplier-ref="shibboleth.HttpServletResponseSupplier" init-method=""
- p:velocityEngine-ref="shibboleth.VelocityEngine" />
+ p:velocityEngine-ref="shibboleth.VelocityEngine"
+ p:objectMapper-ref="#{'%{idp.oidc.logging.objectMapper:shibboleth.oidc.JSONObjectMapper}'.trim()}"/>
<bean id="EncodeMessage" class="org.opensaml.profile.action.impl.EncodeMessage" scope="prototype"
p:messageEncoderFactory-ref="oidc.messageEncoderFactory"
diff --git a/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/register/register-beans.xml b/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/register/register-beans.xml
index 48fe8013..63e7af9b 100644
--- a/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/register/register-beans.xml
+++ b/idp-oidc-extension-impl/src/main/resources/META-INF/net/shibboleth/idp/flows/oidc/register/register-beans.xml
@@ -30,7 +30,8 @@
class="net.shibboleth.idp.plugin.oidc.op.decoding.impl.OIDCClientRegistrationRequestDecoder"
scope="prototype"
p:httpServletRequestSupplier-ref="shibboleth.HttpServletRequestSupplier"
- p:removeIpAddressFromEndpointUri="%{idp.oidc.logging.removeIpAddressFromProtocolMessage:false}"/>
+ p:removeIpAddressFromEndpointUri="%{idp.oidc.logging.removeIpAddressFromProtocolMessage:false}"
+ p:objectMapper-ref="#{'%{idp.oidc.logging.objectMapper:shibboleth.oidc.JSONObjectMapper}'.trim()}"/>
</constructor-arg>
</bean>
@@ -194,6 +195,7 @@
class="net.shibboleth.idp.plugin.oidc.op.encoding.impl.NimbusResponseEncoder"
scope="prototype"
p:httpServletResponseSupplier-ref="shibboleth.HttpServletResponseSupplier"
+ p:objectMapper-ref="#{'%{idp.oidc.logging.objectMapper:shibboleth.oidc.JSONObjectMapper}'.trim()}"
init-method="" />
<bean id="EncodeMessage"
diff --git a/idp-oidc-extension-impl/src/main/resources/net/shibboleth/idp/plugin/oidc/op/conf/oidc.properties b/idp-oidc-extension-impl/src/main/resources/net/shibboleth/idp/plugin/oidc/op/conf/oidc.properties
index fec6e776..055bec09 100644
--- a/idp-oidc-extension-impl/src/main/resources/net/shibboleth/idp/plugin/oidc/op/conf/oidc.properties
+++ b/idp-oidc-extension-impl/src/main/resources/net/shibboleth/idp/plugin/oidc/op/conf/oidc.properties
@@ -117,6 +117,9 @@ idp.oidc.subject.salt = this_too_should_be_ch4ng3d
# Set to true to hide protocol-scheme, IP-address and port for endpointURI in PROTOCOL_MESSAGE.OAUTH2 logging. Defaults to false.
#idp.oidc.logging.removeIpAddressFromProtocolMessage = true
+# ObjectMapper bean used for pretty-printing JSON in rotocol messages. Defaults to shibboleth.oidc.JSONObjectMapper
+#idp.oidc.logging.objectMapper = shibboleth.oidc.JSONObjectMapper
+
# Settings for issue-registration-access-token flow
#idp.oidc.admin.registration.logging = IssueRegistrationAccessToken
#idp.oidc.admin.registration.nonBrowserSupported = true
diff --git a/idp-oidc-extension-impl/src/test/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoderTest.java b/idp-oidc-extension-impl/src/test/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoderTest.java
index dd21b898..82330400 100644
--- a/idp-oidc-extension-impl/src/test/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoderTest.java
+++ b/idp-oidc-extension-impl/src/test/java/net/shibboleth/idp/plugin/oidc/op/decoding/impl/OIDCClientRegistrationRequestDecoderTest.java
@@ -24,11 +24,13 @@ import org.testng.Assert;
import org.testng.annotations.BeforeMethod;
import org.testng.annotations.Test;
+import com.fasterxml.jackson.databind.ObjectMapper;
import com.google.common.io.Files;
import com.nimbusds.oauth2.sdk.http.HTTPRequest.Method;
import com.nimbusds.openid.connect.sdk.rp.OIDCClientRegistrationRequest;
import jakarta.servlet.http.HttpServletRequest;
+import net.shibboleth.shared.component.ComponentInitializationException;
import net.shibboleth.shared.primitive.NonnullSupplier;
/**
@@ -43,6 +45,23 @@ public class OIDCClientRegistrationRequestDecoderTest {
protected void setUp() throws Exception {
httpRequest = new MockHttpServletRequest();
httpRequest.setMethod(Method.POST.toString());
+ decoder = new OIDCClientRegistrationRequestDecoder();
+ decoder.setHttpServletRequestSupplier(new NonnullSupplier<> () {
+ public HttpServletRequest get() { return httpRequest;}
+ });
+ decoder.setObjectMapper(new ObjectMapper());
+ decoder.initialize();
+ }
+
+ @Test(expectedExceptions = ComponentInitializationException.class)
+ public void testNoHttpServletRequest() throws ComponentInitializationException {
+ decoder = new OIDCClientRegistrationRequestDecoder();
+ decoder.setObjectMapper(new ObjectMapper());
+ decoder.initialize();
+ }
+
+ @Test(expectedExceptions = ComponentInitializationException.class)
+ public void testNoObjectMapper() throws ComponentInitializationException {
decoder = new OIDCClientRegistrationRequestDecoder();
decoder.setHttpServletRequestSupplier(new NonnullSupplier<> () {
public HttpServletRequest get() { return httpRequest;}
--
To stop receiving notification emails like this one, please contact
the administrator of this repository.
More information about the commits
mailing list