[OH 2.4.0 M6] Testing Results

openhab2
testing
milestone
Tags: #<Tag:0x00007f0146031738> #<Tag:0x00007f01460315a8> #<Tag:0x00007f0146031440>

(Angelos) #1

Summary here:

Time to upgrade people! Let’s make OH2.4 the most stable Release ever :slight_smile:


Old stuff below

Let’s use this thread to report testing results for the latest openHAB 2.4.0 Milestone Build 6

Announcement Post: openHAB 2.4 Milestone builds

FAQs

This is based on my understanding of how it works:

What is this "Milestone" stuff?

As of the time of this post, openHAB2 has 3 main branches under which the distribution is made available to all:

1) The Stable Release = 2.3.0. Published on 28/May/2018. Cycle: ~6M
2) The Milestone Build = 2.4.0 M6. Published on 20/Nov/2018. Cycle: ~1M
3) The Snapshot Build = 2.4.0 S1434. Published on 21/Nov/2018. Cycle: ~1d

The Milestone build is a testing (semi-stable) build of the OH2 distribution and includes all new enhancements, features and bug fixes.

The Snapshot build is a bleeding-edge (considered unstable) build of the OH2 distribution and includes all the latest enhancements, features and bug fixes.

Get 2.3.0 Stable from here: Main Web Site (or the stable repo)
Get 2.4.0 Milestone 6 from here: JFrog.io (or the testing repo)
Get 2.4.0 Snapshot from here: Jenkins (or the unstable repo)

I want to test 2.4.0.M6, how I can switch to it?

Linux Apt Based: Change to the Testing (aka Beta) Repository on your systems apt sources list

apt-get update && sudo apt-get install openhab2=2.4.0~M6-1

Win/Mac: Download the zip file from JFrog.io

Docker: Read docs @ openhab-docker

How do I report issues that I have identified with Milestone build?

Use the community forum to start with. Maybe your issue is due to a miss-configuration and not due to a bug.

If the results of the troubleshooting in the forum point to a bug, you can open up a github issue to be tracked and reviewed by the developers.

When you post problems (either in the forum or in github) add as much info as you can (relevant to the problem) in order to help with identification and possible reproduction of the issue.

Is 2.4.0 M6 going to become 2.4.0 Stable if all is OK with it? The development team is planning to make available more Milestones (M7/M8) before the final Release of 2.4.0 Stable.
Can I run 2.4.0.M6 with Java VM 11? No! The recommended JVM is: Zulu 8. See more here: Prerequisites

