Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

'Unable to find service zha_toolkit.execute' #89

Closed
gsemet opened this issue Sep 26, 2022 · 19 comments
Closed

'Unable to find service zha_toolkit.execute' #89

gsemet opened this issue Sep 26, 2022 · 19 comments
Labels
Needs more info Further information is requested

Comments

@gsemet
Copy link

gsemet commented Sep 26, 2022

I have not idea with this happens, but the ZHA_TOOLKIT integration kind of "disappear" from time to time, maybe after a soft reload.
When I do a complete server reboot, the service is working, but after a HASC package install, or some automation reload, the service disapear, and I see the following message in the logs:

Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
@mdeweerd
Copy link
Owner

Look for other hints in the log.

Key information I find in my home-assistant.log:

2022-09-21 21:16:17.154 WARNING (SyncWorker_1) [homeassistant.loader] We found a custom integration zha_toolkit which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

which shows that the integration is loaded.

You can enable debug level logging which might help confirm that the other setup action are (not) done.

At this point I do not know what is happening.

@mdeweerd mdeweerd added the Needs more info Further information is requested label Sep 28, 2022
@mdeweerd
Copy link
Owner

@Nothinx44 Did you add the following to your configuration file?

zha_toolkit:

In the log, can you see that the custom_component is loaded?

@Nothinx44
Copy link

@Nothinx44 Did you add the following to your configuration file?

zha_toolkit:

In the log, can you see that the custom_component is loaded?

Indeed i miss that line , its work perfectly now ! Thx !

@gsemet
Copy link
Author

gsemet commented Oct 11, 2022

Did not worked until 4am this morning for a few days, were I updated to the cutting edge core 2022.10.3

@mdeweerd
Copy link
Owner

@gsemet Quite strange, I guess we'll not learn what it was about, I suggest you close this issue .

@gsemet
Copy link
Author

gsemet commented Oct 12, 2022

Happened today after a reboot:

