


martin-nekula-h
martin-nekula-h
07-03-2020
When we moved from AEM 6.2 to 6.5.3, bundle deployment started taking more time. According to log, each servlet and service registration is accompanied by some Adobe Granite Maintenance Scheduler Update Task.
I am enclosing below the initial log snippet when starting the deployment of a content package containing our OSGi bundle. After this it goes on in a similar manner for 25 seconds before finishing. Is there a way to disable the Update for development environment?
07.03.2020 21:35:08.135 *INFO* [oak-repository-executor-1] com.adobe.granite.repository Service [23631, [org.apache.jackrabbit.oak.api.jmx.SessionMBean]] ServiceEvent REGISTERED
07.03.2020 21:35:10.415 *INFO* [oak-repository-executor-1] com.adobe.granite.repository Service [23632, [org.apache.jackrabbit.oak.api.jmx.SessionMBean]] ServiceEvent REGISTERED
07.03.2020 21:35:12.782 *INFO* [oak-repository-executor-1] com.adobe.granite.repository Service [23633, [org.apache.jackrabbit.oak.api.jmx.SessionMBean]] ServiceEvent REGISTERED
07.03.2020 21:38:18.520 *INFO* [qtp910998498-6010] org.apache.jackrabbit.vault.packaging.impl.ActivityLog devsoft:hartmann-default-components:1.0-SNAPSHOT: CREATE
07.03.2020 21:38:18.520 *INFO* [qtp910998498-6010] org.apache.jackrabbit.vault.packaging.impl.ActivityLog devsoft:hartmann-default-components:1.0-SNAPSHOT: UPLOAD
07.03.2020 21:38:18.528 *INFO* [qtp910998498-6010] com.day.crx.packaging.impl.SlingInstallerSupportImpl Sling installer node /system/sling/installer/jcr/pauseInstallation/51184b5a-4e90-4ae4-b224-0c39ebaf70b7/com.day.crx.packaging.impl.SlingInstallerSupportImpl/201733a5-6203-46b2-aa1a-f140e0217fef created.
07.03.2020 21:38:18.592 *WARN* [qtp910998498-6010] org.apache.jackrabbit.vault.fs.impl.io.DocViewSAXImporter Error while setting property (ignore): javax.jcr.nodetype.ConstraintViolationException: Property is protected: jcr:created = 2013-09-03T09:41:16.304+02:00
07.03.2020 21:38:20.874 *WARN* [qtp910998498-6010] org.apache.jackrabbit.vault.fs.impl.io.DocViewSAXImporter Error while setting property (ignore): javax.jcr.nodetype.ConstraintViolationException: Property is protected: jcr:created = 2013-09-03T09:41:16.304+02:00
07.03.2020 21:38:21.599 *INFO* [qtp910998498-6010] org.apache.jackrabbit.vault.packaging.impl.ActivityLog devsoft:hartmann-default-components:1.0-SNAPSHOT: INSTALL
07.03.2020 21:38:21.601 *INFO* [qtp910998498-6010] com.day.crx.packaging.impl.SlingInstallerSupportImpl Sling installer node /system/sling/installer/jcr/pauseInstallation/51184b5a-4e90-4ae4-b224-0c39ebaf70b7/com.day.crx.packaging.impl.SlingInstallerSupportImpl/201733a5-6203-46b2-aa1a-f140e0217fef removed.
07.03.2020 21:38:21.638 *INFO* [JcrInstaller.1] org.apache.sling.installer.provider.jcr.impl.JcrInstaller Registering resource with OSGi installer: [InstallableResource, priority=200, id=/apps/default/install/hartmann-default-bundle-1.0-SNAPSHOT.jar]
07.03.2020 21:38:21.761 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle BundleEvent STOPPING
07.03.2020 21:38:21.765 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/intranet/competencematrix/instruction/downloadfile,21486, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.771 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/intranet/competencematrix/instruction/downloadfile.servlet,21489, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.773 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.competencematrix.instructionadministration.servlet.DownloadFileAttachmentServlet,21483, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.779 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservicespublic/intranet/registrationform/sendregistrationformtoemail.servlet,21200, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.784 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservicespublic/intranet/registrationform/sendregistrationformtoemail,21201, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.786 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.registrationform.registrationform.RegistrationFormServlet,21199, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.792 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/intranet/competencematrix/instruction/findallinstructionsbyparam,22883, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.797 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/intranet/competencematrix/instruction/findallinstructionsbyparam.servlet,22884, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.799 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.competencematrix.instructionadministration.servlet.FindAllInstructionsByParamServlet,22882, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.805 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/intranet/jobdescription/findjobdescriptionbyuser,23381, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.811 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/intranet/jobdescription/findjobdescriptionbyuser.servlet,23384, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.813 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.jobdescription.servlets.FindJobDescriptionByUser,23374, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.813 *INFO* [Apache Sling Resource Provider Change Notifier] com.day.cq.wcm.mobile.core.impl.devicespecs.WurflXmlLoader Requesting execution of 'wait for no events and parse if needed' task
07.03.2020 21:38:21.814 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='RevisionCleanupTask', Status='UNSCHEDULED', Result='', Details='{"window":"granite_daily"}'
07.03.2020 21:38:21.814 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='LuceneBinariesCleanupTask', Status='UNSCHEDULED', Result='', Details='{"window":"granite_daily"}'
07.03.2020 21:38:21.814 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='DataStoreGarbageCollectionTask', Status='UNSCHEDULED', Result='', Details='{"window":"granite_weekly"}'
07.03.2020 21:38:21.814 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='WorkflowPurgeTask', Status='UNSCHEDULED', Result='', Details='{"window":"granite_weekly"}'
07.03.2020 21:38:21.814 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='com.day.cq.audit.impl.AuditLogMaintenanceTask', Status='UNSCHEDULED', Result='', Details='{"window":"granite_weekly"}'
07.03.2020 21:38:21.815 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23618, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.818 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23617, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.819 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/trainingcourse/getaditionalinfo.servlet,22886, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.821 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23620, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.823 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23619, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.823 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/trainingcourse/getaditionalinfo,22889, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.825 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.trainingcourse.servlets.GetAditionalInfoServlet,22885, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.826 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23622, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.828 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23621, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.830 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23624, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.833 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23623, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.833 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservicespublic/intranet/servlet/exportemployeespersonalnumber,22895, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.836 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23626, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.839 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23625, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.841 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservicespublic/intranet/servlet/exportemployeespersonalnumber.servlet,22898, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.842 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23628, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.843 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.employeesPersonalNumberExport.servlet.EmployeesPersonalNumberExportServlet,22893, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.844 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23627, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.847 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23630, [javax.management.DynamicMBean]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.849 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23629, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.849 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/trainingcourse/deactivateperson.servlet,21357, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.851 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='RevisionCleanupTask', Status='SCHEDULED', Result='', Details='{"window":"granite_daily"}'
07.03.2020 21:38:21.851 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='LuceneBinariesCleanupTask', Status='SCHEDULED', Result='', Details='{"window":"granite_daily"}'
07.03.2020 21:38:21.851 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='DataStoreGarbageCollectionTask', Status='SCHEDULED', Result='', Details='{"window":"granite_weekly"}'
07.03.2020 21:38:21.851 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='WorkflowPurgeTask', Status='SCHEDULED', Result='', Details='{"window":"granite_weekly"}'
07.03.2020 21:38:21.851 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.impl.MaintenanceJobsManagerImpl Name='com.day.cq.audit.impl.AuditLogMaintenanceTask', Status='SCHEDULED', Result='', Details='{"window":"granite_weekly"}'
07.03.2020 21:38:21.853 *INFO* [Adobe Granite Maintenance Scheduler Update Task] org.apache.sling.hc.core Service [23635, [javax.management.DynamicMBean]] ServiceEvent REGISTERED
07.03.2020 21:38:21.853 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.queries.impl.hc.QueryHealthCheckMetrics First execution of gauge [health-com.adobe.granite.maintenance.healthcheck.impl.RevisionCleanupTaskHealthCheck] returned status [0]
07.03.2020 21:38:21.853 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.queries.impl.hc.QueryHealthCheckMetrics Registered Gauge [health-com.adobe.granite.maintenance.healthcheck.impl.RevisionCleanupTaskHealthCheck]
07.03.2020 21:38:21.854 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [ServletResourceProvider for Servlet at /hartmannservices/trainingcourse/deactivateperson,21358, [org.apache.sling.spi.resource.provider.ResourceProvider]] ServiceEvent UNREGISTERING
07.03.2020 21:38:21.854 *INFO* [Adobe Granite Maintenance Scheduler Update Task] com.adobe.granite.maintenance.core Service [23634, [org.apache.sling.hc.api.HealthCheck]] ServiceEvent REGISTERED
07.03.2020 21:38:21.855 *INFO* [OsgiInstallerImpl] cz.devsoft.hartmann.hartmann-default-bundle Service [info.hartmann.intranet.trainingcourse.servlets.attendancelist.DeactivatePerson,21356, [javax.servlet.Servlet]] ServiceEvent UNREGISTERING
Jörg_Hoh
Employee
Jörg_Hoh
Employee
13-03-2020
Hi,
that's indeed a strange behavior. Can you check what kind of OSGI events are triggered during such a deployment via the OSGI webconsole ("events")? Does this happen just during the the registration/deregistration of the servlets?
martin-nekula-h
martin-nekula-h
16-03-2020
Hello @Jörg_Hoh,
I have checked the system/console/events after deploying a component zip with bundle but the total length was longer than 250 lines, which is the limit of the console there. But I am enclosing it below through Pastebin:
Also the whole error.log concerning the deployment of the package and bundle inside. Maybe it will be helpful:
jurgenbrouwer
jurgenbrouwer
09-04-2020
We're facing a similar issue on our 6.4.8 environment. We can see a crazy amount of maintenance unscheduling/scheduling after our deployments. In some cases it takes up to 5 minutes for our system to recover.
I'm sending you a message on LinkedIn as well. I'm really curious if you were able to solve this!
martin-nekula-h
martin-nekula-h
09-04-2020
Hello Jurgen, unfortunately not 😣
I´ve been through many settings in console and the maintenance UI but nothing helped so far. My only hope is Service Pack 4 for AEM 6.5 which we haven´t tried yet, but I don´t have much hope for that.
martin-nekula-h
martin-nekula-h
09-04-2020
Hello Jörg, I replied below. Unfortunately in the time when I was posting my reply to you, the "Reply" button was somehow not visible.
Jörg_Hoh
Employee
Jörg_Hoh
Employee
09-04-2020
Have you raised a Daycare ticket already?
Jörg_Hoh
Employee
Jörg_Hoh
Employee
09-04-2020
I investigated on it, and it seems to be a problem with the Sling ResourceChangeListener functionality, which seems to trigger too often. I asked on the sling user list, if this is a known issue[1].
I checked and found that 6.5.2 is affected as well, so I don't think that you just can wait for the fix to arrive in a SP.
I would recommend you to open a Daycare ticket for this, and ask for help and a patch.
HTH,
Jörg
jurgenbrouwer
jurgenbrouwer
09-04-2020
Thanks for the update Jörg.
We investigated it and on 6.4.6 the issue did not occur yet. Anyway, looking at this thread it seems to be introduced by a SP for both 6.4 and 6.5 recently.
I'll create a Daycare ticket for it on our side.
Jörg_Hoh
Employee
Jörg_Hoh
Employee
10-04-2020
I just tested a workaround, and it seems to work.
Just create an OSGI configuration for com.adobe.granite.maintenance.impl.TaskScheduler and provide a multi-value property "resource.change.types" with the values "ADDED", "CHANGED" and "REMOVED".