search

enonic / xp

Enonic XP
https://enonic.com
GNU General Public License v3.0
201 stars 34 forks source link

Initialization times out leaving nodes "dead" #8173

Closed gbbirkisson closed 3 years ago

gbbirkisson commented 4 years ago

When spinning up a cluster, with multiple nodes simultaneously for the first time, the elected master has to initialize the repos. If for some reason that process is slower then expected (probably slow disk in this case), some nodes might timeout waiting, try to start essential services and error out leaving them impaired or dead.

Elected master (master-2)

                         _____
____________________________(_)______   ____  _________
_  _ \_  __ \  __ \_  __ \_  /_  ___/   __  |/_/__  __ \
/  __/  / / / /_/ /  / / /  / / /__     __>  < __  /_/ /
\___//_/ /_/\____//_/ /_//_/  \___/     /_/|_| _  .___/
                                               /_/

# Enonic XP 7.3.0
# Built on 2020-06-15T08:18:49Z (hash = 60707c9718ad500cd807f91c8a5dc85481e55e8d, branch = 7.3)
# OpenJDK 64-Bit Server VM 11.0.7 (AdoptOpenJDK)
# Linux 4.15.0-1083-azure (amd64)
# Install directory is /enonic-xp
# Home directory is /enonic-xp/home

2020-06-24 14:12:08,618 INFO  c.e.x.l.i.framework.FrameworkService - Starting Enonic XP...
2020-06-24 14:12:09,064 INFO  c.e.x.l.i.p.ProvisionActivator - Installing 92 bundles...
2020-06-24 14:12:10,218 INFO  ROOT - bundle org.apache.felix.scr:2.1.16 (11)Starting with globalExtender setting: false
2020-06-24 14:12:10,234 INFO  ROOT - bundle org.apache.felix.scr:2.1.16 (11) Version = 2.1.16
2020-06-24 14:12:11,714 WARN  org.apache.tika.parsers.PDFParser - TIFFImageWriter not loaded. tiff files will not be processed
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.
J2KImageReader not loaded. JPEG2000 files will not be processed.
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.