2022-10-12 17:16:09.164 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration zha_toolkit which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant
2022-10-12 17:18:44.405 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xA9DB:1:0x0006]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.NWK_ROUTE_DISCOVERY_FAILED: 208>'), DeliveryError('Failed to deliver packet: <TXStatus.NWK_ROUTE_DISCOVERY_FAILED: 208>'), DeliveryError('Failed to deliver packet: <TXStatus.NWK_ROUTE_DISCOVERY_FAILED: 208>'), DeliveryError('Failed to deliver packet: <TXStatus.NWK_ROUTE_DISCOVERY_FAILED: 208>')]
2022-10-12 17:19:11.127 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xDA9B:1:0x0001]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:19:17.543 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xDA9B:1:0x0402]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:19:18.195 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0xDA9B:1:0x0405]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:24:00.022 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:25:27.454 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x13A7:1:0x0405]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:27:00.015 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:30:00.249 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:32:00.210 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x9B11:1:0x0402]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:32:00.319 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x9B11:2:0x0405]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:32:00.509 WARNING (MainThread) [homeassistant.components.zha.core.channels.base] [0x9B11:1:0x0001]: async_initialize: all attempts have failed: [DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>'), DeliveryError('Failed to deliver packet: <TXStatus.APS_NO_ACK: 167>')]
2022-10-12 17:33:00.029 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:36:00.035 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:39:00.039 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:42:00.045 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:45:00.020 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:48:00.068 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:51:00.028 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:54:00.061 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 17:57:00.024 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:00:00.103 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:03:00.033 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:06:00.048 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:09:00.044 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:12:00.043 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:15:00.056 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:18:00.040 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:21:00.024 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute
2022-10-12 18:24:00.022 ERROR (MainThread) [homeassistant.components.automation.read_zlinky_tic_every_minute] Read ZLinky_TIC every minute: Error executing script. Service not found for call_service at pos 1: Unable to find service zha_toolkit.execute

I may have not the logs, despite the following snippet in a packages/zigbee.yaml

# https://github.com/fairecasoimeme/Zlinky_TIC/issues/71
# Enable ZHA-toolkit for forced zlinky cluster refresh
zha_toolkit:

logger:
  logs:
    custom_components.zha_toolkit: debug

@mdeweerd
Copy link
Owner

You do not have the zha-toolkit's debug log apparently.

The configuration somehow needs to be included or inserted in your configuration.yaml.

So:

logger:
  logs:
    custom_components.zha_toolkit: debug

is something that you add directly to your configuration.yaml. Or you add this to configuration.yaml:

logger: !include logger.yaml

And create a logger.yaml in the same directory:

logs:
  custom_components.zha_toolkit: debug

This is what I get for zha-toolkit in my log. You should at least see "Setup services from async_setup" and then plenty of "Add service" notification with the first being the execute service:

2022-10-11 21:51:51.253 DEBUG (MainThread) [custom_components.zha_toolkit] DEFAULT_OTAU = /config/zb_ota
2022-10-11 21:51:51.253 DEBUG (MainThread) [custom_components.zha_toolkit] Setup services from async_setup
2022-10-11 21:51:51.255 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.execute

I also think that you are polling your ZLinky while you can avoid that if the attribute support reporting:

service: zha_toolkit.conf_report
data:
      ieee: sensor.LinkyEntity
      cluster: 1794
      attribute: 0
      min_interval: 60
      max_interval: 600
      reportable_change: 1
      event_done: zha_done
      tries: 3

That would make the linky report attribute 0 of the cluster by itself when it changed in the previous 60 seconds or on its first change after 60 seconds and at least every 10 minutes.

You can configure that once and forget about it, or add it to some script to remind you of all the special initialisations that you did so that you can easily redo them when you have to repair a device for some reason.

@oudoulj
Copy link

oudoulj commented Nov 11, 2022

I'm a little lost although I read the installation process a couple times on https://github.com/mdeweerd/zha-toolkit#using-zha-toolkit and cannot find the zha_toolkit.execute service on https://mysite.duckdns.org:8123/developer-tools/service 😢

My configuration.yaml contains

zha:
  zigpy_config:
    ota:
      otau_directory: /config/zigpy_ota
      ikea_provider: true # Auto update Trådfri devices

logger:
  default: warning
  logs:
    # https://www.home-assistant.io/integrations/zha/#debug-logging
    homeassistant.core: debug
    homeassistant.components.zha: debug
    bellows.zigbee.application: debug
    bellows.ezsp: debug
    zigpy: debug
    zigpy_deconz.zigbee.application: debug
    zigpy_deconz.api: debug
    zigpy_xbee.zigbee.application: debug
    zigpy_xbee.api: debug
    zigpy_zigate: debug
    zigpy_znp: debug
    zhaquirks: debug
    # https://github.com/mdeweerd/zha-toolkit#setup
    custom_components.zha_toolkit: debug

And I have restarted HA a few times.
Running Hassio on RPi4 with

Home Assistant 2022.11.2
Supervisor 2022.10.2
Operating System 9.3
Frontend 20221108.0 - latest

image

On the /config/logs page I have this line (like reported above)
2022-11-11 19:31:39.693 WARNING (SyncWorker_0) [homeassistant.loader] We found a custom integration zha_toolkit which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant

@mdeweerd
Copy link
Owner

@oudoulj - you need to do the following (from the README.md).
image

@oudoulj
Copy link

oudoulj commented Nov 13, 2022

@oudoulj - you need to do the following (from the README.md). image

The thing is I do have this line in my configuration.yaml (and have restarted HA) which is why I'm confused :|
And I'm not sure what to look up in the logs to help me identify the error...

@mdeweerd
Copy link
Owner

OK, so you have "[homeassistant.loader] We found a custom integration zha_toolkit which has not been tested by Home Assistant. This component might cause stability problems, be sure to disable it if you experience issues with Home Assistant" which indicates the toolkit is loaded.

You also have

logger:
  logs:
    custom_components.zha_toolkit: debug

so you should see lines containing custom_components.zha_toolkit like this as well:

2022-11-08 23:05:17.893 DEBUG (MainThread) [custom_components.zha_toolkit] Setup services from async_setup
2022-11-08 23:05:17.896 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.execute
2022-11-08 23:05:17.898 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.add_group
2022-11-08 23:05:17.907 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.add_to_group
2022-11-08 23:05:17.908 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.all_routes_and_neighbours
2022-11-08 23:05:17.917 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.attr_read
2022-11-08 23:05:17.920 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.attr_write
2022-11-08 23:05:17.921 DEBUG (MainThread) [custom_components.zha_toolkit] Add service zha_toolkit.backup

And apparently you have no error messages?!

You could try

service: zha_toolkit.all_routes_and_neighbours

and check if there are errors/if anything shows up in the config/scans director after a while.

@oudoulj
Copy link

oudoulj commented Nov 14, 2022

The only thing popping when searching the logs for zha_toolkit is :

image

And there is nothing starting with zha on the Service page...

image

What is this config/scans directory you're talking about ? (it's a blank page if I try to directly paste the url) 🤔

