AEMaaCS: Startup Hook executed too early for ACLs on mutable content

[kwin]

Currently the Install Hook is disabled by default in AEMaaCS (https://github.com/Netcentric/accesscontroltool/blob/48e1bfee12347ac958288bffce0ff0c978d77ff9/accesscontroltool-bundle/src/main/java/biz/netcentric/cq/tools/actool/installhook/AcToolInstallHook.java#L80).

When the Startup Hook is executed during the Docker build (when first starting the instance) it works on top of the already set up immutable repo (being initialized with https://github.com/apache/sling-org-apache-sling-jcr-packageinit/blob/master/src/main/java/org/apache/sling/jcr/packageinit/impl/ExecutionPlanRepoInitializer.java). That works fine.

When the Startup Hook is executed while the new Kubernetes pod is starting, the mutable content packages are not yet installed (i.e. the content to which to apply the ACLs might not be there yet), so this execution might fail during the first deployment (but works then on subsequent ones).

[kwin]

It turned out that in our case we had an issue with the Startup Hook being executed during the Docker build because we relied on Cloud Manager Environment variables for a service user key which were not accessible during the Docker build.

20.01.2021 19:06:40.038 *ERROR* [Apache Sling Repository Startup Thread #1] biz.netcentric.cq.tools.actool.impl.AcInstallationServiceImpl Exception in AceServiceImpl: {}
biz.netcentric.cq.tools.actool.validators.exceptions.AcConfigBeanValidationException: Invalid authorizable dtm-reactor-imsconfig-service
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigReader.getAuthorizableBeans(YamlConfigReader.java:230) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigReader.getUserConfigurationBeans(YamlConfigReader.java:152) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigurationMerger.getMergedConfigurations(YamlConfigurationMerger.java:165) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.impl.AcInstallationServiceImpl.installConfigurationFiles(AcInstallationServiceImpl.java:292) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.impl.AcInstallationServiceImpl.apply(AcInstallationServiceImpl.java:223) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.startuphook.impl.AcToolStartupHookServiceImpl.activate(AcToolStartupHookServiceImpl.java:83) [biz.netcentric.cq.tools.accesscontroltool.startuphook.bundle:2.7.0]
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
	at java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invokeMethod(BaseMethod.java:242) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.access$500(BaseMethod.java:41) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod$Resolved.invoke(BaseMethod.java:678) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.inject.methods.BaseMethod.invoke(BaseMethod.java:524) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:318) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:308) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:342) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:984) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:957) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:766) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1091) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1043) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.framework.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:990)
	at org.apache.felix.framework.EventDispatcher.fireEventImmediately(EventDispatcher.java:838)
	at org.apache.felix.framework.EventDispatcher.fireServiceEvent(EventDispatcher.java:545)
	at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:4833)
	at org.apache.felix.framework.Felix.registerService(Felix.java:3804)
	at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:328)
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:907) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:893) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:960) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:733) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1091) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1043) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) [org.apache.felix.scr:2.1.20]
	at org.apache.felix.framework.EventDispatcher.invokeServiceListenerCallback(EventDispatcher.java:990)
	at org.apache.felix.framework.EventDispatcher.fireEventImmediately(EventDispatcher.java:838)
	at org.apache.felix.framework.EventDispatcher.fireServiceEvent(EventDispatcher.java:545)
	at org.apache.felix.framework.Felix.fireServiceEvent(Felix.java:4833)
	at org.apache.felix.framework.Felix.registerService(Felix.java:3804)
	at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:328)
	at org.apache.sling.jcr.base.AbstractSlingRepositoryManager.registerService(AbstractSlingRepositoryManager.java:222) [org.apache.sling.jcr.base:3.1.6]
	at org.apache.sling.jcr.base.AbstractSlingRepositoryManager.initializeAndRegisterRepositoryService(AbstractSlingRepositoryManager.java:566) [org.apache.sling.jcr.base:3.1.6]
	at org.apache.sling.jcr.base.AbstractSlingRepositoryManager.access$300(AbstractSlingRepositoryManager.java:92) [org.apache.sling.jcr.base:3.1.6]
	at org.apache.sling.jcr.base.AbstractSlingRepositoryManager$4.run(AbstractSlingRepositoryManager.java:527) [org.apache.sling.jcr.base:3.1.6]
Caused by: biz.netcentric.cq.tools.actool.validators.exceptions.InvalidAuthorizableException: Invalid key format given
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigReader.setupAuthorizableBean(YamlConfigReader.java:442) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigReader.getAuthorizableBeans(YamlConfigReader.java:224) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	... 57 common frames omitted
Caused by: java.security.InvalidKeyException: No supported PEM format as defined in https://tools.ietf.org/html/rfc7468 detected!
	at biz.netcentric.cq.tools.actool.configmodel.pkcs.DerData.parseFromPem(DerData.java:59) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configmodel.pkcs.Key.<init>(Key.java:65) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configmodel.pkcs.Key.createFromPrivateKeyAndCertificate(Key.java:57) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigReader.setupAuthorizableKeys(YamlConfigReader.java:471) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	at biz.netcentric.cq.tools.actool.configreader.YamlConfigReader.setupAuthorizableBean(YamlConfigReader.java:440) [biz.netcentric.cq.tools.accesscontroltool.bundle:2.7.0]
	... 58 common frames omitted
20.01.2021 19:06:40.038 *INFO* [Apache Sling Repository Startup Thread #1] biz.netcentric.cq.tools.actool.startuphook.impl.AcToolStartupHookServiceImpl AC Tool Startup Hook done. (start level 30)

The problem is that failures in the Startup Hook are not propagated back to the Cloud Manager, i.e. the according step will not fail.

[kwin]

Probably the startup hook should implement SlingRepositoryInitializer to be able to dispatch the exceptions (and not only log them). An exception during installation of the YAML should lead to stopping the startup process, as you cannot recover from it.

This hook has been implemented in the context of SLING-5456 and is only available in AEM 6.3 or newer though.

[kwin]

Using the Install Hook instead of the Startup Hook does not work due to the issue outlined at https://github.com/Netcentric/aem-cloud-validator/issues/3.

[kwin]

Maybe one can leverage somehow https://jackrabbit.apache.org/filevault/apidocs/org/apache/jackrabbit/vault/packaging/events/PackageEventListener.html to defer installation or trigger it again when mutable packages have been installed. Not sure how to distinguish regular mutable package installation via WebUI from the one triggered as part of the Cloud Manager Deployment, though.

[francisbonheur]

Hi,

I am also facing that issue. Is there any plan to deliver a fix for that ? Is there any workaround ?

Regards,

Francis BONHEUR.