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

Skyconnect Problem with Silicon Labs Multiprotocol #2869

Closed
ALutz273 opened this issue Feb 1, 2023 · 20 comments
Closed

Skyconnect Problem with Silicon Labs Multiprotocol #2869

ALutz273 opened this issue Feb 1, 2023 · 20 comments

Comments

@ALutz273
Copy link

ALutz273 commented Feb 1, 2023

Describe the issue you are experiencing

I got my Skyconnect adapter today and wanted to set it up.
Unfortunately there are problems with the Multiprtocol support.

Silicon Labs Multiprotocol 0.12.0


s6-rc: info: service mdns: starting
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service mdns successfully started
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/check-cpcd-shm.sh
[17:22:38] INFO: Starting mDNS Responder...
Default: mDNSResponder (Engineering Build) (Jan 23 2023 22:46:33) starting
Default: mDNS_AddDNSServer: Lock not held! mDNS_busy (0) mDNS_reentrancy (0)
cont-init: info: /etc/cont-init.d/check-cpcd-shm.sh exited 0
cont-init: info: running /etc/cont-init.d/config.sh
[17:22:38] INFO: Generating cpcd configuration.
cont-init: info: /etc/cont-init.d/config.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service banner: starting
-----------------------------------------------------------
 Add-on: Silicon Labs Multiprotocol
 Zigbee and OpenThread multiprotocol add-on
-----------------------------------------------------------
 Add-on version: 0.12.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 9.5  (amd64 / qemux86-64)
 Home Assistant Core: 2023.2.0b9
 Home Assistant Supervisor: 2023.01.1
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[17:22:39] INFO: Checking /dev/ttyUSB0 identifying SkyConnect v1.0 from Nabu Casa
[17:22:39] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0 (baudrate 115200)
2023-02-01 17:22:39 core-silabs-multiprotocol universal_silabs_flasher.flash[219] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version=<AwesomeVersion SemVer '4.1.4'>, ezsp_version=None, fw_type=<FirmwareImageType.RCP_UART_802154: 'rcp-uart-802154'>)
2023-02-01 17:22:39 core-silabs-multiprotocol universal_silabs_flasher.flasher[219] INFO Probing ApplicationType.GECKO_BOOTLOADER
2023-02-01 17:22:41 core-silabs-multiprotocol universal_silabs_flasher.flasher[219] INFO Probing ApplicationType.CPC
2023-02-01 17:22:45 core-silabs-multiprotocol universal_silabs_flasher.flasher[219] INFO Probing ApplicationType.EZSP
Error: Failed to probe running application type
2023-02-01 17:22:50 core-silabs-multiprotocol concurrent.futures[219] ERROR exception calling callback for <Future at 0x7f9e2fb1e9d0 state=finished returned NoneType>
Traceback (most recent call last):
  File "/usr/lib/python3.9/concurrent/futures/_base.py", line 329, in _invoke_callbacks
    callback(self)
  File "/usr/lib/python3.9/asyncio/futures.py", line 398, in _call_set_state
    dest_loop.call_soon_threadsafe(_set_state, destination, source)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe
    self._check_closed()
  File "/usr/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
s6-rc: warning: unable to start service universal-silabs-flasher: command exited 1
/run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information.
prog: fatal: stopping the container.
s6-rc: info: service mdns: stopping
s6-rc: info: service banner: stopping
Default: mDNSResponder (Engineering Build) (Jan 23 2023 22:46:33) stopping
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
[17:22:50] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped



What type of installation are you running?

Home Assistant OS

Which operating system are you running on?

Home Assistant Operating System

Which add-on are you reporting an issue with?

Silicon Labs Multiprotocol

What is the version of the add-on?

Silicon Labs Multiprotocol

Steps to reproduce the issue

  1. Flash via laptop to the System -> firmware from https://github.com/NabuCasa/silabs-firmware/blob/main/EmberZNetAndOpenThreadRCP/beta/NabuCasa_SkyConnect_EZSP_OpenThread_RCP_v4.1.3.0_ncp-uart-hw_230400.gbl
  2. Plugin in the System (VM)
  3. System -> Hardware-> Home Assistant SkyConnect -> start configuration