@mdeweerd
Copy link
Owner

  • config/scans - inside the folder where configuration.yaml is located, a "scans" directory is created to write the result of the scan of a device once it's completed. Using a device scan is a way to avoid catching events.
  • IMHO, according to the logs, zha_toolkit is loaded so I am fairly surprised that the services do not show up.

@oudoulj
Copy link

oudoulj commented Nov 20, 2022

  • config/scans

I cannot find a config/scans folder 🤔
Here is my tree view :

Screenshot - 20_11_2022 , 15_14_42

The only mention of config/scans I was able to find was in custom_components/zha_toolkit/services.yaml

all_routes_and_neigbours:
  description: Scan for all routes and neighbours, results saved to config/scans/...

@mdeweerd
Copy link
Owner

service: zha_toolkit.register_services

Is a method to reregister all the services.

I just used it while developing "ha_set_state" - the service did not appear before calling this so that could be a test for you.

@oudoulj
Copy link

oudoulj commented Nov 21, 2022

I have just upgraded to 0.8.25 and restarted but still no dice.
I must be missing something obvious 😐

zha

mdeweerd added a commit that referenced this issue Nov 22, 2022
Add message about missing zha for #89
@mdeweerd
Copy link
Owner

@oudoulj
Apparently you have [custom_components.zha_toolkit] DEFAULT_OTAU = /config/zb_ota in your logs but not [custom_components.zha_toolkit] Setup services from async_setup which suggests that "hass.data['zha']['zha_gateway'] does not have the expected value.

I released v0.8.26 to add a debug message in case hass.data['zha']['zha_gateway'] is not provided. In that case you'll see something starting with "hass.data['zha']['zha_gateway'] in your log and I suggest you share which message it is.

The custom component expects that value to be present and set.
In case it is not set, maybe the gateway is ready well after loading the zha-toolkit or there is some other issue.

What is your zha setup/zigbee coordinator setup?

Apparently you are using deconz - I do not think that is zha based. And zha-toolkit is only for zha.

@oudoulj
Copy link

oudoulj commented Nov 22, 2022

I have a Conbee II stick with 2 integrations installed : ZHA and Phoscon.
But I think I should NOT have both running at the same time 😐

I have disabled the ZHA integration eventually to avoid conflicts (plus I always had this "Failed to setup / Check logs" warning in its tile)

Therefore I don't think zha-toolkit is for me, sorry for the disturbance and thanks for your help anyway 😊

Screenshot - 22_11_2022 , 23_57_52

Screenshot - 22_11_2022 , 23_57_33

Screenshot - 23_11_2022 , 00_09_57

Screenshot - 22_11_2022 , 23_59_24

@mdeweerd
Copy link
Owner

@oudoulj Thank you for your feedback - this is what I thought.

You can't have two integrations managing the same stick. You have deconz managing it, so zha could not have control over it.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Needs more info Further information is requested
Projects
None yet
Development

No branches or pull requests

4 participants