[SLING-12478] Add potential origins of violations to the RequestDispatcher include API

• Type: Improvement
• Status: Closed
• Priority: Minor
• Resolution: Fixed
• Fix Version/s: Engine 2.16.0
• Component/s: Engine
• Assignee: Remo Liechti
• Reporter: Remo Liechti
• Created: 08/Nov/24 13:12
• Updated: 26/Nov/24 15:03
• Resolved: 19/Nov/24 10:15

Description

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.

 

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

 

Issue Links

• relates to: SLING-12454 Allow configuring the warning severity of scripts that don't obey the RequestDispatcher include API
• links to: GitHub Pull Request #53