2020-06-24 14:12:11,785 WARN  org.apache.tika.parser.SQLite3Parser - org.xerial's sqlite-jdbc is not loaded.
Please provide the jar on your classpath to parse sqlite files.
See tika-parsers/pom.xml for the correct version.
2020-06-24 14:12:12,182 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.hazelcast]
2020-06-24 14:12:12,185 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.app.status]
2020-06-24 14:12:12,187 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.web.sessionstore]
2020-06-24 14:12:12,230 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.app.main]
2020-06-24 14:12:12,233 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.elasticsearch]
2020-06-24 14:12:12,269 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.cluster]
2020-06-24 14:12:12,272 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.web.vhost]
2020-06-24 14:12:12,318 INFO  c.e.x.s.shell.impl.ShellActivator - Remote shell access is disabled
2020-06-24 14:12:13,094 INFO  c.e.x.s.internal.trace.TraceService - Call tracing is disabled in config
2020-06-24 14:12:13,408 INFO  c.e.x.c.i.a.c.AuditLogConfigImpl - Audit log is enabled and mappings updated.
2020-06-24 14:12:13,493 INFO  c.e.x.i.blobstore.BlobStoreActivator - Waiting for blobstore-provider [file]
2020-06-24 14:12:13,495 INFO  c.e.x.i.blobstore.BlobStoreActivator - Found blobstore-provider [file]
2020-06-24 14:12:13,571 INFO  c.e.x.i.blobstore.BlobStoreActivator - Registered blobstore [file] successfully
2020-06-24 14:12:14,769 INFO  org.elasticsearch.node - [master-2] version[2.4.6], pid[1], build[NA/NA]
2020-06-24 14:12:14,770 INFO  org.elasticsearch.node - [master-2] initializing ...
2020-06-24 14:12:14,773 INFO  org.elasticsearch.plugins - [master-2] modules [], plugins [], sites []
2020-06-24 14:12:14,786 INFO  org.elasticsearch.env - [master-2] using [1] data paths, mounts [[/enonic-xp/home/repo/index (/dev/sdc)]], net usable_space [958.6mb], net total_space [975.8mb], spins? [possibly], types [ext4]
2020-06-24 14:12:14,787 INFO  org.elasticsearch.env - [master-2] heap size [2.9gb], compressed ordinary object pointers [true]
2020-06-24 14:12:16,791 INFO  org.elasticsearch.node - [master-2] initialized
2020-06-24 14:12:16,791 INFO  org.elasticsearch.node - [master-2] starting ...
2020-06-24 14:12:16,840 INFO  org.elasticsearch.transport - [master-2] publish_address {10.244.2.3:9300}, bound_addresses {10.244.2.3:9300}
2020-06-24 14:12:16,864 INFO  org.elasticsearch.discovery - [master-2] klp-klp-test-xp7/35AHy4EdRtqiLcUdKw-Mzg
2020-06-24 14:12:19,971 INFO  org.elasticsearch.cluster.service - [master-2] new_master {master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}, added {{backend-0}{xUAraBIBSa-TifTHaKjnog}{10.244.1.2}{10.244.1.2:9300}{local=false, master=false},{backend-1}{ICPWHKEYRECCd1Zw-3P7hg}{10.244.7.2}{10.244.7.2:9300}{local=false, master=false},{master-1}{3YOXOYRQSYqX_2WfkbyYWA}{10.244.8.2}{10.244.8.2:9300}{data=false, local=false, master=true},{master-0}{yfhL6_A-SFCvgTipmZCBuw}{10.244.6.2}{10.244.6.2:9300}{data=false, local=false, master=true},}, reason: zen-disco-join(elected_as_master, [2] joins received)
2020-06-24 14:12:20,073 INFO  org.elasticsearch.http - [master-2] publish_address {10.244.2.3:9200}, bound_addresses {10.244.2.3:9200}
2020-06-24 14:12:20,073 INFO  org.elasticsearch.node - [master-2] started
2020-06-24 14:12:20,171 INFO  c.e.x.c.impl.ClusterManagerImpl - Adding cluster-provider: elasticsearch
2020-06-24 14:12:20,385 INFO  org.elasticsearch.gateway - [master-2] recovered [0] indices into cluster_state
2020-06-24 14:12:20,405 INFO  c.e.x.c.impl.ClusterManagerImpl - Activating all providers
2020-06-24 14:12:20,405 INFO  c.e.x.e.impl.ElasticsearchCluster - Cluster operational, register elasticsearch-client
2020-06-24 14:12:20,705 INFO  org.eclipse.jetty.util.log - Logging initialized @12777ms to org.eclipse.jetty.util.log.Slf4jLog
2020-06-24 14:12:20,992 INFO  org.eclipse.jetty.server.Server - jetty-9.4.28.v20200408; built: 2020-04-08T17:49:39.557Z; git: ab228fde9e55e9164c738d7fa121f8ac5acd51c9; jvm 11.0.7+10
2020-06-24 14:12:21,073 INFO  org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=master-2
2020-06-24 14:12:21,074 INFO  org.eclipse.jetty.server.session - No SessionScavenger set, using defaults
2020-06-24 14:12:21,075 INFO  org.eclipse.jetty.server.session - master-2 Scavenging every 660000ms
2020-06-24 14:12:21,077 INFO  com.enonic.xp.init.Initializer - Initializing System-repo
2020-06-24 14:12:21,105 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@420c33ec{/,null,AVAILABLE,@xp}
2020-06-24 14:12:21,175 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@5848514a{/,null,AVAILABLE,@api}
2020-06-24 14:12:21,176 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@3eff336c{/,null,AVAILABLE,@status}
2020-06-24 14:12:21,203 INFO  o.e.jetty.server.AbstractConnector - Started xp@2f74af77{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2020-06-24 14:12:21,204 INFO  o.e.jetty.server.AbstractConnector - Started api@69e0cf3e{HTTP/1.1, (http/1.1)}{0.0.0.0:4848}
2020-06-24 14:12:21,205 INFO  o.e.jetty.server.AbstractConnector - Started status@7c148c06{HTTP/1.1, (http/1.1)}{0.0.0.0:2609}
2020-06-24 14:12:21,205 INFO  org.eclipse.jetty.server.Server - Started @13278ms
2020-06-24 14:12:21,214 INFO  c.e.xp.web.jetty.impl.JettyActivator - Started Jetty
2020-06-24 14:12:21,215 INFO  c.e.xp.web.jetty.impl.JettyActivator - Listening on ports [8080](xp), [4848](management) and [2609](monitoring)
2020-06-24 14:12:21,273 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - creating index search-system-repo
2020-06-24 14:12:21,298 INFO  c.e.x.w.v.i.c.VirtualHostConfigImpl - Virtual host is enabled and mappings updated.
2020-06-24 14:12:21,712 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] creating index, cause [api], templates [], shards [1]/[1], mappings []
2020-06-24 14:12:22,866 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Index search-system-repo created with status true
2020-06-24 14:12:22,866 INFO  org.elasticsearch.cluster.service - [master-2] added {{admin-0}{T3oHAGijRquqO1hPAoeEcg}{10.244.4.2}{10.244.4.2:9300}{data=false, local=false, master=false},{frontend-0}{ozwWkPcLSwiaqcK6uBc7Vg}{10.244.5.2}{10.244.5.2:9300}{data=false, local=false, master=false},}, reason: zen-disco-join(join from node[{admin-0}{T3oHAGijRquqO1hPAoeEcg}{10.244.4.2}{10.244.4.2:9300}{data=false, local=false, master=false}])
2020-06-24 14:12:22,867 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - creating index storage-system-repo
2020-06-24 14:12:22,978 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[search-system-repo][0], [search-system-repo][0]] ...]).
2020-06-24 14:12:23,256 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system-repo] creating index, cause [api], templates [], shards [1]/[1], mappings []
2020-06-24 14:12:23,338 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Index storage-system-repo created with status true
2020-06-24 14:12:23,339 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[storage-system-repo][0], [search-system-repo][0]] ...]).
2020-06-24 14:12:23,343 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index search-system-repo
2020-06-24 14:12:23,510 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] create_mapping [_default_]
2020-06-24 14:12:23,679 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index search-system-repo applied
2020-06-24 14:12:23,679 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-system-repo
2020-06-24 14:12:23,680 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[storage-system-repo][0], [storage-system-repo][0]] ...]).
2020-06-24 14:12:23,711 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system-repo] create_mapping [branch]
2020-06-24 14:12:23,776 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-system-repo applied
2020-06-24 14:12:23,777 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-system-repo
2020-06-24 14:12:23,797 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system-repo] create_mapping [version]
2020-06-24 14:12:23,876 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-system-repo applied
2020-06-24 14:12:23,876 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-system-repo
2020-06-24 14:12:23,891 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system-repo] create_mapping [commit]
2020-06-24 14:12:23,925 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-system-repo applied
2020-06-24 14:12:24,314 INFO  org.elasticsearch.cluster.service - [master-2] added {{backend-2}{x9JKuPhYRE2uniapEVQf7Q}{10.244.3.2}{10.244.3.2:9300}{local=false, master=false},}, reason: zen-disco-join(join from node[{backend-2}{x9JKuPhYRE2uniapEVQf7Q}{10.244.3.2}{10.244.3.2:9300}{local=false, master=false}])
2020-06-24 14:12:25,571 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] create_mapping [master]
2020-06-24 14:12:26,323 INFO  c.e.x.r.i.r.RepositoryServiceImpl - Created root node in with id [000-000-000-000] in repository [system-repo]
2020-06-24 14:12:26,616 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:27,044 INFO  com.enonic.xp.init.Initializer - System-repo successfully initialized
2020-06-24 14:12:27,074 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.system bundle 87
2020-06-24 14:12:27,095 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.applications bundle 89
2020-06-24 14:12:27,108 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.main bundle 90
2020-06-24 14:12:27,110 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.standardidprovider bundle 91
2020-06-24 14:12:27,119 INFO  c.e.x.l.i.framework.FrameworkService - Started Enonic XP in 18502 ms
2020-06-24 14:12:27,163 INFO  E.F.org.apache.felix.framework - FrameworkEvent STARTLEVEL CHANGED
2020-06-24 14:12:27,165 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.users bundle 92
2020-06-24 14:12:27,323 INFO  com.enonic.xp.init.Initializer - Initializing System-repo [applications] layout
2020-06-24 14:12:27,324 INFO  c.e.x.c.i.a.ApplicationRepoInitializer - Initializing [/applications] folder
2020-06-24 14:12:27,841 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:27,947 INFO  com.enonic.xp.init.Initializer - System-repo [applications] layout successfully initialized
2020-06-24 14:12:28,495 INFO  com.enonic.xp.init.Initializer - Initializing System-repo [security] layout
2020-06-24 14:12:28,496 INFO  c.e.x.c.i.s.SecurityInitializer - Initializing [/identity] folder
2020-06-24 14:12:28,877 INFO  c.e.x.c.i.s.SecurityInitializer - Initializing [/identity/roles] folder
2020-06-24 14:12:29,312 INFO  c.e.x.c.i.s.SecurityInitializer - Initializing id provider [system]
2020-06-24 14:12:29,540 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:32,015 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:32,155 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.admin
2020-06-24 14:12:32,370 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.authenticated
2020-06-24 14:12:32,587 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.everyone
2020-06-24 14:12:32,808 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.admin.login
2020-06-24 14:12:33,062 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.user.app
2020-06-24 14:12:33,272 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.user.admin
2020-06-24 14:12:33,474 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:cms.cm.app
2020-06-24 14:12:33,745 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:cms.expert
2020-06-24 14:12:33,956 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:cms.admin
2020-06-24 14:12:34,229 INFO  c.e.x.c.i.s.SecurityInitializer - Role created: role:system.auditlog
2020-06-24 14:12:34,433 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:34,563 INFO  c.e.x.c.i.s.SecurityInitializer - User created: user:system:anonymous
2020-06-24 14:12:34,768 INFO  c.e.x.c.i.s.SecurityInitializer - User created: user:system:su
2020-06-24 14:12:34,975 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:35,063 INFO  c.e.x.c.i.s.SecurityInitializer - Added user:system:su as member of role:system.admin
2020-06-24 14:12:35,063 INFO  com.enonic.xp.init.Initializer - System-repo [security] layout successfully initialized
2020-06-24 14:12:35,105 INFO  com.enonic.xp.init.Initializer - Initializing system.auditlog repo
2020-06-24 14:12:35,112 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - creating index search-system.auditlog
2020-06-24 14:12:35,184 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system.auditlog] creating index, cause [api], templates [], shards [1]/[1], mappings []
2020-06-24 14:12:35,334 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Index search-system.auditlog created with status true
2020-06-24 14:12:35,335 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - creating index storage-system.auditlog
2020-06-24 14:12:35,340 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[search-system.auditlog][0]] ...]).
2020-06-24 14:12:35,505 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system.auditlog] creating index, cause [api], templates [], shards [1]/[1], mappings []
2020-06-24 14:12:35,553 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Index storage-system.auditlog created with status true
2020-06-24 14:12:35,554 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index search-system.auditlog
2020-06-24 14:12:35,593 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system.auditlog] create_mapping [_default_]
2020-06-24 14:12:35,665 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index search-system.auditlog applied
2020-06-24 14:12:35,666 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-system.auditlog
2020-06-24 14:12:35,668 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[storage-system.auditlog][0], [search-system.auditlog][0], [storage-system.auditlog][0], [search-system.auditlog][0]] ...]).
2020-06-24 14:12:35,717 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system.auditlog] create_mapping [branch]
2020-06-24 14:12:35,771 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[storage-system.auditlog][0]] ...]).
2020-06-24 14:12:35,771 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-system.auditlog applied
2020-06-24 14:12:35,772 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-system.auditlog
2020-06-24 14:12:35,797 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system.auditlog] create_mapping [version]
2020-06-24 14:12:35,835 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-system.auditlog applied
2020-06-24 14:12:35,836 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-system.auditlog
2020-06-24 14:12:35,879 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-system.auditlog] create_mapping [commit]
2020-06-24 14:12:35,945 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-system.auditlog applied
2020-06-24 14:12:36,390 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system.auditlog] create_mapping [master]
2020-06-24 14:12:36,503 INFO  c.e.x.r.i.r.RepositoryServiceImpl - Created root node in with id [000-000-000-000] in repository [system.auditlog]
2020-06-24 14:12:36,786 INFO  com.enonic.xp.init.Initializer - system.auditlog repo successfully initialized
2020-06-24 14:12:36,853 INFO  com.enonic.xp.init.Initializer - Initializing com.enonic.cms.default repo
2020-06-24 14:12:36,864 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - creating index search-com.enonic.cms.default
2020-06-24 14:12:36,888 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] creating index, cause [api], templates [], shards [1]/[1], mappings []
2020-06-24 14:12:37,003 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Index search-com.enonic.cms.default created with status true
2020-06-24 14:12:37,004 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - creating index storage-com.enonic.cms.default
2020-06-24 14:12:37,004 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[search-com.enonic.cms.default][0]] ...]).
2020-06-24 14:12:37,063 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-com.enonic.cms.default] creating index, cause [api], templates [], shards [1]/[1], mappings []
2020-06-24 14:12:37,137 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [RED] to [YELLOW] (reason: [shards started [[search-com.enonic.cms.default][0], [storage-com.enonic.cms.default][0]] ...]).
2020-06-24 14:12:37,138 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Index storage-com.enonic.cms.default created with status true
2020-06-24 14:12:37,139 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index search-com.enonic.cms.default
2020-06-24 14:12:37,200 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] create_mapping [_default_]
2020-06-24 14:12:37,240 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index search-com.enonic.cms.default applied
2020-06-24 14:12:37,240 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-com.enonic.cms.default
2020-06-24 14:12:37,244 INFO  o.e.cluster.routing.allocation - [master-2] Cluster health status changed from [YELLOW] to [GREEN] (reason: [shards started [[storage-com.enonic.cms.default][0]] ...]).
2020-06-24 14:12:37,284 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-com.enonic.cms.default] create_mapping [branch]
2020-06-24 14:12:37,321 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-com.enonic.cms.default applied
2020-06-24 14:12:37,321 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-com.enonic.cms.default
2020-06-24 14:12:37,372 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-com.enonic.cms.default] create_mapping [version]
2020-06-24 14:12:37,482 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-com.enonic.cms.default applied
2020-06-24 14:12:37,482 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Apply mapping for index storage-com.enonic.cms.default
2020-06-24 14:12:37,491 INFO  org.elasticsearch.cluster.metadata - [master-2] [storage-com.enonic.cms.default] create_mapping [commit]
2020-06-24 14:12:37,521 INFO  c.e.x.r.i.e.IndexServiceInternalImpl - Mapping for index storage-com.enonic.cms.default applied
2020-06-24 14:12:37,929 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] create_mapping [master]
2020-06-24 14:12:38,047 INFO  c.e.x.r.i.r.RepositoryServiceImpl - Created root node in with id [000-000-000-000] in repository [com.enonic.cms.default]
2020-06-24 14:12:38,375 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] create_mapping [draft]
2020-06-24 14:12:38,640 INFO  c.e.x.c.i.p.init.ContentInitializer - Content root-node not found, creating
2020-06-24 14:12:38,947 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] update_mapping [master]
2020-06-24 14:12:39,014 INFO  c.e.x.c.i.p.init.ContentInitializer - Created content root-node: /content
2020-06-24 14:12:39,125 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] update_mapping [draft]
2020-06-24 14:12:39,192 INFO  com.enonic.xp.init.Initializer - com.enonic.cms.default repo successfully initialized
2020-06-24 14:12:39,198 INFO  com.enonic.xp.init.Initializer - Initializing com.enonic.cms.default repo [issue] layout
2020-06-24 14:12:39,198 INFO  c.e.x.c.i.p.init.IssueInitializer - Issue root-node not found, creating
2020-06-24 14:12:39,530 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] update_mapping [master]
2020-06-24 14:12:41,800 INFO  c.e.x.c.i.p.init.IssueInitializer - Created issue root-node: /issues
2020-06-24 14:12:41,862 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-com.enonic.cms.default] update_mapping [draft]
2020-06-24 14:12:42,764 INFO  org.elasticsearch.cluster.metadata - [master-2] [search-system-repo] update_mapping [master]
2020-06-24 14:12:42,834 INFO  com.enonic.xp.init.Initializer - com.enonic.cms.default repo [issue] layout successfully initialized
2020-06-24 14:12:43,068 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Searching for installed applications
2020-06-24 14:12:43,084 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Found [0] installed applications
2020-06-24 14:12:43,175 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,175 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,176 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Local application [com.enonic.app.snapshotter] installed successfully
2020-06-24 14:12:43,208 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - All notifiers configured, starting schedules
2020-06-24 14:12:43,305 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - Scheduler already started
2020-06-24 14:12:43,370 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - Scheduler already started
2020-06-24 14:12:43,373 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Configuring application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,373 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Started application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,373 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Application [com.enonic.app.snapshotter] started successfully
2020-06-24 14:12:43,385 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.alive bundle 94
2020-06-24 14:12:43,386 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.alive bundle 94
2020-06-24 14:12:43,386 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Local application [com.enonic.app.alive] installed successfully
2020-06-24 14:12:43,394 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Started application com.enonic.app.alive bundle 94
2020-06-24 14:12:43,394 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Application [com.enonic.app.alive] started successfully
2020-06-24 14:12:44,096 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Configuring application com.enonic.app.alive bundle 94
2020-06-24 15:00:00,031 INFO  org.elasticsearch.repositories - [master-2] put repository [enonic-xp-snapshot-repo]
2020-06-24 15:01:03,823 INFO  org.elasticsearch.snapshots - [master-2] snapshot [enonic-xp-snapshot-repo:hourly_2020-06-24t15_01_00.002511z] is done

