search

sebr / bhyve-home-assistant

Orbit BHyve custom component for Home Assistant
MIT License
251 stars 42 forks source link

b-hyve HT34 - Automation doesn't start watering (for one specific zone only) #252

Closed cdmicacc closed 1 month ago

cdmicacc commented 1 month ago

Describe the bug I have an HT34 with two zones connected - "Veggies" (zone 1) and "Flowers" (zone 3) - and two identical automations. The automations include a "Call Service" with this YAML:

service: bhyve.start_watering
data:
  entity_id: switch.unknown_zone
  minutes: "{{ states(\"input_number.veggies_watering_time\") }}"

(with the entity_id and template variable changed, of course) veggies_watering_time is set to 20 (minutes). flowers_watering_time is set to 5.

The automations run at different times, so there is no overlap. The issue is that the Veggies automation successfully starts watering, but the Flowers automation never does. The traces for the Flowers automation show that the Call Service step ran, but there are never logbook entries for watering actually beginning. For the Veggies zone there are, and the manual watering happens correctly.

This problem seems fairly recent (within the last few weeks) though I can't pinpoint when it began failing. I am running the most recent version of the B-Hyve integration (3.2.4) according to HACS.

I have also checked in the b-hyve app to see if something in set up wrong there, but as far as I can tell both zones are configured the same - there are no B-Hyve smart watering or other programs set up inside B-hyve itself.

The strangest thing is that manually starting watering by setting the switch for Flowers to "On" works, and successfully begins watering of that zone.

Expected behaviour Both zones should begin a manual watering program when the start_watering service is called.

