openHAB 3.3 Release discussion

This is this issue?

It is still opened.

1 Like

How or who sets the config value to 0 instead of false?
Is it MainUI that sets the config parameter to 0 instead of false?
I checked this hue parameter, it is defined as boolean and I don’t think it was charged.

After fixing the value, try to edit it again with MainUI to determine if this is a MainUI bug… or not.

I upgraded to OH3.3 at a first gance without problems. However it seems that the system never gets beyond startlevel 70. I can’t however see any issues in the log. Also from a UI perspective everything seems to be functional. Any ideas?

SystemInfo endpoint:

{
    "systemInfo": {
        "configFolder": "/openhab/conf",
        "userdataFolder": "/openhab/userdata",
        "logFolder": "/openhab/userdata/logs",
        "javaVersion": "11.0.15",
        "javaVendor": "Eclipse Adoptium",
        "javaVendorVersion": "Temurin-11.0.15+10",
        "osName": "Linux",
        "osVersion": "5.10.92-v8+",
        "osArchitecture": "aarch64",
        "availableProcessors": 4,
        "freeMemory": 36974600,
        "totalMemory": 187695104,
        "startLevel": 70
    }
}

Start log

2022-06-29 07:46:19.412 [INFO ] [port.EventAdminConfigurationNotifier] - Sending Event Admin notification (configuration successful) to org/ops4j/pax/logging/Configuration
2022-06-29 07:46:21.749 [INFO ] [raf.deployer.features.osgi.Activator] - Deployment finished. Registering FeatureDeploymentListener
2022-06-29 07:46:23.753 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.jaas.command/4.3.7
2022-06-29 07:46:23.766 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.3.7
2022-06-29 07:46:23.774 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.3.7
2022-06-29 07:46:23.823 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.commands/4.3.7
2022-06-29 07:46:23.828 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.deployer.kar/4.3.7
2022-06-29 07:46:24.440 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.wrapper.core/4.3.7
2022-06-29 07:46:25.701 [INFO ] [ROOT                                ] - bundle org.apache.felix.scr:2.1.30 (68) Starting with globalExtender setting: false
2022-06-29 07:46:25.731 [INFO ] [ROOT                                ] - bundle org.apache.felix.scr:2.1.30 (68)  Version = 2.1.30
2022-06-29 07:46:26.060 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.bundle.core/4.3.7
2022-06-29 07:46:26.248 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.config.core/4.3.7
2022-06-29 07:46:26.727 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.diagnostic.core/4.3.7
2022-06-29 07:46:26.811 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.features.command/4.3.7
2022-06-29 07:46:26.851 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.http.core/4.3.7. Missing service: [org.apache.karaf.http.core.ServletService, org.apache.karaf.http.core.ProxyService]
2022-06-29 07:46:26.943 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.instance.core/4.3.7
2022-06-29 07:46:27.009 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.kar.core/4.3.7
2022-06-29 07:46:27.031 [INFO ] [ll.impl.action.osgi.CommandExtension] - Unregistering commands for bundle org.apache.karaf.kar.core/4.3.7
2022-06-29 07:46:27.050 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.kar.core/4.3.7
2022-06-29 07:46:27.108 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.log.core/4.3.7
2022-06-29 07:46:27.200 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.package.core/4.3.7
2022-06-29 07:46:27.460 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.service.core/4.3.7
2022-06-29 07:46:27.645 [INFO ] [ll.impl.action.osgi.CommandExtension] - Command registration delayed for bundle org.apache.karaf.shell.ssh/4.3.7. Missing service: [org.apache.sshd.server.SshServer]
2022-06-29 07:46:27.695 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.system.core/4.3.7
2022-06-29 07:46:27.852 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.http.Http1FieldPreEncoder of service org.eclipse.jetty.http.HttpFieldPreEncoder in bundle org.eclipse.jetty.http
2022-06-29 07:46:28.046 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.common.extensions.identity.IdentityExtension of service org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2022-06-29 07:46:28.056 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.common.extensions.fragment.FragmentExtension of service org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2022-06-29 07:46:28.068 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.common.extensions.compress.PerMessageDeflateExtension of service org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2022-06-29 07:46:28.076 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.common.extensions.compress.DeflateFrameExtension of service org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2022-06-29 07:46:28.086 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.common.extensions.compress.XWebkitDeflateFrameExtension of service org.eclipse.jetty.websocket.api.extensions.Extension in bundle org.eclipse.jetty.websocket.common
2022-06-29 07:46:28.178 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.jsr356.JettyClientContainerProvider of service javax.websocket.ContainerProvider in bundle org.eclipse.jetty.websocket.javax.websocket
2022-06-29 07:46:28.231 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.jsr356.server.deploy.WebSocketServerContainerInitializer of service javax.servlet.ServletContainerInitializer in bundle org.eclipse.jetty.websocket.javax.websocket.server
2022-06-29 07:46:28.250 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.jsr356.server.ContainerDefaultConfigurator of service javax.websocket.server.ServerEndpointConfig$Configurator in bundle org.eclipse.jetty.websocket.javax.websocket.server
2022-06-29 07:46:28.267 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.eclipse.jetty.websocket.server.NativeWebSocketServletContainerInitializer of service javax.servlet.ServletContainerInitializer in bundle org.eclipse.jetty.websocket.server
2022-06-29 07:46:28.630 [INFO ] [org.eclipse.jetty.util.log          ] - Logging initialized @19331ms to org.eclipse.jetty.util.log.Slf4jLog
2022-06-29 07:46:28.724 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.shell.ssh/4.3.7
2022-06-29 07:46:28.772 [INFO ] [j.pax.web.service.internal.Activator] - EventAdmin support enabled, servlet events will be posted to topics.
2022-06-29 07:46:28.792 [INFO ] [j.pax.web.service.internal.Activator] - LogService support enabled, log events will be created.
2022-06-29 07:46:28.815 [INFO ] [j.pax.web.service.internal.Activator] - Pax Web started
2022-06-29 07:46:29.659 [INFO ] [org.apache.cxf.bus.osgi.CXFActivator] - Adding the extensions from bundle org.apache.cxf.cxf-rt-frontend-jaxrs (63) [org.apache.cxf.jaxrs.JAXRSBindingFactory]
2022-06-29 07:46:29.669 [INFO ] [org.apache.cxf.bus.osgi.CXFActivator] - Adding the extensions from bundle org.apache.cxf.cxf-rt-rs-sse (65) [org.apache.cxf.transport.sse.SseProvidersExtension]
2022-06-29 07:46:29.677 [INFO ] [org.apache.cxf.bus.osgi.CXFActivator] - Adding the extensions from bundle org.apache.cxf.cxf-rt-transports-http (67) [org.apache.cxf.transport.http.HTTPTransportFactory, org.apache.cxf.transport.http.HTTPWSDLExtensionLoader, org.apache.cxf.transport.http.policy.HTTPClientAssertionBuilder, org.apache.cxf.transport.http.policy.HTTPServerAssertionBuilder, org.apache.cxf.transport.http.policy.NoOpPolicyInterceptorProvider]
2022-06-29 07:46:29.839 [INFO ] [blueprint.NamespaceHandlerRegisterer] - Aries Blueprint packages not available. So namespaces will not be registered
2022-06-29 07:46:29.849 [INFO ] [blueprint.NamespaceHandlerRegisterer] - Aries Blueprint packages not available. So namespaces will not be registered
2022-06-29 07:46:29.866 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.apache.aries.jax.rs.whiteboard.internal.client.ClientBuilderImpl of service javax.ws.rs.client.ClientBuilder in bundle org.apache.aries.jax.rs.whiteboard
2022-06-29 07:46:29.894 [INFO ] [blueprint.NamespaceHandlerRegisterer] - Aries Blueprint packages not available. So namespaces will not be registered
2022-06-29 07:46:29.915 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.apache.cxf.jaxrs.impl.RuntimeDelegateImpl of service javax.ws.rs.ext.RuntimeDelegate in bundle org.apache.aries.jax.rs.whiteboard
2022-06-29 07:46:29.936 [INFO ] [rg.apache.aries.spifly.BaseActivator] - Registered provider org.apache.cxf.jaxrs.sse.client.SseEventSourceBuilderImpl of service javax.ws.rs.sse.SseEventSource.Builder in bundle org.apache.aries.jax.rs.whiteboard
2022-06-29 07:46:30.222 [INFO ] [rd.activator.CxfJaxrsBundleActivator] - Registered ClientBuilder
2022-06-29 07:46:30.234 [INFO ] [rd.activator.CxfJaxrsBundleActivator] - Registered SseEventSourceFactory
2022-06-29 07:46:30.703 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.event/4.3.7
2022-06-29 07:46:31.834 [INFO ] [rvice.jetty.internal.JettyServerImpl] - Pax Web available at [0.0.0.0]:[8443]
2022-06-29 07:46:31.915 [INFO ] [vice.jetty.internal.JettyFactoryImpl] - No ALPN class available
2022-06-29 07:46:31.928 [INFO ] [vice.jetty.internal.JettyFactoryImpl] - HTTP/2 not available, creating standard ServerConnector for Http
2022-06-29 07:46:31.938 [INFO ] [rvice.jetty.internal.JettyServerImpl] - Pax Web available at [0.0.0.0]:[8080]
2022-06-29 07:46:31.993 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.apache.karaf.http.core_4.3.7 [77]] to http service
2022-06-29 07:46:32.103 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.ops4j.pax.web.pax-web-extender-whiteboard_7.3.25 [219]] to http service
2022-06-29 07:46:32.153 [INFO ] [rd.activator.CxfJaxrsBundleActivator] - created whiteboard from configuration: {org.apache.karaf.features.configKey=org.apache.aries.jax.rs.whiteboard.default, replace.loopback.address.with.localhost=false, service.pid=org.apache.aries.jax.rs.whiteboard.default}
2022-06-29 07:46:32.187 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.apache.karaf.http.core/4.3.7
2022-06-29 07:46:32.941 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.apache.aries.jax.rs.whiteboard_2.0.0 [59]] to http service
2022-06-29 07:46:33.035 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Berlin'.
2022-06-29 07:46:33.070 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SI'.
2022-06-29 07:46:38.593 [INFO ] [ll.impl.action.osgi.CommandExtension] - Registering commands for bundle org.openhab.core.io.console.karaf/3.3.0
2022-06-29 07:46:38.722 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.io.http_3.3.0 [169]] to http service
2022-06-29 07:46:38.758 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.audio_3.3.0 [151]] to http service
2022-06-29 07:46:38.804 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:46:39.262 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.audio_3.3.0 [151], contextID=custom], with context-name: 
2022-06-29 07:46:39.353 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:46:39.520 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:46:39.666 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
2022-06-29 07:46:39.733 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_1.tld
2022-06-29 07:46:39.785 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c.tld
2022-06-29 07:46:39.820 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0-rt.tld
2022-06-29 07:46:39.866 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0.tld
2022-06-29 07:46:39.915 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt.tld
2022-06-29 07:46:39.970 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fn.tld
2022-06-29 07:46:39.991 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/permittedTaglibs.tld
2022-06-29 07:46:40.003 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/scriptfree.tld
2022-06-29 07:46:40.015 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0-rt.tld
2022-06-29 07:46:40.037 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0.tld
2022-06-29 07:46:40.057 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql.tld
2022-06-29 07:46:40.073 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0-rt.tld
2022-06-29 07:46:40.091 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0.tld
2022-06-29 07:46:40.114 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:46:40.229 [INFO ] [org.eclipse.jetty.server.session    ] - DefaultSessionIdManager workerName=node0
2022-06-29 07:46:40.233 [INFO ] [org.eclipse.jetty.server.session    ] - No SessionScavenger set, using defaults
2022-06-29 07:46:40.248 [INFO ] [org.eclipse.jetty.server.session    ] - node0 Scavenging every 600000ms
2022-06-29 07:46:40.358 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.audio_3.3.0 [151], contextID=custom]}
2022-06-29 07:46:40.411 [INFO ] [org.eclipse.jetty.server.Server     ] - jetty-9.4.46.v20220331; built: 2022-03-31T16:38:08.030Z; git: bc17a0369a11ecf40bb92c839b9ef0a8ac50ea18; jvm 11.0.15+10
2022-06-29 07:46:40.537 [INFO ] [.jetty.server.handler.ContextHandler] - Started o.e.j.s.h.ContextHandler@9e84b47{/static,null,AVAILABLE}
2022-06-29 07:46:40.677 [INFO ] [pse.jetty.util.ssl.SslContextFactory] - x509=X509@6b2e0116(mykey,h=[openhab.org],a=[],w=[]) for Server@560f6ad7[provider=null,keyStore=file:///openhab/userdata/etc/keystore,trustStore=file:///openhab/userdata/etc/keystore]
2022-06-29 07:46:40.843 [INFO ] [lipse.jetty.server.AbstractConnector] - Started 0.0.0.0:8443@57af85b3{SSL, (ssl, http/1.1)}{0.0.0.0:8443}
2022-06-29 07:46:40.862 [INFO ] [lipse.jetty.server.AbstractConnector] - Started default@476d7df9{HTTP/1.1, (http/1.1)}{0.0.0.0:8080}
2022-06-29 07:46:40.867 [INFO ] [org.eclipse.jetty.server.Server     ] - Started @31568ms
2022-06-29 07:46:40.970 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.io.http.auth_3.3.0 [170]] to http service
2022-06-29 07:46:40.988 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:46:40.993 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.io.http.auth_3.3.0 [170], contextID=default], with context-name: 
2022-06-29 07:46:40.998 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:46:41.013 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:46:41.055 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
...
2022-06-29 07:46:41.448 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:46:41.498 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.io.http.auth_3.3.0 [170], contextID=default]}
2022-06-29 07:46:41.849 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:46:41.859 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context org.ops4j.pax.web.extender.whiteboard.internal.WebApplication$1@4e7d1a7, with context-name: rest
2022-06-29 07:46:41.869 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:46:41.910 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:46:41.941 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
2022-06-29 07:46:41.970 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_1.tld
...
2022-06-29 07:46:42.461 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=org.ops4j.pax.web.extender.whiteboard.internal.WebApplication$1@4e7d1a7}
2022-06-29 07:46:43.161 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:46:43.452 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:46:43.745 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
... repeated a couple of times
2022-06-29 07:46:46.498 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.3.7
2022-06-29 07:46:46.509 [INFO ] [ll.impl.action.osgi.CommandExtension] - Updating commands for bundle org.apache.karaf.jaas.command/4.3.7
2022-06-29 07:46:50.778 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2022-06-29 07:46:52.716 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'default.sitemap'
2022-06-29 07:46:53.466 [INFO ] [el.core.internal.ModelRepositoryImpl] - Validation issues found in configuration model 'default.sitemap', using it anyway:
Linkable widget should contain either only frames or none at all
2022-06-29 07:46:54.068 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'knx.things'
2022-06-29 07:46:54.525 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:46:56.213 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:46:58.411 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:03.051 [INFO ] [.core.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2022-06-29 07:47:04.257 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:04.677 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:05.029 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:05.672 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:06.028 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:06.518 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:07.098 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:07.386 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.ui_3.3.0 [213]] to http service
2022-06-29 07:47:07.404 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:07.410 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.ui_3.3.0 [213], contextID=custom], with context-name: 
2022-06-29 07:47:07.414 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:07.444 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:47:07.473 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
2022-06-29 07:47:07.492 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_1.tld
2022-06-29 07:47:07.507 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c.tld
2022-06-29 07:47:07.527 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0-rt.tld
2022-06-29 07:47:07.549 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0.tld
2022-06-29 07:47:07.570 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt.tld
2022-06-29 07:47:07.588 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fn.tld
2022-06-29 07:47:07.607 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/permittedTaglibs.tld
2022-06-29 07:47:07.613 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/scriptfree.tld
2022-06-29 07:47:07.620 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0-rt.tld
2022-06-29 07:47:07.633 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0.tld
2022-06-29 07:47:07.645 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql.tld
2022-06-29 07:47:07.655 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0-rt.tld
2022-06-29 07:47:07.670 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0.tld
2022-06-29 07:47:07.686 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:47:07.747 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.ui_3.3.0 [213], contextID=custom]}
2022-06-29 07:47:08.049 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:08.434 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:08.439 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.ui_3.3.0 [213], contextID=default], with context-name: 
2022-06-29 07:47:08.445 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:08.462 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:47:08.484 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
...
2022-06-29 07:47:08.886 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.ui_3.3.0 [213], contextID=default]}
2022-06-29 07:47:09.019 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:09.361 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.core.ui.icon_3.3.0 [214]] to http service
2022-06-29 07:47:09.374 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:09.379 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.core.ui.icon_3.3.0 [214], contextID=custom], with context-name: 
2022-06-29 07:47:09.383 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:09.393 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:47:09.413 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
2022-06-29 07:47:09.430 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_1.tld
2022-06-29 07:47:09.443 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c.tld
2022-06-29 07:47:09.461 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0-rt.tld
2022-06-29 07:47:09.477 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0.tld
2022-06-29 07:47:09.496 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt.tld
2022-06-29 07:47:09.512 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fn.tld
2022-06-29 07:47:09.521 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/permittedTaglibs.tld
2022-06-29 07:47:09.527 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/scriptfree.tld
2022-06-29 07:47:09.534 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0-rt.tld
2022-06-29 07:47:09.566 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0.tld
2022-06-29 07:47:09.579 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql.tld
2022-06-29 07:47:09.599 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0-rt.tld
2022-06-29 07:47:09.617 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0.tld
2022-06-29 07:47:09.634 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:47:09.694 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.core.ui.icon_3.3.0 [214], contextID=custom]}
2022-06-29 07:47:09.806 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:10.254 [INFO ] [org.apache.cxf.endpoint.ServerImpl  ] - Setting the server's publish address to be /
2022-06-29 07:47:10.596 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui_3.3.0 [216]] to http service
2022-06-29 07:47:10.607 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:10.619 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui_3.3.0 [216], contextID=custom], with context-name: 
2022-06-29 07:47:10.625 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:10.632 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:47:10.677 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
2022-06-29 07:47:10.699 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_1.tld
2022-06-29 07:47:10.729 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c.tld
2022-06-29 07:47:10.746 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0-rt.tld
2022-06-29 07:47:10.766 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0.tld
2022-06-29 07:47:10.780 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt.tld
2022-06-29 07:47:10.795 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fn.tld
2022-06-29 07:47:10.803 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/permittedTaglibs.tld
2022-06-29 07:47:10.810 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/scriptfree.tld
2022-06-29 07:47:10.816 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0-rt.tld
2022-06-29 07:47:10.829 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0.tld
2022-06-29 07:47:10.841 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql.tld
2022-06-29 07:47:10.850 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0-rt.tld
2022-06-29 07:47:10.871 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0.tld
2022-06-29 07:47:10.884 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:47:10.917 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui_3.3.0 [216], contextID=custom]}
2022-06-29 07:47:10.924 [INFO ] [org.openhab.ui.internal.UIService   ] - Started UI on port 8080
2022-06-29 07:47:11.227 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.jupnp_2.6.1 [239]] to http service
2022-06-29 07:47:11.337 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:11.343 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.jupnp_2.6.1 [239], contextID=custom], with context-name: 
2022-06-29 07:47:11.347 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:11.371 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.jupnp_2.6.1 [239], contextID=custom]}
2022-06-29 07:47:12.970 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.binding.netatmo_3.3.0 [251]] to http service
2022-06-29 07:47:13.266 [INFO ] [o.internal.handler.AstroThingHandler] - Scheduled Positional job astro:sun:local every 60 seconds
2022-06-29 07:47:13.728 [INFO ] [um.core.network.config.NetworkConfig] - loading properties from file /openhab/userdata/Californium.properties
2022-06-29 07:47:13.771 [INFO ] [um.core.network.RandomTokenGenerator] - using tokens of 8 bytes in length
2022-06-29 07:47:14.187 [INFO ] [alifornium.core.network.CoapEndpoint] - coap CoapEndpoint uses udp plain
2022-06-29 07:47:14.327 [INFO ] [um.core.network.stack.BlockwiseLayer] - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
2022-06-29 07:47:14.346 [INFO ] [.core.network.stack.ReliabilityLayer] - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
2022-06-29 07:47:14.433 [INFO ] [um.core.network.RandomTokenGenerator] - using tokens of 8 bytes in length
2022-06-29 07:47:14.436 [INFO ] [alifornium.core.network.CoapEndpoint] - coap CoapEndpoint uses udp plain
2022-06-29 07:47:14.438 [INFO ] [um.core.network.stack.BlockwiseLayer] - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
2022-06-29 07:47:14.442 [INFO ] [.core.network.stack.ReliabilityLayer] - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
2022-06-29 07:47:14.454 [INFO ] [shelly.internal.ShellyHandlerFactory] - Shelly Manager started at http(s)://172.29.0.9:8,080/shelly/manager"
2022-06-29 07:47:14.475 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.binding.shelly_3.3.0 [254]] to http service
2022-06-29 07:47:14.498 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:14.501 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.binding.shelly_3.3.0 [254], contextID=default], with context-name: 
2022-06-29 07:47:14.507 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:14.529 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
2022-06-29 07:47:14.564 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0.tld
2022-06-29 07:47:14.578 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_1.tld
2022-06-29 07:47:14.590 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c.tld
2022-06-29 07:47:14.601 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0-rt.tld
2022-06-29 07:47:14.616 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt-1_0.tld
2022-06-29 07:47:14.661 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fmt.tld
2022-06-29 07:47:14.676 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/fn.tld
2022-06-29 07:47:14.682 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/permittedTaglibs.tld
2022-06-29 07:47:14.687 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/scriptfree.tld
2022-06-29 07:47:14.693 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0-rt.tld
2022-06-29 07:47:14.694 [INFO ] [e.automation.internal.RuleEngineImpl] - Rule engine started.
2022-06-29 07:47:14.704 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql-1_0.tld
2022-06-29 07:47:14.716 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/sql.tld
2022-06-29 07:47:14.746 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0-rt.tld
2022-06-29 07:47:14.760 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x-1_0.tld
2022-06-29 07:47:14.785 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:47:14.815 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.binding.shelly_3.3.0 [254], contextID=default]}
2022-06-29 07:47:14.825 [INFO ] [d.internal.element.ServletWebElement] - Ignoring servlet [485] without valid alias or url patterns property.
2022-06-29 07:47:14.918 [INFO ] [d.internal.element.ServletWebElement] - Ignoring servlet [488] without valid alias or url patterns property.
2022-06-29 07:47:15.380 [WARN ] [ty.util.ssl.SslContextFactory.config] - Trusting all certificates configured for Client@5872a216[provider=null,keyStore=null,trustStore=null]
2022-06-29 07:47:15.383 [WARN ] [ty.util.ssl.SslContextFactory.config] - No Client EndPointIdentificationAlgorithm configured for Client@5872a216[provider=null,keyStore=null,trustStore=null]
2022-06-29 07:47:16.378 [INFO ] [rt.modbus.internal.ModbusManagerImpl] - Modbus manager activated
2022-06-29 07:47:17.455 [INFO ] [um.core.network.RandomTokenGenerator] - using tokens of 8 bytes in length
2022-06-29 07:47:17.457 [INFO ] [alifornium.core.network.CoapEndpoint] - coap CoapEndpoint uses udp plain
2022-06-29 07:47:17.461 [INFO ] [um.core.network.stack.BlockwiseLayer] - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
2022-06-29 07:47:17.471 [INFO ] [.core.network.stack.ReliabilityLayer] - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
2022-06-29 07:47:17.474 [INFO ] [um.core.network.RandomTokenGenerator] - using tokens of 8 bytes in length
2022-06-29 07:47:17.480 [INFO ] [alifornium.core.network.CoapEndpoint] - coap CoapEndpoint uses udp plain
2022-06-29 07:47:17.487 [INFO ] [um.core.network.stack.BlockwiseLayer] - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
2022-06-29 07:47:17.503 [INFO ] [.core.network.stack.ReliabilityLayer] - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
2022-06-29 07:47:17.515 [INFO ] [alifornium.core.network.CoapEndpoint] - coap Endpoint [coap://0.0.0.0:5683] requires an executor to start, using default single-threaded daemon executor
2022-06-29 07:47:17.579 [INFO ] [se.californium.elements.UDPConnector] - UDPConnector starts up 1 sender threads and 1 receiver threads
2022-06-29 07:47:17.632 [INFO ] [se.californium.elements.UDPConnector] - UDPConnector listening on 0.0.0.0/0.0.0.0:5683, recv buf = 106496, send buf = 106496, recv packet size = 2048
2022-06-29 07:47:17.640 [INFO ] [alifornium.core.network.CoapEndpoint] - coap Started endpoint at coap://0.0.0.0:5683
2022-06-29 07:47:17.642 [INFO ] [.eclipse.californium.core.CoapClient] - started set client endpoint 0.0.0.0/0.0.0.0:5683
2022-06-29 07:47:20.800 [INFO ] [vice.internal.HttpServiceFactoryImpl] - Binding bundle: [org.openhab.ui.basic_3.3.0 [268]] to http service
2022-06-29 07:47:20.825 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:20.833 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.basic_3.3.0 [268], contextID=custom], with context-name: 
2022-06-29 07:47:20.842 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:20.877 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
...
2022-06-29 07:47:21.234 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/x.tld
2022-06-29 07:47:21.418 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.basic_3.3.0 [268], contextID=custom]}
2022-06-29 07:47:21.589 [INFO ] [rg.ops4j.pax.web.utils.ClassPathUtil] - Ignoring bundle scan for /META-INF/services javax.servlet.ServletContainerInitializer.
2022-06-29 07:47:21.601 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering context DefaultHttpContext [bundle=org.openhab.ui.basic_3.3.0 [268], contextID=custom], with context-name: 
2022-06-29 07:47:21.630 [INFO ] [ce.jetty.internal.HttpServiceContext] - registering JasperInitializer
2022-06-29 07:47:21.664 [INFO ] [org.ops4j.pax.web.jsp.TldScanner    ] - found TLD bundleresource://221.fwk10915321/META-INF/c-1_0-rt.tld
...
2022-06-29 07:47:22.140 [INFO ] [.jetty.server.handler.ContextHandler] - Started HttpServiceContext{httpContext=DefaultHttpContext [bundle=org.openhab.ui.basic_3.3.0 [268], contextID=custom]}
2022-06-29 07:47:22.151 [INFO ] [d.internal.element.ServletWebElement] - Ignoring servlet [531] without valid alias or url patterns property.
2022-06-29 07:47:26.149 [INFO ] [zwave.handler.ZWaveControllerHandler] - Attempting to add listener when controller is null
2022-06-29 07:47:27.008 [INFO ] [um.core.network.RandomTokenGenerator] - using tokens of 8 bytes in length
2022-06-29 07:47:27.011 [INFO ] [alifornium.core.network.CoapEndpoint] - coap CoapEndpoint uses udp plain
2022-06-29 07:47:27.014 [INFO ] [um.core.network.stack.BlockwiseLayer] - BlockwiseLayer uses MAX_MESSAGE_SIZE=1024, PREFERRED_BLOCK_SIZE=512, BLOCKWISE_STATUS_LIFETIME=300000, MAX_RESOURCE_BODY_SIZE=8192, BLOCKWISE_STRICT_BLOCK2_OPTION=false
2022-06-29 07:47:27.016 [INFO ] [.core.network.stack.ReliabilityLayer] - ReliabilityLayer uses ACK_TIMEOUT=2000, ACK_RANDOM_FACTOR=1.5, and ACK_TIMEOUT_SCALE=2.0 as default
2022-06-29 07:47:27.020 [INFO ] [alifornium.core.network.CoapEndpoint] - coap Endpoint [coap://0.0.0.0:0] requires an executor to start, using default single-threaded daemon executor
2022-06-29 07:47:27.024 [INFO ] [se.californium.elements.UDPConnector] - UDPConnector starts up 1 sender threads and 1 receiver threads
2022-06-29 07:47:27.033 [INFO ] [se.californium.elements.UDPConnector] - UDPConnector listening on 0.0.0.0/0.0.0.0:53385, recv buf = 106496, send buf = 106496, recv packet size = 2048
2022-06-29 07:47:27.043 [INFO ] [alifornium.core.network.CoapEndpoint] - coap Started endpoint at coap://0.0.0.0:53385
2022-06-29 07:47:27.046 [INFO ] [fornium.core.network.EndpointManager] - created implicit endpoint coap://0.0.0.0:53385 for coap
2022-06-29 07:47:31.388 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2022-06-29 07:47:31.392 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2022-06-29 07:47:34.444 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 10: Not initialized (ie node unknown), ignoring message.
2022-06-29 07:47:34.447 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 10: Not initialized (ie node unknown), ignoring message.
2022-06-29 07:47:34.451 [WARN ] [nal.protocol.ZWaveTransactionManager] - NODE 12: Not initialized (ie node unknown), ignoring message.
2022-06-29 07:47:43.906 [INFO ] [net/IP Tunneling 192.168.100.30:3671] - connection established (data endpoint 192.168.100.30:3671, channel 33, tunneling address 15.15.250)
2022-06-29 07:47:57.151 [INFO ] [org.openhab.rule.edbdc5b52f         ] - HABApp turned online



1 Like

If no Accept header is send, text/plain is assumed and you get the plain item state. But if the client explicitly requests a content-type and that can’t be fulfilled (as we don’t send html or xml), a bad request return code is correct.

Thanks for the great release. My installation has many “2022-06-29 08:31:35.532 [ERROR] [org.influxdb.impl.BatchProcessor ] - Batch could not be sent. Data will be lost” errors in the log. (database not found: “openhab”) I try to reinstall influxdb (openhabian on my Raspberry Pi) but it does not solve the problem. The “openhab” DB is not existing. This solve my problem:

Connect via: influx
Run: CREATE USER openhab WITH PASSWORD 'XXXXXX' WITH ALL PRIVILEGES

Connect via: influx -username openhab -password XXXXXX
Run: CREATE DATABASE openhab;

Perhaps others have the same problem.

Regards,
Tim

seems to be related to some things. If I delete all things related data the installation reaches startlevel 100. Any idea how to figure out what actually is the problem?

1 Like

I don’t thing ther’e was any change to GoogleTTS between M7 and final release.
Could you check that the problem is not in your (Python) rule engine ?
Just try the say command in the console to see if GoogleTTS is working or not.

It was not me.

In version openHABian 3.2. (it was a totally new installation) everything was fine, then I did the Upgrade to 3.3 and these 3 devices have been disabled, by … the Upgrade (?)

In the MainUI, i wasnt able to set the parameter correctly (only on/off = 0 and 1 i guess), was manually only possible in the Yaml section.

After the first manual correction … now the configuration sets correct the parameters (true/false) in the yaml section. Strange but it works :kissing_smiling_eyes:

Hmmm… perhaps I have the same issue, because there are some “Init” rules, that are not executed anymore, if the openhab is restarted. Where I could find information about log files of openhab/openhabian? /var/log/openhab/openhab.log do not show any information about startlevel?!

UPDATE: Perhaps I found the problem in this log. There are Netatmo-Things that are invalid (I could not delete them via GUI: State changed to REMOVING, but nothing happens. How can I drop this 3 Things) and there are some errors in Blockly rules (I will check this later).

If you click again on delete the thing can be forefully deleted

2 Likes

openhab> voice ttsservices                                                                                                                                                                          
* Google Cloud (googletts)

openhab> voice voices
  Google Cloud - Afrikaans (South Africa) - af-ZA-Standard-A (googletts:afZAStandardA)
  Google Cloud - Arabic (XA) - ar-XA-Standard-A (googletts:arXAStandardA)
   ..
  Google Cloud - Vietnamese (Vietnam) - vi-VN-Wavenet-D (googletts:viVNWavenetD)

openhab> voice say test
An unexpected error occurred during execution.

and in the log I get:


2022-06-29 11:06:06.404 [DEBUG] [.googletts.internal.GoogleTTSService] - Synthesize 'test ' for voice 'googletts:deDEWavenetC' in format AudioFormat [codec=PCM_SIGNED, container=WAVE, bigEndian=true, bitDepth=16, bitRate=705600, frequency=44100channels=1]
2022-06-29 11:06:06.411 [DEBUG] [lient.internal.OAuthStoreHandlerImpl] - Decrypting token: AccessTokenResponse [accessToken=LdEWmHAg7GjsYW8XBtoBIWPo7Y1oW3lX4tWVbxkZUw4yzxsrVPhAm2YJHEyB3vvO9mK3h6RJ26OCCfGz5lhZ6j4nmHIyiRkv/GNKdeK7yey85xsMRaPfK6Fd48a+5rQh17Iamybo1ZvC8Xlb5YAfCrmCN0Mx/Ziu1D7cMLKl8iKqvlXa5x3PL8TtQyrCILUWG/AebJ7WmWETjwDJ0Gt1+Zj73By8G4O6PEOHQ+hZfiMlA8l3CCayCNvABy0RqxQP, tokenType=Bearer, expiresIn=3461, refreshToken=null, scope=https://www.googleapis.com/auth/cloud-platform, state=null, createdOn=2022-06-28T17:53:33.196313]
2022-06-29 11:06:06.612 [ERROR] [b.core.io.console.ConsoleInterpreter] - An error occurred while executing the console command.
java.lang.NullPointerException: null
	at org.openhab.voice.googletts.internal.GoogleCloudAPI.synthesizeSpeechByGoogle(GoogleCloudAPI.java:456) ~[?:?]
	at org.openhab.voice.googletts.internal.GoogleCloudAPI.synthesizeSpeech(GoogleCloudAPI.java:356) ~[?:?]
	at org.openhab.voice.googletts.internal.GoogleTTSService.synthesize(GoogleTTSService.java:335) ~[?:?]
	at org.openhab.core.voice.internal.VoiceManagerImpl.say(VoiceManagerImpl.java:241) ~[?:?]
	at org.openhab.core.voice.internal.VoiceManagerImpl.say(VoiceManagerImpl.java:176) ~[?:?]
	at org.openhab.core.voice.internal.VoiceConsoleCommandExtension.say(VoiceConsoleCommandExtension.java:246) ~[?:?]
	at org.openhab.core.voice.internal.VoiceConsoleCommandExtension.execute(VoiceConsoleCommandExtension.java:112) ~[?:?]
	at org.openhab.core.io.console.ConsoleInterpreter.execute(ConsoleInterpreter.java:57) [bundleFile:?]
	at org.openhab.core.io.console.karaf.internal.CommandWrapper.execute(CommandWrapper.java:77) [bundleFile:?]
	at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:68) [bundleFile:4.3.7]
	at org.apache.karaf.shell.impl.console.osgi.secured.SecuredCommand.execute(SecuredCommand.java:86) [bundleFile:4.3.7]
	at org.apache.felix.gogo.runtime.Closure.executeCmd(Closure.java:599) [bundleFile:4.3.7]
	at org.apache.felix.gogo.runtime.Closure.executeStatement(Closure.java:526) [bundleFile:4.3.7]
	at org.apache.felix.gogo.runtime.Closure.execute(Closure.java:415) [bundleFile:4.3.7]
	at org.apache.felix.gogo.runtime.Pipe.doCall(Pipe.java:416) [bundleFile:4.3.7]
	at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:229) [bundleFile:4.3.7]
	at org.apache.felix.gogo.runtime.Pipe.call(Pipe.java:59) [bundleFile:4.3.7]
	at java.util.concurrent.FutureTask.run(FutureTask.java:264) [?:?]
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
	at java.lang.Thread.run(Thread.java:829) [?:?]

