robinostlund / homeassistant-volkswagencarnet

Volkswagen Carnet Component for home assistant
GNU General Public License v3.0
303 stars 61 forks source link

[BUG] Zone enter/exit for device_tracker doesn't seem to be triggered #608

Closed virtualdj closed 2 months ago

virtualdj commented 3 months ago

Environment

Describe the bug

Zone triggers doesn't seem to work with the provided device tracker.

Steps to reproduce

I have created two automations, this is the first one:

alias: Test Golf at home 1
description: ""
trigger:
  - platform: zone
    entity_id: device_tracker.golf_position
    zone: zone.home
    event: enter
condition: []
action:
  - service: notify.mobile_app_phone
    data:
      message: Golf at home (1).
mode: single

And this is the second:

alias: Test Golf at home 2
description: ""
trigger:
  - platform: device
    device_id: 9268bcbafb0fe0ee4659a62bb73901b6
    domain: device_tracker
    entity_id: 7b1fed5dd2fb4514c7422ae66b3159d5
    type: enters
    zone: zone.home
condition: []
action:
  - service: notify.mobile_app_phone
    data:
      message: Golf at home (2).
mode: single

None of the two is ever triggered: they report Never as their last execution (from the automations view in HA) and thus no traces are recorded.

If I check the device_tracker.golf_position sensor it correctly changes between Home and Away, with an Unknown state between the two (dark grey below), but this shouldn't be an issue with the automations above as I'm not tracking the state change but the zone enter/exit.

Device tracker history

The zone trigger should work because the device tracker has GPS coordinates: I can see them from the sensor attributes. Also, I wouldn't like to use state change trigger due to the problem of the Unknown state.

Is this a problem of my Home Assistant installation only? Does the same work for you?

virtualdj commented 3 months ago

Today I tried to capture the debug logs, here's the Position filtered data:

2024-04-05 17:12:49.402 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('not_home' == 'not_home'), skipping update.
2024-04-05 17:12:49.416 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-05 17:17:55.325 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-05 17:22:58.366 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('unknown' == 'None'), skipping update.
2024-04-05 17:22:58.388 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-05 17:28:01.241 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-05 17:33:08.968 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('home' == 'home'), skipping update.
2024-04-05 17:33:08.982 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-05 17:38:18.389 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('home' == 'home'), skipping update.

Here's the history:

Position history

and here there are the automations which didn't trigger at all:

Automations based on zone didn't trigger

Could it possibly be the missing transitions between not_home => unknown / None => home, i.e. the unknown state? Not an high priority bug, though... But having other reports from different users could help.

stickpin commented 2 months ago

@virtualdj The problem is, that when a vehicle is moving, there is no positioning data provided by VW and this is the reason for the "Unknown" state. Integration is not controlling the "home"/"not_home" status it's controlled by the Home Assistant based on the GPS data.

Btw, your logs are missing two updates: 2024-04-05 17:17:55.325 - At this time state changes from not_home to unknown 2024-04-05 17:28:01.241 - At this time state changes from unknown to home

Try to use automation based on the state change, I don't know how Zones are handling the unknown status:

description: ""
mode: single
trigger:
  - platform: state
    entity_id:
      - device_tracker.vw_touran_position
    to: home
condition: []
action:
  - service: notify.my_phone
    metadata: {}
    data:
      message: Master I am home!

This one should work.

virtualdj commented 2 months ago

Btw, your logs are missing two updates: 2024-04-05 17:17:55.325 - At this time state changes from not_home to unknown 2024-04-05 17:28:01.241 - At this time state changes from unknown to home

@stickpin I noticed the same, but I don't really have those lines in the log... 😮

I don't know how Zones are handling the unknown status:

Probably they don't handle it at all... hence, the problem. I can't find more documentation about it on the HA website.

Try to use automation based on the state change

Initially I though the same, but then I was frightened by the fact the automation could be triggered not only when I was actually "coming home" (transition away > home) but also when the VW servers were unable to get the position (so that the state was unknown / unavailable for a while and then "home" again).

I'll try to add an additional automation and see if this is the case and also to capture new logs to see if those two lines above are still missing.

stickpin commented 2 months ago

You can try to combine it with the vehicle_moving sensor. Something like this:

