Error when running the Python CHIP controller

I'm actually trying to run the Python CHIP controller in my PC but I got some errors.

I've successfully set up the Open Thread Border Router in a Raspberry PI and I'm using the Light Bulb Matter example flashed in a nRF5340 DK which is my Matter accessory.

I followed the tutorial https://developer.nordicsemi.com/nRF_Connect_SDK/doc/1.9.1/matter/python_chip_controller_building.html#using-python-chip-controller-for-matter-accessory-testing to create my Matter controller using the tool Python CHIP controller.

I used all the required commands here below for installation and building the Python CHIP controller.

Then I tried to run the tool as shown here below :

I successfully activated the Python virtual environment. Then I tried to run the Python CHIP controller using "sudo out/python_env/bin/chip-device-ctrl " but I got the following output :

:~/connectedhomeip$ sudo out/python_env/bin/chip-device-ctrl 
[1647525260.928139][48172:48172] CHIP:CTL: Setting attestation nonce to random value
[1647525260.928241][48172:48172] CHIP:CTL: Setting CSR nonce to random value
[1647525260.930233][48172:48172] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-hoBbXJ)
[1647525260.930450][48172:48172] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1647525260.930478][48172:48172] CHIP:DL: NVS set: chip-counters/reboot-count = 6 (0x6)
[1647525260.930711][48172:48172] CHIP:DL: Got Ethernet interface: enp0s31f6
[1647525260.930868][48172:48172] CHIP:DL: Found the primary Ethernet interface:enp0s31f6
[1647525260.931027][48172:48172] CHIP:DL: Got WiFi interface: wlp1s0
[1647525260.931673][48172:48172] CHIP:DL: Found the primary WiFi interface:wlp1s0
[1647525260.931786][48172:48186] CHIP:DL: Platform main loop started.
2022-03-17 14:54:20 IMP-IT0087lx root[48172] CRITICAL Loading configuration from /tmp/chip-device-ctrl-storage.json...
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 1
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 2
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 3
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 4
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 5
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 6
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 7
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 8
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 9
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 10
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 11
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 12
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 13
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 14
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 15
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO Loading from storage for fabric index 16
2022-03-17 14:54:20 IMP-IT0087lx chip.DL[48172] INFO writing settings to file (/tmp/chip_counters.ini-23Pp4J)
2022-03-17 14:54:20 IMP-IT0087lx chip.DL[48172] ERROR renamed tmp file to file (/tmp/chip_counters.ini)
2022-03-17 14:54:20 IMP-IT0087lx chip.DL[48172] INFO NVS set: chip-counters/GlobalMCTR = 6000 (0x1770)
2022-03-17 14:54:20 IMP-IT0087lx root[48172] INFO SetSdkKey: gcc = b'\xd0\x07\x00\x00'
2022-03-17 14:54:20 IMP-IT0087lx root[48172] INFO SetSdkKey: gdc = b'\xd0\x07\x00\x00'
2022-03-17 14:54:20 IMP-IT0087lx chip.ZCL[48172] INFO Using ZAP configuration...
2022-03-17 14:54:20 IMP-IT0087lx chip.DL[48172] INFO Avahi connecting
2022-03-17 14:54:20 IMP-IT0087lx chip.IN[48172] INFO CASE Server enabling CASE session setups
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] ERROR Failed to initialize advertiser: ../../src/platform/Linux/DnssdImpl.cpp:333: CHIP Error 0x00000003: Incorrect state
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] INFO Failed to find a valid admin pairing. Node ID unknown
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] INFO Start dns-sd server - no current nodeId
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] INFO Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] ERROR Failed to advertise unprovisioned commissionable node: ../../src/lib/dnssd/Discovery_ImplPlatform.cpp:473: CHIP Error 0x00000003: Incorrect state
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] INFO Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15
2022-03-17 14:54:20 IMP-IT0087lx chip.DIS[48172] ERROR Failed to advertise commissioner: ../../src/lib/dnssd/Discovery_ImplPlatform.cpp:473: CHIP Error 0x00000003: Incorrect state
2022-03-17 14:54:21 IMP-IT0087lx chip.DL[48172] ERROR Avahi client failure
2022-03-17 14:54:21 IMP-IT0087lx chip.DIS[48172] ERROR DNS-SD error: ../../src/platform/Linux/DnssdImpl.cpp:405: CHIP Error 0x000000AC: Internal error
New FabricAdmin: FabricId: 1(1)
2022-03-17 14:54:21 IMP-IT0087lx root[48172] INFO SetReplKey: fabricAdmins = {'1': {'fabricId': 1}}
Allocating new controller with FabricId: 1(1), NodeId: 1
2022-03-17 14:54:21 IMP-IT0087lx chip.CTL[48172] INFO Setting attestation nonce to random value
2022-03-17 14:54:21 IMP-IT0087lx chip.CTL[48172] INFO Setting CSR nonce to random value
2022-03-17 14:54:21 IMP-IT0087lx chip.CTL[48172] INFO Generating NOC
CHIP Error 0x00000003: Incorrect state
Failed to bringup CHIPDeviceController CLI
Exception ignored in: <function ChipDeviceController.__del__ at 0x7f75f07d4040>
Traceback (most recent call last):
  File "/home/czena/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/ChipDeviceCtrl.py", line 186, in __del__
    self.Shutdown()
  File "/home/czena/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/ChipDeviceCtrl.py", line 150, in Shutdown
    if (self.isActive):