BHyve devices 1 Orbit B-Hyve HT-34 with two zones (#1 and #3) in use. Connected via a B-Hyve Wifi BH1G2.

Both devices firmwares are up-to-date.

Device Diagnostics

{
  "home_assistant": {
    "installation_type": "Home Assistant OS",
    "version": "2024.7.0",
    "dev": false,
    "hassio": true,
    "virtualenv": false,
    "python_version": "3.12.4",
    "docker": true,
    "arch": "aarch64",
    "timezone": "America/Toronto",
    "os_name": "Linux",
    "os_version": "6.6.33-haos",
    "supervisor": "2024.06.2",
    "host_os": "Home Assistant OS 12.4",
    "docker_version": "26.1.4",
    "chassis": "embedded",
    "run_as_root": true
  },
  "custom_components": {
    "hacs": {
      "documentation": "https://hacs.xyz/docs/configuration/start",
      "version": "1.34.0",
      "requirements": [
        "aiogithubapi>=22.10.1"
      ]
    },
    "alexa_media": {
      "documentation": "https://github.com/alandtse/alexa_media_player/wiki",
      "version": "4.10.2",
      "requirements": [
        "alexapy==1.27.10",
        "packaging>=20.3",
        "wrapt>=1.14.0"
      ]
    },
    "chargepoint": {
      "documentation": "https://github.com/mbillow/ha-chargepoint",
      "version": "0.7.0",
      "requirements": [
        "python-chargepoint==1.9.2"
      ]
    },
    "monitor_docker": {
      "documentation": "https://github.com/ualex73/monitor_docker",
      "version": "1.18",
      "requirements": [
        "aiodocker==0.21.0",
        "python-dateutil==2.8.2"
      ]
    },
    "webrtc": {
      "documentation": "https://github.com/AlexxIT/WebRTC",
      "version": "v3.5.2",
      "requirements": []
    },
    "composite": {
      "documentation": "https://github.com/pnbruckner/ha-composite-tracker/blob/3.4.2/README.md",
      "version": "3.4.2",
      "requirements": [
        "filetype==1.2.0"
      ]
    },
    "bhyve": {
      "documentation": "https://github.com/sebr/bhyve-home-assistant/blob/main/README.md",
      "version": "3.2.4",
      "requirements": []
    }
  },
  "integration_manifest": {
    "domain": "bhyve",
    "name": "Orbit B-hyve",
    "codeowners": [
      "sebr"
    ],
    "config_flow": true,
    "dependencies": [],
    "documentation": "https://github.com/sebr/bhyve-home-assistant/blob/main/README.md",
    "iot_class": "cloud_push",
    "requirements": [],
    "version": "3.2.4",
    "is_built_in": false
  },
  "setup_times": {
    "null": {
      "setup": 0.0001377980224788189
    },
    "0be6c49e3ac31890514848a6d0446fdc": {
      "wait_import_platforms": -7.088571018073708,
      "config_entry_setup": 8.838657742016949
    }
  },
  "data": {
    "devices": [
      {
        "last_connected_at": "2024-07-02T12:27:37.663Z",
        "address": "**REDACTED**",
        "timezone": {
          "dst_offset": 3600,
          "raw_offset": -18000,
          "timezone_id": "America/Toronto",
          "timezone_name": "Eastern Daylight Time"
        },
        "full_location": "**REDACTED**",
        "firmware_version": "0042",
        "name": "b-hyve Wifi",
        "type": "bridge",
        "updated_at": "2024-07-02T12:28:07.308Z",
        "reference": "44675528b5d7",
        "mac_address": "44675528b5d7",
        "wifi_version": 0,
        "id": "64723aaa8f95440e1a242e3c",
        "num_stations": 0,
        "user_id": "647236472e722208ad503a34",
        "device_gateway_topic": "devices-9",
        "hardware_version": "BH1G2-0000",
        "is_connected": true,
        "location": "**REDACTED**",
        "created_at": "2023-05-27T17:15:22.195Z",
        "network_topology_id": "64723aaa8f95440e1a242e3f"
      },
      {
        "last_connected_at": "2024-07-04T12:49:15.355Z",
        "address": "**REDACTED**",
        "water_sense_mode": "off",
        "timezone": {
          "dst_offset": 3600,
          "raw_offset": -18000,
          "timezone_id": "America/Toronto",
          "timezone_name": "Eastern Daylight Time"
        },
        "full_location": "**REDACTED**",
        "weather_forecast_location_id": "**REDACTED**",
        "firmware_version": "0058",
        "name": "b-hyve",
        "type": "sprinkler_timer",
        "battery": {
          "percent": 53,
          "charging": false,
          "mv": 2723
        },
        "restricted_frequency": null,
        "weather_delay_thresholds": {
          "precip_prob": 60,
          "precip_in": 0.12618110236220473,
          "wind_speed_mph": 37.39839338264535,
          "freeze_temp_f": 37
        },
        "updated_at": "2024-07-04T12:49:16.165Z",
        "reference": "4467559c0d91",
        "mac_address": "4467559c0d91",
        "weather_station_id": "**REDACTED**",
        "status": {
          "run_mode": "manual",
          "rssi": -84,
          "provisioned": true,
          "rain_delay_overridden_at": "2023-06-12T21:53:57.173Z",
          "phy": "le_1m_1000",
          "watering_status": {
            "program": null,
            "current_station": 3,
            "started_watering_station_at": "2024-07-04T12:46:36.000Z",
            "stations": [
              {
                "run_time": 5.0,
                "station": 3
              }
            ],
            "rain_sensor_hold": false
          },
          "rain_delay": 0,
          "last_battery_alarm_at": "2024-05-31T12:21:37.763Z",
          "status_updated_at": "2024-07-04T12:41:24.657Z",
          "flow_sensor": null,
          "watering-status": null,
          "rain_delay_started_at": "2024-07-04T12:49:12.000Z"
        },
        "id": "64723ba8c7d3027ce1321abe",
        "num_stations": 4,
        "zones": [
          {
            "station": 1,
            "slope_grade": 0,
            "sun_shade": "mostly_sunny",
            "name": "Veggies",
            "landscape_type": "annual_flowers",
            "num_sprinklers": 0,
            "soil_type": "sandy_loam",
            "catch_cup_volumes": [],
            "catch_cup_run_time": 0,
            "smart_watering_enabled": false,
            "sprinkler_type": "drip"
          },
          {
            "station": 2,
            "slope_grade": 0,
            "sun_shade": "mostly_shady",
            "landscape_type": "annual_flowers",
            "geometry": {
              "type": "circle",
              "radius": 1
            },
            "num_sprinklers": 3,
            "soil_type": "loam",
            "catch_cup_volumes": [],
            "catch_cup_run_time": 0,
            "smart_watering_enabled": false,
            "sprinkler_type": "spray"
          },
          {
            "station": 3,
            "slope_grade": 0,
            "sun_shade": "mostly_sunny",
            "name": "Flowers",
            "landscape_type": "annual_flowers",
            "geometry": {
              "type": "circle",
              "radius": 1
            },
            "num_sprinklers": 4,
            "soil_type": "sandy",
            "catch_cup_volumes": [],
            "catch_cup_run_time": 0,
            "smart_watering_enabled": false,
            "sprinkler_type": "spray"
          },
          {
            "station": 4,
            "num_sprinklers": 0,
            "catch_cup_volumes": [],
            "catch_cup_run_time": 0,
            "smart_watering_enabled": false
          }
        ],
        "user_id": "647236472e722208ad503a34",
        "google_home_status": null,
        "device_gateway_topic": "devices-9",
        "smart_watering_enabled": true,
        "hardware_version": "HT34-0001",
        "is_connected": true,
        "location": "**REDACTED**",
        "created_at": "2023-05-27T17:19:36.970Z",
        "suggested_start_time": null,
        "et_id": "5644ff04ad27a7777ff68152",
        "network_topology_id": "64723aaa8f95440e1a242e3f"
      }
    ],
    "programs": []
  }
}

I have captured debug logs for an unsuccessful run of the automation but I am not sure what it's telling me. The automation runs at 8:15am local time (EDT):

2024-07-03 08:14:03.993 DEBUG (MainThread) [custom_components.bhyve.sensor] b-hyve battery: {'percent': 56, 'mv': 2740}
2024-07-03 08:15:00.123 INFO (MainThread) [custom_components.bhyve.switch] start_watering service called
2024-07-03 08:15:00.123 DEBUG (MainThread) [custom_components.bhyve.switch] Service handler: start_watering {'minutes': 5}
2024-07-03 08:15:00.124 INFO (MainThread) [custom_components.bhyve.switch] Starting watering
2024-07-03 08:15:52.578 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"change_mode","mode":"off","device_id":"64723ba8c7d3027ce1321abe","timestamp":"2024-07-02T12:39:19.000Z"}', extra='')
2024-07-03 08:15:52.578 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve state - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.579 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve battery level - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.579 DEBUG (MainThread) [custom_components.bhyve.sensor] b-hyve battery: {'percent': 56, 'mv': 2740}
2024-07-03 08:15:52.579 INFO (MainThread) [custom_components.bhyve] Message received: Veggies zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.579 INFO (MainThread) [custom_components.bhyve] Message received: Unnamed Zone zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.579 INFO (MainThread) [custom_components.bhyve] Message received: Flowers zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.579 INFO (MainThread) [custom_components.bhyve] Message received: Unnamed Zone zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.581 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"fault","stations":[],"timestamp":"2024-07-02T12:39:19.000Z","stream-id":"94568b2c-b9be-41a9-9e8b-adcf82b7d7c9","client-topics":null,"device_id":"64723ba8c7d3027ce1321abe"}', extra='')
2024-07-03 08:15:52.583 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"battery_status","mv":2656,"charging":false,"timestamp":"2024-07-02T12:39:19.000Z","stream-id":"94568b2c-b9be-41a9-9e8b-adcf82b7d7c9","client-topics":null,"device_id":"64723ba8c7d3027ce1321abe"}', extra='')
2024-07-03 08:15:52.584 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve battery level - 64723ba8c7d3027ce1321abe - {'event': 'battery_status', 'mv': 2656, 'charging': False, 'timestamp': '2024-07-02T12:39:19.000Z', 'stream-id': '94568b2c-b9be-41a9-9e8b-adcf82b7d7c9', 'client-topics': None, 'device_id': '64723ba8c7d3027ce1321abe'}
2024-07-03 08:15:52.584 DEBUG (MainThread) [custom_components.bhyve.sensor] b-hyve battery: {'percent': 56, 'mv': 2740}
2024-07-03 08:15:52.587 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"rain_delay","delay":0,"rain_delay_weather_type":"rain","rain_delay_cause":"manual","device_id":"64723ba8c7d3027ce1321abe","timestamp":"2024-07-02T12:39:19.000Z"}', extra='')
2024-07-03 08:15:52.587 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve rain delay - 64723ba8c7d3027ce1321abe - {'event': 'rain_delay', 'delay': 0, 'rain_delay_weather_type': 'rain', 'rain_delay_cause': 'manual', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-02T12:39:19.000Z'}
2024-07-03 08:15:52.942 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"change_mode","mode":"off","device_id":"64723ba8c7d3027ce1321abe","timestamp":"2024-07-03T12:15:50.000Z"}', extra='')
2024-07-03 08:15:52.942 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve state - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:52.943 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve battery level - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:52.943 DEBUG (MainThread) [custom_components.bhyve.sensor] b-hyve battery: {'percent': 56, 'mv': 2740}
2024-07-03 08:15:52.943 INFO (MainThread) [custom_components.bhyve] Message received: Veggies zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:52.943 INFO (MainThread) [custom_components.bhyve] Message received: Unnamed Zone zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:52.943 INFO (MainThread) [custom_components.bhyve] Message received: Flowers zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:52.943 INFO (MainThread) [custom_components.bhyve] Message received: Unnamed Zone zone - 64723ba8c7d3027ce1321abe - {'event': 'change_mode', 'mode': 'off', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:52.946 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"fault","stations":[],"timestamp":"2024-07-03T12:15:50.000Z","stream-id":"94568b2c-b9be-41a9-9e8b-adcf82b7d7c9","client-topics":null,"device_id":"64723ba8c7d3027ce1321abe"}', extra='')
2024-07-03 08:15:52.952 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"battery_status","mv":2656,"charging":false,"timestamp":"2024-07-03T12:15:50.000Z","stream-id":"94568b2c-b9be-41a9-9e8b-adcf82b7d7c9","client-topics":null,"device_id":"64723ba8c7d3027ce1321abe"}', extra='')
2024-07-03 08:15:52.952 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve battery level - 64723ba8c7d3027ce1321abe - {'event': 'battery_status', 'mv': 2656, 'charging': False, 'timestamp': '2024-07-03T12:15:50.000Z', 'stream-id': '94568b2c-b9be-41a9-9e8b-adcf82b7d7c9', 'client-topics': None, 'device_id': '64723ba8c7d3027ce1321abe'}
2024-07-03 08:15:52.952 DEBUG (MainThread) [custom_components.bhyve.sensor] b-hyve battery: {'percent': 56, 'mv': 2740}
2024-07-03 08:15:52.955 DEBUG (MainThread) [custom_components.bhyve.pybhyve.websocket] msg received WSMessage(type=<WSMsgType.TEXT: 1>, data='{"event":"rain_delay","delay":0,"rain_delay_weather_type":"rain","rain_delay_cause":"manual","device_id":"64723ba8c7d3027ce1321abe","timestamp":"2024-07-03T12:15:50.000Z"}', extra='')
2024-07-03 08:15:52.956 INFO (MainThread) [custom_components.bhyve] Message received: b-hyve rain delay - 64723ba8c7d3027ce1321abe - {'event': 'rain_delay', 'delay': 0, 'rain_delay_weather_type': 'rain', 'rain_delay_cause': 'manual', 'device_id': '64723ba8c7d3027ce1321abe', 'timestamp': '2024-07-03T12:15:50.000Z'}
2024-07-03 08:15:53.957 INFO (MainThread) [custom_components.bhyve.pybhyve.client] Forcing device refresh
2024-07-03 08:19:03.330 DEBUG (MainThread) [custom_components.bhyve.sensor] b-hyve battery: {'percent': 42, 'charging': False, 'mv': 2656}

It's entirely possible I have something misconfigured where that I am not seeing. I am happy to provide any additional details if needed, or do any local debugging.

cdmicacc commented 1 month ago

Closing this - it seems like the issue was something in the b-hyve, since a factory reset has gotten everything working again. I would still love to know what, if anything, the logs might have been telling me (in case it happens again).