Dead node 1 (master-1)

                         _____
____________________________(_)______   ____  _________
_  _ \_  __ \  __ \_  __ \_  /_  ___/   __  |/_/__  __ \
/  __/  / / / /_/ /  / / /  / / /__     __>  < __  /_/ /
\___//_/ /_/\____//_/ /_//_/  \___/     /_/|_| _  .___/
                                               /_/

# Enonic XP 7.3.0
# Built on 2020-06-15T08:18:49Z (hash = 60707c9718ad500cd807f91c8a5dc85481e55e8d, branch = 7.3)
# OpenJDK 64-Bit Server VM 11.0.7 (AdoptOpenJDK)
# Linux 4.15.0-1083-azure (amd64)
# Install directory is /enonic-xp
# Home directory is /enonic-xp/home

2020-06-24 14:12:08,038 INFO  c.e.x.l.i.framework.FrameworkService - Starting Enonic XP...
2020-06-24 14:12:08,429 INFO  c.e.x.l.i.p.ProvisionActivator - Installing 92 bundles...
2020-06-24 14:12:09,636 INFO  ROOT - bundle org.apache.felix.scr:2.1.16 (11)Starting with globalExtender setting: false
2020-06-24 14:12:09,647 INFO  ROOT - bundle org.apache.felix.scr:2.1.16 (11) Version = 2.1.16
2020-06-24 14:12:11,014 WARN  org.apache.tika.parsers.PDFParser - TIFFImageWriter not loaded. tiff files will not be processed
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.
J2KImageReader not loaded. JPEG2000 files will not be processed.
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.

