[ 
https://issues.apache.org/jira/browse/SLING-12478?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
 ]

Remo Liechti updated SLING-12478:
---------------------------------
    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.

 
{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}
 

  was:
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.


> Add potential origins of violations to the RequestDispatcher include API
> ------------------------------------------------------------------------
>
>                 Key: SLING-12478
>                 URL: https://issues.apache.org/jira/browse/SLING-12478
>             Project: Sling
>          Issue Type: Improvement
>          Components: Engine
>            Reporter: Remo Liechti
>            Assignee: Remo Liechti
>            Priority: Minor
>             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)

Reply via email to