Expand my Community achievements bar.

Dive into Adobe Summit 2024! Explore curated list of AEM sessions & labs, register, connect with experts, ask questions, engage, and share insights. Don't miss the excitement.
SOLVED

Login and OOTB consoles broken on AEM 6.5 Author after in-place upgrade from 6.3

Avatar

Level 2

Hi, we're working on an AEM upgrade from 6.3 to 6.5 SP11. We've already managed to upgrade one environment, which was a short-lived development box in the cloud. We got the upgrade to succeed and get our custom code working on top of the upgraded 6.5 AEM too.

The sequence looks as follows:

 

  1. Pre-upgrade steps
  2. Upgrade
  3. Post-upgrade steps
  4. Installation of AEM 6.5 compatible versions of custom software

 

When we tried to repeat the same steps on a long-lived environment that has been used as a shared integration server, the Author instance apparently broke down. Basic AEM functionality is refusing to work. There's a lot of stuff happening so I'll have to split it across several posts.

Symptoms

Here's a list of observations pertaining to core functionality and main errors we've seen.

Login page doesn't open

Opening the login page yields an HTTP 403, with Authentication Failed in the response body.

The contents of the page are present at the expected location in the JCR (inspected via CRXDE) and the ACL
rules look the same as they do on a healthy instance, i.e. there's a policy assigned to the everyone
group that allows jcr:read access.

 

The org.apache.sling.engine.impl.auth.SlingAuthenticator config appears to be correct. Allow Anonymous Access is
unchecked, which is to be expected on an Author instance (and is the same as on another Author instance that works) and the
Authentication Requirements settings show -/libs/granite/core/content/login, which, as I understand,
means accessing the page shouldn't require authentication to visit.

In the error.log, there's a couple of entries coinciding with every attempt to visit the page

 

27.04.2022 09:21:29.794 *ERROR* [REDACTED [1651044089673] GET /libs/granite/core/content/login.html HTTP/1.1] com.day.cq.auth.impl.LoginSelectorHandler requestCredentials: Abort login due to apparent misconfiguration.
27.04.2022 09:21:29.794 *ERROR* [REDACTED [1651044089673] GET /libs/granite/core/content/login.html HTTP/1.1] com.day.cq.auth.impl.LoginSelectorHandler requestCredentials: Possible reasons: login page not existing or not accessible

 

 

This looks very similar to the issue described here https://experienceleaguecommunities.adobe.com/t5/adobe-experience-manager/authentication-failed-afte...
but we're upgrading from 6.3 to 6.5. The solution to that issue was apparently to copy the service pack into /crx-quickstart/install and restart

We could try that with the SP11, though it feels a bit like a cargo cult approach. In that thread, another person appears to
have encountered a similar issue when upgrading from 6.1 to 6.1 CFP 13 and also finds that step unclear.

 

1 Accepted Solution

Avatar

Correct answer by
Level 2

Upon closer inspection, the method being called in the head.jsp (see the stack trace from /editor.html in the thread) comes from another JSP, /libs/cq/gui/components/authoring/editors/core/instrumentationUtil.jsp, which is different on the broken instance than on the working one.

 

The version on the broken instance only has one method named getTrackingPageContent, which takes a single argument. The version on the working instance has an additional version that takes two String parameters. This is the one the head.jsp seems to be calling.

 

Searching CRXDE for /libs/cq/gui/components/authoring/editors/ yields the filters of two CRX packages, both of which appear to come from inside the Service Pack 11 zip.

 

On the broken instance, these packages, along with one other, appear not to be installed

tomaszn90975356_0-1651063874858.png

On the working instance, they look fine. Seems like the Service Pack installation hasn't succeeded.

I can see that two of these packages happen to contain the misaligned JSP.

I've tried deleting them and reinstalling the Service Pack (expecting it to reinstall them). The packages do reappear but they're not installed.

When I tried manually installing cq-ui-wcm-editor-content-1.1.418.zip, it threw an exception:

saving approx 331 nodes... 
Error during processing:

org.apache.jackrabbit.vault.packaging.PackageException: javax.jcr.nodetype.ConstraintViolationException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]
	at org.apache.jackrabbit.vault.packaging.impl.ZipVaultPackage.extract(ZipVaultPackage.java:238)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.extract(JcrPackageImpl.java:401)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.installDependencies(JcrPackageImpl.java:802)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.extract(JcrPackageImpl.java:383)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.extract(JcrPackageImpl.java:360)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.install(JcrPackageImpl.java:354)
	at com.day.crx.packaging.impl.J2EEPackageManager.consoleInstall(J2EEPackageManager.java:363)
	at com.day.crx.packaging.impl.J2EEPackageManager.doPost(J2EEPackageManager.java:205)
	at com.day.crx.packaging.impl.PackageManagerServlet.doPost(PackageManagerServlet.java:172)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
	at org.apache.felix.http.base.internal.handler.ServletHandler.handle(ServletHandler.java:123)
	at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:86)
	at com.adobe.granite.license.impl.LicenseCheckFilter.doFilter(LicenseCheckFilter.java:308)
	at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:142)
	at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81)
	at org.apache.sling.i18n.impl.I18NFilter.doFilter(I18NFilter.java:131)
	at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:142)
	at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81)
	at org.apache.felix.http.base.internal.dispatch.Dispatcher$1.doFilter(Dispatcher.java:146)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1002)
	at com.adobe.granite.auth.ims.impl.IMSClusterExchangeTokenPreprocessor.doFilter(IMSClusterExchangeTokenPreprocessor.java:281)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at com.adobe.granite.auth.oauth.impl.OAuthCallbackFilter.doFilter(OAuthCallbackFilter.java:69)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:326)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at org.apache.felix.http.sslfilter.internal.SslFilter.doFilter(SslFilter.java:97)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager.invokePreprocessors(WhiteboardManager.java:1012)
	at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:91)
	at org.apache.felix.http.base.internal.dispatch.DispatcherServlet.service(DispatcherServlet.java:49)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:191)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
	at java.lang.Thread.run(Thread.java:750)
Caused by: javax.jcr.nodetype.ConstraintViolationException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]
	at org.apache.jackrabbit.oak.api.CommitFailedException.asRepositoryException(CommitFailedException.java:226)
	at org.apache.jackrabbit.oak.api.CommitFailedException.asRepositoryException(CommitFailedException.java:213)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.newRepositoryException(SessionDelegate.java:669)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.save(SessionDelegate.java:495)
	at org.apache.jackrabbit.oak.jcr.session.SessionImpl$8.performVoid(SessionImpl.java:424)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performVoid(SessionDelegate.java:273)
	at org.apache.jackrabbit.oak.jcr.session.SessionImpl.save(SessionImpl.java:421)
	at org.apache.jackrabbit.vault.fs.io.AutoSave.save(AutoSave.java:177)
	at org.apache.jackrabbit.vault.fs.io.Importer.run(Importer.java:437)
	at org.apache.jackrabbit.vault.packaging.impl.ZipVaultPackage.extract(ZipVaultPackage.java:233)
	... 66 more