System Health information

Derzeit sind keine Reparaturen verfügbar

Currently no repairs are available

Anything in the Supervisor logs that might be useful for us?

No response

Anything in the add-on logs that might be useful for us?

No response

Additional information

No response

@regevbr
Copy link

regevbr commented Feb 1, 2023

Same issue - Just installed 2023.2.0, upgraded the firmware of my skyconnect from the hardware configuration page to multi-pan, and then started the addon and it keeps restarting. Here are my logs:

s6-rc: info: service mdns: starting
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service mdns successfully started
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/check-cpcd-shm.sh
[23:54:36] INFO: Starting mDNS Responder...
Default: mDNSResponder (Engineering Build) (Jan 23 2023 22:49:33) starting
Default: mDNS_AddDNSServer: Lock not held! mDNS_busy (0) mDNS_reentrancy (0)
cont-init: info: /etc/cont-init.d/check-cpcd-shm.sh exited 0
cont-init: info: running /etc/cont-init.d/config.sh
[23:54:38] INFO: Generating cpcd configuration.
cont-init: info: /etc/cont-init.d/config.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service banner: starting
-----------------------------------------------------------
 Add-on: Silicon Labs Multiprotocol
 Zigbee and OpenThread multiprotocol add-on
-----------------------------------------------------------
 Add-on version: 0.12.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 9.5  (aarch64 / raspberrypi4-64)
 Home Assistant Core: 2023.2.0
 Home Assistant Supervisor: 2023.01.1
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[23:54:41] INFO: Checking /dev/ttyUSB1 identifying SkyConnect v1.0 from Nabu Casa
[23:54:41] INFO: Starting universal-silabs-flasher with /dev/ttyUSB1 (baudrate 115200)
2023-02-01 23:54:43 core-silabs-multiprotocol universal_silabs_flasher.flash[219] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version=<AwesomeVersion SemVer '4.1.4'>, ezsp_version=None, fw_type=<FirmwareImageType.RCP_UART_802154: 'rcp-uart-802154'>)
2023-02-01 23:54:43 core-silabs-multiprotocol universal_silabs_flasher.flasher[219] INFO Probing ApplicationType.GECKO_BOOTLOADER
2023-02-01 23:54:45 core-silabs-multiprotocol universal_silabs_flasher.flasher[219] INFO Probing ApplicationType.CPC
2023-02-01 23:54:49 core-silabs-multiprotocol universal_silabs_flasher.flasher[219] INFO Probing ApplicationType.EZSP
Error: Failed to probe running application type
2023-02-01 23:54:55 core-silabs-multiprotocol concurrent.futures[219] ERROR exception calling callback for <Future at 0x7fb7ae59a0 state=finished returned NoneType>
Traceback (most recent call last):
  File "/usr/lib/python3.9/concurrent/futures/_base.py", line 329, in _invoke_callbacks
    callback(self)
  File "/usr/lib/python3.9/asyncio/futures.py", line 398, in _call_set_state
    dest_loop.call_soon_threadsafe(_set_state, destination, source)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe
    self._check_closed()
  File "/usr/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
s6-rc: warning: unable to start service universal-silabs-flasher: command exited 1
/run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information.
prog: fatal: stopping the container.
s6-rc: info: service mdns: stopping
s6-rc: info: service banner: stopping
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init: stopping
Default: mDNSResponder (Engineering Build) (Jan 23 2023 22:49:33) stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
[00:05:49] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped

@skgsergio
Copy link
Contributor

Context: NabuCasa/silabs-firmware#9

This is happening because the SkyConnect has firmware configured for a baudrate of 230400 and the addon is trying to flash the device connecting at a baudrate of 115200:

[17:22:39] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0 (baudrate 115200)

I don't own a SkyConnect but I'm guessing that either the addon flashed a 230400 baudrate firmware in the past or users having issues flashed a 230400 baudrate firmware manually. By the git history, I guess it was the later.

