This is an automated email from the ASF dual-hosted git repository.
joerghoh 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 7bcfb6c SLING-13361 escape data for the
RequestProgressTrackerLogFilter (#92)
7bcfb6c is described below
commit 7bcfb6c005f0986bfc00ae32f9362dfd69e8fd84
Author: Jörg Hoh <[email protected]>
AuthorDate: Wed Sep 23 19:33:17 2026 +0200
SLING-13361 escape data for the RequestProgressTrackerLogFilter (#92)
---
.../debug/RequestProgressTrackerLogFilter.java | 46 +++++++-
.../debug/RequestProgressTrackerLogFilterTest.java | 118 +++++++++++++++++++++
2 files changed, 160 insertions(+), 4 deletions(-)
diff --git
a/src/main/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilter.java
b/src/main/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilter.java
index 0fae220..de45734 100644
---
a/src/main/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilter.java
+++
b/src/main/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilter.java
@@ -131,11 +131,10 @@ public class RequestProgressTrackerLogFilter implements
Filter {
private void logCompactFormat(RequestProgressTracker rpt) {
final Iterator<String> messages = rpt.getMessages();
- final StringBuilder sb = new StringBuilder("\n");
+ final StringBuilder sb = new StringBuilder();
while (messages.hasNext()) {
- sb.append(messages.next());
+ sb.append('\n').append(escapeLogMessage(messages.next()));
}
- sb.setLength(sb.length() - 1);
log.debug(sb.toString());
}
@@ -146,10 +145,49 @@ public class RequestProgressTrackerLogFilter implements
Filter {
}
final Iterator<String> it = rpt.getMessages();
while (it.hasNext()) {
- log.debug("REQUEST_{} - " + it.next(), requestId);
+ log.debug("REQUEST_{} - {}", requestId,
escapeLogMessage(it.next()));
}
}
+ /**
+ * Escapes a request progress tracker message for logging.
+ * <p>
+ * Tracker messages embed request-derived, attacker-controllable data
+ * (container-decoded path info, selectors, suffix, request URI). Escaping
+ * embedded CR and LF prevents such data from forging additional log lines
+ * (log injection, CWE-117). Messages must also always be passed to SLF4J
+ * as a parameter - never concatenated into the format string - so that
+ * attacker-supplied <code>{}</code> sequences are not substituted. The
+ * line terminator the tracker appends to each message is removed.
+ *
+ * @param message the tracker message, may be <code>null</code>
+ * @return the escaped message
+ */
+ static String escapeLogMessage(final String message) {
+ if (message == null) {
+ return null;
+ }
+ // strip the line terminator the tracker appends to each message
+ int end = message.length();
+ while (end > 0 && (message.charAt(end - 1) == '\n' ||
message.charAt(end - 1) == '\r')) {
+ end--;
+ }
+ StringBuilder sb = null;
+ for (int i = 0; i < end; i++) {
+ final char c = message.charAt(i);
+ if (c == '\n' || c == '\r') {
+ if (sb == null) {
+ sb = new StringBuilder(end + 8);
+ sb.append(message, 0, i);
+ }
+ sb.append(c == '\n' ? "\\n" : "\\r");
+ } else if (sb != null) {
+ sb.append(c);
+ }
+ }
+ return sb != null ? sb.toString() : message.substring(0, end);
+ }
+
private String extractExtension(SlingJakartaHttpServletRequest request) {
final RequestPathInfo requestPathInfo = request.getRequestPathInfo();
String extension = requestPathInfo.getExtension();
diff --git
a/src/test/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilterTest.java
b/src/test/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilterTest.java
index 37ca80b..f99bf3e 100644
---
a/src/test/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilterTest.java
+++
b/src/test/java/org/apache/sling/engine/impl/debug/RequestProgressTrackerLogFilterTest.java
@@ -19,13 +19,26 @@
package org.apache.sling.engine.impl.debug;
import java.lang.annotation.Annotation;
+import java.lang.reflect.Field;
import java.lang.reflect.Method;
+import java.util.Arrays;
+import java.util.Iterator;
import org.apache.sling.api.request.RequestProgressTracker;
import org.apache.sling.api.request.builder.Builders;
import org.junit.Test;
+import org.mockito.ArgumentCaptor;
+import org.slf4j.Logger;
+import org.slf4j.helpers.MessageFormatter;
+import static org.junit.Assert.assertEquals;
+import static org.junit.Assert.assertFalse;
+import static org.junit.Assert.assertNull;
import static org.junit.Assert.assertTrue;
+import static org.mockito.Mockito.mock;
+import static org.mockito.Mockito.times;
+import static org.mockito.Mockito.verify;
+import static org.mockito.Mockito.when;
/** Partial tests of RequestProgressTrackerLogFilter */
public class RequestProgressTrackerLogFilterTest {
@@ -89,6 +102,111 @@ public class RequestProgressTrackerLogFilterTest {
assertTrue("Expecting min ratio of " + minExpectedRatio + ", got " +
ratio, ratio > minExpectedRatio);
}
+ @Test
+ public void testEscapeLogMessageEscapesCrLf() {
+ // a percent-encoded CR/LF in the request path is decoded by the
+ // container, recorded by the tracker and must not forge log lines
+ assertEquals(
+ "17 LOG Method=GET, PathInfo=/content/x\\r\\n2026-08-11 FAKE
admin login OK",
+ RequestProgressTrackerLogFilter.escapeLogMessage(
+ "17 LOG Method=GET, PathInfo=/content/x\r\n2026-08-11
FAKE admin login OK\n"));
+ }
+
+ @Test
+ public void testEscapeLogMessageKeepsBenignMessage() {
+ assertEquals(
+ "20 TIMER_START{handleSecurity}",
+ RequestProgressTrackerLogFilter.escapeLogMessage("20
TIMER_START{handleSecurity}\n"));
+ assertEquals("",
RequestProgressTrackerLogFilter.escapeLogMessage("\n"));
+ assertNull(RequestProgressTrackerLogFilter.escapeLogMessage(null));
+ }
+
+ /**
+ * Replaces the filter's private final SLF4J {@code Logger} with a mock so
+ * the exact arguments reaching the logger can be captured.
+ */
+ private Logger injectMockLogger(final RequestProgressTrackerLogFilter
filter) throws Exception {
+ final Logger logger = mock(Logger.class);
+ final Field logField =
RequestProgressTrackerLogFilter.class.getDeclaredField("log");
+ logField.setAccessible(true);
+ logField.set(filter, logger);
+ return logger;
+ }
+
+ private void invokeLogFormat(
+ final RequestProgressTrackerLogFilter filter, final String
methodName, final RequestProgressTracker rpt)
+ throws Exception {
+ final Method method = filter.getClass().getDeclaredMethod(methodName,
RequestProgressTracker.class);
+ method.setAccessible(true);
+ method.invoke(filter, rpt);
+ }
+
+ private RequestProgressTracker rptWithMessages(final String... messages) {
+ final RequestProgressTracker rpt = mock(RequestProgressTracker.class);
+ final Iterator<String> it = Arrays.asList(messages).iterator();
+ when(rpt.getMessages()).thenAnswer(invocation -> it);
+ return rpt;
+ }
+
+ @Test
+ public void
testLogDefaultFormatNeverConcatenatesMessageIntoFormatStringAndEscapesCrLf()
throws Exception {
+ // a percent-encoded CR/LF in the request path, decoded by the
+ // container and recorded by the tracker, plus a literal "{}" that an
+ // attacker could use to try to smuggle an extra SLF4J placeholder
+ final String attackerMessage = "17 LOG Method=GET,
PathInfo=/content/x\r\n2026-08-11 FAKE admin login OK {}";
+ final RequestProgressTracker rpt = rptWithMessages(attackerMessage);
+
+ final RequestProgressTrackerLogFilter filter = new
RequestProgressTrackerLogFilter();
+ final Logger logger = injectMockLogger(filter);
+
+ invokeLogFormat(filter, "logDefaultFormat", rpt);
+
+ // the message must be passed to SLF4J as a parameter, never
+ // concatenated into the format string itself - otherwise attacker
+ // supplied "{}" sequences would be (mis)interpreted as placeholders
+ final ArgumentCaptor<String> formatCaptor =
ArgumentCaptor.forClass(String.class);
+ final ArgumentCaptor<Object> requestIdCaptor =
ArgumentCaptor.forClass(Object.class);
+ final ArgumentCaptor<Object> messageCaptor =
ArgumentCaptor.forClass(Object.class);
+ verify(logger, times(1)).debug(formatCaptor.capture(),
requestIdCaptor.capture(), messageCaptor.capture());
+
+ assertEquals("REQUEST_{} - {}", formatCaptor.getValue());
+ final String escapedMessage = (String) messageCaptor.getValue();
+ assertFalse(escapedMessage.contains("\r"));
+ assertFalse(escapedMessage.contains("\n"));
+
+ // simulate the actual SLF4J rendering to prove the injected CRLF can
+ // no longer forge a new log record and the attacker's literal "{}"
+ // is not treated as an additional placeholder
+ final String rendered = MessageFormatter.arrayFormat(
+ formatCaptor.getValue(), new Object[]
{requestIdCaptor.getValue(), messageCaptor.getValue()})
+ .getMessage();
+ assertFalse(rendered.contains("\r"));
+ assertFalse(rendered.contains("\n"));
+ assertEquals(
+ "REQUEST_1 - 17 LOG Method=GET,
PathInfo=/content/x\\r\\n2026-08-11 FAKE admin login OK {}", rendered);
+ }
+
+ @Test
+ public void testLogCompactFormatEscapesEveryMessageBeforeJoining() throws
Exception {
+ final String benign = "20 TIMER_START{handleSecurity}";
+ final String attackerMessage = "17 LOG Method=GET,
PathInfo=/content/x\r\nFORGED admin login OK";
+ final RequestProgressTracker rpt = rptWithMessages(benign,
attackerMessage);
+
+ final RequestProgressTrackerLogFilter filter = new
RequestProgressTrackerLogFilter();
+ final Logger logger = injectMockLogger(filter);
+
+ invokeLogFormat(filter, "logCompactFormat", rpt);
+
+ final ArgumentCaptor<String> messageCaptor =
ArgumentCaptor.forClass(String.class);
+ verify(logger, times(1)).debug(messageCaptor.capture());
+
+ final String logged = messageCaptor.getValue();
+ assertFalse(logged.contains("\r"));
+ assertFalse("no raw newline may remain other than the message
separators", logged.contains("\r\n"));
+ assertEquals(
+ "\n" + benign + "\n" + "17 LOG Method=GET,
PathInfo=/content/x\\r\\nFORGED admin login OK", logged);
+ }
+
@Test
public void testConfigMsec() throws Exception {
final RequestProgressTrackerLogFilter filter = new
RequestProgressTrackerLogFilter();
