![[Jenkins]](/jenkins/static/096e06b9/images/svgs/logo.svg){kind=logo}
[INFO] [INFO] ----------< org.eclipse.sensinact.gateway.nthbnd:mqtt-agent >----------- [INFO] Building sensiNact IoT Gateway - MQTT Northbound Agent Instance 2.0-SNAPSHOT [72/120] [INFO] --------------------------------[ jar ]--------------------------------- [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/maven/plugins/maven-antrun-plugin/1.8/maven-antrun-plugin-1.8.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/maven/plugins/maven-antrun-plugin/1.8/maven-antrun-plugin-1.8.pom (3.3 kB at 221 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/maven/plugins/maven-plugins/27/maven-plugins-27.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/maven/plugins/maven-plugins/27/maven-plugins-27.pom (11 kB at 812 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/maven/plugins/maven-antrun-plugin/1.8/maven-antrun-plugin-1.8.jar [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/maven/plugins/maven-antrun-plugin/1.8/maven-antrun-plugin-1.8.jar (36 kB at 2.6 MB/s) [INFO] [INFO] --- maven-clean-plugin:3.1.0:clean (default-clean) @ mqtt-agent --- [INFO] [INFO] --- maven-enforcer-plugin:3.0.0-M3:enforce (enforce) @ mqtt-agent --- [INFO] [INFO] --- maven-resources-plugin:3.1.0:copy-resources (generate-test-resources) @ mqtt-agent --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] skip non existing resourceDirectory /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/src/test/resources [INFO] [INFO] --- directory-maven-plugin:0.3.1:highest-basedir (directories) @ mqtt-agent --- [INFO] Highest basedir set to: /var/jenkins_home/jobs/Eclipse Sensinact/workspace [INFO] [INFO] --- maven-resources-plugin:3.1.0:resources (default-resources) @ mqtt-agent --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] Copying 1 resource [INFO] [INFO] --- maven-compiler-plugin:3.8.1:compile (default-compile) @ mqtt-agent --- [INFO] Changes detected - recompiling the module! [INFO] Compiling 2 source files to /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/target/classes [INFO] [INFO] --- bnd-maven-plugin:6.1.0-SNAPSHOT:bnd-process (default) @ mqtt-agent --- [INFO] [INFO] --- maven-antrun-plugin:1.8:run (keystoreCopy) @ mqtt-agent --- [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/junit/junit/3.8.1/junit-3.8.1.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/junit/junit/3.8.1/junit-3.8.1.pom (998 B at 77 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/codehaus/plexus/plexus-utils/3.0.20/plexus-utils-3.0.20.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/codehaus/plexus/plexus-utils/3.0.20/plexus-utils-3.0.20.pom (3.8 kB at 272 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant/1.9.4/ant-1.9.4.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant/1.9.4/ant-1.9.4.pom (9.6 kB at 740 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant-parent/1.9.4/ant-parent-1.9.4.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant-parent/1.9.4/ant-parent-1.9.4.pom (5.6 kB at 374 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant-launcher/1.9.4/ant-launcher-1.9.4.pom [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant-launcher/1.9.4/ant-launcher-1.9.4.pom (2.3 kB at 167 kB/s) [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/junit/junit/3.8.1/junit-3.8.1.jar [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/codehaus/plexus/plexus-utils/3.0.20/plexus-utils-3.0.20.jar [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant/1.9.4/ant-1.9.4.jar [INFO] Downloading from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant-launcher/1.9.4/ant-launcher-1.9.4.jar [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant-launcher/1.9.4/ant-launcher-1.9.4.jar (18 kB at 511 kB/s) [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/junit/junit/3.8.1/junit-3.8.1.jar (121 kB at 3.2 MB/s) [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/codehaus/plexus/plexus-utils/3.0.20/plexus-utils-3.0.20.jar (243 kB at 4.8 MB/s) [INFO] Downloaded from repo1.maven.org: https://repo1.maven.org/maven2/org/apache/ant/ant/1.9.4/ant-1.9.4.jar (2.0 MB at 23 MB/s) [INFO] Executing tasks main: [mkdir] Created dir: /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/target/felix/tmp [copy] Copying 1 file to /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/target/felix/bundle [INFO] Executed tasks [INFO] [INFO] --- maven-resources-plugin:3.1.0:testResources (default-testResources) @ mqtt-agent --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] skip non existing resourceDirectory /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/src/test/resources [INFO] [INFO] --- maven-compiler-plugin:3.8.1:testCompile (default-testCompile) @ mqtt-agent --- [INFO] Changes detected - recompiling the module! [INFO] Compiling 1 source file to /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/target/test-classes [INFO] [INFO] --- bnd-maven-plugin:6.1.0-SNAPSHOT:bnd-process-tests (bnd-process-tests) @ mqtt-agent --- [INFO] [INFO] --- maven-surefire-plugin:2.22.2:test (default-test) @ mqtt-agent --- [INFO] Tests are skipped. [INFO] [INFO] --- maven-jar-plugin:3.2.0:jar (default-jar) @ mqtt-agent --- [INFO] Building jar: /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/target/mqtt-agent-2.0-SNAPSHOT.jar [INFO] [INFO] --- maven-jar-plugin:3.2.0:test-jar (test-jar) @ mqtt-agent --- [INFO] Building jar: /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/target/mqtt-agent-2.0-SNAPSHOT-tests.jar [INFO] [INFO] --- bnd-resolver-maven-plugin:6.1.0-SNAPSHOT:resolve (resolve-test) @ mqtt-agent --- [INFO] Resolving /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/tests.bndrun: [INFO] -runbundles: org.osgi.util.function;version='[1.1.0,1.1.1)',org.osgi.util.promise;version='[1.1.1,1.1.2)',junit-platform-commons;version='[1.7.2,1.7.3)',junit-jupiter-api;version='[5.7.2,5.7.3)',junit-jupiter-engine;version='[5.7.2,5.7.3)',junit-platform-engine;version='[1.7.2,1.7.3)',junit-platform-launcher;version='[1.7.2,1.7.3)',org.opentest4j;version='[1.2.0,1.2.1)',junit-jupiter-params;version='[5.7.2,5.7.3)',org.apache.felix.scr;version='[2.1.16,2.1.17)',org.osgi.test.common;version='[1.0.1,1.0.2)',org.osgi.test.junit5;version='[1.0.1,1.0.2)',ch.qos.logback.core;version='[1.2.3,1.2.4)',log4j;version='[1.2.17,1.2.18)',slf4j.api;version='[1.7.30,1.7.31)',org.eclipse.sensinact.gateway.sensinact-common;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-core;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-datastore-api;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-generic;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-signature-validator-api;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-utils;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-security-none;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-signature-validator-mock;version='[2.0.0,2.0.1)',org.apache.felix.framework.security;version='[2.8.1,2.8.2)',org.osgi.service.component;version='[1.4.0,1.4.1)',org.apache.felix.configadmin;version='[1.9.16,1.9.17)',org.osgi.test.junit5.cm;version='[1.0.1,1.0.2)',org.apache.felix.http.jetty;version='[4.1.10,4.1.11)',org.apache.felix.http.servlet-api;version='[1.1.4,1.1.5)',json;version='[20190722.0.0,20190722.0.1)',org.eclipse.paho.client.mqttv3;version='[1.2.2,1.2.3)',org.eclipse.sensinact.gateway.nthbnd.mqtt-agent;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.nthbnd.mqtt-agent-tests;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.nthbnd.mqtt-generic-agent;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.simulated.devices.slider;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.tools.mqtt-server;version='[2.0.0,2.0.1)',ch.qos.logback.classic;version='[1.2.3,1.2.4)',org.osgi.util.converter;version='[1.0.8,1.0.9)' [INFO] [INFO] --- bnd-testing-maven-plugin:6.1.0-SNAPSHOT:testing (testing) @ mqtt-agent --- [INFO] Matching glob * [INFO] Testing /var/jenkins_home/jobs/Eclipse Sensinact/workspace/platform/northbound/mqtt/mqtt-agent/tests.bndrun: [INFO] -runbundles: org.osgi.util.function;version='[1.1.0,1.1.1)',org.osgi.util.promise;version='[1.1.1,1.1.2)',junit-platform-commons;version='[1.7.2,1.7.3)',junit-jupiter-api;version='[5.7.2,5.7.3)',junit-jupiter-engine;version='[5.7.2,5.7.3)',junit-platform-engine;version='[1.7.2,1.7.3)',junit-platform-launcher;version='[1.7.2,1.7.3)',org.opentest4j;version='[1.2.0,1.2.1)',junit-jupiter-params;version='[5.7.2,5.7.3)',org.apache.felix.scr;version='[2.1.16,2.1.17)',org.osgi.test.common;version='[1.0.1,1.0.2)',org.osgi.test.junit5;version='[1.0.1,1.0.2)',ch.qos.logback.core;version='[1.2.3,1.2.4)',log4j;version='[1.2.17,1.2.18)',slf4j.api;version='[1.7.30,1.7.31)',org.eclipse.sensinact.gateway.sensinact-common;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-core;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-datastore-api;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-generic;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-signature-validator-api;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-utils;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-security-none;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.sensinact-signature-validator-mock;version='[2.0.0,2.0.1)',org.apache.felix.framework.security;version='[2.8.1,2.8.2)',org.osgi.service.component;version='[1.4.0,1.4.1)',org.apache.felix.configadmin;version='[1.9.16,1.9.17)',org.osgi.test.junit5.cm;version='[1.0.1,1.0.2)',org.apache.felix.http.jetty;version='[4.1.10,4.1.11)',org.apache.felix.http.servlet-api;version='[1.1.4,1.1.5)',json;version='[20190722.0.0,20190722.0.1)',org.eclipse.paho.client.mqttv3;version='[1.2.2,1.2.3)',org.eclipse.sensinact.gateway.nthbnd.mqtt-agent;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.nthbnd.mqtt-agent-tests;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.nthbnd.mqtt-generic-agent;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.simulated.devices.slider;version='[2.0.0,2.0.1)',org.eclipse.sensinact.gateway.tools.mqtt-server;version='[2.0.0,2.0.1)',ch.qos.logback.classic;version='[1.2.3,1.2.4)',org.osgi.util.converter;version='[1.0.8,1.0.9)' 16:52:31.770 [main] DEBUG org.eclipse.jetty.util.log - Logging to Logger[org.eclipse.jetty.util.log] via org.eclipse.jetty.util.log.Slf4jLog 16:52:31.773 [main] INFO org.eclipse.jetty.util.log - Logging initialized @911ms to org.eclipse.jetty.util.log.Slf4jLog 16:52:31.780 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - QueuedThreadPool[qtp442199874]@1a5b6f42{STOPPED,8<=0<=200,i=0,r=-1,q=0}[NO_TRY] added {org.eclipse.jetty.util.thread.ThreadPoolBudget@78fa769e,POJO} 16:52:31.783 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STOPPED}[9.4.42.v20210604] added {QueuedThreadPool[qtp442199874]@1a5b6f42{STOPPED,8<=0<=200,i=0,r=-1,q=0}[NO_TRY],AUTO} 16:52:31.785 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - HashLoginService@18ece7f4[null] added {org.eclipse.jetty.security.DefaultIdentityService@3cce57c7,POJO} 16:52:31.786 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - HashLoginService@18ece7f4[OSGi HTTP Service Realm] added {UserStore@1cf56a1c{STOPPED},AUTO} 16:52:31.786 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STOPPED}[9.4.42.v20210604] added {HashLoginService@18ece7f4[OSGi HTTP Service Realm],AUTO} 16:52:31.797 [main] DEBUG org.eclipse.jetty.server.handler.ContextHandlerCollection - ->[{o.e.j.s.ServletContextHandler@791d1f8b{/,null,STOPPED},[o.e.j.s.ServletContextHandler@791d1f8b{/,null,STOPPED}]}] 16:52:31.797 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ContextHandlerCollection@2415fc55{STOPPED} added {o.e.j.s.ServletContextHandler@791d1f8b{/,null,STOPPED},AUTO} 16:52:31.799 [main] DEBUG org.eclipse.jetty.util.DecoratedObjectFactory - Adding Decorator: org.eclipse.jetty.util.DeprecationWarning@205d38da 16:52:31.803 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - o.e.j.s.ServletContextHandler@791d1f8b{/,null,STOPPED} added {org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=-1,MANAGED} 16:52:31.806 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=-1 added {ServletHandler@7a3793c7{STOPPED},MANAGED} 16:52:31.806 [main] DEBUG org.eclipse.jetty.server.session - Sessions created by this manager are immortal (default maxInactiveInterval=0) 16:52:31.807 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=0 added {org.apache.felix.http.base.internal.EventDispatcher@39d76cb5,UNMANAGED} 16:52:31.809 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServletHandler@7a3793c7{STOPPED} added {org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED},AUTO} 16:52:31.809 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServletHandler@7a3793c7{STOPPED} added {[/*]=>org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499,POJO} 16:52:31.810 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STOPPED}[9.4.42.v20210604] added {ContextHandlerCollection@2415fc55{STOPPED},MANAGED} 16:52:31.810 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting Server@5852c06f{STOPPED}[9.4.42.v20210604] 16:52:31.811 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STARTING}[9.4.42.v20210604] added {ErrorHandler@a37aefe{STOPPED},AUTO} 16:52:31.812 [main] INFO org.eclipse.jetty.server.Server - jetty-9.4.42.v20210604; built: 2021-06-04T17:33:38.939Z; git: 5cd5e6d2375eeab146813b0de9f19eda6ab6e6cb; jvm 1.8.0_272-b10 16:52:31.824 [main] DEBUG org.eclipse.jetty.server.handler.AbstractHandler - starting Server@5852c06f{STARTING}[9.4.42.v20210604] 16:52:31.825 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting QueuedThreadPool[qtp442199874]@1a5b6f42{STOPPED,8<=0<=200,i=0,r=-1,q=0}[NO_TRY] 16:52:31.826 [main] DEBUG org.eclipse.jetty.util.thread.ReservedThreadExecutor - ReservedThreadExecutor@1e81f160{s=0/12,p=0} 16:52:31.826 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=0<=200,i=0,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] added {ReservedThreadExecutor@1e81f160{s=0/12,p=0},AUTO} 16:52:31.826 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ReservedThreadExecutor@1e81f160{s=0/12,p=0} 16:52:31.831 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @969ms ReservedThreadExecutor@1e81f160{s=0/12,p=0} 16:52:31.831 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-33,5,main] 16:52:31.832 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-34,5,main] 16:52:31.832 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-35,5,main] 16:52:31.832 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-36,5,main] 16:52:31.832 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-37,5,main] 16:52:31.832 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-38,5,main] 16:52:31.832 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-39,5,main] 16:52:31.832 [qtp442199874-33] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=3<=200,i=3,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.832 [qtp442199874-34] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=3<=200,i=3,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.833 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Starting Thread[qtp442199874-40,5,main] 16:52:31.833 [qtp442199874-37] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=7<=200,i=7,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.833 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @971ms QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.833 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting HashLoginService@18ece7f4[OSGi HTTP Service Realm] 16:52:31.833 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting UserStore@1cf56a1c{STOPPED} 16:52:31.833 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @972ms UserStore@1cf56a1c{STARTED} 16:52:31.833 [qtp442199874-35] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=7<=200,i=7,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.834 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @972ms HashLoginService@18ece7f4[OSGi HTTP Service Realm] 16:52:31.834 [qtp442199874-36] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.834 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ContextHandlerCollection@2415fc55{STOPPED} 16:52:31.834 [qtp442199874-39] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.834 [main] DEBUG org.eclipse.jetty.server.handler.AbstractHandler - starting ContextHandlerCollection@2415fc55{STARTING} 16:52:31.834 [qtp442199874-40] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.834 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting o.e.j.s.ServletContextHandler@791d1f8b{/,null,STOPPED} 16:52:31.834 [qtp442199874-38] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - Runner started for QueuedThreadPool[qtp442199874]@1a5b6f42{STARTING,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.835 [main] DEBUG org.eclipse.jetty.http.PreEncodedHttpField - HttpField encoders loaded: [] 16:52:31.841 [main] DEBUG org.eclipse.jetty.server.handler.AbstractHandler - starting o.e.j.s.ServletContextHandler@791d1f8b{/,null,STARTING} 16:52:31.841 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=0 16:52:31.843 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=0 added {org.eclipse.jetty.server.session.DefaultSessionCache@1205bd62[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false],AUTO} 16:52:31.844 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.server.session.DefaultSessionCache@1205bd62[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] added {org.eclipse.jetty.server.session.NullSessionDataStore@4032d386[passivating=false,graceSec=3600],AUTO} 16:52:31.845 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting DefaultSessionIdManager@55cf0d14{STOPPED}[worker=null] 16:52:31.845 [main] INFO org.eclipse.jetty.server.session - DefaultSessionIdManager workerName=node0 16:52:31.845 [main] INFO org.eclipse.jetty.server.session - No SessionScavenger set, using defaults 16:52:31.845 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - DefaultSessionIdManager@55cf0d14{STARTING}[worker=node0] added {HouseKeeper@b83a9be{STOPPED}[interval=600000, ownscheduler=false],MANAGED} 16:52:31.845 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting HouseKeeper@b83a9be{STOPPED}[interval=600000, ownscheduler=false] 16:52:31.846 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ScheduledExecutorScheduler@2b175c00{STOPPED} 16:52:31.846 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @985ms ScheduledExecutorScheduler@2b175c00{STARTED} 16:52:31.846 [main] DEBUG org.eclipse.jetty.server.session - Using own scheduler for scavenging 16:52:31.847 [main] INFO org.eclipse.jetty.server.session - node0 Scavenging every 600000ms 16:52:31.847 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @985ms HouseKeeper@b83a9be{STARTED}[interval=600000, ownscheduler=true] 16:52:31.847 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @985ms DefaultSessionIdManager@55cf0d14{STARTED}[worker=node0] 16:52:31.847 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STARTING}[9.4.42.v20210604] added {DefaultSessionIdManager@55cf0d14{STARTED}[worker=node0],MANAGED} 16:52:31.847 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=0 added {DefaultSessionIdManager@55cf0d14{STARTED}[worker=node0],UNMANAGED} 16:52:31.848 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ScheduledExecutorScheduler@1f75a668{STOPPED} 16:52:31.848 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @986ms ScheduledExecutorScheduler@1f75a668{STARTED} 16:52:31.848 [main] DEBUG org.eclipse.jetty.server.handler.AbstractHandler - starting org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=0 16:52:31.848 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ServletHandler@7a3793c7{STOPPED} 16:52:31.850 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - Path=/*[EMBEDDED:null] mapped to servlet=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499[EMBEDDED:null] 16:52:31.851 [main] DEBUG org.eclipse.jetty.http.pathmap.PathMappings - Added MappedResource[pathSpec=ServletPathSpec@5fa{/*},resource=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}] to PathMappings[size=1] 16:52:31.851 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - filterNameMap={} 16:52:31.851 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - pathFilters=null 16:52:31.851 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletFilterMap=null 16:52:31.852 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletPathMap=PathMappings[size=1] 16:52:31.852 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletNameMap={org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}} 16:52:31.852 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - Adding Default404Servlet to ServletHandler@7a3793c7{STARTING} 16:52:31.852 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServletHandler@7a3793c7{STARTING} added {org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED},AUTO} 16:52:31.852 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServletHandler@7a3793c7{STARTING} added {[/]=>org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224,POJO} 16:52:31.852 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - Path=/*[EMBEDDED:null] mapped to servlet=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499[EMBEDDED:null] 16:52:31.852 [main] DEBUG org.eclipse.jetty.http.pathmap.PathMappings - Added MappedResource[pathSpec=ServletPathSpec@5fa{/*},resource=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}] to PathMappings[size=1] 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - Path=/[EMBEDDED:null] mapped to servlet=org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224[EMBEDDED:null] 16:52:31.853 [main] DEBUG org.eclipse.jetty.http.pathmap.PathMappings - Added MappedResource[pathSpec=ServletPathSpec@4e{/},resource=org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}] to PathMappings[size=2] 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - filterNameMap={} 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - pathFilters=null 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletFilterMap=null 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletPathMap=PathMappings[size=2] 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletNameMap={org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}, org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224=org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}} 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - Path=/*[EMBEDDED:null] mapped to servlet=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499[EMBEDDED:null] 16:52:31.853 [main] DEBUG org.eclipse.jetty.http.pathmap.PathMappings - Added MappedResource[pathSpec=ServletPathSpec@5fa{/*},resource=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}] to PathMappings[size=1] 16:52:31.853 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - Path=/[EMBEDDED:null] mapped to servlet=org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224[EMBEDDED:null] 16:52:31.854 [main] DEBUG org.eclipse.jetty.http.pathmap.PathMappings - Added MappedResource[pathSpec=ServletPathSpec@4e{/},resource=org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}] to PathMappings[size=2] 16:52:31.854 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - filterNameMap={} 16:52:31.854 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - pathFilters=null 16:52:31.854 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletFilterMap=null 16:52:31.854 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletPathMap=PathMappings[size=2] 16:52:31.854 [main] DEBUG org.eclipse.jetty.servlet.ServletHandler - servletNameMap={org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499=org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}, org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224=org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED}} 16:52:31.854 [main] DEBUG org.eclipse.jetty.server.handler.AbstractHandler - starting ServletHandler@7a3793c7{STARTING} 16:52:31.854 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @992ms ServletHandler@7a3793c7{STARTED} 16:52:31.854 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting org.eclipse.jetty.server.session.DefaultSessionCache@1205bd62[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] 16:52:31.854 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting org.eclipse.jetty.server.session.NullSessionDataStore@4032d386[passivating=false,graceSec=3600] 16:52:31.854 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @993ms org.eclipse.jetty.server.session.NullSessionDataStore@4032d386[passivating=false,graceSec=3600] 16:52:31.854 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @993ms org.eclipse.jetty.server.session.DefaultSessionCache@1205bd62[evict=-1,removeUnloadable=false,saveOnCreate=false,saveOnInactiveEvict=false] 16:52:31.855 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @993ms org.eclipse.jetty.server.session.SessionHandler1856158867==dftMaxIdleSec=0 16:52:31.857 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED} 16:52:31.857 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @996ms org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499==org.apache.felix.http.base.internal.dispatch.DispatcherServlet@2b588c04{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STARTED} 16:52:31.859 [main] DEBUG org.eclipse.jetty.servlet.ServletHolder - Servlet.init null for org.apache.felix.http.base.internal.dispatch.DispatcherServlet-7f8a9499 16:52:31.859 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STOPPED} 16:52:31.859 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @997ms org.eclipse.jetty.servlet.ServletHandler$Default404Servlet-6aa61224==org.eclipse.jetty.servlet.ServletHandler$Default404Servlet@fa7ac5d7{jsp=null,order=-1,inst=false,async=true,src=EMBEDDED:null,STARTED} 16:52:31.859 [main] INFO org.eclipse.jetty.server.handler.ContextHandler - Started o.e.j.s.ServletContextHandler@791d1f8b{/,null,AVAILABLE} 16:52:31.860 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @998ms o.e.j.s.ServletContextHandler@791d1f8b{/,null,AVAILABLE} 16:52:31.860 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @998ms ContextHandlerCollection@2415fc55{STARTED} 16:52:31.860 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ErrorHandler@a37aefe{STOPPED} 16:52:31.860 [main] DEBUG org.eclipse.jetty.server.handler.AbstractHandler - starting ErrorHandler@a37aefe{STARTING} 16:52:31.860 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @998ms ErrorHandler@a37aefe{STARTED} 16:52:31.860 [main] INFO org.eclipse.jetty.server.Server - Started @998ms 16:52:31.860 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @998ms Server@5852c06f{STARTED}[9.4.42.v20210604] 16:52:31.860 [main] INFO org.eclipse.jetty.server.session - node0 Scavenging every 660000ms 16:52:31.865 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - HttpConnectionFactory@60b4beb4[HTTP/1.1] added {HttpConfiguration@7fcf2fc1{32768/8192,8192/8192,https://:0,[]},POJO} 16:52:31.873 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{null, ()}{0.0.0.0:0} added {Server@5852c06f{STARTED}[9.4.42.v20210604],UNMANAGED} 16:52:31.874 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{null, ()}{0.0.0.0:0} added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.874 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{null, ()}{0.0.0.0:0} added {ScheduledExecutorScheduler@2d778add{STOPPED},AUTO} 16:52:31.874 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{null, ()}{0.0.0.0:0} added {org.eclipse.jetty.io.ArrayByteBufferPool@73302995,POJO} 16:52:31.874 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{null, (http/1.1)}{0.0.0.0:0} added {HttpConnectionFactory@60b4beb4[HTTP/1.1],AUTO} 16:52:31.874 [main] DEBUG org.eclipse.jetty.server.AbstractConnector - ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:0} added HttpConnectionFactory@60b4beb4[HTTP/1.1] 16:52:31.876 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:0} added {SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:0},MANAGED} 16:52:31.877 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STARTED}[9.4.42.v20210604] added {ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898},UNMANAGED} 16:52:31.877 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} 16:52:31.881 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {sun.nio.ch.ServerSocketChannelImpl[/0.0.0.0:8898],POJO} 16:52:31.881 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ScheduledExecutorScheduler@2d778add{STOPPED} 16:52:31.881 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1020ms ScheduledExecutorScheduler@2d778add{STARTED} 16:52:31.881 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting HttpConnectionFactory@60b4beb4[HTTP/1.1] 16:52:31.882 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1020ms HttpConnectionFactory@60b4beb4[HTTP/1.1] 16:52:31.882 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} 16:52:31.890 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.888Z added {SelectorProducer@6d167f58,POJO} 16:52:31.890 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.89Z added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.890 [main] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.89Z created 16:52:31.891 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ManagedSelector@12359a82{STOPPED} id=0 keys=-1 selected=-1 updates=0 added {EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.89Z,MANAGED} 16:52:31.891 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {ManagedSelector@12359a82{STOPPED} id=0 keys=-1 selected=-1 updates=0,AUTO} 16:52:31.891 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.891Z added {SelectorProducer@479460a6,POJO} 16:52:31.891 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.891Z added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.892 [main] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.891Z created 16:52:31.892 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ManagedSelector@7164ca4c{STOPPED} id=1 keys=-1 selected=-1 updates=0 added {EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.892Z,MANAGED} 16:52:31.892 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {ManagedSelector@7164ca4c{STOPPED} id=1 keys=-1 selected=-1 updates=0,AUTO} 16:52:31.892 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.892Z added {SelectorProducer@5be46f9d,POJO} 16:52:31.893 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.892Z added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.893 [main] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.893Z created 16:52:31.893 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ManagedSelector@3f91b517{STOPPED} id=2 keys=-1 selected=-1 updates=0 added {EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.893Z,MANAGED} 16:52:31.893 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {ManagedSelector@3f91b517{STOPPED} id=2 keys=-1 selected=-1 updates=0,AUTO} 16:52:31.893 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.893Z added {SelectorProducer@7a220c9a,POJO} 16:52:31.894 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.894Z added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.894 [main] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.894Z created 16:52:31.894 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ManagedSelector@2421cc4{STOPPED} id=3 keys=-1 selected=-1 updates=0 added {EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.894Z,MANAGED} 16:52:31.894 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {ManagedSelector@2421cc4{STOPPED} id=3 keys=-1 selected=-1 updates=0,AUTO} 16:52:31.895 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.895Z added {SelectorProducer@59a008ba,POJO} 16:52:31.895 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.895Z added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.895 [main] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.895Z created 16:52:31.895 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ManagedSelector@338c99c8{STOPPED} id=4 keys=-1 selected=-1 updates=0 added {EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.895Z,MANAGED} 16:52:31.896 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {ManagedSelector@338c99c8{STOPPED} id=4 keys=-1 selected=-1 updates=0,AUTO} 16:52:31.896 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.896Z added {SelectorProducer@58ce9668,POJO} 16:52:31.896 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.896Z added {QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}],UNMANAGED} 16:52:31.896 [main] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.896Z created 16:52:31.897 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ManagedSelector@172b013{STOPPED} id=5 keys=-1 selected=-1 updates=0 added {EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.897Z,MANAGED} 16:52:31.897 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {ManagedSelector@172b013{STOPPED} id=5 keys=-1 selected=-1 updates=0,AUTO} 16:52:31.897 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ManagedSelector@12359a82{STOPPED} id=0 keys=-1 selected=-1 updates=0 16:52:31.897 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.897Z 16:52:31.897 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1036ms EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=8,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.897Z 16:52:31.899 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@1fa1cab1 startThread=0 16:52:31.899 [main] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change lazy=false org.eclipse.jetty.io.ManagedSelector$Start@70f02c32 on ManagedSelector@12359a82{STARTING} id=0 keys=0 selected=0 updates=0 16:52:31.899 [qtp442199874-33] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@1fa1cab1 in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=7,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.900 [qtp442199874-33] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@1583741e/SelectorProducer@6d167f58/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=7,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.899Z tryProduce false 16:52:31.901 [qtp442199874-33] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 1 16:52:31.901 [qtp442199874-33] DEBUG org.eclipse.jetty.io.ManagedSelector - update org.eclipse.jetty.io.ManagedSelector$Start@70f02c32 16:52:31.902 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1040ms ManagedSelector@12359a82{STARTED} id=0 keys=0 selected=0 updates=0 16:52:31.902 [qtp442199874-33] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0 16:52:31.902 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ManagedSelector@7164ca4c{STOPPED} id=1 keys=-1 selected=-1 updates=0 16:52:31.902 [qtp442199874-33] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@273527b2 waiting with 0 keys 16:52:31.902 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=7,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.902Z 16:52:31.902 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1040ms EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=7,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.902Z 16:52:31.902 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@62010f5c startThread=0 16:52:31.902 [main] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change lazy=false org.eclipse.jetty.io.ManagedSelector$Start@51fadaff on ManagedSelector@7164ca4c{STARTING} id=1 keys=0 selected=0 updates=0 16:52:31.902 [qtp442199874-34] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@62010f5c in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=6,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.903 [qtp442199874-34] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@68df9280/SelectorProducer@479460a6/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=6,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.903Z tryProduce false 16:52:31.903 [qtp442199874-34] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 1 16:52:31.903 [qtp442199874-34] DEBUG org.eclipse.jetty.io.ManagedSelector - update org.eclipse.jetty.io.ManagedSelector$Start@51fadaff 16:52:31.903 [qtp442199874-34] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0 16:52:31.903 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1042ms ManagedSelector@7164ca4c{STARTED} id=1 keys=0 selected=0 updates=0 16:52:31.903 [qtp442199874-34] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@6c118677 waiting with 0 keys 16:52:31.903 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ManagedSelector@3f91b517{STOPPED} id=2 keys=-1 selected=-1 updates=0 16:52:31.903 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=6,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.903Z 16:52:31.904 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1042ms EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=6,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.904Z 16:52:31.904 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@401f7633 startThread=0 16:52:31.904 [main] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change lazy=false org.eclipse.jetty.io.ManagedSelector$Start@31ff43be on ManagedSelector@3f91b517{STARTING} id=2 keys=0 selected=0 updates=0 16:52:31.904 [qtp442199874-37] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@401f7633 in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=5,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.904 [qtp442199874-37] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@4f3bbf68/SelectorProducer@5be46f9d/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=5,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.904Z tryProduce false 16:52:31.904 [qtp442199874-37] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 1 16:52:31.904 [qtp442199874-37] DEBUG org.eclipse.jetty.io.ManagedSelector - update org.eclipse.jetty.io.ManagedSelector$Start@31ff43be 16:52:31.904 [qtp442199874-37] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0 16:52:31.904 [qtp442199874-37] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@50edbfab waiting with 0 keys 16:52:31.904 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1043ms ManagedSelector@3f91b517{STARTED} id=2 keys=0 selected=0 updates=0 16:52:31.904 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ManagedSelector@2421cc4{STOPPED} id=3 keys=-1 selected=-1 updates=0 16:52:31.904 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=5,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.904Z 16:52:31.905 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1043ms EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=5,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.904Z 16:52:31.905 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@5b6ec132 startThread=0 16:52:31.905 [main] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change lazy=false org.eclipse.jetty.io.ManagedSelector$Start@5c44c582 on ManagedSelector@2421cc4{STARTING} id=3 keys=0 selected=0 updates=0 16:52:31.905 [qtp442199874-35] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@5b6ec132 in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=4,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.905 [qtp442199874-35] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@68702e03/SelectorProducer@7a220c9a/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=4,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.905Z tryProduce false 16:52:31.905 [qtp442199874-35] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 1 16:52:31.905 [qtp442199874-35] DEBUG org.eclipse.jetty.io.ManagedSelector - update org.eclipse.jetty.io.ManagedSelector$Start@5c44c582 16:52:31.905 [qtp442199874-35] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0 16:52:31.905 [qtp442199874-35] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@706947e9 waiting with 0 keys 16:52:31.905 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1044ms ManagedSelector@2421cc4{STARTED} id=3 keys=0 selected=0 updates=0 16:52:31.906 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ManagedSelector@338c99c8{STOPPED} id=4 keys=-1 selected=-1 updates=0 16:52:31.906 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=4,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.906Z 16:52:31.906 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1044ms EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=4,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.906Z 16:52:31.906 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@67d18ed7 startThread=0 16:52:31.906 [main] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change lazy=false org.eclipse.jetty.io.ManagedSelector$Start@2c78d320 on ManagedSelector@338c99c8{STARTING} id=4 keys=0 selected=0 updates=0 16:52:31.906 [qtp442199874-36] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@67d18ed7 in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=3,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.907 [qtp442199874-36] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@30c93896/SelectorProducer@59a008ba/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=3,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.906Z tryProduce false 16:52:31.907 [qtp442199874-36] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 1 16:52:31.907 [qtp442199874-36] DEBUG org.eclipse.jetty.io.ManagedSelector - update org.eclipse.jetty.io.ManagedSelector$Start@2c78d320 16:52:31.907 [qtp442199874-36] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0 16:52:31.907 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1045ms ManagedSelector@338c99c8{STARTED} id=4 keys=0 selected=0 updates=0 16:52:31.907 [qtp442199874-36] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@16b90ca9 waiting with 0 keys 16:52:31.907 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting ManagedSelector@172b013{STOPPED} id=5 keys=-1 selected=-1 updates=0 16:52:31.907 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - starting EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=3,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.907Z 16:52:31.907 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1046ms EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=3,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.907Z 16:52:31.907 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@132e0cc startThread=0 16:52:31.908 [main] DEBUG org.eclipse.jetty.io.ManagedSelector - Queued change lazy=false org.eclipse.jetty.io.ManagedSelector$Start@7b205dbd on ManagedSelector@172b013{STARTING} id=5 keys=0 selected=0 updates=0 16:52:31.908 [qtp442199874-39] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run org.eclipse.jetty.io.ManagedSelector$$Lambda$42/189207010@132e0cc in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=2,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] 16:52:31.908 [qtp442199874-39] DEBUG org.eclipse.jetty.util.thread.strategy.EatWhatYouKill - EatWhatYouKill@21ba0741/SelectorProducer@58ce9668/IDLE/p=false/QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=2,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}][pc=0,pic=0,pec=0,epc=0]@2021-11-24T16:52:31.908Z tryProduce false 16:52:31.908 [qtp442199874-39] DEBUG org.eclipse.jetty.io.ManagedSelector - updateable 1 16:52:31.908 [qtp442199874-39] DEBUG org.eclipse.jetty.io.ManagedSelector - update org.eclipse.jetty.io.ManagedSelector$Start@7b205dbd 16:52:31.908 [qtp442199874-39] DEBUG org.eclipse.jetty.io.ManagedSelector - updates 0 16:52:31.908 [qtp442199874-39] DEBUG org.eclipse.jetty.io.ManagedSelector - Selector sun.nio.ch.EPollSelectorImpl@73b3507a waiting with 0 keys 16:52:31.908 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1047ms ManagedSelector@172b013{STARTED} id=5 keys=0 selected=0 updates=0 16:52:31.908 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1047ms SelectorManager@ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} 16:52:31.909 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} added {acceptor-0@6cc558c6,POJO} 16:52:31.909 [main] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - queue acceptor-0@6cc558c6 startThread=0 16:52:31.909 [main] INFO org.eclipse.jetty.server.AbstractConnector - Started ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} 16:52:31.909 [main] DEBUG org.eclipse.jetty.util.component.AbstractLifeCycle - STARTED @1047ms ServerConnector@20c0a64d{HTTP/1.1, (http/1.1)}{0.0.0.0:8898} 16:52:31.909 [qtp442199874-40] DEBUG org.eclipse.jetty.util.thread.QueuedThreadPool - run acceptor-0@6cc558c6 in QueuedThreadPool[qtp442199874]@1a5b6f42{STARTED,8<=8<=200,i=1,r=-1,q=0}[ReservedThreadExecutor@1e81f160{s=0/12,p=0}] [INFO] Started Jetty 9.4.42.v20210604 at port(s) HTTP:8898 on context path / [minThreads=8,maxThreads=200,acceptors=1,selectors=6] 16:52:31.921 [main] DEBUG org.eclipse.jetty.util.component.ContainerLifeCycle - Server@5852c06f{STARTED}[9.4.42.v20210604] added {org.apache.felix.http.jetty.internal.RequestLogTracker@c9d0d6,POJO} 16:52:31.929 [main] DEBUG org.eclipse.sensinact.gateway.common.bundle.AbstractActivator - Starting introspection in bundle %s 16:52:31.934 [main] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.BundleValidationImpl - check bundle: %s 16:52:31.936 [main] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.SignedBundle - Better performance, data found (signatureFile) 16:52:31.936 [main] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.SignatureFile - Looking for Manifest hash header [%s] 16:52:31.936 [main] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.BundleValidationImpl - %s %s is valid? %s 16:52:32.032 [main] DEBUG org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler - org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler.policiesStart(org.xml.sax.Attributes) 16:52:32.033 [main] DEBUG org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler - org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler.policiesEnd() 16:52:32.037 [main] DEBUG org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler - org.eclipse.sensinact.gateway.generic.parser.ResourceInfoDefinition.identifierEnd() 16:52:32.041 [main] DEBUG org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler - org.eclipse.sensinact.gateway.generic.parser.AttributeDefinition.valueEnd() 16:52:32.041 [main] DEBUG org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler - org.eclipse.sensinact.gateway.generic.parser.ResourceInfoDefinition.attributeEnd() 16:52:32.041 [main] DEBUG org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler - org.eclipse.sensinact.gateway.generic.parser.XmlResourceConfigHandler.resourceInfoEnd() 16:52:32.046 [main] INFO org.eclipse.sensinact.gateway.generic.ExtModelConfiguration - ExtModelConfiguration initialized... 16:52:32.098 [main] DEBUG org.eclipse.sensinact.gateway.generic.DefaultConnectorCustomizer - pre-processing done 16:52:32.110 [main] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.BundleValidationImpl - check bundle: %s 16:52:32.136 [main] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.BundleValidationImpl - check bundle: %s 16:52:32.147 [main] DEBUG org.eclipse.sensinact.gateway.core.ResourceImpl - '%s' resource registered 16:52:32.149 [main] DEBUG org.eclipse.sensinact.gateway.core.ResourceImpl - '%s' resource registered 16:52:32.149 [main] DEBUG org.eclipse.sensinact.gateway.core.ResourceImpl - '%s' resource registered 16:52:32.150 [main] DEBUG org.eclipse.sensinact.gateway.core.ResourceImpl - '%s' resource registered 16:52:32.152 [main] INFO org.eclipse.sensinact.gateway.core.ServiceProviderImpl - New service discovered for '%s' service provider : %s 16:52:32.154 [main] DEBUG org.eclipse.sensinact.gateway.core.ResourceImpl - '%s' resource registered 16:52:32.154 [main] DEBUG org.eclipse.sensinact.gateway.core.ResourceImpl - %s already started 16:52:32.155 [main] DEBUG org.eclipse.sensinact.gateway.core.ServiceProviderImpl - ServiceProvider '%s' started 16:52:32.155 [main] DEBUG org.eclipse.sensinact.gateway.generic.Connector - Service provider discovered : slider 16:52:32.156 [main] DEBUG org.eclipse.sensinact.gateway.generic.DefaultConnectorCustomizer - post-processing done 16:52:32.654 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.agent.broker~ag1)] DEBUG org.eclipse.sensinact.gateway.agent.mqtt.inst.internal.NorthboundBroker - Starting MQTT Agent point to server %s with prefix %s and qos %s 16:52:32.655 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.agent.broker~ag1)] DEBUG org.eclipse.sensinact.gateway.agent.mqtt.generic.internal.GenericMqttAgent - Connecting to broker tcp://127.0.0.1:1884 with QoS 1 and prefix / 16:52:32.655 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.agent.broker~ag1)] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.BundleValidationImpl - check bundle: %s 16:52:32.656 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.agent.broker~ag1)] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.SignedBundle - Better performance, data found (signatureFile) 16:52:32.656 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.agent.broker~ag1)] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.SignatureFile - Looking for Manifest hash header [%s] 16:52:32.656 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.agent.broker~ag1)] DEBUG org.eclipse.sensinact.gateway.security.signature.internal.BundleValidationImpl - %s %s is valid? %s 16:52:32.715 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO org.sensinact.mqtt.server.internal.SensiNactServer - Persistent store file: null 16:52:32.780 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] DEBUG io.moquette.spi.impl.subscriptions.SubscriptionsStore - init invoked 16:52:32.781 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - retrieveAllSubscriptions returning subs [] 16:52:32.781 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] DEBUG io.moquette.spi.impl.subscriptions.SubscriptionsStore - Reloading all stored subscriptions...subscription tree before 16:52:32.782 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO io.moquette.spi.impl.SensiNactProtocolProcessorBootstrapper - Starting without ACL definition Nov 24, 2021 4:52:32 PM io.netty.bootstrap.AbstractBootstrap setChannelOption WARNING: Unknown channel option 'TCP_NODELAY' for channel '[id: 0x6bc14598]' 16:52:32.924 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO io.moquette.server.netty.NettyAcceptor - Server binded host: , port: 1884 16:52:32.928 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO io.moquette.server.netty.NettyAcceptor - WebSocket is disabled 16:52:38.311 [Thread-14] INFO messageLogger - C->B CONNECT client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.311 [Thread-14] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type CONNECT 16:52:38.311 [Thread-14] INFO io.moquette.spi.impl.ProtocolProcessor - CONNECT for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.312 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Connect with keepAlive 60 s 16:52:38.312 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Connect create session <[id: 0xc78e39dc, L:/127.0.0.1:1884 - R:/127.0.0.1:56108]> 16:52:38.314 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Create persistent session for clientID <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.314 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - createNewSession for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> with clean flag <true> 16:52:38.314 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - clientID 6a7c6545-04d9-4518-b076-ad49ffa4e56b is a newcome, creating it's empty subscriptions set 16:52:38.321 [Thread-14] INFO io.moquette.spi.ClientSession - cleaning old saved subscriptions for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.321 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - wipeSubscriptions 16:52:38.322 [Thread-14] DEBUG io.moquette.spi.ClientSession - Wiped subscriptions for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.324 [Thread-14] DEBUG io.moquette.spi.ClientSession - Removed messages in session for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.324 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Created session for client ID <6a7c6545-04d9-4518-b076-ad49ffa4e56b> with clean session true 16:52:38.325 [Thread-14] INFO io.moquette.spi.impl.ProtocolProcessor - Connection established 16:52:38.325 [Thread-14] INFO io.moquette.spi.impl.ProtocolProcessor - CONNECT processed 16:52:38.326 [Thread-14] INFO messageLogger - C->B SUBSCRIBE <6a7c6545-04d9-4518-b076-ad49ffa4e56b> to topics [[qos=1, topicFilter='/slider/cursor/position']] 16:52:38.326 [Thread-14] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type SUBSCRIBE 16:52:38.326 [Thread-14] INFO io.moquette.spi.impl.ProtocolProcessor - SUBSCRIBE client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:38.326 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - SUBSCRIBE client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> on server 1884 packetID 1 16:52:38.327 [Thread-14] INFO io.moquette.spi.ClientSession - <6a7c6545-04d9-4518-b076-ad49ffa4e56b> subscribed to the topic filter </slider/cursor/position> with QoS 1 - LEAST_ONE 16:52:38.330 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - subscriptions_6a7c6545-04d9-4518-b076-ad49ffa4e56b: {} 16:52:38.330 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - addNewSubscription invoked with subscription [filter:/slider/cursor/position, cliID: 6a7c6545-04d9-4518-b076-ad49ffa4e56b, qos: LEAST_ONE, active: true] 16:52:38.331 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - SUBACK for packetID 1 16:52:38.331 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Persisting subscription [filter:/slider/cursor/position, cliID: 6a7c6545-04d9-4518-b076-ad49ffa4e56b, qos: LEAST_ONE, active: true] 16:52:38.331 [Thread-14] DEBUG io.moquette.spi.impl.subscriptions.SubscriptionsStore - root ref io.moquette.spi.impl.subscriptions.TreeNode@1dbc88a0, original root was io.moquette.spi.impl.subscriptions.TreeNode@5d76f2e6 16:52:38.332 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Publish persisted messages in session [filter:/slider/cursor/position, cliID: 6a7c6545-04d9-4518-b076-ad49ffa4e56b, qos: LEAST_ONE, active: true] 16:52:38.332 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBMessagesStore - searchMatching scanning all retained messages, presents are 0 16:52:38.333 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Found 0 messages to republish 16:52:38.363 [main] DEBUG org.eclipse.sensinact.gateway.generic.DefaultConnectorCustomizer - pre-processing done 16:52:38.364 [main] DEBUG org.eclipse.sensinact.gateway.generic.DefaultConnectorCustomizer - post-processing done 16:52:38.570 [Stack Engine Worker Thread] DEBUG org.eclipse.sensinact.gateway.agent.mqtt.inst.internal.SnaEventEventHandler - Event received update:{"notification":{"name":"position","type":"int","value":5,"timestamp":1637772758363},"type":"ATTRIBUTE_VALUE_UPDATED","uri":"/slider/cursor/position/value"} 16:52:38.880 [Thread-21] INFO messageLogger - C->B CONNECT client <paho14325821422064532> 16:52:38.881 [Thread-21] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type CONNECT 16:52:38.881 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - CONNECT for client <paho14325821422064532> 16:52:38.881 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Connect with keepAlive 60 s 16:52:38.881 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Connect create session <[id: 0x7e5bfcd1, L:/127.0.0.1:1884 - R:/127.0.0.1:56114]> 16:52:38.882 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Create persistent session for clientID <paho14325821422064532> 16:52:38.882 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - createNewSession for client <paho14325821422064532> with clean flag <true> 16:52:38.882 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - clientID paho14325821422064532 is a newcome, creating it's empty subscriptions set 16:52:38.883 [Thread-21] INFO io.moquette.spi.ClientSession - cleaning old saved subscriptions for client <paho14325821422064532> 16:52:38.883 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - wipeSubscriptions 16:52:38.884 [Thread-21] DEBUG io.moquette.spi.ClientSession - Wiped subscriptions for client <paho14325821422064532> 16:52:38.889 [Thread-21] DEBUG io.moquette.spi.ClientSession - Removed messages in session for client <paho14325821422064532> 16:52:38.890 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Created session for client ID <paho14325821422064532> with clean session true 16:52:38.890 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - Connection established 16:52:38.890 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - CONNECT processed 16:52:38.891 [Thread-21] DEBUG io.moquette.parser.netty.PublishDecoder - decode invoked with buffer PooledUnsafeDirectByteBuf(ridx: 1, widx: 30, cap: 1024) 16:52:38.891 [Thread-21] INFO messageLogger - C->B PUBLISH <paho14325821422064532> to topics </slider/cursor/position> 16:52:38.891 [Thread-21] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type PUBLISH 16:52:38.891 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - PUB --PUBLISH--> SRV executePublish invoked with io.moquette.parser.proto.messages.PublishMessage@24996c6 16:52:38.892 [Thread-21] DEBUG io.moquette.spi.impl.Qos1PublishHandler - publish2Subscribers_qos1 republishing to existing subscribers that matches the topic /slider/cursor/position 16:52:38.894 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - subscriptions_6a7c6545-04d9-4518-b076-ad49ffa4e56b: {/slider/cursor/position=[filter:/slider/cursor/position, cliID: 6a7c6545-04d9-4518-b076-ad49ffa4e56b, qos: LEAST_ONE, active: true]} 16:52:38.894 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBMessagesStore - storePublishForFuture store evt PublishEvent{m_msgID=1, clientID='paho14325821422064532', m_retain=false, m_qos=LEAST_ONE, m_topic='/slider/cursor/position'} 16:52:38.895 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBMessagesStore - storePublishForFuture guid <MessageGUID{guid='8cc206ea-1939-432d-b8ce-e58d137a9256'}> 16:52:38.897 [Thread-21] DEBUG io.moquette.spi.impl.MessagesPublisher - Broker republishing to client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> topicFilter </slider/cursor/position> qos <LEAST_ONE>, active true 16:52:38.908 [Thread-21] INFO io.moquette.spi.persistence.MapDBSessionsStore - storing inflight clientID <6a7c6545-04d9-4518-b076-ad49ffa4e56b> messageID 1 guid <MessageGUID{guid='8cc206ea-1939-432d-b8ce-e58d137a9256'}> 16:52:38.909 [Thread-21] INFO io.moquette.spi.impl.PersistentQueueMessageSender - send publish message to <6a7c6545-04d9-4518-b076-ad49ffa4e56b> on topic </slider/cursor/position> 16:52:38.909 [Thread-21] DEBUG io.moquette.spi.impl.PersistentQueueMessageSender - directSend invoked clientId <6a7c6545-04d9-4518-b076-ad49ffa4e56b> on topic </slider/cursor/position> QoS LEAST_ONE retained false messageID 1 16:52:38.910 [Thread-21] DEBUG io.moquette.spi.impl.PersistentQueueMessageSender - content <5> 16:52:38.910 [Thread-21] DEBUG io.moquette.spi.impl.PersistentQueueMessageSender - channel is writable 16:52:38.910 [Thread-21] DEBUG io.moquette.spi.impl.Qos1PublishHandler - clientIDs are {paho14325821422064532=ConnectionDescriptor{clientID=paho14325821422064532, cleanSession=true, state=ESTABLISHED}, 6a7c6545-04d9-4518-b076-ad49ffa4e56b=ConnectionDescriptor{clientID=6a7c6545-04d9-4518-b076-ad49ffa4e56b, cleanSession=true, state=ESTABLISHED}} 16:52:38.911 [Thread-21] INFO messageLogger - C<-B PUBACK <paho14325821422064532> packetID <1> 16:52:38.911 [Thread-14] INFO messageLogger - C<-B PUBLISH <6a7c6545-04d9-4518-b076-ad49ffa4e56b> to topics </slider/cursor/position> 16:52:38.911 [Thread-21] INFO io.moquette.spi.impl.Qos1PublishHandler - server 1884 replying with PubAck to MSG ID 1 [/slider/cursor/position]5 16:52:38.913 [main] DEBUG org.eclipse.sensinact.gateway.generic.DefaultConnectorCustomizer - pre-processing done 16:52:38.915 [main] DEBUG org.eclipse.sensinact.gateway.generic.DefaultConnectorCustomizer - post-processing done 16:52:38.916 [Thread-14] INFO messageLogger - C->B PUBACK <6a7c6545-04d9-4518-b076-ad49ffa4e56b> packetID <1> 16:52:38.916 [Thread-14] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type PUBACK 16:52:38.917 [Thread-14] INFO io.moquette.spi.persistence.MapDBSessionsStore - inflight messageID 1 guid <MessageGUID{guid='8cc206ea-1939-432d-b8ce-e58d137a9256'}> 16:52:38.917 [Thread-14] INFO io.moquette.spi.persistence.MapDBSessionsStore - acknowledging inflight clientID <6a7c6545-04d9-4518-b076-ad49ffa4e56b> messageID 1 16:52:39.116 [Stack Engine Worker Thread] DEBUG org.eclipse.sensinact.gateway.agent.mqtt.inst.internal.SnaEventEventHandler - Event received update:{"notification":{"name":"position","type":"int","value":45,"timestamp":1637772758913},"type":"ATTRIBUTE_VALUE_UPDATED","uri":"/slider/cursor/position/value"} 16:52:39.118 [Thread-21] DEBUG io.moquette.parser.netty.PublishDecoder - decode invoked with buffer PooledUnsafeDirectByteBuf(ridx: 1, widx: 31, cap: 512) 16:52:39.118 [Thread-21] INFO messageLogger - C->B PUBLISH <paho14325821422064532> to topics </slider/cursor/position> 16:52:39.118 [Thread-21] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type PUBLISH 16:52:39.118 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - PUB --PUBLISH--> SRV executePublish invoked with io.moquette.parser.proto.messages.PublishMessage@240c5438 16:52:39.118 [Thread-21] DEBUG io.moquette.spi.impl.Qos1PublishHandler - publish2Subscribers_qos1 republishing to existing subscribers that matches the topic /slider/cursor/position 16:52:39.119 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - subscriptions_6a7c6545-04d9-4518-b076-ad49ffa4e56b: {/slider/cursor/position=[filter:/slider/cursor/position, cliID: 6a7c6545-04d9-4518-b076-ad49ffa4e56b, qos: LEAST_ONE, active: true]} 16:52:39.119 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBMessagesStore - storePublishForFuture store evt PublishEvent{m_msgID=2, clientID='paho14325821422064532', m_retain=false, m_qos=LEAST_ONE, m_topic='/slider/cursor/position'} 16:52:39.119 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBMessagesStore - storePublishForFuture guid <MessageGUID{guid='1663917c-0357-438f-b2bb-75675b3cb501'}> 16:52:39.120 [Thread-21] DEBUG io.moquette.spi.impl.MessagesPublisher - Broker republishing to client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> topicFilter </slider/cursor/position> qos <LEAST_ONE>, active true 16:52:39.120 [Thread-21] INFO io.moquette.spi.persistence.MapDBSessionsStore - storing inflight clientID <6a7c6545-04d9-4518-b076-ad49ffa4e56b> messageID 1 guid <MessageGUID{guid='1663917c-0357-438f-b2bb-75675b3cb501'}> 16:52:39.122 [Thread-21] INFO io.moquette.spi.impl.PersistentQueueMessageSender - send publish message to <6a7c6545-04d9-4518-b076-ad49ffa4e56b> on topic </slider/cursor/position> 16:52:39.122 [Thread-21] DEBUG io.moquette.spi.impl.PersistentQueueMessageSender - directSend invoked clientId <6a7c6545-04d9-4518-b076-ad49ffa4e56b> on topic </slider/cursor/position> QoS LEAST_ONE retained false messageID 1 16:52:39.122 [Thread-21] DEBUG io.moquette.spi.impl.PersistentQueueMessageSender - content <45> 16:52:39.122 [Thread-21] DEBUG io.moquette.spi.impl.PersistentQueueMessageSender - channel is writable 16:52:39.122 [Thread-21] DEBUG io.moquette.spi.impl.Qos1PublishHandler - clientIDs are {paho14325821422064532=ConnectionDescriptor{clientID=paho14325821422064532, cleanSession=true, state=ESTABLISHED}, 6a7c6545-04d9-4518-b076-ad49ffa4e56b=ConnectionDescriptor{clientID=6a7c6545-04d9-4518-b076-ad49ffa4e56b, cleanSession=true, state=ESTABLISHED}} 16:52:39.123 [Thread-21] INFO messageLogger - C<-B PUBACK <paho14325821422064532> packetID <2> 16:52:39.123 [Thread-14] INFO messageLogger - C<-B PUBLISH <6a7c6545-04d9-4518-b076-ad49ffa4e56b> to topics </slider/cursor/position> 16:52:39.123 [Thread-21] INFO io.moquette.spi.impl.Qos1PublishHandler - server 1884 replying with PubAck to MSG ID 2 [/slider/cursor/position]45 16:52:39.125 [Thread-14] INFO messageLogger - C->B PUBACK <6a7c6545-04d9-4518-b076-ad49ffa4e56b> packetID <1> 16:52:39.125 [Thread-14] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type PUBACK 16:52:39.125 [Thread-14] INFO io.moquette.spi.persistence.MapDBSessionsStore - inflight messageID 1 guid <MessageGUID{guid='1663917c-0357-438f-b2bb-75675b3cb501'}> 16:52:39.125 [Thread-14] INFO io.moquette.spi.persistence.MapDBSessionsStore - acknowledging inflight clientID <6a7c6545-04d9-4518-b076-ad49ffa4e56b> messageID 1 16:52:39.129 [Thread-14] DEBUG io.moquette.parser.netty.DisconnectDecoder - Decoding disconnect 16:52:39.129 [Thread-14] INFO messageLogger - C->B DISCONNECT <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:39.130 [Thread-14] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type DISCONNECT 16:52:39.131 [Thread-14] INFO io.moquette.spi.impl.ProtocolProcessor - cleaning old saved subscriptions for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:39.131 [Thread-14] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - wipeSubscriptions 16:52:39.134 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Wiped subscriptions for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:39.134 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Removing messages in session's queue for client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:39.135 [Thread-14] DEBUG io.moquette.spi.impl.ProtocolProcessor - Removed messages in session for client's queue <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:39.136 [Thread-21] DEBUG io.moquette.parser.netty.DisconnectDecoder - Decoding disconnect 16:52:39.137 [Thread-21] INFO messageLogger - C->B DISCONNECT <paho14325821422064532> 16:52:39.137 [Thread-14] INFO io.moquette.spi.impl.ProtocolProcessor - DISCONNECT client <6a7c6545-04d9-4518-b076-ad49ffa4e56b> finished 16:52:39.137 [Thread-21] INFO io.moquette.server.netty.NettyMQTTHandler - Received a message of type DISCONNECT 16:52:39.137 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - cleaning old saved subscriptions for client <paho14325821422064532> 16:52:39.137 [Thread-21] DEBUG io.moquette.spi.persistence.MapDBSessionsStore - wipeSubscriptions 16:52:39.137 [Thread-14] INFO messageLogger - Channel closed <6a7c6545-04d9-4518-b076-ad49ffa4e56b> 16:52:39.137 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Wiped subscriptions for client <paho14325821422064532> 16:52:39.137 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Removing messages in session's queue for client <paho14325821422064532> 16:52:39.137 [Thread-21] DEBUG io.moquette.spi.impl.ProtocolProcessor - Removed messages in session for client's queue <paho14325821422064532> 16:52:39.138 [Thread-21] INFO io.moquette.spi.impl.ProtocolProcessor - DISCONNECT client <paho14325821422064532> finished 16:52:39.138 [Thread-21] INFO messageLogger - Channel closed <paho14325821422064532> 16:52:39.139 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO org.sensinact.mqtt.server.internal.SensiNactServer - Server stopping... 16:52:39.346 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO io.moquette.server.netty.NettyAcceptor - Msg read: 18, msg wrote: 14 16:52:39.347 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO io.moquette.server.netty.NettyAcceptor - Bytes read: 376, bytes wrote: 3420 16:52:39.355 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] DEBUG io.moquette.spi.persistence.MapDBPersistentStore - closed disk storage 16:52:39.356 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] DEBUG io.moquette.spi.persistence.MapDBPersistentStore - Persistence commit scheduler is shutdown 16:52:39.356 [CM Event Dispatcher (Fire ConfigurationEvent: pid=mqtt.server~ag1)] INFO org.sensinact.mqtt.server.internal.SensiNactServer - Server stopped [INFO] No Errors