Caused by: org.apache.jackrabbit.oak.api.CommitFailedException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor$1.onConstraintViolation(TypeEditor.java:109)
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor.constraintViolation(TypeEditor.java:234)
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor.childNodeChanged(TypeEditor.java:312)
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor.childNodeAdded(TypeEditor.java:285)
	at org.apache.jackrabbit.oak.spi.commit.VisibleEditor.childNodeAdded(VisibleEditor.java:89)
	at org.apache.jackrabbit.oak.spi.commit.CompositeEditor.childNodeAdded(CompositeEditor.java:107)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeAdded(EditorDiff.java:115)
	at org.apache.jackrabbit.oak.segment.MapRecord$4.childNodeAdded(MapRecord.java:465)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:527)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:462)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:444)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147)
	at org.apache.jackrabbit.oak.segment.MapRecord$4.childNodeChanged(MapRecord.java:471)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:517)
	at org.apache.jackrabbit.oak.segment.MapRecord.compareBranch(MapRecord.java:595)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:496)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:462)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:517)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.process(EditorDiff.java:51)
	at org.apache.jackrabbit.oak.spi.commit.EditorHook.processCommit(EditorHook.java:54)
	at org.apache.jackrabbit.oak.spi.commit.CompositeHook.processCommit(CompositeHook.java:60)
	at org.apache.jackrabbit.oak.spi.commit.CompositeHook.processCommit(CompositeHook.java:60)
	at org.apache.jackrabbit.oak.segment.scheduler.Commit.apply(Commit.java:99)
	at org.apache.jackrabbit.oak.segment.scheduler.LockBasedScheduler.execute(LockBasedScheduler.java:299)
	at org.apache.jackrabbit.oak.segment.scheduler.LockBasedScheduler.schedule(LockBasedScheduler.java:270)
	at org.apache.jackrabbit.oak.segment.SegmentNodeStore.merge(SegmentNodeStore.java:211)
	at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:251)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.commit(SessionDelegate.java:346)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.save(SessionDelegate.java:493)
	... 72 more


Error: javax.jcr.nodetype.ConstraintViolationException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]

It appears to be complaining about a node type definiton that I can see in CRXDE at /jcr:system/jcr:nodeTypes/cq:WorkflowModel

It looks the same on the working instance and the broken one.

 

However, the parent node, /var/workflow/models on this instance appears to have the jcr:primaryType of nt:folder, rather than the expected sling:Folder

 

This prevents the package (and presumably any other packages containing workflow models) from installing properly. I've checked the backups and it seems the node had already been there prior to the upgrade. This is very strange because in AEM 6.3, workflow models used to sit under /etc/workflow, not at /var/workflow. The other 6.3 instances we're updgrading don't have that node at all.

 

My best guess is that at some point in the past, someone mistakenly tried to install a package containing a workflow model, placed relative to the 6.4/6.5 workflow model folder location. At that point, AEM would have created an intermediate node with type nt:folder

 

Removing the malformed and ill-placed /var/workflow folder from the 6.3 instance prior to the upgrade and repeating the upgrade procedure appears to have resolved all the issues mentioned in this thread.

View solution in original post

4 Replies

Avatar

Level 2

The sites console throws NPE when opened

Upon visiting the Sites console at /sites.html/content, an HTTP 500 is returned. Here's the output from the error
handler, with client-specific packages redacted and vendor-specific ones intact.

 

Internal Server Error

Cannot serve request to /sites.html/content in /libs/granite/ui/components/shell/collectionpage/collectionpage.jsp
Exception:

java.lang.NullPointerException
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.loadLibrary(HtmlLibraryManagerImpl.java:1135)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.loadLibs(HtmlLibraryManagerImpl.java:1076)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.assertLoaded(HtmlLibraryManagerImpl.java:916)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.assertResolved(HtmlLibraryManagerImpl.java:936)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.lockedGetLibs(HtmlLibraryManagerImpl.java:981)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.lockAndGetLibs(HtmlLibraryManagerImpl.java:959)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryWriter.internalWriteIncludes(HtmlLibraryWriter.java:148)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryWriter.writeIncludes(HtmlLibraryWriter.java:77)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.writeIncludes(HtmlLibraryManagerImpl.java:540)
at com.adobe.granite.ui.tags.IncludeClientLibraryTag.doEndTag(IncludeClientLibraryTag.java:96)
at org.apache.jsp.libs.granite.ui.components.shell.collectionpage.collectionpage_jsp._jspx_meth_ui_005fincludeClientLib_005f1(collectionpage_jsp.java:1420)
at org.apache.jsp.libs.granite.ui.components.shell.collectionpage.collectionpage_jsp._jspService(collectionpage_jsp.java:577)
at org.apache.sling.scripting.jsp.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:502)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:449)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory.callJsp(JspScriptEngineFactory.java:339)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory.access$100(JspScriptEngineFactory.java:97)
///
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
at java.lang.Thread.run(Thread.java:750)

Request Progress:

0 TIMER_START{Request Processing}
2 COMMENT timer_end format is {<elapsed microseconds>,<timer name>} <optional message>
6 LOG Method=GET, PathInfo=null
8 TIMER_START{handleSecurity}
1619 TIMER_END{1610,handleSecurity} authenticator org.apache.sling.auth.core.impl.SlingAuthenticator@2312586e returns true
1914 TIMER_START{ResourceResolution}
2060 TIMER_END{145,ResourceResolution} URI=/sites.html/content resolves to Resource=JcrNodeResource, type=cq:Page, superType=null, path=/libs/wcm/core/content/sites
2074 LOG Resource Path Info: SlingRequestPathInfo: path='/libs/wcm/core/content/sites', selectorString='null', extension='html', suffix='/content'
2074 TIMER_START{ServletResolution}
2079 TIMER_START{resolveServlet(/libs/wcm/core/content/sites)}
3625 TIMER_END{1545,resolveServlet(/libs/wcm/core/content/sites)} Using servlet /libs/cq/Page/Page.jsp
3632 TIMER_END{1557,ServletResolution} URI=/sites.html/content handled by Servlet=/libs/cq/Page/Page.jsp
3641 LOG Applying Requestfilters
3647 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.prettifier.HtmlPrettifierFilter
3653 LOG Calling filter: com.cognifide.zg.webapp.foundation.forwarding.ForwardMultipleChoicesFilter
3657 LOG Calling filter: com.cognifide.zg.webapp.layoutengine.core.impl.BvmFilter
3662 LOG Calling filter: com.cognifide.zg.webapp.licenseprotection.core.blockade.BlockadeFilter
4061 LOG Calling filter: com.cognifide.redacted.redacted.com.extension.preview.filter.WcmModeDisabledFilter
4067 LOG Calling filter: com.adobe.granite.resourceresolverhelper.impl.ResourceResolverHelperImpl
4071 LOG Calling filter: com.cognifide.bridge.binding.service.DataBindingSlingFilter
//
5050 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDebugFilter
5093 TIMER_START{/libs/cq/Page/Page.jsp#0}
160721 LOG Including resource JcrNodeResource, type=granite/ui/components/shell/collectionpage, superType=null, path=/libs/wcm/core/content/sites/jcr:content (SlingRequestPathInfo: path='/libs/wcm/core/content/sites/jcr:content', selectorString='null', extension='html', suffix='/content')
160801 TIMER_START{resolveServlet(/libs/wcm/core/content/sites/jcr:content)}
162454 TIMER_END{1650,resolveServlet(/libs/wcm/core/content/sites/jcr:content)} Using servlet /libs/granite/ui/components/shell/collectionpage/collectionpage.jsp
162477 LOG Applying Includefilters
162483 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
162494 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
162501 LOG Calling filter: com.cognifide.anatracking.filter.ComponentFilter
162559 LOG Calling filter: com.crownpeakdqm.aem.ComponentDecoratorFilter
162603 LOG Calling filter: com.cognifide.composites.model.filter.ParsysFilter
//
164603 TIMER_START{/libs/granite/ui/components/shell/collectionpage/collectionpage.jsp#1}
438163 LOG Including resource FilteringResourceWrapper, type=granite/ui/components/coral/foundation/admin/contentchecker, path=/mnt/overlay/wcm/core/content/sites/jcr:content/redirector, resource=[MergedResource [path=/mnt/overlay/wcm/core/content/sites/jcr:content/redirector, resources=[/libs/wcm/core/content/sites/jcr:content/redirector]]] (SlingRequestPathInfo: path='/mnt/overlay/wcm/core/content/sites/jcr:content/redirector', selectorString='null', extension='html', suffix='/content')
438183 TIMER_START{resolveServlet(/mnt/overlay/wcm/core/content/sites/jcr:content/redirector)}
439791 TIMER_END{1604,resolveServlet(/mnt/overlay/wcm/core/content/sites/jcr:content/redirector)} Using servlet /libs/granite/ui/components/coral/foundation/admin/contentchecker/contentchecker.jsp
439804 LOG Applying Includefilters
439812 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
439824 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
//
441646 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
441678 TIMER_START{/libs/granite/ui/components/coral/foundation/admin/contentchecker/contentchecker.jsp#2}
517110 TIMER_END{75430,/libs/granite/ui/components/coral/foundation/admin/contentchecker/contentchecker.jsp#2}
517172 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, 
//
522170 LOG Including resource FilteringResourceWrapper, type=wcm/commons/ui/shell/datasources/breadcrumbs, path=/mnt/overlay/wcm/core/content/sites/jcr:content/breadcrumbs, resource=[MergedResource [path=/mnt/overlay/wcm/core/content/sites/jcr:content/breadcrumbs, resources=[/libs/wcm/core/content/sites/jcr:content/breadcrumbs]]] (SlingRequestPathInfo: path='/mnt/overlay/wcm/core/content/sites/jcr:content/breadcrumbs', selectorString='null', extension='html', suffix='/content')
522188 TIMER_START{resolveServlet(/mnt/overlay/wcm/core/content/sites/jcr:content/breadcrumbs)}
523734 TIMER_END{1544,resolveServlet(/mnt/overlay/wcm/core/content/sites/jcr:content/breadcrumbs)} Using servlet /libs/wcm/commons/ui/shell/datasources/breadcrumbs/breadcrumbs.jsp
523748 LOG Applying Includefilters
523755 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
523767 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
//
524956 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
524983 TIMER_START{/libs/wcm/commons/ui/shell/datasources/breadcrumbs/breadcrumbs.jsp#3}
609000 TIMER_END{84015,/libs/wcm/commons/ui/shell/datasources/breadcrumbs/breadcrumbs.jsp#3}
609042 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=84, total=84, outer=0
//
609104 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=85, total=85, outer=0
618146 LOG Including resource MergedResource [path=/mnt/overlay/granite/ui/content/globalhead/experiencelog, resources=[/libs/granite/ui/content/globalhead/experiencelog]] (SlingRequestPathInfo: path='/mnt/overlay/granite/ui/content/globalhead/experiencelog', selectorString='null', extension='html', suffix='/content')
618161 TIMER_START{resolveServlet(/mnt/overlay/granite/ui/content/globalhead/experiencelog)}
619804 TIMER_END{1641,resolveServlet(/mnt/overlay/granite/ui/content/globalhead/experiencelog)} Using servlet /libs/cq/experiencelog/components/head/head.jsp
619818 LOG Applying Includefilters
619824 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
619836 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
//
620814 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
620840 TIMER_START{/libs/cq/experiencelog/components/head/head.jsp#4}
692827 TIMER_END{71985,/libs/cq/experiencelog/components/head/head.jsp#4}
692863 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=72, total=72, outer=0
692866 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDebugFilter, inner=72, total=72, outer=0
//
692924 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=73, total=73, outer=0
872361 LOG SCRIPT ERROR:
872370 TIMER_END{707764,/libs/granite/ui/components/shell/collectionpage/collectionpage.jsp#1}
872651 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=708, total=708, outer=0
//
873724 LOG SCRIPT ERROR: An exception occurred processing JSP page /libs/cq/Page/proxy.jsp at line 48
873731 TIMER_END{868636,/libs/cq/Page/Page.jsp#0}
873977 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDebugFilter, inner=869, total=869, outer=0
//
875121 LOG Applying Error filters
875127 LOG Calling filter: org.apache.sling.i18n.impl.I18NFilter
875131 LOG Calling filter: org.apache.sling.rewriter.impl.RewriterFilter
875134 LOG Calling filter: com.cognifide.slice.core.internal.filter.ContextRequestFilter
875230 TIMER_START{handleError:throwable=java.lang.NullPointerException}
877242 TIMER_END{2010,handleError:throwable=java.lang.NullPointerException} Using handler /apps/sling/servlet/errorhandler/Throwable.jsp
882619 LOG Found processor for post processing ProcessorConfiguration: {contentTypes=[text/html], order=0, active=true, valid=true, processErrorResponse=true, pipeline=(generator=Config(type=htmlparser, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/generator-htmlparser: { jcr:primaryType = nt:unstructured, includeTags = [A, AREA, FORM, BASE, LINK, SCRIPT, BODY, META, DIV]}}], values={jcr:primaryType=nt:unstructured, includeTags=[Ljava.lang.String;@197cb830}]), transformers=(Config(type=linkchecker, config={}), Config(type=mobile, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/transformer-mobile: { jcr:primaryType = nt:unstructured, component-optional = true}}], values={jcr:primaryType=nt:unstructured, component-optional=true}]), Config(type=mobiledebug, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/transformer-mobiledebug: { jcr:primaryType = nt:unstructured, component-optional = true}}], values={jcr:primaryType=nt:unstructured, component-optional=true}]), Config(type=contentsync, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/transformer-contentsync: { jcr:primaryType = nt:unstructured, component-optional = true}}], values={jcr:primaryType=nt:unstructured, component-optional=true}]), serializer=Config(type=htmlwriter, config={}))}
888042 TIMER_END{888040,Request Processing} Dumping SlingRequestProgressTracker Entries

ApacheSling/2.7 (jetty/9.4.42.v20210604, Java HotSpot(TM) 64-Bit Server VM 1.8.0_321, Linux 3.10.0-1160.59.1.el7.x86_64 amd64)

 

The NPE seems to be thrown while clientlibs are being included, but the lines in question are closed-source:

 

at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.loadLibrary(.java:1135)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.loadLibs(HtmlLibraryManagerImpl.java:1076)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.assertLoaded(HtmlLibraryManagerImpl.java:916)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.assertResolved(HtmlLibraryManagerImpl.java:936)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.lockedGetLibs(HtmlLibraryManagerImpl.java:981)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.lockAndGetLibs(HtmlLibraryManagerImpl.java:959)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryWriter.internalWriteIncludes(HtmlLibraryWriter.java:148)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryWriter.writeIncludes(HtmlLibraryWriter.java:77)
at com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl.writeIncludes(HtmlLibraryManagerImpl.java:540)
at com.adobe.granite.ui.tags.IncludeClientLibraryTag.doEndTag(IncludeClientLibraryTag.java:96)
at org.apache.jsp.libs.granite.ui.components.shell.collectionpage.collectionpage_jsp._jspx_meth_ui_005fincludeClientLib_005f1(collectionpage_jsp.java:1420)
at org.apache.jsp.libs.granite.ui.components.shell.collectionpage.collectiHtmlLibraryManagerImplonpage_jsp._jspService(collectionpage_jsp.java:577)
at org.apache.sling.scripting.jsp.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)

 