description: ""
mode: single
trigger:
  - platform: state
    entity_id:
      - binary_sensor.vw_touran_vehicle_moving
    from: "on"
    to: "off"
condition:
  - condition: state
    entity_id: device_tracker.vw_touran_position
    state: home
action:
  - service: notify.my_phone
    metadata: {}
    data:
      message: I am home!
stickpin commented 2 months ago

@stickpin I noticed the same, but I don't really have those lines in the log... 😮

yes, you are missing library debugging. Check the Wiki page on how to enable full debug logs: https://github.com/robinostlund/homeassistant-volkswagencarnet/wiki/Enabling-Debug-Logging-in-Home-Assistant

janchlebek commented 2 months ago

Just as hint: I'm using the state triggers for a long time and it seems to works properly for me, I do not really care about any moving or not moving, just checking from or to states. image

virtualdj commented 2 months ago

Yep, I tried both moving and non-moving automations and they worked.

Automations statuses

However, I tried re-capturing the logs and I still think there's something missing. This is the Position sensor logbook for today:

Position sensor logbook

Here's the full log (only relevant lines, extracted with $ cat home-assistant.log | grep -i -E 'position|moving' | grep -i -v 'selectivestatus') with VIN and location redacted:

2024-04-09 17:47:27.300 DEBUG (MainThread) [volkswagencarnet.vw_connection] HTTP GET "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition"
2024-04-09 17:47:30.390 DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition" returned with status code [200], headers: <CIMultiDictProxy('Date': 'Tue, 09 Apr 2024 15:47:31 GMT', 'Content-Type': 'application/json; charset=UTF-8', 'Content-Length': '109', 'Connection': 'keep-alive', 'Bff-Trace-Id': 'c58adeef-8876-4aaa-91e8-fa96af5b334b', 'Content-Encoding': 'gzip', 'Content-Security-Policy': "default-src 'self'", 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains', 'Vary': 'Accept-Encoding', 'X-Content-Type-Options': 'nosniff', 'X-Dns-Prefetch-Control': 'off', 'X-Download-Options': 'noopen', 'X-Frame-Options': 'DENY', 'X-Xss-Protection': '1; mode=block')>, response: {'data': {'lon': 11.00000, 'lat': 46.000000, 'carCapturedTimestamp': datetime.datetime(2024, 4, 9, 15, 16, 29, tzinfo=datetime.timezone.utc)}}
2024-04-09 17:47:34.925 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Position is supported
2024-04-09 17:47:34.934 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 API parkingposition is supported
2024-04-09 17:47:34.938 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Vehicle Moving is supported
2024-04-09 17:47:35.019 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-09 17:47:35.060 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('not_home' == 'not_home'), skipping update.
2024-04-09 17:47:35.071 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 17:47:35.071 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 17:47:35.071 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Vehicle Moving: state not changed ('off' == 'off'), skipping update.

2024-04-09 17:52:34.299 DEBUG (MainThread) [volkswagencarnet.vw_connection] HTTP GET "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition"
2024-04-09 17:52:37.179 DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition" returned with status code [204], headers: <CIMultiDictProxy('Date': 'Tue, 09 Apr 2024 15:52:38 GMT', 'Connection': 'keep-alive', 'Bff-Trace-Id': '3f28faf2-881e-458d-ad99-548df3b8b33b', 'Content-Security-Policy': "default-src 'self'", 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains', 'Vary': 'Accept-Encoding', 'X-Content-Type-Options': 'nosniff', 'X-Dns-Prefetch-Control': 'off', 'X-Download-Options': 'noopen', 'X-Frame-Options': 'DENY', 'X-Xss-Protection': '1; mode=block')>, response: {'status_code': 204}
2024-04-09 17:52:37.179 DEBUG (MainThread) [volkswagencarnet.vw_connection] Seems car is moving, HTTP 204 received from parkingposition
2024-04-09 17:52:38.764 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Position is supported
2024-04-09 17:52:38.775 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 API parkingposition is supported
2024-04-09 17:52:38.779 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Vehicle Moving is supported
2024-04-09 17:52:38.823 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-09 17:52:38.865 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving

2024-04-09 17:57:38.300 DEBUG (MainThread) [volkswagencarnet.vw_connection] HTTP GET "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition"
2024-04-09 17:57:39.632 DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition" returned with status code [204], headers: <CIMultiDictProxy('Date': 'Tue, 09 Apr 2024 15:57:40 GMT', 'Connection': 'keep-alive', 'Bff-Trace-Id': '3aabbbc9-3fcd-4972-93f2-9245966f17f5', 'Content-Security-Policy': "default-src 'self'", 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains', 'Vary': 'Accept-Encoding', 'X-Content-Type-Options': 'nosniff', 'X-Dns-Prefetch-Control': 'off', 'X-Download-Options': 'noopen', 'X-Frame-Options': 'DENY', 'X-Xss-Protection': '1; mode=block')>, response: {'status_code': 204}
2024-04-09 17:57:39.632 DEBUG (MainThread) [volkswagencarnet.vw_connection] Seems car is moving, HTTP 204 received from parkingposition
2024-04-09 17:57:41.518 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Position is supported
2024-04-09 17:57:41.528 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 API parkingposition is supported
2024-04-09 17:57:41.532 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Vehicle Moving is supported
2024-04-09 17:57:41.546 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-09 17:57:41.574 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('unknown' == 'None'), skipping update.
2024-04-09 17:57:41.584 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 17:57:41.584 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 17:57:41.584 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Vehicle Moving: state not changed ('on' == 'on'), skipping update.

2024-04-09 18:02:41.299 DEBUG (MainThread) [volkswagencarnet.vw_connection] HTTP GET "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition"
2024-04-09 18:02:42.041 DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition" returned with status code [200], headers: <CIMultiDictProxy('Date': 'Tue, 09 Apr 2024 16:02:43 GMT', 'Content-Type': 'application/json; charset=UTF-8', 'Content-Length': '111', 'Connection': 'keep-alive', 'Bff-Trace-Id': '0c02f9a9-9e59-43e9-aca6-ff33ffdf9a13', 'Content-Encoding': 'gzip', 'Content-Security-Policy': "default-src 'self'", 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains', 'Vary': 'Accept-Encoding', 'X-Content-Type-Options': 'nosniff', 'X-Dns-Prefetch-Control': 'off', 'X-Download-Options': 'noopen', 'X-Frame-Options': 'DENY', 'X-Xss-Protection': '1; mode=block')>, response: {'data': {'lon': 12.000000, 'lat': 47.000000, 'carCapturedTimestamp': datetime.datetime(2024, 4, 9, 16, 2, 41, tzinfo=datetime.timezone.utc)}}
2024-04-09 18:02:42.532 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Position is supported
2024-04-09 18:02:42.545 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 API parkingposition is supported
2024-04-09 18:02:42.549 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Vehicle Moving is supported
2024-04-09 18:02:42.635 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-09 18:02:42.679 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 18:02:42.694 INFO (MainThread) [homeassistant.components.automation.golf_not_moving_and_state_at_home] Golf not moving and state at home: Running automation actions
2024-04-09 18:02:42.694 INFO (MainThread) [homeassistant.components.automation.golf_not_moving_and_state_at_home] Golf not moving and state at home: Executing step call service

