2.5.2 on openhabian running on a raspi 3B+ and while I have seen those log entries before and already have a cron job restarting oh2 3 times a week the frequency of these events seems to have risen now.
My recent changes:
migration from MQTT v1 to v2
installed JSR223 and started to migrate rules into python
It feels like one of these changes, or even both put a higher load on the system …
So, I can step it up a notch and restart oh2 every night, but other than that? Are there known best practices to sort of streamline the system, to hunt for performance killers or recommended (hardware) upgrades?
What is actually taxing the system? Does it matter how many items there are and whether I keep ‘left from before’ items dormant in some .items file or clean and purge them (risking that I delete to much and things break)? Is there an easy way to read out the number of items currently known to the system?
Is there anything like a profiler which could help me understand why events remain undispatched for >5 seconds?
Oh, and even a small change in an .items file triggers a reload of all the rules and lately I see that happening even after some changes to a .rules. Is there any internal parameter to regulate the sensitivity for those reloads?
Should I start to be more restrictive about which updates and events I allow onto the event bus?
Is it just me or do other people see those issues as well?
Thanks in advance for any pointers
No, you’re victim to a problem to possibly affect everybody. It’s not due to “regular” overload of OH.
But it’s sort of a generic error that has been observed in a number of different situations.
To find out, first exclude the possibility that it’s due to rules to reload.
Does top show 100+ % CPU for Java ?
Do you change things config, DSL rules ?
Cease doing do for some minutes to see if load drops. Bundle changes if you cannot avoid them. Clear the cache and restart OH. Check if anything from this applies.
Increase debug logging for a start, org.apache.karaf and org.openhab being candidates to get an idea about what’s going on in the system.Increase debug logging for a start.
The most taxing thing in OH is loading .rules files. But thread leaks, memory leaks, and sometimes poorly written rules can cause problems as well.
You must have unique names for your Items. So if you are moving Items from .items files to the REST API, you must remove that Item from the .items file or use a different name for the REST API Item. If you have it defined in both places at a minimum the .items file definition will dominate, at worse OH will become confused.
curl -s -X GET --header "Accept: application/json" "http://spare:8080/rest/items?recursive=false" | grep -o name | wc -l
This assumes you don’t have the word “name” in any tags or Item labels. Use “link” or “state” instead of “name” if you do.
But the number of Items is almost certainly irrelevant. Something is pegging your CPU preventing OH from doing it’s job.That something is almost certainly one of the following:
loading/reloading the text based config files, especially .rules
poorly written rules that have tight loops (e.g. a while for for loop without a sleep)
Grafana static chart rendering
some other process on the RPi consuming all of the CPU.
The size of the change is irrelevant. When you change a config, it needs to reload them in order for them to take effect. If you don’t want a reload every time you make a change to a file, make the change outside of OH’s config directories and copy the files over after all your changes are made.
I only ever see this when my RPi 0 is loading .rules files. That’s one reason I’m moving all the configs on that machine to the JSONDB. So far I’ve gotten it from 25-30 minutes before OH becomes usable on a reboot down to < 10 minutes. I’ve a few hundred more lines of .rules code to transition and I think I can get it down to about 7 minutes to reboot, just by moving everything to the JSONDB (everything possible meaning things, items and rules). I’ve also seen those errors go away as a result as well.
well, I’m sort of a file-based-config orthodox so there is no mix of items or rules from files and paperui.
And yes, I’m aware that oh2 walks knee-deep through molten cheese while it’s reloading the rules-files. So I’m not surprised to see it slow down and get less responsive while that happens.
With a logInfo - line in each .rules file’s ‘when System started’ this process is visible in the openhab.log and I’m positive that this is not what I write about.
Thanks! for the curl line. 1085 items here, just for the record.
Went down your checklist, no while loop at all except 5 under automation/lib/python, no Grafana chart rendering I’m aware off (do HabPanel charts count? But I removed the ‘live’ flag from most of them as they were an obvious suspect and easily get Chromium to it’s knees.)
Which leaves me with ‘some other’.
Typical restart loops (that includes stop and start times until the last rule logs it’s init done) are 12-14 min with a 3 min pause after the initial 005_start.rules was called, included. I implemented a deferred rule loading inspired by Cleaning up the startup process / renaming rules (windows possible)
I went down the checklist Markus Storm kindly posted and linked and what i found was telegram action was still installed and telegram binding already. I fixed that. The REST documentation package binding is not installed here, does that matter?
Nothing else from that list triggered here so I fear I’ll have to get my hands dirty and enable debug logging. With regard to this, has any of you a link with info how to direct debug output into dedicated logs and not flood the openhab.log?
Checked the logs this morning and it was writing line after line of Dispatching…5000ms.
top jumped a bit with java from 16 to 168% but the majority of values were above 99%
I tried to log in with openha-cli console but after letting me wait a while the session was simply closed.
So I stopped openhab2 and cleared the contents of /var/lib/openhab2/cache and ./tmp
Starting openhab again after that looked ok in the logs until the moment that the .rules should load. It turned very angry then, throwing error logs at me to the tune of 17MB per minute.
Not kidding you:
ls -ltr /var/log/openhab2 returned:
-rw-rw-r-- 1 openhab openhab 0 Dec 11 13:13 audit.log
-rwxr-xr-x 1 openhab openhab 0 Feb 20 08:24 Readme.txt*
-rw-rw-r-- 1 openhab openhab 0 Mar 4 02:07 mqtt.log
-rw-rw-r-- 1 openhab openhab 17M Mar 4 21:28 openhab.log.1
lrwxrwxrwx 1 root root 33 Mar 5 14:38 rules.log -> /var/log/openhab2/rules/rules.log
lrwxrwxrwx 1 root root 35 Mar 5 14:38 jsr223.log -> /var/log/openhab2/jsr223/jsr223.log
-rw-rw-r-- 1 openhab openhab 17M Mar 8 00:06 events.log.1
-rw-rw-r-- 1 openhab openhab 17M Mar 8 11:28 events.log.2
-rw-rw-r-- 1 openhab openhab 17M Mar 8 19:00 events.log.3
drwxrwxr-x+ 2 openhab openhab 4.0K Mar 8 23:11 rules/
-rw-rw-r-- 1 openhab openhab 17M Mar 9 02:01 events.log.4
-rw-rw-r-- 1 openhab openhab 17M Mar 9 11:32 events.log.5
drwxrwxr-x+ 2 openhab openhab 4.0K Mar 9 18:31 jsr223/
-rw-rw-r-- 1 openhab openhab 17M Mar 9 20:11 events.log.6
-rw-rw-r-- 1 openhab openhab 17M Mar 10 04:40 events.log.7
drwxr-xr-x 23 root root 4.0K Mar 10 06:25 ../
-rw-rw-r-- 1 openhab openhab 17M Mar 10 08:14 openhab.log.2
-rw-rw-r-- 1 openhab openhab 17M Mar 10 08:16 openhab.log.3
-rw-rw-r-- 1 openhab openhab 17M Mar 10 08:17 openhab.log.4
-rw-rw-r-- 1 openhab openhab 17M Mar 10 08:19 openhab.log.5
-rw-rw-r-- 1 openhab openhab 17M Mar 10 08:20 openhab.log.6
-rw-rw-r-- 1 openhab openhab 17M Mar 10 08:21 openhab.log.7
drwxrwxr-x+ 4 openhab openhabian 4.0K Mar 10 08:21 ./
-rw-rw-r-- 1 openhab openhab 5.4M Mar 10 08:22 events.log
-rw-rw-r-- 1 openhab openhab 6.0M Mar 10 08:22 openhab.log
As far as I can tell the errors all start with lines like:
]
2020-03-10 08:23:24.317 [ERROR] [xbase.resource.BatchLinkableResource] - resolution of uriFragment '|::0.1.28.1::1::/0' failed.
java.lang.NullPointerException: null
at org.eclipse.smarthome.model.script.ScriptServiceUtil.getActionServices(ScriptServiceUtil.java:111) ~[?:?]
at org.eclipse.smarthome.model.script.scoping.ActionClassLoader.loadClass(ActionClassLoader.java:37) ~[?:?]
at java.lang.Class.forName0(Native Method) ~[?:1.8.0_222]
at java.lang.Class.forName(Class.java:348) ~[?:1.8.0_222]
at org.eclipse.xtext.common.types.access.impl.ClassFinder.forName(ClassFinder.java:41) ~[?:?]
at org.eclipse.xtext.common.types.access.impl.ClassFinder.forName(ClassFinder.java:15) ~[?:?]
and then 80 more lines. And then the next error, identical. It’s been doing that for half an hour now. Quite impressive when you look at it, java error messages are really something.
top lists java with ~110%
edit:
I lost patience after a while and stopped oh2 and the very last log lines gave a hint at what it had been trying to achieve:
]
2020-03-10 08:53:02.763 [ERROR] [xbase.resource.BatchLinkableResource] - resolution of uriFragment '|::0.2.0.2.0.0.7::0::/1' failed.
java.lang.NullPointerException: null
at org.eclipse.smarthome.model.script.ScriptServiceUtil.getActionServices(ScriptServiceUtil.java:111) ~[?:?]
at org.eclipse.smarthome.model.script.scoping.ActionClassLoader.loadClass(ActionClassLoader.java:37) ~[?:?]
at java.lang.Class.forName0(Native Method) ~[?:1.8.0_222]
at java.lang.Class.forName(Class.java:348) ~[?:1.8.0_222]
at org.eclipse.xtext.common.types.access.impl.ClassFinder.forName(ClassFinder.java:41) ~[?:?]
at org.eclipse.xtext.common.types.access.impl.ClassFinder.forName(ClassFinder.java:15) ~[?:?]
at org.eclipse.xtext.common.types.access.impl.AbstractClassFinder.forName(AbstractClassFinder.java:43) ~[?:?]
at org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.findClassByName(ReflectionTypeProvider.java:155) ~[?:?]
at org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.doFindTypeByName(ReflectionTypeProvider.java:116) ~[?:?]
at org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.findTypeByName(ReflectionTypeProvider.java:109) ~[?:?]
at org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getSingleElement(AbstractTypeScope.java:59) ~[?:?]
at org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getSingleElement(AbstractTypeScope.java:54) ~[?:?]
at org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getElements(AbstractTypeScope.java:73) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getElements(AbstractScope.java:137) ~[?:?]
at org.eclipse.xtext.scoping.impl.ScopeBasedSelectable.getExportedObjects(ScopeBasedSelectable.java:40) ~[?:?]
at org.eclipse.xtext.scoping.impl.ImportScope.getLocalElementsByName(ImportScope.java:154) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getElements(AbstractScope.java:134) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getElements(AbstractScope.java:137) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getElements(AbstractScope.java:137) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getElements(AbstractScope.java:137) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.ConstructorTypeScopeWrapper.getElements(ConstructorTypeScopeWrapper.java:123) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions(ScopeProviderAccess.java:143) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates(AbstractTypeComputationState.java:534) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:662) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:126) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractRootTypeComputationState.computeTypes(AbstractRootTypeComputationState.java:32) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver._computeTypes(LogicalContainerAwareReentrantTypeResolver.java:745) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes(LogicalContainerAwareReentrantTypeResolver.java:709) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeMemberTypes(LogicalContainerAwareReentrantTypeResolver.java:897) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver._computeTypes(LogicalContainerAwareReentrantTypeResolver.java:886) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes(LogicalContainerAwareReentrantTypeResolver.java:705) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes(LogicalContainerAwareReentrantTypeResolver.java:697) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.DefaultReentrantTypeResolver.resolve(DefaultReentrantTypeResolver.java:164) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.DefaultReentrantTypeResolver.reentrantResolve(DefaultReentrantTypeResolver.java:139) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$LazyResolvedTypes.resolveTypes(CachingBatchTypeResolver.java:80) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$2.process(CachingBatchTypeResolver.java:57) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$2.process(CachingBatchTypeResolver.java:53) ~[?:?]
at org.eclipse.xtext.util.concurrent.IUnitOfWork$Void.exec(IUnitOfWork.java:37) ~[bundleFile:?]
at org.eclipse.xtext.util.OnChangeEvictingCache.execWithoutCacheClear(OnChangeEvictingCache.java:128) ~[bundleFile:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver.doResolveTypes(CachingBatchTypeResolver.java:53) ~[bundleFile:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractBatchTypeResolver.resolveTypes(AbstractBatchTypeResolver.java:69) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkingService.resolveBatched(BatchLinkingService.java:60) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkingService.resolveBatched(BatchLinkingService.java:41) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkableResource.getEObject(BatchLinkableResource.java:117) ~[bundleFile:?]
at org.eclipse.emf.ecore.resource.impl.ResourceSetImpl.getEObject(ResourceSetImpl.java:223) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.EcoreUtil.resolve(EcoreUtil.java:203) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.EcoreUtil.resolve(EcoreUtil.java:259) ~[bundleFile:?]
at org.eclipse.emf.ecore.impl.BasicEObjectImpl.eResolveProxy(BasicEObjectImpl.java:1477) ~[bundleFile:?]
at org.eclipse.xtext.xbase.impl.XAbstractFeatureCallImplCustom.getFeature(XAbstractFeatureCallImplCustom.java:48) ~[?:?]
at org.eclipse.xtext.xbase.validation.XbaseValidator.checkNoCircularConstructorCall(XbaseValidator.java:996) ~[?:?]
at sun.reflect.GeneratedMethodAccessor58.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_222]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_222]
at org.eclipse.xtext.validation.AbstractDeclarativeValidator$MethodWrapper.invoke(AbstractDeclarativeValidator.java:127) ~[bundleFile:?]
at org.eclipse.xtext.validation.AbstractDeclarativeValidator.internalValidate(AbstractDeclarativeValidator.java:318) ~[bundleFile:?]
at org.eclipse.xtext.validation.AbstractInjectableValidator.validate(AbstractInjectableValidator.java:71) ~[bundleFile:?]
at org.eclipse.xtext.validation.CompositeEValidator.validate(CompositeEValidator.java:150) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidate(Diagnostician.java:171) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:158) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:181) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:181) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:185) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:185) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:108) ~[bundleFile:?]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.lambda$2(ModelRepositoryImpl.java:290) ~[bundleFile:?]
at org.eclipse.smarthome.model.core.internal.SafeEMFImpl.call(SafeEMFImpl.java:30) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.validateModel(ModelRepositoryImpl.java:290) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:103) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:247) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.processWatchEvent(FolderObserver.java:310) [bundleFile:?]
at org.eclipse.smarthome.core.service.WatchQueueReader.run(WatchQueueReader.java:240) [bundleFile:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_222]
2020-03-10 08:53:03.427 [INFO ] [b.core.service.AbstractActiveService] - Expire Refresh Service has been shut down
2020-03-10 08:53:03.427 [INFO ] [b.core.service.AbstractActiveService] - HTTP Refresh Service has been shut down
2020-03-10 08:53:03.726 [WARN ] [el.core.internal.ModelRepositoryImpl] - Ignoring file '020_coloring.rules' as we do not have a parser for it.
2020-03-10 08:53:03.889 [INFO ] [basic.internal.servlet.WebAppServlet] - Stopped Basic UI
2020-03-10 08:53:34.156 [INFO ] [panel.internal.HABPanelDashboardTile] - Stopped HABPanel
2020-03-10 08:53:34.190 [INFO ] [openhab.ui.paper.internal.PaperUIApp] - Stopped Paper UI
2020-03-10 08:53:34.205 [INFO ] [.dashboard.internal.DashboardService] - Stopped Dashboard
“Ignoring file ‘020_coloring.rules’ as we do not have a parser for it.” That would have been the second of the DSL rules to load.
edit 2:
When I started it again, oh2 looked at me with innocent eyes and booted like nothing unusual had ever happened. Looks like clearing the cache to get a clean start is not an option currently.
Only do this if you are seeing errors that you think a reinstall of the bindings will fix. I’m not sure that’s the case here.
Cleaning the cache is actually quite disruptive, almost as disruptive as an upgrade. It is not unusual to see errors after a cache cleaning and there is at least one known bug requiring one or more restarts of OH after cleaning the cache. The errors are usually different from what you saw (i.e. Items that clearly exist are reported as not existing) but the caution is the same, after clearing the cache you should expect to need to restart OH at least once. And never clear the cache while OH is running.
just for the record, an update after 2 days:
I had noticed that rather often there was an error message from the chromecast binding just before the Dispatching…5000ms lines would begin. Something about 0 payload.
I gave it a try and uninstalled the chromecast binding.
Things have run remarkably calm since then.
My log looks really messy with similar messages and I wonder if I should not have clearde the cache.
I restarted OH several time and also removed all rules during startup and copied them back in afterwards.
I still get plenty of messages like (on raspi 3bx + openhabian and 2.5.3 stable:
2020-03-31 19:06:57.253 [ERROR] [xbase.resource.BatchLinkableResource] - resolution of uriFragment '|::0.2.5.2.0.1.2::0::/2' failed.
java.lang.NullPointerException: null
at org.eclipse.smarthome.model.script.ScriptServiceUtil.getActionServices(ScriptServiceUtil.java:111) ~[?:?]
at org.eclipse.smarthome.model.script.scoping.ActionClassLoader.loadClass(ActionClassLoader.java:37) ~[?:?]
at java.lang.Class.forName0(Native Method) ~[?:1.8.0_152]
at java.lang.Class.forName(Class.java:348) ~[?:1.8.0_152]
at org.eclipse.xtext.common.types.access.impl.ClassFinder.forName(ClassFinder.java:41) ~[?:?]
at org.eclipse.xtext.common.types.access.impl.ClassFinder.forName(ClassFinder.java:15) ~[?:?]
at org.eclipse.xtext.common.types.access.impl.AbstractClassFinder.forName(AbstractClassFinder.java:43) ~[?:?]
at org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.findClassByName(ReflectionTypeProvider.java:155) ~[?:?]
at org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.doFindTypeByName(ReflectionTypeProvider.java:116) ~[?:?]
at org.eclipse.xtext.common.types.access.reflect.ReflectionTypeProvider.findTypeByName(ReflectionTypeProvider.java:109) ~[?:?]
at org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getSingleElement(AbstractTypeScope.java:59) ~[?:?]
at org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getSingleElement(AbstractTypeScope.java:54) ~[?:?]
at org.eclipse.xtext.common.types.xtext.AbstractTypeScope.getElements(AbstractTypeScope.java:73) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getElements(AbstractScope.java:137) ~[?:?]
at org.eclipse.xtext.scoping.impl.ScopeBasedSelectable.getExportedObjects(ScopeBasedSelectable.java:40) ~[?:?]
at org.eclipse.xtext.scoping.impl.ImportScope.getLocalElementsByName(ImportScope.java:154) ~[?:?]
at org.eclipse.xtext.scoping.impl.ImportScope.getSingleLocalElementByName(ImportScope.java:142) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement(AbstractScope.java:105) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement(AbstractScope.java:108) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement(AbstractScope.java:108) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement(AbstractScope.java:108) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.TypeLiteralScope.getLocalElementsByName(TypeLiteralScope.java:48) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractSessionBasedScope.getElements(AbstractSessionBasedScope.java:174) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractSessionBasedScope$1.get(AbstractSessionBasedScope.java:180) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractSessionBasedScope$1.get(AbstractSessionBasedScope.java:177) ~[?:?]
at org.eclipse.xtext.scoping.impl.AbstractScope$ParentIterable.iterator(AbstractScope.java:60) ~[?:?]
at com.google.common.collect.FluentIterable$3$1.get(FluentIterable.java:296) ~[bundleFile:?]
at com.google.common.collect.FluentIterable$3$1.get(FluentIterable.java:293) ~[bundleFile:?]
at com.google.common.collect.AbstractIndexedListIterator.next(AbstractIndexedListIterator.java:77) ~[bundleFile:?]
at com.google.common.collect.Iterators$ConcatenatedIterator.hasNext(Iterators.java:1330) ~[bundleFile:?]
at com.google.common.collect.Iterators$5.computeNext(Iterators.java:635) ~[bundleFile:?]
at com.google.common.collect.AbstractIterator.tryToComputeNext(AbstractIterator.java:141) ~[bundleFile:?]
at com.google.common.collect.AbstractIterator.hasNext(AbstractIterator.java:136) ~[bundleFile:?]
at com.google.common.collect.Iterators$ConcatenatedIterator.hasNext(Iterators.java:1321) ~[bundleFile:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates(AbstractTypeComputationState.java:412) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:1226) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:112) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState$1.getActualType(AbstractTypeComputationState.java:403) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScopeForReceiver(FeatureScopes.java:215) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScope(FeatureScopes.java:92) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.createFeatureCallScope(AbstractFeatureScopeSession.java:177) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.getScope(AbstractFeatureScopeSession.java:48) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions(ScopeProviderAccess.java:142) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates(AbstractTypeComputationState.java:409) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:1226) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:112) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState$1.getActualType(AbstractTypeComputationState.java:403) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScopeForReceiver(FeatureScopes.java:215) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScope(FeatureScopes.java:92) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.createFeatureCallScope(AbstractFeatureScopeSession.java:177) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.getScope(AbstractFeatureScopeSession.java:48) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions(ScopeProviderAccess.java:142) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates(AbstractTypeComputationState.java:409) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:1226) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:112) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState$1.getActualType(AbstractTypeComputationState.java:403) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScopeForReceiver(FeatureScopes.java:215) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.FeatureScopes.createFeatureCallScope(FeatureScopes.java:92) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.createFeatureCallScope(AbstractFeatureScopeSession.java:177) ~[?:?]
at org.eclipse.xtext.xbase.scoping.batch.AbstractFeatureScopeSession.getScope(AbstractFeatureScopeSession.java:48) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions(ScopeProviderAccess.java:142) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates(AbstractTypeComputationState.java:409) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:1226) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:112) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:254) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:132) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:483) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:118) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:38) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.doComputeTypes(AbstractTypeComputationState.java:121) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.computeTypes(AbstractTypeComputationState.java:109) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractRootTypeComputationState.computeTypes(AbstractRootTypeComputationState.java:32) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver._computeTypes(LogicalContainerAwareReentrantTypeResolver.java:827) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes(LogicalContainerAwareReentrantTypeResolver.java:711) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeMemberTypes(LogicalContainerAwareReentrantTypeResolver.java:897) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver._computeTypes(LogicalContainerAwareReentrantTypeResolver.java:886) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes(LogicalContainerAwareReentrantTypeResolver.java:705) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.LogicalContainerAwareReentrantTypeResolver.computeTypes(LogicalContainerAwareReentrantTypeResolver.java:697) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.DefaultReentrantTypeResolver.resolve(DefaultReentrantTypeResolver.java:164) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.DefaultReentrantTypeResolver.reentrantResolve(DefaultReentrantTypeResolver.java:139) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$LazyResolvedTypes.resolveTypes(CachingBatchTypeResolver.java:80) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$2.process(CachingBatchTypeResolver.java:57) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver$2.process(CachingBatchTypeResolver.java:53) ~[?:?]
at org.eclipse.xtext.util.concurrent.IUnitOfWork$Void.exec(IUnitOfWork.java:37) ~[bundleFile:?]
at org.eclipse.xtext.util.OnChangeEvictingCache.execWithoutCacheClear(OnChangeEvictingCache.java:128) ~[bundleFile:?]
at org.eclipse.xtext.xbase.typesystem.internal.CachingBatchTypeResolver.doResolveTypes(CachingBatchTypeResolver.java:53) ~[bundleFile:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractBatchTypeResolver.resolveTypes(AbstractBatchTypeResolver.java:69) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkingService.resolveBatched(BatchLinkingService.java:60) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkingService.resolveBatched(BatchLinkingService.java:41) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkableResource.getEObject(BatchLinkableResource.java:117) ~[bundleFile:?]
at org.eclipse.emf.ecore.resource.impl.ResourceSetImpl.getEObject(ResourceSetImpl.java:223) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.EcoreUtil.resolve(EcoreUtil.java:203) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.EcoreUtil.resolve(EcoreUtil.java:259) ~[bundleFile:?]
at org.eclipse.emf.ecore.impl.BasicEObjectImpl.eResolveProxy(BasicEObjectImpl.java:1477) ~[bundleFile:?]
at org.eclipse.xtext.xbase.impl.XAbstractFeatureCallImplCustom.getFeature(XAbstractFeatureCallImplCustom.java:48) ~[?:?]
at org.eclipse.xtext.xbase.validation.XbaseValidator.checkExplicitOperationCall(XbaseValidator.java:1795) ~[?:?]
at sun.reflect.GeneratedMethodAccessor35.invoke(Unknown Source) ~[?:?]
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:1.8.0_152]
at java.lang.reflect.Method.invoke(Method.java:498) ~[?:1.8.0_152]
at org.eclipse.xtext.validation.AbstractDeclarativeValidator$MethodWrapper.invoke(AbstractDeclarativeValidator.java:127) ~[bundleFile:?]
at org.eclipse.xtext.validation.AbstractDeclarativeValidator.internalValidate(AbstractDeclarativeValidator.java:318) ~[bundleFile:?]
at org.eclipse.xtext.validation.AbstractInjectableValidator.validate(AbstractInjectableValidator.java:71) ~[bundleFile:?]
at org.eclipse.xtext.validation.CompositeEValidator.validate(CompositeEValidator.java:150) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidate(Diagnostician.java:171) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:158) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:181) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:185) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:185) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.doValidateContents(Diagnostician.java:185) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:161) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:137) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.Diagnostician.validate(Diagnostician.java:108) ~[bundleFile:?]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.lambda$2(ModelRepositoryImpl.java:290) ~[bundleFile:?]
at org.eclipse.smarthome.model.core.internal.SafeEMFImpl.call(SafeEMFImpl.java:30) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.validateModel(ModelRepositoryImpl.java:290) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.ModelRepositoryImpl.addOrRefreshModel(ModelRepositoryImpl.java:103) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.checkFile(FolderObserver.java:247) [bundleFile:?]
at org.eclipse.smarthome.model.core.internal.folder.FolderObserver.processWatchEvent(FolderObserver.java:310) [bundleFile:?]
at org.eclipse.smarthome.core.service.WatchQueueReader.run(WatchQueueReader.java:240) [bundleFile:?]
at java.lang.Thread.run(Thread.java:748) [?:1.8.0_152]
I think I may have seen someone mention a similar error in another thread but I don’t have time right now to search to verify (search for “BatchLinckableResource”) and see if you can find it.
It’s comming from xbase/xtext so it’s ultimately coming from something related to DSL Rules or other text based configs. So a clear the cache is unlikely to have been the cause and doing it again is unlikely to be the solution.
Lacking any other ideas, I’d start OH with a clean conf folder (i.e. no text based configs what so ever) and add them back one at a time until the error occurs again. Then you will have at least narrowed it down to a specific file.
That would be great because I’m clueless right now.
Thanks for your quick response. I will search for the thread you mentioned.
My log is flooded with other errors as well, so it feels like more wrong than right.
(Also some persistence related stuff).
Maybe it would be the right time to start from scratch with a brand new openhabian image…
It suddenly happened
EDIT:
Actually this is the only thread mentioning BatchLinckableResource
Anyway, I need to look for the errors step by step and might come up with a new thread at some point
You could be looking at symptom here with “takes more than”, not clue for cause. If things are getting bogged down dealing with errors, it seems likely other things would complain about delays.
Given that getActionServices is involved in the thread I posted, as well as the error posted above, this would seem to have something to do with the use of thing actions. In the thread I posted, the issue appeared to be the call to getActions outside the body of a rule.
