[SOLVED] createTimer in rule stopped working and shows error

4u2fast · January 26, 2019, 11:48am

i’m testing some Echo Control rules

here the rule

var var_Echo_Garten_Volume = null
var Timer Test1_Timer = null
rule "Test"
when 
Item testbutton changed to ON
then
			{
					val var_Echo_Garten_Volume =  Echo_Garten_Volume.state()
					Echo_Garten_Volume.sendCommand(60)
					Echo_Garten_TTS.sendCommand('Test TTS ')
					
						Test1_Timer = createTimer(now.plusSeconds(10)) [|
						Echo_Garten_Volume.sendCommand(var_Echo_Garten_Volume)
					]
			}
end

main issue is that TTS_Volume is not working for me, so i created a rule to save the volume and restore it after the announcement (was working fine several days)

no after apt-get update / upgrade i receive the following error

any idea what is causing this ?
Thanks
Thomas

2019-01-26 12:39:56.555 [ome.event.ItemCommandEvent] - Item 'testbutton' received command ON

2019-01-26 12:39:56.570 [vent.ItemStateChangedEvent] - testbutton changed from OFF to ON

2019-01-26 12:39:57.683 [ome.event.ItemCommandEvent] - Item 'Echo_Garten_Volume' received command 60

2019-01-26 12:39:57.687 [ome.event.ItemCommandEvent] - Item 'Echo_Garten_TTS' received command Test TTS 

2019-01-26 12:39:57.693 [nt.ItemStatePredictedEvent] - Echo_Garten_Volume predicted to become 60

2019-01-26 12:39:57.704 [nt.ItemStatePredictedEvent] - Echo_Garten_TTS predicted to become Test TTS 

2019-01-26 12:39:57.711 [vent.ItemStateChangedEvent] - Echo_Garten_TTS changed from  to Test TTS 

2019-01-26 12:40:00.087 [vent.ItemStateChangedEvent] - Echo_Garten_TTS changed from Test TTS  to 

==> /var/log/openhab2/openhab.log <==

2019-01-26 12:40:07.688 [ERROR] [org.quartz.core.JobRunShell         ] - Job DEFAULT.2019-01-26T12:40:07.685+01:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {

  <XFeatureCallImplCustom>.sendCommand(<XFeatureCallImplCustom>)

} ] threw an unhandled Exception: 

java.lang.IllegalStateException: Could not invoke method: org.eclipse.smarthome.model.script.actions.BusEvent.sendCommand(org.eclipse.smarthome.core.items.Item,java.lang.String) on instance: null

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1103) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1061) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._invokeFeature(XbaseInterpreter.java:1047) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeFeature(XbaseInterpreter.java:992) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.invokeFeature(ScriptInterpreter.java:151) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:772) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:220) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:204) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:447) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:228) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:204) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluate(XbaseInterpreter.java:190) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.ClosureInvocationHandler.doInvoke(ClosureInvocationHandler.java:46) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.AbstractClosureInvocationHandler.invoke(AbstractClosureInvocationHandler.java:29) ~[?:?]

	at com.sun.proxy.$Proxy129.apply(Unknown Source) ~[?:?]

	at org.eclipse.smarthome.model.script.internal.actions.TimerExecutionJob.execute(TimerExecutionJob.java:49) ~[?:?]

	at org.quartz.core.JobRunShell.run(JobRunShell.java:202) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]

	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]

Caused by: java.lang.IllegalArgumentException: java.lang.ClassCastException@153e27d

	at sun.reflect.GeneratedMethodAccessor158.invoke(Unknown Source) ~[?:?]

	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]

	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1086) ~[?:?]

	... 19 more

2019-01-26 12:40:07.794 [ERROR] [org.quartz.core.ErrorLogger         ] - Job (DEFAULT.2019-01-26T12:40:07.685+01:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {

  <XFeatureCallImplCustom>.sendCommand(<XFeatureCallImplCustom>)

} ] threw an exception.

org.quartz.SchedulerException: Job threw an unhandled exception.

	at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]

	at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [107:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]

Caused by: java.lang.IllegalStateException: Could not invoke method: org.eclipse.smarthome.model.script.actions.BusEvent.sendCommand(org.eclipse.smarthome.core.items.Item,java.lang.String) on instance: null

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1103) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1061) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._invokeFeature(XbaseInterpreter.java:1047) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeFeature(XbaseInterpreter.java:992) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.invokeFeature(ScriptInterpreter.java:151) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:772) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:220) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:204) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:447) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:228) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:204) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluate(XbaseInterpreter.java:190) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.ClosureInvocationHandler.doInvoke(ClosureInvocationHandler.java:46) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.AbstractClosureInvocationHandler.invoke(AbstractClosureInvocationHandler.java:29) ~[?:?]

	at com.sun.proxy.$Proxy129.apply(Unknown Source) ~[?:?]

	at org.eclipse.smarthome.model.script.internal.actions.TimerExecutionJob.execute(TimerExecutionJob.java:49) ~[?:?]

	at org.quartz.core.JobRunShell.run(JobRunShell.java:202) ~[?:?]

	... 1 more

