[SOLVED] Doorbell rule / persistence too slow

Hey folks,

I have a problem what I can’t solve after hours of thinking and trying.

I’m trying to create a rule which sends a notification to my smartphone when somebody rings at my door.
For this i installed a MDT AIO-0410V.01 which looks over the Voltage that my doorbell receives.

The output in my logfile looks like below:

19:14:47.205 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 232.0 to 1253.76
19:14:47.261 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 1253.76 to 3399.6800000000003
19:14:47.394 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 3399.6800000000003 to 5591.04
19:14:47.566 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5591.04 to 4590.08
19:14:47.717 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4590.08 to 2570.2400000000002
19:14:47.774 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 2570.2400000000002 to 1475.84
19:14:47.964 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 1475.84 to 558.72

My rule so far looks like this:

var Number Benachrichtigung = 0
var Timer Klingel_timer = null
rule "Klingel_Info"
when
	Item Klingel_Spannung changed
then
	if(Klingel_Spannung.historicState(now.minusSeconds(30)).state <= 1000 )
	{
		if(Benachrichtigung == 0)
		{
			Thread::sleep(5000)
			sendNotification("xxx@msn.com",Klingel_Spannung.maximumSince(now.minusSeconds(20)).state.toString)
			if(Klingel_Spannung.maximumSince(now.minusSeconds(10)).state >= 1000){
				sendNotification("xxx@msn.com","Ding Dong")
				Benachrichtigung = 1
				if (Klingel_timer !== null) 
				{
					Klingel_timer.reschedule(now.plusSeconds(30))
				}
				else
				{
					Klingel_timer = createTimer(now.plusSeconds(30))[|Benachrichtigung = 0]
				}
			}
		}
	}

My huge problem now is that the persistence service (mysql) only logs 1 of the 7 changed values.

| 2019-09-04 19:14:47 | 558.72 |

I have to use the persisted values cause over the day there are changes of the Voltage and the rule gets triggered without someone even ringing.
The changes are everytime betwen 50mV and 1000mV. Thats why i want to check if the current value is above 1000.
If i check the current value in the rule it gives out the value that gets persisted. I think the engine is to slow for so much changes in such a little time.

Have someone of you a good idea how to solve this?

I’m not so sure that as this is implemented this would work very well even if persistence were able to keep up, which won’t ever be the case.

I’m also very concerned about that 5 second sleep. You only get five Rule threads. That means only five Rules can run at the same time. With that set of log statements you would have the following take place:

  • Rule triggers 1253.76, sleeps for five seconds
  • Rule triggers 3399.6800000000003 sleeps for five seconds
  • Rule triggers 5591.04 sleeps for five seconds
  • Rule triggers 4590.08 sleeps for five seconds
  • Rule triggers 2570.2400000000002 sleeps for five seconds
  • Rule can’t trigger for 1475.84 because all five threads are in use, waits to trigger
  • Rule can’t trigger for 558.72 because all five threads are in use, waits to trigger
  • about 4.5 seconds later the first Rule completes, second to last Rule triggers
  • about 4.5 seconds later the second Rule completes, last Rule triggers

I don’t think that is desired behavior.

OH is not a real time system and the order of processing of events and the timeliness of that processing is not guaranteed when events occur this close together. I could definitely see MySQL or the add-on dropping all values until it remains the same for at least half a second. If the value is changing that fast, it is unlikely that you would want to save any but the last value to persistence as that’s the value most likely to have meaning.

So, you will not be able to achieve what you are after using persistence.

Looking at the values it looks like the voltage ramps up and then drops. It also looks like it raises by at least 1000 at each reading when you press the button. So why not just look to see if the current state is greater than 1000 more than the previous state and add a debounce?

var Timer Klingel_timer = null
rule "Klingel_Info"
when
	Item Klingel_Spannung changed
then
    if(Klingel_timer != null) return; // if there is a timer, we've already detected the press so ignore the event

    if(Klingel_Spannung.state as Number >= (previousState as Number) + 1000){
        sendNotification("xxx@msn.com","Ding Dong")
        // Choose an appropriate debounce time (i.e. amount of time to ignore changes)
        Klingel_Spannung = createTimer(now.plusSeconds(5), [ |   Klingel_Spannung = null]) // the Timer doesn't need to do anything
    }
end