For @regevbr just flash manually the SkyConnect again like this:

universal-silabs-flasher --device /dev/ttyUSB1 --baudrate 230400 flash --firmware NabuCasa_SkyConnect_RCP_v4.1.4_rcp-uart-hw-802154_115200.gbl

You can grab the firmware file from here: https://github.com/home-assistant/addons/tree/master/silabs-multiprotocol/rootfs/root

@regevbr
Copy link

regevbr commented Feb 2, 2023

Thanks

For me restarting my pi and then the addon one more time fixed it

@Moqume
Copy link

Moqume commented Feb 4, 2023

I've found it to be the Automatically flash firmware option. If it is enabled, I get the same error:

s6-rc: info: service mdns: starting
s6-rc: info: service s6rc-oneshot-runner: starting
s6-rc: info: service mdns successfully started
s6-rc: info: service s6rc-oneshot-runner successfully started
s6-rc: info: service fix-attrs: starting
s6-rc: info: service fix-attrs successfully started
s6-rc: info: service legacy-cont-init: starting
cont-init: info: running /etc/cont-init.d/check-cpcd-shm.sh
[21:18:01] INFO: Starting mDNS Responder...
Default: mDNSResponder (Engineering Build) (Jan 23 2023 22:46:33) starting
Default: mDNS_AddDNSServer: Lock not held! mDNS_busy (0) mDNS_reentrancy (0)
cont-init: info: /etc/cont-init.d/check-cpcd-shm.sh exited 0
cont-init: info: running /etc/cont-init.d/config.sh
[21:18:03] INFO: Generating cpcd configuration.
cont-init: info: /etc/cont-init.d/config.sh exited 0
s6-rc: info: service legacy-cont-init successfully started
s6-rc: info: service banner: starting
-----------------------------------------------------------
 Add-on: Silicon Labs Multiprotocol
 Zigbee and OpenThread multiprotocol add-on
-----------------------------------------------------------
 Add-on version: 0.12.0
 You are running the latest version of this add-on.
 System: Home Assistant OS 9.5  (amd64 / generic-x86-64)
 Home Assistant Core: 2023.2.1
 Home Assistant Supervisor: 2023.01.1
-----------------------------------------------------------
 Please, share the above information when looking for help
 or support in, e.g., GitHub, forums or the Discord chat.
-----------------------------------------------------------
s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[21:18:05] INFO: Checking /dev/ttyUSB0 identifying SkyConnect v1.0 from Nabu Casa
[21:18:05] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0 (baudrate 230400)
2023-02-04 21:18:07 core-silabs-multiprotocol universal_silabs_flasher.flash[217] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version=<AwesomeVersion SemVer '4.1.4'>, ezsp_version=None, fw_type=<FirmwareImageType.RCP_UART_802154: 'rcp-uart-802154'>)
2023-02-04 21:18:07 core-silabs-multiprotocol universal_silabs_flasher.flasher[217] INFO Probing ApplicationType.GECKO_BOOTLOADER
2023-02-04 21:18:09 core-silabs-multiprotocol universal_silabs_flasher.flasher[217] INFO Probing ApplicationType.CPC
2023-02-04 21:18:13 core-silabs-multiprotocol universal_silabs_flasher.flasher[217] INFO Probing ApplicationType.EZSP
Error: Failed to probe running application type
2023-02-04 21:18:18 core-silabs-multiprotocol concurrent.futures[217] ERROR exception calling callback for <Future at 0x7fd7ab246910 state=finished returned NoneType>
Traceback (most recent call last):
  File "/usr/lib/python3.9/concurrent/futures/_base.py", line 329, in _invoke_callbacks
    callback(self)
  File "/usr/lib/python3.9/asyncio/futures.py", line 398, in _call_set_state
    dest_loop.call_soon_threadsafe(_set_state, destination, source)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 791, in call_soon_threadsafe
    self._check_closed()
  File "/usr/lib/python3.9/asyncio/base_events.py", line 510, in _check_closed
    raise RuntimeError('Event loop is closed')
