Remo Liechti created SLING-12661:
------------------------------------
Summary: Potential origins of violations to the RequestDispatcher
include API may run into OOM error on excessive recursions
Key: SLING-12661
URL: https://issues.apache.org/jira/browse/SLING-12661
Project: Sling
Issue Type: Improvement
Components: Engine
Reporter: Remo Liechti
Assignee: Remo Liechti
Fix For: Engine 2.16.0
Add more information to the log about potential origins of the violation
message added in SLING-12454.
Use the RequestProgressTracker API to get the messages to find START_TIMER's
that do not have an END_TIMER yet, which means a violation is most likely
caused by that origin.
As an example message, please see below artificial message that was initially
generated with the sling snapshot docker image and then manually changed a bit
for unit testing reasons. The changes of this Jira task is highlighted in bold.
{code:java}
Servlet activeServlet 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-.
, Including scripts: [/libs/slingshot/Component/head.html.jsp#1,
/libs/slingshot/Home/html.jsp#0]. All RequestProgressTracker messages: 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
{code}
--
This message was sent by Atlassian Jira
(v8.20.10#820010)
