Openhab unstable after upgrade to 2.5

That’s a good hint, I’m uninstalling it right now to see what happens.
Can I pipe the output of shell:threads --list somehow to a file?
I tried shell:threads --list | tac -a ~/threadlist.txt but with no success…

EDIT:
Ok I think I was able to do some digging now:
Here are my top threads sorted by cpu time

And shell:threads 13272 gives:
Thread 13272 OH-ruleEngine-212 RUNNABLE

Stacktrace:
org.eclipse.xtext.resource.SynchronizedXtextResourceSet.getResource line: 24
org.eclipse.xtext.resource.impl.ResourceSetBasedResourceDescriptions.getResourceDescription line: 111
org.eclipse.xtext.resource.impl.ResourceSetBasedResourceDescriptions$1$1.computeNext line: 74
org.eclipse.xtext.resource.impl.ResourceSetBasedResourceDescriptions$1$1.computeNext line: 64
com.google.common.collect.AbstractIterator.tryToComputeNext line: 141
com.google.common.collect.AbstractIterator.hasNext line: 136
com.google.common.collect.Iterators$5.computeNext line: 635
com.google.common.collect.AbstractIterator.tryToComputeNext line: 141
com.google.common.collect.AbstractIterator.hasNext line: 136
com.google.common.collect.TransformedIterator.hasNext line: 42
com.google.common.collect.TransformedIterator.hasNext line: 42
com.google.common.collect.Iterators$ConcatenatedIterator.getTopMetaIterator line: 1309
com.google.common.collect.Iterators$ConcatenatedIterator.hasNext line: 1325
org.eclipse.xtext.common.types.access.impl.IndexedJvmTypeAccess.getIndexedJvmType line: 109
org.eclipse.xtext.common.types.access.impl.IndexedJvmTypeAccess.getIndexedJvmType line: 101
org.eclipse.xtext.common.types.access.impl.AbstractRuntimeJvmTypeProvider.doTryFindInIndex line: 110
org.eclipse.xtext.common.types.access.impl.AbstractRuntimeJvmTypeProvider.doTryFindInIndex line: 95
org.eclipse.xtext.common.types.access.impl.AbstractRuntimeJvmTypeProvider$TypeInResourceSetAdapter.tryFindTypeInIndex line: 56
org.eclipse.xtext.common.types.access.impl.AbstractRuntimeJvmTypeProvider.tryFindTypeInIndex line: 120
org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.doFindTypeByName line: 128
org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.findTypeByName line: 109
org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getSingleElement line: 59
org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getSingleElement line: 54
org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getElements line: 73
org.eclipse.xtext.scoping.impl.AbstractScope.getElements line: 137
org.eclipse.xtext.scoping.impl.ScopeBasedSelectable.getExportedObjects line: 40
org.eclipse.xtext.scoping.impl.ImportScope.getLocalElementsByName line: 154
org.eclipse.xtext.scoping.impl.ImportScope.getSingleLocalElementByName line: 142
org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement line: 105
org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement line: 108
org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement line: 108
org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement line: 108
org.eclipse.xtext.xbase.scoping.batch.TypeLiteralScope.getLocalElementsByName line: 48
org.eclipse.xtext.xbase.scoping.batch.AbstractSessionBasedScope.getElements line: 174
org.eclipse.xtext.xbase.scoping.batch.AbstractSessionBasedScope$1.get line: 180
org.eclipse.xtext.xbase.scoping.batch.AbstractSessionBasedScope$1.get line: 177
org.eclipse.xtext.scoping.impl.AbstractScope$ParentIterable.iterator line: 60
com.google.common.collect.FluentIterable$3$1.get line: 296
com.google.common.collect.FluentIterable$3$1.get line: 293
com.google.common.collect.AbstractIndexedListIterator.next line: 77
com.google.common.collect.Iterators$ConcatenatedIterator.hasNext line: 1330
com.google.common.collect.Iterators$5.computeNext line: 635
com.google.common.collect.AbstractIterator.tryToComputeNext line: 141
com.google.common.collect.AbstractIterator.hasNext line: 136
com.google.common.collect.Iterators$ConcatenatedIterator.hasNext line: 1321
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates line: 412
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1226
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState$1.getActualType line: 403
org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScopeForReceiver line: 215
org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScope line: 92
org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.createFeatureCallScope line: 177
org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.getScope line: 48
org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions line: 142
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates line: 409
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1226
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 752
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 122
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState$1.getActualType line: 403
org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScopeForReceiver line: 215
org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScope line: 92
org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.createFeatureCallScope line: 177
org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.getScope line: 48
org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions line: 142
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates line: 409
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1226
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.resolveArgumentType line: 627
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.resolveArgumentType line: 963
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeFixedArityArgumentType line: 579
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentType line: 443
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.getConformanceFlags line: 999
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.getConformanceFlags line: 551
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareByArgumentTypes line: 804
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareByArgumentTypes line: 613
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareByArgumentTypes line: 679
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareByArgumentTypes line: 604
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareTo line: 588
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareTo line: 742
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareTo line: 523
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.getPreferredCandidate line: 485
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.getBestCandidate line: 1238
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1227
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.resolveArgumentType line: 627
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.resolveArgumentType line: 963
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeFixedArityArgumentType line: 579
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentType line: 443
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentTypes line: 430
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.preApply line: 378
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.preApply line: 896
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.applyToComputationState line: 286
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState$5.applyToComputationState line: 511
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1231
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.resolveArgumentType line: 627
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.resolveArgumentType line: 963
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeFixedArityArgumentType line: 579
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentType line: 443
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.getConformanceFlags line: 999
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.getConformanceFlags line: 551
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareByArgumentTypes line: 804
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareByArgumentTypes line: 613
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareByArgumentTypes line: 679
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareByArgumentTypes line: 604
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareTo line: 588
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareTo line: 742
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareTo line: 523
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.getPreferredCandidate line: 485
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.getBestCandidate line: 1238
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1227
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.resolveArgumentType line: 627
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.resolveArgumentType line: 963
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeFixedArityArgumentType line: 579
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentType line: 443
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.getConformanceFlags line: 999
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.getConformanceFlags line: 551
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareByArgumentTypes line: 804
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareByArgumentTypes line: 613
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareByArgumentTypes line: 679
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareByArgumentTypes line: 604
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareTo line: 588
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.compareTo line: 742
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.compareTo line: 523
org.eclipse.xtext.xbase.typesystem.internal.AbstractPendingLinkingCandidate.getPreferredCandidate line: 485
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.getBestCandidate line: 1238
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1227
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 112
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.resolveArgumentType line: 627
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.resolveArgumentType line: 963
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeFixedArityArgumentType line: 579
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentType line: 443
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.computeArgumentTypes line: 430
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.preApply line: 378
org.eclipse.xtext.xbase.typesystem.internal.FeatureLinkingCandidate.preApply line: 896
org.eclipse.xtext.xbase.typesystem.internal.AbstractLinkingCandidate.applyToComputationState line: 286
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 1222
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 110
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.ExpressionTypeComputationState.doComputeTypes line: 59
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 495
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 118
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.ExpressionTypeComputationState.doComputeTypes line: 59
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 259
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 132
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes line: 483
org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes line: 118
org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes line: 38
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes line: 121
org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes line: 109
org.eclipse.xtext.xbase.typesystem.internal.AbstractRootTypeComputationState.computeTypes line: 32
org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver._computeTypes line: 827
org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes line: 711
org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeMemberTypes line: 897
org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver._computeTypes line: 886
org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes line: 705
org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes line: 697
org.eclipse.xtext.xbase.typesystem.internal.DefaultReentrantTypeResolver.resolve line: 164
org.eclipse.xtext.xbase.typesystem.internal.DefaultReentrantTypeResolver.reentrantResolve line: 139
org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$LazyResolvedTypes.resolveTypes line: 80
org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$2.process line: 57
org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$2.process line: 53
org.eclipse.xtext.util.concurrent.IUnitOfWork$Void.exec line: 37
org.eclipse.xtext.util.OnChangeEvictingCache.execWithoutCacheClear line: 128
org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver.doResolveTypes line: 53
org.eclipse.xtext.xbase.typesystem.internal.AbstractBatchTypeResolver.resolveTypes line: 69
org.eclipse.xtext.xbase.typesystem.internal.AbstractBatchTypeResolver.resolveTypes line: 55
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate line: 216
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate line: 857
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate line: 231
org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate line: 226
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate line: 215
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluateArgumentExpressions line: 1205
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._invokeFeature line: 1135
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeFeature line: 1081
org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.invokeFeature line: 151
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate line: 861
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate line: 231
org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate line: 226
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate line: 215
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate line: 458
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate line: 239
org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate line: 226
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate line: 215
org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluate line: 201
org.eclipse.smarthome.model.script.runtime.internal.engine.ScriptImpl.execute line: 81
org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl.lambda$2 line: 313
org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl$$Lambda$529/14736831.run line: -1
java.util.concurrent.Executors$RunnableAdapter.call line: 511
java.util.concurrent.FutureTask.run line: 266
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201 line: 180
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run line: 293
java.util.concurrent.ThreadPoolExecutor.runWorker line: 1149
java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624
java.lang.Thread.run line: 748