openHAB 2.4 Milestone builds
VScode and OH2.4 M6
Homematic CCU3 connection issues - COMMUNICATION_ERROR Unknown XML-RPC tag: title
No Update of netatmo items
Homematic CCU3 connection issues - COMMUNICATION_ERROR Unknown XML-RPC tag: title
[ZigBee] Thing Channels disappeared?
Help with a few item warnings OH 2.3
openHAB 2.4 Milestone builds
New Jeelink Openhab2 Binding
Problem with Anel HUT in latest snapshot (openHAB 2.4.0 Build #1399)
[JVM11] Trouble with initial install
[Solved] [Google TTS] Chromecast Audio Sink not working
(Angelos) #2

First test result:

  • Platform information:

    • Hardware: Laptop i5-7200U@2.5GHz / 8Gigs RAM / 256Gigs SSD
    • OS: Windows 10 Ent x64
    • Java Runtime Environment: Oracle 1.8.0_192
    • openHAB version: OH 2.4.0 M6
  • Please post configurations (if applicable):

    • Items configuration: TBD
    • Sitemap configuration: TBD
    • Rules code: TBD
    • Services configuration: just selected Expert at the initial startup
  • Logs: TBD

Good news ! I cannot reproduce https://github.com/openhab/openhab-distro/issues/729 using openhab-addons-2.4.0-SNAPSHOT.kar from OH 2.4.0 Snapshot Build # 1433. I will try to dig deeper to see how this was fixed.


Second test result:

Next system working fine so far: the production one :slight_smile:

23 secs to a full OH2 startup… that’s fast !

  • Platform information:
    • Hardware: Laptop with Intel CPU i5-6200U, 8GB RAM, 1TB HDD
    • OS: Linux Debian Jessie x64
    • Java Runtime Environment: Oracle JVM x64 build 1.8.0_191-b12
    • openHAB version: OH 2.4.0 M6
  • Please post configurations (if applicable):
    • Items configuration: TBD
    • Sitemap configuration: TBD
    • Rules code: TBD
    • Services configuration:
binding = knx,mqtt1,zwave,weather1,samsungtv,astro,ntp,wol1,networkupstools1
ui = basic,paper,habpanel,habmin
persistence = mapdb,influxdb
action = mail,pushover
transformation = map,regex,jsonpath,javascript
voice = googletts
misc = restdocs,openhabcloud
  • Logs:
    openhab.log
2018-11-20 16:09:31.809 [INFO ] [.googletts.internal.GoogleTTSService] - Using home folder: /var/lib/openhab2/googletts
2018-11-20 16:09:31.814 [INFO ] [.googletts.internal.GoogleTTSService] - Using cache folder /var/lib/openhab2/cache/org.openhab.voice.googletts
2018-11-20 16:09:32.118 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2018-11-20 16:09:33.511 [WARN ] [.googletts.internal.GoogleTTSService] - Audio format OGG_OPUS is not yet supported.
2018-11-20 16:09:33.819 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Time zone set to 'Europe/Athens'.
2018-11-20 16:09:33.822 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Location set to 'xx.xxx,yy.yyy'.
2018-11-20 16:09:33.823 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Locale set to 'en_GR'.
2018-11-20 16:09:33.824 [INFO ] [.core.internal.i18n.I18nProviderImpl] - Measurement system set to 'SIUnits'.
2018-11-20 16:09:34.118 [INFO ] [.googletts.internal.GoogleTTSService] - Using home folder: /var/lib/openhab2/googletts
2018-11-20 16:09:34.119 [INFO ] [.googletts.internal.GoogleTTSService] - Using cache folder /var/lib/openhab2/cache/org.openhab.voice.googletts
2018-11-20 16:09:34.353 [WARN ] [.googletts.internal.GoogleTTSService] - Audio format OGG_OPUS is not yet supported.
2018-11-20 16:09:35.225 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = xxx, base URL = http://localhost:8081)
2018-11-20 16:09:37.322 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'KNX.items'
2018-11-20 16:09:37.433 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Simulation.items'
2018-11-20 16:09:37.445 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Unifi.items'
2018-11-20 16:09:37.467 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Paradox.items'
2018-11-20 16:09:37.481 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Astro.items'
2018-11-20 16:09:37.502 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Energy.items'
2018-11-20 16:09:37.531 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'UPS.items'
2018-11-20 16:09:37.542 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'voice.items'
2018-11-20 16:09:37.549 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ESP.items'
2018-11-20 16:09:37.562 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ZWave.items'
2018-11-20 16:09:37.583 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'WoL.items'
2018-11-20 16:09:37.593 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Weather.items'
2018-11-20 16:09:37.616 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Groups.items'
2018-11-20 16:09:37.667 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mPower.items'
2018-11-20 16:09:37.698 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.items'
2018-11-20 16:09:37.704 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'SamsungTV.items'
2018-11-20 16:09:37.907 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'mapdb.persist'
2018-11-20 16:09:37.916 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'influxdb.persist'
2018-11-20 16:09:39.521 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Sun.rules'
2018-11-20 16:09:39.620 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Master_Lights.rules'
2018-11-20 16:09:39.695 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'UPS.rules'
2018-11-20 16:09:41.326 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Fib_Eyes.rules'
2018-11-20 16:09:41.367 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'voice_demo.rules'
2018-11-20 16:09:41.390 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Email.rules'
2018-11-20 16:09:41.507 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Fib_Buttons.rules'
2018-11-20 16:09:41.558 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Paradox.rules'
2018-11-20 16:09:41.584 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Simona_Home.rules'
2018-11-20 16:09:48.368 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Unifi.rules'
2018-11-20 16:09:48.586 [INFO ] [thome.model.lsp.internal.ModelServer] - Started Language Server Protocol (LSP) service on port 5007
2018-11-20 16:09:48.734 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Ana.sitemap'
2018-11-20 16:09:48.755 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'HomeR.sitemap'
2018-11-20 16:09:48.867 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Astro.things'
2018-11-20 16:09:49.043 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'KNX.things'
2018-11-20 16:09:49.061 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'ntp.things'
2018-11-20 16:09:49.065 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'SamsungTV.things'
2018-11-20 16:09:49.070 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'Unifi.things'
2018-11-20 16:09:49.298 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:sun:local
2018-11-20 16:09:49.324 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled Positional job astro:sun:local every 60 seconds
2018-11-20 16:09:49.361 [INFO ] [thome.binding.astro.internal.job.Job] - Scheduled Astro event-jobs for thing astro:moon:local
2018-11-20 16:09:49.371 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled Positional job astro:moon:local every 60 seconds
2018-11-20 16:09:50.448 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Connecting to serial port '/dev/ttyACM0'
2018-11-20 16:09:50.576 [INFO ] [ing.zwave.handler.ZWaveSerialHandler] - Serial port is initialized
2018-11-20 16:09:50.598 [INFO ] [ve.internal.protocol.ZWaveController] - Starting ZWave controller
2018-11-20 16:09:50.598 [INFO ] [ve.internal.protocol.ZWaveController] - ZWave timeout is set to 5000ms. Soft reset is false.
2018-11-20 16:09:50.769 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at http://172.16.13.100:8081
2018-11-20 16:09:50.770 [INFO ] [.dashboard.internal.DashboardService] - Started Dashboard at https://172.16.13.100:8444
2018-11-20 16:09:51.258 [INFO ] [arthome.ui.paper.internal.PaperUIApp] - Started Paper UI at /paperui
2018-11-20 16:09:51.931 [INFO ] [eather.internal.common.WeatherConfig] - ProviderConfig[providerName=WUNDERGROUND,apiKey=xxx]
2018-11-20 16:09:51.946 [INFO ] [eather.internal.common.WeatherConfig] - LocationConfig[providerName=WUNDERGROUND,language=en,updateInterval=10,latitude=xx,longitude=yy,woeid=<null>,locationId=HomeR,name=HomeR]
2018-11-20 16:09:51.973 [INFO ] [b.core.service.AbstractActiveService] - NetworkUpsTools Refresh Service has been started
2018-11-20 16:09:52.098 [INFO ] [penhab.io.transport.mqtt.MqttService] - MQTT Service initialization completed.
2018-11-20 16:09:52.099 [INFO ] [t.mqtt.internal.MqttBrokerConnection] - Starting MQTT broker connection 'HomeR'
2018-11-20 16:09:52.743 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2018-11-20 16:09:54.962 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Starting and scheduling weatherJob-HomeR with interval of 10 minutes

(Kristof Rado) #3

I’m using OpenWeatherMap binding. After updating to M6 I can’t get it to work.
I have installed it from the IoT market, but as soon as it gets installed it first goes to initializing and after to OFFLINE.
What is the package name for these IoT bindings? I couldn’t get it change the logging level…


(Angelos) #4

you mean the Thing here… correct?

Did you go over the documentation for the Binding? https://github.com/eclipse/smarthome/blob/master/extensions/binding/org.eclipse.smarthome.binding.openweathermap/README.md


(Angelos) #5

Remove the old installation from the IoT Market

The OpenWeatherMap Binding is now part of the OH 2.4.0 M6 distribution. Install this one.


(Kristof Rado) #6

Thanks :slight_smile:
Yes, that’s what I have installed. However the binding slightly changed, that’s why it didn’t work. (Now there is no seperate thing for Current and Forecast… I didn’t knew that change.)


(Angelos) #7

updated first post to include some “FAQs” :stuck_out_tongue:


(Ben Clark) #8

I like that notation! Since there is regular confusion on which apt/yum version (which uses a timestamp) relates to which build number (which uses an incremental counter), I’d like to start naming the snapshot versions like this. Not sure how it would be done just yet though.

2.4.0~S1434-1 would be the first linuxpkg build from CI build #1434. If there ever needed a second build of the same snapshot (i.e. for a apt/yum specific bugfix), then it would be released as 2.4.0~S1434-2.


(Paul Hansen) #9

Upgraded from 2.3 stable this time yesterday and so far so good.

That being said I did do the usual cache clearing before starting 2.4M6 but it still took two reboots before the logs were clear of messages about transformations not being installed.


(Angelos) #10

I experience the same with all upgrades. I believe that it has something to do with the clearing of cache+tmp (a step in the upgrade script). I am not sure if I reliably reproduce this for every restart following a cache+tmp clear.

I haven’t tested the system to see if it is stable even with these warnings about transformations not being loaded since I just perform a second restart of the OH2 service immediately and the warn goes away. I usually let the service down for 10 seconds to let it “cool down” before I start it up again for the second time :stuck_out_tongue: (otherwise I get these strange HK2 errors)

I think that there is an issue tracking this (xformations not loading after clearing cache+tmp) somewhere.


(Angelos) #11

@Kai By popular demand :smile: , please include the build # on the footer of the dashboard for the next (M7):


(Juelicher) #12

I tried to update from Milestone 5, but even after restarting openHAB several time I still get some exceptions during startup I don_t know the reason of:

2018-11-22 20:28:03.137 [ERROR] [org.apache.felix.scr                ] - bundle org.apache.felix.scr:2.1.2 (39)Circular reference detected trying to get service {org.eclipse.smarthome.automation.module.script.ScriptExtensionProvider}={service.id=342, service.bundleid=217, service.scope=bundle, component.name=org.eclipse.smarthome.automation.module.media.internal.MediaScriptScopeProvider, component.id=200}
 stack of references: ServiceReference: {org.eclipse.smarthome.automation.module.script.ScriptExtensionProvider}={service.id=342, service.bundleid=217, service.scope=bundle, component.name=org.eclipse.smarthome.automation.module.media.internal.MediaScriptScopeProvider, component.id=200}
    Dependency: DependencyManager: Component [Component: org.eclipse.smarthome.automation.module.script.internal.ScriptExtensionManager (202)] reference [ScriptExtensionProvider]
ServiceReference: {org.eclipse.smarthome.automation.module.script.ScriptEngineManager}={service.id=344, service.bundleid=218, service.scope=bundle, component.name=org.eclipse.smarthome.automation.module.script.internal.ScriptEngineManagerImpl, component.id=201}
ServiceReference: {org.eclipse.smarthome.automation.module.script.internal.ScriptExtensionManager}={service.id=343, service.bundleid=218, service.scope=bundle, component.name=org.eclipse.smarthome.automation.module.script.internal.ScriptExtensionManager, component.id=202}

java.lang.Exception: stack trace
	at org.apache.felix.scr.impl.ComponentRegistry.enterCreate(ComponentRegistry.java:481) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.BundleComponentActivator.enterCreate(BundleComponentActivator.java:735) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:845) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:419) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.prebind(DependencyManager.java:1162) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1053) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1007) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [39:org.apache.felix.scr:2.1.2]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) [?:?]
	at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:468) [?:?]
	at org.eclipse.osgi.internal.hooks.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:103) [?:?]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:529) [?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:328) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:368) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:446) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) [?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) [?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) [?:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:564) [?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.initDependencyManagers(AbstractComponentManager.java:984) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1011) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) [39:org.apache.felix.scr:2.1.2]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) [?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) [?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) [20:com.eclipsesource.jaxrs.publisher:5.3.1.201602281253]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) [?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) [?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) [?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) [?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) [?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) [39:org.apache.felix.scr:2.1.2]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) [39:org.apache.felix.scr:2.1.2]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) [?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) [?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) [?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) [?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) [?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) [?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) [?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) [?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]