RuntimeError: Event loop is closed
s6-rc: warning: unable to start service universal-silabs-flasher: command exited 1
/run/s6/basedir/scripts/rc.init: warning: s6-rc failed to properly bring all the services up! Check your logs (in /run/uncaught-logs/current if you have in-container logging) for more information.
prog: fatal: stopping the container.
s6-rc: info: service mdns: stopping
s6-rc: info: service banner: stopping
Default: mDNSResponder (Engineering Build) (Jan 23 2023 22:46:33) stopping
s6-rc: info: service banner successfully stopped
s6-rc: info: service legacy-cont-init: stopping
s6-rc: info: service legacy-cont-init successfully stopped
s6-rc: info: service fix-attrs: stopping
s6-rc: info: service fix-attrs successfully stopped
s6-rc: info: service s6rc-oneshot-runner: stopping
s6-rc: info: service s6rc-oneshot-runner successfully stopped
[21:18:19] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped

When it is disabled, it starts, except it loops with Failed to connect to Secondary... filling up the log:

s6-rc: info: service banner successfully started
s6-rc: info: service universal-silabs-flasher: starting
[21:24:58] INFO: Flashing firmware is disabled
s6-rc: info: service universal-silabs-flasher successfully started
s6-rc: info: service cpcd: starting
[21:24:58] INFO: Starting cpcd...
[21:24:58:910] Info : [CPCd v4.1.4.0] [Library API v2] [RCP Protocol v2]
[21:24:58:910] Info : Git commit: 5df3ef9fb8891987b623b623694ec4c435ea5644 / branch: 
[21:24:58:910] Info : Sources hash: 2606b603ff85938a832e691804f2d1fcf86745370d236a1a9c47f03bdf95898e
[21:24:58:910] Info : Reading cli arguments
[21:24:58:910] Info : /usr/local/bin/cpcd 
[21:24:58:929] Info : Reading configuration
[21:24:58:929] Info : file_path = /usr/local/etc/cpcd.conf
[21:24:58:929] Info : instance_name = cpcd_0
[21:24:58:929] Info : socket_folder = /dev/shm
[21:24:58:929] Info : operation_mode = MODE_NORMAL
[21:24:58:929] Info : use_encryption = false
[21:24:58:929] Info : binding_key_file = /etc/binding-key.key
[21:24:58:929] Info : binding_method = 
[21:24:58:929] Info : stdout_tracing = false
[21:24:58:929] Info : file_tracing = false
[21:24:58:929] Info : lttng_tracing = false
[21:24:58:929] Info : enable_frame_trace = false
[21:24:58:929] Info : traces_folder = /dev/shm/cpcd-traces
[21:24:58:929] Info : bus = UART
[21:24:58:929] Info : uart_baudrate = 230400
[21:24:58:929] Info : uart_hardflow = true
[21:24:58:929] Info : uart_file = /dev/ttyUSB0
[21:24:58:929] Info : spi_file = /dev/spidev0.0
[21:24:58:929] Info : spi_bitrate = 1000000
[21:24:58:929] Info : spi_mode = SPI_MODE_0
[21:24:58:929] Info : spi_bit_per_word = 8
[21:24:58:929] Info : spi_cs_chip = gpiochip0
[21:24:58:929] Info : spi_cs_pin = 8
[21:24:58:930] Info : spi_irq_chip = gpiochip0
[21:24:58:930] Info : spi_irq_pin = 22
[21:24:58:930] Info : fu_reset_chip = gpiochip0
[21:24:58:930] Info : fu_spi_reset_pin = 23
[21:24:58:930] Info : fu_wake_chip = gpiochip0
[21:24:58:930] Info : fu_spi_wake_pin = 24
[21:24:58:930] Info : fu_recovery_enabled = false
[21:24:58:930] Info : fu_connect_to_bootloader = false
[21:24:58:930] Info : fu_enter_bootloader = false
[21:24:58:930] Info : fu_file = 
[21:24:58:930] Info : fu_restart_daemon = false
[21:24:58:930] Info : board_controller_ip_addr = 
[21:24:58:930] Info : application_version_validation = false
[21:24:58:930] Info : print_secondary_versions_and_exit = false
[21:24:58:930] Info : use_noop_keep_alive = false
[21:24:58:930] Info : reset_sequence = true
[21:24:58:930] Info : uart_validation_test_option = 
[21:24:58:930] Info : stats_interval = 0
[21:24:58:930] Info : rlimit_nofile = 2000
[21:24:58:930] Info : ENCRYPTION IS DISABLED 
[21:24:58:930] Info : Starting daemon in normal mode
[21:24:58:952] Info : Connecting to Secondary...
[21:25:00:952] Info : Failed to connect to Secondary.
[21:25:00:952] Info : Connecting to Secondary...
... etc ....

