NabuCasa / silabs-firmware

Silicon Labs firmware for Yellow and SkyConnect
106 stars 2 forks source link

Multiprotocol activation error (Failed to parse buffer / Failed to probe application) #28

Closed matebenyovszky closed 8 months ago

matebenyovszky commented 8 months ago

Hi All, Zigbee was working fine, but I got this while tried to enable multiprotocol support:

[15:52:29] INFO: The otbr-web is disabled.
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
[15:52:29] INFO: Starting mDNS Responder...
Default: mDNSResponder (Engineering Build) (Aug 23 2023 18:27:14) starting
cont-init: info: /etc/cont-init.d/check-cpcd-shm.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: 2.3.2
 You are running the latest version of this add-on.
 System: Home Assistant OS 11.2  (amd64 / qemux86-64)
 Home Assistant Core: 2023.12.3
 Home Assistant Supervisor: 2023.12.0
-----------------------------------------------------------
 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
[15:52:30] INFO: Checking /dev/ttyUSB0 identifying SkyConnect v1.0 from Nabu Casa.
[15:52:30] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0
2024-01-01 15:52:30 homeassistant universal_silabs_flasher.flash[182] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version='4.3.1', ezsp_version=None, ot_rcp_version=None, fw_type=<FirmwareImageType.RCP_UART_802154: 'rcp-uart-802154'>, baudrate=460800)
2024-01-01 15:52:30 homeassistant universal_silabs_flasher.flasher[182] INFO Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
2024-01-01 15:52:32 homeassistant universal_silabs_flasher.flasher[182] INFO Probing ApplicationType.CPC at 460800 baud
2024-01-01 15:52:32 homeassistant universal_silabs_flasher.cpc[182] WARNING Failed to parse buffer bytearray(b'\xf8'): ValueError('Invalid flag')
2024-01-01 15:52:37 homeassistant universal_silabs_flasher.flasher[182] INFO Probing ApplicationType.CPC at 115200 baud
2024-01-01 15:52:41 homeassistant universal_silabs_flasher.flasher[182] INFO Probing ApplicationType.CPC at 230400 baud
2024-01-01 15:52:45 homeassistant universal_silabs_flasher.flasher[182] INFO Probing ApplicationType.EZSP at 115200 baud
2024-01-01 15:52:50 homeassistant universal_silabs_flasher.flasher[182] INFO Probing ApplicationType.SPINEL at 460800 baud
Error: Failed to probe running application type
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.
/run/s6/basedir/scripts/rc.init: fatal: stopping the container.
s6-rc: info: service mdns: stopping
s6-rc: info: service banner: stopping
Default: mDNSResponder (Engineering Build) (Aug 23 2023 18:27:14) 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
[15:52:55] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped

These are the settings: image

I am running HAOS in a VM on Unraid with the following settings: image

puddly commented 8 months ago

Did you follow this guide? https://skyconnect.home-assistant.io/procedures/enable-multiprotocol/

matebenyovszky commented 8 months ago

Thanks, yeah, I did it according to the steps there. I stuck at Step 2 and never reached Step 3. Opened an issue here too: https://github.com/NabuCasa/universal-silabs-flasher/issues/56

matebenyovszky commented 8 months ago

Was able to update firmware on this site: https://skyconnect.home-assistant.io/firmware-update/