The system is for 8hrs now and goes in and out overload…

@mark_leonard_tuil could you check for threads? Maybe we’ll find some similarities…
Did a threads --list this morning and now it looks like this:

And a threads 106 gives:

Thread 106 pool-5-thread-1 WAITING
Stacktrace:
sun.misc.Unsafe.park line: -2
java.util.concurrent.locks.LockSupport.park line: 175
java.util.concurrent.locks.AbstractQueuedSynchronizer$ConditionObject.await line: 2039
java.util.concurrent.LinkedBlockingQueue.take line: 442
java.util.concurrent.ThreadPoolExecutor.getTask line: 1074
java.util.concurrent.ThreadPoolExecutor.runWorker line: 1134
java.util.concurrent.ThreadPoolExecutor$Worker.run line: 624
java.lang.Thread.run line: 748

After the weekend I will give it a try. Just a quick question, do I do this from the openhab console?

BTW, you can check to see if you have the same problem as I have by adding rules like this in your rules files.

rule "System started RULE FILE NAME"
when
        System started 
then
       	logInfo("System started Rule", "RULE FILE NAME done")
end

I don’t have any system started triggers, but I have one bigger rule file that took long to load (like 20 minutes). It had a lot of persistence queries.
You can output your threads list with:

sudo openhab-cli console
shell:threads --list | tac -a threadslist.txt
shell:threads 1234 | tac -a thread_1234_stacktrace.txt