@ALutz273
Copy link
Author

ALutz273 commented Feb 5, 2023

The problem looks exactly the same for me.
With 230400 or with 115200
run1.txt
run2.txt

@DiaboloVampire
Copy link

I have exactly the same issues as you described. Hopefully they fix it soon. Don’t want to flash firmware manually.

@miniminne
Copy link

Hey, I'm having the same issues as listed here but even when I try to manually flash I'm hit with "Error: failed to probe application type". Any advice? This fails when trying to probe ApplicationType.EZSP

@Moqume
Copy link

Moqume commented Feb 6, 2023

To note, I resolved the Failed to connect to Secondary. loop (after disabling the Automatically flash firmware option) the following way (whilst the Silicon Labs Multiprotocol add-on was running):

  1. Disconnect the Skyconnect from the USB
  2. Delete the Zigbee Home Automation device.
  3. Plug the Skyconnect back in (while the Silicon Labs Multiprotocol add-on was already running).

HA will discover a new device at this point, SkyConnect Multi-PAN (also Zigbee Home Automation, but didn't show it as Multi-PAN AFAICR). It already had the right details pre-set (The USB ID, EZSP, etc), so didn't have to change anything setting up the device.

Then the add-on stopped looping at Failed to connect to Secondary.:

[20:35:45:219] Info : Connecting to Secondary...
[20:35:45:303] Info : Connected to Secondary
[20:35:45:309] Info : Secondary Protocol v2
[20:35:45:322] Info : Secondary CPC v4.1.4
[20:35:45:328] Info : Secondary APP vUNDEFINED
[20:35:45:329] Info : Daemon startup was successful. Waiting for client connections
[20:35:46] INFO: Setup OTBR firewall...
[20:35:46] INFO: Starting otbr-agent...
otbr-agent[268]: [NOTE]-AGENT---: Running 0.3.0
otbr-agent[268]: [NOTE]-AGENT---: Thread version: 1.3.0
otbr-agent[268]: [NOTE]-AGENT---: Thread interface: wpan0
otbr-agent[268]: [NOTE]-AGENT---: Backbone interface: enp1s0
otbr-agent[268]: [NOTE]-AGENT---: Radio URL: spinel+cpc:https://cpcd_0?iid=2
otbr-agent[268]: [INFO]-NCP-----: OpenThread log level changed to 4
otbr-agent[268]: 51d.15:04:10.331 [C] Platform------: mCpcBusSpeed = 115200
otbr-agent[268]: 51d.15:04:10.331 [I] Platform------: RCP reset: RESET_SOFTWARE
[20:35:46:605] Info : Client is using library v2
[20:35:46:612] Info : Opened connection socket for ep#12
[20:35:46:612] Info : Endpoint socket #12: Client connected. 1 connections
[20:35:47:174] Info : Client is using library v2
[20:35:47:184] Info : Endpoint socket #12: Client connected. 2 connections
otbr-agent[268]: 51d.15:04:12.405 [I] Platform------: RCP reset: RESET_UNKNOWN
otbr-agent[268]: 51d.15:04:12.457 [N] Platform------: RCP API Version: 6
otbr-agent[268]: 51d.15:04:12.469 [I] Platform------: Backbone interface is configured to enp1s0 (2)
...etc...

YMMV.

@mlacayoemery
Copy link

mlacayoemery commented Feb 6, 2023

Context: NabuCasa/silabs-firmware#9

This is happening because the SkyConnect has firmware configured for a baudrate of 230400 and the addon is trying to flash the device connecting at a baudrate of 115200:

[17:22:39] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0 (baudrate 115200)

I don't own a SkyConnect but I'm guessing that either the addon flashed a 230400 baudrate firmware in the past or users having issues flashed a 230400 baudrate firmware manually. By the git history, I guess it was the later.

For @regevbr just flash manually the SkyConnect again like this:

universal-silabs-flasher --device /dev/ttyUSB1 --baudrate 230400 flash --firmware NabuCasa_SkyConnect_RCP_v4.1.4_rcp-uart-hw-802154_115200.gbl

You can grab the firmware file from here: https://github.com/home-assistant/addons/tree/master/silabs-multiprotocol/rootfs/root

Thanks to @skgsergio this sent me down the right path. I followed the instructions in the wiki and was able to flash version 4.2.0 after connecting it to my computer and this problem was resolved. I was not able to flash directly from Home Assistant OS.

Now I have issue #2872

@StefanDorschu
Copy link

StefanDorschu commented Feb 10, 2023

I'm trying to flash from my Mac, but even that does not work.

silabs-firmware % universal-silabs-flasher -vvv --device /dev/tty.usbserial-210 --baudrate 230400 --bootloader-baudrate 115200 flash --allow-cross-flashing --firmware EmberZNet/beta/NabuCasa_SkyConnect_EZSP_v7.2.1.0_ncp-uart-hw_115200.gbl 2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box asyncio[31064] DEBUG Using selector: KqueueSelector 2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flash[31064] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version=<AwesomeVersion SemVer '4.2.1'>, ezsp_version=<AwesomeVersion SimpleVer '7.2.1.0'>, fw_type=<FirmwareImageType.NCP_UART_HW: 'ncp-uart-hw'>) 2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flasher[31064] INFO Probing ApplicationType.GECKO_BOOTLOADER 2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Connection made: SerialTransport(<_UnixSelectorEventLoop running=True closed=False debug=False>, <universal_silabs_flasher.gecko_bootloader.GeckoBootloaderProtocol object at 0x1047fbbe0>, Serial<id=0x1047fb460, open=True>(port='/dev/tty.usbserial-210', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False)) 2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'3' 2023-02-10 14:13:42 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flasher[31064] INFO Probing ApplicationType.CPC 2023-02-10 14:13:43 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Connection made: SerialTransport(<_UnixSelectorEventLoop running=True closed=False debug=False>, <universal_silabs_flasher.cpc.CPCProtocol object at 0x1047fbcd0>, Serial<id=0x1047fbca0, open=True>(port='/dev/tty.usbserial-210', baudrate=230400, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False)) 2023-02-10 14:13:43 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))) 2023-02-10 14:13:43 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12' 2023-02-10 14:13:44 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 1 of 4) 2023-02-10 14:13:44 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))) 2023-02-10 14:13:44 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12' 2023-02-10 14:13:45 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 2 of 4) 2023-02-10 14:13:45 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))) 2023-02-10 14:13:45 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12' 2023-02-10 14:13:46 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 3 of 4) 2023-02-10 14:13:46 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))) 2023-02-10 14:13:46 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12' 2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 4 of 4) 2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flasher[31064] INFO Probing ApplicationType.EZSP 2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box bellows.ezsp[31064] DEBUG Resetting EZSP 2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Resetting ASH 2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Sending: b'1ac038bc7e' 2023-02-10 14:13:52 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Connection lost: None 2023-02-10 14:13:52 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Closed serial connection Error: Failed to probe running application type

