NabuCasa / hass-nabucasa

Issues related to the cloud integration in Nabu Casa
GNU General Public License v3.0
171 stars 56 forks source link

Ikea blind won't work with open or close command with google home. #152

Closed blair287 closed 11 months ago

blair287 commented 4 years ago

Not sure when this issue starts but this is whats happening used to work ok.

1) if i control the ikea blind via HA UI up or down it works fine.

2) if i ask google to open or close (linked through nabu casa) it will start moving then stop after about 10cm this happens every time.

3) if i unlink the blind from google and relink it works for first go then back to the 10cm and stop.

4) if i ask say open to 10% and its closed for example it will open or close normally issue only seems to occur when opening or closing commands used.

this comes up sometimes with a different number everytime i ask google to open or close the blind.

allanpersson commented 4 years ago

@blair287 are you having your repeaters connected and within a few meters? That problem did I have and it was related to the repeaters bot connected and/or close enough 🙏

blair287 commented 4 years ago

@blair287 are you having your repeaters connected and within a few meters? That problem did I have and it was related to the repeaters bot connected and/or close enough 🙏

The repeater is less than a meter from the blind.

controlling from the UI works 100% only issue when using google so zigbee network cant be issue.

blair287 commented 4 years ago

Well this is getting super annoying may have to switch back to smartthings all these issues are driving me mad.

cogneato commented 4 years ago

Is there a difference between "open the blinds" and "open the blinds 100%"?

blair287 commented 4 years ago

Is there a difference between "open the blinds" and "open the blinds 100%"?

If I say open or set to 100% moves all the way same as 0% but open and close on their own 90% of the time moves only about 10cm and stops again.

balloob commented 4 years ago

What blinds do you use?

Can you enable debug logging for hass_nabucasa and see what data is exchanged with Google?

blair287 commented 4 years ago

What blinds do you use?

Can you enable debug logging for hass_nabucasa and see what data is exchanged with Google?

How do I do that?

balloob commented 4 years ago

Add this to your configuration.yaml:

logger:
  logs:
    hass_nabucasa: debug
blair287 commented 4 years ago

Add this to your configuration.yaml:

logger:
  logs:
    hass_nabucasa: debug

Ok added it will post logs soon. It's IKEA blind connected through ZHA.

Pressing open or close in app will make blind open or close correctly but ask Google to close blind for example it will move a few cm then stop again. Then asking it again a second time close the blind it will move a bit more and stop or sometimes then move fully.

blair287 commented 4 years ago

If i open and close the blind via home assistant it works although with a 5 second delay on command issue to it executing, but if the command is issued via google to close the blind (linked via Nabucasa) it says sure and home assistant shows the down arrow picture so its received a command but then does absolutely nothing just sits there.

If i issue the command again for a second time then it moves.

Screenshot_20200720-094109

logs:

{'handler': 'google_actions',
 'msgid': '5e509ba7-f3d0-4de3-9e07-f98852125cb5',
 'payload': {'inputs': [{'context': {'locale_country': 'GB',
                                     'locale_language': 'en'},
                         'intent': 'action.devices.EXECUTE',
                         'payload': {'commands': [{'devices': [{'customData': {'baseUrl': 'https://mylink.ui.nabu.casa',
                                                                               'httpPort': 8123,
                                                                               'httpSSL': False,
                                                                               'proxyDeviceId': 'dc25e787-65fd-4c8e-bf64-7ec6681ecb93',
                                                                               'uuid': '3a199554fb2542fe87c0ff516e651fdd',
                                                                               'webhookId': 'ce565e5a19587d7e06f9f8aed82d68d10a796dea8e200b7b414709bd35610114'},
                                                                'id': 'cover.bedroom_blind'}],
                                                   'execution': [{'command': 'action.devices.commands.OpenClose',
                                                                  'params': {'openPercent': 0}}]}]}}],
             'requestId': '11090729089018306071'}}