The standard console pw is habopen

I have thrown out some stuff of my bigger rule file, and also found three thread:sleep in another rule file (yes I’m ashamed) that I deleted or replaced with timers.

But still I don’t feel that could’ve been the problem, as those rules only got triggered 2-3 times a day. My system is better now, but you can still see ups and downs that I can not explain.

@mark_leonard_tuil So I did as you recommended and added a rule that puts a log when loading on startup. That is the result:

2019-12-21 20:51:59.777 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-21 21:06:20.880 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-21 21:52:05.397 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-21 22:06:23.117 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-21 22:51:54.594 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-21 23:06:14.686 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-21 23:52:13.690 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 00:06:43.589 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 00:52:01.092 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 01:06:56.237 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 01:52:06.693 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 02:06:29.172 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 02:35:44.799 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 02:36:00.492 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 02:37:02.781 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 02:52:24.009 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 02:52:42.311 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 03:06:29.364 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 03:52:26.518 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 04:06:39.119 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 04:07:03.823 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 04:52:33.438 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 05:06:51.123 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 05:52:39.420 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 06:06:54.903 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 06:52:47.390 [INFO ] [marthome.model.script.System started] - READING RULE FILES
2019-12-22 07:06:59.837 [INFO ] [marthome.model.script.System started] - READING RULE FILES

I have not tinkered with Openhab during that time, so I’m pretty sure that shouldn’t show up like it does!
Can others put this to the test?

Edit2: I have added some of the log entries from the night. The system startup rule gets triggered a lot! I have checked the events.log for hints, but nothing unusual happens. Also I don’t think I have specific rules that fire at those times…

Edit3: Even more digging done. I was able to set the overall debug level to DEBUG just before it started doing it again. Here is what I saw (I spare you the full file but I’ll share it on request):
First of all I see a lot of these:

2019-12-22 08:04:12.351 [DEBUG] [oshi.util.FileUtil                  ] - Reading file /proc/self/mounts
2019-12-22 08:04:12.383 [DEBUG] [oshi.util.FileUtil                  ] - Reading file /proc/meminfo
2019-12-22 08:04:12.389 [DEBUG] [oshi.util.FileUtil                  ] - Reading file /proc/meminfo
2019-12-22 08:04:12.396 [DEBUG] [oshi.util.FileUtil                  ] - Reading file /proc/self/mounts