@miniminne
Copy link

I'm trying to flash from my Mac, but even that does not work.

`silabs-firmware % universal-silabs-flasher -vvv --device /dev/tty.usbserial-210 --baudrate 230400 --bootloader-baudrate 115200 flash --allow-cross-flashing --firmware EmberZNet/beta/NabuCasa_SkyConnect_EZSP_v7.2.1.0_ncp-uart-hw_115200.gbl

2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box asyncio[31064] DEBUG Using selector: KqueueSelector

2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flash[31064] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version=<AwesomeVersion SemVer '4.2.1'>, ezsp_version=<AwesomeVersion SimpleVer '7.2.1.0'>, fw_type=<FirmwareImageType.NCP_UART_HW: 'ncp-uart-hw'>)

2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flasher[31064] INFO Probing ApplicationType.GECKO_BOOTLOADER

2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Connection made: SerialTransport(<_UnixSelectorEventLoop running=True closed=False debug=False>, <universal_silabs_flasher.gecko_bootloader.GeckoBootloaderProtocol object at 0x1047fbbe0>, Serial<id=0x1047fb460, open=True>(port='/dev/tty.usbserial-210', baudrate=115200, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))

2023-02-10 14:13:40 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'3'

2023-02-10 14:13:42 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flasher[31064] INFO Probing ApplicationType.CPC

2023-02-10 14:13:43 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Connection made: SerialTransport(<_UnixSelectorEventLoop running=True closed=False debug=False>, <universal_silabs_flasher.cpc.CPCProtocol object at 0x1047fbcd0>, Serial<id=0x1047fbca0, open=True>(port='/dev/tty.usbserial-210', baudrate=230400, bytesize=8, parity='N', stopbits=1, timeout=0, xonxoff=False, rtscts=False, dsrdtr=False))

2023-02-10 14:13:43 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b'')))

2023-02-10 14:13:43 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12'

2023-02-10 14:13:44 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 1 of 4)

2023-02-10 14:13:44 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b'')))

2023-02-10 14:13:44 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12'

2023-02-10 14:13:45 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 2 of 4)

2023-02-10 14:13:45 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b'')))

2023-02-10 14:13:45 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12'

2023-02-10 14:13:46 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 3 of 4)

2023-02-10 14:13:46 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Sending frame CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b'')))

2023-02-10 14:13:46 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.common[31064] DEBUG Sending data b'\x14\x00\n\x00\xc4U\xd3\x02\x00\x04\x00\x03\x00\x00\x00\xdb\x12'

2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.cpc[31064] DEBUG Failed to send CPCTransportFrame(endpoint=<EndpointId.SYSTEM: 0>, control=196, payload=UnnumberedFrame(command_id=<UnnumberedFrameCommandId.PROP_VALUE_GET: 2>, command_seq=0, payload=PropertyCommand(property_id=<PropertyId.SECONDARY_CPC_VERSION: 3>, value=b''))), trying again in 0.10s (attempt 4 of 4)

2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box universal_silabs_flasher.flasher[31064] INFO Probing ApplicationType.EZSP

2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box bellows.ezsp[31064] DEBUG Resetting EZSP

2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Resetting ASH

2023-02-10 14:13:47 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Sending: b'1ac038bc7e'

2023-02-10 14:13:52 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Connection lost: None

2023-02-10 14:13:52 MacBook-Pro-Stefan.fritz.box bellows.uart[31064] DEBUG Closed serial connection

Error: Failed to probe running application type

`