Both org.openhab.core.auth.oauth2client and org.openhab.voice.googlettsare set to TRACE

However, I get this now with M7, too

Update:

After seeing the failure on M7 this morning I did a restart, generated a new authCode, put that in and voice say test worked again from console.
So I re-installed 3.3.0-1, starting up googletts did not work, so generated a new authCode, put that in and voice say test worked again from console.
Thus, my impression that the released version comes with completly broken googletts was wrong.
Still, the outh2 authentication appears to be super fragile and the process to renew it with copying the authCode from the address line feels clumsy, to put it mildly.

I’m not 100% certain if the error which I now keep getting when opening the Apple Watch App upon launch ("Request explicitly cancelled") is related to my upgrade from 3.2 to 3.3, but if others have the same issue, feel free to contribute to the thread here.

Hello, just wanted to let everyone know that my Openhab 3.2.0 → 3.3.0 upgrade (I’m using Docker) was completed without any errors, hiccups or annoyances at all. This is the first time I had nothing to do (no rule rewrites or redefining things/items) so just wanted to put a big thank you out there for the great work the developers have put into this.

On 3.2.0, I had some issues with jupnp so I had to add some additional configuration on timeouts/retries to make my Sonos speakers work; I haven’t removed that but I will check if those are still needed on 3.3.0. and report separately.