and

2018-11-22 20:28:03.161 [WARN ] [se.smarthome.automation.module.media] - FrameworkEvent WARNING - org.eclipse.smarthome.automation.module.media
org.osgi.framework.ServiceException: org.apache.felix.scr.impl.manager.SingleComponentManager.getService() returned a null service object
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:232) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) ~[?:?]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$MultipleDynamicCustomizer.prebind(DependencyManager.java:419) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleRefPair.getServiceObject(SingleRefPair.java:73) ~[?:?]
	at org.apache.felix.scr.impl.inject.BindParameters.getServiceObject(BindParameters.java:47) ~[?:?]
	at org.apache.felix.scr.impl.inject.methods.BindMethod.getServiceObject(BindMethod.java:662) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.getServiceObject(DependencyManager.java:2304) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.prebind(DependencyManager.java:1162) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager.prebind(DependencyManager.java:1576) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1014) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1053) ~[?:?]
	at org.apache.felix.scr.impl.manager.DependencyManager$SingleStaticCustomizer.addedService(DependencyManager.java:1007) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1216) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.customizerAdded(ServiceTracker.java:1137) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.trackAdding(ServiceTracker.java:944) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$AbstractTracked.track(ServiceTracker.java:880) ~[?:?]
	at org.apache.felix.scr.impl.manager.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:1168) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator$ListenerInfo.serviceChanged(BundleComponentActivator.java:125) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
	at org.eclipse.osgi.framework.util.SecureAction.start(SecureAction.java:468) ~[?:?]
	at org.eclipse.osgi.internal.hooks.EclipseLazyStarter.postFindLocalClass(EclipseLazyStarter.java:103) ~[?:?]
	at org.eclipse.osgi.internal.loader.classpath.ClasspathManager.findLocalClass(ClasspathManager.java:529) ~[?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.findLocalClass(ModuleClassLoader.java:328) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findLocalClass(BundleLoader.java:368) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClassInternal(BundleLoader.java:446) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:395) ~[?:?]
	at org.eclipse.osgi.internal.loader.BundleLoader.findClass(BundleLoader.java:387) ~[?:?]
	at org.eclipse.osgi.internal.loader.ModuleClassLoader.loadClass(ModuleClassLoader.java:150) ~[?:?]
	at java.lang.ClassLoader.loadClass(ClassLoader.java:357) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxBundle.loadClass(EquinoxBundle.java:564) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.initDependencyManagers(AbstractComponentManager.java:984) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.collectDependencies(AbstractComponentManager.java:1011) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getServiceInternal(SingleComponentManager.java:899) ~[?:?]
	at org.apache.felix.scr.impl.manager.SingleComponentManager.getService(SingleComponentManager.java:863) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse$1.run(ServiceFactoryUse.java:212) ~[?:?]
	at java.security.AccessController.doPrivileged(Native Method) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.factoryGetService(ServiceFactoryUse.java:210) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceFactoryUse.getService(ServiceFactoryUse.java:111) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceConsumer$2.getService(ServiceConsumer.java:45) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.getService(ServiceRegistrationImpl.java:508) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.getService(ServiceRegistry.java:461) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.getService(BundleContextImpl.java:624) ~[?:?]
	at com.eclipsesource.jaxrs.publisher.internal.ResourceTracker.addingService(ResourceTracker.java:39) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:941) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.customizerAdding(ServiceTracker.java:870) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.trackAdding(AbstractTracked.java:256) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:229) ~[?:?]
	at org.osgi.util.tracker.ServiceTracker$Tracked.serviceChanged(ServiceTracker.java:901) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.FilteredServiceListener.serviceChanged(FilteredServiceListener.java:109) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:920) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEventPrivileged(ServiceRegistry.java:862) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.publishServiceEvent(ServiceRegistry.java:801) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistrationImpl.register(ServiceRegistrationImpl.java:127) ~[?:?]
	at org.eclipse.osgi.internal.serviceregistry.ServiceRegistry.registerService(ServiceRegistry.java:225) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.registerService(BundleContextImpl.java:469) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:891) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager$3.register(AbstractComponentManager.java:877) ~[?:?]
	at org.apache.felix.scr.impl.manager.RegistrationManager.changeRegistration(RegistrationManager.java:128) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.registerService(AbstractComponentManager.java:944) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.activateInternal(AbstractComponentManager.java:727) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enableInternal(AbstractComponentManager.java:661) ~[?:?]
	at org.apache.felix.scr.impl.manager.AbstractComponentManager.enable(AbstractComponentManager.java:427) ~[?:?]
	at org.apache.felix.scr.impl.manager.ConfigurableComponentHolder.enableComponents(ConfigurableComponentHolder.java:665) ~[?:?]
	at org.apache.felix.scr.impl.BundleComponentActivator.initialEnable(BundleComponentActivator.java:339) ~[?:?]
	at org.apache.felix.scr.impl.Activator.loadComponents(Activator.java:381) ~[?:?]
	at org.apache.felix.scr.impl.Activator.access$200(Activator.java:49) ~[?:?]
	at org.apache.felix.scr.impl.Activator$ScrExtension.start(Activator.java:263) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.createExtension(AbstractExtender.java:196) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:169) ~[?:?]
	at org.apache.felix.scr.impl.AbstractExtender.modifiedBundle(AbstractExtender.java:49) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:482) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.customizerModified(BundleTracker.java:415) ~[?:?]
	at org.osgi.util.tracker.AbstractTracked.track(AbstractTracked.java:232) ~[?:?]
	at org.osgi.util.tracker.BundleTracker$Tracked.bundleChanged(BundleTracker.java:444) ~[?:?]
	at org.eclipse.osgi.internal.framework.BundleContextImpl.dispatchEvent(BundleContextImpl.java:908) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.ListenerQueue.dispatchEventSynchronous(ListenerQueue.java:148) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEventPrivileged(EquinoxEventPublisher.java:213) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:120) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxEventPublisher.publishBundleEvent(EquinoxEventPublisher.java:112) ~[?:?]
	at org.eclipse.osgi.internal.framework.EquinoxContainerAdaptor.publishModuleEvent(EquinoxContainerAdaptor.java:168) ~[?:?]
	at org.eclipse.osgi.container.Module.publishEvent(Module.java:476) ~[?:?]
	at org.eclipse.osgi.container.Module.start(Module.java:467) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1634) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.incStartLevel(ModuleContainer.java:1614) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.doContainerStartLevel(ModuleContainer.java:1585) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1528) ~[?:?]
	at org.eclipse.osgi.container.ModuleContainer$ContainerStartLevel.dispatchEvent(ModuleContainer.java:1) ~[?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager.dispatchEvent(EventManager.java:230) [?:?]
	at org.eclipse.osgi.framework.eventmgr.EventManager$EventThread.run(EventManager.java:340) [?:?]

(Angelos) #13

Can you try to Clear tmp & cache and see if the situation improves?


(Juelicher) #14

I already did this after installing the Milestone 6, before starting ist for the first time. But I could try a clean install on the weekend.


(Matthias) #15

Hi Dim,

there seems to be some kind of issue (just a warning though) with my item definition. I have 2 or 3 channels linked to a single item. Is this use case deprecated?

  • Platform information:
    • openHAB version: OH 2.4.0 M6 running in docker
  • Please post configurations (if applicable):
    • Items configuration:
Dimmer aLivingCeilingBulb "Deckenlampe" <wallswitch> (gLivingCeilingBulb) { channel="hue:0220:00178840cd07:5:brightness", channel="hue:0220:00178840cd07:6:brightness", channel="hue:0220:00178840cd07:7:brightness" }
Dimmer aLivingFloorLeftBulbs "Stehlampe Links" <wallswitch> (gLivingFloorLeftBulbs) { channel="hue:0220:00178840cd07:12:brightness", channel="hue:0220:00178840cd07:13:brightness" }
Dimmer aLivingFloorRightBulbs "Stehlampe Rechts" <wallswitch> (gLivingFloorRightBulbs) { channel="hue:0220:00178840cd07:14:brightness", channel="hue:0220:00178840cd07:15:brightness" }
  • Logs:
2018-11-22 19:51:01.838 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "Metadata" with key "channel:aLivingCeilingBulb". It exists already from provider "GenericMetadataProvider"! Failed to add a second with the same UID from provider "GenericMetadataProvider"!
2018-11-22 19:51:01.839 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "Metadata" with key "channel:aLivingCeilingBulb". It exists already from provider "GenericMetadataProvider"! Failed to add a second with the same UID from provider "GenericMetadataProvider"!
2018-11-22 19:51:01.844 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "Metadata" with key "channel:aLivingFloorRightBulbs". It exists already from provider "GenericMetadataProvider"! Failed to add a second with the same UID from provider "GenericMetadataProvider"!
2018-11-22 19:51:01.845 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "Metadata" with key "channel:aLivingFloorRightBulbs_switch". It exists already from provider "GenericMetadataProvider"! Failed to add a second with the same UID from provider "GenericMetadataProvider"!
2018-11-22 19:51:01.846 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "Metadata" with key "channel:aLivingFloorLeftBulbs". It exists already from provider "GenericMetadataProvider"! Failed to add a second with the same UID from provider "GenericMetadataProvider"!
2018-11-22 19:51:01.847 [WARN ] [ore.common.registry.AbstractRegistry] - Cannot add "Metadata" with key "channel:aLivingFloorLeftBulbs_switch". It exists already from provider "GenericMetadataProvider"! Failed to add a second with the same UID from provider "GenericMetadataProvider"!

[OH2.4.0.M#] Milestone Testing Summary
(Frederic Chaballe) #16

Hello Dears,

I’m running 2.4 SNAPSHOT Build 1436 (just upgraded from 2.3.0 from Synology DSM) that is very slow (was already slow in 2.3 since I started 1 month ago). No upgrade issue faced but I now started investigating why it is so slow and wanted to share 2 first strange behaviours I observed.

Here is my configuration:
openhab> info
Karaf
Karaf version 4.2.1
OSGi Framework org.eclipse.osgi-3.12.100.v20180210-1608

JVM
Java Virtual Machine Java HotSpot™ 64-Bit Server VM version 25.191-b12
Version 1.8.0_191
Vendor Oracle Corporation
Uptime 1 hour 6 minutes
Process CPU time 25 minutes
Process CPU load 0.06
System CPU load 0.11
Open file descriptors 259
Max file descriptors 4,096
Total compile time 47 minutes
Threads
Live threads 232
Daemon threads 101
Peak 251
Total started 4381
Memory
Current heap size 125,028 kbytes
Maximum heap size 160,384 kbytes
Committed heap size 160,384 kbytes
Pending objects 0
Garbage collector Name = ‘Copy’, Collections = 394, Time = 1 minute
Garbage collector Name = ‘MarkSweepCompact’, Collections = 34, Time = 24 minutes
Classes
Current classes loaded 20,931
Total classes loaded 22,800
Total classes unloaded 1,869
Operating system
Name Linux version 4.4.59+
Architecture aarch64
Processors 4

Quite rapidly after startup (and even after a while), it is hanging and facing timeouts left and right like:

  • [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException: Total timeout 5000 ms elapsed
  • for HTTP Clients typically foriCloud and CalDav bindings:
    [DEBUG] [rg.eclipse.jetty.client.HttpExchange] - Failed HttpExchange@5385495f req=COMPLETED/java.util.concurrent.TimeoutException: Total timeout 10000 ms
  • for myOpenhab Cloud reconnections:
    [WARN ] [l.handler.ICloudAccountBridgeHandler] - Unable to refresh device data
    java.io.IOException: java.util.concurrent.TimeoutException: Total timeout 10000 ms elapsed
    ,
    [INFO ] [io.openhabcloud.internal.CloudClient] - Disconnected from the openHAB Cloud service (UUID = 93001014-b2ca-43d5-b3e0-c2abdee9cfac, base URL = http://localhost:8080)
  • for pools (MariaDB with JDBC?):
    [WARN ] [com.zaxxer.hikari.pool.HikariPool ] - 2m15s967ms724μs102ns - Thread starvation or clock leap detected (housekeeper delta=yank-default).
  • for events ti the LOGGER: [WARN ] [me.core.internal.events.EventHandler] - Dispatching event to subscriber ‘org.eclipse.smarthome.io.monitor.internal.EventLogger@6668705f’ takes more than 5000ms.

But I don’t really know the origin of these problems. If someone has some insights on where to start the investigation, he is welcome. The only 2 strange behaviours I could really identify are as follow:
1/ OH tries endlessly to fetch maven-metadata.xml which does not exist (rather the maven-metadata**-local**.xml @ https://openhab.jfrog.io:443/openhab/online-repo-snapshot/2.4/org/openhab/distro/openhab-addons-legacy/2.4.0-SNAPSHOT/)
This thread is the most CPU consuming one. Here is the stack trace of features-3-thread-1 :
openhab> threads 174
Thread 174 features-3-thread-1 WAITING
Stacktrace:
java.lang.Object.wait line: -2
java.lang.Object.wait line: 502
org.apache.karaf.features.internal.download.impl.MavenDownloadManager$MavenDownloader.await line: 101
org.apache.karaf.features.internal.region.Subsystem.downloadBundles line: 537
org.apache.karaf.features.internal.region.Subsystem.downloadBundles line: 452
org.apache.karaf.features.internal.region.SubsystemResolver.resolve line: 224
org.apache.karaf.features.internal.service.Deployer.deploy line: 388
org.apache.karaf.features.internal.service.FeaturesServiceImpl.doProvision line: 1025
org.apache.karaf.features.internal.service.FeaturesServiceImpl.lambda$doProvisionInThread$13 line: 964
org.apache.karaf.features.internal.service.FeaturesServiceImpl$$Lambda$379/1169167538.call line: -1
java.util.concurrent.FutureTask.run line: 266
java.util.concurrent.ThreadPoolExecutor.runWorker line: 1149
java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624
java.lang.Thread.run line: 748

–> Only visible with DEBUG log level: 404 File Not found.

2/ There are regular entries in the log about a nma binding I don’t know anything about.
[DEBUG] [core.karaf.internal.FeatureInstaller] - Installed ‘openhab-action-nma’
Does it reinstall the binding all the time? Why?

This is my first post so my apologies if I am not at the right place, and/or if the post is not very well formatted :blush:
I hope these 2 points raised would help improving the next deliveries.
You’re doing a great job, I love it :heart_eyes:


(Hilbrand Bouwkamp) #17

This is related to the performance improvements in https://github.com/eclipse/smarthome/pull/6438 I think this needs some more research in how this use case can be supported. Nice find.


(Kai Kreuzer) #18

Would definitely need to be fixed for the 2.4.0 release (actually already for ESH 0.10.0, which is planned for Dec 7). Hope you can come up with a fix!


(Yann) #19

Hello,
I’ve get a try to the M6 milestones. Good work from the team as always :clap::clap::clap:

Here are some findings after the lauch of openHAB (or simply I miss a steop??) :slight_smile:

17:46:08.433 [WARN ] [.internal.service.FeaturesServiceImpl] - Can’t load features repository mvn:org.openhab.distro/distro/2.4.0-SNAPSHOT/xml/features
java.lang.RuntimeException: Error resolving artifact org.openhab.distro:distro:xml:features:2.4.0-SNAPSHOT: [Could not find artifact org.openhab.distro:distro:xml:features:2.4.0-SNAPSHOT in openhab (https://openhab.jfrog.io/openhab/online-repo-snapshot/2.4/)] : mvn:org.openhab.distro/distro/2.4.0-SNAPSHOT/xml/features
at org.apache.karaf.features.internal.service.RepositoryImpl.load(RepositoryImpl.java:116) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryImpl.(RepositoryImpl.java:50) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryCacheImpl.create(RepositoryCacheImpl.java:51) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.getFeatureCache(FeaturesServiceImpl.java:593) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.listInstalledFeatures(FeaturesServiceImpl.java:643) ~[?:?]
at org.openhab.core.karaf.internal.FeatureInstaller.installFeature(FeatureInstaller.java:450) ~[?:?]
at org.openhab.core.karaf.internal.FeatureInstaller.installPackage(FeatureInstaller.java:491) ~[?:?]
at org.openhab.core.karaf.internal.FeatureInstaller.lambda$2(FeatureInstaller.java:163) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: java.io.IOException: Error resolving artifact org.openhab.distro:distro:xml:features:2.4.0-SNAPSHOT: [Could not find artifact org.openhab.distro:distro:xml:features:2.4.0-SNAPSHOT in openhab (https://openhab.jfrog.io/openhab/online-repo-snapshot/2.4/)]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:720) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:659) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:600) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:567) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:557) ~[?:?]
at org.ops4j.pax.url.mvn.internal.Connection.getInputStream(Connection.java:123) ~[?:?]
at java.net.URL.openStream(URL.java:1045) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryImpl.load(RepositoryImpl.java:113) ~[?:?]
… 10 more
Suppressed: shaded.org.eclipse.aether.transfer.ArtifactNotFoundException: Could not find artifact org.openhab.distro:distro:xml:features:2.4.0-SNAPSHOT in openhab (https://openhab.jfrog.io/openhab/online-repo-snapshot/2.4/)
at shaded.org.eclipse.aether.connector.basic.ArtifactTransportListener.transferFailed(ArtifactTransportListener.java:39) ~[?:?]
at shaded.org.eclipse.aether.connector.basic.BasicRepositoryConnector$TaskRunner.run(BasicRepositoryConnector.java:355) ~[?:?]
at shaded.org.eclipse.aether.util.concurrency.RunnableErrorForwarder$1.run(RunnableErrorForwarder.java:67) ~[?:?]
at shaded.org.eclipse.aether.connector.basic.BasicRepositoryConnector$DirectExecutor.execute(BasicRepositoryConnector.java:581) ~[?:?]
at shaded.org.eclipse.aether.connector.basic.BasicRepositoryConnector.get(BasicRepositoryConnector.java:249) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.performDownloads(DefaultArtifactResolver.java:520) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:421) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:246) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifact(DefaultArtifactResolver.java:223) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveArtifact(DefaultRepositorySystem.java:294) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:705) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:659) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:600) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:567) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:557) ~[?:?]
at org.ops4j.pax.url.mvn.internal.Connection.getInputStream(Connection.java:123) ~[?:?]
at java.net.URL.openStream(URL.java:1045) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryImpl.load(RepositoryImpl.java:113) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryImpl.(RepositoryImpl.java:50) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryCacheImpl.create(RepositoryCacheImpl.java:51) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.getFeatureCache(FeaturesServiceImpl.java:593) ~[?:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.listInstalledFeatures(FeaturesServiceImpl.java:643) ~[?:?]
at org.openhab.core.karaf.internal.FeatureInstaller.installFeature(FeatureInstaller.java:450) ~[?:?]
at org.openhab.core.karaf.internal.FeatureInstaller.installPackage(FeatureInstaller.java:491) ~[?:?]
at org.openhab.core.karaf.internal.FeatureInstaller.lambda$2(FeatureInstaller.java:163) ~[?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
Caused by: shaded.org.eclipse.aether.resolution.ArtifactResolutionException: Error resolving artifact org.openhab.distro:distro:xml:features:2.4.0-SNAPSHOT
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolve(DefaultArtifactResolver.java:444) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifacts(DefaultArtifactResolver.java:246) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultArtifactResolver.resolveArtifact(DefaultArtifactResolver.java:223) ~[?:?]
at shaded.org.eclipse.aether.internal.impl.DefaultRepositorySystem.resolveArtifact(DefaultRepositorySystem.java:294) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:705) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:659) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:600) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:567) ~[?:?]
at org.ops4j.pax.url.mvn.internal.AetherBasedResolver.resolve(AetherBasedResolver.java:557) ~[?:?]
at org.ops4j.pax.url.mvn.internal.Connection.getInputStream(Connection.java:123) ~[?:?]
at java.net.URL.openStream(URL.java:1045) ~[?:?]
at org.apache.karaf.features.internal.service.RepositoryImpl.load(RepositoryImpl.java:113) ~[?:?]
… 10 more
17:46:08.537 [ERROR] [.core.karaf.internal.FeatureInstaller] - Failed installing ‘openhab-package-expert’: No matching features for openhab-package-expert/0

and also

17:46:21.221 [ERROR] [.core.karaf.internal.FeatureInstaller] - Failed installing ‘openhab-misc-restdocs’: Unable to resolve root: missing requirement [root] osgi.identity; osgi.identity=openhab-runtime-base; type=karaf.feature; version="[2.4.0.SNAPSHOT,2.4.0.SNAPSHOT]"; filter:="(&(osgi.identity=openhab-runtime-base)(type=karaf.feature)(version>=2.4.0.SNAPSHOT)(version<=2.4.0.SNAPSHOT))"
17:46:22.808 [WARN ] [ome.core.internal.events.EventHandler] - Dispatching event to subscriber ‘org.eclipse.smarthome.io.monitor.internal.EventLogger@231e47de’ takes more than 5000ms.

my system info:

openhab> info
Karaf
Karaf version 4.2.1
Karaf home /volume1/@appstore/openHAB/runtime
Karaf base /volume1/public/openHAB/userdata
OSGi Framework org.eclipse.osgi-3.12.100.v20180210-1608

JVM
  Java Virtual Machine        Java HotSpot(TM) 64-Bit Server VM version 25.191-b12
  Version                     1.8.0_191
  Vendor                      Oracle Corporation
  Pid                         11016
  Uptime                      22 minutes
  Process CPU time            7 minutes
  Process CPU load            0.04
  System CPU load             0.31
  Open file descriptors       268
  Max file descriptors        4,096
  Total compile time          4 minutes
Threads
  Live threads                181
  Daemon threads              91
  Peak                        232
  Total started               1851
Memory
  Current heap size           88,614 kbytes
  Maximum heap size           2,023,424 kbytes
  Committed heap size         126,976 kbytes
  Pending objects             0
  Garbage collector           Name = 'G1 Young Generation', Collections = 222, Time = 5.294 seconds
  Garbage collector           Name = 'G1 Old Generation', Collections = 0, Time = 0.000 seconds
Classes
  Current classes loaded      18,354
  Total classes loaded        18,405
  Total classes unloaded      51
Operating system
  Name                        Linux version 3.10.105
  Architecture                amd64
  Processors                  4

Hope this could help
Regards


(Angelos) #20

this is the second time that I see this and I am getting worried (because I can’t understand where it’s coming from)…

how did you upgrade your OH2.4.0S# (Snapshot #?) to OH2.4.0M6 ? using apt?

Somehow the upgrade process leaves some configs not updated and your OH2 keeps looking at the wrong repo…