Adobe-Consulting-Services / acs-aem-commons

http://adobe-consulting-services.github.io/acs-aem-commons/
Apache License 2.0
451 stars 597 forks source link

Environment Indicator setting causes Contexthub calls to fail #2271

Closed pegr69 closed 4 years ago

pegr69 commented 4 years ago

Required Information

Expected Behavior

http://localhost:4502/etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub Should return the contexthub configuration or a 304 no content if already cached.

Please describe briefly the expected behavior, i.e. when I do X, Y should happen.

Actual Behavior

Every OTHER call return an error 500. If browser is in dev mode(F12), and no cache enabled, all calls are fine since the browser always request a full response.

Steps to Reproduce

1, Set Enviroment Indicator setting color to ex: "blue", save. 2, Call contexthub URL: http://localhost:4502/etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub

20.04.2020 14:35:39.919 *ERROR* [qtp190519350-7502] org.apache.felix.http.jetty Exception while processing request to /etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub (java.io.IOException: org.eclipse.jetty.http.BadMessageException: 500: Content for no content response) java.io.IOException: org.eclipse.jetty.http.BadMessageException: 500: Content for no content response at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:225) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:397) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Response.flushBuffer(Response.java:1233) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.ServletResponseWrapper.flushBuffer(ServletResponseWrapper.java:168) [org.apache.felix.http.servlet-api:1.1.2] at javax.servlet.ServletResponseWrapper.flushBuffer(ServletResponseWrapper.java:168) [org.apache.felix.http.servlet-api:1.1.2] at com.adobe.acs.commons.util.BufferedServletOutput.close(BufferedServletOutput.java:173) at com.adobe.acs.commons.util.BufferedHttpServletResponse.close(BufferedHttpServletResponse.java:73) at com.adobe.acs.commons.wcm.impl.AemEnvironmentIndicatorFilter.doFilter(AemEnvironmentIndicatorFilter.java:214) [com.adobe.acs.acs-aem-commons-bundle:4.5.0] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.tracer.internal.LogTracer$TracerFilter.doFilter(LogTracer.java:299) [org.apache.sling.tracer:1.0.6] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at com.adobe.granite.license.impl.LicenseCheckFilter.doFilter(LicenseCheckFilter.java:308) [com.adobe.granite.license:1.2.6.CQ640-B0001] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.sslfilter.internal.SslFilter.doFilter(SslFilter.java:96) [org.apache.felix.http.sslfilter:1.2.4] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.i18n.impl.I18NFilter.doFilter(I18NFilter.java:131) [org.apache.sling.i18n:2.5.14] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.featureflags.impl.FeatureManager.doFilter(FeatureManager.java:116) [org.apache.sling.featureflags:1.2.2] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.engine.impl.log.RequestLoggerFilter.doFilter(RequestLoggerFilter.java:72) [org.apache.sling.engine:2.6.16] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.engine.impl.parameters.RequestParameterSupportConfigurer.doFilter(RequestParameterSupportConfigurer.java:63) [org.apache.sling.engine:2.6.16] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher$1.doFilter(Dispatcher.java:146) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1014) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:326) [org.apache.sling.security:1.1.16] at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:133) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1020) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager.invokePreprocessors(WhiteboardManager.java:1024) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:91) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.DispatcherServlet.service(DispatcherServlet.java:49) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) [org.apache.felix.http.servlet-api:1.1.2] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Server.handle(Server.java:503) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683) [org.apache.felix.http.jetty:4.0.6] at java.lang.Thread.run(Thread.java:745) Caused by: org.eclipse.jetty.http.BadMessageException: 500: Content for no content response at org.eclipse.jetty.http.HttpGenerator.generateHeaders(HttpGenerator.java:739) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.http.HttpGenerator.generateResponse(HttpGenerator.java:448) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:733) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:538) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:831) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:887) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:239) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:215) [org.apache.felix.http.jetty:4.0.6] ... 67 common frames omitted 20.04.2020 14:35:39.919 *WARN* [qtp190519350-7502] org.eclipse.jetty.server.HttpChannel /etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub java.lang.IllegalStateException: Committed at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:894) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:959) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1312) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.ServletResponseWrapper.resetBuffer(ServletResponseWrapper.java:195) [org.apache.felix.http.servlet-api:1.1.2] at org.apache.felix.http.base.internal.dispatch.ServletResponseWrapper.sendError(ServletResponseWrapper.java:67) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.ServletResponseWrapper.sendError(ServletResponseWrapper.java:61) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher$1.doFilter(Dispatcher.java:155) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1014) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:326) [org.apache.sling.security:1.1.16] at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:133) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1020) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager.invokePreprocessors(WhiteboardManager.java:1024) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:91) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.DispatcherServlet.service(DispatcherServlet.java:49) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) [org.apache.felix.http.servlet-api:1.1.2] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Server.handle(Server.java:503) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683) [org.apache.felix.http.jetty:4.0.6] at java.lang.Thread.run(Thread.java:745) 20.04.2020 14:35:39.920 *WARN* [qtp190519350-7502] org.eclipse.jetty.server.HttpChannel ERROR dispatch failed java.lang.IllegalStateException: Committed at org.eclipse.jetty.server.HttpChannel.resetBuffer(HttpChannel.java:894) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.resetBuffer(HttpOutput.java:959) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Response.resetBuffer(Response.java:1312) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.ServletResponseWrapper.resetBuffer(ServletResponseWrapper.java:195) [org.apache.felix.http.servlet-api:1.1.2] at org.apache.felix.http.base.internal.dispatch.ServletResponseWrapper.sendError(ServletResponseWrapper.java:67) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.ServletResponseWrapper.sendError(ServletResponseWrapper.java:61) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher$1.doFilter(Dispatcher.java:155) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1014) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:326) [org.apache.sling.security:1.1.16] at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:133) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1020) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager.invokePreprocessors(WhiteboardManager.java:1024) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:91) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.DispatcherServlet.service(DispatcherServlet.java:49) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) [org.apache.felix.http.servlet-api:1.1.2] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Server.handle(Server.java:503) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:260) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:305) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:103) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.io.ChannelEndPoint$2.run(ChannelEndPoint.java:118) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:333) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:310) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:168) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:126) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:366) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:765) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.thread.QueuedThreadPool$2.run(QueuedThreadPool.java:683) [org.apache.felix.http.jetty:4.0.6] at java.lang.Thread.run(Thread.java:745) Suppressed: java.lang.IllegalStateException: Error already set at org.eclipse.jetty.server.HttpChannelState.onError(HttpChannelState.java:758) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.handleException(HttpChannel.java:590) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannelOverHttp.handleException(HttpChannelOverHttp.java:489) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:526) [org.apache.felix.http.jetty:4.0.6] ... 12 common frames omitted Caused by: java.io.IOException: org.eclipse.jetty.http.BadMessageException: 500: Content for no content response at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:225) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.flush(HttpOutput.java:397) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Response.flushBuffer(Response.java:1233) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.ServletResponseWrapper.flushBuffer(ServletResponseWrapper.java:168) [org.apache.felix.http.servlet-api:1.1.2] at javax.servlet.ServletResponseWrapper.flushBuffer(ServletResponseWrapper.java:168) [org.apache.felix.http.servlet-api:1.1.2] at com.adobe.acs.commons.util.BufferedServletOutput.close(BufferedServletOutput.java:173) at com.adobe.acs.commons.util.BufferedHttpServletResponse.close(BufferedHttpServletResponse.java:73) at com.adobe.acs.commons.wcm.impl.AemEnvironmentIndicatorFilter.doFilter(AemEnvironmentIndicatorFilter.java:214) [com.adobe.acs.acs-aem-commons-bundle:4.5.0] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.tracer.internal.LogTracer$TracerFilter.doFilter(LogTracer.java:299) [org.apache.sling.tracer:1.0.6] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at com.adobe.granite.license.impl.LicenseCheckFilter.doFilter(LicenseCheckFilter.java:308) [com.adobe.granite.license:1.2.6.CQ640-B0001] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.sslfilter.internal.SslFilter.doFilter(SslFilter.java:96) [org.apache.felix.http.sslfilter:1.2.4] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.i18n.impl.I18NFilter.doFilter(I18NFilter.java:131) [org.apache.sling.i18n:2.5.14] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.featureflags.impl.FeatureManager.doFilter(FeatureManager.java:116) [org.apache.sling.featureflags:1.2.2] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.engine.impl.log.RequestLoggerFilter.doFilter(RequestLoggerFilter.java:72) [org.apache.sling.engine:2.6.16] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.engine.impl.parameters.RequestParameterSupportConfigurer.doFilter(RequestParameterSupportConfigurer.java:63) [org.apache.sling.engine:2.6.16] at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:135) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher$1.doFilter(Dispatcher.java:146) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1014) [org.apache.felix.http.jetty:4.0.6] at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:326) [org.apache.sling.security:1.1.16] at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:133) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1020) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager.invokePreprocessors(WhiteboardManager.java:1024) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:91) [org.apache.felix.http.jetty:4.0.6] at org.apache.felix.http.base.internal.dispatch.DispatcherServlet.service(DispatcherServlet.java:49) [org.apache.felix.http.jetty:4.0.6] at javax.servlet.http.HttpServlet.service(HttpServlet.java:725) [org.apache.felix.http.servlet-api:1.1.2] at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:865) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:535) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1595) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:255) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1340) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:203) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:473) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1564) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:201) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1242) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:144) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:220) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:132) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.Server.handle(Server.java:503) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:364) [org.apache.felix.http.jetty:4.0.6] ... 12 common frames omitted Caused by: org.eclipse.jetty.http.BadMessageException: 500: Content for no content response at org.eclipse.jetty.http.HttpGenerator.generateHeaders(HttpGenerator.java:739) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.http.HttpGenerator.generateResponse(HttpGenerator.java:448) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection$SendCallback.process(HttpConnection.java:733) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.IteratingCallback.processing(IteratingCallback.java:241) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.util.IteratingCallback.iterate(IteratingCallback.java:224) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpConnection.send(HttpConnection.java:538) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.sendResponse(HttpChannel.java:831) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpChannel.write(HttpChannel.java:887) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:239) [org.apache.felix.http.jetty:4.0.6] at org.eclipse.jetty.server.HttpOutput.write(HttpOutput.java:215) [org.apache.felix.http.jetty:4.0.6] ... 67 common frames omitted

