openHAB 3.3 Release discussion

Lolodomo · June 29, 2022, 5:11am

This is this issue?

github.com/openhab/openhab-addons

[keba] Power channel stays UNDEF

opened 07:27PM - 26 Mar 22 UTC

closed 07:12PM - 21 Dec 22 UTC

lgusewski

bug

## Expected Behavior channel "power" should changed when car is loading ##… Current Behavior channel "power" stays as UNDEF, while others channels delivers values ## Steps to Reproduce (for Bugs) `Number:Power keba_p30_x_power "Von der Ladestation gelieferte Wirkleistung [%.1f Wh]" <energy> (gKEBA) ["Measurement", "Power"] {channel="keba:kecontact:1:power"} Number:Energy keba_p30_x_sessionconsumption "Energie während der aktuellen Sitzung [%.1f Wh]" <energy> (gKEBA) ["Measurement", "Energy"] {channel="keba:kecontact:1:sessionconsumption"}` The channel "power" stays as UNDEF while "sessionconsumption" changes, so the binding connects to the wallbox, but get not all values. ## Your Environment openHAB 3.2, Ubuntu Server 20.04 LTS. Zulu Java <img width="446" alt="sessionconsumption" src="https://user-images.githubusercontent.com/35467203/160254277-75274503-2ec5-4124-a93b-c6659135858d.png"> <img width="341" alt="power" src="https://user-images.githubusercontent.com/35467203/160254278-c838519f-12da-4755-8e96-ed333a31beac.png">

It is still opened.

Lolodomo · June 29, 2022, 5:17am

Mikel_2:

Hi, XXX is my bridge ID

UID: hue:0106:XXX:79
label: Hue ambient light sensor 1
thingTypeUID: hue:0106
configuration:
  tholddark: 3
  ledindication: 0
  tholdoffset: 100
  on: true
  sensorId: "79"
bridgeUID: hue:bridge:XXX

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.

Dominik_Bernhardt · June 29, 2022, 5:57am

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

J-N-K · June 29, 2022, 5:57am

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.

timl · June 29, 2022, 6:39am

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

Dominik_Bernhardt · June 29, 2022, 6:58am

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?

Lolodomo · June 29, 2022, 7:02am

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.

Mikel_2 · June 29, 2022, 7:22am

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

timl · June 29, 2022, 8:33am

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).

Dominik_Bernhardt · June 29, 2022, 9:15am

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

rubens · June 29, 2022, 9:26am


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.

Cplant · June 29, 2022, 11:13am

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.

Z0l · June 29, 2022, 11:18am

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.

Lolodomo · June 29, 2022, 11:44am

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.

github.com

