search

valtech / aem-easy-content-upgrade

AEM Easy Content Upgrade simplifies content migrations in AEM projects
Other
61 stars 25 forks source link

Script still fail during deployment on AEM as a cloud when script uses groovyconsole or aecu methods #188

Closed michal-tobiasz-wttech closed 2 years ago

michal-tobiasz-wttech commented 2 years ago

I'm still facing an issue from this ticket https://github.com/valtech/aem-easy-content-upgrade/issues/184 It looks like it happens only on the Author instance. groovy.lang.MissingPropertyException: No such property: aecu for class: Script1 or

groovy.lang.MissingMethodException: No signature of method: Script1.getPage() is applicable for argument types: (java.lang.String) values: [/content/test]
Possible solutions: getAt(java.lang.String), getClass()
25.05.2022 13:01:05.087 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [Apache Sling Repository Startup Thread #1] de.valtech.aecu.core.service.AecuServiceImpl Executing script /apps/aecu-scripts/test/common-repo-tests/1-pages-modification.groovy
25.05.2022 13:01:05.088 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [Apache Sling Repository Startup Thread #1] de.valtech.aecu.core.service.AecuServiceImpl Executing script /apps/aecu-scripts/test/common-repo-tests/1-pages-modification.prechecks.groovy
25.05.2022 13:01:05.128 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.xmp.worker.files.ncomm.XMPFilesNComm INIT: Update Builder with parameters=[maxConnections=4, maxRequests=50000, requestTimeout=30000, logDir=crx-quickstart/logs]
25.05.2022 13:01:05.136 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.apache.sling.commons.threads.impl.DefaultThreadPool Initializing thread pool [org-apache-sling-sitemap]  ...
25.05.2022 13:01:05.137 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.apache.sling.commons.threads.impl.ThreadLocalCleaner Validating reflective access is permitted... 
25.05.2022 13:01:05.137 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.apache.sling.commons.threads.impl.DefaultThreadPool min-pool-size (0) < max-pool-size (5) for pool "org-apache-sling-sitemap" which has unbounded queue (queue size -1). Set to 5
25.05.2022 13:01:05.137 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.apache.sling.commons.threads.impl.ThreadLocalCleaner Accessed thread locals of current thread, found 4096
25.05.2022 13:01:05.137 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.apache.sling.commons.threads.impl.DefaultThreadPool Thread pool [org-apache-sling-sitemap] initialized.
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.impl.DirectSchedulerFactory Quartz scheduler version: 2.3.2
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.simpl.RAMJobStore RAMJobStore initialized.
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.core.QuartzScheduler Quartz Scheduler v.2.3.2 created.
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.core.SchedulerSignalerImpl Initialized Scheduler Signaller of type: class org.quartz.core.SchedulerSignalerImpl
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.impl.DirectSchedulerFactory Quartz scheduler 'ApacheSlingorg-apache-sling-sitemap
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.core.QuartzScheduler Scheduler meta-data: Quartz Scheduler (v2.3.2) 'ApacheSlingorg-apache-sling-sitemap' with instanceId 'Wed_May_25_13:01:05_UTC_2022822346942'
  Scheduler class: 'org.quartz.core.QuartzScheduler' - running locally.
  NOT STARTED.
  Currently in standby mode.
  Number of jobs executed: 0
  Using thread pool 'org.apache.sling.commons.scheduler.impl.QuartzThreadPool' - with 5 threads.
  Using job-store 'org.quartz.simpl.RAMJobStore' - which does not support persistence. and is not clustered.
25.05.2022 13:01:05.164 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixStartLevel] org.quartz.core.QuartzScheduler Scheduler ApacheSlingorg-apache-sling-sitemap_$_Wed_May_25_13:01:05_UTC_2022822346942 started.
25.05.2022 13:01:05.166 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.org.apache.sling.sitemap Service [org.apache.sling.sitemap.impl.SitemapGeneratorExecutor,4282, [org.apache.sling.event.jobs.consumer.JobExecutor]] ServiceEvent REGISTERED
25.05.2022 13:01:05.178 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.org.apache.sling.sitemap Service [org.apache.sling.sitemap.impl.SitemapServiceImpl,4283, [org.apache.sling.sitemap.SitemapService]] ServiceEvent REGISTERED
25.05.2022 13:01:05.179 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.org.apache.sling.sitemap Service [org.apache.sling.sitemap.impl.console.SitemapInventoryPlugin,4284, [org.apache.felix.inventory.InventoryPrinter]] ServiceEvent REGISTERED
25.05.2022 13:01:05.207 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.org.apache.sling.sitemap Service [4285, [javax.servlet.Servlet]] ServiceEvent REGISTERED
25.05.2022 13:01:05.211 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.org.apache.sling.sitemap Service [org.apache.sling.sitemap.impl.SitemapServlet,4286, [javax.servlet.Servlet]] ServiceEvent REGISTERED
25.05.2022 13:01:05.217 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixDispatchQueue] org.apache.sling.launchpad.startupmanager.StartupListenerTracker Startup progress: 83% (bundles 502/599)
25.05.2022 13:01:05.218 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Bundle.com.adobe.cq.wcm.com.adobe.aem.wcm.seo.impl BundleEvent STARTED
25.05.2022 13:01:05.222 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Bundle.com.adobe.granite.ui.clientlibs.compiler.less BundleEvent RESOLVED
25.05.2022 13:01:05.225 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.com.adobe.granite.ui.clientlibs.compiler.less Service [com.adobe.granite.ui.clientlibs.compiler.less.impl.LessCompilerImpl,4287, [com.adobe.granite.ui.clientlibs.script.ScriptCompiler]] ServiceEvent REGISTERED
25.05.2022 13:01:05.228 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixDispatchQueue] org.apache.sling.launchpad.startupmanager.StartupListenerTracker Startup progress: 83% (bundles 503/599)
25.05.2022 13:01:05.229 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Bundle.com.adobe.granite.ui.clientlibs.compiler.less BundleEvent STARTED
25.05.2022 13:01:05.232 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Bundle.com.adobe.granite.ui.clientlibs.processor.gcc BundleEvent RESOLVED
25.05.2022 13:01:05.237 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.xmp.worker.files.ncomm.XMPFilesNComm INIT: Native worker will be initialized with pluginPath=/opt/aem/launcher/framework/bundle346/data/.octopus/res/linux
25.05.2022 13:01:05.280 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.day.cq.dam.core.impl.metadata.editor.MetadataFieldProviderService Binding Component Handler for: any
25.05.2022 13:01:05.280 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.day.cq.dam.core.impl.metadata.editor.MetadataFieldProviderService Binding Component Handler for: granite/ui/components/coral/foundation/form/select
25.05.2022 13:01:05.280 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.day.cq.dam.core.impl.metadata.editor.MetadataFieldProviderService Binding Component Handler for: dam/gui/coral/components/admin/schemaforms/formbuilder/formfields/v2/metadataselect
25.05.2022 13:01:05.308 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.com.adobe.granite.ui.clientlibs.processor.gcc Service [com.adobe.granite.ui.clientlibs.processor.gcc.impl.GCCScriptProcessor,4288, [com.adobe.granite.ui.clientlibs.script.ScriptProcessor]] ServiceEvent REGISTERED
25.05.2022 13:01:05.313 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [Timer-3] com.adobe.granite.probes.impl.K8SProbesMaintaner Probe systemready Status HCOk:2 nHC:4 mostSevier:TEMPORARILY_UNAVAILABLE Probes active:true 
25.05.2022 13:01:05.313 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [Timer-3] com.adobe.granite.probes.impl.K8SProbesMaintaner Probe systemalive Status HCOk:2 nHC:3 mostSevier:TEMPORARILY_UNAVAILABLE Probes active:true 
25.05.2022 13:01:05.313 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [Timer-3] com.adobe.granite.probes.impl.K8SProbesMaintaner Start State: Starting 
25.05.2022 13:01:05.333 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixDispatchQueue] org.apache.sling.launchpad.startupmanager.StartupListenerTracker Startup progress: 84% (bundles 505/599)
25.05.2022 13:01:05.333 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Bundle.com.adobe.granite.ui.clientlibs.processor.gcc BundleEvent STARTED
25.05.2022 13:01:05.339 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.com.adobe.granite.ui.clientlibs Service [4289, [org.osgi.service.cm.ManagedService]] ServiceEvent REGISTERED
25.05.2022 13:01:05.343 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [FelixLogListener] Events.Service.com.adobe.granite.ui.clientlibs Service [com.adobe.granite.ui.clientlibs.impl.CompilerProviderImpl,4290, [com.adobe.granite.ui.clientlibs.impl.CompilerProvider]] ServiceEvent REGISTERED
25.05.2022 13:01:05.377 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.day.cq.dam.handler.ffmpeg.LocatorImpl Search path: /opt/local/bin, /usr/local/bin, /usr/lib/jvm/jre-11.0.13/bin, /usr/local/sbin, /usr/local/bin, /usr/sbin, /usr/bin, /sbin, /bin
25.05.2022 13:01:05.527 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [qtp1448494341-93] com.adobe.granite.probes.impl.K8SProbes Ready Probe: Instance was last seen at 1653483626528, assuming not ready
25.05.2022 13:01:05.596 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [qtp167487703-93] com.adobe.granite.probes.impl.K8SProbes Start Probe: Instance still starting at 1653483665313
25.05.2022 13:01:05.624 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.cloudservices.provisioning.impl.ProvisioningCommand bound new ProvisioningHandler: com.day.cq.analytics.testandtarget.impl.provisioning.TargetProvisioningHandler, id=target
25.05.2022 13:01:05.624 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.cloudservices.provisioning.impl.ProvisioningCommand bound new ProvisioningHandler: com.day.cq.analytics.sitecatalyst.impl.provisioning.SiteCatalystProvisioningHandler, id=analytics
25.05.2022 13:01:05.671 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: openProjectLink
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: unlockPage
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: createPage
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: createVersion
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: createMetadataTemplate
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: createAssetShare
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: open
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: copyLanguages
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: restoreVersion
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: lockPage
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: lockNode
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: provisionCloudService
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: restoreTree
25.05.2022 13:01:05.672 [cm-p29439-e93903-aem-author-586857fd96-fw4ls] *INFO* [Apache Sling Repository Startup Thread #1] com.adobe.cq.dashboards.impl.servlets.WCMCommandService Binding WCMCommand: unlockNode
25.05.2022 13:01:05.755 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *ERROR* [Apache Sling Repository Startup Thread #1] com.icfolson.aem.groovy.console.impl.DefaultGroovyConsoleService error running script
groovy.lang.MissingMethodException: No signature of method: Script1.getPage() is applicable for argument types: (java.lang.String) values: [/content/test]
gruberrolandvaltech commented 2 years ago

Is a simple AECU script like this working?

aecu.contentUpgradeBuilder() .forResources((String[])["/content"]) .printPath() .run()

gruberrolandvaltech commented 2 years ago

Also, it looks like the message does not come from AECU. I miss e.g. an info message "AECU migration started" before. Maybe the script is executed directly by Groovy Console via its scheduler or external trigger?

michal-tobiasz-wttech commented 2 years ago

Sorry I missed the message. These messages I can see in /apps/valtech/aecu/tools/history/details.html also In case of the info message "AECU migration started" I see in logs

25.05.2022 13:01:04.726 [cm-p29439-e93903-aem-author-586857fd96-fgb27] *INFO* [Apache Sling Repository Startup Thread #1] de.valtech.aecu.core.service.AecuCloudStartupService AECU migration started

Script Example: aecu.contentUpgradeBuilder() .forResources((String[]) ['/content/test']) .printPath() .run()

getPage('/content/test')

gruberrolandvaltech commented 2 years ago

Thanks, I will do some more experiments like changing the bundle start level and using a Sling startup listener.

gruberrolandvaltech commented 2 years ago

We changed the startup level of the startup hook to 27 which should prevent this issue. You can retry with version 6.0.2 that will be published the next few days. Please reopen the issue if it is still a problem.

gruberrolandvaltech commented 2 years ago

6.0.2 was released today.