This is an automated email from the ASF dual-hosted git repository.
rombert pushed a commit to branch master
in repository
https://gitbox.apache.org/repos/asf/sling-org-apache-sling-engine.git
The following commit(s) were added to refs/heads/master by this push:
new ff2569d SLING-12478 Add potential origins of violations to the
RequestDispatcher include API (#53)
ff2569d is described below
commit ff2569d45e7c683535258e08a602c9d9212066c9
Author: Remo Liechti <[email protected]>
AuthorDate: Tue Nov 19 11:15:04 2024 +0100
SLING-12478 Add potential origins of violations to the RequestDispatcher
include API (#53)
---
.../engine/impl/SlingHttpServletResponseImpl.java | 101 +++++++++++++++++--
.../impl/SlingHttpServletResponseImplTest.java | 107 ++++++++++++++++-----
2 files changed, 179 insertions(+), 29 deletions(-)
diff --git
a/src/main/java/org/apache/sling/engine/impl/SlingHttpServletResponseImpl.java
b/src/main/java/org/apache/sling/engine/impl/SlingHttpServletResponseImpl.java
index f4f6d94..cb639c5 100644
---
a/src/main/java/org/apache/sling/engine/impl/SlingHttpServletResponseImpl.java
+++
b/src/main/java/org/apache/sling/engine/impl/SlingHttpServletResponseImpl.java
@@ -26,9 +26,19 @@ import javax.servlet.http.HttpServletResponseWrapper;
import java.io.IOException;
import java.io.PrintWriter;
+import java.util.ArrayDeque;
+import java.util.ArrayList;
import java.util.Arrays;
+import java.util.Deque;
+import java.util.Iterator;
+import java.util.List;
import java.util.Locale;
import java.util.Optional;
+import java.util.Spliterators;
+import java.util.regex.Matcher;
+import java.util.regex.Pattern;
+import java.util.stream.Collectors;
+import java.util.stream.StreamSupport;
import org.apache.sling.api.SlingException;
import org.apache.sling.api.SlingHttpServletResponse;
@@ -41,6 +51,17 @@ public class SlingHttpServletResponseImpl extends
HttpServletResponseWrapper imp
private static final Logger LOG =
LoggerFactory.getLogger(SlingHttpServletResponseImpl.class);
+ // this regex matches TIMER_START{ followed by any characters except },
and then
+ // a closing }. The part inside the braces is captured for later use.
+ private static final String REGEX_TIMER_START = "TIMER_START\\{([^}]+)\\}";
+
+ // this regex matches TIMER_END{ followed by one or more digits, a comma,
any
+ // characters except }, and then a closing }. The part after the comma and
+ // before the closing brace is captured for later use.
+ private static final String REGEX_TIMER_END =
"TIMER_END\\{\\d+,([^}]+)\\}";
+
+ private static final String TIMER_SEPARATOR = " -> ";
+
public static class WriterAlreadyClosedException extends
IllegalStateException {
// just a marker class.
}
@@ -316,7 +337,9 @@ public class SlingHttpServletResponseImpl extends
HttpServletResponseWrapper imp
}
/**
- * Checks if the 'Content-Type' header is being overridden and provides a
message to log if it is.
+ * Checks if the 'Content-Type' header is being overridden and provides a
+ * message to log if it is.
+ *
* @param contentType the 'Content-Type' value that is being set
* @return an optional message to log
*/
@@ -339,28 +362,94 @@ public class SlingHttpServletResponseImpl extends
HttpServletResponseWrapper imp
}
/**
- * Retrieves the message to log when the 'Content-Type' header is changed
via an include.
+ * Finds unmatched TIMER_START messages in a log of messages.
+ *
+ * @return a string containing the unmatched TIMER_START messages
+ */
+ private String findUnmatchedTimerStarts() {
+ Iterator<String> messages =
requestData.getRequestProgressTracker().getMessages();
+ List<String> unmatchedStarts = new ArrayList<>();
+ Deque<String> timerDeque = new ArrayDeque<>();
+
+ Pattern startPattern = Pattern.compile(REGEX_TIMER_START);
+ Pattern endPattern = Pattern.compile(REGEX_TIMER_END);
+
+ while (messages.hasNext()) {
+ String message = messages.next();
+ Matcher startMatcher = startPattern.matcher(message);
+ Matcher endMatcher = endPattern.matcher(message);
+
+ // use a Deque to keep track of the timers that have been started.
When
+ // an end timer is found, it is compared to the top of the deque.
If they match,
+ // the timer is removed from the deque. If they don't match, the
timer is added
+ // to the list of unmatched starts. As the deque is a LIFO data
structure, the
+ // last timer that was started will be the first one to be ended.
There is no
+ // Start1, Start2, End1 scenario, without an End2 in between.
+ if (startMatcher.find()) {
+ timerDeque.push(startMatcher.group(1));
+ } else if (endMatcher.find()) {
+ String endTimer = endMatcher.group(1);
+ if (!timerDeque.isEmpty() &&
timerDeque.peek().equals(endTimer)) {
+ timerDeque.pop();
+ } else {
+ unmatchedStarts.add(endTimer);
+ }
+ }
+ }
+
+ // ignore the first element, as it will never have a matching end, as
it is the
+ // first timer started and is not finished processing
+ while (timerDeque.size() > 1) {
+ unmatchedStarts.add(timerDeque.pop());
+ }
+ StringBuilder sb = new StringBuilder();
+ for (String script : unmatchedStarts) {
+ sb.append(script).append(TIMER_SEPARATOR);
+ }
+ String ret = sb.toString();
+ if (ret.endsWith(TIMER_SEPARATOR)) {
+ ret = ret.substring(0, ret.length() - TIMER_SEPARATOR.length());
+ }
+ return ret;
+ }
+
+ /**
+ * Retrieves the message to log when the 'Content-Type' header is changed
via an
+ * include.
+ *
* @param currentContentType the current 'Content-Type' header
* @param setContentType the 'Content-Type' header that is being set
*/
private String getMessage(@Nullable String currentContentType, @Nullable
String setContentType) {
+ String unmatchedStartTimers = findUnmatchedTimerStarts();
+ String allMessages = StreamSupport.stream(
+ Spliterators.spliteratorUnknownSize(
+
requestData.getRequestProgressTracker().getMessages(), 0),
+ false)
+ .collect(Collectors.joining(System.lineSeparator()));
if (!isCheckContentTypeOnInclude()) {
return String.format(
"Servlet %s tried to override the 'Content-Type' header
from '%s' to '%s'. This is a violation of "
+ "the RequestDispatcher.include() contract - "
- +
"https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.";,
- requestData.getActiveServletName(), currentContentType,
setContentType);
+ +
"https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.
, Include stack: %s. All RequestProgressTracker messages: %s",
+ requestData.getActiveServletName(),
+ currentContentType,
+ setContentType,
+ unmatchedStartTimers,
+ allMessages);
}
return String.format(
"Servlet %s tried to override the 'Content-Type' header from
'%s' to '%s', however the"
+ " %s forbids this via the %s configuration property.
This is a violation of the "
+ "RequestDispatcher.include() contract - "
- +
"https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.";,
+ +
"https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.
, Include stack: %s. All RequestProgressTracker messages: %s",
requestData.getActiveServletName(),
currentContentType,
setContentType,
Config.PID,
- "sling.includes.checkcontenttype");
+ "sling.includes.checkcontenttype",
+ unmatchedStartTimers,
+ allMessages);
}
private static class ContentTypeChangeException extends SlingException {
diff --git
a/src/test/java/org/apache/sling/engine/impl/SlingHttpServletResponseImplTest.java
b/src/test/java/org/apache/sling/engine/impl/SlingHttpServletResponseImplTest.java
index 7407d9a..b358cc1 100644
---
a/src/test/java/org/apache/sling/engine/impl/SlingHttpServletResponseImplTest.java
+++
b/src/test/java/org/apache/sling/engine/impl/SlingHttpServletResponseImplTest.java
@@ -23,16 +23,21 @@ import javax.servlet.http.Cookie;
import javax.servlet.http.HttpServletResponse;
import java.io.IOException;
+import java.util.ArrayList;
+import java.util.Arrays;
+import java.util.stream.Collectors;
import org.apache.sling.api.SlingHttpServletResponse;
import org.apache.sling.api.request.RequestProgressTracker;
import org.apache.sling.engine.impl.request.DispatchingInfo;
import org.apache.sling.engine.impl.request.RequestData;
import org.junit.Test;
+import org.mockito.ArgumentCaptor;
import org.mockito.Mockito;
import static org.junit.Assert.assertEquals;
import static org.junit.Assert.assertNotNull;
+import static org.junit.Assert.assertTrue;
import static org.mockito.Mockito.mock;
import static org.mockito.Mockito.never;
import static org.mockito.Mockito.times;
@@ -42,6 +47,43 @@ import static org.mockito.Mockito.when;
public class SlingHttpServletResponseImplTest {
private static final String ACTIVE_SERVLET_NAME = "activeServlet";
+ String[] logMessages = {
+ "0 TIMER_START{Request Processing}",
+ "6 COMMENT timer_end format is {<elapsed microseconds>,<timer name>}
<optional message>",
+ "17 LOG Method=GET, PathInfo=null",
+ "20 TIMER_START{handleSecurity}",
+ "2104 TIMER_END{2081,handleSecurity} authenticator
org.apache.sling.auth.core.impl.SlingAuthenticator@6367091e returns true",
+ "2478 TIMER_START{ResourceResolution}",
+ "2668 TIMER_END{189,ResourceResolution} URI=/content/slingshot.html
resolves to Resource=JcrNodeResource, type=slingshot/Home, superType=null,
path=/content/slingshot",
+ "2678 LOG Resource Path Info: SlingRequestPathInfo:
path='/content/slingshot', selectorString='null', extension='html',
suffix='null'",
+ "2678 TIMER_START{ServletResolution}",
+ "2683 TIMER_START{resolveServlet(/content/slingshot)}",
+ "3724 TIMER_END{1040,resolveServlet(/content/slingshot)} Using servlet
/libs/slingshot/Home/html.jsp",
+ "3727 TIMER_END{1047,ServletResolution} URI=/content/slingshot.html
handled by Servlet=/libs/slingshot/Home/html.jsp",
+ "3736 LOG Applying REQUESTfilters",
+ "3751 LOG Calling filter:
com.composum.sling.nodes.mount.remote.RemoteRequestFilter",
+ "4722 TIMER_START{/libs/slingshot/Component/head.html.jsp#1}",
+ "3757 LOG Calling filter: org.apache.sling.i18n.impl.I18NFilter",
+ "4859 TIMER_END{135,/libs/slingshot/Component/head.html.jsp#1}",
+ "3765 LOG Calling filter:
org.apache.sling.engine.impl.debug.RequestProgressTrackerLogFilter",
+ "2678 TIMER_START{ServletResolution}",
+ "2683 TIMER_START{resolveServlet(/content/slingshot)}",
+ "2678 TIMER_START{ServletResolution}",
+ "2683 TIMER_START{resolveServlet(/content/slingshot)}",
+ "3724 TIMER_END{1040,resolveServlet(/content/slingshot)} Using servlet
/libs/slingshot/Home/html.jsp",
+ "3727 TIMER_END{1047,ServletResolution} URI=/content/slingshot.html
handled by Servlet=/libs/slingshot/Home/html.jsp",
+ "3724 TIMER_END{1040,resolveServlet(/content/slingshot)} Using servlet
/libs/slingshot/Home/html.jsp",
+ "3727 TIMER_END{1047,ServletResolution} URI=/content/slingshot.html
handled by Servlet=/libs/slingshot/Home/html.jsp",
+ "3774 LOG Applying Componentfilters",
+ "3797 TIMER_START{/libs/slingshot/Home/html.jsp#0}",
+ "3946 LOG Adding bindings took 18 microseconds",
+ "4405 LOG Including resource JcrNodeResource, type=slingshot/Home,
superType=null, path=/content/slingshot (SlingRequestPathInfo:
path='/content/slingshot', selectorString='head', extension='html',
suffix='null')",
+ "4414 TIMER_START{resolveServlet(/content/slingshot)}",
+ "4670 TIMER_END{253,resolveServlet(/content/slingshot)} Using servlet
/libs/slingshot/Component/head.html.jsp",
+ "4673 LOG Applying Includefilters",
+ "4722 TIMER_START{/libs/slingshot/Component/head.html.jsp#1}",
+ "4749 LOG Adding bindings took 4 microseconds"
+ };
@Test
public void testReset() {
@@ -74,6 +116,9 @@ public class SlingHttpServletResponseImplTest {
when(requestData.getDispatchingInfo()).thenReturn(info);
when(requestData.getRequestProgressTracker()).thenReturn(requestProgressTracker);
when(requestData.getActiveServletName()).thenReturn(ACTIVE_SERVLET_NAME);
+
+ ArrayList<String> logMessagesList = new
ArrayList<>(Arrays.asList(logMessages));
+ when(requestProgressTracker.getMessages()).thenAnswer(invocation ->
logMessagesList.iterator());
info.setProtectHeadersOnInclude(true);
final HttpServletResponse include = new
SlingHttpServletResponseImpl(requestData, orig);
@@ -90,12 +135,15 @@ public class SlingHttpServletResponseImplTest {
Mockito.verify(orig, never()).setLocale(null);
Mockito.verify(orig, never()).setBufferSize(4500);
- verify(requestProgressTracker, times(1))
- .log(String.format(
- "ERROR: Servlet %s tried to override the
'Content-Type' header from 'null'"
- + " to 'text/plain'. This is a violation of
the RequestDispatcher.include() contract -"
- + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.";,
- ACTIVE_SERVLET_NAME));
+ ArgumentCaptor<String> logCaptor =
ArgumentCaptor.forClass(String.class);
+ verify(requestProgressTracker, times(1)).log(logCaptor.capture());
+ String logMessage = logCaptor.getValue();
+ assertEquals(
+ String.format(
+ "ERROR: Servlet %s tried to override the
'Content-Type' header from 'null' to 'text/plain'. This is a violation of the
RequestDispatcher.include() contract -
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.
, Include stack: /libs/slingshot/Component/head.html.jsp#1 ->
/libs/slingshot/Home/html.jsp#0. All RequestProgressTracker messages: %s",
+ ACTIVE_SERVLET_NAME,
+
Arrays.asList(logMessages).stream().collect(Collectors.joining(System.lineSeparator()))),
+ logMessage);
}
@Test
@@ -134,6 +182,8 @@ public class SlingHttpServletResponseImplTest {
when(requestData.getDispatchingInfo()).thenReturn(info);
when(orig.getContentType()).thenReturn("text/html");
when(requestData.getRequestProgressTracker()).thenReturn(requestProgressTracker);
+ ArrayList<String> logMessagesList = new
ArrayList<>(Arrays.asList(logMessages));
+ when(requestProgressTracker.getMessages()).thenAnswer(invocation ->
logMessagesList.iterator());
info.setCheckContentTypeOnInclude(true);
final HttpServletResponse include = new
SlingHttpServletResponseImpl(requestData, orig);
@@ -146,24 +196,28 @@ public class SlingHttpServletResponseImplTest {
throwable = e;
}
Mockito.verify(orig, never()).setContentType("application/json");
- verify(requestProgressTracker, times(1))
- .log(String.format(
- "ERROR: Servlet %s tried to override the
'Content-Type' header from 'text/html'"
- + " to 'application/json', however the
org.apache.sling.engine.impl.SlingMainServlet"
- + " forbids this via the
sling.includes.checkcontenttype configuration property."
- + " This is a violation of the
RequestDispatcher.include() contract -"
- + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.";,
- ACTIVE_SERVLET_NAME));
+ ArgumentCaptor<String> logCaptor =
ArgumentCaptor.forClass(String.class);
+ verify(requestProgressTracker, times(1)).log(logCaptor.capture());
+ String logMessage = logCaptor.getValue();
+ assertTrue(logMessage.startsWith(String.format(
+ "ERROR: Servlet %s tried to override the 'Content-Type' header
from 'text/html'"
+ + " to 'application/json', however the
org.apache.sling.engine.impl.SlingMainServlet"
+ + " forbids this via the
sling.includes.checkcontenttype configuration property."
+ + " This is a violation of the
RequestDispatcher.include() contract -"
+ + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.
, Include stack: /libs/slingshot/Component/head.html.jsp#1 ->
/libs/slingshot/Home/html.jsp#0. All RequestProgressTracker messages: %s",
+ ACTIVE_SERVLET_NAME,
+
Arrays.asList(logMessages).stream().collect(Collectors.joining(System.lineSeparator())))));
assertNotNull("Expected a RuntimeException.", throwable);
- assertEquals(
- String.format(
+ assertTrue(throwable
+ .getMessage()
+ .startsWith(String.format(
"Servlet %s tried to override the 'Content-Type'
header from 'text/html' to"
+ " 'application/json', however the
org.apache.sling.engine.impl.SlingMainServlet forbids this"
+ " via the sling.includes.checkcontenttype
configuration property."
+ " This is a violation of the
RequestDispatcher.include() contract -"
- + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.";,
- ACTIVE_SERVLET_NAME),
- throwable.getMessage());
+ + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.
, Include stack: /libs/slingshot/Component/head.html.jsp#1 ->
/libs/slingshot/Home/html.jsp#0. All RequestProgressTracker messages: %s",
+ ACTIVE_SERVLET_NAME,
+
Arrays.asList(logMessages).stream().collect(Collectors.joining(System.lineSeparator())))));
}
@Test
@@ -175,19 +229,26 @@ public class SlingHttpServletResponseImplTest {
when(requestData.getDispatchingInfo()).thenReturn(info);
when(orig.getContentType()).thenReturn("text/html");
when(requestData.getRequestProgressTracker()).thenReturn(requestProgressTracker);
+ ArrayList<String> logMessagesList = new
ArrayList<>(Arrays.asList(logMessages));
+ when(requestProgressTracker.getMessages()).thenAnswer(invocation ->
logMessagesList.iterator());
final HttpServletResponse include = new
SlingHttpServletResponseImpl(requestData, orig);
when(requestData.getActiveServletName()).thenReturn(ACTIVE_SERVLET_NAME);
include.setContentType("application/json");
Mockito.verify(orig, times(1)).setContentType("application/json");
- verify(requestProgressTracker, times(1))
- .log(String.format(
+ ArgumentCaptor<String> logCaptor =
ArgumentCaptor.forClass(String.class);
+ verify(requestProgressTracker, times(1)).log(logCaptor.capture());
+ String logMessage = logCaptor.getValue();
+ assertEquals(
+ String.format(
"WARN: Servlet %s tried to override the 'Content-Type'
header from 'text/html'"
+ " to 'application/json'. This is a violation
of the RequestDispatcher.include()"
+ " contract -"
- + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.";,
- ACTIVE_SERVLET_NAME));
+ + "
https://jakarta.ee/specifications/servlet/4.0/apidocs/javax/servlet/requestdispatcher#include-javax.servlet.ServletRequest-javax.servlet.ServletResponse-.
, Include stack: /libs/slingshot/Component/head.html.jsp#1 ->
/libs/slingshot/Home/html.jsp#0. All RequestProgressTracker messages: %s",
+ ACTIVE_SERVLET_NAME,
+
Arrays.asList(logMessages).stream().collect(Collectors.joining(System.lineSeparator()))),
+ logMessage);
}
@Test