Links

AEM install with SP 6.4.6(also tested w. 6.4.7, same issue), ACS Commons 4.5.0 and a custom deployment of our own core components.

joerghoh commented 4 years ago

This error is weird. "Content for no content response" means that the there is no content for the body available, but there is nothing to stream (at least I interpret this from the jetty code). So this error seems related to the internal buffering of the filter.

It seems the original response has not yet received the content, but the content-size header already indicates that there must be a response.

[EDIT] I can reproduce the issue on my local 6.4.5 instance. In the first request we get the proper etag:

$ curl -v -o /dev/null -u admin:admin http://localhost:4502/etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub
  % Total    % Received % Xferd  Average Speed   Time    Time     Time  Current
                                 Dload  Upload   Total   Spent    Left  Speed
  0     0    0     0    0     0      0      0 --:--:-- --:--:-- --:--:--     0*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 4502 (#0)
* Server auth using Basic with user 'admin'
> GET /etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub HTTP/1.1
> Host: localhost:4502
> Authorization: Basic YWRtaW46YWRtaW4=
> User-Agent: curl/7.64.1
> Accept: */*
>
< HTTP/1.1 200 OK
< Content-Type: application/javascript; charset=utf-8
< ETag: "23f376135d14e7877c1be54d655eced23ca05bc7"
< Connection: close
< Content-Length: 220084
<
{ [24576 bytes data]
100  214k  100  214k    0     0   211k      0  0:00:01  0:00:01 --:--:--  211k
* Closing connection 0

and then we do the same request again with the proper value for the "If-None-Match"; this request works perfectly if the AemEnvironmentIndicator is not enabled and returns a 302 then:

$ curl -H "If-None-Match: \"9394af895ba104abc327e017f1d2dd0c4a3bbc0b\"" -v -u admin:admin http://localhost:4502/etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub
*   Trying 127.0.0.1...
* TCP_NODELAY set
* Connected to localhost (127.0.0.1) port 4502 (#0)
* Server auth using Basic with user 'admin'
> GET /etc/cloudsettings.kernel.js/libs/settings/cloudsettings/legacy/contexthub HTTP/1.1
> Host: localhost:4502
> Authorization: Basic YWRtaW46YWRtaW4=
> User-Agent: curl/7.64.1
> Accept: */*
> If-None-Match: "9394af895ba104abc327e017f1d2dd0c4a3bbc0b"
>
< HTTP/1.1 500 Server Error
< Connection: close
<
* Closing connection 0

This means that it has something do to with the optimization within this AEM code, which wants to return early when the etag matches.

Regarding the error.log statement: I cannot reproduce this stack trace, not even with AEM 6.4.6. I only get the log entry:

Prevent committing the response, it will be committed deferred, i.e. once this buffered response
joerghoh commented 4 years ago

I wasn't able to create a bugfix using a testcase; it seems that our mocks do not mimick some specialties of Jetty well enough; but using some trial-and-error I was able to come up with a bugfix, which returned a HTTP status 302 on any subsequent request. See #2295.

@pegr69 Can you validate that PR on your side and check if the problem persists?

joerghoh commented 4 years ago

@pegr69 reported that the bugfix created in #2295 didn't help in his scenario.

pegr69 commented 4 years ago

Sorry my bad, tested again, missed a branch during checkout, tested on all our staging envs, works fine!

davidjgonzalez commented 4 years ago

Super! This is in 4.7.0 which is released (commons site pending update)

joerghoh commented 4 years ago

thanks @pegr69 for updating!