The first time the voltage changes by 1000 or more we send the notification and create a Timer for five seconds. For the next five seconds we ignore all the changes to the voltage Item. Then the first time after the Timer expires that the voltage changes by 1000 or more we do it all again.

1 Like

I’d be looking to fix it at source. Are you measuring the voltage on a floating wire? Would a simple pull-down resistor solve noise pick up?

I think you mean Klingel_Tmer instead of Klingel_Spannung in the assignment from createTimer

I now ended with the following Code.
Thanks for your fast help!

//Info Klingel
rule "Klingel_Info"
when
	Item Klingel_Spannung changed
then
	if(Klingel_timer !== null) 
	{
		return
		} // if there is a timer, we've already detected the press so ignore the event

    if(Klingel_Spannung.state as Number >= 1000){
        sendNotification("nanokiller@msn.com","Ding Dong")
        // Choose an appropriate debounce time (i.e. amount of time to ignore changes)
        Klingel_timer = createTimer(now.plusSeconds(30), [ |logInfo("Buttler James", "Ding Dong!")]) // the Timer doesn't need to do anything
    }
end

My log now Throws out the following:

23:55:22.527 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 276.0 to 1324.8
23:55:22.584 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 1324.8 to 3376.64
23:55:22.599 [ERROR] [.model.script.actions.ScriptExecution] - Failed to schedule code for execution.
org.quartz.ObjectAlreadyExistsException: Unable to store Job : ‘DEFAULT.2019-09-04T23:55:52.599+02:00: Proxy for org.eclipse.xtext.xbase.lib.Procedures$Procedure0: [ | {
logInfo(,)
} ]’, because one already exists with this identification.
at org.quartz.simpl.RAMJobStore.storeJob(RAMJobStore.java:279) ~[?:?]
at org.quartz.simpl.RAMJobStore.storeJobAndTrigger(RAMJobStore.java:251) ~[?:?]
at org.quartz.core.QuartzScheduler.scheduleJob(QuartzScheduler.java:886) ~[?:?]
at org.quartz.impl.StdScheduler.scheduleJob(StdScheduler.java:249) ~[?:?]
at org.eclipse.smarthome.model.script.actions.ScriptExecution.makeTimer(ScriptExecution.java:132) ~[?:?]
at org.eclipse.smarthome.model.script.actions.ScriptExecution.createTimer(ScriptExecution.java:92) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) ~[?:?]
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) ~[?:?]
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:902) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter._doEvaluate(XbaseInterpreter.java:865) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:224) ~[?:?]
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:1212) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:216) ~[?:?]
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:460) ~[?:?]
at org.eclipse.xtext.xbase.interpreter.impl.XbaseInterpreter.doEvaluate(XbaseInterpreter.java:244) ~[?:?]
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.smarthome.model.script.runtime.internal.engine.ScriptImpl.execute(ScriptImpl.java:82) ~[?:?]
at org.eclipse.smarthome.model.rule.runtime.internal.engine.RuleEngineImpl.lambda$2(RuleEngineImpl.java:341) ~[?:?]
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511) [?:?]
at java.util.concurrent.FutureTask.run(FutureTask.java:266) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$201(ScheduledThreadPoolExecutor.java:180) [?:?]
at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293) [?:?]
at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149) [?:?]
at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624) [?:?]
at java.lang.Thread.run(Thread.java:748) [?:?]
23:55:22.827 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 3376.64 to 4398.08
23:55:22.883 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4398.08 to 5168.64
23:55:23.097 [INFO ] [smarthome.event.ItemStateChangedEvent] - HS100_Buerolampe_Rssi changed from -84 to -73
23:55:23.129 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5168.64 to 4410.88
23:55:23.251 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4410.88 to 4515.84
23:55:23.352 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4515.84 to 5555.2
23:55:23.576 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5555.2 to 4523.52
23:55:23.728 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4523.52 to 4597.76
23:55:23.801 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4597.76 to 5309.4400000000005
23:55:24.029 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5309.4400000000005 to 4623.36
23:55:24.170 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4623.36 to 4656.64
23:55:24.272 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4656.64 to 5678.08
23:55:24.478 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5678.08 to 4659.2
23:55:24.648 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4659.2 to 4687.36
23:55:24.733 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4687.36 to 5719.04
23:55:24.926 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5719.04 to 4666.88
23:55:25.086 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4666.88 to 4677.12
23:55:25.159 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4677.12 to 5416.96
23:55:25.383 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5416.96 to 4736.0
23:55:25.529 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4736.0 to 4733.4400000000005
23:55:25.633 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4733.4400000000005 to 5734.400000000001
23:55:25.829 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 5734.400000000001 to 4712.96
23:55:26.013 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 4712.96 to 2659.84
23:55:26.085 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 2659.84 to 1550.08
23:55:26.305 [INFO ] [smarthome.event.ItemStateChangedEvent] - Klingel_Spannung changed from 1550.08 to 634.88
23:55:34.271 [INFO ] [smarthome.event.ItemStateChangedEvent] - Network_VPNTunnel_ping changed from 21.0 to 20.0
23:55:46.793 [INFO ] [smarthome.event.ItemStateChangedEvent] - Network_NanoOnePlus_ping changed from 3125.0 to 92.0
23:55:46.797 [INFO ] [smarthome.event.ItemStateChangedEvent] - Network_NanoOnePlus_ping changed from 92.0 to 53.0
23:55:52.602 [INFO ] [.smarthome.model.script.Buttler James] - Ding Dong!
23:55:52.833 [INFO ] [.smarthome.model.script.Buttler James] - Ding Dong!

