[
https://issues.apache.org/jira/browse/SLING-6498?page=com.atlassian.jira.plugin.system.issuetabpanels:all-tabpanel
]
Robert Munteanu closed SLING-6498.
----------------------------------
> DavEx: Login fails
> ------------------
>
> Key: SLING-6498
> URL: https://issues.apache.org/jira/browse/SLING-6498
> Project: Sling
> Issue Type: Bug
> Components: JCR
> Environment: Apache Karaf 4.1.0-SNAPSHOT
> Sling Launchpad 9-SNAPSHOT
> Reporter: Oliver Lietz
> Assignee: Robert Munteanu
> Fix For: JCR Davex 1.3.8
>
>
> {noformat}
> 2017-01-30T09:36:20,104 | DEBUG | qtp970611410-129 | HttpChannel
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | REQUEST for
> //localhost:8181/server/ on
> HttpChannelOverHttp@381fd32f{r=1,c=false,a=IDLE,uri=//localhost:8181/server/}
> OPTIONS //localhost:8181/server/ HTTP/1.1
> User-Agent: Transmit/4.4.10 neon/0.29.3
> Keep-Alive:
> Connection: TE, Keep-Alive
> TE: trailers
> Host: localhost:8181
> 2017-01-30T09:36:20,104 | DEBUG | qtp970611410-129 | HttpChannel
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> HttpChannelOverHttp@381fd32f{r=1,c=false,a=IDLE,uri=//localhost:8181/server/}
> onRequestComplete
> 2017-01-30T09:36:20,104 | DEBUG | qtp970611410-129 | HttpInput
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> HttpInputOverHTTP@cf04085[c=0,q=1,[0]=EOF,s=STREAM] addContent EOF
> 2017-01-30T09:36:20,104 | DEBUG | qtp970611410-129 | HttpConnection
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> HttpConnection@be8ba01[SelectChannelEndPoint@4bbe2802{/127.0.0.1:58514<->8181,Open,in,out,-,-,4/30000,HttpConnection@be8ba01}{io=0/0,kio=0,kro=1}][p=HttpParser{s=END,0
> of
> 0},g=HttpGenerator@312c6d46{s=START},c=HttpChannelOverHttp@381fd32f{r=1,c=false,a=IDLE,uri=//localhost:8181/server/}]
> parsed true HttpParser{s=END,0 of 0}
> 2017-01-30T09:36:20,104 | DEBUG | qtp970611410-129 | HttpConnection
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> releaseRequestBuffer
> HttpConnection@be8ba01[SelectChannelEndPoint@4bbe2802{/127.0.0.1:58514<->8181,Open,in,out,-,-,4/30000,HttpConnection@be8ba01}{io=0/0,kio=0,kro=1}][p=HttpParser{s=END,0
> of
> 0},g=HttpGenerator@312c6d46{s=START},c=HttpChannelOverHttp@381fd32f{r=1,c=false,a=IDLE,uri=//localhost:8181/server/}]
> 2017-01-30T09:36:20,104 | DEBUG | qtp970611410-129 | HttpChannel
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> HttpChannelOverHttp@381fd32f{r=1,c=false,a=IDLE,uri=//localhost:8181/server/}
> handle //localhost:8181/server/
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | HttpChannelState
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> HttpChannelState@165f70b7{s=IDLE a=NOT_ASYNC i=true r=!P!U w=false} handling
> IDLE
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | HttpChannel
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> HttpChannelOverHttp@381fd32f{r=1,c=false,a=DISPATCHED,uri=//localhost:8181/server/}
> action DISPATCH
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | Server
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | REQUEST OPTIONS
> /server/ on
> HttpChannelOverHttp@381fd32f{r=1,c=false,a=DISPATCHED,uri=//localhost:8181/server/}
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | ServerModel
> | 91 - org.ops4j.pax.web.pax-web-spi - 6.0.2 | Matching [/server/]...
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | ServerModel
> | 91 - org.ops4j.pax.web.pax-web-spi - 6.0.2 | Path [/server/]
> matched to
> {pattern=/server/.*,model=ServletModel{id=org.ops4j.pax.web.service.spi.model.ServletModel-52,name=org.ops4j.pax.web.service.spi.model.ServletModel-52,urlPatterns=[/server/*],alias=null,servlet=org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet@736cbf61,initParams={csrf-protection=disabled,
> createAbsoluteURI=true,
> resource-path-prefix=/server},context=ContextModel{id=org.ops4j.pax.web.service.spi.model.ContextModel-47,name=,httpContext=org.ops4j.pax.web.extender.whiteboard.internal.WebApplication$1@2b9e3a45,contextParams={httpContext.shared=true,
> webapp.context=},virtualHosts={},connectors={}}}}
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | ContextHandler
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | scope
> null||/server/ @
> HttpServiceContext{httpContext=org.ops4j.pax.web.extender.whiteboard.internal.WebApplication$1@2b9e3a45}
> 2017-01-30T09:36:20,105 | DEBUG | qtp970611410-129 | ContextHandler
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | context=||/server/
> @
> HttpServiceContext{httpContext=org.ops4j.pax.web.extender.whiteboard.internal.WebApplication$1@2b9e3a45}
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 | session
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> sessionManager=org.ops4j.pax.web.service.jetty.internal.LateInvalidatingHashSessionManager@74b3ce17
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 | session
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | session=null
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 | ServletHandler
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | servlet |/server|/
> ->
> org.ops4j.pax.web.service.spi.model.ServletModel-52@b9f03ed5==org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet,-1,true
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 | HttpServiceContext
> | 88 - org.ops4j.pax.web.pax-web-jetty - 6.0.2 | Handling request for
> [/server/] using http context
> [org.ops4j.pax.web.extender.whiteboard.internal.WebApplication$1@2b9e3a45]
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 |
> HttpBasicAuthenticationHandler | 122 - org.apache.sling.auth.core - 1.3.24
> | forceAuthentication: Not forcing authentication because request parameter
> sling:authRequestLogin is not set
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 | SlingAuthenticator
> | 122 - org.apache.sling.auth.core - 1.3.24 | getAuthenticationInfo:
> no handler could extract credentials; assuming anonymous
> 2017-01-30T09:36:20,106 | DEBUG | qtp970611410-129 | SlingAuthenticator
> | 122 - org.apache.sling.auth.core - 1.3.24 | doHandleSecurity: No
> credentials in the request, anonymous
> 2017-01-30T09:36:20,107 | DEBUG | qtp970611410-129 | OakSlingRepository
> | 143 - org.apache.sling.jcr.base - 3.0.0 | login: Logging in to
> workspace 'default'
> 2017-01-30T09:36:20,107 | DEBUG | qtp970611410-129 | LoginContextProviderImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Found
> pre-authenticated subject: No further login actions required.
> 2017-01-30T09:36:20,107 | DEBUG | qtp970611410-129 | AbstractLoginModule
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Login: retrieving
> Credentials using callback.
> 2017-01-30T09:36:20,108 | DEBUG | qtp970611410-129 | AbstractLoginModule
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Login: No supported
> credentials obtained from callback; trying shared state.
> 2017-01-30T09:36:20,108 | DEBUG | qtp970611410-129 | AbstractLoginModule
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Login: No supported
> credentials found in shared state; looking for credentials in subject.
> 2017-01-30T09:36:20,108 | DEBUG | qtp970611410-129 | AbstractLoginModule
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | No credentials
> found.
> 2017-01-30T09:36:20,108 | DEBUG | qtp970611410-129 | AbstractLoginModule
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Login: retrieving
> Credentials using callback.
> 2017-01-30T09:36:20,109 | DEBUG | qtp970611410-129 | AbstractLoginModule
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Login: Credentials
> 'javax.jcr.GuestCredentials@4d22d354' obtained from callback
> 2017-01-30T09:36:20,109 | DEBUG | qtp970611410-129 | LoginContextProviderImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Found
> pre-authenticated subject: No further login actions required.
> 2017-01-30T09:36:20,109 | DEBUG | qtp970611410-129 | PropertyIndex
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | property cost for
> uuid is 2.0
> 2017-01-30T09:36:20,110 | DEBUG | qtp970611410-129 | QueryEngineImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | No alternatives
> found. Query: select [nt:base].[jcr:primaryType] as [nt:base.jcr:primaryType]
> from [nt:base] as [nt:base] where [nt:base].[jcr:uuid] = $id
> 2017-01-30T09:36:20,110 | DEBUG | qtp970611410-129 | LoginModuleImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Adding Credentials
> to shared state.
> 2017-01-30T09:36:20,110 | DEBUG | qtp970611410-129 | LoginModuleImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | Adding login name
> to shared state.
> 2017-01-30T09:36:20,111 | DEBUG | qtp970611410-129 | PropertyIndex
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | property cost for
> uuid is 2.0
> 2017-01-30T09:36:20,111 | DEBUG | qtp970611410-129 | QueryEngineImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | No alternatives
> found. Query: select [nt:base].[jcr:primaryType] as [nt:base.jcr:primaryType]
> from [nt:base] as [nt:base] where [nt:base].[jcr:uuid] = $id
> 2017-01-30T09:36:20,112 | DEBUG | qtp970611410-129 | QueryEngineImpl
> | 116 - org.apache.jackrabbit.oak-core - 1.5.18 | No alternatives
> found. Query: select [rep:MemberReferences].[jcr:primaryType] as
> [rep:MemberReferences.jcr:primaryType] from [rep:MemberReferences] as
> [rep:MemberReferences] where property([rep:MemberReferences].[rep:members],
> 'weakreference') = $uuid
> 2017-01-30T09:36:20,112 | DEBUG | qtp970611410-129 | SlingAuthenticator
> | 122 - org.apache.sling.auth.core - 1.3.24 | setAttributes:
> ResourceResolver stored as request attribute: user=anonymous
> 2017-01-30T09:36:20,112 | DEBUG | qtp970611410-129 |
> HttpServiceServletHandler | 88 - org.ops4j.pax.web.pax-web-jetty -
> 6.0.2 | handling request
> org.ops4j.pax.web.service.jetty.internal.HttpServiceRequestWrapper@39aba8a7,
> org.ops4j.pax.web.service.jetty.internal.HttpServiceResponseWrapper@34a347f4
> 2017-01-30T09:36:20,113 | DEBUG | qtp970611410-129 | ServletHandler
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 |
> chain=Jetty_WebSocketUpgradeFilter->org.ops4j.pax.web.service.spi.model.ServletModel-52@b9f03ed5==org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet,-1,true
> 2017-01-30T09:36:20,113 | DEBUG | qtp970611410-129 | ServletHandler
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | call filter
> Jetty_WebSocketUpgradeFilter
> 2017-01-30T09:36:20,113 | DEBUG | qtp970611410-129 | ServletHandler
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | call servlet
> org.ops4j.pax.web.service.spi.model.ServletModel-52@b9f03ed5==org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet,-1,true
> 2017-01-30T09:36:20,113 | DEBUG | qtp970611410-129 | IfHeader
> | 113 - org.apache.jackrabbit.jackrabbit-webdav - 2.14.0 | IfHeader:
> No If header in request
> 2017-01-30T09:36:20,114 | DEBUG | qtp970611410-129 | IfHeader
> | 113 - org.apache.jackrabbit.jackrabbit-webdav - 2.14.0 | IfHeader:
> No If header in request
> 2017-01-30T09:36:20,114 | DEBUG | qtp970611410-129 | DavException
> | 113 - org.apache.jackrabbit.jackrabbit-webdav - 2.14.0 |
> DavException: (403) Cannot get session for anonymous
> 2017-01-30T09:36:20,114 | DEBUG | qtp970611410-129 | JcrDavException
> | 146 - org.apache.sling.jcr.davex - 1.3.6 | Handling exception with
> error code 403
> javax.jcr.RepositoryException: Cannot get session for anonymous
> at
> org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet$1.getLongLivedSession(SlingDavExServlet.java:205)
> [146:org.apache.sling.jcr.davex:1.3.6]
> at
> org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet$1.getSession(SlingDavExServlet.java:163)
> [146:org.apache.sling.jcr.davex:1.3.6]
> at
> org.apache.jackrabbit.server.jcr.JCRWebdavServer$SessionCache.getRepositorySession(JCRWebdavServer.java:337)
> [146:org.apache.sling.jcr.davex:1.3.6]
> at
> org.apache.jackrabbit.server.jcr.JCRWebdavServer$SessionCache.get(JCRWebdavServer.java:232)
> [146:org.apache.sling.jcr.davex:1.3.6]
> at
> org.apache.jackrabbit.server.jcr.JCRWebdavServer$SessionCache.access$200(JCRWebdavServer.java:165)
> [146:org.apache.sling.jcr.davex:1.3.6]
> at
> org.apache.jackrabbit.server.jcr.JCRWebdavServer.attachSession(JCRWebdavServer.java:103)
> [146:org.apache.sling.jcr.davex:1.3.6]
> at
> org.apache.jackrabbit.webdav.server.AbstractWebdavServlet.service(AbstractWebdavServlet.java:276)
> [113:org.apache.jackrabbit.jackrabbit-webdav:2.14.0]
> at javax.servlet.http.HttpServlet.service(HttpServlet.java:790)
> [10:javax.servlet-api:3.1.0]
> at
> org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:837)
> [70:org.eclipse.jetty.servlet:9.3.15.v20161220]
> at
> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1772)
> [70:org.eclipse.jetty.servlet:9.3.15.v20161220]
> at
> org.eclipse.jetty.websocket.server.WebSocketUpgradeFilter.doFilter(WebSocketUpgradeFilter.java:193)
> [80:org.eclipse.jetty.websocket.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1759)
> [70:org.eclipse.jetty.servlet:9.3.15.v20161220]
> at
> org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:582)
> [70:org.eclipse.jetty.servlet:9.3.15.v20161220]
> at
> org.ops4j.pax.web.service.jetty.internal.HttpServiceServletHandler.doHandle(HttpServiceServletHandler.java:70)
> [88:org.ops4j.pax.web.pax-web-jetty:6.0.2]
> at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:143)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.security.SecurityHandler.handle(SecurityHandler.java:548)
> [67:org.eclipse.jetty.security:9.3.15.v20161220]
> at
> org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:226)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1180)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.ops4j.pax.web.service.jetty.internal.HttpServiceContext.doHandle(HttpServiceContext.java:284)
> [88:org.ops4j.pax.web.pax-web-jetty:6.0.2]
> at
> org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:512)
> [70:org.eclipse.jetty.servlet:9.3.15.v20161220]
> at
> org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1112)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.ops4j.pax.web.service.jetty.internal.JettyServerHandlerCollection.handle(JettyServerHandlerCollection.java:80)
> [88:org.ops4j.pax.web.pax-web-jetty:6.0.2]
> at
> org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:134)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at org.eclipse.jetty.server.Server.handle(Server.java:531)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:320)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:251)
> [69:org.eclipse.jetty.server:9.3.15.v20161220]
> at
> org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:283)
> [61:org.eclipse.jetty.io:9.3.15.v20161220]
> at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:110)
> [61:org.eclipse.jetty.io:9.3.15.v20161220]
> at
> org.eclipse.jetty.io.SelectChannelEndPoint$2.run(SelectChannelEndPoint.java:93)
> [61:org.eclipse.jetty.io:9.3.15.v20161220]
> at
> org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.executeProduceConsume(ExecuteProduceConsume.java:303)
> [72:org.eclipse.jetty.util:9.3.15.v20161220]
> at
> org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.produceConsume(ExecuteProduceConsume.java:148)
> [72:org.eclipse.jetty.util:9.3.15.v20161220]
> at
> org.eclipse.jetty.util.thread.strategy.ExecuteProduceConsume.run(ExecuteProduceConsume.java:136)
> [72:org.eclipse.jetty.util:9.3.15.v20161220]
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:671)
> [72:org.eclipse.jetty.util:9.3.15.v20161220]
> at
> org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:589)
> [72:org.eclipse.jetty.util:9.3.15.v20161220]
> at java.lang.Thread.run(Thread.java:745) [?:?]
> Caused by: javax.jcr.LoginException: Cannot derive user name for bundle
> org.apache.sling.jcr.davex [146] and sub service null
> at
> org.apache.sling.jcr.base.AbstractSlingRepository2.impersonateFromService(AbstractSlingRepository2.java:344)
> ~[?:?]
> at
> org.apache.sling.jcr.davex.impl.servlets.SlingDavExServlet$1.getLongLivedSession(SlingDavExServlet.java:198)
> ~[146:org.apache.sling.jcr.davex:1.3.6]
> ... 36 more
> 2017-01-30T09:36:20,118 | DEBUG | qtp970611410-129 | HttpChannel
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | sendResponse
> info=null content=HeapByteBuffer@71160752[p=0,l=260,c=512,r=260]={<<<<?xml
> version="1....tion></D:error>>>>\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00...\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00\x00}
> complete=true committing=true callback=Blocker@151c7747{null}
> 2017-01-30T09:36:20,118 | DEBUG | qtp970611410-129 | HttpChannel
> | 72 - org.eclipse.jetty.util - 9.3.15.v20161220 | COMMIT for
> /server/ on
> HttpChannelOverHttp@381fd32f{r=1,c=true,a=DISPATCHED,uri=//localhost:8181/server/}
> 403 null HTTP/1.1
> Date: Mon, 30 Jan 2017 08:36:20 GMT
> Content-Type: text/xml;charset=utf-8
> Content-Length: 260
> {noformat}
> ----
> * {{org.apache.sling.jcr.davex}} is whitelisted
> * request was done with {{admin}} credentials
--
This message was sent by Atlassian JIRA
(v6.4.14#64029)
