Some times, EMS server on app cluster fails to start (see the logs below). If the EMS server is restarted (deleting the pod and waiting for K8s to recreate it), the server works OK.
Event Management System (ems), v.7.0.0-SNAPSHOT, Mozilla Public License, v2.0
Copyright (C) 2017-2025 Institute of Communication and Computer Systems (imu.iccs.gr)
2024-07-02T12:25:00.288Z INFO 30 --- [ main] o.s.boot.SpringApplication :
███████╗███╗ ███╗███████╗ ██████╗ ██████╗ ███╗ ██╗████████╗██████╗ ██████╗ ██╗
██╔════╝████╗ ████║██╔════╝ ██╔════╝██╔═══██╗████╗ ██║╚══██╔══╝██╔══██╗██╔═══██╗██║
█████╗ ██╔████╔██║███████╗ ██║ ██║ ██║██╔██╗ ██║ ██║ ██████╔╝██║ ██║██║
██╔══╝ ██║╚██╔╝██║╚════██║ ██║ ██║ ██║██║╚██╗██║ ██║ ██╔══██╗██║ ██║██║
███████╗██║ ╚═╝ ██║███████║ ╚██████╗╚██████╔╝██║ ╚████║ ██║ ██║ ██║╚██████╔╝███████╗
╚══════╝╚═╝ ╚═╝╚══════╝ ╚═════╝ ╚═════╝ ╚═╝ ╚═══╝ ╚═╝ ╚═╝ ╚═╝ ╚═════╝ ╚══════╝
:: EMS Control :: (7.0.0-SNAPSHOT)
:: Spring Boot :: (v3.2.5)
:: Java (TM) :: (21.0.3)
:: Build Num. :: 19964270a68b719d4d512297d1e6252757c88163
:: Build Date :: 2024-07-02 12:28:19.031+0300
:: SCM Branch :: master, at Repos.: https://gitlab.com/nebulous-project/ems-main.git
:: Image Tag :: ems-server:2024-jul
:: Description :: ***** Preparing EMS for NebulOus *****
========== EMS Nebulous Docker Image details ==========
:: Build Num. :: cbabe7f5357d8eb5075e3543f4b7d954136069ac
:: Build Date :: 2024-07-02 12:29:37.539+0300
:: SCM Branch :: master, at Repos.: https://gitlab.com/nebulous-project/ems-nebulous.git
:: Image Tag :: ems-server:2024-jul-nebulous
:: Description :: EMS Nebulous Docker Image is based on the EMS Core Docker Image
2024-07-02T12:25:00.395Z INFO 30 --- [ main] g.i.imu.ems.util.NetUtilPostProcessor : NetUtilPostProcessor: NetUtilPropertySource registered (deferred log)
2024-07-02T12:25:00.402Z INFO 30 --- [ main] g.i.i.e.c.ControlServiceApplication : Starting ControlServiceApplication using Java 21.0.3 with PID 30 (/opt/ems-server/BOOT-INF/classes started by emsuser in /opt/ems-server)
2024-07-02T12:25:00.403Z INFO 30 --- [ main] g.i.i.e.c.ControlServiceApplication : No active profile set, falling back to 1 default profile: "default"
2024-07-02T12:25:02.448Z INFO 30 --- [ main] faultConfiguringBeanFactoryPostProcessor : No bean named 'errorChannel' has been explicitly defined. Therefore, a default PublishSubscribeChannel will be created.
2024-07-02T12:25:02.457Z INFO 30 --- [ main] faultConfiguringBeanFactoryPostProcessor : No bean named 'integrationHeaderChannelRegistry' has been explicitly defined. Therefore, a default DefaultHeaderChannelRegistry will be created.
2024-07-02T12:25:03.067Z WARN 30 --- [ main] gr.iccs.imu.ems.util.NetUtil : NetUtil.getPublicIpAddress(): No Public IP address or connectivity problems exist
2024-07-02T12:25:03.221Z INFO 30 --- [ main] gr.iccs.imu.ems.util.PasswordUtil : PasswordUtil: Initialized default Password Encoder: gr.iccs.imu.ems.util.password.AsterisksPasswordEncoder
2024-07-02T12:25:04.825Z INFO 30 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat initialized with port 8111 (https)
2024-07-02T12:25:04.846Z INFO 30 --- [ main] o.apache.catalina.core.StandardService : Starting service [Tomcat]
2024-07-02T12:25:04.846Z INFO 30 --- [ main] o.apache.catalina.core.StandardEngine : Starting Servlet engine: [Apache Tomcat/10.1.20]
2024-07-02T12:25:04.909Z INFO 30 --- [ main] o.a.c.c.C.[Tomcat].[localhost].[/] : Initializing Spring embedded WebApplicationContext
2024-07-02T12:25:04.910Z INFO 30 --- [ main] w.s.c.ServletWebServerApplicationContext : Root WebApplicationContext: initialization completed in 4123 ms
2024-07-02T12:25:05.440Z INFO 30 --- [ main] g.i.i.e.b.c.s.SelfHealingManagerImpl : Self-Healing Manager initialized
2024-07-02T12:25:05.441Z INFO 30 --- [ main] g.i.i.e.b.c.s.SelfHealingManagerImpl : Recovery context: RecoveryContext(variablesMap={BAGUETTE_CLIENT_BASE_DIR=~/baguette-client})
2024-07-02T12:25:05.545Z INFO 30 --- [ main] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer: Generated new username/password: username=user-a4a7bc4c-90e0-4012-a888-992f1dac7bdf, password=********
2024-07-02T12:25:05.951Z INFO 30 --- [ main] eu.nebulous.ems.EmsNebulousProperties : EmsNebulousProperties(applicationId=1414020207rest-processor-app1719922442226, appId=null, appUid=null, appUuid=null, emsServerPodUid=b778883e-6756-4b6e-ba4b-ae2f6b297670, emsServerPodNamespace=default, appPodLabel=app)
2024-07-02T12:25:05.955Z INFO 30 --- [ main] sEmsClientDeploymentPostProcessingPlugin : K8sEmsClientDeploymentPostProcessingPlugin: Application Id (from Env.): 1414020207rest-processor-app1719922442226
2024-07-02T12:25:06.578Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Loaded the Bouncy Castle security provider at position: -1
2024-07-02T12:25:06.751Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Using Persistence Adapter: MemoryPersistenceAdapter
2024-07-02T12:25:06.751Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Starting Persistence Adapter: MemoryPersistenceAdapter
2024-07-02T12:25:06.751Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Starting Temp Data Store
2024-07-02T12:25:06.751Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Starting Job Scheduler Store
2024-07-02T12:25:06.751Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Persistence Adapter successfully started
2024-07-02T12:25:06.899Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Apache ActiveMQ 6.0.1 (broker, ID:ems-ems-server-6864dbd89-szj7k-36753-1719923106764-0:1) is starting
2024-07-02T12:25:06.908Z INFO 30 --- [ main] o.a.a.t.TransportServerThreadSupport : Listening for connections at: ssl://ems-ems-server-6864dbd89-szj7k:61617?transport.daemon=true&transport.trace=false&transport.useKeepAlive=true&transport.useInactivityMonitor=false&transport.needClientAuth=false&transport.verifyHostName=true&transport.connectionTimeout=0&transport.keepAlive=true
2024-07-02T12:25:06.909Z INFO 30 --- [ main] o.a.activemq.broker.TransportConnector : Connector ssl://ems-ems-server-6864dbd89-szj7k:61617?transport.daemon=true&transport.trace=false&transport.useKeepAlive=true&transport.useInactivityMonitor=false&transport.needClientAuth=false&transport.verifyHostName=true&transport.connectionTimeout=0&transport.keepAlive=true started
2024-07-02T12:25:06.910Z INFO 30 --- [ main] o.a.a.t.TransportServerThreadSupport : Listening for connections at: tcp://ems-ems-server-6864dbd89-szj7k:61616?transport.daemon=true&transport.trace=false&transport.useKeepAlive=true&transport.useInactivityMonitor=false&transport.needClientAuth=false&transport.verifyHostName=true&transport.connectionTimeout=0&transport.keepAlive=true
2024-07-02T12:25:06.910Z INFO 30 --- [ main] o.a.activemq.broker.TransportConnector : Connector tcp://ems-ems-server-6864dbd89-szj7k:61616?transport.daemon=true&transport.trace=false&transport.useKeepAlive=true&transport.useInactivityMonitor=false&transport.needClientAuth=false&transport.verifyHostName=true&transport.connectionTimeout=0&transport.keepAlive=true started
2024-07-02T12:25:06.911Z INFO 30 --- [ main] o.a.a.t.TransportServerThreadSupport : Listening for connections at: stomp://ems-ems-server-6864dbd89-szj7k:61610
2024-07-02T12:25:06.912Z INFO 30 --- [ main] o.a.activemq.broker.TransportConnector : Connector stomp://ems-ems-server-6864dbd89-szj7k:61610 started
2024-07-02T12:25:06.912Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : Apache ActiveMQ 6.0.1 (broker, ID:ems-ems-server-6864dbd89-szj7k-36753-1719923106764-0:1) started
2024-07-02T12:25:06.912Z INFO 30 --- [ main] o.apache.activemq.broker.BrokerService : For help or more information please see: http://activemq.apache.org
2024-07-02T12:25:06.933Z INFO 30 --- [ Thread-5] .i.i.e.b.b.i.MessageForwarderInterceptor : MessageQueueProcessor: Starts processing message queue and forward messages
2024-07-02T12:25:07.068Z INFO 30 --- [ main] c.e.e.c.service.EPServiceProviderImpl : Initializing engine URI 'default' version 7.1.0
2024-07-02T12:25:07.488Z INFO 30 --- [ main] e.n.ems.translate.NebulousEmsTranslator : NebulousEmsTranslator: initialized
2024-07-02T12:25:07.537Z INFO 30 --- [ main] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.initTranslator(): Effective translator: eu.nebulous.ems.translate.NebulousEmsTranslator
2024-07-02T12:25:07.537Z INFO 30 --- [ main] eu.nebulous.ems.service.MvvService : MvvService: initialized
2024-07-02T12:25:07.538Z INFO 30 --- [ main] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer.startServer(): Starting SSH server...
2024-07-02T12:25:07.539Z INFO 30 --- [ main] gr.iccs.imu.ems.baguette.server.Sshd : ** SSH server **
2024-07-02T12:25:07.540Z INFO 30 --- [ main] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Public IP address: 10.0.0.66
2024-07-02T12:25:07.540Z INFO 30 --- [ main] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Starting on port: 2222
2024-07-02T12:25:07.540Z INFO 30 --- [ main] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Server key file: /opt/ems-server/config/hostkey.pem
2024-07-02T12:25:07.597Z INFO 30 --- [ main] s.c.u.s.e.EdDSASecurityProviderRegistrar : getOrCreateProvider(EdDSA) created instance of net.i2p.crypto.eddsa.EdDSASecurityProvider
2024-07-02T12:25:07.719Z INFO 30 --- [ main] o.a.s.s.k.SimpleGeneratorHostKeyProvider : generateKeyPair(EC) generating host key=nistp521
2024-07-02T12:25:07.865Z INFO 30 --- [ main] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Ready
2024-07-02T12:25:07.867Z INFO 30 --- [ Thread-6] gr.iccs.imu.ems.baguette.server.Sshd : --> Heartbeat: Started: period=60000ms
2024-07-02T12:25:07.867Z INFO 30 --- [ main] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer.startServer(): Starting SSH server... done
2024-07-02T12:25:07.915Z INFO 30 --- [ main] g.iccs.imu.ems.control.util.TopicBeacon : Topic Beacon started: init-delay=60000ms, delay=60000ms
2024-07-02T12:25:07.920Z INFO 30 --- [ main] g.i.imu.ems.common.plugin.PluginManager : PluginManager: Started
2024-07-02T12:25:08.089Z INFO 30 --- [ main] g.iccs.imu.ems.brokercep.EventForwarder : EventForwarder: Starting event publish/forward worker
2024-07-02T12:25:08.163Z INFO 30 --- [ main] g.i.i.e.c.misc.SystemResourceMonitor : SystemResourceMonitor started
2024-07-02T12:25:08.249Z INFO 30 --- [ main] g.i.i.e.c.c.AbstractEndpointCollector : Collectors::ServerPrometheusCollector: New Allowed Topics: null -- Topics Map: null
2024-07-02T12:25:08.339Z INFO 30 --- [ main] .c.i.ControlServiceInfoEndpointExtension : Info endpoint is enabled and exposed. Added EMS info extension.
2024-07-02T12:25:08.347Z INFO 30 --- [ main] g.i.i.e.c.c.AbstractEndpointCollector : Collectors::ServerNetdataCollector: New Allowed Topics: null -- Topics Map: null
2024-07-02T12:25:08.405Z INFO 30 --- [ main] eu.nebulous.ems.k8s.K8sPodWatcher : K8sPodWatcher: Enabled (running every PT1Msec, init-delay=PT30S)
2024-07-02T12:25:08.412Z INFO 30 --- [ main] eu.nebulous.ems.boot.EmsBootProperties : EmsBootProperties(enabled=false, processorPeriod=500, applicationIdPropertyName=application, modelsDir=models, modelsIndexFile=models/index.json, dslTopic=eu.nebulouscloud.ui.dsl.generic, optimiserMetricsTopic=eu.nebulouscloud.optimiser.controller.metric_list, modelsTopic=eu.nebulouscloud.ui.dsl.metric_model, modelsResponseTopic=eu.nebulouscloud.ui.dsl.metric_model.reply, emsBootTopic=eu.nebulouscloud.ems.boot, emsBootResponseTopic=eu.nebulouscloud.ems.boot.reply, validateModels=true, storeInvalidModels=true, reportInvalidModels=true)
2024-07-02T12:25:08.421Z INFO 30 --- [ main] eu.nebulous.ems.boot.ModelsService : ModelsService is disabled because EMS Boot is disabled
2024-07-02T12:25:08.423Z INFO 30 --- [ main] e.n.ems.boot.NebulousEventsService : EMS Boot is disabled
2024-07-02T12:25:08.426Z INFO 30 --- [ main] e.n.e.s.EmsBootInitializerProperties : EmsBootInitializerProperties(enabled=true, initialWait=PT1S, retryPeriod=PT30S)
2024-07-02T12:25:08.434Z INFO 30 --- [ main] e.n.e.s.ExternalBrokerListenerService : ExternalBrokerListenerService: Application Id: 1414020207rest-processor-app1719922442226
2024-07-02T12:25:08.753Z INFO 30 --- [ main] e.n.e.s.ExternalBrokerListenerService : ExternalBrokerListenerService: created subscribers
2024-07-02T12:25:08.755Z INFO 30 --- [ main] e.n.e.s.ExternalBrokerListenerService : ExternalBrokerListenerService: created publishers
2024-07-02T12:25:08.827Z INFO 30 --- [ main] eu.nebulouscloud.exn.Connector : Starting connector...
2024-07-02T12:25:08.948Z INFO 30 --- [ main] eu.nebulouscloud.exn.core.Context : Registering 2 consumers
2024-07-02T12:25:09.623Z INFO 30 --- [:1): I/O Thread] o.a.q.p.client.impl.ClientConnection : Connection ID:1c4eb146-80b5-4506-bce6-5932f4b56129:1:1 connected to server: 158.37.63.86:32754
2024-07-02T12:25:09.893Z INFO 30 --- [pool-6-thread-2] eu.nebulouscloud.exn.core.Manager : Linking consumer topic://eu.nebulouscloud.monitoring.commands
2024-07-02T12:25:10.135Z INFO 30 --- [pool-6-thread-3] eu.nebulouscloud.exn.core.Manager : Linking consumer topic://eu.nebulouscloud.optimiser.solver.solution
2024-07-02T12:25:10.137Z INFO 30 --- [pool-6-thread-3] eu.nebulouscloud.exn.core.Manager : for application 1414020207rest-processor-app1719922442226
2024-07-02T12:25:10.137Z INFO 30 --- [ main] eu.nebulouscloud.exn.core.Context : Registering 1 publishers
2024-07-02T12:25:10.146Z INFO 30 --- [ main] e.n.e.s.AbstractExternalBrokerService : AbstractExternalBrokerService: Connected to broker
2024-07-02T12:25:10.147Z INFO 30 --- [ main] e.n.e.s.ExternalBrokerListenerService : ExternalBrokerListenerService: Initialized listeners and publishers
2024-07-02T12:25:10.153Z INFO 30 --- [ main] e.n.ems.translate.analyze.AnalysisUtils : AnalysisUtils: useCompositeNames: false
2024-07-02T12:25:10.909Z INFO 30 --- [ main] o.s.b.a.e.web.EndpointLinksResolver : Exposing 2 endpoint(s) beneath base path '/actuator'
2024-07-02T12:25:10.999Z INFO 30 --- [ main] o.s.s.web.DefaultSecurityFilterChain : Will secure any request with [org.springframework.security.web.session.DisableEncodeUrlFilter@72cbe3b6, org.springframework.security.web.session.ForceEagerSessionCreationFilter@7aadb5e8, org.springframework.security.web.context.request.async.WebAsyncManagerIntegrationFilter@6f8060ac, org.springframework.security.web.context.SecurityContextHolderFilter@519f6adb, org.springframework.security.web.header.HeaderWriterFilter@3f2731e5, org.springframework.web.filter.CorsFilter@308a2eb0, org.springframework.security.web.authentication.logout.LogoutFilter@d6de944, org.springframework.security.web.authentication.UsernamePasswordAuthenticationFilter@23591a2c, gr.iccs.imu.ems.control.webconf.WebSecurityConfig$$Lambda/0x00007e333cba4f58@1df1bd44, gr.iccs.imu.ems.control.webconf.WebSecurityConfig$$Lambda/0x00007e333cba5198@ae449e7, gr.iccs.imu.ems.control.webconf.WebSecurityConfig$$Lambda/0x00007e333cba53d8@660dcd17, gr.iccs.imu.ems.control.webconf.WebSecurityConfig$$Lambda/0x00007e333cba5618@71390c8, org.springframework.security.web.savedrequest.RequestCacheAwareFilter@22938166, org.springframework.security.web.servletapi.SecurityContextHolderAwareRequestFilter@72bb3f3e, org.springframework.security.web.authentication.AnonymousAuthenticationFilter@179806f3, org.springframework.security.web.session.SessionManagementFilter@6a636c62, org.springframework.security.web.access.ExceptionTranslationFilter@73c71083, org.springframework.security.web.access.intercept.AuthorizationFilter@6eef7af3]
2024-07-02T12:25:11.166Z WARN 30 --- [ main] ion$DefaultTemplateResolverConfiguration : Cannot find template location: classpath:/templates/ (please add some templates, check your Thymeleaf configuration, or set spring.thymeleaf.check-template-location=false)
2024-07-02T12:25:11.387Z WARN 30 --- [ main] .b.a.g.t.GroovyTemplateAutoConfiguration : Cannot find template location: classpath:/templates/ (please add some templates, check your Groovy configuration, or set spring.groovy.template.check-template-location=false)
2024-07-02T12:25:11.744Z INFO 30 --- [ main] o.s.i.endpoint.EventDrivenConsumer : Adding {logging-channel-adapter:_org.springframework.integration.errorLogger} as a subscriber to the 'errorChannel' channel
2024-07-02T12:25:11.745Z INFO 30 --- [ main] o.s.i.channel.PublishSubscribeChannel : Channel 'application.errorChannel' has 1 subscriber(s).
2024-07-02T12:25:11.746Z INFO 30 --- [ main] o.s.i.endpoint.EventDrivenConsumer : started bean '_org.springframework.integration.errorLogger'
2024-07-02T12:25:11.811Z INFO 30 --- [ main] o.a.t.util.net.NioEndpoint.certificate : Connector [https-jsse-nio-8111], TLS virtual host [_default_], certificate type [UNDEFINED] configured from keystore [/opt/ems-server/.keystore] using alias [ems] with trust store [null]
2024-07-02T12:25:11.816Z INFO 30 --- [ main] o.s.b.w.embedded.tomcat.TomcatWebServer : Tomcat started on port 8111 (https) with context path ''
2024-07-02T12:25:11.819Z INFO 30 --- [ main] i.i.e.b.c.i.h.AbstractInstallationHelper : Server PEM certificate stored in file: /opt/ems-server/config/server.pem
2024-07-02T12:25:11.820Z INFO 30 --- [ main] i.i.e.b.c.i.h.AbstractInstallationHelper : Server PEM certificate stored in file: /opt/ems-server/config/server.pem
2024-07-02T12:25:11.840Z INFO 30 --- [ main] g.i.i.e.c.ControlServiceApplication : Started ControlServiceApplication in 12.087 seconds (process running for 12.888)
2024-07-02T12:25:11.849Z INFO 30 --- [ main] e.n.ems.service.EmsBootInitializer : ===================> EMS is ready -- Scheduling EMS Boot message -- App Id: 1414020207rest-processor-app1719922442226
2024-07-02T12:25:11.853Z INFO 30 --- [ main] eu.nebulouscloud.exn.Connector : Starting connector...
2024-07-02T12:25:11.854Z INFO 30 --- [ main] eu.nebulouscloud.exn.core.Context : Registering 1 consumers
2024-07-02T12:25:12.378Z INFO 30 --- [:1): I/O Thread] o.a.q.p.client.impl.ClientConnection : Connection ID:6ea3b7a7-06e2-4875-97f2-13043ad5e2d9:2:1 connected to server: 158.37.63.86:32754
2024-07-02T12:25:12.632Z INFO 30 --- [pool-8-thread-2] eu.nebulouscloud.exn.core.Manager : Linking consumer topic://eu.nebulouscloud.ems.boot.reply
2024-07-02T12:25:12.632Z INFO 30 --- [pool-8-thread-2] eu.nebulouscloud.exn.core.Manager : for application 1414020207rest-processor-app1719922442226
2024-07-02T12:25:12.632Z INFO 30 --- [ main] eu.nebulouscloud.exn.core.Context : Registering 1 publishers
2024-07-02T12:25:12.634Z INFO 30 --- [ main] e.n.e.s.AbstractExternalBrokerService : AbstractExternalBrokerService: Connected to broker
2024-07-02T12:25:12.636Z INFO 30 --- [ main] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.applicationReady(): IP setting: DEFAULT_IP
2024-07-02T12:25:12.636Z INFO 30 --- [ main] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.preloadModels(): No model to preload
2024-07-02T12:25:12.637Z INFO 30 --- [ main] g.i.i.e.c.ControlServiceApplication : EMS server initialized in 12990ms
2024-07-02T12:25:13.910Z INFO 30 --- [pool-8-thread-2] e.n.ems.service.EmsBootInitializer : EmsBootInitializer: Received an EMS Boot Response:
App-Id: 1414020207rest-processor-app1719922442226
Bindings: {}
Opt. Metrics: [AccumulatedSecondsPendingRequests]
Model: {"apiVersion":"nebulous/v1","kind":"MetricModel","metadata":{"name":"1414020207rest-processor-app1719922442226","labels":{"app":"1414020207rest-processor-app1719922442226"}},"templates":[],"spec":{"components":[{"name":"spec-comp","metrics":[]}],"scopes":[{"name":"app-wide-scope","components":[],"metrics":[{"name":"RawMaxMessageAge","type":"raw","sensor":{"type":"-","config":{}},"output":"all 15 sec"},{"name":"NumWorkers","type":"raw","sensor":{"type":"-","config":{}},"output":"all 15 sec"},{"name":"NumPendingRequests","type":"raw","sensor":{"type":"-","config":{}},"output":"all 15 sec"},{"name":"AccumulatedSecondsPendingRequests","type":"raw","sensor":{"type":"-","config":{}},"output":"all 15 sec"},{"name":"MeanMaxMessageAge","type":"composite","template":"","formula":"mean(RawMaxMessageAge)","window":{"type":"sliding","size":"30 sec"},"output":"last 30 sec"},{"name":"PendingRequestsMinusWorkers","type":"composite","template":"","formula":"NumPendingRequests-NumWorkers","window":{"type":"sliding","size":"30 sec"},"output":"last 30 sec"},{"name":"currentcpu","type":"raw","sensor":{"type":"netdata k8s.cgroup.cpu","config":{}},"output":"all 10 sec"}],"requirements":[{"name":"MaxMessageAge_SLO","type":"slo","constraint":"(MeanMaxMessageAge > 50)"},{"name":"UnusedResources_SLO","type":"slo","constraint":"(PendingRequestsMinusWorkers < 0)"},{"name":"CPU_SLO","type":"slo","constraint":"(currentcpu > -100000)"}]}]}}
2024-07-02T12:25:13.912Z INFO 30 --- [pool-8-thread-2] e.n.ems.service.EmsBootInitializer : ExternalBrokerListenerService: Stored metric model in file: models/1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:13.915Z INFO 30 --- [pool-8-thread-2] e.n.ems.service.EmsBootInitializer : Set MVV bindings to: {}
2024-07-02T12:25:13.916Z INFO 30 --- [pool-8-thread-2] e.n.ems.service.EmsBootInitializer : Set optimiser metrics to: [AccumulatedSecondsPendingRequests]
2024-07-02T12:25:13.917Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): BEGIN: app-model-id=1414020207rest-processor-app1719922442226.yml, app-exec-model-id=null, request-info=ControlServiceRequestInfo(notificationUri=null, requestUuid=null, applicationId=1414020207rest-processor-app1719922442226, callback=eu.nebulous.ems.service.EmsBootInitializer$$Lambda/0x00007e333cc6efa8@23d691ef)
2024-07-02T12:25:13.917Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.translateAppModelAndStore(): Model translation: model-id=1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:13.917Z INFO 30 --- [ taskExecutor-1] e.n.ems.translate.NebulousEmsTranslator : NebulousEmsTranslator: Parsing metric model file: 1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:13.923Z INFO 30 --- [ taskExecutor-1] e.n.ems.translate.NebulousEmsTranslator : NebulousEmsTranslator: Translating metric model: 1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:14.492Z INFO 30 --- [ taskExecutor-1] e.n.e.t.analyze.MetricModelValidator : MetricModelValidator: Metric model is valid: 1414020207rest-processor-app1719922442226
2024-07-02T12:25:15.039Z INFO 30 --- [ taskExecutor-1] e.n.ems.translate.NebulousEmsTranslator : NebulousEmsTranslator: Translating metric model completed: 1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:15.040Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.translateAppModelAndStore(): Running 4 post-translation plugins
2024-07-02T12:25:15.049Z INFO 30 --- [ taskExecutor-1] eu.nebulouscloud.exn.Connector : Starting connector...
2024-07-02T12:25:15.050Z INFO 30 --- [ taskExecutor-1] eu.nebulouscloud.exn.core.Context : Registering 0 consumers
2024-07-02T12:25:15.051Z INFO 30 --- [ taskExecutor-1] eu.nebulouscloud.exn.core.Context : Registering 15 publishers
2024-07-02T12:25:15.055Z INFO 30 --- [ taskExecutor-1] e.n.e.s.AbstractExternalBrokerService : AbstractExternalBrokerService: Connected to broker
2024-07-02T12:25:15.055Z INFO 30 --- [ taskExecutor-1] e.n.e.s.ExternalBrokerPublisherService : ExternalBrokerPublisherService: initialized publishers
2024-07-02T12:25:15.088Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.translateAppModelAndStore(): Saved translation data in file: /opt/ems-server/logs/_TC.json
2024-07-02T12:25:15.088Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): Running 1 TranslationContext plugins
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : **** T R A N S L A T I O N R E S U L T S ****
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Model Name: 1414020207rest-processor-app1719922442226
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Event-to-Action map:
{}
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : SLO set:
[UnusedResources_SLO, MaxMessageAge_SLO, CPU_SLO]
2024-07-02T12:25:15.091Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.092Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Component-to-Sensor map:
{null::null=[PullSensor::NumWorkers_SENSOR, PullSensor::RawMaxMessageAge_SENSOR, PullSensor::AccumulatedSecondsPendingRequests_SENSOR, PullSensor::NumPendingRequests_SENSOR, PullSensor::currentcpu_SENSOR]}
2024-07-02T12:25:15.092Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.092Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Data-to-Sensor map:
{}
2024-07-02T12:25:15.092Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.092Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Monitors:
[NumPendingRequests_SENSOR, RawMaxMessageAge_SENSOR, currentcpu_SENSOR, AccumulatedSecondsPendingRequests_SENSOR, NumWorkers_SENSOR]
2024-07-02T12:25:15.092Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.094Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Grouping-to-EPL Rules map:
-----------------------
PER_INSTANCE:
AccumulatedSecondsPendingRequests:
- /* RAW-CTX-PER_INSTANCE */ /*INSERT INTO AccumulatedSecondsPendingRequests*/
SELECT * FROM AccumulatedSecondsPendingRequests_SENSOR OUTPUT ALL EVERY 15 SECONDS
NumPendingRequests:
- /* RAW-CTX-PER_INSTANCE */ /*INSERT INTO NumPendingRequests*/
SELECT * FROM NumPendingRequests_SENSOR OUTPUT ALL EVERY 15 SECONDS
NumWorkers:
- /* RAW-CTX-PER_INSTANCE */ /*INSERT INTO NumWorkers*/
SELECT * FROM NumWorkers_SENSOR OUTPUT ALL EVERY 15 SECONDS
RawMaxMessageAge:
- /* RAW-CTX-PER_INSTANCE */ /*INSERT INTO RawMaxMessageAge*/
SELECT * FROM RawMaxMessageAge_SENSOR OUTPUT ALL EVERY 15 SECONDS
currentcpu:
- /* RAW-CTX-PER_INSTANCE */ /*INSERT INTO currentcpu*/
SELECT * FROM currentcpu_SENSOR OUTPUT ALL EVERY 10 SECONDS
-----------------------
GLOBAL:
CPU_SLO:
- /* SLO-any */ /*INSERT INTO CPU_SLO*/
SELECT * FROM CPU_SLO_CONSTRAINT
CPU_SLO_CONSTRAINT:
- /* CONSTR-MET-any */ /*INSERT INTO CPU_SLO_CONSTRAINT*/
SELECT * FROM currentcpu HAVING currentcpu.metricValue > -100000.0
MaxMessageAge_SLO:
- /* SLO-any */ /*INSERT INTO MaxMessageAge_SLO*/
SELECT * FROM MaxMessageAge_SLO_CONSTRAINT
MaxMessageAge_SLO_CONSTRAINT:
- /* CONSTR-MET-any */ /*INSERT INTO MaxMessageAge_SLO_CONSTRAINT*/
SELECT * FROM MeanMaxMessageAge HAVING MeanMaxMessageAge.metricValue > 50.0
MeanMaxMessageAge:
- /* COMP-CTX-AGG-any */ /*INSERT INTO MeanMaxMessageAge*/
SELECT EVALAGG( 'mean(RawMaxMessageAge)', 'RawMaxMessageAge', RawMaxMessageAge ) AS metricValue,
3 AS level,
current_timestamp AS timestamp
FROM RawMaxMessageAge.win:time(30 SECONDS) AS RawMaxMessageAge
OUTPUT SNAPSHOT EVERY 30 SECONDS
PendingRequestsMinusWorkers:
- /* COMP-CTX-any */ /*INSERT INTO PendingRequestsMinusWorkers*/
SELECT EVAL( 'NumPendingRequests-NumWorkers', 'NumPendingRequests,NumWorkers', NumPendingRequests, NumWorkers ) AS metricValue,
3 AS level,
current_timestamp AS timestamp
FROM NumPendingRequests.win:time(30 SECONDS) AS NumPendingRequests, NumWorkers.win:time(30 SECONDS) AS NumWorkers
OUTPUT LAST EVERY 30 SECONDS
UnusedResources_SLO:
- /* SLO-any */ /*INSERT INTO UnusedResources_SLO*/
SELECT * FROM UnusedResources_SLO_CONSTRAINT
UnusedResources_SLO_CONSTRAINT:
- /* CONSTR-MET-any */ /*INSERT INTO UnusedResources_SLO_CONSTRAINT*/
SELECT * FROM PendingRequestsMinusWorkers HAVING PendingRequestsMinusWorkers.metricValue < 0.0
2024-07-02T12:25:15.095Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.095Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Grouping-to-Topics map:
PER_INSTANCE:
- NumPendingRequests
- NumWorkers
- currentcpu
- RawMaxMessageAge
- currentcpu_SENSOR
- AccumulatedSecondsPendingRequests
- AccumulatedSecondsPendingRequests_SENSOR
- RawMaxMessageAge_SENSOR
- NumPendingRequests_SENSOR
- NumWorkers_SENSOR
GLOBAL:
- UnusedResources_SLO_CONSTRAINT
- CPU_SLO
- PendingRequestsMinusWorkers
- MaxMessageAge_SLO_CONSTRAINT
- CPU_SLO_CONSTRAINT
- UnusedResources_SLO
- NumPendingRequests
- NumWorkers
- RawMaxMessageAge
- currentcpu
- MeanMaxMessageAge
- MaxMessageAge_SLO
2024-07-02T12:25:15.095Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.096Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Topics-Connections map:
PER_INSTANCE:
NumPendingRequests: [GLOBAL]
NumWorkers: [GLOBAL]
RawMaxMessageAge: [GLOBAL]
currentcpu: [GLOBAL]
2024-07-02T12:25:15.096Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.096Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : MVV set:
[]
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : MVV_CP map:
{}
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : CMVAR set:
[]
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : RMVAR set:
[]
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Function Definitions set:
[]
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.097Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Metric Constraints:
[MetricConstraint(super=UnaryConstraint(super=Constraint(super=NamedElement(super=AbstractRootObject(_objectClass=gr.iccs.imu.ems.translate.model.MetricConstraint, object=null, container=null), name=UnusedResources_SLO_CONSTRAINT, description=null, annotations=null)), validity=null, comparisonOperator=LESS_THAN, threshold=0.0), metricContext=null), MetricConstraint(super=UnaryConstraint(super=Constraint(super=NamedElement(super=AbstractRootObject(_objectClass=gr.iccs.imu.ems.translate.model.MetricConstraint, object=null, container=null), name=CPU_SLO_CONSTRAINT, description=null, annotations=null)), validity=null, comparisonOperator=GREATER_THAN, threshold=-100000.0), metricContext=null), MetricConstraint(super=UnaryConstraint(super=Constraint(super=NamedElement(super=AbstractRootObject(_objectClass=gr.iccs.imu.ems.translate.model.MetricConstraint, object=null, container=null), name=MaxMessageAge_SLO_CONSTRAINT, description=null, annotations=null)), validity=null, comparisonOperator=GREATER_THAN, threshold=50.0), metricContext=null)]
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Busy-Status Destination-to-Metric Context names map:
{}
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Busy-Status Metrics:
[]
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Top-Level Metric names:
[CPU_SLO, MeanMaxMessageAge_METRIC, PendingRequestsMinusWorkers_METRIC, AccumulatedSecondsPendingRequests_METRIC, UnusedResources_SLO, MaxMessageAge_SLO, NumWorkers_METRIC, RawMaxMessageAge_METRIC, NumPendingRequests_METRIC]
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Additional Results:
{NEBULOUS_PREDICTION_SLO_METRIC_DECOMPOSITION_MAP={name=1414020207rest-processor-app1719922442226, constraints=[{metric=PendingRequestsMinusWorkers, name=UnusedResources_SLO_CONSTRAINT, operator=<, threshold=0.0}, {metric=MeanMaxMessageAge, name=MaxMessageAge_SLO_CONSTRAINT, operator=>, threshold=50.0}, {metric=currentcpu, name=CPU_SLO_CONSTRAINT, operator=>, threshold=-100000.0}], version=0.0, operator=OR}, NEBULOUS_PREDICTION_SLO_METRIC_DECOMPOSITION={"name":"1414020207rest-processor-app1719922442226","constraints":[{"metric":"PendingRequestsMinusWorkers","name":"UnusedResources_SLO_CONSTRAINT","operator":"<","threshold":0.0},{"metric":"MeanMaxMessageAge","name":"MaxMessageAge_SLO_CONSTRAINT","operator":">","threshold":50.0},{"metric":"currentcpu","name":"CPU_SLO_CONSTRAINT","operator":">","threshold":-100000.0}],"version":0,"operator":"OR"}, NEBULOUS_PREDICTION_TOP_LEVEL_NODES_METRICS_MAP={metric_list=[{lower_bound=-Infinity, name=AccumulatedSecondsPendingRequests, upper_bound=Infinity}], name=1414020207rest-processor-app1719922442226, version=0}, NEBULOUS_PREDICTION_TOP_LEVEL_NODES_METRICS={"metric_list":[{"lower_bound":"-Infinity","name":"AccumulatedSecondsPendingRequests","upper_bound":"Infinity"}],"name":"1414020207rest-processor-app1719922442226","version":0}}
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : Export files:
[]
2024-07-02T12:25:15.099Z INFO 30 --- [ taskExecutor-1] g.i.i.e.t.TranslationContextPrinter : *********************************************************
2024-07-02T12:25:15.100Z WARN 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): No App Exec model has been provided
2024-07-02T12:25:15.100Z INFO 30 --- [ taskExecutor-1] g.iccs.imu.ems.brokercep.cep.CepService : CepService: Clear registered Statements
2024-07-02T12:25:15.100Z INFO 30 --- [ taskExecutor-1] g.iccs.imu.ems.brokercep.cep.CepService : CepService: Clear registered Event Types
2024-07-02T12:25:15.106Z INFO 30 --- [ taskExecutor-1] g.i.imu.ems.brokercep.BrokerCepService : BrokerCepService.addEventTypes(): Adding event types: [UnusedResources_SLO_CONSTRAINT, CPU_SLO, PendingRequestsMinusWorkers, MaxMessageAge_SLO_CONSTRAINT, CPU_SLO_CONSTRAINT, UnusedResources_SLO, NumPendingRequests, NumWorkers, RawMaxMessageAge, currentcpu, MeanMaxMessageAge, MaxMessageAge_SLO]
2024-07-02T12:25:15.149Z INFO 30 --- [ taskExecutor-1] g.i.imu.ems.brokercep.BrokerCepService : BrokerCepService.setConstants(): Add/Set constants: {}
2024-07-02T12:25:15.150Z INFO 30 --- [ taskExecutor-1] g.i.imu.ems.brokercep.BrokerCepService : BrokerCepService.addFunctionDefinitions(): Adding function definitions: []
2024-07-02T12:25:15.581Z INFO 30 --- [:1): I/O Thread] o.a.q.p.client.impl.ClientConnection : Connection ID:2e4b1068-eb91-425a-b0b8-8e43a095f668:3:1 connected to server: 158.37.63.86:32754
2024-07-02T12:25:15.975Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer.setServerConfiguration(): stopping SSH server...
2024-07-02T12:25:15.976Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Stopping SSH server...
2024-07-02T12:25:15.984Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Stopped
2024-07-02T12:25:15.985Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer.setServerConfiguration(): stopping SSH server... done
2024-07-02T12:25:15.991Z INFO 30 --- [ taskExecutor-1] g.i.i.e.b.s.c.c.ClusteringCoordinator : Cluster Detector class: gr.iccs.imu.ems.baguette.server.coordinator.cluster.ClusterZoneDetector
2024-07-02T12:25:15.992Z INFO 30 --- [ taskExecutor-1] g.i.i.e.b.s.c.TwoLevelCoordinator : TwoLevelCoordinator.initialize(): Groupings: top-level=GLOBAL, node-level=PER_INSTANCE
2024-07-02T12:25:15.993Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer.startServer(): Starting SSH server...
2024-07-02T12:25:15.993Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : ** SSH server **
2024-07-02T12:25:15.993Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Public IP address: 10.0.0.66
2024-07-02T12:25:15.993Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Starting on port: 2222
2024-07-02T12:25:15.993Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Server key file: /opt/ems-server/config/hostkey.pem
2024-07-02T12:25:16.018Z INFO 30 --- [ taskExecutor-1] gr.iccs.imu.ems.baguette.server.Sshd : SSH server: Ready
2024-07-02T12:25:16.019Z INFO 30 --- [ taskExecutor-1] g.i.i.e.b.s.coordinator.NoopCoordinator : TwoLevelCoordinator: start(): Invoking callback
2024-07-02T12:25:16.020Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : ****************************************
2024-07-02T12:25:16.021Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : **** MONITORING TOPOLOGY IS READY ****
2024-07-02T12:25:16.021Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : ****************************************
2024-07-02T12:25:16.022Z INFO 30 --- [ taskExecutor-1] g.i.i.e.baguette.server.BaguetteServer : BaguetteServer.startServer(): Starting SSH server... done
2024-07-02T12:25:16.027Z INFO 30 --- [ Thread-7] gr.iccs.imu.ems.baguette.server.Sshd : --> Heartbeat: Started: period=60000ms
2024-07-02T12:25:16.037Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator.startNetdataCollector(): Starting NetdataCollector: app-model-id=1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:16.038Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.AbstractEndpointCollector : Collectors::ServerNetdataCollector: Started
2024-07-02T12:25:16.039Z WARN 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): Skipping MetaSolver setup due to configuration
2024-07-02T12:25:16.039Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): Cache translation results: app-model-id=1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:16.039Z WARN 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): Skipping notification due to configuration
2024-07-02T12:25:16.039Z INFO 30 --- [ taskExecutor-1] sEmsClientDeploymentPostProcessingPlugin : K8sEmsClientDeploymentPostProcessingPlugin: Set applicationId to: 1414020207rest-processor-app1719922442226 -- was: 1414020207rest-processor-app1719922442226
2024-07-02T12:25:16.040Z INFO 30 --- [ taskExecutor-1] sEmsClientDeploymentPostProcessingPlugin : K8sEmsClientDeploymentPostProcessingPlugin: Start deploying EMS clients...
2024-07-02T12:25:16.060Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.NodeRegistrationCoordinator : NodeRegistrationCoordinator.registerNode(): ExecutionWare: PROACTIVE
2024-07-02T12:25:16.063Z INFO 30 --- [ taskExecutor-1] g.i.i.e.c.c.ControlServiceCoordinator : ControlServiceCoordinator._processAppModel(): END: app-model-id=1414020207rest-processor-app1719922442226.yml
2024-07-02T12:25:16.063Z INFO 30 --- [pool-4-thread-1] g.i.i.e.b.c.install.ClientInstaller : ClientInstaller: Executing Client installation Task #0: task-id=K8S-_-dummy-1719923116040-dummy-1719923116040-Kubernetes-_-_, node-id=dummy-1719923116040, name=dummy-1719923116040, type=K8S, address=unknown-address-1719923116059
2024-07-02T12:25:16.064Z INFO 30 --- [ taskExecutor-1] e.n.ems.service.EmsBootInitializer : Metric model processing result: {ems-state=READY, ems-state-message=, ems-state-change-timestamp=1719923116064}
2024-07-02T12:25:16.114Z INFO 30 --- [pool-4-thread-1] g.i.i.e.b.c.install.ClientInstaller : ClientInstaller: Using K8sClientInstaller for task #0
2024-07-02T12:25:16.116Z INFO 30 --- [pool-4-thread-1] g.i.i.e.b.c.i.i.K8sClientInstaller : K8sClientInstaller: Extra Env.Vars:
2024-07-02T12:25:17.153Z WARN 30 --- [pool-4-thread-1] i.f.kubernetes.client.internal.SSLUtils : SSL handshake failed. Falling back to insecure connection.
2024-07-02T12:26:07.867Z INFO 30 --- [ Thread-6] gr.iccs.imu.ems.baguette.server.Sshd : --> Heartbeat: Stopped
2024-07-02T12:26:07.911Z INFO 30 --- [ scheduling-1] g.iccs.imu.ems.control.util.TopicBeacon : Topic Beacon: updateModelVersion: Model changed: -> /1414020207rest-processor-app1719922442226.yml, version: 1
2024-07-02T12:26:07.927Z INFO 30 --- [ Thread-5] .i.i.e.b.b.i.MessageForwarderInterceptor : MessageQueueProcessor: Forward destinations initialized: []
2024-07-02T12:27:26.574Z ERROR 30 --- [pool-4-thread-1] g.i.i.e.b.c.i.i.K8sClientInstaller : K8sClientInstaller: Failed executing installation instructions for task #0, Exception:
io.fabric8.kubernetes.client.KubernetesClientException: Operation: [patch] for kind: [ConfigMap] with name: [ems-client-configmap] in namespace: [default] failed.
at io.fabric8.kubernetes.client.KubernetesClientException.launderThrowable(KubernetesClientException.java:159)
at io.fabric8.kubernetes.client.dsl.internal.HasMetadataOperation.lambda$patch$2(HasMetadataOperation.java:234)
at io.fabric8.kubernetes.client.dsl.internal.HasMetadataOperation.patch(HasMetadataOperation.java:237)
at io.fabric8.kubernetes.client.dsl.internal.HasMetadataOperation.patch(HasMetadataOperation.java:252)
at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.serverSideApply(BaseOperation.java:1172)
at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.serverSideApply(BaseOperation.java:97)
at gr.iccs.imu.ems.common.k8s.K8sClient.createConfigMap(K8sClient.java:102)
at gr.iccs.imu.ems.baguette.client.install.installer.K8sClientInstaller.createEmsClientConfigMap(K8sClientInstaller.java:163)
at gr.iccs.imu.ems.baguette.client.install.installer.K8sClientInstaller.deployOnCluster(K8sClientInstaller.java:140)
at gr.iccs.imu.ems.baguette.client.install.installer.K8sClientInstaller.deployOnCluster(K8sClientInstaller.java:134)
at gr.iccs.imu.ems.baguette.client.install.installer.K8sClientInstaller.executeTask(K8sClientInstaller.java:119)
at gr.iccs.imu.ems.baguette.client.install.ClientInstallerPlugin.execute(ClientInstallerPlugin.java:15)
at gr.iccs.imu.ems.baguette.client.install.ClientInstaller.lambda$executeKubernetesTask$6(ClientInstaller.java:232)
at gr.iccs.imu.ems.baguette.client.install.ClientInstaller.executeInstaller(ClientInstaller.java:180)
at gr.iccs.imu.ems.baguette.client.install.ClientInstaller.executeKubernetesTask(ClientInstaller.java:222)
at gr.iccs.imu.ems.baguette.client.install.ClientInstaller.executeTask(ClientInstaller.java:139)
at gr.iccs.imu.ems.baguette.client.install.ClientInstaller.lambda$addTask$1(ClientInstaller.java:87)
at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown Source)
at java.base/java.util.concurrent.FutureTask.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.io.IOException: timeout
at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.waitForResult(OperationSupport.java:504)
at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handleResponse(OperationSupport.java:524)
at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handlePatch(OperationSupport.java:419)
at io.fabric8.kubernetes.client.dsl.internal.OperationSupport.handlePatch(OperationSupport.java:397)
at io.fabric8.kubernetes.client.dsl.internal.BaseOperation.handlePatch(BaseOperation.java:763)
at io.fabric8.kubernetes.client.dsl.internal.HasMetadataOperation.lambda$patch$2(HasMetadataOperation.java:232)
... 20 common frames omitted
Caused by: java.io.InterruptedIOException: timeout
at okhttp3.internal.connection.RealCall.timeoutExit(RealCall.kt:398)
at okhttp3.internal.connection.RealCall.callDone(RealCall.kt:360)
at okhttp3.internal.connection.RealCall.noMoreExchanges$okhttp(RealCall.kt:325)
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:209)
at okhttp3.internal.connection.RealCall$AsyncCall.run(RealCall.kt:517)
... 3 common frames omitted
Caused by: java.net.SocketException: Socket closed
at java.base/sun.nio.ch.NioSocketImpl.endConnect(Unknown Source)
at java.base/sun.nio.ch.NioSocketImpl.connect(Unknown Source)
at java.base/java.net.SocksSocketImpl.connect(Unknown Source)
at java.base/java.net.Socket.connect(Unknown Source)
at okhttp3.internal.platform.Platform.connectSocket(Platform.kt:128)
at okhttp3.internal.connection.RealConnection.connectSocket(RealConnection.kt:295)
at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:207)
at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.kt:226)
at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:106)
at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.kt:74)
at okhttp3.internal.connection.RealCall.initExchange$okhttp(RealCall.kt:255)
at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:32)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76)
at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109)
at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201)
... 4 common frames omitted
Some times, EMS server on app cluster fails to start (see the logs below). If the EMS server is restarted (deleting the pod and waiting for K8s to recreate it), the server works OK.