And the logs show what?
Please use code fences.
How to use code fences - Tutorials & Examples - openHAB Community
Under "var/log/openhab2/ all log files show nothing - they are just empty.
I am now back to 2.5.0-1 from my SD-Card backup. There the logs are not 0 size and openhab is working as expected…
I have the same problem, and I had not backed up.
Can I get back to 2.5.2? 
apt -y --allow-downgrades -y install openhab2=2.5.2-1 worked for me but maybe I had luck 
2 Likes
it worked, thanks for the tip, now wait to fix the update. 
This is what’s in logs after upgrade:
2020-03-21 20:22:27.096 [ERROR] [ternal.service.BootFeaturesInstaller] - Error installing boot feature repository mvn:org.openhab.distro/distro/2.5.3/xml/features
java.lang.IllegalStateException: BundleContext is no longer valid
at org.eclipse.osgi.internal.framework.BundleContextImpl.checkValid(BundleContextImpl.java:989) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getDataFile(BundleContextImpl.java:694) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.apache.karaf.features.internal.osgi.Activator$1.getOutputStream(Activator.java:261) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.StateStorage.save(StateStorage.java:59) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.saveState(FeaturesServiceImpl.java:237) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:388) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:375) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.addRepositories(BootFeaturesInstaller.java:123) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.installBootFeatures(BootFeaturesInstaller.java:93) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.start(BootFeaturesInstaller.java:87) [bundleFile:?]
at org.apache.karaf.features.internal.osgi.Activator.doStart(Activator.java:196) [bundleFile:?]
at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-03-21 20:22:27.627 [ERROR] [ternal.service.BootFeaturesInstaller] - Error installing boot feature repository mvn:org.openhab.distro/openhab-addons/2.5.3/xml/features
java.lang.IllegalStateException: BundleContext is no longer valid
at org.eclipse.osgi.internal.framework.BundleContextImpl.checkValid(BundleContextImpl.java:989) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getDataFile(BundleContextImpl.java:694) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.apache.karaf.features.internal.osgi.Activator$1.getOutputStream(Activator.java:261) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.StateStorage.save(StateStorage.java:59) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.saveState(FeaturesServiceImpl.java:237) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:388) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:375) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.addRepositories(BootFeaturesInstaller.java:123) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.installBootFeatures(BootFeaturesInstaller.java:93) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.start(BootFeaturesInstaller.java:87) [bundleFile:?]
at org.apache.karaf.features.internal.osgi.Activator.doStart(Activator.java:196) [bundleFile:?]
at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-03-21 20:22:27.674 [ERROR] [ternal.service.BootFeaturesInstaller] - Error installing boot feature repository mvn:org.apache.karaf.features/framework/4.2.7/xml/features
java.lang.IllegalStateException: BundleContext is no longer valid
at org.eclipse.osgi.internal.framework.BundleContextImpl.checkValid(BundleContextImpl.java:989) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getDataFile(BundleContextImpl.java:694) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.apache.karaf.features.internal.osgi.Activator$1.getOutputStream(Activator.java:261) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.StateStorage.save(StateStorage.java:59) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.saveState(FeaturesServiceImpl.java:237) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:388) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:375) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.addRepositories(BootFeaturesInstaller.java:123) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.installBootFeatures(BootFeaturesInstaller.java:93) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.start(BootFeaturesInstaller.java:87) [bundleFile:?]
at org.apache.karaf.features.internal.osgi.Activator.doStart(Activator.java:196) [bundleFile:?]
at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-03-21 20:22:27.743 [ERROR] [ternal.service.BootFeaturesInstaller] - Error installing boot feature repository mvn:org.apache.karaf.features/standard/4.2.7/xml/features
java.lang.IllegalStateException: BundleContext is no longer valid
at org.eclipse.osgi.internal.framework.BundleContextImpl.checkValid(BundleContextImpl.java:989) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.eclipse.osgi.internal.framework.BundleContextImpl.getDataFile(BundleContextImpl.java:694) ~[org.eclipse.osgi-3.12.100.jar:?]
at org.apache.karaf.features.internal.osgi.Activator$1.getOutputStream(Activator.java:261) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.StateStorage.save(StateStorage.java:59) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.saveState(FeaturesServiceImpl.java:237) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:388) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.FeaturesServiceImpl.addRepository(FeaturesServiceImpl.java:375) ~[bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.addRepositories(BootFeaturesInstaller.java:123) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.installBootFeatures(BootFeaturesInstaller.java:93) [bundleFile:?]
at org.apache.karaf.features.internal.service.BootFeaturesInstaller.start(BootFeaturesInstaller.java:87) [bundleFile:?]
at org.apache.karaf.features.internal.osgi.Activator.doStart(Activator.java:196) [bundleFile:?]
at org.apache.karaf.util.tracker.BaseActivator.run(BaseActivator.java:312) [bundleFile:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:1.8.0_222]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:1.8.0_222]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:1.8.0_222]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-03-21 20:22:27.906 [ERROR] [ternal.service.BootFeaturesInstaller] - Error installing boot features
java.util.concurrent.RejectedExecutionException: Task java.util.concurrent.FutureTask@1b4fe11 rejected from java.util.concurrent.ThreadPoolExecutor@f9005d[Terminated, pool size = 0, active threads = 0, queued tasks = 0, completed tasks = 0]Hello, had the same issue. Found somewhere advice to stop openhab2 service, clean cache and run it again. It is working as for now…
2 Likes
I have a separate issue with Rule processing and will be downgrading too. Rule processing for the example rule I show below, seems to process twice, with rules that worked fine before the upgrade.
EDIT: I downgraded to 2.5.2 and all is working correctly again
I use mosquitto and the 1.4 binding for mqtt. This rule should change the current state to ON or OFF (flip state from what it was at).
rule "Upstairs button1"
when
Item RFDataLights received update "811305"
then
if (RFDataLights.state == "811305" && gUpstairs.state == OFF ) { gUpstairs.sendCommand("ON") }
else gUpstairs.sendCommand("OFF")
end
This is an RF button, that when pressed, sends the “811305”. The RF bridge I use, shows that only 1 of the “811305” arrives at it for mosquitto to process. However, Openhab processes this rule twice. Here is what is sent via MQTT.
So if the lights were on, they immediately switch OFF and ON again… or if they are off, they switch ON and OFF again. As such, I dont think its a case of the rule ignoring the “else” command in the rule, but the rule being processed twice.
All my rules that process in this way, perform the same on 2.5.3-1
If I switch the lights on or off via the web interface, which isnt a Rule, but just an ON or OFF, they work absolutely fine.
Multiple openHAB restarts and cleaning cache have become part of the regular routine when upgrading for the last year, I think, Some people say it takes up to 3 restarts of openHAB.
2 Likes
After cleaning the cache the upgrade did work well on mi PI - thank you all.
Christian
Thanks! I had the same issue and it worked for me as well!
1 Like
What makes you think that? Your events.log would offer solid clues.
You seem to be saying the RF button is coming in via MQTT too; what QoS does that use? Not all messages are guaranteed delivery only once from broker.
The rule is a little odd; it only triggers for update “811305” but then tests immediately for state “811305” anyway.
The events I showed on there are direct from Mosquitto, so showing exactly what was sent/arrived via MQTT at the broker. So as far as network QOS, that is negated as any arrival of a second MQTT packet would show up here. If youre talking about internally within my Openhab servers memory/cpu… Id have to upgrade again and look at the logs, however, downgrading Openhab made things work again.
The reason that the rule is using Item RFDataLights received update “811305” is because I have multiple sets of rules assessing the RFDataLights item variable. Just so to avoid multiple variable items/channels processing MQTT data when it comes in. So multiple rules, analyse RFDataLights to see if the correct code arrives for that rule, then flips the group status On or Off as required. (Yes, I could probably tidy the rules up into a “case” type scenario).
All I can say is that this rule worked fine on all previous versions of Openhab, hasnt changed for multiple revisions and as of 2.5.3, started this behavior where it double switches the state. If I get time to re-upgrade Ill look into it and pull more data from the event log, though as things have been time wise, I just needed a working system, so the downgrade was the quickest solution.
Yes, timings of stuff can change between versions.
Let us know when you want to investigate further. A clip of your openHAB events.log would be really useful.
Make it even more useful by adding diagnostics that would indicate if your guess was correct.
when
Item RFDataLights received update "811305"
then
logInfo("test", "Rule running " + RFDataLights.state.toString + " x " + gUpstairs.state.toString)
You could give a bit more info, I would guess that gUpstairs is a Group Item and not actually linked to MQTT in any way? It may be that group command propogation has something to do with it.
My query about the rule was this duplication -
You’d expect that always to be true.
Maybe it isn’t, and that is what goes wrong; perhaps the update event triggers the rule before the Item is actually updated. This is where timings can change.
But that would not explain multiple triggering.
RFDataLights is not a Group Item too, is it?
1 Like
Yes RFDataLights is a string item, pulling mqtt from my RF bridge/mosquitto
String RFDataLights "[%s]" {mqtt="<[mybroker:tele/RFBridge/RESULT:state:JSONPATH($.RfReceived.Data)]"}
And yes you’re right, gUpstairs is just a group, with no other MQTT links
Group gUpstairs "Upstairs Lights" <lightbulb1>
Agreed, I can cut the 2nd test, at that stage, I cant see it making a difference to the actual functionality… though I cant see a good logic based reason why it should cause a problem… though Im happy to cut it out when I upgrade and feed back any log issues on here, based on the revised rule.
(RFDataLights.state == "811305" &&
If I get chance a bit later/a couple of hours… Ill revise the rule first, confirm it works as expected… upgrade to 2.5.3, setup the additional logging and post my results back here.
Oooh … still using MQTT version 1. Can’t see a connection really (but QoS?), but don’t expect any rush to fix should it be a screwy binding timing issue.
What worried me was that if there were multiple updates of the RF Item - let’s says it’s followed rapidly by a different code for button release … you could enter the rule with one state, and a few mS later read a different state. With a different on/off command result.
Yeah, still on v1. I cant recall exactly why right at the moment why… though I think it was something to do with using map files and JSONPATH together with items, that caused me an issue on the newer version. Perhaps something that was/is resolvable, but at the time, too complicated to research and switch over my whole setup. Though maybe something I can re-visit in the coming weeks of being locked up at home (work allowing).
Ill let you know what comes out of the upgrade, when I can get it done.
Thanks
Ive done everything we agreed (tidied rules, added logging, tested, upgraded etc). At the moment, on 2.5.3, things are working correctly… Though, this is how it was when I upgraded before and the problem started to occur when I hadnt perhaps used Openhab for a few hours and of course, in the evening when I was switching lights on/off.
So, maybe there was something in the rule with the double test of the RFDataLights … or maybe not. I guess give me 24 hours to test/find out what happens.
Thanks
1 Like
Well… we have a mystery on our hands but one that may never get solved!!
So far, everything has remained working as it should! Which is great, and thanks for the help/pushing me forward to taking another look.
The mystery part is this:
I had this at the top of the rule file:
rule "Pre-Load Lighting Rules"
when
System started
then
logInfo("Pre-Load Lighting Rules", "finished")
end
as well as the additional RFDataLights check in the if statement.
So as I said in my last post, I had removed the extra RFDataLights check. When I would reboot the Openhab server, if the lighting group was switched OFF, it would turn them ON when Openhab started… However, if the lights were ON, it wouldnt turn them OFF when Openhab started… very strange!!
So I removed the pre-load of rules and seemingly… all started acting as it should.
Since then, as I say, all has been fine!! 
For the sake of completeness… just to prove things… I put the rules, bar the pre-load, back to having the additional RFDataLights check in the if statement… and… well… everything still worked fine.
A bit more playing around… I dont exactly know what caused the problem, but it seems to be something that is a mix between the Pre-load of rules AND the additional check that causes this… but not either of those solely on their own. Thats the best I can ascertain anyway… And yes, I did have some other Pre-load of rules in some other rules files, of which they are all cleared out now.
So I think it will remain a mystery as to how all these things were interacting as they were… but my system seems to be all happy and stable again now… Though I thought it worth leaving this here, should this strange occurrence pop up for anyone else in future.
@rossko57 Thanks for your help!!!