2020-07-20 09:40:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event google_assistant_command[L]: request_id=11090729089018306071, entity_id=cover.bedroom_blind, execution=command=action.devices.commands.OpenClose, params=openPercent=0, source=cloud>
2020-07-20 09:40:40 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event call_service[L]: domain=cover, service=close_cover, service_data=entity_id=cover.bedroom_blind>
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy.device] [0x5d0b] Extending timeout for 0x91 request
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.zigbee.application] Sending Zigbee request with tsn 145 under 146 request id, data: b'019101'
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_request (18, 146, 0, <DeconzAddressEndpoint address_mode=2 address=0x5d0b endpoint=1>, 260, 258, 1, b'\x01\x91\x01', 2, 0)
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.uart] Send: 0x121700190012009200020b5d01040102010103000191010200
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x121700090002002292
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.api] APS data request response: [2, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, 146]
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x0e18000700a600
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_CONFIRM|2: 166>, 0]
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_confirm (0,)
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.uart] Send: 0x04180007000000
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x04180013000c002292020b5d01010000000000
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.api] APS data confirm response for request with id 146: 00
2020-07-20 09:40:40 DEBUG (MainThread) [zigpy_deconz.api] Request id: 0x92 'aps_data_confirm' for <DeconzAddressEndpoint address_mode=ADDRESS_MODE.NWK address=0x5d0b endpoint=1>, status: 0x00
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x0e19000700aa00
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] Device state changed response: [<DeviceState.128|APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 170>, 0]
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.uart] Send: 0x1719000800010001
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x17190023001c002a02000001020b5d01040102010500088e0b010000afff233a8600ca
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [28, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|APSDE_DATA_INDICATION|2: 42>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x5d0b>, 1, 260, 258, b'\x08\x8e\x0b\x01\x00', 0, 175, 255, 35, 58, 134, 0, -54]
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy.zcl] [0x5d0b:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=142 command_id=Command.Default_Response>
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x5d0b>, ep: 1, profile: 0x0104, cluster_id: 0x0102, data: b'088e0b0100'
2020-07-20 09:40:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5d0b:1:0x0102]: executed 'down_close' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-07-20 09:40:41 DEBUG (MainThread) [homeassistant.components.zha.cover] state=closing
2020-07-20 09:40:41 DEBUG (MainThread) [homeassistant.core] Bus:Handling <Event state_changed[L]: entity_id=cover.bedroom_blind, old_state=<state cover.bedroom_blind=open; current_position=100, friendly_name=Bedroom Blind, supported_features=15 @ 2020-07-20T07:30:35.886728+01:00>, new_state=<state cover.bedroom_blind=closing; current_position=100, friendly_name=Bedroom Blind, supported_features=15 @ 2020-07-20T09:40:41.780775+01:00>>
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] Command Command.aps_data_indication (1, 1)
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.uart] Send: 0x171a000800010001
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.uart] Frame received: 0x171a0023001c002202000001020b5d0104010201050008910b010000afffc0338600ca
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] APS data indication response: [28, <DeviceState.APSDE_DATA_REQUEST_SLOTS_AVAILABLE|2: 34>, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x0000>, 1, <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x5d0b>, 1, 260, 258, b'\x08\x91\x0b\x01\x00', 0, 175, 255, 192, 51, 134, 0, -54]
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy.zcl] [0x5d0b:1:0x0102] ZCL deserialize: <ZCLHeader frame_control=<FrameControl frame_type=GLOBAL_COMMAND manufacturer_specific=False is_reply=True disable_default_response=False> manufacturer=None tsn=145 command_id=Command.Default_Response>
2020-07-20 09:40:41 DEBUG (MainThread) [zigpy_deconz.api] 'aps_data_indication' response from <DeconzAddress address_mode=ADDRESS_MODE.NWK address=0x5d0b>, ep: 1, profile: 0x0104, cluster_id: 0x0102, data: b'08910b0100'
2020-07-20 09:40:41 DEBUG (MainThread) [homeassistant.components.zha.core.channels.base] [0x5d0b:1:0x0102]: executed 'down_close' command with args: '()' kwargs: '{}' result: [1, <Status.SUCCESS: 0>]
2020-07-20 09:40:41 DEBUG (MainThread) [homeassistant.components.zha.cover] state=closing
2020-07-20 09:40:41 DEBUG (MainThread) [hass_nabucasa.iot] Publishing message:
{'msgid': '5e509ba7-f3d0-4de3-9e07-f98852125cb5',
 'payload': {'payload': {'commands': [{'ids': ['cover.bedroom_blind'],
                                       'states': {'online': True,
                                                  'openPercent': 100},
                                       'status': 'SUCCESS'}]},
             'requestId': '11090729089018306071'}}
blair287 commented 4 years ago

The logs show it was asked to move to 0% but it reports it's at 100% and it says success? I'd says that's a failure 😂

blair287 commented 4 years ago

Add this to your configuration.yaml:

logger:
  logs:
    hass_nabucasa: debug

Logs above.

balloob commented 4 years ago

The report of 100% is because ZHA has not updated the state yet when we finish calling the service. That should however not impact how the cover operates.

It's weird that the first time it does not start closing, even if it looks like zigpy is responding to the voice request.

blair287 commented 4 years ago

The report of 100% is because ZHA has not updated the state yet when we finish calling the service. That should however not impact how the cover operates.

It's weird that the first time it does not start closing, even if it looks like zigpy is responding to the voice request.

The guys on the ZHA GitHub as basically saying it's not ZHA fault but I fail to see how it isn't given the fact the logs show it was asked to move to 0% and it reports back 100% how is that right it should be moving.