2024-04-09 18:07:42.301 DEBUG (MainThread) [volkswagencarnet.vw_connection] HTTP GET "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition"
2024-04-09 18:07:42.982 DEBUG (MainThread) [volkswagencarnet.vw_connection] Request for "https://emea.bff.cariad.digital/vehicle/v1/vehicles/WVWZZZCDZMW000000/parkingposition" returned with status code [200], headers: <CIMultiDictProxy('Date': 'Tue, 09 Apr 2024 16:07:44 GMT', 'Content-Type': 'application/json; charset=UTF-8', 'Content-Length': '111', 'Connection': 'keep-alive', 'Bff-Trace-Id': '0e059c74-042f-4da3-a37c-1a042633d129', 'Content-Encoding': 'gzip', 'Content-Security-Policy': "default-src 'self'", 'Strict-Transport-Security': 'max-age=31536000; includeSubDomains', 'Vary': 'Accept-Encoding', 'X-Content-Type-Options': 'nosniff', 'X-Dns-Prefetch-Control': 'off', 'X-Download-Options': 'noopen', 'X-Frame-Options': 'DENY', 'X-Xss-Protection': '1; mode=block')>, response: {'data': {'lon': 12.000000, 'lat': 47.000000, 'carCapturedTimestamp': datetime.datetime(2024, 4, 9, 16, 2, 41, tzinfo=datetime.timezone.utc)}}
2024-04-09 18:07:44.380 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Position is supported
2024-04-09 18:07:44.390 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 API parkingposition is supported
2024-04-09 18:07:44.394 DEBUG (MainThread) [volkswagencarnet.vw_dashboard] WVWZZZCDZMW000000 Vehicle Moving is supported
2024-04-09 18:07:44.407 DEBUG (MainThread) [custom_components.volkswagencarnet.sensor] Getting state of api_parkingposition_status
2024-04-09 18:07:44.440 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Position: state not changed ('home' == 'home'), skipping update.
2024-04-09 18:07:44.452 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 18:07:44.452 DEBUG (MainThread) [custom_components.volkswagencarnet.binary_sensor] Getting state of vehicle_moving
2024-04-09 18:07:44.452 DEBUG (MainThread) [custom_components.volkswagencarnet] Golf Vehicle Moving: state not changed ('off' == 'off'), skipping update.

A brief summary:

2024-04-09 17:47:30.390 >> Status: 200
2024-04-09 17:47:35.060 >> Position: not_home

2024-04-09 17:52:37.179 >> Status: 204
2024-04-09 17:52:38.823 >> Position: ??? (not reported)

2024-04-09 17:57:39.632 >> Status: 204
2024-04-09 17:57:41.574 >> Position: None

2024-04-09 18:02:42.041 >> Status: 200
2024-04-09 18:02:42.635 >> Position: Home

I still cannot "see" a clear line with the transitions from these states:

Is this correct?

janchlebek commented 2 months ago

I am not sure what exactly you are trying to achieve but based on the screenshot in this post it seems to work properly and the position is reported.

My idea is that the trigger for your automation should not be the moving/not_moving state (with position as condition) but simply only trigger on the state of the position (just remove the moving part completely).

The position is anyway only updated to the real location when moving state changes so it makes no sense to wait for the movement status, position should be enough.

virtualdj commented 2 months ago

based on the screenshot in this post it seems to work properly and the position is reported

The position is reported correcly, it works in the sense of displaying "Away" or "Home" but it doesn't run the zone enter / zone exit triggers.

My idea is that the trigger for your automation should not be the moving/not_moving state (with position as condition) but simply only trigger on the state of the position (just remove the moving part completely).

This is a workaround, ok, but I still think that zone enter / exit should work, as the position is reported. Otherwise why having the Zone triggers in Home Assistant?

The position is anyway only updated to the real location when moving state changes so it makes no sense to wait for the movement status, position should be enough.

The movement status has been added just to be sure that the state change (transition from anything to home) could not be triggered when VW servers were unable to get the position (so that the state becomes unknown / unavailable for a while) and then "home" again (after the API comes online). I don't want the automation to trigger in this case, because the vehicle is already at home.

janchlebek commented 2 months ago

I get your point. I think this has to do with the way location is reported. The vehicle is not really moving but more "jumping" around having the unknown state in between and this is not playing well with HA Zone detection I suppose. And this is where the state trigger instead of zone enter/leave comes to play and works. In fact I had the problem you mention as well and solved it as I mentioned before. You can create some logic with a helper that will change to ON when the vehicle is moving at least for a minute or two and then have this in your automation as condition and trigger only when this is true (this will avoid firing the automation again if there is a problem).

stickpin commented 2 months ago

@virtualdj what @janchlebek is saying is correct. I've mentioned it in my initial responses as well. VW is not reporting any location once a vehicle is moving, VW replies with HTTP 204 nothing I can do about it. It doesn't make any sense to continue reporting an old location, because it will be completely misleading.

Regarding Zones... It seems that the zone change from unknown to home/not_home is not triggering anything on the Home Assistant side. It's an internal Home Assistant Core logic, I cannot change this behavior either. I don't think it's necessary as well, as you have a few other options to get the same result.

You can solve it in two ways, both were proposed by me and @janchlebek.