openhab/openhab-addons/blob/main/bundles/org.openhab.voice.googletts/src/main/java/org/openhab/voice/googletts/internal/GoogleCloudAPI.java#L456


      
          /**
           * Copyright (c) 2010-2024 Contributors to the openHAB project
           *
           * See the NOTICE file(s) distributed with this work for additional
           * information.
           *
           * This program and the accompanying materials are made available under the
           * terms of the Eclipse Public License 2.0 which is available at
           * http://www.eclipse.org/legal/epl-2.0
           *
           * SPDX-License-Identifier: EPL-2.0
           */
          package org.openhab.voice.googletts.internal;
          
          import java.io.IOException;
          import java.nio.charset.StandardCharsets;
          import java.util.ArrayList;
          import java.util.Base64;
          import java.util.Dictionary;
          import java.util.HashMap;
          import java.util.HashSet;
          import java.util.List;
          import java.util.Locale;
          import java.util.Map;
          import java.util.Set;
          
          import org.eclipse.jdt.annotation.Nullable;
          import org.eclipse.jetty.http.HttpHeader;
          import org.eclipse.jetty.http.MimeTypes;
          import org.openhab.core.audio.AudioFormat;
          import org.openhab.core.auth.AuthenticationException;
          import org.openhab.core.auth.client.oauth2.AccessTokenResponse;
          import org.openhab.core.auth.client.oauth2.OAuthClientService;
          import org.openhab.core.auth.client.oauth2.OAuthException;
          import org.openhab.core.auth.client.oauth2.OAuthFactory;
          import org.openhab.core.auth.client.oauth2.OAuthResponseException;
          import org.openhab.core.i18n.CommunicationException;
          import org.openhab.core.io.net.http.HttpRequestBuilder;
          import org.openhab.voice.googletts.internal.dto.AudioConfig;
          import org.openhab.voice.googletts.internal.dto.AudioEncoding;
          import org.openhab.voice.googletts.internal.dto.ListVoicesResponse;
          import org.openhab.voice.googletts.internal.dto.SsmlVoiceGender;
          import org.openhab.voice.googletts.internal.dto.SynthesisInput;
          import org.openhab.voice.googletts.internal.dto.SynthesizeSpeechRequest;
          import org.openhab.voice.googletts.internal.dto.SynthesizeSpeechResponse;
          import org.openhab.voice.googletts.internal.dto.Voice;
          import org.openhab.voice.googletts.internal.dto.VoiceSelectionParams;
          import org.osgi.service.cm.Configuration;
          import org.osgi.service.cm.ConfigurationAdmin;
          import org.slf4j.Logger;
          import org.slf4j.LoggerFactory;
          
          import com.google.gson.Gson;
          import com.google.gson.GsonBuilder;
          import com.google.gson.JsonSyntaxException;
          
          /**
           * Google Cloud TTS API call implementation.
           *
           * @author Gabor Bicskei - Initial contribution and API
           */
          class GoogleCloudAPI {
          
              private static final String BEARER = "Bearer ";
          
              private static final String GCP_AUTH_URI = "https://accounts.google.com/o/oauth2/auth";
              private static final String GCP_TOKEN_URI = "https://accounts.google.com/o/oauth2/token";
              private static final String GCP_REDIRECT_URI = "https://www.google.com";
              /**
               * Google Cloud Platform authorization scope
               */
              private static final String GCP_SCOPE = "https://www.googleapis.com/auth/cloud-platform";
          
              /**
               * URL used for retrieving the list of available voices
               */
              private static final String LIST_VOICES_URL = "https://texttospeech.googleapis.com/v1/voices";
          
              /**
               * URL used for synthesizing text to speech
               */
              private static final String SYTNHESIZE_SPEECH_URL = "https://texttospeech.googleapis.com/v1/text:synthesize";
          
              /**
               * Logger
               */
              private final Logger logger = LoggerFactory.getLogger(GoogleCloudAPI.class);
          
              /**
               * Supported voices and locales
               */
              private final Map<Locale, Set<GoogleTTSVoice>> voices = new HashMap<>();
          
              /**
               * Configuration
               */
              private @Nullable GoogleTTSConfig config;
          
              private final Gson gson = new GsonBuilder().create();
              private final ConfigurationAdmin configAdmin;
              private final OAuthFactory oAuthFactory;
          
              private @Nullable OAuthClientService oAuthService;
          
              /**
               * Constructor.
               *
               */
              GoogleCloudAPI(ConfigurationAdmin configAdmin, OAuthFactory oAuthFactory) {
                  this.configAdmin = configAdmin;
                  this.oAuthFactory = oAuthFactory;
              }
          
              /**
               * Configuration update.
               *
               * @param config New configuration.
               */
              void setConfig(GoogleTTSConfig config) {
                  this.config = config;
          
                  if (oAuthService != null) {
                      oAuthFactory.ungetOAuthService(GoogleTTSService.SERVICE_PID);
                      oAuthService = null;
                  }
          
                  String clientId = config.clientId;
                  String clientSecret = config.clientSecret;
                  if (clientId != null && !clientId.isEmpty() && clientSecret != null && !clientSecret.isEmpty()) {
                      final OAuthClientService oAuthService = oAuthFactory.createOAuthClientService(GoogleTTSService.SERVICE_PID,
                              GCP_TOKEN_URI, GCP_AUTH_URI, clientId, clientSecret, GCP_SCOPE, false);
                      this.oAuthService = oAuthService;
                      try {
                          getAccessToken();
                          initVoices();
                      } catch (AuthenticationException | CommunicationException e) {
                          logger.warn("Error initializing Google Cloud TTS service: {}", e.getMessage());
                          oAuthFactory.ungetOAuthService(GoogleTTSService.SERVICE_PID);
                          this.oAuthService = null;
                          voices.clear();
                      }
                  } else {
                      voices.clear();
                  }
              }
          
              public void dispose() {
                  if (oAuthService != null) {
                      oAuthFactory.ungetOAuthService(GoogleTTSService.SERVICE_PID);
                      oAuthService = null;
                  }
                  voices.clear();
              }
          
              /**
               * Fetches the OAuth2 tokens from Google Cloud Platform if the auth-code is set in the configuration. If successful
               * the auth-code will be removed from the configuration.
               *
               * @throws AuthenticationException
               * @throws CommunicationException
               */
              @SuppressWarnings("null")
              private void getAccessToken() throws AuthenticationException, CommunicationException {
                  String authcode = config.authcode;
                  if (authcode != null && !authcode.isEmpty()) {
                      logger.debug("Trying to get access and refresh tokens.");
                      try {
                          AccessTokenResponse response = oAuthService.getAccessTokenResponseByAuthorizationCode(authcode,
                                  GCP_REDIRECT_URI);
                          if (response.getRefreshToken() == null || response.getRefreshToken().isEmpty()) {
                              throw new AuthenticationException("Error fetching refresh token. Please reauthorize");
                          }
                      } catch (OAuthException | OAuthResponseException e) {
                          logger.debug("Error fetching access token: {}", e.getMessage(), e);
                          throw new AuthenticationException(
                                  "Error fetching access token. Invalid authcode? Please generate a new one.");
                      } catch (IOException e) {
                          throw new CommunicationException(
                                  String.format("An unexpected IOException occurred: %s", e.getMessage()));
                      }
          
                      config.authcode = null;
          
                      try {
                          Configuration serviceConfig = configAdmin.getConfiguration(GoogleTTSService.SERVICE_PID);
                          Dictionary<String, Object> configProperties = serviceConfig.getProperties();
                          if (configProperties != null) {
                              configProperties.put(GoogleTTSService.PARAM_AUTHCODE, "");
                              serviceConfig.update(configProperties);
                          }
                      } catch (IOException e) {
                          // should not happen
                          logger.warn(
                                  "Failed to update configuration for Google Cloud TTS service. Please clear the 'authcode' configuration parameter manualy.");
                      }
                  }
              }
          
              @SuppressWarnings("null")
              private String getAuthorizationHeader() throws AuthenticationException, CommunicationException {
                  final AccessTokenResponse accessTokenResponse;
                  try {
                      accessTokenResponse = oAuthService.getAccessTokenResponse();
                  } catch (OAuthException | OAuthResponseException e) {
                      logger.debug("Error fetching access token: {}", e.getMessage(), e);
                      throw new AuthenticationException(
                              "Error fetching access token. Invalid authcode? Please generate a new one.");
                  } catch (IOException e) {
                      throw new CommunicationException(String.format("An unexpected IOException occurred: %s", e.getMessage()));
                  }
                  if (accessTokenResponse == null || accessTokenResponse.getAccessToken() == null
                          || accessTokenResponse.getAccessToken().isEmpty()) {
                      throw new AuthenticationException("No access token. Is this thing authorized?");
                  }
                  if (accessTokenResponse.getRefreshToken() == null || accessTokenResponse.getRefreshToken().isEmpty()) {
                      throw new AuthenticationException("No refresh token. Please reauthorize");
                  }
                  return BEARER + accessTokenResponse.getAccessToken();
              }
          
              /**
               * Loads supported audio formats
               *
               * @return Set of audio formats
               */
              Set<String> getSupportedAudioFormats() {
                  Set<String> formats = new HashSet<>();
                  for (AudioEncoding audioEncoding : AudioEncoding.values()) {
                      if (audioEncoding != AudioEncoding.AUDIO_ENCODING_UNSPECIFIED) {
                          formats.add(audioEncoding.toString());
                      }
                  }
                  return formats;
              }
          
              /**
               * Supported locales.
               *
               * @return Set of locales
               */
              Set<Locale> getSupportedLocales() {
                  return voices.keySet();
              }
          
              /**
               * Supported voices for locale.
               *
               * @param locale Locale
               * @return Set of voices
               */
              Set<GoogleTTSVoice> getVoicesForLocale(Locale locale) {
                  Set<GoogleTTSVoice> localeVoices = voices.get(locale);
                  return localeVoices != null ? localeVoices : Set.of();
              }
          
              /**
               * Google API call to load locales and voices.
               *
               * @throws AuthenticationException
               * @throws CommunicationException
               */
              private void initVoices() throws AuthenticationException, CommunicationException {
                  if (oAuthService != null) {
                      voices.clear();
                      for (GoogleTTSVoice voice : listVoices()) {
                          Locale locale = voice.getLocale();
                          Set<GoogleTTSVoice> localeVoices;
                          if (!voices.containsKey(locale)) {
                              localeVoices = new HashSet<>();
                              voices.put(locale, localeVoices);
                          } else {
                              localeVoices = voices.get(locale);
                          }
                          localeVoices.add(voice);
                      }
                  } else {
                      logger.error("Google client is not initialized!");
                  }
              }
          
              @SuppressWarnings("null")
              private List<GoogleTTSVoice> listVoices() throws AuthenticationException, CommunicationException {
                  HttpRequestBuilder builder = HttpRequestBuilder.getFrom(LIST_VOICES_URL)
                          .withHeader(HttpHeader.AUTHORIZATION.name(), getAuthorizationHeader());
          
                  try {
                      ListVoicesResponse listVoicesResponse = gson.fromJson(builder.getContentAsString(),
                              ListVoicesResponse.class);
          
                      if (listVoicesResponse == null || listVoicesResponse.getVoices() == null) {
                          return List.of();
                      }
          
                      List<GoogleTTSVoice> result = new ArrayList<>();
                      for (Voice voice : listVoicesResponse.getVoices()) {
                          for (String languageCode : voice.getLanguageCodes()) {
                              result.add(new GoogleTTSVoice(Locale.forLanguageTag(languageCode), voice.getName(),
                                      voice.getSsmlGender().name()));
                          }
                      }
                      return result;
                  } catch (JsonSyntaxException e) {
                      // do nothing
                  } catch (IOException e) {
                      throw new CommunicationException(String.format("An unexpected IOException occurred: %s", e.getMessage()));
                  }
                  return List.of();
              }
          
              /**
               * Converts audio format to Google parameters.
               *
               * @param codec Requested codec
               * @return String array of Google audio format and the file extension to use.
               */
              private String getFormatForCodec(String codec) {
                  switch (codec) {
                      case AudioFormat.CODEC_MP3:
                          return AudioEncoding.MP3.toString();
                      case AudioFormat.CODEC_PCM_SIGNED:
                          return AudioEncoding.LINEAR16.toString();
                      default:
                          throw new IllegalArgumentException("Audio format " + codec + " is not yet supported");
                  }
              }
          
              public byte[] synthesizeSpeech(String text, GoogleTTSVoice voice, String codec) {
                  String format = getFormatForCodec(codec);
                  try {
                      return synthesizeSpeechByGoogle(text, voice, format);
                  } catch (AuthenticationException e) {
                      logger.warn("Error authenticating Google Cloud TTS service: {}", e.getMessage());
                      if (oAuthService != null) {
                          oAuthFactory.ungetOAuthService(GoogleTTSService.SERVICE_PID);
                          oAuthService = null;
                      }
                  } catch (CommunicationException e) {
                      logger.warn("Error initializing Google Cloud TTS service: {}", e.getMessage());
                  }
                  voices.clear();
                  return null;
              }
          
              /**
               * Call Google service to synthesize the required text
               *
               * @param text Text to synthesize
               * @param voice Voice parameter
               * @param audioFormat Audio encoding format
               * @return Audio input stream or {@code null} when encoding exceptions occur
               * @throws AuthenticationException
               * @throws CommunicationException
               */
              @SuppressWarnings("null")
              private byte[] synthesizeSpeechByGoogle(String text, GoogleTTSVoice voice, String audioFormat)
                      throws AuthenticationException, CommunicationException {
                  AudioConfig audioConfig = new AudioConfig(AudioEncoding.valueOf(audioFormat), config.pitch, config.speakingRate,
                          config.volumeGainDb);
                  SynthesisInput synthesisInput = new SynthesisInput(text);
                  VoiceSelectionParams voiceSelectionParams = new VoiceSelectionParams(voice.getLocale().getLanguage(),
                          voice.getLabel(), SsmlVoiceGender.valueOf(voice.getSsmlGender()));
          
                  SynthesizeSpeechRequest request = new SynthesizeSpeechRequest(audioConfig, synthesisInput,
                          voiceSelectionParams);
          
                  HttpRequestBuilder builder = HttpRequestBuilder.postTo(SYTNHESIZE_SPEECH_URL)
                          .withHeader(HttpHeader.AUTHORIZATION.name(), getAuthorizationHeader())
                          .withContent(gson.toJson(request), MimeTypes.Type.APPLICATION_JSON.name());
          
                  try {
                      SynthesizeSpeechResponse synthesizeSpeechResponse = gson.fromJson(builder.getContentAsString(),
                              SynthesizeSpeechResponse.class);
          
                      if (synthesizeSpeechResponse == null) {
                          return null;
                      }
          
                      byte[] encodedBytes = synthesizeSpeechResponse.getAudioContent().getBytes(StandardCharsets.UTF_8);
                      return Base64.getDecoder().decode(encodedBytes);
                  } catch (JsonSyntaxException e) {
                      // do nothing
                  } catch (IOException e) {
                      throw new CommunicationException(String.format("An unexpected IOException occurred: %s", e.getMessage()));
                  }
                  return null;
              }
          
              boolean isInitialized() {
                  return oAuthService != null;
              }
          }