(To the MultiPAN version, see: https://skyconnect.home-assistant.io/about-firmware-options/)

But after the update I now get this - version mismatch?: "2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flash[181] INFO Firmware version '4.3.1' does not match expected version '4.3.2'"

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
[01:02:17] INFO: Starting mDNS Responder...
Default: mDNSResponder (Engineering Build) (Aug 23 2023 18:27:14) starting
cont-init: info: /etc/cont-init.d/check-cpcd-shm.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: 2.3.2
 You are running the latest version of this add-on.
 System: Home Assistant OS 11.2  (amd64 / qemux86-64)
 Home Assistant Core: 2023.12.4
 Home Assistant Supervisor: 2023.12.0
-----------------------------------------------------------
 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
[01:02:18] INFO: Checking /dev/ttyUSB0 identifying SkyConnect v1.0 from Nabu Casa.
[01:02:18] INFO: Starting universal-silabs-flasher with /dev/ttyUSB0
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flash[181] INFO Extracted GBL metadata: NabuCasaMetadata(metadata_version=1, sdk_version='4.3.1', ezsp_version=None, ot_rcp_version=None, fw_type=<FirmwareImageType.RCP_UART_802154: 'rcp-uart-802154'>, baudrate=460800)
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flasher[181] INFO Probing ApplicationType.GECKO_BOOTLOADER at 115200 baud
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flasher[181] INFO Launched application from bootloader
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flasher[181] INFO Detected bootloader version '2.1.1'
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flasher[181] INFO Probing ApplicationType.CPC at 460800 baud
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flasher[181] INFO Detected ApplicationType.CPC, version '4.3.2' at 460800 baudrate (bootloader baudrate 115200)
2024-01-02 01:02:19 homeassistant universal_silabs_flasher.flash[181] INFO Firmware version '4.3.1' does not match expected version '4.3.2'
2024-01-02 01:02:20 homeassistant universal_silabs_flasher.cpc[181] WARNING Failed to parse buffer bytearray(b'\x00'): ValueError('Invalid flag')
2024-01-02 01:02:20 homeassistant universal_silabs_flasher.cpc[181] WARNING Failed to parse buffer bytearray(b'\x80'): ValueError('Invalid flag')
2024-01-02 01:02:20 homeassistant universal_silabs_flasher.cpc[181] WARNING Failed to parse buffer bytearray(b'\x00'): ValueError('Invalid flag')
NabuCasa_SkyConnect_RCP_v4.3.1_rcp-uart-hw-802154_460800.gbl
Traceback (most recent call last):
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/gecko_bootloader.py", line 70, in probe
    return await self.ebl_info()
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/gecko_bootloader.py", line 77, in ebl_info
    await self._state_machine.wait_for_state(State.IN_MENU)
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/common.py", line 106, in wait_for_state
    return await future
asyncio.exceptions.CancelledError

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "/usr/local/bin/universal-silabs-flasher", line 8, in <module>
    sys.exit(main())
  File "/usr/local/lib/python3.9/dist-packages/click/core.py", line 1157, in __call__
    return self.main(*args, **kwargs)
  File "/usr/local/lib/python3.9/dist-packages/click/core.py", line 1078, in main
    rv = self.invoke(ctx)
  File "/usr/local/lib/python3.9/dist-packages/click/core.py", line 1688, in invoke
    return _process_result(sub_ctx.command.invoke(sub_ctx))
  File "/usr/local/lib/python3.9/dist-packages/click/core.py", line 1434, in invoke
    return ctx.invoke(self.callback, **ctx.params)
  File "/usr/local/lib/python3.9/dist-packages/click/core.py", line 783, in invoke
    return __callback(*args, **kwargs)
  File "/usr/local/lib/python3.9/dist-packages/click/decorators.py", line 33, in new_func
    return f(get_current_context(), *args, **kwargs)
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/flash.py", line 36, in inner
    return asyncio.run(f(*args, **kwargs))
  File "/usr/lib/python3.9/asyncio/runners.py", line 44, in run
    return loop.run_until_complete(main)
  File "/usr/lib/python3.9/asyncio/base_events.py", line 642, in run_until_complete
    return future.result()
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/flash.py", line 407, in flash
    await flasher.flash_firmware(
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/flasher.py", line 322, in flash_firmware
    await gecko.probe()
  File "/usr/local/lib/python3.9/dist-packages/universal_silabs_flasher/gecko_bootloader.py", line 70, in probe
    return await self.ebl_info()
  File "/usr/lib/python3/dist-packages/async_timeout/__init__.py", line 55, in __aexit__
    self._do_exit(exc_type)
  File "/usr/lib/python3/dist-packages/async_timeout/__init__.py", line 92, in _do_exit
    raise asyncio.TimeoutError
asyncio.exceptions.TimeoutError
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.
/run/s6/basedir/scripts/rc.init: fatal: stopping the container.
s6-rc: info: service mdns: stopping
s6-rc: info: service banner: stopping
Default: mDNSResponder (Engineering Build) (Aug 23 2023 18:27:14) 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
[01:02:22] INFO: mDNS ended with exit code 4 (signal 0)...
s6-rc: info: service mdns successfully stopped
puddly commented 8 months ago

The web flasher and the addon use exactly the same code to communicate with your stick: the only difference is that you are not using Unraid when flashing. I think that may be the underlying issue.

The website also flashes firmware 4.3.2, not 4.3.1, so you should not be getting a mismatch. Did you manually provide the firmware file?

matebenyovszky commented 8 months ago

No, I installed automatically with the web flasher. The web flasher also mentioned 4.3.2 after it was ready, so I assume ,y the addon version is the older one.

Looking at the changelog of the HA addon, this seems possible: image

The latest according to the changelog from Gecko SDK is 4.3.1 in my installed addon version 2.3.2

puddly commented 8 months ago

You should instead flash 4.3.1: https://github.com/NabuCasa/silabs-firmware/blob/main/RCPMultiPAN/beta/NabuCasa_SkyConnect_RCP_v4.3.1_rcp-uart-hw-802154_460800.gbl. Something about your Unraid setup is preventing the addon from being able to flash firmware to your device.

matebenyovszky commented 8 months ago

Thanks, I will try it. But am I right, that probably this should be updated synced to the firmware? https://github.com/home-assistant/addons/blob/master/silabs-multiprotocol/build.yaml

puddly commented 8 months ago

4.3.2 was never deployed due to bugs so 4.3.1 is still the latest version.

matebenyovszky commented 8 months ago

OK, so I had this: image

Downloaded 4.3.1 from the link: image

And now see this on the web flasher: image

And this seemingly solved the problem, thanks for your help and the development of this solution!!! 🙏🙏🙏

(Probably the web updater should note this version mismatch possibility)