2 Likes

Ok, I think I saw several topics in the forum about google stuff no more working due to changes in way to suthenticate.

The last change in this binding is dated 12th of April.

The NPE at this line is because synthesizeSpeechResponse.getAudioContent() is not tested, So at least this NPE could be avoided in favor of a more appropriate error.

Thanks for looking into it.

Yes, this was in M7 already. I figured how to get it with google but it’s clumsy (copy authCode from addressline of browser, edit the code 4%2F → 4/ ) and authentication seems fragile so I’m forced to repeat that quite often.
Frankly, that part doesn’t feel Ready.

I posted an update to my former post: in a nutshell I see now that M7 and 3.3.0-1 behave quite alike.

1 Like

Hi there,

updated my openhabian using “openhabian-config”. Installation was quite fresh, I did start over 2 month ago from a newly written microSD card, just restoring my files from /etc/openhab/*

I stopped openhabian services before requesting update, cleaned cache, then reboot. Now I can’t see my things in PaperUI and just see continously that message in log viewer:

2022-06-29 14:06:30.012 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:06:45.016 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:07:00.019 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:07:15.023 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:07:30.027 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:07:45.030 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:08:00.034 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:08:15.037 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

2022-06-29 14:08:30.041 [INFO ] [core.karaf.internal.FeatureInstaller] - Some .kar files are not installed yet. Delaying add-on installation by 15s.

Ok, strange, another graceful restart did solve that issue, stop openhab.service, clean cache, reboot …

Not sure of it’s relevant here, but I ran into an issue with reauthorizations after the first auth is a problem because the refresh token is returned only after the first authorization. The net effect is that it works until the access token needs to be refreshed (about an hour), then it breaks.

I pushed this change for the nest binding, but may be relevant for Google TTS, too. Note the addition of &prompt=consent to the URL.

Edit: I should note that this problem drove me absolutely crazy for days. I would do a reauth, then it would work for a while, then it would break. Rinse and repeat. Finally figured it out.

Thanks! Looks like it might be relevant indeed.
There is a line with the values of the decrypted token in the log and I had noticed it always showed refreshToken=null,
Using the &prompt=consent parameter in the uri when requesting the authCode results in a token which does have a value there.

Let’s see if this results in a more stable behavior.

Yep, a null refresh token in the log is a definite indicator of the problem.

If that’s it, we’ll need an update to the Readme to include the change to the authorization url.

And maybe a change to the code to complain if the refresh token is null.