I entered that RANDOMNUMBER myself. Not sure if it was wise to put the real number so I just masked it. I did the same here but made it look similar to what is really there. again one can never be too safe …
2018-04-20 23:07:00.761 [DEBUG] [ing.rachio.handler.RachioZoneHandler] - RachioZone.handleCommand ON for rachio:zone:1:0C3B70193560-1:run
2018-04-20 23:07:00.762 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone: Starting zone 'Pool Zone [1]' for 0 secs
2018-04-20 23:07:00.763 [DEBUG] [ing.rachio.handler.RachioZoneHandler] - RachioZone: No specific runtime selected, using default (120 secs);
==> events.log <==
2018-04-20 23:07:00.763 [ome.event.ItemCommandEvent] - Item 'IRO1PoolZone_RunZone' received command ON
==> openhab.log <==
2018-04-20 23:07:00.763 [DEBUG] [inding.rachio.internal.api.RachioApi] - RachioApi: Start zone '7d2dcc70-f11c-42bc-92b2-6df87684a971' for 120 sec.
==> events.log <==
2018-04-20 23:07:00.765 [vent.ItemStateChangedEvent] - IRO1PoolZone_RunZone changed from OFF to ON
==> openhab.log <==
2018-04-20 23:07:01.287 [ERROR] [inding.rachio.internal.api.RachioApi] - RachioApi: Running zone '7d2dcc70-f11c-42bc-92b2-6df87684a971' for 120sec failed: can't parse argument number:
I used that last binding and this is the outcome. Still no update to the switch when finished but it does look like all the errors are gone.
Also Markus for the rachio debug, I am assuming I should use this below correct?
openhab> log:set debug org.openhab.binding.rachio
Here are my logs…
==> events.log <==
2018-04-21 07:12:49.702 [ome.event.ItemCommandEvent] - Item 'IRO1PoolZone_RunZone' received command ON
==> openhab.log <==
2018-04-21 07:12:49.703 [DEBUG] [ing.rachio.handler.RachioZoneHandler] - RachioZone.handleCommand ON for rachio:zone:1:0C3B70193560-1:run
2018-04-21 07:12:49.704 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone: Starting zone 'Pool Zone [1]' for 60 secs
==> events.log <==
2018-04-21 07:12:49.707 [vent.ItemStateChangedEvent] - IROGongora1PoolZone_RunZone changed from OFF to ON
==> openhab.log <==
2018-04-21 07:12:49.708 [DEBUG] [inding.rachio.internal.api.RachioApi] - RachioApi: Start zone '7d2dcc70-f11c-42bc-92b2-6df87684a971' for 60 sec.
2018-04-21 08:17:27.984 [vent.ItemStateChangedEvent] - RachioTurtlePineHouse1Zone1FrontYard_RunZone changed from OFF to ON
2018-04-21 08:17:27.988 [vent.ItemStateChangedEvent] - RachioTurtlePineHouse1Zone1FrontYard_LastZoneEvent changed from {"timetstamp":"2018-04-21T12:14:04Z","summary":"Zone 1 - Front Yard stopped watering at 08:14 AM (EDT) for 26 seconds.","topic":"","type":"ZONE_STATUS","subType":"ZONE_STOPPED"} to {"timetstamp":"2018-04-21T12:16:05Z","summary":"Zone 1 - Front Yard began watering at 08:16 AM (EDT).","topic":"","type":"ZONE_STATUS","subType":"ZONE_STARTED"}
2018-04-21 08:19:00.776 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone: Event for zone[2] 'Zone 2 - Pool Front': Zone 2 - Pool Front began watering at 08:18 AM (EDT). (status=STARTED, duration = 120sec)
2018-04-21 08:19:00.779 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone[2]: 'Zone 2 - Pool Front' STARTED watering (2018-04-21T12:18:05Z).
2018-04-21 08:19:00.805 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone: Event for zone[1] 'Zone 1 - Front Yard': Zone 1 - Front Yard completed watering at 08:18 AM (EDT) for 2 minutes. (status=COMPLETED, duration = 120sec)
2018-04-21 08:19:00.813 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone[1]: 'Zone 1 - Front Yard' STOPPED watering (2018-04-21T12:18:04Z).
2018-04-21 08:19:00.814 [vent.ItemStateChangedEvent] - RachioTurtlePineHouse2Zone2PoolFront_RunZone changed from NULL to ON
2018-04-21 08:19:00.823 [vent.ItemStateChangedEvent] - RachioTurtlePineHouse2Zone2PoolFront_LastZoneEvent changed from NULL to {"timetstamp":"2018-04-21T12:18:05Z","summary":"Zone 2 - Pool Front began watering at 08:18 AM (EDT).","topic":"","type":"ZONE_STATUS","subType":"ZONE_STARTED"}
2018-04-21 08:19:00.847 [vent.ItemStateChangedEvent] - RachioTurtlePineHouse1Zone1FrontYard_RunZone changed from ON to OFF
2018-04-21 08:19:00.856 [vent.ItemStateChangedEvent] - RachioTurtlePineHouse1Zone1FrontYard_LastZoneEvent changed from {"timetstamp":"2018-04-21T12:16:05Z","summary":"Zone 1 - Front Yard began watering at 08:16 AM (EDT).","topic":"","type":"ZONE_STATUS","subType":"ZONE_STARTED"} to {"timetstamp":"2018-04-21T12:18:04Z","summary":"Zone 1 - Front Yard completed watering at 08:18 AM (EDT) for 2 minutes.","topic":"","type":"ZONE_STATUS","subType":"ZONE_COMPLETED"}
2018-04-21 08:20:20.919 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone: Event for zone[2] 'Zone 2 - Pool Front': Zone 2 - Pool Front completed watering at 08:20 AM (EDT) for 2 minutes. (status=COMPLETED, duration = 120sec)
Do you see the last zone/device event in PaperUI->Control?
If those are empty after a zone action you are defiantly not receiving the events. In this case check again your router setup.
You should see way more messages when debug is turned on
open the openHAB console (ssh openhab@ip_address -p 8108) and enter:
Markus I just entered that RANDOMNUMBER stuff here on the forum not on my setup. I do have real information on the logs… I just don’t know if anyone can do anything malicious with that info so it was my attempt at covering it up… Sorry for the confusion.
I made sure I had the debug command in karaf . I am not sure if it took last time as I noticed I put DEBUG in lower case. ( not sure if that makes a difference)
In paper UI I changed the ZoneRuntime for Pool Zone to 68 and then I clicked on Run Zone. Here is the output of that. I am still not getting the switch to update when it is done.
==> events.log <==
2018-04-21 09:25:47.835 [vent.ItemStateChangedEvent] - IRO1PoolZone_ZoneRuntime changed from 0 to 68
==> openhab.log <==
2018-04-21 09:25:54.726 [DEBUG] [ing.rachio.handler.RachioZoneHandler] - RachioZone.handleCommand ON for rachio:zone:1:0C3B70193560-1:run
2018-04-21 09:25:54.727 [INFO ] [ing.rachio.handler.RachioZoneHandler] - RachioZone: Starting zone 'Pool Zone [1]' for 68 secs
==> events.log <==
2018-04-21 09:25:54.727 [ome.event.ItemCommandEvent] - Item 'IRO1PoolZone_RunZone' received command ON
==> openhab.log <==
2018-04-21 09:25:54.727 [DEBUG] [inding.rachio.internal.api.RachioApi] - RachioApi: Start zone '7d2dcc70-f11c-42bc-92b2-6df87684a971' for 68 sec.
==> events.log <==
2018-04-21 09:25:54.730 [vent.ItemStateChangedEvent] - IRO1PoolZone_RunZone changed from OFF to ON
And this is what I see when I visit the webhook from within my network and outside as well. I changed my domain to redacted.com just for this forum post that’s not the real domain name…
$ curl -IS https://mqtt.rach.io
curl: (51) SSL: certificate subject name (*.iot.us-west-2.amazonaws.com) does not match target host name
'mqtt.rach.io'
looks to me like a cert issue but on the rachio side?
I’m referring to the following section of the README:
you could verify the proper registration of the callback after the binding is initialized
get the deviceId for the controller from the Rachio log entries
open a terminal window and run
curl -X GET -H "Content-Type: application/json" -H "Authorization: Bearer xxxxxxxx-xxxx-xxxx-xxxx-dc8d5c90350d" https://api.rach.io/1/public/notification/yyyyyyyy-yyyy-yyyy-yyyy-yyyyyyyy/webhook
replace xxxxxxxx-... with the apikey and yyyyyyyy... with the device id found in the OH log
you should see the configured url
all I get as a response is []. Weird because when I initialize it shows the webhook url and it is correct. Quick question, when I stated working with I remember reading about a rachio service file. I still don’t have that set up. Could that be the issue or would the things file take care of that?
nope, the rachio.cfg will supply global defaults, so you don’t need to set it for every thing.
please do the curl stuff mentioned above, we need to male sure that the webhook registration works fine. I could provide you the exact command if you send me your apikey and domain by email.
and we need the debug log - anything changed since you entered the log:set command?
I’m sure this is a tiny thing, which breaks the events coming through
ok, I am pretty sure that I have the URL call correct because I tried putting in a fake number just to see what happened and it returned an error. When I put my apikey and deviceid, it just returns"[]".
Here is my log after I make a small change to the things file just to make it restart. All I changed was the location that makes it appear on a different tab in my paper ui control page.
Hi, running the following commmand (after editing the ids)
curl -X GET -H "Content-Type: application/json" -H "Authorization: Bearer 8e600a4c-0027-4a9a-9bda-dc8d5c90350d" https://api.rach.io/1/public/notification/2a5e7d3c-c140-4e2e-91a1-a212a518adc5/webhook
replace '8e600a4c-0027-4a9a-9bda-dc8d5c90350d' by your appkey and
'2a5e7d3c-c140-4e2e-91a1-a212a518adc5' by your device id.
yep, https is not yet supported (see Security section in README)
I’m working on this, but for know jetty rejects the certificate (which means the inbound https requests gets dropped).
I did a lot of security functions inside the bundle. All Ids are useless if you don’t have the apikey. The communication is filtered by various network level thins (AWS ip address range - ip filter list gets loaded dynamically, http, right URI) and the externalId, which is a hash code generated by the binding. So appkey gets transmitted via https, but will not be visible in the http inbound webhook call.
I don’t like this status, but I think it’s safe to use. I’m still in discussion with Rachio, because of the inbound certificate.
Try to set a call back without https.
I updated the README to reflect the current status - sorry for confusion.
ok its done… Hmm based on the below I am thinking it may have something to do with my reverse proxy setup.
2018-04-22 21:20:57.862 [TRACE] [io.internal.api.RachioWebHookServlet] - RachioWebHook: Reqeust from 192.168.1.2:45696/rachio/webhook (192.168.1.2, HTTP/1.1)
2018-04-22 21:20:57.864 [TRACE] [io.internal.api.RachioWebHookServlet] - RachioWebHook: Data=''
2018-04-22 21:20:57.865 [DEBUG] [io.internal.api.RachioWebHookServlet] - RachioWebHook: Unable to process inbound request, data=''
I am not sure where that port number is coming from. The IP denoted there is for the machine I use that performs a reverse proxy and not the actual openhab machine.
My nat goes to the machine that has the reverse proxy and that redirects it to my openhab box if it hits the desired port. Its looking like I may need to nat that port as well but where is that port number coming from?
