Folks,
I’m hoping someone can point out where by hole is in the code below -
Rule:
val Functions$Function3<GenericItem, String, ReentrantLock, Boolean> getPosition = [
GenericItem itemBlind,
String mac,
ReentrantLock fronRoomBlindLock
|
try{
if (fronRoomBlindLock.getHoldCount() > 0){logWarn("Blinds - Front room", "getPosition - Waiting on other locks. Count:" + fronRoomBlindLock.getHoldCount().toString)}
if (!fronRoomBlindLock.tryLock(5, TimeUnit.SECONDS)){
logInfo("Blinds - Front room - getPosition", "Could not lock!")
return false;
}
// logInfo("Blinds - Front room - getPosition", "Locked")
val value = sendHttpGetRequest("http://rpiblinds01:8080/getposition/" + mac, 1000)
val int pos = Integer.parseInt(transform("JS", "blindsExtractValue.js", value))
if (pos < 0){
logWarn("Blinds - Check Position", "Position for blind " + itemBlind.name + " reports less than zero")
return false;
}
itemBlind.postUpdate(pos)
}
catch(Throwable t) {
logError("Blinds - getPosition", t.getMessage())
}
finally {
fronRoomBlindLock.unlock()
//logInfo("Blinds - Front room - getPosition", "Unlocked")
}
return true;
]
rule "Check Blind Position"
when
Time cron "0 0/5 * 1/1 * ? *"
then
getPosition.apply(FrontRoomBlindsLeft_PC, "F3:95:30:3E:DD:4A", fronRoomBlindLock)
Thread::sleep(500)
getPosition.apply(FrontRoomBlindsRight_PC, "C1:03:74:91:05:6C", fronRoomBlindLock)
end
logs:
2018-09-03 03:30:02.459 [WARN ] [model.script.Blinds - Check Position] - Position for blind FrontRoomBlindsLeft_PC reports less than zero
2018-09-03 03:30:03.023 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
2018-09-03 03:30:04.083 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-03 03:30:04.137 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-03 03:30:06.685 [INFO ] [ipt.Blinds - Front room - getBattery] - Could not lock!
2018-09-03 03:35:00.044 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
2018-09-03 03:35:01.166 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-03 03:35:01.280 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-03 03:35:01.839 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
2018-09-03 03:40:05.043 [INFO ] [pt.Blinds - Front room - getPosition] - Could not lock!
2018-09-03 03:40:10.597 [INFO ] [pt.Blinds - Front room - getPosition] - Could not lock!
2018-09-03 03:45:00.059 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
2018-09-03 03:45:01.143 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-03 03:45:01.196 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-03 03:45:01.736 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
2018-09-03 03:45:05.056 [INFO ] [ipt.Blinds - Front room - getBattery] - Could not lock!
2018-09-03 03:45:10.636 [INFO ] [ipt.Blinds - Front room - getBattery] - Could not lock!
2018-09-03 03:50:00.028 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
2018-09-03 03:50:01.087 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-03 03:50:01.149 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-03 03:50:01.702 [WARN ] [ome.model.script.Blinds - Front room] - getPosition - Waiting on other locks. Count:1
So, what’s happening?
I have the rule which fires on cron. This calls the lambda and gets the position.
The endpoint it’s hitting is a python web server running on an rpi. Said service connects to blind controller via BT, gets the details and then returns. Sometimes, it does not connect or return. When this happens, for the getPosition, I don’t really care.
What I am seeing is that it works fine for a while then at some point it goes wonky and stops. it has a http timeout (I care not) but then the lock seems to be left locked. Subsequent calls are not made because they timeout waiting on the locks.
What I do see a lot of is the timeout exception but it handles normally -
2018-09-02 23:15:01.046 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:15:01.119 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-02 23:15:02.926 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:15:02.980 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-02 23:17:47.106 [ERROR] [twaverf.internal.LightwaveRfWifiLink] - Error converting message: *?{"trans":257440,"mac":"20:20:0C","cmd":"get_duskdawn","lat":51.73,"long":-0.21,"offset":0}
2018-09-02 23:20:01.042 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:20:01.131 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-02 23:25:01.046 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:25:01.106 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-02 23:25:02.677 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:25:02.778 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-02 23:30:01.068 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:30:01.121 [ERROR] [me.model.script.Blinds - getPosition] - null
2018-09-02 23:30:02.164 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:30:02.316 [ERROR] [ome.model.script.Blinds - getBattery] - null
2018-09-02 23:30:03.377 [ERROR] [.smarthome.model.script.actions.HTTP] - Fatal transport error: java.util.concurrent.TimeoutException
2018-09-02 23:30:03.431 [ERROR] [me.model.script.Blinds - getPosition] - null
Ok, the fact that it’s failing so much is interesting but not important to this problem.
When this happens (the timeouts) I can still access it from a browser on my laptop so it’s not python which is sick.
For some reason, the call from the OH RPi times out when talking to the blinds one.
Again, interesting but the code should handle it.
Why is lock not unlocking?
Edit: Is the catch type wrong?
Thanks.
C