The request progress log also points at a NullPointerException in /libs/cq/Page/proxy.jsp, line 48.

 

if (crd != null) {
  crd.include(request, response); // line 48
  return;
}

 

There's an explicit null check before the line so it's probably something inside the include method, but the stack trace doesn't provide more detail than this.

A very similar error is thrown by the /miscadmin console. The /useradmin throws a similar NPE but no stack trace is present in either the rendered page, or the error.log.

Page editor is broken

The /editor.html/path/to/an/existing/page throws a different exception where it apparently can't compile classes for JSP

 

Unable to compile class for JSP: An error occurred at line: 37 in the jsp file: /apps/cq/gui/components/authoring/editors/core/head.jsp The method getTrackingPageContent(String) in the type head_jsp is not applicable for the arguments (String, String) 34: try { 35: String consoleId = StringUtils.trimToNull(cfg.get("consoleId", String.class)); 36: String trackingFeature = StringUtils.trimToNull(cfg.get("trackingFeature", "Editor")); 37: String trackingPageContent = getTrackingPageContent(consoleId, trackingFeature); 38: if(StringUtils.isNotBlank(trackingPageContent)) { 39: %><meta name="foundation.tracking.page" content="<%= xssAPI.encodeForHTMLAttr(trackingPageContent) %>"><% 40: }

Cannot serve request to /editor.html/content/redacted-demo/redacted-com1/en_gb/home/home.html in /libs/cq/gui/components/authoring/page/page.jsp
Exception:

org.apache.sling.scripting.jsp.jasper.JasperException: Unable to compile class for JSP:

An error occurred at line: 37 in the jsp file: /apps/cq/gui/components/authoring/editors/core/head.jsp
The method getTrackingPageContent(String) in the type head_jsp is not applicable for the arguments (String, String)
34: try {
35: String consoleId = StringUtils.trimToNull(cfg.get("consoleId", String.class));
36: String trackingFeature = StringUtils.trimToNull(cfg.get("trackingFeature", "Editor"));
37: String trackingPageContent = getTrackingPageContent(consoleId, trackingFeature);
38: if(StringUtils.isNotBlank(trackingPageContent)) {
39: %><meta name="foundation.tracking.page" content="<%= xssAPI.encodeForHTMLAttr(trackingPageContent) %>"><%
40: }

at org.apache.sling.scripting.jsp.jasper.compiler.DefaultErrorHandler.javacError(DefaultErrorHandler.java:93)
at org.apache.sling.scripting.jsp.jasper.compiler.ErrorDispatcher.javacError(ErrorDispatcher.java:330)
at org.apache.sling.scripting.jsp.jasper.compiler.JDTCompiler.generateClass(JDTCompiler.java:136)
at org.apache.sling.scripting.jsp.jasper.compiler.Compiler.compile(Compiler.java:304)
at org.apache.sling.scripting.jsp.jasper.compiler.Compiler.compile(Compiler.java:282)
at org.apache.sling.scripting.jsp.jasper.compiler.Compiler.compile(Compiler.java:269)
at org.apache.sling.scripting.jsp.jasper.JspCompilationContext.compile(JspCompilationContext.java:501)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.prepareServlet(JspServletWrapper.java:427)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:486)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:449)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory.callJsp(JspScriptEngineFactory.java:339)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory.access$100(JspScriptEngineFactory.java:97)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory$JspScriptEngine.eval(JspScriptEngineFactory.java:600)
at org.apache.sling.scripting.core.impl.DefaultSlingScript.call(DefaultSlingScript.java:388)
at org.apache.sling.scripting.core.impl.DefaultSlingScript.eval(DefaultSlingScript.java:184)
at org.apache.sling.scripting.core.impl.DefaultSlingScript.service(DefaultSlingScript.java:491)
at org.apache.sling.scripting.jsp.taglib.CallTag.doEndTag(CallTag.java:124)
at org.apache.jsp.libs.cq.gui.components.authoring.page.page_jsp._jspx_meth_sling_005fcall_005f0(page_jsp.java:226)
at org.apache.jsp.libs.cq.gui.components.authoring.page.page_jsp._jspService(page_jsp.java:168)
at org.apache.sling.scripting.jsp.jasper.runtime.HttpJspBase.service(HttpJspBase.java:70)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:502)
at org.apache.sling.scripting.jsp.jasper.servlet.JspServletWrapper.service(JspServletWrapper.java:449)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory.callJsp(JspScriptEngineFactory.java:339)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory.access$100(JspScriptEngineFactory.java:97)
at org.apache.sling.scripting.jsp.JspScriptEngineFactory$JspScriptEngine.eval(JspScriptEngineFactory.java:600)
at 
///
org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
at java.lang.Thread.run(Thread.java:750)

Request Progress:

