[
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel&focusedCommentId=14994887#comment-14994887
]
Alexander Klimetschek edited comment on SLING-5274 at 11/7/15 2:31 AM:
-----------------------------------------------------------------------
Attached patch: [^SLING-5274.patch]
Example authentication success:
{noformat}
0 TIMER_START{Request Processing}
1 COMMENT timer_end format is {<elapsed microsec>,<timer name>} <optional
message>
8 LOG Method=GET,
Path=/is/image/content/dam/geometrixx/portraits/scott_reynolds.jpg
12 TIMER_START{Authentication}
24 LOG Calling auth handler: Cloud IMS Authentication Handler
46 LOG Calling auth handler: OAuth Authentication Handler
65 LOG Calling auth handler: Day CQ Login Selector Authentication Handler
68 LOG Calling auth handler: Granite Client Certificate Authentication
Handler
71 LOG Calling auth handler: Token Authentication Handler
77 LOG Calling auth handler: ImageServer Authentication Handler
80 LOG Calling auth handler:
org.apache.sling.auth.core.impl.HttpBasicAuthenticationHandler
101 LOG AuthenticationHandlers returned: type=BASIC, userId=admin
105 LOG Calling auth post processor:
com.adobe.cq.social.commons.cors.CORSAuthInfoPostProcessor
106 LOG Calling auth post processor:
org.apache.sling.jcr.resource.internal.WorkspaceAuthInfoPostProcessor
109 LOG Calling auth post processor:
com.adobe.cq.creativecloud.cloudims.impl.auth.cookie.TokenAuthenticationInfoPostProcessor
144 LOG Trying to get a resource resolver for: type=BASIC, userId=admin
12408 LOG Login success: Resource Resolver, userId=admin
12428 TIMER_END{12415,Authentication} succeeded
12611 TIMER_START{ResourceResolution}
... existing logs
{noformat}
Example authentication failure (note that these were not recorded/visible so
far!):
{noformat}
0 TIMER_START{Request Processing}
1 COMMENT timer_end format is {<elapsed microsec>,<timer name>} <optional
message>
8 LOG Method=GET, Path=/bin/ping
15 TIMER_START{Authentication}
31 LOG Calling auth handler: Cloud IMS Authentication Handler
59 LOG Calling auth handler: OAuth Authentication Handler
78 LOG Calling auth handler: Day CQ Login Selector Authentication Handler
81 LOG Calling auth handler: Granite Client Certificate Authentication
Handler
83 LOG Calling auth handler: Token Authentication Handler
88 LOG Calling auth handler: ImageServer Authentication Handler
91 LOG Calling auth handler:
org.apache.sling.auth.core.impl.HttpBasicAuthenticationHandler
115 LOG AuthenticationHandlers returned: type=BASIC, userId=admin
120 LOG Calling auth post processor:
com.adobe.cq.social.commons.cors.CORSAuthInfoPostProcessor
121 LOG Calling auth post processor:
org.apache.sling.jcr.resource.internal.WorkspaceAuthInfoPostProcessor
125 LOG Calling auth post processor:
com.adobe.cq.creativecloud.cloudims.impl.auth.cookie.TokenAuthenticationInfoPostProcessor
160 LOG Trying to get a resource resolver for: type=BASIC, userId=admin
4572 LOG Login failed: UserId/Password mismatch.
4738 TIMER_END{4720,Authentication} failed
{noformat}
Note that the examples include microsecond logging from the patch in SLING-5275.
Notes about the changes:
- the SlingRequestProgressTracker is now created in
SlingHttpContext#handleSecurity() to start early
- and passed around as request attribute (since at that early stage there is no
SlingHttpServletRequest present yet)
- also getPathInfo() will be null at this early stage and actually never
resolved if the authentication fails, hence using getRequestURI() if it's null
(in the recent request console printer)
- tried to log all pluggable parts and their actual order (auth handlers, auth
post processors)
was (Author: alexander.klimetschek):
Attached patch: [^SLING-5274.patch]
Example authentication success:
{noformat}
0 TIMER_START{Request Processing}
1 COMMENT timer_end format is {<elapsed microsec>,<timer name>} <optional
message>
8 LOG Method=GET,
Path=/is/image/content/dam/geometrixx/portraits/scott_reynolds.jpg
12 TIMER_START{Authentication}
24 LOG Calling auth handler: Cloud IMS Authentication Handler
46 LOG Calling auth handler: OAuth Authentication Handler
65 LOG Calling auth handler: Day CQ Login Selector Authentication Handler
68 LOG Calling auth handler: Granite Client Certificate Authentication
Handler
71 LOG Calling auth handler: Token Authentication Handler
77 LOG Calling auth handler: ImageServer Authentication Handler
80 LOG Calling auth handler:
org.apache.sling.auth.core.impl.HttpBasicAuthenticationHandler
101 LOG AuthenticationHandlers returned: type=BASIC, userId=admin
105 LOG Calling auth post processor:
com.adobe.cq.social.commons.cors.CORSAuthInfoPostProcessor
106 LOG Calling auth post processor:
org.apache.sling.jcr.resource.internal.WorkspaceAuthInfoPostProcessor
109 LOG Calling auth post processor:
com.adobe.cq.creativecloud.cloudims.impl.auth.cookie.TokenAuthenticationInfoPostProcessor
144 LOG Trying to get a resource resolver for: type=BASIC, userId=admin
12408 LOG Login success: Resource Resolver, userId=admin
12428 TIMER_END{12415,Authentication} succeeded
12611 TIMER_START{ResourceResolution}
... existing logs
{noformat}
Example authentication failure (note that these were not recorded/visible so
far!):
{noformat}
0 TIMER_START{Request Processing}
1 COMMENT timer_end format is {<elapsed microsec>,<timer name>} <optional
message>
8 LOG Method=GET, Path=/bin/ping
15 TIMER_START{Authentication}
31 LOG Calling auth handler: Cloud IMS Authentication Handler
59 LOG Calling auth handler: OAuth Authentication Handler
78 LOG Calling auth handler: Day CQ Login Selector Authentication Handler
81 LOG Calling auth handler: Granite Client Certificate Authentication
Handler
83 LOG Calling auth handler: Token Authentication Handler
88 LOG Calling auth handler: ImageServer Authentication Handler
91 LOG Calling auth handler:
org.apache.sling.auth.core.impl.HttpBasicAuthenticationHandler
115 LOG AuthenticationHandlers returned: type=BASIC, userId=admin
120 LOG Calling auth post processor:
com.adobe.cq.social.commons.cors.CORSAuthInfoPostProcessor
121 LOG Calling auth post processor:
org.apache.sling.jcr.resource.internal.WorkspaceAuthInfoPostProcessor
125 LOG Calling auth post processor:
com.adobe.cq.creativecloud.cloudims.impl.auth.cookie.TokenAuthenticationInfoPostProcessor
160 LOG Trying to get a resource resolver for: type=BASIC, userId=admin
4572 LOG Login failed: UserId/Password mismatch.
4738 TIMER_END{4720,Authentication} failed
{noformat}
> Include authentication in RequestProgressTracker
> ------------------------------------------------
>
> Key: SLING-5274
> URL: https://issues.apache.org/jira/browse/SLING-5274
> Project: Sling
> Issue Type: Improvement
> Components: Engine
> Reporter: Alexander Klimetschek
> Attachments: SLING-5274.patch
>
>
> The request progress tracker only starts with the sling filters, after the
> sling authentication ran through. Since authentication steps can be complex
> with multiple handlers (just like filters) and can have a major performance
> impact (custom auth handlers, slow resource resolver login) it would be very
> useful to include it with detailed information.
--
This message was sent by Atlassian JIRA
(v6.3.4#6332)
