Highlighted

Timeout session when edit fragment

Avatar

Avatar

paulojorgemtava

Avatar

paulojorgemtava

paulojorgemtava

21-06-2018

AEM 6.2

When the user starts editing of fragment and not exist a token, a version is created and a token for this new editing session is sent to the client, but not generate the token, because the call return is 504(timeout). http://host:4502/content/dam/fragments/teste-noticia.cfm.edit.json

someone have idea

Replies

Highlighted

Avatar

Avatar

kautuk_sahni

Community Manager

Total Posts

5.5K

Likes

955

Correct Answer

1.1K

Avatar

kautuk_sahni

Community Manager

Total Posts

5.5K

Likes

955

Correct Answer

1.1K
kautuk_sahni
Community Manager

02-07-2018

Can you help us reproduce this?

-kautuk

Highlighted

Avatar

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K
Jörg_Hoh
Employee

02-07-2018

Please check which request exactly is resulting a timeout. If the request for the mentioned URL goes into timeout, please validate this request on the AEM side (using "Recent requests" on the OSGI webconsole) to find out what component exactly takes that long.

Jörg

Highlighted

Avatar

Avatar

paulojorgemtava

Avatar

paulojorgemtava

paulojorgemtava

02-07-2018

Jörg Hoh

Screenshot of Recent request

1520253_pastedImage_0.png

Regards

Paulo Jorge

Highlighted

Avatar

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K
Jörg_Hoh
Employee

02-07-2018

can you post the bottom of the screen as well? Everything listed here happens within the 1st milisecond, which means that the problem is not listed in the screenshot.

kind regards,

Jörg

Highlighted

Avatar

Avatar

paulojorgemtava

Avatar

paulojorgemtava

paulojorgemtava

02-07-2018

Sorry Jörg Hoh

I attached new screenshot.

504.png

Highlighted

Avatar

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K
Jörg_Hoh
Employee

03-07-2018

Hi Paulo,

it should be clear which code is problematic, is it? 🙂 It's the EditSessionServlet.

Can you do a threaddump while such a request is being processed?

regards,

Jörg

Highlighted

Avatar

Avatar

paulojorgemtava

Avatar

paulojorgemtava

paulojorgemtava

20-07-2018

Jörg Hoh

We changed the timeout and it is no more returned 504, but the call still takes 4 minutes in average, I found in the log these warnings.

20.07.2018 09:41:53.733 *WARN* [sling-oak-489-Registered Service.1180] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint b0f38ae0-f4ad-4977-939b-bfa88b046b57 in 10 seconds.

20.07.2018 09:42:03.734 *WARN* [sling-oak-489-Registered Service.1183] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint dce41885-808a-4eb6-9f4e-b3433af0d072 in 10 seconds.

20.07.2018 09:42:13.734 *WARN* [sling-oak-489-Registered Service.1180] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint 1d13b685-64b8-4ed4-b831-476766b94436 in 10 seconds.

20.07.2018 09:42:23.734 *WARN* [sling-oak-489-Registered Service.1183] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint 06b91541-2f72-4310-88fe-2283ce1ea570 in 10 seconds.

20.07.2018 09:42:33.735 *WARN* [sling-oak-489-Registered Service.1180] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint 7842392a-7e3d-49b3-8955-7c16d21d7c31 in 10 seconds.

20.07.2018 09:42:43.735 *WARN* [sling-oak-489-Registered Service.1183] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint b0ff70f2-715a-43dc-9d84-c7a68b40e481 in 10 seconds.

20.07.2018 09:42:53.735 *WARN* [sling-oak-489-Registered Service.1180] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint 4044a8a7-fca2-43d6-af6e-7f90256f7847 in 10 seconds.

20.07.2018 09:43:03.736 *WARN* [sling-oak-489-Registered Service.1183] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint 77d9f73d-790f-4564-901c-d563354d6d5b in 10 seconds.

20.07.2018 09:43:13.736 *WARN* [sling-oak-489-Registered Service.1180] org.apache.jackrabbit.oak.plugins.segment.SegmentNodeStore Failed to create checkpoint 6e98720a-6aa0-4c8a-9cc8-c9a58c2a678c in 10 seconds.

