[rPi3B, Stretch Lite, Zulu Java (zulu8.31.1.122-jdk1.8.0_181-linux_aarch32hf)
OH2.4.0-1 (apt-get), mosquitto, samba]
My irrigation rules are built on Rich’s pattern of cascading timers, which I installed on a OHv1 system in March 2018. It worked ever since (however, I cannot say, whether the problem I found three days ago existed back then). I migrated from OH1 to OH2 on Jan 1st, 2019.
Three days ago, my wife noticed that valve 3 of one of the irrigation systems ran twice in a row.
I checked over the weekend; it ran fine on Saturday; today it ran valve 2 twice. Hover, tracking MQTT messages sent by the OH rules say that valve 1 was sent an ON command twice.
The valve commands are strings with 4 characters (built by rules and published via MQTT), the first two for the valve 00-99, the second pair for the time in minutes or 00 = OFF; e.g. 0320 = valve 3 for 20 minutes; 0300 valve 3 off.
My suspicion is an item update timing issue; why there is the odd Threat::sleep in the rules (aiming to prevent that).
Only investigating OH2.4.0 running since Jan 1:
Irrigation days .....: 120
Faulty days..........: 7
Max. valve triggers..: 17
7 days showed more than the 8 valve triggers; 4 valves with two commands (ON|OFF) = 8 commands (triggers).
1 day had 17 triggers.
No changes were made to the irrigation rules post migration from OH1 to OH2 in on Jan 1st.
What comes next are:
- the MQTT tracking for today
- the OH log file for today (Please note: “turning OFF all valves regardless of state” was added yesterday to make sure valves are OFF before another one comes on)
- the rules (Please note: Irrigation valve 2…4 OFF is the same as for valve 1, except for the identifier)
mosquitto_sub -v -t ArgyleCourt/Property/PumpStation1/Valve | xargs -d$'\n' -L1 sh -c 'date "+%D %T.%3N $0"'
05/04/19 20:53:36.387 ArgyleCourt/Property/PumpStation1/Valve 0000
05/05/19 10:00:15.209 ArgyleCourt/Property/PumpStation1/Valve 0115
05/05/19 10:15:15.251 ArgyleCourt/Property/PumpStation1/Valve 0100
05/05/19 10:15:16.265 ArgyleCourt/Property/PumpStation1/Valve 0000
05/05/19 10:15:30.421 ArgyleCourt/Property/PumpStation1/Valve 0115
05/05/19 10:30:30.439 ArgyleCourt/Property/PumpStation1/Valve 0100
05/05/19 10:30:31.456 ArgyleCourt/Property/PumpStation1/Valve 0000
05/05/19 10:30:45.565 ArgyleCourt/Property/PumpStation1/Valve 0215
05/05/19 10:45:45.576 ArgyleCourt/Property/PumpStation1/Valve 0200
05/05/19 10:45:46.591 ArgyleCourt/Property/PumpStation1/Valve 0000
05/05/19 10:46:00.721 ArgyleCourt/Property/PumpStation1/Valve 0325
05/05/19 11:11:00.737 ArgyleCourt/Property/PumpStation1/Valve 0300
05/05/19 11:11:01.752 ArgyleCourt/Property/PumpStation1/Valve 0000
05/05/19 11:11:15.886 ArgyleCourt/Property/PumpStation1/Valve 0420
05/05/19 11:31:15.913 ArgyleCourt/Property/PumpStation1/Valve 0400
05/05/19 11:31:16.933 ArgyleCourt/Property/PumpStation1/Valve 0000
2019-05-05 10:00:00.043 [INFO ] [arthome.model.script.Irrigation1.11a] - ... PumpStation1_LastSessionTotal set to 919
2019-05-05 10:00:05.059 [INFO ] [arthome.model.script.Irrigation1.11b] - ... PumpStation1_LastSessionTotal set to 841
2019-05-05 10:00:10.070 [INFO ] [arthome.model.script.Irrigation1.11e] - ... PumpStation1_LastSessionMemory -> to 0
2019-05-05 10:00:15.092 [INFO ] [marthome.model.script.Irrigation1.14] - ... station1 VolumeSession ... -> set to 0; is it? -> 0
2019-05-05 10:00:15.101 [INFO ] [marthome.model.script.Irrigation1.15] - ..> turning Irrigation1_1 ON
2019-05-05 10:00:15.132 [INFO ] [marthome.model.script.Irrigation1.21] - ... currValveSwitch...: ON
2019-05-05 10:00:15.152 [INFO ] [rthome.model.script.Irrigation1.23.1] - ... currValveMins.dec.: 15.0
2019-05-05 10:00:15.158 [INFO ] [rthome.model.script.Irrigation1.23.2] - ... currValveMinsInt..: 15
2019-05-05 10:00:15.178 [INFO ] [marthome.model.script.Irrigation1.24] - ... VolumePrevious (meter 1) . -> 0
2019-05-05 10:15:15.210 [INFO ] [ome.model.script.Irrigation1.timer.1] - ..< turning Irrigation1_1 OFF
2019-05-05 10:15:15.250 [INFO ] [home.model.script.Irrigation1_1.off1] - ... valve flow rate .......... -> 9
2019-05-05 10:15:15.272 [INFO ] [home.model.script.Irrigation1_1.off2] - ... current meter reading .... -> 193
2019-05-05 10:15:15.282 [INFO ] [home.model.script.Irrigation1_1.off3] - ... valveVolume (calculated) . -> 193
2019-05-05 10:15:16.255 [INFO ] [marthome.model.script.Irrigation1.1b] - ..! turning OFF all valves regardless of state
2019-05-05 10:15:30.269 [INFO ] [ome.model.script.Irrigation1.timer.2] - ..> turning Irrigation1_2 ON
2019-05-05 10:15:30.333 [INFO ] [marthome.model.script.Irrigation1.21] - ... currValveSwitch...: OFF
2019-05-05 10:15:30.363 [INFO ] [rthome.model.script.Irrigation1.23.1] - ... currValveMins.dec.: 15.0
2019-05-05 10:15:30.377 [INFO ] [rthome.model.script.Irrigation1.23.2] - ... currValveMinsInt..: 15
2019-05-05 10:15:30.397 [INFO ] [marthome.model.script.Irrigation1.24] - ... VolumePrevious (meter 1) . -> 194
2019-05-05 10:30:30.421 [INFO ] [ome.model.script.Irrigation1.timer.1] - ..< turning Irrigation1_1 OFF
2019-05-05 10:30:30.444 [INFO ] [home.model.script.Irrigation1_1.off1] - ... valve flow rate .......... -> 9
2019-05-05 10:30:30.453 [INFO ] [home.model.script.Irrigation1_1.off2] - ... current meter reading .... -> 331
2019-05-05 10:30:30.458 [INFO ] [home.model.script.Irrigation1_1.off3] - ... valveVolume (calculated) . -> 137
2019-05-05 10:30:31.441 [INFO ] [marthome.model.script.Irrigation1.1b] - ..! turning OFF all valves regardless of state
2019-05-05 10:30:45.462 [INFO ] [ome.model.script.Irrigation1.timer.2] - ..> turning Irrigation1_2 ON
2019-05-05 10:30:45.493 [INFO ] [marthome.model.script.Irrigation1.21] - ... currValveSwitch...: ON
2019-05-05 10:30:45.512 [INFO ] [rthome.model.script.Irrigation1.23.1] - ... currValveMins.dec.: 15.0
2019-05-05 10:30:45.518 [INFO ] [rthome.model.script.Irrigation1.23.2] - ... currValveMinsInt..: 15
2019-05-05 10:30:45.537 [INFO ] [marthome.model.script.Irrigation1.24] - ... VolumePrevious (meter 1) . -> 333
2019-05-05 10:45:45.564 [INFO ] [ome.model.script.Irrigation1.timer.1] - ..< turning Irrigation1_2 OFF
2019-05-05 10:45:45.592 [INFO ] [home.model.script.Irrigation1_2.off1] - ... valve flow rate .......... -> 5
2019-05-05 10:45:45.604 [INFO ] [home.model.script.Irrigation1_2.off2] - ... current meter reading .... -> 441
2019-05-05 10:45:45.611 [INFO ] [home.model.script.Irrigation1_2.off3] - ... valveVolume (calculated) . -> 108
2019-05-05 10:45:46.577 [INFO ] [marthome.model.script.Irrigation1.1b] - ..! turning OFF all valves regardless of state
2019-05-05 10:46:00.590 [INFO ] [ome.model.script.Irrigation1.timer.2] - ..> turning Irrigation1_3 ON
2019-05-05 10:46:00.631 [INFO ] [marthome.model.script.Irrigation1.21] - ... currValveSwitch...: ON
2019-05-05 10:46:00.654 [INFO ] [rthome.model.script.Irrigation1.23.1] - ... currValveMins.dec.: 25.0
2019-05-05 10:46:00.660 [INFO ] [rthome.model.script.Irrigation1.23.2] - ... currValveMinsInt..: 25
2019-05-05 10:46:00.684 [INFO ] [marthome.model.script.Irrigation1.24] - ... VolumePrevious (meter 1) . -> 442
2019-05-05 11:11:00.720 [INFO ] [ome.model.script.Irrigation1.timer.1] - ..< turning Irrigation1_3 OFF
2019-05-05 11:11:00.749 [INFO ] [home.model.script.Irrigation1_3.off1] - ... valve flow rate .......... -> 11
2019-05-05 11:11:00.758 [INFO ] [home.model.script.Irrigation1_3.off2] - ... current meter reading .... -> 754
2019-05-05 11:11:00.764 [INFO ] [home.model.script.Irrigation1_3.off3] - ... valveVolume (calculated) . -> 312
2019-05-05 11:11:01.738 [INFO ] [marthome.model.script.Irrigation1.1b] - ..! turning OFF all valves regardless of state
2019-05-05 11:11:15.751 [INFO ] [ome.model.script.Irrigation1.timer.2] - ..> turning Irrigation1_4 ON
2019-05-05 11:11:15.799 [INFO ] [marthome.model.script.Irrigation1.21] - ... currValveSwitch...: ON
2019-05-05 11:11:15.826 [INFO ] [rthome.model.script.Irrigation1.23.1] - ... currValveMins.dec.: 20.0
2019-05-05 11:11:15.832 [INFO ] [rthome.model.script.Irrigation1.23.2] - ... currValveMinsInt..: 20
2019-05-05 11:11:15.856 [INFO ] [marthome.model.script.Irrigation1.24] - ... VolumePrevious (meter 1) . -> 757
2019-05-05 11:31:15.886 [INFO ] [ome.model.script.Irrigation1.timer.1] - ..< turning Irrigation1_4 OFF
2019-05-05 11:31:15.944 [INFO ] [home.model.script.Irrigation1_4.off1] - ... valve flow rate .......... -> 10
2019-05-05 11:31:15.954 [INFO ] [home.model.script.Irrigation1_4.off2] - ... current meter reading .... -> 981
2019-05-05 11:31:15.964 [INFO ] [home.model.script.Irrigation1_4.off3] - ... valveVolume (calculated) . -> 224
2019-05-05 11:31:16.918 [INFO ] [marthome.model.script.Irrigation1.1b] - ..! turning OFF all valves regardless of state
2019-05-05 11:31:30.931 [INFO ] [e.smarthome.model.script.Irrigation1] - Irrigation group 1 finished.
2019-05-05 11:31:30.964 [INFO ] [marthome.model.script.Irrigation1.41] - Irrigation1 -> reset Auto Switch
// When either auto or manual switch is flicked ON, the whole sequence kicks off
// one valve after the other, as per set durations
rule "Start Irrigation1"
when
// triggers to start this group; either auto (by cron) or manual
Item Irrigation1_Auto changed to ON or
Item Irrigation1_Now changed to ON
then
// only irrigate if allowed is ON
if (Irrigation1_Allowed.state == ON) {
// start up valve 1 of 4
logInfo("Irrigation1.10", "Irrigation1 started...")
// capture current meter (from last session) and store it in last session total
logInfo("Irrigation1.11a", "... PumpStation1_LastSessionTotal set to {}", PumpStation1_LastSessionTotal.state)
PumpStation1_LastSessionTotal.postUpdate(PumpStation1_LastSessionMemory.state)
Thread::sleep(5000)
logInfo("Irrigation1.11b", "... PumpStation1_LastSessionTotal set to {}", PumpStation1_LastSessionTotal.state)
// zero the last session memory and start at zero for this session
//logInfo("Irrigation1.11c", "... PumpStation1_LastSessionMemory -> to {}", PumpStation1_LastSessionMemory.state)
PumpStation1_LastSessionMemory.postUpdate(0)
//logInfo("Irrigation1.11d", "... PumpStation1_LastSessionMemory -> to {}", PumpStation1_LastSessionMemory.state)
Thread::sleep(5000)
logInfo("Irrigation1.11e", "... PumpStation1_LastSessionMemory -> to {}", PumpStation1_LastSessionMemory.state)
// ----- reset meter to 0 for good...
// reset the controller's meter to 0
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Command", "resetMeter")
//logInfo("Irrigation1.11f", "... MQTT: pump station 1 meter -> set to 0")
// also publish the reset to 0 to the item 'PumpStation1_Meter' item, because
// the controller does not publish (force) this value
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Meter", "0")
//logInfo("Irrigation1.12", "... MQTT: PumpStation1_Meter .. -> set to 0")
// we now have to update this value as well, because the controller does
// not publish back the forced change to 0
PumpStation1_Meter.postUpdate(0)
//logInfo("Irrigation1.13a", "... PumpStation1_Meter ....... -> set to 0 -> {}", PumpStation1_Meter.state)
// reset the session volume counter to zero
// sleep for 5 seconds to let the meter settle
Thread::sleep(5000)
//logInfo("Irrigation1.13b", "... PumpStation1_Meter ....... -> set to 0 -> {}", PumpStation1_Meter.state)
//logInfo("Irrigation1.14a", "... station1 VolumeSession ... -> set to {}", PumpStation1_MemoriseMeterRead)
PumpStation1_MemoriseMeterRead = (PumpStation1_Meter.state as Number).intValue
//logInfo("Irrigation1.14b", "... station1 VolumeSession ... -> set to {}", PumpStation1_MemoriseMeterRead)
// was
//PumpStation1_MemoriseMeterRead = 0
//logInfo("Irrigation1.14", "... station1 VolumeSession ... -> set to 0")
logInfo("Irrigation1.14", "... PumpStation1 VolumeSession ... -> set to 0; is it? -> {}", PumpStation1_MemoriseMeterRead)
// update 'curr'ent valve name; which is #1
Irrigation1_Curr.sendCommand(Irrigation1_1.name)
// now switch valve 1 ON
Irrigation1_1.sendCommand(ON)
logInfo("Irrigation1.15", "..> turning {} ON ", Irrigation1_Curr.state)
} else {
logInfo("Irrigation1.16", "Irrigation1 not started -> not allowed!")
Irrigation1_Reset.postUpdate(ON)
}
end
// This is the domino rule, to trigger the next valve ON
// 1. It starts with 1 from the previous rule
// 2...4 one after the other
rule "Irrigation1 valve cascade ON"
when
Item Irrigation1_1 received command ON or
Item Irrigation1_2 received command ON or
Item Irrigation1_3 received command ON or
Item Irrigation1_4 received command ON
then
// Get the currently running valve's name: e.g. Irrigation1_1
val currValveName = Irrigation1_Curr.state.toString
//logInfo("Irrigation1.20", "... currValveName.....: {}", currValveName)
// get the part 'Irrigation1'
val currValveSwitch = gIrrigation1.members.filter[i | i.name == currValveName].head
logInfo("Irrigation1.21", "... currValveSwitch...: {}", currValveSwitch.state)
// e.g. Irrigation1_1 -> split at _ and get array item 0 and 1,
// with array item 0 being the irrigation1 part, and
// with array item 1 being the number of the valve having been triggered
val currValveNum = Integer::parseInt(currValveName.split("_").get(1))
//logInfo("Irrigation1.22", "... currValveNum......: {}", currValveNum)
// the valve time comes from an item named e.g. Irrigation1_1_Time
val currValveMins = gIrrigation1Time.members.filter[t | t.name == currValveName + "_Time"].head.state as DecimalType
// current duration for display on sitemap; decimal value
logInfo("Irrigation1.23.1", "... currValveMins.dec.: {}", currValveMins)
// 181231 MaxG: make it integer permanently
val currValveMinsInt = currValveMins.intValue
// current duration for display on sitemap; cast to integer
Irrigation1_CurrTimer.postUpdate(currValveMinsInt)
logInfo("Irrigation1.23.2", "... currValveMinsInt..: {}", currValveMinsInt)
// Get the next running valve in the sequence
val nextValveName = "Irrigation1_" + (currValveNum + 1)
// will be null if not found
val nextValveSwitch = gIrrigation1.members.filter[i|i.name == nextValveName].head
// global: memorise current total volume
PumpStation1_MemoriseMeterRead = (PumpStation1_Meter.state as Number).intValue
logInfo("Irrigation1.24", "... VolumePrevious (meter 1) . -> {}", PumpStation1_MemoriseMeterRead)
// ----- build MQTT message for valve OFF
var String valveMessageOff = ""
// add leading zero to send 2-digit number as string
if (currValveNum < 10) {
valveMessageOff = "0" + currValveNum.toString
} else {
valveMessageOff = currValveNum.toString
}
// prefix with double zero for OFF (Arduino OFF = 00)
valveMessageOff = valveMessageOff + "00"
// assign var to val; has to be due to use in lambda, which requires a constant (val)
val finalValveMessageOff = valveMessageOff
// ----- build MQTT message for valve ON
var String valveMessageOn = ""
// add leading zero to send 2-digit number as string
if (currValveNum < 10) {
valveMessageOn = "0" + currValveNum.toString
} else {
valveMessageOn = currValveNum.toString
}
// ----- add minutes to MQTT message
// add leading zero to send 2-digit number as string
if (currValveMinsInt < 10) {
valveMessageOn = valveMessageOn + "0" + currValveMinsInt.toString
} else {
valveMessageOn = valveMessageOn + currValveMinsInt.toString
}
// send MQTT command to switch valve xx ON for yy minutes, received by controller
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Valve", valveMessageOn)
// ----- timer: runs when its time has expired
// Create a timer to turn off curr and change state to on for next next valve
// while this timer is created here, it only executes its contents on expire
irrigation1Timer = createTimer(now.plusMinutes(currValveMinsInt), [|
// turn OFF current valve
logInfo("Irrigation1.timer.1", "..< turning {} OFF ", currValveName)
currValveSwitch.sendCommand(OFF)
// send valve OFF via MQTT to pump station controller
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Valve", finalValveMessageOff)
// 190503 added; fail safe; had OH sent switch valve 2 OFF twice, instead of OFF 2 then OFF 3
Thread::sleep(1000)
logInfo("Irrigation1.1b", "..! turning OFF all valves regardless of state")
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Valve", "0000")
// without the sleep commands OFF and ON the next may follow too quickly
// here: sleep 14 seconds
Thread::sleep(14000)
if (nextValveSwitch !== null) {
logInfo("Irrigation1.timer.2", "..> turning {} ON ", nextValveName)
Irrigation1_Curr.sendCommand(nextValveName)
nextValveSwitch.sendCommand(ON)
} else {
logInfo("Irrigation1", "Irrigation group 1 finished.")
Irrigation1_Curr.sendCommand("None")
// switch OFF Now and Auto
Irrigation1_Reset.postUpdate(ON)
// update last run time
Irrigation1_LastOn.postUpdate(new DateTimeType())
}
irrigation1Timer = null
])
end
rule "Irrigation1 valve 1 OFF"
when
Item Irrigation1_1 received command OFF
then
// ----- water volume calculations
// ----- flow calculations
// get current flow rate from controller update via MQTT;
// should be reflective of mean at end of valve duration
var int valveFlow = (PumpStation1_Flow.state as Number).intValue
logInfo("Irrigation1_1.off1", "... valve flow rate .......... -> {}", valveFlow)
// send flow rate to site map item for this session
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Flow1", valveFlow.toString)
// ----- calculate valve volume
// get current meter reading
var int valveVolume = (PumpStation1_Meter.state as Number).intValue
logInfo("Irrigation1_1.off2", "... current meter reading .... -> {}", valveVolume)
// subtract the memorised meter (valve start value) for this valve from the current valve meter reading
valveVolume = valveVolume - PumpStation1_MemoriseMeterRead
logInfo("Irrigation1_1.off3", "... valveVolume (calculated) . -> {}", valveVolume)
// send valve volume to valve volume item for site map display
publish("mymosquitto", "ArgyleCourt/Property/PumpStation1/Volume1", valveVolume.toString)
// add volume to build SessionMemory
val int tmpVolume = (PumpStation1_LastSessionMemory.state as Number).intValue
PumpStation1_LastSessionMemory.postUpdate(tmpVolume + valveVolume)
// alternative:
//PumpStation1_LastSessionMemory.postUpdate((PumpStation1_LastSessionMemory.state as Number).intValue + valveVolume)
end