2020-06-24 14:12:11,038 WARN  org.apache.tika.parser.SQLite3Parser - org.xerial's sqlite-jdbc is not loaded.
Please provide the jar on your classpath to parse sqlite files.
See tika-parsers/pom.xml for the correct version.
2020-06-24 14:12:11,415 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.hazelcast]
2020-06-24 14:12:11,422 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.app.status]
2020-06-24 14:12:11,427 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.web.sessionstore]
2020-06-24 14:12:11,431 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.app.main]
2020-06-24 14:12:11,435 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.elasticsearch]
2020-06-24 14:12:11,439 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.cluster]
2020-06-24 14:12:11,537 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.web.vhost]
2020-06-24 14:12:11,616 INFO  c.e.x.s.shell.impl.ShellActivator - Remote shell access is disabled
2020-06-24 14:12:12,199 INFO  c.e.x.s.internal.trace.TraceService - Call tracing is disabled in config
2020-06-24 14:12:12,623 INFO  c.e.x.c.i.a.c.AuditLogConfigImpl - Audit log is enabled and mappings updated.
2020-06-24 14:12:12,695 INFO  c.e.x.i.blobstore.BlobStoreActivator - Waiting for blobstore-provider [file]
2020-06-24 14:12:12,696 INFO  c.e.x.i.blobstore.BlobStoreActivator - Found blobstore-provider [file]
2020-06-24 14:12:12,719 INFO  c.e.x.i.blobstore.BlobStoreActivator - Registered blobstore [file] successfully
2020-06-24 14:12:13,438 INFO  org.elasticsearch.node - [master-1] version[2.4.6], pid[1], build[NA/NA]
2020-06-24 14:12:13,438 INFO  org.elasticsearch.node - [master-1] initializing ...
2020-06-24 14:12:13,441 INFO  org.elasticsearch.plugins - [master-1] modules [], plugins [], sites []
2020-06-24 14:12:13,502 INFO  org.elasticsearch.env - [master-1] using [1] data paths, mounts [[/enonic-xp/home/repo/index (/dev/sdc)]], net usable_space [958.6mb], net total_space [975.8mb], spins? [possibly], types [ext4]
2020-06-24 14:12:13,502 INFO  org.elasticsearch.env - [master-1] heap size [2.9gb], compressed ordinary object pointers [true]
2020-06-24 14:12:15,311 INFO  org.elasticsearch.node - [master-1] initialized
2020-06-24 14:12:15,311 INFO  org.elasticsearch.node - [master-1] starting ...
2020-06-24 14:12:15,400 INFO  org.elasticsearch.transport - [master-1] publish_address {10.244.8.2:9300}, bound_addresses {10.244.8.2:9300}
2020-06-24 14:12:15,403 INFO  org.elasticsearch.discovery - [master-1] klp-klp-test-xp7/3YOXOYRQSYqX_2WfkbyYWA
2020-06-24 14:12:20,000 INFO  org.elasticsearch.cluster.service - [master-1] detected_master {master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}, added {{backend-1}{ICPWHKEYRECCd1Zw-3P7hg}{10.244.7.2}{10.244.7.2:9300}{local=false, master=false},{master-0}{yfhL6_A-SFCvgTipmZCBuw}{10.244.6.2}{10.244.6.2:9300}{data=false, local=false, master=true},{backend-0}{xUAraBIBSa-TifTHaKjnog}{10.244.1.2}{10.244.1.2:9300}{local=false, master=false},{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true},}, reason: zen-disco-receive(from master [{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}])
2020-06-24 14:12:20,022 INFO  org.elasticsearch.http - [master-1] publish_address {10.244.8.2:9200}, bound_addresses {10.244.8.2:9200}
2020-06-24 14:12:20,022 INFO  org.elasticsearch.node - [master-1] started
2020-06-24 14:12:20,123 INFO  c.e.x.c.impl.ClusterManagerImpl - Adding cluster-provider: elasticsearch
2020-06-24 14:12:20,413 INFO  c.e.x.c.impl.ClusterManagerImpl - Activating all providers
2020-06-24 14:12:20,413 INFO  c.e.x.e.impl.ElasticsearchCluster - Cluster operational, register elasticsearch-client
2020-06-24 14:12:20,432 INFO  org.eclipse.jetty.util.log - Logging initialized @13120ms to org.eclipse.jetty.util.log.Slf4jLog
2020-06-24 14:12:20,702 INFO  org.eclipse.jetty.server.Server - jetty-9.4.28.v20200408; built: 2020-04-08T17:49:39.557Z; git: ab228fde9e55e9164c738d7fa121f8ac5acd51c9; jvm 11.0.7+10
2020-06-24 14:12:20,722 INFO  org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=master-1
2020-06-24 14:12:20,722 INFO  org.eclipse.jetty.server.session - No SessionScavenger set, using defaults
2020-06-24 14:12:20,723 INFO  org.eclipse.jetty.server.session - master-1 Scavenging every 600000ms
2020-06-24 14:12:20,736 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@5273a3ea{/,null,AVAILABLE,@xp}
2020-06-24 14:12:20,746 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@565d0cc0{/,null,AVAILABLE,@api}
2020-06-24 14:12:20,794 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@18d1f15e{/,null,AVAILABLE,@status}
2020-06-24 14:12:20,808 INFO  o.e.jetty.server.AbstractConnector - Started xp@7331cb15{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2020-06-24 14:12:20,809 INFO  o.e.jetty.server.AbstractConnector - Started api@4a4990d7{HTTP/1.1, (http/1.1)}{0.0.0.0:4848}
2020-06-24 14:12:20,810 INFO  o.e.jetty.server.AbstractConnector - Started status@710c437c{HTTP/1.1, (http/1.1)}{0.0.0.0:2609}
2020-06-24 14:12:20,810 INFO  org.eclipse.jetty.server.Server - Started @13499ms
2020-06-24 14:12:20,816 INFO  c.e.xp.web.jetty.impl.JettyActivator - Started Jetty
2020-06-24 14:12:20,816 INFO  c.e.xp.web.jetty.impl.JettyActivator - Listening on ports [8080](xp), [4848](management) and [2609](monitoring)
2020-06-24 14:12:20,836 INFO  c.e.x.w.v.i.c.VirtualHostConfigImpl - Virtual host is enabled and mappings updated.
2020-06-24 14:12:21,119 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:22,167 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:22,870 INFO  org.elasticsearch.cluster.service - [master-1] added {{frontend-0}{ozwWkPcLSwiaqcK6uBc7Vg}{10.244.5.2}{10.244.5.2:9300}{data=false, local=false, master=false},{admin-0}{T3oHAGijRquqO1hPAoeEcg}{10.244.4.2}{10.244.4.2:9300}{data=false, local=false, master=false},}, reason: zen-disco-receive(from master [{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}])
2020-06-24 14:12:23,402 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:24,317 INFO  org.elasticsearch.cluster.service - [master-1] added {{backend-2}{x9JKuPhYRE2uniapEVQf7Q}{10.244.3.2}{10.244.3.2:9300}{local=false, master=false},}, reason: zen-disco-receive(from master [{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}])
2020-06-24 14:12:24,407 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:25,412 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:26,417 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:27,020 WARN  c.e.x.i.s.rest.ApplicationResource - bundle com.enonic.xp.server.rest:7.3.0 (86)[com.enonic.xp.impl.server.rest.ApplicationResource(264)] : Could not get service from ref [com.enonic.xp.app.ApplicationService]
2020-06-24 14:12:27,021 INFO  c.e.x.i.s.rest.ApplicationResource - bundle com.enonic.xp.server.rest:7.3.0 (86)[com.enonic.xp.impl.server.rest.ApplicationResource(264)] :  Could not obtain all required dependencies, getService returning null
2020-06-24 14:12:27,030 ERROR E.F.com.enonic.xp.server.rest - FrameworkEvent ERROR
org.apache.felix.log.LogException: org.osgi.framework.ServiceException: Service factory exception: Could not obtain lock
    at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:353)
    at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:248)
    at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:350)
    at org.apache.felix.framework.Felix.getService(Felix.java:3954)
    at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:450)
    at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86)
    at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47)
    at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.prebind(DependencyManager.java:1154)
    at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1568)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1029)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:935)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:756)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:666)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:432)
    at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665)
    at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:338)
    at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:382)
    at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49)
    at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:264)
    at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196)
    at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169)
    at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49)
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:488)
    at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:420)
    at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232)
    at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:450)
    at org.apache.felix.framework.EventDispatcher.invokeBundleListenerCallback(EventDispatcher.java:915)
    at org.apache.felix.framework.EventDispatcher.fireEventImmediately(EventDispatcher.java:834)
    at org.apache.felix.framework.EventDispatcher.fireBundleEvent(EventDispatcher.java:516)
    at org.apache.felix.framework.Felix.fireBundleEvent(Felix.java:4817)
    at org.apache.felix.framework.Felix.startBundle(Felix.java:2336)
    at org.apache.felix.framework.Felix.setActiveStartLevel(Felix.java:1539)
    at org.apache.felix.framework.FrameworkStartLevelImpl.run(FrameworkStartLevelImpl.java:308)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.IllegalStateException: Could not obtain lock
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.obtainLock(AbstractComponentManager.java:240)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.obtainStateLock(AbstractComponentManager.java:287)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:888)
    at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:348)
    ... 35 common frames omitted