20.07.2018 09:43:15.284 *WARN* [201.49.58.221 [1532090338982] POST /content/dam/teste-content-fragment.cfm.edit.json HTTP/1.1] org.apache.jackrabbit.oak.jcr.session.RefreshStrategy This session has been idle for 4 minutes and might be out of date. Consider using a fresh session or explicitly refresh the session.

java.lang.Exception: The session was created here:

at org.apache.jackrabbit.oak.jcr.session.RefreshStrategy$LogOnce.<init>(RefreshStrategy.java:169)

at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:277)

at com.adobe.granite.repository.impl.CRX3RepositoryImpl.login(CRX3RepositoryImpl.java:94)

at org.apache.jackrabbit.oak.jcr.repository.RepositoryImpl.login(RepositoryImpl.java:219)

at org.apache.sling.jcr.base.AbstractSlingRepository2.login(AbstractSlingRepository2.java:288)

at org.apache.sling.jcr.resource.internal.helper.jcr.JcrProviderStateFactory.createProviderState(JcrProviderStateFactory.java:121)

at org.apache.sling.jcr.resource.internal.helper.jcr.JcrResourceProvider.authenticate(JcrResourceProvider.java:267)

at org.apache.sling.jcr.resource.internal.helper.jcr.JcrResourceProvider.authenticate(JcrResourceProvider.java:78)

at org.apache.sling.resourceresolver.impl.providers.stateful.ProviderManager.authenticate(ProviderManager.java:161)

at org.apache.sling.resourceresolver.impl.providers.stateful.ProviderManager.getOrCreateProvider(ProviderManager.java:87)

at org.apache.sling.resourceresolver.impl.providers.stateful.ProviderManager.authenticateAll(ProviderManager.java:129)

at org.apache.sling.resourceresolver.impl.ResourceResolverImpl.createControl(ResourceResolverImpl.java:154)

at org.apache.sling.resourceresolver.impl.ResourceResolverImpl.<init>(ResourceResolverImpl.java:116)

at org.apache.sling.resourceresolver.impl.ResourceResolverImpl.<init>(ResourceResolverImpl.java:110)

at org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getResourceResolverInternal(CommonResourceResolverFactoryImpl.java:258)

at org.apache.sling.resourceresolver.impl.CommonResourceResolverFactoryImpl.getResourceResolver(CommonResourceResolverFactoryImpl.java:163)

at org.apache.sling.resourceresolver.impl.ResourceResolverFactoryImpl.getResourceResolver(ResourceResolverFactoryImpl.java:101)

at org.apache.sling.auth.core.impl.SlingAuthenticator.getResolver(SlingAuthenticator.java:782)

at org.apache.sling.auth.core.impl.SlingAuthenticator.doHandleSecurity(SlingAuthenticator.java:497)

at org.apache.sling.auth.core.impl.SlingAuthenticator.handleSecurity(SlingAuthenticator.java:451)

at org.apache.sling.engine.impl.SlingHttpContext.handleSecurity(SlingHttpContext.java:121)

at org.apache.felix.http.base.internal.service.ServletContextImpl.handleSecurity(ServletContextImpl.java:421)

at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:57)

at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:124)

at org.apache.felix.http.base.internal.DispatcherServlet.service(DispatcherServlet.java:61)

at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)

at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:812)

at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:587)

at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:221)

at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1127)

at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:515)

at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:185)

at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1061)

at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)

at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:215)

at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:97)

at org.eclipse.jetty.server.Server.handle(Server.java:499)

at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:311)

at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:257)

at org.eclipse.jetty.io.AbstractConnection$2.run(AbstractConnection.java:544)

at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:635)

at org.eclipse.jetty.util.thread.QueuedThreadPool$3.run(QueuedThreadPool.java:555)

at java.lang.Thread.run(Thread.java:745)

immediately after the update session the call returns 200. What could be causing this delay?

Regards

Paulo Jorge

Highlighted

Avatar

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K

Avatar

Jörg_Hoh

Employee

Total Posts

3.0K

Likes

891

Correct Answer

1.0K
Jörg_Hoh
Employee

23-07-2018

Please do threaddumps while that request is running. This message just indicates that this POST is slow (and the session is the one used for the request).

Jörg