Caused by: java.lang.IllegalArgumentException: java.lang.ClassCastException@153e27d

	at sun.reflect.GeneratedMethodAccessor158.invoke(Unknown Source) ~[?:?]

	at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) ~[?:?]

	at java.lang.reflect.Method.invoke(Method.java:498) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1086) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1061) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._invokeFeature(XbaseInterpreter.java:1047) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeFeature(XbaseInterpreter.java:992) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.invokeFeature(ScriptInterpreter.java:151) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:772) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:220) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:204) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:447) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:228) ~[?:?]

	at org.eclipse.smarthome.model.script.interpreter.ScriptInterpreter.doEvaluate(ScriptInterpreter.java:226) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.internalEvaluate(XbaseInterpreter.java:204) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.evaluate(XbaseInterpreter.java:190) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.ClosureInvocationHandler.doInvoke(ClosureInvocationHandler.java:46) ~[?:?]

	at org.eclipse.xtext.xbase.interpreter.impl.AbstractClosureInvocationHandler.invoke(AbstractClosureInvocationHandler.java:29) ~[?:?]

	at com.sun.proxy.$Proxy129.apply(Unknown Source) ~[?:?]

	at org.eclipse.smarthome.model.script.internal.actions.TimerExecutionJob.execute(TimerExecutionJob.java:49) ~[?:?]

	at org.quartz.core.JobRunShell.run(JobRunShell.java:202) ~[?:?]

	... 1 more

==> /var/log/openhab2/events.log <==

2019-01-26 12:40:16.782 [vent.ItemStateChangedEvent] - TimeKNX changed from 2019-01-26T12:39:36.961+0100

4u2fast · January 26, 2019, 12:18pm

ok, after clear cache and reboot all is working again !

vzorglub · January 26, 2019, 12:26pm

It don’t know how it is working, your rule is riddled with errors:

Test if the timer is null before creating is and then reset it in the lambda
.state not .state()
ADVICE: use the syntax createTimer(time, [ | .... ]) instead of createTimer(time) [| ... ] it’s clearer as everything is inside the timer ()
You defined var_Echo_Garten_Volume as a val inside the rule again but you declared it as global
Try to define the type of global variables as the “compiler” may ave trouble figuring it out later
ADVICE: use spaces instead of TABS. It will be more consistent is different editors and the website

QUESTION, do you use VS Code to edit your files?

var Number var_Echo_Garten_Volume = null
var Timer Test1_Timer = null
rule "Test"
when 
    Item testbutton changed to ON
then
    var_Echo_Garten_Volume =  Echo_Garten_Volume.state
    Echo_Garten_Volume.sendCommand(60)
    Echo_Garten_TTS.sendCommand("Test TTS")
    if (Test1_Timer === null) {
        Test1_Timer = createTimer(now.plusSeconds(10), [ |
            Echo_Garten_Volume.sendCommand(var_Echo_Garten_Volume)
            Test1_Timer = null //Cancel Timer
        ])
    }
end

4u2fast · January 26, 2019, 3:46pm

Thanks for your help and suggestion to improve my rules

i have tried with your code but it doesn’t work

2019-01-26 16:39:34.800 [ome.event.ItemCommandEvent] - Item 'testbutton' received command ON

2019-01-26 16:39:34.831 [vent.ItemStateChangedEvent] - testbutton changed from OFF to ON


==> /var/log/openhab2/openhab.log <==

2019-01-26 16:39:35.967 [ERROR] [ntime.internal.engine.RuleEngineImpl] - Rule 'Test': An error occurred during the script execution: Couldn't invoke 'assignValueTo' for feature JvmVoid:  (eProxyURI: Test.rules#|::0.2.1.2.0.0::0::/1)

==> /var/log/openhab2/events.log <==

i’m using Programmers notepad to update the config (plain text)

will try to debug it

thanks
Thomas

4u2fast · January 26, 2019, 3:56pm

ok, got it working like this:

var Timer Test1_Timer = null
rule "Test"
when 
Item testbutton changed to ON
then
	{
        val var_Echo_Garten_Volume =  Echo_Garten_Volume.state
	Echo_Garten_Volume.sendCommand(60)
	Echo_Garten_TTS.sendCommand('Test TTS ')
		if (Test1_Timer === null) {
				Test1_Timer = createTimer(now.plusSeconds(10)) [ |
				Echo_Garten_Volume.sendCommand(var_Echo_Garten_Volume)
				Test1_Timer = null
					]
			}}

here the log

2019-01-26 16:57:54.626 [vent.ItemStateChangedEvent] - testbutton changed from OFF to ON

2019-01-26 16:57:54.649 [ome.event.ItemCommandEvent] - Item 'Echo_Garten_Volume' received command 60

2019-01-26 16:57:54.658 [ome.event.ItemCommandEvent] - Item 'Echo_Garten_TTS' received command Test TTS 

2019-01-26 16:57:54.664 [nt.ItemStatePredictedEvent] - Echo_Garten_Volume predicted to become 60

2019-01-26 16:57:54.674 [nt.ItemStatePredictedEvent] - Echo_Garten_TTS predicted to become Test TTS 

2019-01-26 16:57:54.690 [vent.ItemStateChangedEvent] - Echo_Garten_Volume changed from 42 to 60

2019-01-26 16:57:54.697 [vent.ItemStateChangedEvent] - Echo_Garten_TTS changed from  to Test TTS 

2019-01-26 16:57:55.750 [ome.event.ItemCommandEvent] - Item 'testbutton' received command OFF

2019-01-26 16:57:55.756 [vent.ItemStateChangedEvent] - testbutton changed from ON to OFF

2019-01-26 16:57:56.902 [vent.ItemStateChangedEvent] - Echo_Garten_TTS changed from Test TTS  to 

2019-01-26 16:58:04.669 [ome.event.ItemCommandEvent] - Item 'Echo_Garten_Volume' received command 42

2019-01-26 16:58:04.683 [nt.ItemStatePredictedEvent] - Echo_Garten_Volume predicted to become 42

2019-01-26 16:58:04.703 [vent.ItemStateChangedEvent] - Echo_Garten_Volume changed from 60 to 42