It took some days before the error occurred again.
I added a log statement right at the beginning of the script and even this statement is not logged when the error occurs. Currently I have the suspicion, that the error only occurs when the script is started with a “system started” trigger, but I have to do more testing to confirm this.
You shouldn’t have to. What is the error you are seeing? The only think I can think of is that holidayName is still null when you call postUpdate. That wouldn’t work. But if holidayName is any sort of String that will work.
We need to see the whole rule. These few lines do not give any context. For example, what the heck is dayOfYear and how is it populated? What do you do with holiday? Are any of these Items, local variables, global variables? If variables, are they populated from Items?
I have the same error with the same script. But i didn’t find any solution in the other thread.
If i update openhab to the newest snapshot (i do that once a week or so) the first startup takes way longer than usual and the openhab.log is filled with the same errors. My script is called feestdag.script, but it is the exact same holiday.script from the same tutorial. feestdag.txt (3.7 KB)
rule "Feestdagen"
when
Time cron "0 0 0 * * ?" or
System started
then
callScript("feestdag")
end
//partial stack trace:
2019-08-25 21:00:31.814 [ERROR] [xbase.resource.BatchLinkableResource] - resolution of uriFragment '|::0.0.18.2.7.0.6::0::/2' failed.
java.lang.IllegalStateException: ON uses unsupported uri fragment tmp_feestdag.script#/1/@members.6
at org.eclipse.xtext.xbase.typesystem.internal.ScopeProviderAccess.getCandidateDescriptions(ScopeProviderAccess.java:158) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.internal.AbstractTypeComputationState.getLinkingCandidates(AbstractTypeComputationState.java:409) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:1112) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:101) ~[?:?]
at org.eclipse.smarthome.model.script.jvmmodel.ScriptTypeComputer.computeTypes(ScriptTypeComputer.java:39) ~[?:?]
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.AbstractLinkingCandidate.resolveArgumentType(AbstractLinkingCandidate.java:627) ~[?:?]
There are known problems with rules becoming active before other parts of openHAB have completely initialized. Especially when it is a more long winded startup, such as after an upgrade or cache deletion.
Thinks, i might work something out with a timer as workaround. Do you know if there is some github issue/discussion? Maybe i can add this as an example to get a fix?
Because the script is not using any binding/addon/ui/io/action/persistence etc. It must be some core stuff that is not initialized yet. Without really knowing all the inner workings of openHAB, it seems wrong to start a rule while the core is not yet ready to start anything.
I have no real idea if your symptom is another manifestation of the general boot-order problem, it just feels like it.
Even if it is, it may need something else to be taken account in any eventual fix.
I would suggest it is worth opening a new github issue - I would guess against openhab core.
I’m getting the same error message since updating to 2.5.0 M2. The script is also the same but in my case adapted to german language. feiertag.script.txt (3.6 KB)
I did some tests and it seems not being related to the rule which is calling the script is triggered before everything is loaded. I removed the call to my script and still get the issue.
Hence it seems this error occurs already when the script file is loaded. The only solution I found is to completely remove the script file from openhab.
If I readd the file once openhab is up and running the error doesn’t occure.
Is there any idea, what I can do to solve this issue, since it is completely blocking openhab from completing startup?
Well spotted; this rang a bell. Files in the /scripts folder are parsed at load time (and edit/save), so you don’t need to call them to trigger an error.
Delaying rule execution doesn’t help, sorry.
I would still say this is to do with boot order, parsing scripts before all Items are available, and I’m not surprised if timing does change between versions.
This does not seem right at all. I just tried a nonsense script in 2.4.0 and it loads without complaint. Perhaps you could try this in 2.5 to see if it shows something up.
/scripts/nonsense.script
postUpdate(nonsenseItem, "rubbish")
openhab.log
2019-08-28 23:05:49.618 [INFO ] [el.core.internal.ModelRepositoryImpl] - Loading model 'nonsense.script'
That loads properly you are right. However there seems to be something wired at the moment.
I copied the script back to /etc/openhab2/scripts while openhab2 is up and running fine and it was loaded properly.
When changing the rule file back so it is called I get the following error:
==> /var/log/openhab2/openhab.log <==
2019-08-29 07:18:33.740 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Error during the execution of startup rule 'Tageszeit berechnen': null
2019-08-29 07:18:33.886 [ERROR] [xbase.resource.BatchLinkableResource] - resolution of uriFragment '|::0.0.0.0::1::/0' failed.
org.eclipse.xtext.util.RuntimeIOException: java.io.FileNotFoundException: /var/lib/openhab2/zeit.rules (No such file or directory)
That looks like a big clue. Sorry I do not have OH2.5 to confirm.
That’s obviously wrong folder, I’m guessing that is the correct filename for the rule that calls the script. Like the script return messing up.
It’s quite possible that not many people use scripts to expose a bug here.
I suggest if this is repeatable you create a simple example and a github issue.
I’m using the same script for a year now, but after at least the update to 2.5.3 a normal system startup is no longer possible. As with the other posters the log is flooded with the Java exception, which causes the system so busy, that the initialization will not complete.
2020-05-24 16:12:55.795 [ERROR] [xbase.resource.BatchLinkableResource] - resolution of uriFragment '|::0.0.4.0::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_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.linking.impl.ImportedNamesAdapter$WrappingScope$1.iterator(ImportedNamesAdapter.java:79) ~[bundleFile:?]
at org.eclipse.xtext.scoping.impl.ImportScope.getLocalElementsByName(ImportScope.java:156) ~[bundleFile:?]
at org.eclipse.xtext.scoping.impl.ImportScope.getSingleLocalElementByName(ImportScope.java:142) ~[bundleFile:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement(AbstractScope.java:105) ~[bundleFile:?]
at org.eclipse.xtext.scoping.impl.AbstractScope.getSingleElement(AbstractScope.java:108) ~[bundleFile:?]
at org.eclipse.xtext.linking.impl.DefaultLinkingService.getLinkedObjects(DefaultLinkingService.java:114) ~[bundleFile:?]
at org.eclipse.xtext.linking.lazy.LazyLinkingResource.getEObject(LazyLinkingResource.java:265) ~[bundleFile:?]
at org.eclipse.xtext.xbase.resource.BatchLinkableResource.getEObject(BatchLinkableResource.java:119) ~[bundleFile:?]
at org.eclipse.emf.ecore.resource.impl.ResourceSetImpl.getEObject(ResourceSetImpl.java:223) ~[bundleFile:?]
at org.eclipse.emf.ecore.util.EcoreUtil.resolve(EcoreUtil.java:199) ~[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.common.types.impl.JvmTypeReferenceImplCustom.eResolveProxy(JvmTypeReferenceImplCustom.java:31) ~[?:?]
at org.eclipse.xtext.common.types.impl.JvmParameterizedTypeReferenceImpl.getType(JvmParameterizedTypeReferenceImpl.java:111) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.references.LightweightTypeReferenceFactory.getType(LightweightTypeReferenceFactory.java:242) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.references.LightweightTypeReferenceFactory.doVisitParameterizedTypeReference(LightweightTypeReferenceFactory.java:173) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.references.LightweightTypeReferenceFactory.doVisitParameterizedTypeReference(LightweightTypeReferenceFactory.java:52) ~[?:?]
at org.eclipse.xtext.common.types.impl.JvmParameterizedTypeReferenceImplCustom.accept(JvmParameterizedTypeReferenceImplCustom.java:53) ~[?:?]
at org.eclipse.xtext.common.types.util.AbstractTypeReferenceVisitor.visit(AbstractTypeReferenceVisitor.java:34) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.references.LightweightTypeReferenceFactory.toLightweightReference(LightweightTypeReferenceFactory.java:83) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.references.StandardTypeReferenceOwner.toLightweightTypeReference(StandardTypeReferenceOwner.java:117) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer._computeTypes(XbaseTypeComputer.java:524) ~[?:?]
at org.eclipse.xtext.xbase.typesystem.computation.XbaseTypeComputer.computeTypes(XbaseTypeComputer.java:152) ~[?:?]
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:199) ~[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.impl.XAbstractFeatureCallImplCustom.isStatic(XAbstractFeatureCallImplCustom.java:151) ~[?:?]
at org.eclipse.xtext.xbase.impl.XAbstractFeatureCallImplCustom.getActualArguments(XAbstractFeatureCallImplCustom.java:180) ~[?:?]
at org.eclipse.xtext.xbase.impl.XAbstractFeatureCallImplCustom.getActualArguments(XAbstractFeatureCallImplCustom.java:174) ~[?:?]
at org.eclipse.xtext.xbase.impl.XBinaryOperationImplCustom.getActualArguments(XBinaryOperationImplCustom.java:37) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer._exitPoints(DefaultEarlyExitComputer.java:244) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer.exitPoints(DefaultEarlyExitComputer.java:308) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer.getExitPoints(DefaultEarlyExitComputer.java:65) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer._exitPoints(DefaultEarlyExitComputer.java:190) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer.exitPoints(DefaultEarlyExitComputer.java:330) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer.getExitPoints(DefaultEarlyExitComputer.java:65) ~[?:?]
at org.eclipse.xtext.xbase.controlflow.DefaultEarlyExitComputer.isEarlyExit(DefaultEarlyExitComputer.java:48) ~[?:?]
at org.eclipse.xtext.xbase.validation.EarlyExitValidator.checkDeadCode(EarlyExitValidator.java:105) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:1.8.0_152]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:1.8.0_152]
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.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]
Today I updated to 2.5.5-1 and took some time in investigating. As here and in other threats already mentioned I figured out it is related to timing. After updating openHAB it looks like, that the items used in the postUpdate() are not available at the time the script is loaded.
Updates are applied to my installation as part of an “apt upgrade”. During the update the openhab2.service is stopped, but not restarted. My solution for the issue is to comment out the part of the script, which is updating the items, start the openhab2.service and let the system initialize. After half an hour I uncomment the part containing the postUpdate() and the script loads without any error.
Usually I would expect, that rules and scripts are loaded after things and items. I’m not familiar in posting bugs on github, but if someone could give me a hint how-to, I’ll do.
Hi Scott,
the update from 2.4 to 2.5 had not produced the issue, it started on one of the minor updates within 2.5. I think it was 2.5.2 to 2.5.3 but I’m not sure.
I’ve attached the complete openhab.log beginning with the startup after the update from 2.5.4-1 to 2.5.5-1 until it run without errors. I’ve only masked my coordinates in the Location settings. (it’s a tarball, but have to have a known extension to allow the upload. Please remove .txt from the filename to allow proper processing) openhab.log.tgz.txt (261.5 KB)
*Update: Clearing the cache only slowed down startup, but hadn’t helped to avoid the Java exeptions.