[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2016-02-12 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15145701#comment-15145701
 ] 

Alexander Klimetschek edited comment on SLING-5274 at 2/13/16 1:55 AM:
---

Thanks Bertrand for SLING-5489 
([331ff05a|https://github.com/apache/sling/commit/331ff05a157455c8a030b5afe3fa2299ef8539ce]),
 it's a good start.

For the record, here are the other features in my patch that aren't covered and 
that might be useful:
* include requests with authentication failures in the request history console
** done using RequestHistoryConsolePlugin.recordRequest(request) at the end of 
handleSecurity() when it returns false; also required some changes in 
RequestHistoryConsolePlugin to not rely on SlingHttpServletRequest and 
getPathInfo(), plus appropriate logging in handleSecurity()
* more detailed logging inside SlingAuthenticator for the individual 
authentication steps

AFAICS, these changes shouldn't depend on the switch to the OSGi http 
whiteboard implementation, but I don't know for sure.


was (Author: alexander.klimetschek):
Thanks Bertrand for SLING-5489, it's a good start.

For the record, here are the other features in my patch that aren't covered and 
that might be useful:
* include requests with authentication failures in the request history console
** done using RequestHistoryConsolePlugin.recordRequest(request) at the end of 
handleSecurity() when it returns false; also required some changes in 
RequestHistoryConsolePlugin to not rely on SlingHttpServletRequest and 
getPathInfo(), plus appropriate logging in handleSecurity()
* more detailed logging inside SlingAuthenticator for the individual 
authentication steps

AFAICS, these changes shouldn't depend on the switch to the OSGi http 
whiteboard implementation, but I don't know for sure.

> 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-bertrand.patch, 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)


[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2016-02-12 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=15145701#comment-15145701
 ] 

Alexander Klimetschek edited comment on SLING-5274 at 2/13/16 1:55 AM:
---

Thanks Bertrand for SLING-5489 
([331ff05a|https://github.com/apache/sling/commit/331ff05a157455c8a030b5afe3fa2299ef8539ce]),
 it's a good start.

For the record, here are the other features in my patch that might be useful:
* include requests with authentication failures in the request history console
** done using RequestHistoryConsolePlugin.recordRequest(request) at the end of 
handleSecurity() when it returns false; also required some changes in 
RequestHistoryConsolePlugin to not rely on SlingHttpServletRequest and 
getPathInfo(), plus appropriate logging in handleSecurity()
* more detailed logging inside SlingAuthenticator for the individual 
authentication steps

AFAICS, these changes shouldn't depend on the switch to the OSGi http 
whiteboard implementation, but I don't know for sure.


was (Author: alexander.klimetschek):
Thanks Bertrand for SLING-5489 
([331ff05a|https://github.com/apache/sling/commit/331ff05a157455c8a030b5afe3fa2299ef8539ce]),
 it's a good start.

For the record, here are the other features in my patch that aren't covered and 
that might be useful:
* include requests with authentication failures in the request history console
** done using RequestHistoryConsolePlugin.recordRequest(request) at the end of 
handleSecurity() when it returns false; also required some changes in 
RequestHistoryConsolePlugin to not rely on SlingHttpServletRequest and 
getPathInfo(), plus appropriate logging in handleSecurity()
* more detailed logging inside SlingAuthenticator for the individual 
authentication steps

AFAICS, these changes shouldn't depend on the switch to the OSGi http 
whiteboard implementation, but I don't know for sure.

> 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-bertrand.patch, 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)


[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2015-11-06 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=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 {,} 
  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 {,} 
  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 {,} 
  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: 

[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2015-11-06 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14994887#comment-14994887
 ] 

Alexander Klimetschek edited comment on SLING-5274 at 11/7/15 2:32 AM:
---

Attached patch: [^SLING-5274.patch]

Example authentication success:
{noformat}
  0 TIMER_START{Request Processing}
  1 COMMENT timer_end format is {,} 
  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 {,} 
  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 enough
- 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 {,} 
  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: 

[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2015-11-06 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14994887#comment-14994887
 ] 

Alexander Klimetschek edited comment on SLING-5274 at 11/7/15 2:32 AM:
---

Attached patch: [^SLING-5274.patch]

Example authentication success:
{noformat}
  0 TIMER_START{Request Processing}
  1 COMMENT timer_end format is {,} 
  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 {,} 
  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 enough
- and passed around as request attribute (since at that early stage there is no 
SlingHttpServletRequest 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 {,} 
  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: 

[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2015-11-06 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14994887#comment-14994887
 ] 

Alexander Klimetschek edited comment on SLING-5274 at 11/7/15 2:23 AM:
---

Attached patch: [^SLING-5274.patch]

Example authentication success:
{noformat}
  0 TIMER_START{Request Processing}
  1 COMMENT timer_end format is {,} 
  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 {,} 
  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}



was (Author: alexander.klimetschek):
Example authentication success:
{noformat}
  0 TIMER_START{Request Processing}
  1 COMMENT timer_end format is {,} 
  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 {,} 
  8 LOG Method=GET, Path=/bin/ping
 15 TIMER_START{Authentication}
 31 LOG Calling auth handler: Cloud IMS Authentication Handler
 59 LOG Calling auth 

[jira] [Comment Edited] (SLING-5274) Include authentication in RequestProgressTracker

2015-11-06 Thread Alexander Klimetschek (JIRA)

[ 
https://issues.apache.org/jira/browse/SLING-5274?page=com.atlassian.jira.plugin.system.issuetabpanels:comment-tabpanel=14994887#comment-14994887
 ] 

Alexander Klimetschek edited comment on SLING-5274 at 11/7/15 2:20 AM:
---

Example authentication success:
{noformat}
  0 TIMER_START{Request Processing}
  1 COMMENT timer_end format is {,} 
  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 {,} 
  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}



was (Author: alexander.klimetschek):
Example:
{noformat}
  0 TIMER_START{Request Processing}
  1 COMMENT timer_end format is {,} 
  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}

> 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
>
> The request progress tracker only starts with the