0 TIMER_START{Request Processing}
2 COMMENT timer_end format is {<elapsed microseconds>,<timer name>} <optional message>
6 LOG Method=GET, PathInfo=null
8 TIMER_START{handleSecurity}
1673 TIMER_END{1663,handleSecurity} authenticator org.apache.sling.auth.core.impl.SlingAuthenticator@2312586e returns true
1961 TIMER_START{ResourceResolution}
2107 TIMER_END{145,ResourceResolution} URI=/editor.html/content/redacted-demo/redacted-com1/en_gb/home/home.html resolves to Resource=JcrNodeResource, type=cq/gui/components/authoring/editors/switch, superType=null, path=/libs/cq/gui/content/editor
2121 LOG Resource Path Info: SlingRequestPathInfo: path='/libs/cq/gui/content/editor', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html'
2121 TIMER_START{ServletResolution}
2125 TIMER_START{resolveServlet(/libs/cq/gui/content/editor)}
3293 TIMER_END{1166,resolveServlet(/libs/cq/gui/content/editor)} Using servlet /libs/cq/gui/components/authoring/editors/switch/switch.jsp
3298 TIMER_END{1176,ServletResolution} URI=/editor.html/content/redacted-demo/redacted-com1/en_gb/home/home.html handled by Servlet=/libs/cq/gui/components/authoring/editors/switch/switch.jsp
3307 LOG Applying Requestfilters
3317 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.prettifier.HtmlPrettifierFilter
// filters skipped for brevity
4574 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDebugFilter
4599 TIMER_START{/libs/cq/gui/components/authoring/editors/switch/switch.jsp#0}
36550 LOG Including resource JcrNodeResource, type=dam/cfm/admin/components/renderconditions/fragment, superType=null, path=/libs/cq/gui/content/editor/fragment/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/fragment/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
36560 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/fragment/granite:rendercondition)}
37518 TIMER_END{956,resolveServlet(/libs/cq/gui/content/editor/fragment/granite:rendercondition)} Using servlet /libs/dam/cfm/admin/components/renderconditions/fragment/fragment.jsp
37526 LOG Applying Includefilters
37535 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
// filters skipped for brevity
37981 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
38015 TIMER_START{/libs/dam/cfm/admin/components/renderconditions/fragment/fragment.jsp#1}
77026 TIMER_END{39010,/libs/dam/cfm/admin/components/renderconditions/fragment/fragment.jsp#1}
77069 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=39, total=39, outer=0
// filters skipped for brevity
77117 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=39, total=39, outer=0
77240 LOG Including resource JcrNodeResource, type=fd/af/authoring/editors/rendercondition/template, superType=null, path=/libs/cq/gui/content/editor/formtemplate/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/formtemplate/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
77251 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/formtemplate/granite:rendercondition)}
78210 TIMER_END{958,resolveServlet(/libs/cq/gui/content/editor/formtemplate/granite:rendercondition)} Using servlet /libs/fd/af/authoring/editors/rendercondition/template/template.jsp
78219 LOG Applying Includefilters
78227 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
// filters skipped for brevity
78593 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
78612 TIMER_START{/libs/fd/af/authoring/editors/rendercondition/template/template.jsp#2}
135984 TIMER_END{57369,/libs/fd/af/authoring/editors/rendercondition/template/template.jsp#2}
136027 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=57, total=57, outer=0
// filters skipped for brevity
136070 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=57, total=57, outer=0
136195 LOG Including resource JcrNodeResource, type=cq/gui/components/authoring/editors/rendercondition/template, superType=null, path=/libs/cq/gui/content/editor/template/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/template/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
136212 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/template/granite:rendercondition)}
137191 TIMER_END{977,resolveServlet(/libs/cq/gui/content/editor/template/granite:rendercondition)} Using servlet /libs/cq/gui/components/authoring/editors/rendercondition/template/template.jsp
137201 LOG Applying Includefilters
137210 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
137218 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
// filters skipped for brevity
137612 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
137631 TIMER_START{/libs/cq/gui/components/authoring/editors/rendercondition/template/template.jsp#3}
171375 TIMER_END{33742,/libs/cq/gui/components/authoring/editors/rendercondition/template/template.jsp#3}
171406 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=34, total=34, outer=0
171408 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDebugFilter, inner=34, total=34, outer=0
171410 LOG Filter timing: filter=com.cognifide.zg.webapp.layoutengine.core.template.provider.TouchUiTemplateListFilter, inner=34, total=34, outer=0
// filters skipped for brevity
171444 LOG Filter timing: filter=com.crownpeakdqm.aem.ComponentDecoratorFilter, inner=34, total=34, outer=0
171446 LOG Filter timing: filter=com.cognifide.anatracking.filter.ComponentFilter, inner=34, total=35, outer=1
171448 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=35, total=35, outer=0
171571 LOG Including resource JcrNodeResource, type=fd/af/authoring/editors/rendercondition/theme, superType=null, path=/libs/cq/gui/content/editor/theme/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/theme/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
171581 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/theme/granite:rendercondition)}
172549 TIMER_END{967,resolveServlet(/libs/cq/gui/content/editor/theme/granite:rendercondition)} Using servlet /libs/fd/af/authoring/editors/rendercondition/theme/theme.jsp
172558 LOG Applying Includefilters
172568 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
172576 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
// filters skipped for brevity
173004 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDebugFilter
173009 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
173030 TIMER_START{/libs/fd/af/authoring/editors/rendercondition/theme/theme.jsp#4}
203699 TIMER_END{30668,/libs/fd/af/authoring/editors/rendercondition/theme/theme.jsp#4}
203726 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=31, total=31, outer=0
// filters skipped for brevity
203770 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=31, total=31, outer=0
203889 LOG Including resource JcrNodeResource, type=fd/af/authoring/editors/rendercondition/form, superType=null, path=/libs/cq/gui/content/editor/form/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/form/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
203899 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/form/granite:rendercondition)}
205021 TIMER_END{1121,resolveServlet(/libs/cq/gui/content/editor/form/granite:rendercondition)} Using servlet /libs/fd/af/authoring/editors/rendercondition/form/form.jsp
205031 LOG Applying Includefilters
205040 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
205048 LOG Calling filter: com.cognifide.composites.markup.CompositesDecoratorFilter
// filters skipped for brevity
205439 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
205459 TIMER_START{/libs/fd/af/authoring/editors/rendercondition/form/form.jsp#5}
263507 TIMER_END{58046,/libs/fd/af/authoring/editors/rendercondition/form/form.jsp#5}
263539 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=58, total=58, outer=0
263542 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDebugFilter, inner=58, total=58, outer=0
// filters skipped for brevity
263583 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=59, total=59, outer=0
263706 LOG Including resource JcrNodeResource, type=cq/experience-fragments/editor/components/renderconditions/experiencefragment, superType=null, path=/libs/cq/gui/content/editor/experiencefragment/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/experiencefragment/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
263716 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/experiencefragment/granite:rendercondition)}
264533 TIMER_END{815,resolveServlet(/libs/cq/gui/content/editor/experiencefragment/granite:rendercondition)} Using servlet com.adobe.cq.xf.impl.servlet.rendercondition.EditorRenderCondition
264544 LOG Applying Includefilters
// filters skipped for brevity
265022 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
265045 TIMER_START{com.adobe.cq.xf.impl.servlet.rendercondition.EditorRenderCondition#6}
265494 TIMER_END{448,com.adobe.cq.xf.impl.servlet.rendercondition.EditorRenderCondition#6}
// filters skipped for brevity
265634 LOG Including resource JcrNodeResource, type=cq/gui/components/authoring/editors/rendercondition/page, superType=null, path=/libs/cq/gui/content/editor/page/granite:rendercondition (SlingRequestPathInfo: path='/libs/cq/gui/content/editor/page/granite:rendercondition', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
265642 TIMER_START{resolveServlet(/libs/cq/gui/content/editor/page/granite:rendercondition)}
266593 TIMER_END{949,resolveServlet(/libs/cq/gui/content/editor/page/granite:rendercondition)} Using servlet /libs/cq/gui/components/authoring/editors/rendercondition/page/page.jsp
266600 LOG Applying Includefilters
266606 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
// filters skipped for brevity
266905 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
266920 TIMER_START{/libs/cq/gui/components/authoring/editors/rendercondition/page/page.jsp#7}
298890 TIMER_END{31968,/libs/cq/gui/components/authoring/editors/rendercondition/page/page.jsp#7}
// filters skipped for brevity
299737 TIMER_START{resolveIncludedResource(/mnt/overlay/wcm/core/content/editor/jcr:content)}
299892 TIMER_END{154,resolveIncludedResource(/mnt/overlay/wcm/core/content/editor/jcr:content)} path=/mnt/overlay/wcm/core/content/editor/jcr:content resolves to Resource=MergedResource [path=/mnt/overlay/wcm/core/content/editor/jcr:content, resources=[/libs/wcm/core/content/editor/jcr:content, /apps/wcm/core/content/editor/jcr:content]]
299917 LOG Including resource TypeOverwritingResourceWrapper, type=cq/gui/components/authoring/editors/core, path=/mnt/overlay/wcm/core/content/editor/jcr:content, resource=[MergedResource [path=/mnt/overlay/wcm/core/content/editor/jcr:content, resources=[/libs/wcm/core/content/editor/jcr:content, /apps/wcm/core/content/editor/jcr:content]]] (SlingRequestPathInfo: path='/mnt/overlay/wcm/core/content/editor/jcr:content', selectorString='null', extension='html', suffix='/content/redacted-demo/redacted-com1/en_gb/home/home.html')
299928 TIMER_START{resolveServlet(/mnt/overlay/wcm/core/content/editor/jcr:content)}
301384 TIMER_END{1454,resolveServlet(/mnt/overlay/wcm/core/content/editor/jcr:content)} Using servlet /libs/cq/gui/components/authoring/page/page.jsp
301393 LOG Applying Includefilters
301402 LOG Calling filter: com.cognifide.zg.webapp.commons.impl.compat.components.enhancer.DialogFilter
// filters skipped for brevity
302467 LOG Calling filter: com.day.cq.wcm.core.impl.WCMDeveloperModeFilter
302489 TIMER_START{/libs/cq/gui/components/authoring/page/page.jsp#8}
335287 LOG Including script head.jsp for path=/mnt/overlay/wcm/core/content/editor/jcr:content, type=cq/gui/components/authoring/editors/core: /apps/cq/gui/components/authoring/editors/core/head.jsp
335302 TIMER_START{/apps/cq/gui/components/authoring/editors/core/head.jsp}
376092 LOG SCRIPT ERROR: org.apache.sling.scripting.jsp.jasper.JasperException: Unable to compile class for JSP: //An error occurred at line: 37 in the jsp file: /apps/cq/gui/components/authoring/editors/core/head.jsp/The method getTrackingPageContent(String) in the type head_jsp is not applicable for the arguments (String, String)/34: try {/35: String consoleId = StringUtils.trimToNull(cfg.get("consoleId", String.class));/36: String trackingFeature = StringUtils.trimToNull(cfg.get("trackingFeature", "Editor"));/37: String trackingPageContent = getTrackingPageContent(consoleId, trackingFeature);/38: if(StringUtils.isNotBlank(trackingPageContent)) {/39: %><meta name="foundation.tracking.page" content="<%= xssAPI.encodeForHTMLAttr(trackingPageContent) %>"><%/40: }/
376462 LOG SCRIPT ERROR: org.apache.sling.scripting.jsp.jasper.JasperException: Unable to compile class for JSP: //An error occurred at line: 37 in the jsp file: /apps/cq/gui/components/authoring/editors/core/head.jsp/The method getTrackingPageContent(String) in the type head_jsp is not applicable for the arguments (String, String)/34: try {/35: String consoleId = StringUtils.trimToNull(cfg.get("consoleId", String.class));/36: String trackingFeature = StringUtils.trimToNull(cfg.get("trackingFeature", "Editor"));/37: String trackingPageContent = getTrackingPageContent(consoleId, trackingFeature);/38: if(StringUtils.isNotBlank(trackingPageContent)) {/39: %><meta name="foundation.tracking.page" content="<%= xssAPI.encodeForHTMLAttr(trackingPageContent) %>"><%/40: }/
376470 TIMER_END{73979,/libs/cq/gui/components/authoring/page/page.jsp#8}
376631 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDeveloperModeFilter, inner=74, total=74, outer=0
// filters skipped for brevity
376673 LOG Filter timing: filter=com.cognifide.composites.markup.CompositesDecoratorFilter, inner=75, total=75, outer=0
376807 LOG SCRIPT ERROR: org.apache.sling.scripting.jsp.jasper.JasperException: Unable to compile class for JSP: //An error occurred at line: 37 in the jsp file: /apps/cq/gui/components/authoring/editors/core/head.jsp/The method getTrackingPageContent(String) in the type head_jsp is not applicable for the arguments (String, String)/34: try {/35: String consoleId = StringUtils.trimToNull(cfg.get("consoleId", String.class));/36: String trackingFeature = StringUtils.trimToNull(cfg.get("trackingFeature", "Editor"));/37: String trackingPageContent = getTrackingPageContent(consoleId, trackingFeature);/38: if(StringUtils.isNotBlank(trackingPageContent)) {/39: %><meta name="foundation.tracking.page" content="<%= xssAPI.encodeForHTMLAttr(trackingPageContent) %>"><%/40: }/
376810 TIMER_END{372210,/libs/cq/gui/components/authoring/editors/switch/switch.jsp#0}
376940 LOG Filter timing: filter=com.day.cq.wcm.core.impl.WCMDebugFilter, inner=372, total=372, outer=0
// filters skipped for brevity
377307 LOG Filter timing: filter=com.cognifide.zg.webapp.foundation.forwarding.ForwardMultipleChoicesFilter, inner=373, total=374, outer=1
377309 LOG Filter timing: filter=com.cognifide.zg.webapp.commons.impl.prettifier.HtmlPrettifierFilter, inner=374, total=374, outer=0
377812 LOG Applying Error filters
377821 LOG Calling filter: org.apache.sling.i18n.impl.I18NFilter
377825 LOG Calling filter: org.apache.sling.rewriter.impl.RewriterFilter
377828 LOG Calling filter: com.cognifide.slice.core.internal.filter.ContextRequestFilter
377909 TIMER_START{handleError:throwable=org.apache.sling.scripting.jsp.jasper.JasperException}
378713 TIMER_END{803,handleError:throwable=org.apache.sling.scripting.jsp.jasper.JasperException} Using handler /apps/sling/servlet/errorhandler/Throwable.jsp
380749 LOG Found processor for post processing ProcessorConfiguration: {contentTypes=[text/html], order=0, active=true, valid=true, processErrorResponse=true, pipeline=(generator=Config(type=htmlparser, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/generator-htmlparser: { jcr:primaryType = nt:unstructured, includeTags = [A, AREA, FORM, BASE, LINK, SCRIPT, BODY, META, DIV]}}], values={jcr:primaryType=nt:unstructured, includeTags=[Ljava.lang.String;@197cb830}]), transformers=(Config(type=linkchecker, config={}), Config(type=mobile, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/transformer-mobile: { jcr:primaryType = nt:unstructured, component-optional = true}}], values={jcr:primaryType=nt:unstructured, component-optional=true}]), Config(type=mobiledebug, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/transformer-mobiledebug: { jcr:primaryType = nt:unstructured, component-optional = true}}], values={jcr:primaryType=nt:unstructured, component-optional=true}]), Config(type=contentsync, config=JcrPropertyMap [node=Node[NodeDelegate{tree=/apps/analytics-tracking-imprint/config/rewriter/markupRewriter/transformer-contentsync: { jcr:primaryType = nt:unstructured, component-optional = true}}], values={jcr:primaryType=nt:unstructured, component-optional=true}]), serializer=Config(type=htmlwriter, config={}))}
382679 TIMER_END{382677,Request Processing} Dumping SlingRequestProgressTracker Entries

ApacheSling/2.7 (jetty/9.4.42.v20210604, Java HotSpot(TM) 64-Bit Server VM 1.8.0_321, Linux 3.10.0-1160.59.1.el7.x86_64 amd64)

 


This looks pretty strange

 

An error occurred at line: 37 in the jsp file: /apps/cq/gui/components/authoring/editors/core/head.jsp
The method getTrackingPageContent(String) in the type head_jsp is not applicable for the arguments (String, String)
34: try {
35: String consoleId = StringUtils.trimToNull(cfg.get("consoleId", String.class));
36: String trackingFeature = StringUtils.trimToNull(cfg.get("trackingFeature", "Editor"));
37: String trackingPageContent = getTrackingPageContent(consoleId, trackingFeature);
38: if(StringUtils.isNotBlank(trackingPageContent)) {
39: %><meta name="foundation.tracking.page" content="<%= xssAPI.encodeForHTMLAttr(trackingPageContent) %>"><%
40: }

 

I'm guessing head_jsp refers to /org/apache/jsp/libs/cq/experiencelog/components/head/head_jsp.java, or at least that's the
one candidate I can find when looking at /system/console/fsclassloader

When I view the compiled class in /system/console/fsclassloader?view=/org/apache/jsp/libs/cq/experiencelog/components/head/head_jsp.java,
I can't find a method named getTrackingPageContent.

Using the Clear Class Loader button in the File System Class Loader console doesn't resolve the issue so it doesn't look like a matter of caching.

General picture

Bundle status

The instance worked fine prior to the 6.5 upgrade, it's something about the upgrade that breaks it. In the state described above,
with the login and multiple consoles broken, all bundles present are active.

We've cross-checked the bundle list, as obtained from system/console/bundles.json, on the broken Author instance with a bundle list from another Author instance that has been
upgraded scucessfully and they're almost identical. The only differences are:

The presence of Bundle(we.retail.client.app.core, 1.0.14, installed) on the working instance.

The presence of Bundle(com.crownpeakdqm.validation, 2.1.86, active) on the broken instance. I believe this version isn't compatible with
AEM 6.5 but I wouldn't expect it to be causing the issues described. We haven't tried uninstalling it yet.

Logs

Upgrade

The upgrade log doesn't contain errors or warnings, the procedure appears to have been successful

CrownpeakDQMPlugin.log

Has to do with Crownpeak's DQM solution being installed on the broken instance. The log is completely empty.

 

Error

The error.log contains many instances of the issues described above, but nothing more detailed as far as stack traces are concerned
The error.log, on top of the exceptions mentioned above, contains a lot of entries pertaining to clientlib assembly as we try opening the various consoles.

 

// many more lines like these
27.04.2022 09:46:49.397 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/social/hbs/moderation, sourced from 3 files.
27.04.2022 09:46:49.397 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/social/hbs/moderationshell, sourced from 3 files.
27.04.2022 09:46:49.398 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/social/hbs/qna, sourced from 3 files.
27.04.2022 09:46:49.398 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/social/hbs/notifications, sourced from 3 files.
27.04.2022 09:46:49.398 *WARN* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.FileBundle Referenced path in /etc/clientlibs/social/hbs/featuredcontent/css.txt does not exist: /etc/clientlibs/social/hbs/featuredcontent/featuredcontent.css
27.04.2022 09:46:49.398 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [CSS] library: /etc/clientlibs/social/hbs/featuredcontent, sourced from 2 files.
27.04.2022 09:46:49.399 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/social/connect, sourced from 3 files.
27.04.2022 09:46:49.399 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [CSS] theme library: /etc/clientlibs/social/connect/themes/default, sourced from 3 files.
27.04.2022 09:46:49.399 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/media/publishing, sourced from 2 files.
27.04.2022 09:46:49.399 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/address, sourced from 3 files.
27.04.2022 09:46:49.400 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/ng-maps, sourced from 7 files.
27.04.2022 09:46:49.400 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/push, sourced from 3 files.
27.04.2022 09:46:49.400 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/user, sourced from 4 files.
27.04.2022 09:46:49.401 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/ng-foundation, sourced from 8 files.
27.04.2022 09:46:49.401 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/content-sync, sourced from 6 files.
27.04.2022 09:46:49.401 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/amazonsns, sourced from 4 files.
27.04.2022 09:46:49.402 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/content-sync-2, sourced from 6 files.
27.04.2022 09:46:49.402 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/mobile/swipejs, sourced from 3 files.
27.04.2022 09:46:49.402 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/mobile/ng-toast, sourced from 5 files.
27.04.2022 09:46:49.402 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [CSS] library: /etc/clientlibs/wcm/foundation/accessibility, sourced from 3 files.
27.04.2022 09:46:49.403 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS, CSS] library: /etc/clientlibs/wcm/foundation/main, sourced from 3 files.
27.04.2022 09:46:49.403 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/angularjs, sourced from 8 files.
27.04.2022 09:46:49.403 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/granite/testing/hobbes/bootstrap, sourced from 3 files.
27.04.2022 09:46:49.404 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/browsermap.standard, sourced from 8 files.
27.04.2022 09:46:49.404 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/browsermap, sourced from 3 files.
27.04.2022 09:46:49.404 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/sitecatalyst/tracking, sourced from 5 files.
27.04.2022 09:46:49.405 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/sitecatalyst/plugins, sourced from 5 files.
27.04.2022 09:46:49.405 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/sitecatalyst/appmeasurement, sourced from 3 files.
27.04.2022 09:46:49.405 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/sitecatalyst/util, sourced from 5 files.
27.04.2022 09:46:49.405 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [JS] library: /etc/clientlibs/sitecatalyst/sitecatalyst, sourced from 3 files.
27.04.2022 09:46:49.406 *INFO* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] com.adobe.granite.ui.clientlibs.impl.HtmlLibraryManagerImpl detected [CSS] library: /etc/clientlibs/topcoat, sourced from 4 files.
27.04.2022 09:46:49.408 *ERROR* [REDACTED [1651045609228] GET /sites.html/content HTTP/1.1] org.apache.sling.engine.impl.SlingRequestProcessorImpl service: Uncaught SlingException
java.lang.NullPointerException: null

 

 