This file has been truncated. show original

rubens · June 29, 2022, 12:15pm

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.

fnu · June 29, 2022, 12:16pm

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.

fnu · June 29, 2022, 12:30pm

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

mhilbush · June 29, 2022, 12:49pm

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.

github.com/openhab/openhab-addons

[nest] Fix for missing refresh token after reauthorization

openhab:main ← mhilbush:nest-refresh-token

opened 02:30PM - 10 May 22 UTC

mhilbush

+15 -5

By default, the Google OAuth API returns the refresh token only on the first aut…horization. On subsequent authorizations using the same Client ID and Secret, Google does not return the refresh token in the access token response. This causes the binding to fail on the first refresh of the access token after a reauthorization. This affects the SDM and Pub/Sub APIs. However, the failure is more spectacular with the Pub/Sub API as it causes the binding to repeatedly do a pub/sub request against the Google API every 20-40 msec. This PR adds a new query parameter (prompt=consent) to the URL used to get the authorization code. This parameter causes Google to always return the refresh token in the authorization response (via `oAuthService.getAccessTokenResponseByAuthorizationCode`). In addition, this PR adds checks to make sure the refresh token in present in the access token response in order to fail more quickly and gracefully if the refresh token is missing. Further details of my analysis are here. https://community.openhab.org/t/nest-binding-throwing-pub-sub-errors-repeatedly/135721 I know @wborn is pretty time-constrained right now, but I'm hopeful he can find a few minutes to review. 😉 Signed-off-by: Mark Hilbush <mark@hilbush.com>

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.

rubens · June 29, 2022, 1:25pm

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.

mhilbush · June 29, 2022, 1:36pm

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.