So far, so good. But somehow the rule gets triggered 3 times before the timer is set. I get 3 Messages on my Phone.

This business is going tokill your system performance with processing overheads, just to find out the doorbell is not being pressed.

I repeat the advice to fix at source - it’s only a bell push.

That’s not right. The spam of values only happens when someone presses the doorbell.
If nobody presses there is a maximum of 4-5 changes of the Voltage per Day.

The last log cut was about 5 seconds of pressing the Doorbell button. If i press it about a second there are only 4 to 8 lines appearing in the log file.

My system is more than powerful enough to handle this. Openhab runs on a virtual Machine with a SSD, 3GB RAM and 2 Cores from an I7 8700K. The load newer goes over 20% CPU.

I would fix it at source but I have no clue how. The Doorbell system is an AC 8V one. I can’t change this to DC because I don’t own the full house but only a flat.
Is this a Job for a Relay?

That would be one way, but it is probably over the top. A resistor, diode and a capacitor would probably do it for pennies.
I’m thinking like

---------------- diode + ----------------------------- GPIO
                             |               |
AC doorbel                 resistor     capacitor
                             |               |
-------------------------------------------------------

How are you sensing this now? I assume an ADC GPIO pin or something. Can you describe or draw your wiring?

This suggests your un-pushed condition has the line just floating, which is bad. You might find it improves just by putting a resistor across your input.

----------------------------------------------- ---------------------------- IO1
                                                           |
8V AC Transformer                                     MP3 Doorbell
                                                           |
---------------------------------------------------------------------------- IO GND

The problem is the AC. The MDT AIO-0410V.01 only measures DC right.

I’ve no idea what one of those is. Some GPIO type input thing perhaps?

Not sure I’m interpreting your picture correctly. You already have a diode, but it is between your switched AC and whatever an MP3 doorbell is? I’m guessing that plays MP3 “ding-dongs”, so it must be DC too. Remarkable that works, but it is obviously happy with a rough supply.

I’d be looking to find a clean DC signal from the MP3 thingy, but maybe you don’t want to mess with that.

So,

 --------------------diode + -------------diode +--------------- IO1
                                |                 |         |
8V AC                      MP3 Doorbell       resistor    capacitor
                                |                 |         |
---------------------------------------------------------------- IO GND

The capacitor cleans up your signal. 0.1 uF is fine.
The resistor discharges the cap between pushes. Big value, 100K
The extra diode stops the MP3 stealing the capacitor charge.

Sorry. My Diagram was wrong. I have no diode yet.
So I only need one diode and a resistor + capacitor, right?

Okay, the missing diode to the left makes no difference to the new parts to right of MP3 in the diagram.
You can go bigger with the capacitor if you like, for a better effect - 1uF, 10uF - 0.1uF is just a common size to find in people’s rummage boxes.

I will try that and report after!

I ordert all the parts and build it in.
After that i now only have the Currency gets up and then down again and not hopping up and down due pressing the button.

But it wasn’t handling the spam of the values.
I found out that the IO has the ability to detect an average value in a configurable time (direct, short, mid-short, long). The mid-short preference did the trick. I now only get 1 value about every second while pushing the button.

OpenHAB now can handle to finish the first rule execution before firing another rule start.

Thank you all for your help!

1 Like