2020-06-24 14:12:28,305 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.system bundle 87
2020-06-24 14:12:28,397 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.applications bundle 89
2020-06-24 14:12:28,411 INFO  E.F.org.apache.felix.framework - FrameworkEvent STARTLEVEL CHANGED
2020-06-24 14:12:28,411 INFO  c.e.x.l.i.framework.FrameworkService - Started Enonic XP in 20374 ms
2020-06-24 14:12:29,012 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:29,118 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.main bundle 90
2020-06-24 14:12:29,136 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.standardidprovider bundle 91
2020-06-24 14:12:29,195 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.users bundle 92
2020-06-24 14:12:30,017 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:31,020 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:32,024 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:33,028 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:34,031 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:35,064 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:36,068 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:37,505 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo to be initialized
2020-06-24 14:12:38,573 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo to be initialized
2020-06-24 14:12:39,693 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo [issue] layout to be initialized
2020-06-24 14:12:40,697 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo [issue] layout to be initialized
2020-06-24 14:12:41,701 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo [issue] layout to be initialized
2020-06-24 14:12:43,327 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Searching for installed applications
2020-06-24 14:12:43,553 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Found [0] installed applications
2020-06-24 14:12:43,705 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,706 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,706 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Local application [com.enonic.app.snapshotter] installed successfully
2020-06-24 14:12:43,825 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - All notifiers configured, starting schedules
2020-06-24 14:12:43,899 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - Scheduler already started
2020-06-24 14:12:43,912 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - Scheduler already started
2020-06-24 14:12:43,913 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Configuring application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,920 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Started application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:43,920 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Application [com.enonic.app.snapshotter] started successfully
2020-06-24 14:12:44,250 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,250 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,250 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Local application [com.enonic.app.alive] installed successfully
2020-06-24 14:12:44,251 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Configuring application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,257 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Started application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,257 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Application [com.enonic.app.alive] started successfully