Then there is the Scheduler started:

2019-12-22 08:06:54.590 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@110efe[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1d2fe3a] generate: DONE (null,[p=183,l=183,c=32768,r=0],false)@COMMITTED
2019-12-22 08:06:54.594 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@4a0f8f[p=0,l=183,c=32768,r=183]={<<<event: message\nda...mStateEvent"}\n\n>>>Event"}\n\nalue\\":\\...eeE8ts+9htNtPXM} complete=false committing=false callback=Blocker@1d5e810{null}
2019-12-22 08:06:54.596 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@c8cf55[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1ad7e7a] generate: FLUSH (null,[p=0,l=183,c=32768,r=183],false)@COMMITTED
2019-12-22 08:06:54.600 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 189 SocketChannelEndPoint@c2e0c{/192.168.178.24:50364<->/192.168.178.46:8080,OPEN,fill=-,flush=W,to=26/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1eac6a7[p=HttpParser{s=END,0 of -1},g=HttpGenerator@1bd2a62{s=COMMITTED}]=>HttpChannelOverHttp@17df6a7{r=4,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.178.46:8080/rest/events?topics=smarthome/items/*,age=142791666}
2019-12-22 08:06:54.602 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true written=189 remaining=0 WriteFlusher@11a702{WRITING}->null
2019-12-22 08:06:54.852 [INFO ] [org.quartz.core.QuartzScheduler     ] - Scheduler openHAB-job-scheduler_$_NON_CLUSTERED started.
2019-12-22 08:06:54.859 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@c8cf55[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1ad7e7a] generate: DONE (null,[p=183,l=183,c=32768,r=0],false)@COMMITTED
2019-12-22 08:06:54.864 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@ef2fc3[p=0,l=242,c=32768,r=242]={<<<event: message\nda...hangedEvent"}\n\n>>>"}\n\n}\n\n\n\n\\"groupN...eeE8ts+9htNtPXM} complete=false committing=false callback=Blocker@19d361e{null}
2019-12-22 08:06:54.866 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@110efe[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@131c92a] generate: FLUSH (null,[p=0,l=242,c=32768,r=242],false)@COMMITTED
2019-12-22 08:06:54.869 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 248 SocketChannelEndPoint@1677c48{/192.168.178.24:50363<->/192.168.178.46:8080,OPEN,fill=-,flush=W,to=280/30000}{io=0/0,kio=0,kro=1}->HttpConnection@6998c1[p=HttpParser{s=END,0 of -1},g=HttpGenerator@286294{s=COMMITTED}]=>HttpChannelOverHttp@70e691{r=4,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.178.46:8080/rest/events?topics=smarthome/items/*,age=142792319}
2019-12-22 08:06:54.870 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true written=248 remaining=0 WriteFlusher@25311a{WRITING}->null

And after that eventually comes:

2019-12-22 08:07:07.265 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 187 SocketChannelEndPoint@c2e0c{/192.168.178.24:50364<->/192.168.178.46:8080,OPEN,fill=-,flush=W,to=32/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1eac6a7[p=HttpParser{s=END,0 of -1},g=HttpGenerator@1bd2a62{s=COMMITTED}]=>HttpChannelOverHttp@17df6a7{r=4,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.178.46:8080/rest/events?topics=smarthome/items/*,age=142804332}
2019-12-22 08:07:07.267 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true written=187 remaining=0 WriteFlusher@11a702{WRITING}->null
2019-12-22 08:07:07.270 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@c8cf55[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@1f54702] generate: DONE (null,[p=181,l=181,c=32768,r=0],false)@COMMITTED
2019-12-22 08:07:07.658 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@ef2fc3[p=0,l=179,c=32768,r=179]={<<<event: message\nda...mStateEvent"}\n\n>>>\n\n\\",\\"oldValue\\"...eeE8ts+9htNtPXM} complete=false committing=false callback=Blocker@19d361e{null}
2019-12-22 08:07:07.660 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@110efe[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@817a21] generate: FLUSH (null,[p=0,l=179,c=32768,r=179],false)@COMMITTED
2019-12-22 08:07:07.663 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 185 SocketChannelEndPoint@1677c48{/192.168.178.24:50363<->/192.168.178.46:8080,OPEN,fill=-,flush=W,to=408/30000}{io=0/0,kio=0,kro=1}->HttpConnection@6998c1[p=HttpParser{s=END,0 of -1},g=HttpGenerator@286294{s=COMMITTED}]=>HttpChannelOverHttp@70e691{r=4,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.178.46:8080/rest/events?topics=smarthome/items/*,age=142805114}
2019-12-22 08:07:07.665 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true written=185 remaining=0 WriteFlusher@25311a{WRITING}->null
2019-12-22 08:07:07.667 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@110efe[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@817a21] generate: DONE (null,[p=179,l=179,c=32768,r=0],false)@COMMITTED
2019-12-22 08:07:07.670 [DEBUG] [org.eclipse.jetty.server.HttpChannel] - sendResponse info=null content=DirectByteBuffer@4a0f8f[p=0,l=179,c=32768,r=179]={<<<event: message\nda...mStateEvent"}\n\n>>>\n\n\\",\\"oldValue\\"...eeE8ts+9htNtPXM} complete=false committing=false callback=Blocker@1d5e810{null}
2019-12-22 08:07:07.672 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@c8cf55[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@dd3c8b] generate: FLUSH (null,[p=0,l=179,c=32768,r=179],false)@COMMITTED
2019-12-22 08:07:07.675 [DEBUG] [org.eclipse.jetty.io.ChannelEndPoint] - flushed 185 SocketChannelEndPoint@c2e0c{/192.168.178.24:50364<->/192.168.178.46:8080,OPEN,fill=-,flush=W,to=407/30000}{io=0/0,kio=0,kro=1}->HttpConnection@1eac6a7[p=HttpParser{s=END,0 of -1},g=HttpGenerator@1bd2a62{s=COMMITTED}]=>HttpChannelOverHttp@17df6a7{r=4,c=true,c=false/false,a=ASYNC_WAIT,uri=//192.168.178.46:8080/rest/events?topics=smarthome/items/*,age=142804742}
2019-12-22 08:07:07.677 [DEBUG] [org.eclipse.jetty.io.WriteFlusher   ] - Flushed=true written=185 remaining=0 WriteFlusher@11a702{WRITING}->null
2019-12-22 08:07:07.679 [DEBUG] [.eclipse.jetty.server.HttpConnection] - org.eclipse.jetty.server.HttpConnection$SendCallback@c8cf55[PROCESSING][i=null,cb=org.eclipse.jetty.server.HttpChannel$SendCallback@dd3c8b] generate: DONE (null,[p=179,l=179,c=32768,r=0],false)@COMMITTED
2019-12-22 08:07:07.692 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@1af30826 pairs: {GET /api/xXLd9wAL5TWXJwv2eE4SmmUSOn3hOVaDGmdzuAoG/sensors HTTP/1.1: null}{Content-Type: application/json}{User-Agent: Java/1.8.0_222}{Host: 192.168.178.21}{Accept: text/html, image/gif, image/jpeg, *; q=.2, */*; q=.2}{Connection: keep-alive}
2019-12-22 08:07:07.720 [DEBUG] [.www.protocol.http.HttpURLConnection] - sun.net.www.MessageHeader@19c6e6018 pairs: {null: HTTP/1.1 200 OK}{Server: nginx}{Date: Sun, 22 Dec 2019 07:07:07 GMT}{Content-Type: application/json}{Connection: close}{Cache-Control: no-store, no-cache, must-revalidate, post-check=0, pre-check=0}{Pragma: no-cache}{Expires: Mon, 1 Aug 2011 09:00:00 GMT}{Access-Control-Max-Age: 3600}{Access-Control-Allow-Origin: *}{Access-Control-Allow-Credentials: true}{Access-Control-Allow-Methods: POST, GET, OPTIONS, PUT, DELETE, HEAD}{Access-Control-Allow-Headers: Content-Type}{X-XSS-Protection: 1}{X-Content-Type-Options: nosniff}{Content-Security-Policy: default-src 'self'}{Cache-Control: no-store}{Pragma: no-cache}
2019-12-22 08:07:07.799 [INFO ] [marthome.model.script.System started] - READING RULE FILES

To me it looks like a ton of http requests (that might come from my hue binding) but I don’t know if that’s normal? I think we need a pro here… @mstormi to the rescue? :slight_smile:

There’s no systematic approach. As you spoke about a rule that takes 20 mins to load, I would believe you are in some form hitting or changing your .things, .items or .rules files.
ANY file modification (and be it just the file modification date or some editor to auto-save) will result in a reload AND THEY QUEUE UP. So if you edit a rules file and quickly save three times, your RPi will be busy for a full hour.
So on the one hand side try to reduce load times. It’s often primitives like .intValue() . Try if you can reduce usage.
On the other hand, validate your editing process. I have seen this at times when using VScode, maybe it does some sort of intermediate save of project data to affect your items or rules files.

Hi Markus,

thanks for your answer. I know the system can get clogged when editing rules on-the-fly. Usually I edit them in vim and that also is not the best idea.
But even without editing anything, the system startup rule seems to fire too often, doesn’t it? (That’s where I put the logInfo “READING RULES”)
Should it not only fire on startup of openhab?

Edit1: I think i have found something that coincides with the reloading of rule files!

2019-12-22 10:52:46.048 [vent.ItemStateChangedEvent] - zwave_device_Razberry2_node8_sensor_door changed from NULL to CLOSED
2019-12-22 10:52:46.225 [vent.ItemStateChangedEvent] - zwave_device_Razberry2_node8_battery_level changed from NULL to 100.0
2019-12-22 10:52:46.235 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:Razberry2:node8' has been updated.

and

2019-12-22 11:06:54.397 [vent.ItemStateChangedEvent] - zwave_device_Razberry2_node9_sensor_door changed from NULL to CLOSED
2019-12-22 11:06:54.449 [vent.ItemStateChangedEvent] - zwave_device_Razberry2_node9_battery_level changed from NULL to 100.0
2019-12-22 11:06:54.456 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:Razberry2:node9' has been updated.

Both being my zwave door sensors. I don’t know why they always change from NULL to CLOSED, even though they’re not triggered at all. I will try and find out what’s wrong here…

@mark_leonard_tuil I see you’re using zwave as well. Ca you check if you have something similar around the times where your rules reload?

Edit2: So my zwave door-sensors had a wake up interval of 3600 and every time they woke, the zwave thing got updated and the rules got reloaded. Which would be twice an hour because I have two sensors with the same configuration.
No I have set the wakeup interval of the thing to 36000 and voila, no rule reloading anymore!
image

I have seen the same behaviour since a couple of weeks. Not a clue to what is happening.

Are you sure? 2.5 has been released for only a week.

Many people have had issues with addons restarting once a minute due to bad entries, especially restdocs since it got moved from misc to ui, as documented in the Release Notes.

This was in the test version.

As I already wrote, for me it was because two zwave things were reconfigured every hour and that triggered a reloading of the rules.
Now I don’t think that this is supposed to happen, but at leas I was able to mitigate the impact by defining a longer wakeup interval.

Yes, I see something similar. Around the time that the rules restart, I see the following lines:

2019-12-23 05:48:12.750 [vent.ItemStateChangedEvent] - MotionSensorDouche_SensorLuminance changed from NULL to 0
2019-12-23 05:48:12.783 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:a93e88d5:node44' has been updated.
2019-12-23 05:48:16.696 [vent.ItemStateChangedEvent] - MotionSensorDouche_SensorLuminance changed from NULL to 0
2019-12-23 05:48:16.710 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:a93e88d5:node44' has been updated.

This is a Fibaro motion sensor. I have about ten of them around the house, but this is the only one that gives these kinds of lines (“changed from NULL to 0”). The wakeup interval is 7200 seconds, which is 2 hours, which corresponds to the rule reloading.

Edit:
To see if changing the wakeup time helps, I changed it to 720000. To speed up the change I pressed the button on the device 3 times. The rules are now reloading.

OK so we seem to have tracked it down to what might be the cause:
Zwave things get reconfigured and trigger a reload of the rules including the system startup trigger.

@mark_leonard_tuil can you try and get some debug log when you press the button? (in the console: log:set DEBUG org.openhab.binding.zwave)

I have done the same and we’ll see what it brings up…

1 Like

I have made a log. I must say I don’t see anything obvious, but then again, I don’t know what I am looking for. Just to give some background so far:

  • My rules get reloaded every 2 hours.
  • This corresponds to Z-wave node 44 (fibaro motion sensor) getting updated.
  • I have replaced the battery of that device.
  • I can trigger this by pressing the b-button 3x on this device.
  • Pressing the b-button 3x on other devices does not have the same effect.
  • I have made a log that starts with me pressing the b-button and stops with the first message of rules reloading.

openhab.log (71.9 KB)

I did another test. I use the Max! binding. It is a system to control heating radiators. Max! uses a local hub called the cube. The various radiotors get their imput form the cube. With the binding you can reset the cube. This results in the same reloading of rules behaviour. I have attached the log. I do not think there are entries that (should) account for the rules reloading behaviour. What I see is lines like:

2019-12-23 15:15:22.581 [hingStatusInfoChangedEvent] - 'max:bridge:KEQ0536973' changed from ONLINE to OFFLINE: Rebooting
2019-12-23 15:15:22.593 [hingStatusInfoChangedEvent] - 'max:wallthermostat:KEQ0536973:OEQ1035689' changed from ONLINE to OFFLINE (BRIDGE_OFFLINE)
2019-12-23 15:15:38.142 [me.event.ThingUpdatedEvent] - Thing 'max:bridge:KEQ0536973' has been updated.
2019-12-23 15:15:38.641 [me.event.ThingUpdatedEvent] - Thing 'max:wallthermostat:KEQ0536973:OEQ1035689' has been updated.
2019-12-23 15:15:38.684 [vent.ItemStateChangedEvent] - WallmountedThermostatSlaapkamer_SetTemperature changed from NULL to 16.0
2019-12-23 15:15:39.487 [hingStatusInfoChangedEvent] - 'max:wallthermostat:KEQ0536973:OEQ1035689' changed from OFFLINE (BRIDGE_OFFLINE) to ONLINE
2019-12-23 15:15:40.052 [vent.ItemStateChangedEvent] - ThermostatRadiatorWoonkamerRechts_SetTemperature changed from 20.5 to 0.0

However, I don’t think these events should cause the rules to reload. Nothing is changing about the things and items. All that is happening is things going offline and online and (as a result) things being updated.

Full log:
openhab.log (7.3 KB)

6 posts were split to a new topic: Rules reload on MAX! binding reconnect

I have two situation where this happens. One is

2019-12-24 08:38:14.811 [WARN ] [o.internal.handler.SysteminfoHandler] - No information for channel battery#remainingCapacity with device index 0 :
2019-12-24 08:38:14.813 [WARN ] [o.internal.handler.SysteminfoHandler] - No information for channel battery#remainingTime with device index 0 :
2019-12-24 08:38:34.016 [INFO ] [.smarthome.model.script.System Rules] - System (re)started

and the other is

2019-12-24 09:48:59.284 [INFO ] [l.script.OUTSIDEDIMMABLELIGHTS_RULES] - astro_sun_local_phase_name.state: DAYLIGHT
2019-12-24 09:48:59.285 [INFO ] [.smarthome.model.script.System Rules] - System (re)started

Does this make sense to anyone?

The last one seems to be triggered by the astro add-on.

I have also the same behaviour with my fibaro motion sensor since openhab 2.5. After a thing update from my fibaro motion sensor my “system start” rule is triggered.

2019-12-25 14:38:12.393 [me.event.ThingUpdatedEvent] - Thing 'zwave:device:f7e712f7:node25' has been updated.
2019-12-25 14:38:27.905 [INFO ] [e.smarthome.model.script.Systemstart] - Das System wurde neu gestartet

It seems like updates to things or things configurations or properties trigger the startup rules.
I tried to retrace the call stack (manually, not sure if this is 100% correct) and is something like this:

BaseThingHandler.updateThing | updateProperties | updateConfiguration
ThingManagerImpl.ThingHandlerCallback.thingUpdated
AbstractManagedProvider.update
AbstractProvider.notifyListeners
AbstractRegistry.updated
ThingRegistryImpl.notifyListenersAboutUpdatedElement
AbstractRegistry.notifyListenersAboutUpdatedElement
AbstractRegistry.notifyListeners
RuleEngineImpl.updated
RuleEngineImpl.added
RuleEngineImpl.scheduleStartupRules

I assume this is a desired behaviour by openHab (?) so the issue might be the bindings updating the things periodically. Now clear why this started apprearing with OH 2.5 though…

I notice the same, every few minutes thje system started rule is fired. However I do not see anything weird in the logs or events files. Did not occur with 2.5.Mx versions, only with the release version

@stefaanbolle Post both your addons.cfg and addons.config files…maybe something there is an issue.