Netcentric / accesscontroltool

Rights and roles management for AEM made easy
Eclipse Public License 1.0
150 stars 92 forks source link

Prevent warnings "Unexpected changes (38) performed on a non-default mount" during AEMaaCS first Startup Hook execution #686

Closed kwin closed 5 months ago

kwin commented 7 months ago

The following WARNs are emitted in the deployment log in the Cloud Manager:

5.02.2024 11:46:49.748 *WARN* [ResourceResolverFactory registration] org.apache.jackrabbit.oak.composite.impl.NonDefaultMountWriteReportingObserver$ChangeReporter Unexpected changes (38) performed on a non-default mount. Printing at most 50_- /apps : Changed_- ....
java.lang.RuntimeException: null
    at org.apache.jackrabbit.oak.composite.impl.NonDefaultMountWriteReportingObserver$CountingDiff.report(NonDefaultMountWriteReportingObserver.java:106)
    at org.apache.jackrabbit.oak.composite.impl.NonDefaultMountWriteReportingObserver.contentChanged(NonDefaultMountWriteReportingObserver.java:88)
    at org.apache.jackrabbit.oak.spi.commit.CompositeObserver.contentChanged(CompositeObserver.java:51)
    at org.apache.jackrabbit.oak.spi.commit.ChangeDispatcher.contentChanged(ChangeDispatcher.java:79)
    at org.apache.jackrabbit.oak.segment.scheduler.LockBasedScheduler$ObservableLockBasedScheduler.contentChanged(LockBasedScheduler.java:394)
    at org.apache.jackrabbit.oak.segment.scheduler.LockBasedScheduler.execute(LockBasedScheduler.java:303)
    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:262)
    at org.apache.jackrabbit.oak.jcr.delegate.WorkspaceDelegate$WorkspaceCopy.perform(WorkspaceDelegate.java:130)
    at org.apache.jackrabbit.oak.jcr.delegate.WorkspaceDelegate.copy(WorkspaceDelegate.java:99)
    at org.apache.jackrabbit.oak.jcr.session.WorkspaceImpl$2.performVoid(WorkspaceImpl.java:163)
    at org.apache.jackrabbit.oak.jcr.delegate.SessionDelegate.performVoid(SessionDelegate.java:299)
    at org.apache.jackrabbit.oak.jcr.session.WorkspaceImpl.copy(WorkspaceImpl.java:150)
    at org.apache.jackrabbit.oak.jcr.session.WorkspaceImpl.copy(WorkspaceImpl.java:132)
    at biz.netcentric.cq.tools.actool.startuphook.impl.AcToolStartupHookServiceImpl.copyAcHistoryToOrFromApps(AcToolStartupHookServiceImpl.java:194)
    at biz.netcentric.cq.tools.actool.startuphook.impl.AcToolStartupHookServiceImpl.runAcTool(AcToolStartupHookServiceImpl.java:109)
    at biz.netcentric.cq.tools.actool.startuphook.impl.AcToolStartupHookServiceImpl.activate(AcToolStartupHookServiceImpl.java:94)
    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:245)
    at org.apache.felix.scr.impl.inject.methods.BaseMethod.access$500(BaseMethod.java:41)
    at org.apache.felix.scr.impl.inject.methods.BaseMethod$Resolved.invoke(BaseMethod.java:687)
    at org.apache.felix.scr.impl.inject.methods.BaseMethod.invoke(BaseMethod.java:531)
    at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:317)
    at org.apache.felix.scr.impl.inject.methods.ActivateMethod.invoke(ActivateMethod.java:307)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.createImplementationObject(SingleComponentManager.java:354)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.createComponent(SingleComponentManager.java:115)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:1002)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:975)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:785)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1274)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1225)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116)
    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:4863)
    at org.apache.felix.framework.Felix.registerService(Felix.java:3834)
    at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:328)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1274)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1225)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116)
    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:4863)
    at org.apache.felix.framework.Felix.registerService(Felix.java:3834)
    at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:328)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:929)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:915)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:133)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:984)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:752)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1274)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1225)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1232)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1152)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:959)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:895)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1184)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:116)
    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:4863)
    at org.apache.felix.framework.Felix.registerService(Felix.java:3834)
    at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:328)
    at org.apache.felix.framework.BundleContextImpl.registerService(BundleContextImpl.java:501)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler$FactoryRegistration.<init>(FactoryRegistrationHandler.java:198)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler.lambda$doRegisterFactory$4(FactoryRegistrationHandler.java:152)
    at java.base/java.util.Objects.requireNonNullElseGet(Objects.java:321)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler.lambda$doRegisterFactory$5(FactoryRegistrationHandler.java:151)
    at java.base/java.util.concurrent.atomic.AtomicReference.updateAndGet(AtomicReference.java:209)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler.doRegisterFactory(FactoryRegistrationHandler.java:149)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler.lambda$maybeRegisterFactory$1(FactoryRegistrationHandler.java:127)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler.runWithThreadName(FactoryRegistrationHandler.java:175)
    at org.apache.sling.resourceresolver.impl.FactoryRegistrationHandler.lambda$maybeRegisterFactory$2(FactoryRegistrationHandler.java:127)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:834)

This is caused by the NonDefaultMountWriteReportingObserver which emits stack traces of all writes to non-default mounts (like /apps or /libs) during the seed mode of the CompositeNodeStore (compare with OAK-10655).

As those write operations are actually expected, they should not lead to such a noisy warn message. This can be configured with the OSGi configuration with id NonDefaultMountWriteReportingObserver which should extend the default ignoredClassNameFragments.

kwin commented 7 months ago

The default value of the OSGi configuration is hard to retrieve, as it is no longer set once restarted in non-seed mode, i.e. the AEMaaCS Developer Console of an arbitrary Author/Publish environment does no longer contain any configuration for that PID.

kwin commented 7 months ago

This will be solved in the future by an upcoming AEMaaCS release by extending the default config. This is tracked internally by Adobe in SKYOPS-72536.

kwin commented 5 months ago

This is fixed in AEMaaCS in release 15977.