AttributeError: 'ChipDeviceController' object has no attribute 'isActive'
Segmentation fault

I would like to know why I got a segmentation fault. Could you help me please ?

I'm using OS Ubuntu 20.04.4 LTS and nRF Connect SDK v1.9.1

Parents

0 Karl Ylvisaker over 3 years ago
Hello again,

I hope you have had a great weekend!

Could you confirm that you have the Avahi-daemon up and running?
Could you also tell me what

systemctl status avahi-daemon
and
ps aux | grep avahi-daemon

returns for you?

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Reply

0 Karl Ylvisaker over 3 years ago
Hello again,

I hope you have had a great weekend!

Could you confirm that you have the Avahi-daemon up and running?
Could you also tell me what

systemctl status avahi-daemon
and
ps aux | grep avahi-daemon

returns for you?

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

Children

0 Carla31 over 3 years ago in reply to Karl Ylvisaker

For the first command I get :

connectedhomeip$ systemctl status avahi-daemon
● avahi-daemon.service - Avahi mDNS/DNS-SD Stack
     Loaded: loaded (/lib/systemd/system/avahi-daemon.service; enabled; vendo>
     Active: failed (Result: exit-code) since Tue 2022-04-05 14:46:54 CEST; 1>
TriggeredBy: ● avahi-daemon.socket
    Process: 79823 ExecStart=/usr/sbin/avahi-daemon -s (code=exited, status=2>
   Main PID: 79823 (code=exited, status=255/EXCEPTION)
     Status: "avahi-daemon 0.7 starting up."

For the second command I get : 

connectedhomeip$ ps aux | grep avahi-daemon
czena 81257 0.0 0.0 9052 656 pts/4 S+ 14:50 0:00 grep --color=auto avahi-daemon

I tried to reinstall the Python CHIP controller. I followed steps from the Matter website : https://developer.nordicsemi.com/nRF_Connect_SDK/doc/1.9.1/matter/python_chip_controller_building.html#using-python-chip-controller-for-matter-accessory-testing

I made all the 5 steps from the "Building and installing" section. 
When building and installing the Python CHIP controller using :

scripts/build_python.sh -m platform

I got the following messages :

ACTIVATOR! This sets your shell environment variables.

Activating environment (setting environment variables):

  Setting environment variables for CIPD package manager...done
  Setting environment variables for Python environment.....done
  Setting environment variables for pw packages............skipped
  Setting environment variables for Host tools.............done

Checking the environment:

20220405 14:58:42 INF Environment passes all checks!

Environment looks good, you are ready to go!

Done. Made 2965 targets from 243 files in 252ms
ninja: Entering directory `./out/python_lib'
[179/179] stamp obj/src/controller/python/python.stamp


Then I tried to use the first command from the "Running the tool" section:

source out/python_env/bin/activate

but I realized that folder "python_env" does not exist as shown here bellow. 

Why folder "python_env" is not created ? How can I run Python CHIP controller without errors? 

Thanks!

0 HeneryH over 3 years ago in reply to Karl Ylvisaker
Carla31 I am still having troubles with this but I can address one topic for you. The lack of the env directory. I put a documentation ticket in based on a change to the default options on one of the commands.

devzone.nordicsemi.com/.../documentation-update-needed---matter-instructions

scripts/build_python.sh -m platform <------------ This command now requires the " -i separate " option to generate the env. See --help
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 Carla31 over 3 years ago in reply to HeneryH

Thanks for you answer. Now I can see the python_env folder.

Now I tried to run the Python CHIP controller but with no success. I got the following output :

connectedhomeip$ source out/python_env/bin/activate
(python_env) czena@IMP-IT0087lx:~/Documents/Others/Matter/connectedhomeip$ sudo out/python_env/bin/chip-device-ctrl 
[sudo] password for czena: 
[1649165043.900006][98518:98518] CHIP:CTL: Setting attestation nonce to random value
[1649165043.900108][98518:98518] CHIP:CTL: Setting CSR nonce to random value
[1649165043.901938][98518:98518] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-CWgGZG)
[1649165043.902132][98518:98518] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1649165043.902143][98518:98518] CHIP:DL: NVS set: chip-counters/reboot-count = 4 (0x4)
[1649165043.902389][98518:98518] CHIP:DL: Got Ethernet interface: enp0s31f6
[1649165043.902574][98518:98518] CHIP:DL: Found the primary Ethernet interface:enp0s31f6
[1649165043.902761][98518:98518] CHIP:DL: Got WiFi interface: wlp1s0
[1649165043.904488][98518:98518] CHIP:DL: Found the primary WiFi interface:wlp1s0
[1649165043.904616][98518:98526] CHIP:DL: Platform main loop started.
2022-04-05 15:24:03 IMP-IT0087lx root[98518] CRITICAL Loading configuration from /tmp/chip-device-ctrl-storage.json...
2022-04-05 15:24:03 IMP-IT0087lx chip.DL[98518] INFO writing settings to file (/tmp/chip_counters.ini-OzNelH)
2022-04-05 15:24:03 IMP-IT0087lx chip.DL[98518] ERROR renamed tmp file to file (/tmp/chip_counters.ini)
2022-04-05 15:24:03 IMP-IT0087lx chip.DL[98518] INFO NVS set: chip-counters/GlobalMCTR = 4000 (0xFA0)
2022-04-05 15:24:03 IMP-IT0087lx root[98518] INFO SetSdkKey: g/gcc = b'\xd0\x07\x00\x00'
Exception ignored on calling ctypes callback function: <function _OnSyncSetKeyValueCb at 0x7f6993ecf550>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 44, in _OnSyncSetKeyValueCb
    storageObj.SetSdkKey(key.decode("utf-8"), ctypes.string_at(value, size))
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 147, in SetSdkKey
    self.Sync()
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 111, in Sync
    f"Could not open {path} for writing configuration. Error:")
NameError: name 'path' is not defined
2022-04-05 15:24:03 IMP-IT0087lx root[98518] INFO SetSdkKey: g/gdc = b'\xd0\x07\x00\x00'
Exception ignored on calling ctypes callback function: <function _OnSyncSetKeyValueCb at 0x7f6993ecf550>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 44, in _OnSyncSetKeyValueCb
    storageObj.SetSdkKey(key.decode("utf-8"), ctypes.string_at(value, size))
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 147, in SetSdkKey
    self.Sync()
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 111, in Sync
    f"Could not open {path} for writing configuration. Error:")
NameError: name 'path' is not defined
2022-04-05 15:24:03 IMP-IT0087lx chip.ZCL[98518] INFO Using ZAP configuration...
Segmentation fault
(python_env) czena@IMP-IT0087lx:~/Documents/Others/Matter/connectedhomeip$ sudo out/python_env/bin/chip-device-ctrl 
[1649165195.463120][99597:99597] CHIP:CTL: Setting attestation nonce to random value
[1649165195.463219][99597:99597] CHIP:CTL: Setting CSR nonce to random value
[1649165195.467032][99597:99597] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-E3TpNe)
[1649165195.467209][99597:99597] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1649165195.467237][99597:99597] CHIP:DL: NVS set: chip-counters/reboot-count = 5 (0x5)
[1649165195.467456][99597:99597] CHIP:DL: Got Ethernet interface: enp0s31f6
[1649165195.467614][99597:99597] CHIP:DL: Found the primary Ethernet interface:enp0s31f6
[1649165195.467783][99597:99597] CHIP:DL: Got WiFi interface: wlp1s0
[1649165195.469345][99597:99597] CHIP:DL: Found the primary WiFi interface:wlp1s0
[1649165195.469478][99597:99611] CHIP:DL: Platform main loop started.
2022-04-05 15:26:35 IMP-IT0087lx root[99597] CRITICAL Loading configuration from /tmp/chip-device-ctrl-storage.json...
2022-04-05 15:26:35 IMP-IT0087lx chip.DL[99597] INFO writing settings to file (/tmp/chip_counters.ini-1CfIUf)
2022-04-05 15:26:35 IMP-IT0087lx chip.DL[99597] ERROR renamed tmp file to file (/tmp/chip_counters.ini)
2022-04-05 15:26:35 IMP-IT0087lx chip.DL[99597] INFO NVS set: chip-counters/GlobalMCTR = 5000 (0x1388)
2022-04-05 15:26:35 IMP-IT0087lx root[99597] INFO SetSdkKey: g/gcc = b'\xd0\x07\x00\x00'
Exception ignored on calling ctypes callback function: <function _OnSyncSetKeyValueCb at 0x7fa28f70e550>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 44, in _OnSyncSetKeyValueCb
    storageObj.SetSdkKey(key.decode("utf-8"), ctypes.string_at(value, size))
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 147, in SetSdkKey
    self.Sync()
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 111, in Sync
    f"Could not open {path} for writing configuration. Error:")
NameError: name 'path' is not defined
2022-04-05 15:26:35 IMP-IT0087lx root[99597] INFO SetSdkKey: g/gdc = b'\xd0\x07\x00\x00'
Exception ignored on calling ctypes callback function: <function _OnSyncSetKeyValueCb at 0x7fa28f70e550>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 44, in _OnSyncSetKeyValueCb
    storageObj.SetSdkKey(key.decode("utf-8"), ctypes.string_at(value, size))
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 147, in SetSdkKey
    self.Sync()
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 111, in Sync
    f"Could not open {path} for writing configuration. Error:")
NameError: name 'path' is not defined
2022-04-05 15:26:35 IMP-IT0087lx chip.ZCL[99597] INFO Using ZAP configuration...
2022-04-05 15:26:35 IMP-IT0087lx chip.DL[99597] INFO Avahi connecting
2022-04-05 15:26:35 IMP-IT0087lx chip.IN[99597] INFO CASE Server enabling CASE session setups
2022-04-05 15:26:35 IMP-IT0087lx chip.DIS[99597] INFO Updating services using commissioning mode 0
2022-04-05 15:26:35 IMP-IT0087lx chip.DIS[99597] ERROR Failed to initialize advertiser: ../../src/platform/Linux/DnssdImpl.cpp:333: CHIP Error 0x00000003: Incorrect state
2022-04-05 15:26:35 IMP-IT0087lx chip.DIS[99597] INFO Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15
2022-04-05 15:26:35 IMP-IT0087lx chip.DIS[99597] ERROR Failed to advertise commissioner: ../../src/lib/dnssd/Discovery_ImplPlatform.cpp:473: CHIP Error 0x00000003: Incorrect state
2022-04-05 15:26:35 IMP-IT0087lx chip.DIS[99597] INFO Delaying proxy of operational discovery: missing delegate
2022-04-05 15:26:35 IMP-IT0087lx chip.DL[99597] ERROR Avahi client failure
2022-04-05 15:26:35 IMP-IT0087lx chip.DIS[99597] ERROR DNS-SD error: ../../src/platform/Linux/DnssdImpl.cpp:405: CHIP Error 0x000000AC: Internal error
New FabricAdmin: FabricId: 1(1)
2022-04-05 15:26:35 IMP-IT0087lx root[99597] INFO SetReplKey: fabricAdmins = {'1': {'fabricId': 1}}
name 'path' is not defined
Failed to bringup CHIPDeviceController CLI
Exception ignored in: <function FabricAdmin.__del__ at 0x7fa28df59790>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/FabricAdmin.py", line 209, in __del__
    self.Shutdown(False)
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/FabricAdmin.py", line 188, in Shutdown
    if (self._isActive):
AttributeError: 'FabricAdmin' object has no attribute '_isActive'
Trace/breakpoint trap
(python_env) czena@IMP-IT0087lx:~/Documents/Others/Matter/connectedhomeip$ sudo out/python_env/bin/chip-device-ctrl 
[1649165200.415890][99632:99632] CHIP:CTL: Setting attestation nonce to random value
[1649165200.415975][99632:99632] CHIP:CTL: Setting CSR nonce to random value
[1649165200.417802][99632:99632] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-vACnqU)
[1649165200.418016][99632:99632] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1649165200.418044][99632:99632] CHIP:DL: NVS set: chip-counters/reboot-count = 6 (0x6)
[1649165200.418267][99632:99632] CHIP:DL: Got Ethernet interface: enp0s31f6
[1649165200.418466][99632:99632] CHIP:DL: Found the primary Ethernet interface:enp0s31f6
[1649165200.418676][99632:99632] CHIP:DL: Got WiFi interface: wlp1s0
[1649165200.420319][99632:99632] CHIP:DL: Found the primary WiFi interface:wlp1s0
[1649165200.420422][99632:99638] CHIP:DL: Platform main loop started.
2022-04-05 15:26:40 IMP-IT0087lx root[99632] CRITICAL Loading configuration from /tmp/chip-device-ctrl-storage.json...
2022-04-05 15:26:40 IMP-IT0087lx chip.DL[99632] INFO writing settings to file (/tmp/chip_counters.ini-gYRMIT)
2022-04-05 15:26:40 IMP-IT0087lx chip.DL[99632] ERROR renamed tmp file to file (/tmp/chip_counters.ini)
2022-04-05 15:26:40 IMP-IT0087lx chip.DL[99632] INFO NVS set: chip-counters/GlobalMCTR = 6000 (0x1770)
2022-04-05 15:26:40 IMP-IT0087lx root[99632] INFO SetSdkKey: g/gcc = b'\xd0\x07\x00\x00'
Exception ignored on calling ctypes callback function: <function _OnSyncSetKeyValueCb at 0x7f11e170a550>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 44, in _OnSyncSetKeyValueCb
    storageObj.SetSdkKey(key.decode("utf-8"), ctypes.string_at(value, size))
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 147, in SetSdkKey
    self.Sync()
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 111, in Sync
    f"Could not open {path} for writing configuration. Error:")
NameError: name 'path' is not defined
2022-04-05 15:26:40 IMP-IT0087lx root[99632] INFO SetSdkKey: g/gdc = b'\xd0\x07\x00\x00'
Exception ignored on calling ctypes callback function: <function _OnSyncSetKeyValueCb at 0x7f11e170a550>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 44, in _OnSyncSetKeyValueCb
    storageObj.SetSdkKey(key.decode("utf-8"), ctypes.string_at(value, size))
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 147, in SetSdkKey
    self.Sync()
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/storage/__init__.py", line 111, in Sync
    f"Could not open {path} for writing configuration. Error:")
NameError: name 'path' is not defined
2022-04-05 15:26:40 IMP-IT0087lx chip.ZCL[99632] INFO Using ZAP configuration...
2022-04-05 15:26:40 IMP-IT0087lx chip.DL[99632] INFO Avahi connecting
2022-04-05 15:26:40 IMP-IT0087lx chip.IN[99632] INFO CASE Server enabling CASE session setups
2022-04-05 15:26:40 IMP-IT0087lx chip.DIS[99632] INFO Updating services using commissioning mode 0
2022-04-05 15:26:40 IMP-IT0087lx chip.DIS[99632] ERROR Failed to initialize advertiser: ../../src/platform/Linux/DnssdImpl.cpp:333: CHIP Error 0x00000003: Incorrect state
2022-04-05 15:26:40 IMP-IT0087lx chip.DIS[99632] INFO Advertise commission parameter vendorID=65521 productID=32769 discriminator=3840/15
2022-04-05 15:26:40 IMP-IT0087lx chip.DIS[99632] ERROR Failed to advertise commissioner: ../../src/lib/dnssd/Discovery_ImplPlatform.cpp:473: CHIP Error 0x00000003: Incorrect state
2022-04-05 15:26:40 IMP-IT0087lx chip.DIS[99632] INFO Delaying proxy of operational discovery: missing delegate
2022-04-05 15:26:40 IMP-IT0087lx chip.DL[99632] ERROR Avahi client failure
2022-04-05 15:26:40 IMP-IT0087lx chip.DIS[99632] ERROR DNS-SD error: ../../src/platform/Linux/DnssdImpl.cpp:405: CHIP Error 0x000000AC: Internal error
New FabricAdmin: FabricId: 1(1)
2022-04-05 15:26:40 IMP-IT0087lx root[99632] INFO SetReplKey: fabricAdmins = {'1': {'fabricId': 1}}
name 'path' is not defined
Failed to bringup CHIPDeviceController CLI
Exception ignored in: <function FabricAdmin.__del__ at 0x7f11dff55790>
Traceback (most recent call last):
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/FabricAdmin.py", line 209, in __del__
    self.Shutdown(False)
  File "/home/czena/Documents/Others/Matter/connectedhomeip/out/python_env/lib/python3.8/site-packages/chip/FabricAdmin.py", line 188, in Shutdown
    if (self._isActive):
AttributeError: 'FabricAdmin' object has no attribute '_isActive'
Illegal instruction

How can I solve this ?

0 Karl Ylvisaker over 3 years ago in reply to Carla31
Hello again,

It seems to me that your Avahi deamon is not running, so the Python CHIP controller has nothing to connect to, and therefore fails.
Could you restart the deamon using:
sudo systemctl restart avahi-daemon

and then checking its status again with:
sudo systemctl status avahi-daemon

To see if it is able to get up and running?

If it does not manage to start, could you do a reinstallation of the Avahi deamon?
Alternatively we would have to look into the syslog to see why the deamon does not start.

Best regards,
Karl
Cancel
Vote Up 0 Vote Down

Sign in to reply

Verify Answer

Cancel

0 Carla31 over 3 years ago in reply to Karl Ylvisaker

Hello, I'm trying to connect my board nRF5340DK (with the Light Bulb Matter example) with my PC (Matter controller) over Bluetooth but the connection is not established. This is what I get :

chip-device-ctrl > connect -ble 3840 20202021
2022-04-28 10:44:31 IMP-IT0087lx root[695542] WARNING  /usr/local/bin/chip-device-ctrl:601: DeprecationWarning:This method is being deprecated. Please use the DeviceController.[ConnectBLE|CommissionIP] methods directly in the REPL
Device is assigned with nodeid = 308642
2022-04-28 10:44:31 IMP-IT0087lx chip.IN[695542] INFO Prepared unauthenticated message 0x7ff46affb8f0 to 0x0000000000000000 (0)  of type 0x20 and protocolId (0, 0) on exchange 62712i with MessageCounter:1124971237.
2022-04-28 10:44:31 IMP-IT0087lx chip.IN[695542] INFO Sending unauthenticated msg 0x7ff46affb8f0 with MessageCounter:1124971237 to 0x0000000000000000 at monotonic time: 000000000F76DDB3 msec
2022-04-28 10:44:31 IMP-IT0087lx chip.CTL[695542] INFO Setting attestation nonce to random value
2022-04-28 10:44:31 IMP-IT0087lx chip.CTL[695542] INFO Setting CSR nonce to random value
2022-04-28 10:44:31 IMP-IT0087lx chip.CTL[695542] INFO Commission called for node ID 0x000000000004B5A2
2022-04-28 10:44:31 IMP-IT0087lx chip.BLE[695542] INFO BLE removing known devices.
2022-04-28 10:44:31 IMP-IT0087lx chip.BLE[695542] INFO BLE initiating scan.
2022-04-28 10:44:32 IMP-IT0087lx chip.BLE[695542] INFO New device scanned: DD:30:06:22:DC:86
2022-04-28 10:44:32 IMP-IT0087lx chip.BLE[695542] INFO Device discriminator match. Attempting to connect.
2022-04-28 10:44:32 IMP-IT0087lx chip.BLE[695542] INFO Scan complete notification without an active scan.
2022-04-28 10:44:34 IMP-IT0087lx chip.BLE[695542] INFO subscribe complete, ep = 0x7ff47264cb80
2022-04-28 10:44:34 IMP-IT0087lx chip.BLE[695542] INFO peripheral chose BTP version 4; central expected between 4 and 4
2022-04-28 10:44:34 IMP-IT0087lx chip.BLE[695542] INFO using BTP fragment sizes rx 244 / tx 244.
2022-04-28 10:44:34 IMP-IT0087lx chip.BLE[695542] INFO local and remote recv window size = 5
2022-04-28 10:44:35 IMP-IT0087lx chip.IN[695542] INFO Received malformed unsecure packet with source 0x0000000000000000 destination 0x0000000000000000
2022-04-28 10:45:01 IMP-IT0087lx chip.SC[695542] ERROR PASESession timed out while waiting for a response from the peer. Expected message type was 33
Failed to establish secure session to device: 50
CHIP Error 0x00000032: Timeout

I would like to know why I can't establish the secure connection over Bluetooth LE.

When I use the command ble-scan, to scan all advertised Matter devices, I got the following output:

2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG destroy device
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO Name            = MatterLight
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO ID              = 766dcf2a-2adf-37fc-abbc-b104dd4e0ec4
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO RSSI            = -56
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO Address         = DD:30:06:22:DC:86
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO Adv UUID        = 0000fff6-0000-1000-8000-00805f9b34fb
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO Adv Data        = 00000f5a234c4e00
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] INFO 
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'Name'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'Name'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'Name'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'Name'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'Name'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'ServiceData'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'ServiceData'
2022-04-28 10:44:12 IMP-IT0087lx ChipBLEMgr[695542] DEBUG org.freedesktop.DBus.Error.InvalidArgs: No such property 'ServiceData'

Could you help me please ?