OH 2.1 experience?

HI all

I tried to upgraded from OH 2.0 to 2.1 and a lot of things don’t work anymore. So I was wondering if others had any similar experience?

I saw the two breaking changes, but I don’t have groups that receive updates and I checked the logs for any validation errors of configuration files. I actually had one that was ignored because of a missing }, but don’t need that rules file at the moment so that’s fine.

What’s not working:

  • Everything related to Homematic. No items are updated and changes in OH are not reflected in Homematic. Absolutely nothing in the logs here.
  • Charts don’t work. I saw this error in the logs, pretty sure there’s a connection: “There is no queryable persistence service registered with the id ‘mysql’”
  • Harmony Hub: Reading the current activity works, but setting a new one doesn’t work anymore Again, nothing in the logs.

Luckily I run OH2 in a VM now so I quickly restored a backup and went back to 2.0 for the moment as I didn’t have much time and honestly, don’t know where to start as the logs really don’t reveal anything useful!

Any similar experiences ?

Thanks
Patrick

Guess it’s not a general problem so I have to tackle these one by one. I copied my VM, disabled persistance and tried the update again on this copy. Same result.

Homematic is the most important, so I’ll try to solve that first. There is something in the log after all:

2017-07-09 10:46:01.844 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E582607FC01400_MR/svc/upnp-org/RenderingControl/event/cb SEQUENCE: 0
2017-07-09 10:46:02.410 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway 'ccu' not available, disabling support
2017-07-09 10:46:02.446 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'CUXD' on gateway 'ccu' not available, disabling support
2017-07-09 10:46:02.489 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.27.8,address=KEQ0384088,wired=false,hmip=true,cuxd=false,group=true]
2017-07-09 10:46:06.930 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E582607FC01400_MR/svc/upnp-org/RenderingControl/event/cb SEQUENCE: 0
2017-07-09 10:46:17.006 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E582607FC01400_MR/svc/upnp-org/RenderingControl/event/cb SEQUENCE: 0
2017-07-09 10:46:37.077 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E582607FC01400_MR/svc/upnp-org/RenderingControl/event/cb SEQUENCE: 0
2017-07-09 10:47:15.477 [WARN ] [ome.core.thing.internal.ThingManager] - Cannot delegate command 'ON' for item 'Sw_EG_Lampe_Sofa' to handler for channel 'homematic:HM-LC-Sw1-FM:ccu:MEQ0324326:1#STATE', because no thing with the UID 'homematic:HM-LC-Sw1-FM:ccu:MEQ0324326' could be found.

So apparently my things are not working anymore. Ideas ?

Have a look at this topic:

As easy as that! Sorry, should have found that myself. Homematic and Harmony Hub seem to work again, will test the rest and then do a proper update on my production system again.

Thanks a lot!

1 Like

Updated my main installation now but again, it didn’t work smoothly. When updating, the two folder tmp and cache already were empty, so there was no point in executing the two commands.
After countless restarts, binding re-installations and deleting the two folder contents, everything seems to work now so I will not downgrade again.

I hope everything works stable but at this point, I’m not so sure. For example, the Harmony Hub still wouldn’t work so I re-installed the binding. Then suddenly, the mysql binding was gone, checked in the karaf console. No idea why. After installing that again, charts work too.

But the whole update procedure for a “minor” version was everything but minor to be honest.

There is definitely something wrong. NotifyMyAndroid also didn’t work. Checked, both mail and NotifyMyAndroid were uninstalled. Again, no idea why.
So I installed both, now mysql persistance is uninstalled again.

Let’s hope I can somehow get all bindings / actions / services to be installed at the same time…

Are you doing a mix of editing addons.cfg and installing addons through PaperUI? If so that could account for the weird behavior. OH will always install/uninstall to make the addons match what is in addons.cfg.

Interesting point, thanks! But no, everything in addons.cfg is commented, never used that file. (there’s only one in the services folder, right?)
I did a mix of installing addons through the PaperUI and the Karaf console, not sure if I have to expect similar weird problems?

There is only the one. And if you have never touched it that is not your problem.

There shouldn’t be a problem doing a mix between PaperUI and the console but I’ve no direct experience with that to say so for sure.

This is really annoying. I restarted openhab and after a minute or so, two bindings are suddenly uninstalled again.
I can even see it in the log, but have no idea what causes the uninstallation:

2017-07-11 14:24:52.829 [INFO ] [ding.astro.handler.AstroThingHandler] - Scheduled astro job-positional with interval of 300 seconds for thing astro:moon:home
2017-07-11 14:24:53.178 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'bool.map' : Target value not found in map for 'NULL'
2017-07-11 14:24:53.259 [INFO ] [ui.habmin.internal.servlet.HABminApp] - Started HABmin servlet at /habmin
2017-07-11 14:24:53.316 [INFO ] [panel.internal.HABPanelDashboardTile] - Started HABPanel at /habpanel
2017-07-11 14:24:53.994 [INFO ] [io.openhabcloud.internal.CloudClient] - Connected to the openHAB Cloud service (UUID = <removed>, base URL = http://localhost:8080)
2017-07-11 14:24:54.237 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'WIRED' on gateway 'ccu' not available, disabling support
2017-07-11 14:24:54.260 [INFO ] [ternal.communicator.client.RpcClient] - Interface 'CUXD' on gateway 'ccu' not available, disabling support
2017-07-11 14:24:54.320 [INFO ] [ommunicator.AbstractHomematicGateway] - HmGatewayInfo[id=CCU,type=CCU2,firmware=2.27.8,address=KEQ0384088,wired=false,hmip=true,cuxd=false,group=true]
2017-07-11 14:24:55.054 [WARN ] [rm.AbstractFileTransformationService] - Could not transform 'NULL' with the file 'bool.map' : Target value not found in map for 'NULL'
2017-07-11 14:24:55.161 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:55.162 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:55.171 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:55.173 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:55.174 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:55.175 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:55.894 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Disabling weather locationId 'home-mb', no binding available
2017-07-11 14:24:55.894 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Disabling weather locationId 'home-owm', no binding available
2017-07-11 14:24:55.895 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Disabling weather locationId '<locationId1>', no binding available
2017-07-11 14:24:55.895 [INFO ] [ternal.scheduler.WeatherJobScheduler] - Starting and scheduling weatherJob-home with interval of 15 minutes
2017-07-11 14:24:56.259 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.287 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.289 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.297 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.299 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.299 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.301 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.302 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.321 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.322 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update max and min temperatures UG': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2017-07-11 14:24:56.323 [WARN ] [nce.extensions.PersistenceExtensions] - There is no queryable persistence service registered with the id 'mysql'
2017-07-11 14:24:56.323 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Update max and min humidity UG': cannot invoke method public abstract org.eclipse.smarthome.core.types.State org.eclipse.smarthome.core.persistence.HistoricItem.getState() on null
2017-07-11 14:24:57.050 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-persistence-mysql'
2017-07-11 14:24:58.276 [INFO ] [core.karaf.internal.FeatureInstaller] - Uninstalled 'openhab-binding-harmonyhub'

This sounds familiar to this problem. Is there a mismatch between these files? Or the ones you expect to be installed?

OK, did what’s described in the other thread. My addons.cfg is empty and always has been (everything commented out).
I stopped OH2, moved the addons.config and restarted OH2 again. The file addons.config is recreated so I did a diff between the old and the new one and they are exactly the same.

This is the binding and persistence lines from addons.config:

binding="sonos,koubachi1,chromecast,onkyo,astro,ntp,weather1,exec,kodi,homematic,harmonyhub"
persistence="rrd4j,mysql"
So both homematic and mysql are in the file, no mismatch between the files.

This time, everything still works after a few minutes. So fingers crossed…

1 Like

All I can recommend is to file an issue.

Appreciate the help! I’ll test a bit further. Right now, I think I couldn’t provide enough information to file a proper issue.

But you might have enough info for the maintainers to ask the right questions.

i now have many similar errors since i removed a sonos player to take it with to the holiday house and added it back again in the existing sonos system (if that has any influence to that, what i doubt because this errors seem to affect many players):

2017-07-24 19:32:54.575 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_B8E9377FAC4601400/svc/upnp-org/HTControl/event/cb SEQUENCE: 0
2017-07-24 20:10:23.300 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/ZoneGroupTopology/event/cb SEQUENCE: 0
2017-07-24 20:19:00.446 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/GroupManagement/event/cb SEQUENCE: 0
2017-07-24 20:25:08.565 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/GroupManagement/event/cb SEQUENCE: 0
2017-07-24 20:27:39.599 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/GroupManagement/event/cb SEQUENCE: 0
2017-07-24 20:32:58.711 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_B8E9377FAC4601400/svc/upnp-org/GroupManagement/event/cb SEQUENCE: 0
2017-07-24 20:37:40.798 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/DeviceProperties/event/cb SEQUENCE: 0
2017-07-24 20:40:11.846 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/DeviceProperties/event/cb SEQUENCE: 0
2017-07-24 21:08:30.390 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/GroupManagement/event/cb SEQUENCE: 0
2017-07-24 21:22:46.449 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/DeviceProperties/event/cb SEQUENCE: 0
2017-07-24 21:33:06.767 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_B8E9377FAC4601400_MR/svc/upnp-org/RenderingControl/event/cb SEQUENCE: 0
2017-07-24 21:37:33.853 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/ZoneGroupTopology/event/cb SEQUENCE: 0
2017-07-24 21:40:13.907 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/GroupManagement/event/cb SEQUENCE: 0
2017-07-24 21:40:17.367 [ERROR] [g.jupnp.protocol.sync.ReceivingEvent] - Invalid subscription ID, no active subscription: (IncomingEventRequestMessage) NOTIFY /upnpcallback/dev/RINCON_000E589C682801400/svc/upnp-org/DeviceProperties/event/cb SEQUENCE: 0

any clue what i can do? (cool rhyme :D)

Sorry, can’t really help you there. In fact, even after several restarts, my OH2.1 installations seems to be stable now.