Dead node 2 (backend-0)

                         _____
____________________________(_)______   ____  _________
_  _ \_  __ \  __ \_  __ \_  /_  ___/   __  |/_/__  __ \
/  __/  / / / /_/ /  / / /  / / /__     __>  < __  /_/ /
\___//_/ /_/\____//_/ /_//_/  \___/     /_/|_| _  .___/
                                               /_/

# Enonic XP 7.3.0
# Built on 2020-06-15T08:18:49Z (hash = 60707c9718ad500cd807f91c8a5dc85481e55e8d, branch = 7.3)
# OpenJDK 64-Bit Server VM 11.0.7 (AdoptOpenJDK)
# Linux 4.15.0-1083-azure (amd64)
# Install directory is /enonic-xp
# Home directory is /enonic-xp/home

2020-06-24 14:12:05,514 INFO  c.e.x.l.i.framework.FrameworkService - Starting Enonic XP...
2020-06-24 14:12:05,916 INFO  c.e.x.l.i.p.ProvisionActivator - Installing 92 bundles...
2020-06-24 14:12:06,909 INFO  ROOT - bundle org.apache.felix.scr:2.1.16 (11)Starting with globalExtender setting: false
2020-06-24 14:12:06,920 INFO  ROOT - bundle org.apache.felix.scr:2.1.16 (11) Version = 2.1.16
2020-06-24 14:12:08,177 WARN  org.apache.tika.parsers.PDFParser - TIFFImageWriter not loaded. tiff files will not be processed
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.
J2KImageReader not loaded. JPEG2000 files will not be processed.
See https://pdfbox.apache.org/2.0/dependencies.html#jai-image-io
for optional dependencies.