I had this issue too, but I fixed it by unplugging/plugging it back in after a reboot of HA

@StefanDorschu
Copy link

In the meanwhile i found my solution. I did not have the correct driver installed.
But although i flashed a zigbee only firmware the device is shown in HA as a multi protocol.

@b-reich
Copy link

b-reich commented Feb 15, 2023

Have an simmular issue. After rebooting my raspberry pi. Restarting the addon fix this.

otbr-agent[298]: 49d.17:03:54.459 [N] Platform------: RCP API Version: 6
otbr-agent[298]: 00:00:00.133 [N] BorderRouter--: BR ULA prefix: fd48:7b98:73cb::/48 (loaded)
otbr-agent[298]: 00:00:00.133 [N] BorderRouter--: Local on-link prefix: fdde:ad00:beef:cafe::/64
otbr-agent[298]: 00:00:00.136 [N] BorderRouter--: Local on-link prefix: fdde:ad00:beef:cafe::/64
s6-rc: info: service otbr-agent successfully started
s6-rc: info: service otbr-agent-rest-discovery: starting
[13:18:32] INFO: Successfully sent discovery information to Home Assistant.
s6-rc: info: service otbr-agent-rest-discovery successfully started
s6-rc: info: service legacy-services: starting
s6-rc: info: service legacy-services successfully started
Listening on port 9999 for connection...