Additional information

The short-lived instance we've already upgraded works. Both Author and Publish are okay.

 

Surprisingly, our custom pages render actual content when a request is made directly (i.e. /content/ourapp/en/gb/home/hello.html is requested) rather than via the /editor.html console.


This means whatever affects the OOTB functionality isn't as bad on custom pages. This might have to do with the custom ones relying
on HTL rather than JSP but it's a guess at this point.

 

The Publish instance in this environment, running the same versions of the software, looks healthy. We can access those consoles when circumventing the Dispatcher and see them working.

CRXDE, the Package manager and the Felix console are fine. 


What we've tried so far:

  • Clearing the compiled JSP via /system/console/fsclassloader
  • Restarting the instance
  • For login page issue
    • Reviewing the configuration of the Sling Authenticator to see if anonymous access is allowed
    • Reviewing the ACL applied to the page
    • Restoring the instance from backup and restarting the upgrade procedure, it's the same each time (the procedure is automated)

What we're yet to try

  • Uninstalling the Crownpeak plugin prior to the upgrade and installing a newer version afterwards
  • Dropping the SP11 zip into crx-quickstart/install
  • Creating a very basic component to check which APIs break it when used. This is based on the observation that our custom code, mostly using HTL, works at least partially (there's something wrong with clientlibs) and many basic consoles are broken. CRXDE and the OSGi console work. This implies a potential issue with the Sling JSP engine. CRXDE and the OSGi console also use JSP but they're loaded in a different way.

Has anyone faced similar issues? There's still a couple of things we can try but I feel we're going a little blind at this point. Any suggestions would be welcome.

Avatar

Correct answer by
Level 2

Upon closer inspection, the method being called in the head.jsp (see the stack trace from /editor.html in the thread) comes from another JSP, /libs/cq/gui/components/authoring/editors/core/instrumentationUtil.jsp, which is different on the broken instance than on the working one.

 

The version on the broken instance only has one method named getTrackingPageContent, which takes a single argument. The version on the working instance has an additional version that takes two String parameters. This is the one the head.jsp seems to be calling.

 

Searching CRXDE for /libs/cq/gui/components/authoring/editors/ yields the filters of two CRX packages, both of which appear to come from inside the Service Pack 11 zip.

 

On the broken instance, these packages, along with one other, appear not to be installed

tomaszn90975356_0-1651063874858.png

On the working instance, they look fine. Seems like the Service Pack installation hasn't succeeded.

I can see that two of these packages happen to contain the misaligned JSP.

I've tried deleting them and reinstalling the Service Pack (expecting it to reinstall them). The packages do reappear but they're not installed.

When I tried manually installing cq-ui-wcm-editor-content-1.1.418.zip, it threw an exception:

saving approx 331 nodes... 
Error during processing:

org.apache.jackrabbit.vault.packaging.PackageException: javax.jcr.nodetype.ConstraintViolationException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]
	at org.apache.jackrabbit.vault.packaging.impl.ZipVaultPackage.extract(ZipVaultPackage.java:238)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.extract(JcrPackageImpl.java:401)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.installDependencies(JcrPackageImpl.java:802)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.extract(JcrPackageImpl.java:383)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.extract(JcrPackageImpl.java:360)
	at org.apache.jackrabbit.vault.packaging.impl.JcrPackageImpl.install(JcrPackageImpl.java:354)
	at com.day.crx.packaging.impl.J2EEPackageManager.consoleInstall(J2EEPackageManager.java:363)
	at com.day.crx.packaging.impl.J2EEPackageManager.doPost(J2EEPackageManager.java:205)
	at com.day.crx.packaging.impl.PackageManagerServlet.doPost(PackageManagerServlet.java:172)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:644)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
	at org.apache.felix.http.base.internal.handler.ServletHandler.handle(ServletHandler.java:123)
	at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:86)
	at com.adobe.granite.license.impl.LicenseCheckFilter.doFilter(LicenseCheckFilter.java:308)
	at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:142)
	at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81)
	at org.apache.sling.i18n.impl.I18NFilter.doFilter(I18NFilter.java:131)
	at org.apache.felix.http.base.internal.handler.FilterHandler.handle(FilterHandler.java:142)
	at org.apache.felix.http.base.internal.dispatch.InvocationChain.doFilter(InvocationChain.java:81)
	at org.apache.felix.http.base.internal.dispatch.Dispatcher$1.doFilter(Dispatcher.java:146)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1002)
	at com.adobe.granite.auth.ims.impl.IMSClusterExchangeTokenPreprocessor.doFilter(IMSClusterExchangeTokenPreprocessor.java:281)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at com.adobe.granite.auth.oauth.impl.OAuthCallbackFilter.doFilter(OAuthCallbackFilter.java:69)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at org.apache.sling.security.impl.ReferrerFilter.doFilter(ReferrerFilter.java:326)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at org.apache.felix.http.sslfilter.internal.SslFilter.doFilter(SslFilter.java:97)
	at org.apache.felix.http.base.internal.handler.PreprocessorHandler.handle(PreprocessorHandler.java:137)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager$2.doFilter(WhiteboardManager.java:1008)
	at org.apache.felix.http.base.internal.whiteboard.WhiteboardManager.invokePreprocessors(WhiteboardManager.java:1012)
	at org.apache.felix.http.base.internal.dispatch.Dispatcher.dispatch(Dispatcher.java:91)
	at org.apache.felix.http.base.internal.dispatch.DispatcherServlet.service(DispatcherServlet.java:49)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:725)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:799)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:550)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.session.SessionHandler.doHandle(SessionHandler.java:1624)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
	at org.eclipse.jetty.server.session.SessionHandler.doScope(SessionHandler.java:1594)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:191)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:277)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:338)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:315)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:173)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:131)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:383)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:882)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:1036)
	at java.lang.Thread.run(Thread.java:750)
