I have a question about this:
I have a series of rules, one of which runs on a group trigger. Sometimes it does seem slow to respond (others it is instantaneous), so I have been taking a closer look at it. it does not seem to trigger multiple times though.
here is the item definition
Group:Switch homekit "Homekit Items [%s]" <house> (All)
Group Nest_Thermostat "Downstairs" <climate> (All) ["Thermostat"]
/* Insteon items */
/* oddities */
Dimmer christmasTree_HK "Christmas Tree [%d%%]" <christmas_tree> (homekit) ["Lighting"]
/* Porch */
Switch frontgardenPower_HK "Front Power [%s]" <poweroutlet> (homekit) ["Switchable"]
Dimmer porchLightKuna_HK "Porch Light[%d%%]" (homekit) ["Lighting"]
Dimmer drivewayLightKuna_HK "Driveway Light[%d%%]" (homekit) ["Lighting"]
/* Basement */
Switch basementFluorescents_HK "Basement Main Light[%s]" (homekit) ["Lighting"]
Dimmer workshopBulb_HK "Workshop Light[%d%%]" (homekit) ["Lighting"]
Switch workbenchLight_HK "Workbench Light[%s]" (homekit) ["Lighting"]
...
Dimmer landingMain_HK "Landing Light[%d%%]" (homekit) ["Lighting"]
and so on, there are 51 items in total.
here is the rule:
import java.util.HashMap
import java.util.Map
import java.util.concurrent.locks.Lock
import java.util.concurrent.locks.ReentrantLock
var ReentrantLock HomekitLock = new ReentrantLock(false)
var Map <String, GenericItem> ItemObjects = newHashMap
var Boolean homekit_init = false
rule "Homekit Item Changed"
when
Item homekit received update
then
try {
//HomekitLock.lock
if(!homekit_init) return;
logDebug("HomeKit","Homekit Item received update")
homekit.members.forEach[ i |
//trap special functions (triggers) here - these are usually one shot events, that don't have a "state" as such
//ie trigger them with "ON" (unless you write the rule such that they set themselves OFF after Triggering)
switch(i.name) {
default : { //put something here if needed
}
}
var realitem_name = i.name.split("_HK").get(0) //get realitem name
var realitem = ItemObjects.get(realitem_name) //get realitem object
var realitem_state = realitem.state
//logInfo("HomeKit", "processing: " + realitem.name + " state: " + realitem_state)
switch(realitem.name) {
case "DIRECTsequence" : if(realitem_state == NULL)
realitem_state = OFF
else if(Integer::parseInt(realitem.state.toString) > 2)
realitem_state = ON
else
realitem_state = OFF
}
if(realitem_state != i.state && i.state != NULL) { //if HK state != current state (and not NULL)
//logDebug("HomeKit", "FOUND!!!! Item: " + i.name + " state: " + i.state + " is not the same as " + realitem.name + " state " + realitem.state)
logDebug("HomeKit", "FOUND!!!! Item: " + realitem.name + " updating to: " + i.state)
//handle special case triggers
//logDebug("HomeKit", "Processing " + i.state + " trigger for: " + i.name)
var command = i.state.toString //command to send
var commanditem = realitem.name //item to send it to
switch(realitem.name) {
case "DIRECTsequence" : if(i.state == ON)
command = "8"
else
command = "2"
case "Skype_Answer" : if(i.state == ON)
command = "KEY_ENTER" //send enter to answer SKYPE
else
command = "KEY_EXIT" //send exit to hang up
case "RGBWControllerW" : if(i.state == 100)
command = "10" //set to 10% with ON command
case "TV_Volume" : {if(i.state == 0) {
commanditem = "TV_Mute"
command = "ON"
}
else if (i.state == 100) {
commanditem = "TV_Mute"
command = "OFF"
}}
}
sendCommand(commanditem, command)
logDebug("HomeKit", "Sent Command to realitem: " + commanditem + " to " + command)
}
]
logDebug("HomeKit","End of Homekit Item Received Update rule")
}
catch(Throwable t) {
logError("HomeKit", "Error in Homekit Item Changed: " + t.toString)
}
finally {
// always runs even if there was an error, good place for cleanup
//HomekitLock.unlock
}
end
As you can see I tried messing with locks to see if it was triggering multiple times, but it doesn’t seem to be. This works just fine, just sometimes there is a weird delay.
Here is some output from my log:
20-Apr-2018 18:15:03.975 [DEBUG] [ulation.internal.HueEmulationServlet] - sending 0 to landingMain_HK
20-Apr-2018 18:15:04.044 [DEBUG] [ulation.internal.HueEmulationServlet] - 192.168.100.28: GET /api/YYIxsz94Jbsz8FaviC27PZyhi7jf4uZ5Ynf72iKU/lights/25
20-Apr-2018 18:15:05.976 [DEBUG] [ulation.internal.HueEmulationServlet] - 192.168.100.187: GET /api/7b456dd4-1424-4347-9a2b-d3d8f8b3312d/lights
20-Apr-2018 18:15:16.136 [DEBUG] [ulation.internal.HueEmulationServlet] - 192.168.100.187: GET /api/7b456dd4-1424-4347-9a2b-d3d8f8b3312d/lights
20-Apr-2018 18:15:20.968 [DEBUG] [lipse.smarthome.model.script.HomeKit] - Homekit Item received update
20-Apr-2018 18:15:20.972 [DEBUG] [lipse.smarthome.model.script.HomeKit] - FOUND!!!! Item: landingMain updating to: 0
20-Apr-2018 18:15:20.972 [DEBUG] [lipse.smarthome.model.script.HomeKit] - Sent Command to realitem: landingMain to 0
20-Apr-2018 18:15:20.978 [DEBUG] [lipse.smarthome.model.script.HomeKit] - End of Homekit Item Received Update rule
20-Apr-2018 18:15:21.282 [DEBUG] [lipse.smarthome.model.script.HomeKit] - Real Item changed Rule
20-Apr-2018 18:15:21.291 [DEBUG] [lipse.smarthome.model.script.HomeKit] - End of Real Item Changed rule
homekit_init is set to true during system startup.
Notice “sending 0” is at 18:15:03.975, and the rule is triggered (“Homekit Item received update”) at 18:15:20.968 - ie 17 seconds later. I can see the event in the events log at 18:15:03:
2018-04-20 18:15:03.976 [ome.event.ItemCommandEvent] - Item 'landingMain_HK' received command 0
2018-04-20 18:15:03.976 [vent.ItemStateChangedEvent] - landingMain_HK changed from 100 to 0
There are no ‘homekit’ group events in the events log though.
However, just a bit later:
20-Apr-2018 18:28:56.526 [DEBUG] [ulation.internal.HueEmulationServlet] - sending 0 to landingMain_HK
20-Apr-2018 18:28:56.526 [DEBUG] [lipse.smarthome.model.script.HomeKit] - Homekit Item received update
20-Apr-2018 18:28:56.530 [DEBUG] [lipse.smarthome.model.script.HomeKit] - FOUND!!!! Item: landingMain updating to: 0
20-Apr-2018 18:28:56.530 [DEBUG] [lipse.smarthome.model.script.HomeKit] - Sent Command to realitem: landingMain to 0
20-Apr-2018 18:28:56.532 [DEBUG] [lipse.smarthome.model.script.HomeKit] - Real Item changed Rule
20-Apr-2018 18:28:56.537 [DEBUG] [lipse.smarthome.model.script.HomeKit] - End of Homekit Item Received Update rule
20-Apr-2018 18:28:56.544 [DEBUG] [lipse.smarthome.model.script.HomeKit] - End of Real Item Changed rule
I don’t know what may be causing the variability (unless the rule is running 50 times and I just can’t see it for some reason). I’m running OH2.2 snapshot from a few weeks ago, on an HP Proliant gen8 4GHz 4 core server, so plenty of horsepower.
Any ideas as to what is the problem? if the rule really does run 50 times, how would I see that in the logs? I can use locks to prevent it running twice, but then I might miss a real event, so I’m trying to avoid that.
Any suggestions are appreciated.