2020-06-24 14:12:08,203 WARN  org.apache.tika.parser.SQLite3Parser - org.xerial's sqlite-jdbc is not loaded.
Please provide the jar on your classpath to parse sqlite files.
See tika-parsers/pom.xml for the correct version.
2020-06-24 14:12:08,523 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.hazelcast]
2020-06-24 14:12:08,575 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.app.status]
2020-06-24 14:12:08,585 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.web.sessionstore]
2020-06-24 14:12:08,589 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.app.main]
2020-06-24 14:12:08,593 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.elasticsearch]
2020-06-24 14:12:08,601 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.cluster]
2020-06-24 14:12:08,605 INFO  c.e.x.s.i.config.ConfigInstallerImpl - Loaded config for [com.enonic.xp.web.vhost]
2020-06-24 14:12:08,626 INFO  c.e.x.s.shell.impl.ShellActivator - Remote shell access is disabled
2020-06-24 14:12:09,298 INFO  c.e.x.s.internal.trace.TraceService - Call tracing is disabled in config
2020-06-24 14:12:09,569 INFO  c.e.x.c.i.a.c.AuditLogConfigImpl - Audit log is enabled and mappings updated.
2020-06-24 14:12:09,585 INFO  c.e.x.i.blobstore.BlobStoreActivator - Waiting for blobstore-provider [file]
2020-06-24 14:12:09,587 INFO  c.e.x.i.blobstore.BlobStoreActivator - Found blobstore-provider [file]
2020-06-24 14:12:09,607 INFO  c.e.x.i.blobstore.BlobStoreActivator - Registered blobstore [file] successfully
2020-06-24 14:12:10,579 INFO  org.elasticsearch.node - [backend-0] version[2.4.6], pid[1], build[NA/NA]
2020-06-24 14:12:10,580 INFO  org.elasticsearch.node - [backend-0] initializing ...
2020-06-24 14:12:10,583 INFO  org.elasticsearch.plugins - [backend-0] modules [], plugins [], sites []
2020-06-24 14:12:10,594 INFO  org.elasticsearch.env - [backend-0] using [1] data paths, mounts [[/enonic-xp/home/repo/index (/dev/sdc)]], net usable_space [958.6mb], net total_space [975.8mb], spins? [possibly], types [ext4]
2020-06-24 14:12:10,595 INFO  org.elasticsearch.env - [backend-0] heap size [1.9gb], compressed ordinary object pointers [true]
2020-06-24 14:12:12,337 INFO  org.elasticsearch.node - [backend-0] initialized
2020-06-24 14:12:12,337 INFO  org.elasticsearch.node - [backend-0] starting ...
2020-06-24 14:12:12,414 INFO  org.elasticsearch.transport - [backend-0] publish_address {10.244.1.2:9300}, bound_addresses {10.244.1.2:9300}
2020-06-24 14:12:12,417 INFO  org.elasticsearch.discovery - [backend-0] klp-klp-test-xp7/xUAraBIBSa-TifTHaKjnog
2020-06-24 14:12:20,001 INFO  org.elasticsearch.cluster.service - [backend-0] detected_master {master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}, added {{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true},{backend-1}{ICPWHKEYRECCd1Zw-3P7hg}{10.244.7.2}{10.244.7.2:9300}{local=false, master=false},{master-1}{3YOXOYRQSYqX_2WfkbyYWA}{10.244.8.2}{10.244.8.2:9300}{data=false, local=false, master=true},{master-0}{yfhL6_A-SFCvgTipmZCBuw}{10.244.6.2}{10.244.6.2:9300}{data=false, local=false, master=true},}, reason: zen-disco-receive(from master [{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}])
2020-06-24 14:12:20,035 INFO  org.elasticsearch.http - [backend-0] publish_address {10.244.1.2:9200}, bound_addresses {10.244.1.2:9200}
2020-06-24 14:12:20,036 INFO  org.elasticsearch.node - [backend-0] started
2020-06-24 14:12:20,094 INFO  c.e.x.c.impl.ClusterManagerImpl - Adding cluster-provider: elasticsearch
2020-06-24 14:12:20,412 INFO  c.e.x.c.impl.ClusterManagerImpl - Activating all providers
2020-06-24 14:12:20,413 INFO  c.e.x.e.impl.ElasticsearchCluster - Cluster operational, register elasticsearch-client
2020-06-24 14:12:20,484 INFO  org.eclipse.jetty.util.log - Logging initialized @15581ms to org.eclipse.jetty.util.log.Slf4jLog
2020-06-24 14:12:20,720 INFO  org.eclipse.jetty.server.Server - jetty-9.4.28.v20200408; built: 2020-04-08T17:49:39.557Z; git: ab228fde9e55e9164c738d7fa121f8ac5acd51c9; jvm 11.0.7+10
2020-06-24 14:12:20,806 INFO  org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=backend-0
2020-06-24 14:12:20,806 INFO  org.eclipse.jetty.server.session - No SessionScavenger set, using defaults
2020-06-24 14:12:20,807 INFO  org.eclipse.jetty.server.session - backend-0 Scavenging every 660000ms
2020-06-24 14:12:20,815 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@1dffa58b{/,null,AVAILABLE,@xp}
2020-06-24 14:12:20,873 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@336c6617{/,null,AVAILABLE,@api}
2020-06-24 14:12:20,873 INFO  o.e.j.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@3c310b8d{/,null,AVAILABLE,@status}
2020-06-24 14:12:20,890 INFO  o.e.jetty.server.AbstractConnector - Started xp@190c056c{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2020-06-24 14:12:20,891 INFO  o.e.jetty.server.AbstractConnector - Started api@64868aa1{HTTP/1.1, (http/1.1)}{0.0.0.0:4848}
2020-06-24 14:12:20,892 INFO  o.e.jetty.server.AbstractConnector - Started status@6c05dcec{HTTP/1.1, (http/1.1)}{0.0.0.0:2609}
2020-06-24 14:12:20,896 INFO  org.eclipse.jetty.server.Server - Started @15993ms
2020-06-24 14:12:20,903 INFO  c.e.xp.web.jetty.impl.JettyActivator - Started Jetty
2020-06-24 14:12:20,904 INFO  c.e.xp.web.jetty.impl.JettyActivator - Listening on ports [8080](xp), [4848](management) and [2609](monitoring)
2020-06-24 14:12:20,979 INFO  c.e.x.w.v.i.c.VirtualHostConfigImpl - Virtual host is enabled and mappings updated.
2020-06-24 14:12:21,016 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:22,071 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:22,870 INFO  org.elasticsearch.cluster.service - [backend-0] added {{admin-0}{T3oHAGijRquqO1hPAoeEcg}{10.244.4.2}{10.244.4.2:9300}{data=false, local=false, master=false},{frontend-0}{ozwWkPcLSwiaqcK6uBc7Vg}{10.244.5.2}{10.244.5.2:9300}{data=false, local=false, master=false},}, reason: zen-disco-receive(from master [{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}])
2020-06-24 14:12:23,402 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:24,316 INFO  org.elasticsearch.cluster.service - [backend-0] added {{backend-2}{x9JKuPhYRE2uniapEVQf7Q}{10.244.3.2}{10.244.3.2:9300}{local=false, master=false},}, reason: zen-disco-receive(from master [{master-2}{35AHy4EdRtqiLcUdKw-Mzg}{10.244.2.3}{10.244.2.3:9300}{data=false, local=false, master=true}])
2020-06-24 14:12:24,407 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:25,411 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:26,416 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo to be initialized
2020-06-24 14:12:28,008 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:29,012 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:30,017 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:31,020 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:32,023 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:33,026 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:34,030 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for System-repo [security] layout to be initialized
2020-06-24 14:12:35,201 WARN  c.e.xp.web.impl.auth.BasicAuthFilter - bundle com.enonic.xp.web.impl:7.3.0 (77)[com.enonic.xp.web.impl.auth.BasicAuthFilter(149)] : Could not get service from ref [com.enonic.xp.security.SecurityService]
2020-06-24 14:12:35,201 INFO  c.e.xp.web.impl.auth.BasicAuthFilter - bundle com.enonic.xp.web.impl:7.3.0 (77)[com.enonic.xp.web.impl.auth.BasicAuthFilter(149)] :  Could not obtain all required dependencies, getService returning null
2020-06-24 14:12:35,202 WARN  c.e.x.w.i.d.p.FilterPipelineImpl - bundle com.enonic.xp.web.dispatch:7.3.0 (74)[com.enonic.xp.web.impl.dispatch.pipeline.FilterPipelineImpl(139)] : Could not get service from ref [javax.servlet.Filter]
2020-06-24 14:12:35,202 WARN  c.e.x.w.i.d.p.FilterPipelineImpl - bundle com.enonic.xp.web.dispatch:7.3.0 (74)[com.enonic.xp.web.impl.dispatch.pipeline.FilterPipelineImpl(139)] : DependencyManager : invokeBindMethod : Service not available from service registry for ServiceReference [javax.servlet.Filter] for reference Filter
2020-06-24 14:12:35,205 ERROR E.Framework.com.enonic.xp.web.impl - FrameworkEvent ERROR
org.apache.felix.log.LogException: org.osgi.framework.ServiceException: Service factory exception: Could not obtain lock
    at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:353)
    at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:248)
    at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:350)
    at org.apache.felix.framework.Felix.getService(Felix.java:3954)
    at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:450)
    at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86)
    at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47)
    at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.prebind(DependencyManager.java:1154)
    at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1568)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1029)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:935)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:900)
    at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:348)
    at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:248)
    at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:350)
    at org.apache.felix.framework.Felix.getService(Felix.java:3954)
    at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:450)
    at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86)
    at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47)
    at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308)
    at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1805)
    at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1788)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:435)
    at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:325)
    at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:294)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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.framework.BundleContextImpl.registerService(BundleContextImpl.java:335)
    at com.enonic.xp.elasticsearch.impl.ElasticsearchCluster.registerClient(ElasticsearchCluster.java:158)
    at com.enonic.xp.elasticsearch.impl.ElasticsearchCluster.enable(ElasticsearchCluster.java:141)
    at java.base/java.lang.Iterable.forEach(Unknown Source)
    at com.enonic.xp.cluster.impl.ClusterManagerImpl.activateProviders(ClusterManagerImpl.java:91)
    at com.enonic.xp.cluster.impl.ClusterManagerImpl.checkProviders(ClusterManagerImpl.java:111)
    at com.enonic.xp.core.internal.concurrent.SimpleRecurringJobScheduler$WrappedRunnable.run(SimpleRecurringJobScheduler.java:77)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.base/java.lang.Thread.run(Unknown Source)