Caused by: javax.jcr.nodetype.ConstraintViolationException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]
	at org.apache.jackrabbit.oak.api.CommitFailedException.asRepositoryException(CommitFailedException.java:226)
	at org.apache.jackrabbit.oak.api.CommitFailedException.asRepositoryException(CommitFailedException.java:213)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.newRepositoryException(SessionDelegate.java:669)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.save(SessionDelegate.java:495)
	at org.apache.jackrabbit.oak.jcr.session.SessionImpl$8.performVoid(SessionImpl.java:424)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performVoid(SessionDelegate.java:273)
	at org.apache.jackrabbit.oak.jcr.session.SessionImpl.save(SessionImpl.java:421)
	at org.apache.jackrabbit.vault.fs.io.AutoSave.save(AutoSave.java:177)
	at org.apache.jackrabbit.vault.fs.io.Importer.run(Importer.java:437)
	at org.apache.jackrabbit.vault.packaging.impl.ZipVaultPackage.extract(ZipVaultPackage.java:233)
	... 66 more
Caused by: org.apache.jackrabbit.oak.api.CommitFailedException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor$1.onConstraintViolation(TypeEditor.java:109)
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor.constraintViolation(TypeEditor.java:234)
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor.childNodeChanged(TypeEditor.java:312)
	at org.apache.jackrabbit.oak.plugins.nodetype.TypeEditor.childNodeAdded(TypeEditor.java:285)
	at org.apache.jackrabbit.oak.spi.commit.VisibleEditor.childNodeAdded(VisibleEditor.java:89)
	at org.apache.jackrabbit.oak.spi.commit.CompositeEditor.childNodeAdded(CompositeEditor.java:107)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeAdded(EditorDiff.java:115)
	at org.apache.jackrabbit.oak.segment.MapRecord$4.childNodeAdded(MapRecord.java:465)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:527)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:462)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:444)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147)
	at org.apache.jackrabbit.oak.segment.MapRecord$4.childNodeChanged(MapRecord.java:471)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:517)
	at org.apache.jackrabbit.oak.segment.MapRecord.compareBranch(MapRecord.java:595)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:496)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:462)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.childNodeChanged(EditorDiff.java:147)
	at org.apache.jackrabbit.oak.segment.MapRecord.compare(MapRecord.java:517)
	at org.apache.jackrabbit.oak.segment.SegmentNodeState.compareAgainstBaseState(SegmentNodeState.java:651)
	at org.apache.jackrabbit.oak.spi.commit.EditorDiff.process(EditorDiff.java:51)
	at org.apache.jackrabbit.oak.spi.commit.EditorHook.processCommit(EditorHook.java:54)
	at org.apache.jackrabbit.oak.spi.commit.CompositeHook.processCommit(CompositeHook.java:60)
	at org.apache.jackrabbit.oak.spi.commit.CompositeHook.processCommit(CompositeHook.java:60)
	at org.apache.jackrabbit.oak.segment.scheduler.Commit.apply(Commit.java:99)
	at org.apache.jackrabbit.oak.segment.scheduler.LockBasedScheduler.execute(LockBasedScheduler.java:299)
	at org.apache.jackrabbit.oak.segment.scheduler.LockBasedScheduler.schedule(LockBasedScheduler.java:270)
	at org.apache.jackrabbit.oak.segment.SegmentNodeStore.merge(SegmentNodeStore.java:211)
	at org.apache.jackrabbit.oak.core.MutableRoot.commit(MutableRoot.java:251)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.commit(SessionDelegate.java:346)
	at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.save(SessionDelegate.java:493)
	... 72 more


Error: javax.jcr.nodetype.ConstraintViolationException: OakConstraint0001: /var/workflow/models[[nt:folder, rep:AccessControllable]]: No matching definition found for child node request_for_deletion_without_deactivation with effective type [cq:WorkflowModel]

It appears to be complaining about a node type definiton that I can see in CRXDE at /jcr:system/jcr:nodeTypes/cq:WorkflowModel

It looks the same on the working instance and the broken one.

 

However, the parent node, /var/workflow/models on this instance appears to have the jcr:primaryType of nt:folder, rather than the expected sling:Folder

 

This prevents the package (and presumably any other packages containing workflow models) from installing properly. I've checked the backups and it seems the node had already been there prior to the upgrade. This is very strange because in AEM 6.3, workflow models used to sit under /etc/workflow, not at /var/workflow. The other 6.3 instances we're updgrading don't have that node at all.

 

My best guess is that at some point in the past, someone mistakenly tried to install a package containing a workflow model, placed relative to the 6.4/6.5 workflow model folder location. At that point, AEM would have created an intermediate node with type nt:folder

 

Removing the malformed and ill-placed /var/workflow folder from the 6.3 instance prior to the upgrade and repeating the upgrade procedure appears to have resolved all the issues mentioned in this thread.