Ive lost all hope of this ever working or being fixed I've invested so much in HA now and I love it apart from these IKEA blinds they work brilliantly in smartthings but home assistant is super unreliable with them.

Occasionally this happens the blind moves a few cm then stops.

Screenshot_20200721-210631

HA and these blinds is making me pull my hair out.

blair287 commented 4 years ago

The report of 100% is because ZHA has not updated the state yet when we finish calling the service. That should however not impact how the cover operates.

It's weird that the first time it does not start closing, even if it looks like zigpy is responding to the voice request.

I have put a load of logs in this issue on the ZHA page with several different scenarios some worked some didn't anything useful in the logs?

https://github.com/zigpy/zha-device-handlers/issues/417

blair287 commented 4 years ago

Found more people with this issue some are using Alexa so the problem probably is with Nabu casa as this is the common factor.

blair287 commented 4 years ago

Here is a video of the issue.

https://streamable.com/7vhbgd

blair287 commented 4 years ago

Switched Nabu casa off and using duck DNS and manual Google assistant integration it is working.

Nabu casa on = having to ask twice

Duckdns = works first time

I'd like to support HA through Nabu Casa but this issue seems to be with Nabu casa have also found other people with this issue some using deconz some using Alexa but common item is Nabu casa.

So I'll be canceling my subscription until this is rectified.

blair287 commented 4 years ago

This issue is Nabu casa with duck DNS this issue isn't present at least so far.

Still a delay but working.

bramkragten commented 4 years ago

Duck DNS has nothing to do with this, it would be local Google Assistant vs Nabu Casa Google Assistant.

But all we do is forward requests, and they seem to arrive, so it seems unlikely this is a problem with Naba Casa.

Are you only experiencing this with Tradfri blinds? Is there some way for us to reproduce this (without Tradfri blinds)?

blair287 commented 4 years ago

Duck DNS has nothing to do with this, it would be local Google Assistant vs Nabu Casa Google Assistant.

But all we do is forward requests, and they seem to arrive, so it seems unlikely this is a problem with Naba Casa.

Are you only experiencing this with Tradfri blinds? Is there some way for us to reproduce this (without Tradfri blinds)?

However I have several more people with this issue and with alexa.

I have note had any issues with other devices maybe other items using the cover domain might be affected I only have one cover so cannot try it.

I know it's not duckdns but what ever the difference that duckdns does it compared to Nabu casa as I can replicate the issue every time and with Nabu casa turned off and the manual Google assistant it's working.

I'm new to HA apart from substitution I'm not sure what else I can do to see why this is occuring.

ludeeus commented 4 years ago

I'm unable to reproduce this issue with Home Assistant Version: 0.113.2 (Have not tried other versions)

I have my IKEA Fyrtur (blinds) connected to a ZigBee stick and using the zha integration. On my phone, I have the NC app/skill/thingy for Google Assistant.

Every command I tell it, it executes as expected, up/down/X%

blair287 commented 4 years ago

I'm unable to reproduce this issue with Home Assistant Version: 0.113.2 (Have not tried other versions)

I have my IKEA Fyrtur (blinds) connected to a ZigBee stick and using the zha integration. On my phone, I have the NC app/skill/thingy for Google Assistant.

Every command I tell it, it executes as expected, up/down/X%

I can reproduce it every time and also found other people who are experiencing the same thing.

Using duckdns no issues.

Do you have lag between issuing a command to the blinds and them actually moving like pressing up down or stop from HA UI.

I press down it will start moving after about 4 seconds then if I press stop it sometime takes 7 seconds to actually stop.

ludeeus commented 4 years ago

No, it's pretty much instant. There is maybe a few ms difference when using Google Assistant over the UI. But both are < 1s.

If you have any custom_components loaded, disable all of them and see if that helps

blair287 commented 4 years ago

No, it's pretty much instant. There is maybe a few ms difference when using Google Assistant over the UI. But both are < 1s.

If you have any custom_components loaded, disable all of them and see if that helps

Only custom component I'm using is Xbox and didn't make any difference.

ludeeus commented 4 years ago

What version of Home Assistant are you using? Since I set mine up I have tried it on 113.2, 113.3, and all the beta versions of 114 without any of the issues described in this issue.

HarvsG commented 2 years ago

If i issue the command again for a second time then it moves.

Using duckdns no issues.

Are devices other than blinds (such as bulbs) working without the issue? If not then it sounds like it could be an extension of #298.

gitmayer commented 2 years ago

If i issue the command again for a second time then it moves.

Using duckdns no issues.

Are devices other than blinds (such as bulbs) working without the issue? If not then it sounds like it could be an extension of #298.

It sounds like it is the same issue (large delay or having to ask twice when using Nabu Casa for Google or Alexa integration).

bemble commented 11 months ago

I closed your issue because of non-activity on it for a long time. If you still have the issue and think that's the right place to post it, please open an new issue.