Adding .toString results: cannot invoke method public java.lang.String java.lang.Object.toString() on null
and rule crashes.
It’s been telling us all along; that is the issue. Use nRBG = nRBG + 1
I’ve just been playing with a test rule, and to my surprise that error doesn’t stop the timer execution at once. It stumbles along, but messes up again at the reschedule which has nothing to with nRBG. No idea why, some kind of non-fatal error that ruins the timer context somehow. Maybe it sets the timer handle to the error result.
You mean to change this:
nRBG += 1
for this:
nRBG = nRBG + 1
?
I’ll try, but why? 
Number variables don’t have a += operator
EDIT - Damn this is weird - I played again, and now += is not throwing an error for a Number variable … but it doesn’t increment either. (OH2.4 by the way.)
MORE EDIT - ok, working-but-not-incrementing was my fault, finger trouble.
nnnn += 1
does work as expected.
I went back over what I had done, and I can recreate the error about +=
by having the variable null beforehand. No surprise there, really.
I cannot now make forcing the += error cause a reschedule problem, even though I definitely have a log connecting both from earlier.
2019-03-28 15:01:20.857 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 6
2019-03-28 15:01:20.859 [ERROR] [org.quartz.core.JobRunShell ] - Job DEFAULT.2019-03-28T15:01:20.851+01:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
<null>.nFCTZZ = <XBinaryOperationImplCustom>
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
org.eclipse.xtext.xbase.impl.XSwitchExpressionImpl@11b492b3
} ] threw an unhandled Exception:
java.lang.NullPointerException: cannot invoke method public abstract boolean org.eclipse.smarthome.model.script.actions.Timer.reschedule(org.joda.time.base.AbstractInstant) on null
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1071) ~[?:?]
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._doEvaluate(XbaseInterpreter.java:484) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:256) ~[?:?]
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.$Proxy190.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) [109:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [109:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
What’s that? Comes from some other timer.
Yes, triggered in the the same place as before in Gate rule after change from += …
ok, there is not any “FCTZZ” loginfo mentioned in the two Gate rules you last showed us.
The += appears to be my mistake; it works (so long as you don’t start with a null)
You can log a handle out by using .toString. Obviously that fails if the handle is null.
It’s worse. You will have the same timer code running at the same time. This means with the new one changes variables those changes will be made to the old one too. That’s the problem with lambdas in general. They are not thread safe and unless you create a new one, multiple threads will be working with the same code instead of their own copy of the code.
Usually we never notice this sort of problem with Timer lambdas or forEach and the like because we tend to intuitively avoid the use case you brought up (e.g. reschedule before the Timer is finished). We more often see this problem with global lambdas because it’s much easier to have two Rules execute close enough together that a given lambda will be called before the previous call finished.
@Karol, rossko57 is doing a great job helping here. I’ve only one alternative idea.
I have a philosophy when working with OH that sometimes it can be easier to solve an error by changing the overall approach so that the error isn’t even possible. In this case, perhaps we can solve the problem, or at least get more useful and meaningful errors, if you instead used the Expire binding instead of Timers. See Design Pattern: Expire Binding Based Timers for details.
This would move the errors out of the lambdas which can be informative. And sometimes just reworking the code reveals the problem as you refactor things around.
That’s true. rossko57 have put a lot of effort into solving this problem, and I’m trully grateful for his help and commitment.
But if I can ask for further help, I wan’t to suggest something… Maybe I’m wrong, but everytime exception appears, it shows right after turning ON “Read_Trigger.sendCommand(ON)”, which is very near to well known “tRBG 6” tag (as far as I remember most of exception was initialy disclosed near to that one). “Read_Trigger.sendCommand” is trigger for TTS rule (look bellow) that is responsible for: setting up proper volume level on each home Google speaker, read phrase, and set volume down (it have own timer too).
rule "TTS Function"
when
Item Read_Trigger changed to ON
then
if(tFCTZZ === null) {
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 1")
nFCTZZ = 0
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 2")
tFCTZZ = createTimer(now, [|
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 3")
nFCTZZ = nFCTZZ + 1
logInfo("KWI.debug.rules","R_DEBUG: (" + nFCTZZ + ") FCTZZ 4")
switch (nFCTZZ.intValue) {
case 1 : {
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 5")
Group_Speaker_AllSpeakers.allMembers.forEach [item |
//item.sendCommand(60)
item.sendCommand(30)
]
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 6")
tFCTZZ.reschedule(now.plusSeconds(1))
}
case 2 : {
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 7")
//say(InfoToRead.state.toString)
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 8")
tFCTZZ.reschedule(now.plusSeconds(20))
}
case 3 : {
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 9")
Group_Speaker_AllSpeakers.allMembers.forEach [item |
item.sendCommand(30)
]
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 10")
tFCTZZ.reschedule(now.plusSeconds(1))
}
default: {
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 11")
tFCTZZ = null
}
}
])
}
end
Hint: “say” function is a streamer via Chromcast and Google TTS api.
The letest tests show that when I comment “say line” no exceptions is noticed and when I remove comment and save rules (even restart OH), right after that first exception shows.
2019-03-28 21:40:35.934 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: tRBG 6 (org.eclipse.smarthome.model.script.internal.actions.TimerImpl@638a1aa4)
2019-03-28 21:40:35.936 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: tRBG 7 (org.eclipse.smarthome.model.script.internal.actions.TimerImpl@638a1aa4)
2019-03-28 21:40:36.713 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 1
2019-03-28 21:40:36.714 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 2
2019-03-28 21:40:36.718 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 3
2019-03-28 21:40:36.719 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: (1) FCTZZ 4
2019-03-28 21:40:36.722 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 5
2019-03-28 21:40:36.727 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 6
2019-03-28 21:40:36.728 [ERROR] [org.quartz.core.JobRunShell ] - Job DEFAULT.2019-03-28T21:40:36.715+01:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
<null>.nFCTZZ = <XBinaryOperationImplCustom>
logInfo(<XStringLiteralImpl>,<XBinaryOperationImplCustom>)
org.eclipse.xtext.xbase.impl.XSwitchExpressionImpl@3320cf30
} ] threw an unhandled Exception:
“FCTZZ 6” tag in that rule is near little foreach loop setting volumes for speakers:
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 5")
Group_Speaker_AllSpeakers.allMembers.forEach [item |
//item.sendCommand(60)
item.sendCommand(30)
]
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 6")
Now I’m even more confused… Any sugestions?
EDIT: I have just commented out this foreach and there is no error. Interesting is that the same clausule is few lines bellow, after reading and it not couses this error. Still testing…
EDIT2: Or it’s just coincidence, and removig foreach just pust avay in time that problem…
Bit of a moving target, all this. You do need to keep in mind the effects of editing, while investigating.
okay, it would be nice to confirm the exception, but lets assume it’s the reschedule same as the previous very similar earlier log involving “FCTZZ”
I hear what you say about the “say()” line, but look at your error - it comes 1mS after logInfo “R_DEBUG: FCTZZ 6” so it’s the reschedule of case 1 that broke.
It just looks like something tramples on your global variables.
What java version are you running?
Please change
logInfo(“KWI.debug.rules”,“R_DEBUG: FCTZZ 3”)
to
logInfo(“KWI.debug.rules”,"R_DEBUG: FCTZZ 3 handle " + tFCTZZ.toString)
and
logInfo(“KWI.debug.rules”,“R_DEBUG: FCTZZ 6”)
to
logInfo(“KWI.debug.rules”,“R_DEBUG: FCTZZ 6” handle " + tFCTZZ.toString)
Now it’s in a little different place, but stil around…
2019-03-28 23:38:25.401 [INFO ] [arthome.model.script.KWI.debug.rules] - RS: 1
2019-03-28 23:38:25.402 [INFO ] [arthome.model.script.KWI.debug.rules] - REGRUN: Brama wjazdowa - Command
2019-03-28 23:38:25.405 [INFO ] [arthome.model.script.KWI.debug.rules] - RS: 2
2019-03-28 23:38:28.905 [INFO ] [arthome.model.script.KWI.debug.rules] - RS: 1
2019-03-28 23:38:28.905 [INFO ] [arthome.model.script.KWI.debug.rules] - REGRUN: Brama wjazdowa - Command
2019-03-28 23:38:28.906 [INFO ] [arthome.model.script.KWI.debug.rules] - RS: 2
2019-03-28 23:38:28.910 [INFO ] [arthome.model.script.KWI.debug.rules] - RS: 1
2019-03-28 23:38:28.911 [INFO ] [arthome.model.script.KWI.debug.rules] - REGRUN: Brama wjazdowa - Command
2019-03-28 23:38:28.912 [INFO ] [arthome.model.script.KWI.debug.rules] - RS: 2
2019-03-28 23:38:38.744 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: WWWS 3
2019-03-28 23:38:38.747 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: WWWS 4
2019-03-28 23:38:38.755 [INFO ] [arthome.model.script.KWI.debug.rules] - REGRUN: Funkcja wysyłająca notyfikacje PUSH ze zmiennej
2019-03-28 23:38:38.753 [INFO ] [arthome.model.script.KWI.debug.rules] - REGRUN: Funkcja czytająca tekst ze zmiennej
2019-03-28 23:38:38.756 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 1
2019-03-28 23:38:38.758 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 2
2019-03-28 23:38:38.761 [ERROR] [org.quartz.core.JobRunShell ] - Job DEFAULT.2019-03-28T23:38:38.758+01:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {
logInfo(<XStringLiteralImpl>,<XBinaryOperationImplCustom>)
<null>.nFCTZZ = <XBinaryOperationImplCustom>
logInfo(<XStringLiteralImpl>,<XBinaryOperationImplCustom>)
org.eclipse.xtext.xbase.impl.XSwitchExpressionImpl@6cfc38d8
} ] threw an unhandled Exception:
java.lang.NullPointerException: cannot invoke method public java.lang.String java.lang.Object.toString() on null
I’ll add “.toString” to rest of debug msgs and try again.
If you made this change
logInfo(“KWI.debug.rules”,"R_DEBUG: FCTZZ 3 handle " + tFCTZZ.toString)
that’s the line that broke, because tFCTZZ is null
Very interesting - this is our first pass, executed at time now
I’ll take a wild guess that now somehow causes the timer’s code to start executing before the reference / handle is fully formed in the global variable.
There may be some weird code length effect - maybe it somehow starts running before compilation is finished and messes up populating the occurrences of the global within the timer.
There’s a kind of circular reference, where we use our created lambda within the lambda.
Might only show up with a slow-to-compile code, like switch/case
Try
xxx = createTimer(now.plusMillis(100), [ |
where appropriate, to delay first run
I’m curious what will happen, but I have good feeling. I think we are going to the same direction… Couple minutes before post I’ve added 2s Thread::sleep just before timer creation and no errors appeared. After few minutes of test I had to close OH for Chromecast reconfiguration (because speakers groups was “offline’ing” form time to time, so I had to reconfigure them from scratch), so test was definitely to short:
rule "TTS Function"
when
Item Read_Trigger changed to ON
then
logInfo("KWI.debug.rules","REGRUN: Funkcja czytająca tekst ze zmiennej")
if(tFCTZZ === null) {
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 1")
nFCTZZ = 0
logInfo("KWI.debug.rules","R_DEBUG: FCTZZ 2")
//Thread::sleep(2000)
//tFCTZZ = createTimer(now, [|
tFCTZZ = createTimer(now.plusMillis(100), [|
Above rule already chenged to your suggestion.
Testing… I’ll let it running for few hours and we will see. 
Out of interest, do you run on a powerful box, or on a Pi? These different environments can throw up different timing/threading issues.
Definitely do not do this -
if(tFCTZZ === null) {
...
Thread::sleep(2000)
tFCTZZ = createTimer(
because it makes a window of opportunity in time for the rule to be triggered multiple times and get past the null check, before you make the handle non-null.
“I’ll prevent that happening” is better than “That’s odd, that should never happen?” 
You want the test and the action that affects the test, as close together as you can, since you are using them as a kind of locking mechanism.
OH was running all night and morning. Few (gate, etc.) action accured in meantime and only one exeception appeared but i ndifferent place of code:
2019-03-29 07:50:20.641 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: tSOBW 11
2019-03-29 07:50:20.643 [ERROR] [org.quartz.core.JobRunShell ] - Job DEFAULT.2019-03-29T07:50:15.576+01:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
<null>.nSOBW = <XBinaryOperationImplCustom>
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
org.eclipse.xtext.xbase.impl.XSwitchExpressionImpl@158489f3
} ] threw an unhandled Exception:
java.lang.NullPointerException: cannot invoke method public abstract boolean org.eclipse.smarthome.model.script.actions.Timer .reschedule(org.joda.time.base.AbstractInstant) on null
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1071) ~[?:?]
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._doEvaluate(XbaseInterpreter.java:484) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:256) ~[?:?]
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.$Proxy189.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) [109:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [109:org.eclipse.smarthome.core.sche duler:0.10.0.oh240]
2019-03-29 07:50:20.662 [ERROR] [org.quartz.core.ErrorLogger ] - Job (DEFAULT.2019-03-29T07:50:15.576+01:00: Proxy fo r org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
<null>.nSOBW = <XBinaryOperationImplCustom>
logInfo(<XStringLiteralImpl>,<XStringLiteralImpl>)
org.eclipse.xtext.xbase.impl.XSwitchExpressionImpl@158489f3
} ] threw an exception.
org.quartz.SchedulerException: Job threw an unhandled exception.
at org.quartz.core.JobRunShell.run(JobRunShell.java:213) [109:org.eclipse.smarthome.core.scheduler:0.10.0.oh240]
at org.quartz.simpl.SimpleThreadPool$WorkerThread.run(SimpleThreadPool.java:573) [109:org.eclipse.smarthome.core.sche duler:0.10.0.oh240]
Caused by: java.lang.NullPointerException: cannot invoke method public abstract boolean org.eclipse.smarthome.model.script.ac tions.Timer.reschedule(org.joda.time.base.AbstractInstant) on null
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.invokeOperation(XbaseInterpreter.java:1071) ~[?:?]
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._doEvaluate(XbaseInterpreter.java:484) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:256) ~[?:?]
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.$Proxy189.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
2019-03-29 07:50:37.384 [INFO ] [arthome.model.script.KWI.debug.rules] - R_DEBUG: FCTZZ 3 handleorg.eclipse.smarthome.model.s cript.internal.actions.TimerImpl@1be6561a
Was interesting it’s last line of rule that is made for Gate closing. That part of rule have no timer inside. Relation to last track is that before that line (“R_DEBUG: tSOBW 11”) have been executed 2 functions:
Read_Trigger.sendCommand(ON) //Well known TTS rule
SendNotification_Triggr.sendCommand(ON) //Telegram notofication
“FCTZZ 3” that is after exception is in code just after timer creation in TTS rule. <—
PS I will try to increase delay a little…
Looking at your last error log.
Be careful - just because the last log (tSOBW 11) happens just before the error, that does NOT mean that the error is iin the same bit of code. All these timers and rules can execute in parallel.
In this case, the error occurs within a couple of mS, so its probably associated.
The real clue is the skeleton mini trace thing
The error was preceded by a bit of code about nSOBW
This looks suspicious in your timer. What is the value of variable lBramaWjazdowaTPassed. at the time this timer runs? Can the timer access it, where was it created?
rule "Gate Guard - Opening"
when
Item Stan_bramy_wjazdowej changed to OFF
then
if(tSOBW === null) {
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 1")
nSOBW = 0
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 2")
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 3")
lBramaWjazdowaTOpened = now
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 4")
tSOBW = createTimer(now.plusMinutes(1), [|
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 5")
nSOBW = nSOBW + 1
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 6")
switch (nSOBW.intValue) {
case 1 : {
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 7")
lBramaWjazdowaTPassed = Math::round(( now.millis - lBramaWjazdowaTOpened.millis ) / 60000).intValue
logInfo("rules.IB","Guard: Main gate remains opened for " + lBramaWjazdowaTPassed.intValue + " minutes!")
InfoToRead.sendCommand("Guard: Main gate remains opened for " + lBramaWjazdowaTPassed.intValue + " minutes!")
Read_Trigger.sendCommand(ON)
CCTV_CamFront_Pos4.sendCommand(ON)
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 8")
tSOBW.reschedule(now.plusSeconds(3))
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 9")
}
case 2 : {
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 10")
sendTelegramPhoto("Karol", "http://192.168.1.100/tmpfs/snap.jpg?usr=admin&pwd=XXXXX", "Guard: Main gate remains opened for " + lBramaWjazdowaTPassed.intValue + " minutes!" )
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 11")
tSOBW.reschedule(now.plusSeconds(2))
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 12")
}
case 3 : {
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 13")
CCTV_CamFront_Pos5.sendCommand(ON)
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 14")
nSOBW = 0
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 15")
tSOBW.reschedule(now.plusMinutes(1))
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 16")
}
}
])
}
end
rule "Gate Guard - Closing"
when
Item Stan_bramy_wjazdowej changed to ON
then
logInfo("rules.IB","Guard: Main gate closed.")
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 17")
tSOBW?.cancel
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 18")
lBramaWjazdowaTOpened = null
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 19")
tSOBW = null
logInfo("KWI.debug.rules","R_DEBUG: tSOBW 20")
end
You have not declared this variable anywhere (var)? I’m not sure what scope it is in, but if you want to set it in one timer, read it in another timer, and set it in a rule, you will need to put it in global scope.
Sharing variables among rules and timers requires care.