Caused by: java.lang.IllegalStateException: Could not obtain lock
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.obtainLock(AbstractComponentManager.java:240)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.obtainStateLock(AbstractComponentManager.java:287)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:948)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:900)
    at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:348)
    ... 185 common frames omitted
2020-06-24 14:12:35,206 ERROR E.F.com.enonic.xp.web.dispatch - FrameworkEvent ERROR
org.apache.felix.log.LogException: org.osgi.framework.ServiceException: Service factory returned null. (Component: com.enonic.xp.web.impl.auth.BasicAuthFilter (149))
    at org.apache.felix.framework.ServiceRegistrationImpl.getFactoryUnchecked(ServiceRegistrationImpl.java:381)
    at org.apache.felix.framework.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:248)
    at org.apache.felix.framework.ServiceRegistry.getService(ServiceRegistry.java:350)
    at org.apache.felix.framework.Felix.getService(Felix.java:3954)
    at org.apache.felix.framework.BundleContextImpl.getService(BundleContextImpl.java:450)
    at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:86)
    at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47)
    at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:664)
    at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2308)
    at org.apache.felix.scr.impl.manager.DependencyManager.doInvokeBindMethod(DependencyManager.java:1805)
    at org.apache.felix.scr.impl.manager.DependencyManager.invokeBindMethod(DependencyManager.java:1788)
    at org.apache.felix.scr.impl.manager.SingleComponentManager.invokeBindMethod(SingleComponentManager.java:435)
    at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:325)
    at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.addedService(DependencyManager.java:294)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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:906)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:892)
    at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:959)
    at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:732)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1045)
    at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:999)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944)
    at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880)
    at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168)
    at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125)
    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.framework.BundleContextImpl.registerService(BundleContextImpl.java:335)
    at com.enonic.xp.elasticsearch.impl.ElasticsearchCluster.registerClient(ElasticsearchCluster.java:158)
    at com.enonic.xp.elasticsearch.impl.ElasticsearchCluster.enable(ElasticsearchCluster.java:141)
    at java.base/java.lang.Iterable.forEach(Unknown Source)
    at com.enonic.xp.cluster.impl.ClusterManagerImpl.activateProviders(ClusterManagerImpl.java:91)
    at com.enonic.xp.cluster.impl.ClusterManagerImpl.checkProviders(ClusterManagerImpl.java:111)
    at com.enonic.xp.core.internal.concurrent.SimpleRecurringJobScheduler$WrappedRunnable.run(SimpleRecurringJobScheduler.java:77)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
    at java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source)
    at java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
    at java.base/java.lang.Thread.run(Unknown Source)
2020-06-24 14:12:35,235 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:35,608 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.system bundle 87
2020-06-24 14:12:35,674 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.applications bundle 89
2020-06-24 14:12:35,678 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.main bundle 90
2020-06-24 14:12:35,688 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.standardidprovider bundle 91
2020-06-24 14:12:35,697 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering configured application com.enonic.xp.app.users bundle 92
2020-06-24 14:12:35,697 INFO  c.e.x.l.i.framework.FrameworkService - Started Enonic XP in 30184 ms
2020-06-24 14:12:35,697 INFO  E.F.org.apache.felix.framework - FrameworkEvent STARTLEVEL CHANGED
2020-06-24 14:12:36,239 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for system.auditlog repo to be initialized
2020-06-24 14:12:37,368 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo to be initialized
2020-06-24 14:12:38,457 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo to be initialized
2020-06-24 14:12:39,733 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo [issue] layout to be initialized
2020-06-24 14:12:40,736 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo [issue] layout to be initialized
2020-06-24 14:12:41,738 INFO  com.enonic.xp.init.Initializer - Waiting [1s] for com.enonic.cms.default repo [issue] layout to be initialized
2020-06-24 14:12:43,994 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Searching for installed applications
2020-06-24 14:12:44,064 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Found [0] installed applications
2020-06-24 14:12:44,107 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:44,108 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:44,108 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Local application [com.enonic.app.snapshotter] installed successfully
2020-06-24 14:12:44,173 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - All notifiers configured, starting schedules
2020-06-24 14:12:44,212 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - Scheduler already started
2020-06-24 14:12:44,273 INFO  c.e.a.snapshotter.SnapshotRunnerImpl - Scheduler already started
2020-06-24 14:12:44,275 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Configuring application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:44,275 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Started application com.enonic.app.snapshotter bundle 93
2020-06-24 14:12:44,275 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Application [com.enonic.app.snapshotter] started successfully
2020-06-24 14:12:44,291 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Installed application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,292 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Registering application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,292 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Local application [com.enonic.app.alive] installed successfully
2020-06-24 14:12:44,294 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Started application com.enonic.app.alive bundle 94
2020-06-24 14:12:44,294 INFO  c.e.x.c.i.app.ApplicationServiceImpl - Application [com.enonic.app.alive] started successfully
2020-06-24 14:12:44,871 INFO  c.e.x.c.i.a.ApplicationRegistryImpl - Configuring application com.enonic.app.alive bundle 94
rymsha commented 4 years ago

Initialazers are pure classes that get executed in OSGi activate methods of components that need them "most".

The drawback of this approach is when other components require services provided and initialization takes long Felix (OSGi framework) times out.

One way to fix is to increase timeout ds.lock.timeout.milliseconds, but it is not very robust solution

We may need to extract initialization in own components and specify immediate on them, and use CompletableFuture

rymsha commented 4 years ago

ApplicationResource -> ApplicationService -> ApplicationRepoService -> NodeService -> RepositoryService -> SystemRepoInitializer in Activate

FilterPipelineImpl -> Filter (BasicAuthFilter) -> BasicAuthFilter -> SecurityService -> SecurityInitializer in Activate