Accepting connection.

Accepted connection 7.

Restarting
[13:19:02:298139] Info : Endpoint socket #12: Client disconnected. 1 connections
[13:19:02:298295] Info : Client disconnected
[13:19:03:303389] Info : New client connection using library v4.2.1.0
[13:19:03:311627] Info : Endpoint socket #12: Client connected. 2 connections
Reusing socket from previous instance.

Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::cce0:79ff:fee1:9f18/vethc8e0980/24
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::cce0:79ff:fee1:9f18/vethc8e0980/24
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::cce0:79ff:fee1:9f18/vethc8e0980/24
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::fca9:3aff:fe3f:1650/veth0ac53ef/26
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::fca9:3aff:fe3f:1650/veth0ac53ef/26
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::fca9:3aff:fe3f:1650/veth0ac53ef/26
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::b857:47ff:feb9:7764/veth68661bd/28
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::b857:47ff:feb9:7764/veth68661bd/28
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::b857:47ff:feb9:7764/veth68661bd/28
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::b857:47ff:feb9:7764/veth68661bd/28
Default: mDNSPlatformSendUDP got error 99 (Cannot assign requested address) sending packet to ff02::fb on interface fe80::b857:47ff:feb9:7764/veth68661bd/28

@slider162
Copy link

slider162 commented Mar 7, 2023

2023-03-07 10:39:22 core-silabs-multiprotocol universal_silabs_flasher.flasher[236] INFO Probing ApplicationType.EZSP
Error: Failed to probe running application type

I get the same error at either baud rate. Same error in HA or manually flashing.

Edit: I can reproduce this after a failed attempt to migrate radio.

  • Silicon Labs Multiprotocol starts and Skyconnect is automatically configured as Open Thread Border Router.
  • SONOFF Zigbee 3.0 USB Dongle Plus V2 > Migrate Radio
  • Migration fails
  • Reboot HA
  • Silicon Labs Multiprotocol fails to start with errors "Error: Failed to probe running application type".
  • Unplug Skyconnect USB. (Bus 1 Device 11)
  • Plug Skyconnect back in. (Bus 1 Device 12)
  • Reboot HA
  • Everything is back to normal and running.

@agners
Copy link
Member

agners commented Mar 29, 2023

The universal-silabs-flasher got updated recently.

@ALutz273 (or someone else) is this still a problem for you?

@Mrsash2020
Copy link

Mrsash2020 commented Apr 1, 2023

Yup not working for me currently

Cant believe removing it and plugging it back in fixes this issues, go figure.

@github-actions
Copy link

github-actions bot commented May 4, 2023

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@EddieDSuza
Copy link

Adding some context here - please check the logs and confirm which baudrate its reporting. Update the configuration with that value and restart. Thats how I was able to add both protocols to my HA instance

@agners
Copy link
Member

agners commented May 16, 2023

If automatic firmware updating is enabled (by default), with the recent versions of this add-on the baudrate configuration is always taken from the firmware metadata (since we know the firmware communicates at this baud rate). The user configuration is not really doing anything in that case. It doesn't hurt to update the baudrate, but it also doesn't change anything really.

So if changing the baudrate helped, then it is because you had to restart the add-on due to that.

@github-actions
Copy link

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@github-actions github-actions bot added the stale label Jun 15, 2023
@github-actions github-actions bot closed this as not planned Won't fix, can't repro, duplicate, stale Jun 22, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests