MATTER
[esp-matter ][CHIP-Tool] [1] build/ run / 사용법
하니_즐거운하루
2024. 1. 3. 14:07
: esp-matter github 기준으로 chip-tool 빌드 및 사용법 정리합니다.
목차
esp-matter 소스코드 다운로드
https://github.com/espressif/esp-matter
GitHub - espressif/esp-matter: Espressif's SDK for Matter
Espressif's SDK for Matter. Contribute to espressif/esp-matter development by creating an account on GitHub.
github.com
Build
→ chip-tool 소스 디렉토리
..../connectedhomeip/examples/chip-tool
→ connectedhomeip 디렉토리에서 아래 명령 실행
./scripts/examples/gn_build_example.sh examples/chip-tool BUILD_PATH
→ build 로그
더보기
$ ./scripts/examples/gn_build_example.sh examples/chip-tool/ BUILD_PATH
WELCOME TO...
█
█
▄ █ ▄ █ █
▀▀█████▀▀ ▄▀▀▀▄ ▄▀▀▀▄ ▄▀▀▀▀▄█ ▀▀█▀▀▀▀▀█▀▀ ▄▀▀▀▀▄ ▄▀▀
▀█▄ ▄█▀ █ █ █ █ █ █ █ █▄▄▄▄▄▄█ █
▀█▄ ▄█▀ █ █ █ █ █ █ █ █ █
▄██▀▀█ █▀▀██▄ █ █ █ ▀▄▄▄▄▀█ ▀▄▄ ▀▄▄ ▀▄▄▄▄▀ █
▀▀ █ █ ▀▀
ACTIVATOR! This sets your shell environment variables.
Activating environment (setting environment variables):
Setting environment variables for CIPD package manager...done
Setting environment variables for Project actions........skipped
Setting environment variables for Python environment.....done
Setting environment variables for pw packages............skipped
Setting environment variables for Host tools.............done
Checking the environment:
20240103 14:23:24 INF Environment passes all checks!
Environment looks good, you are ready to go!
+ env
SHELL=/bin/bash
SESSION_MANAGER=local/ubuntu22:@/tmp/.ICE-unix/1959,unix/ubuntu22:/tmp/.ICE-unix/1959
QT_ACCESSIBILITY=1
COLORTERM=truecolor
XDG_CONFIG_DIRS=/etc/xdg/xdg-ubuntu:/etc/xdg
SSH_AGENT_LAUNCHER=gnome-keyring
XDG_MENU_PREFIX=gnome-
GNOME_DESKTOP_SESSION_ID=this-is-deprecated
GNOME_SHELL_SESSION_MODE=ubuntu
SSH_AUTH_SOCK=/run/user/1000/keyring/ssh
PW_PROJECT_ROOT=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip
XMODIFIERS=@im=ibus
DESKTOP_SESSION=ubuntu
IDF_PYTHON_ENV_PATH=/home/xxx/.espressif/python_env/idf5.2_py3.10_env
PW_ZAP_CIPD_INSTALL_DIR=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/zap
GTK_MODULES=gail:atk-bridge
PWD=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip
XDG_SESSION_DESKTOP=ubuntu
LOGNAME=xxx
XDG_SESSION_TYPE=wayland
SYSTEMD_EXEC_PID=2024
IDF_PATH=/home/xxx/esp/esp-idf
XAUTHORITY=/run/user/1000/.mutter-Xwaylandauth.QR9VG2
OPENOCD_SCRIPTS=/home/xxx/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230921/openocd-esp32/share/openocd/scripts
CIPD_CACHE_DIR=/home/xxx/.cipd-cache-dir
ZAP_INSTALL_PATH=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/zap
PW_ROOT=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/third_party/pigweed/repo
HOME=/home/xxx
USERNAME=xxx
IM_CONFIG_PHASE=1
ESP_IDF_VERSION=5.2
LANG=en_US.UTF-8
LS_COLORS=rs=0:di=01;34:ln=01;36:mh=00:pi=40;33:so=01;35:do=01;35:bd=40;33;01:cd=40;33;01:or=40;31;01:mi=00:su=37;41:sg=30;43:ca=30;41:tw=30;42:ow=34;42:st=37;44:ex=01;32:*.tar=01;31:*.tgz=01;31:*.arc=01;31:*.arj=01;31:*.taz=01;31:*.lha=01;31:*.lz4=01;31:*.lzh=01;31:*.lzma=01;31:*.tlz=01;31:*.txz=01;31:*.tzo=01;31:*.t7z=01;31:*.zip=01;31:*.z=01;31:*.dz=01;31:*.gz=01;31:*.lrz=01;31:*.lz=01;31:*.lzo=01;31:*.xz=01;31:*.zst=01;31:*.tzst=01;31:*.bz2=01;31:*.bz=01;31:*.tbz=01;31:*.tbz2=01;31:*.tz=01;31:*.deb=01;31:*.rpm=01;31:*.jar=01;31:*.war=01;31:*.ear=01;31:*.sar=01;31:*.rar=01;31:*.alz=01;31:*.ace=01;31:*.zoo=01;31:*.cpio=01;31:*.7z=01;31:*.rz=01;31:*.cab=01;31:*.wim=01;31:*.swm=01;31:*.dwm=01;31:*.esd=01;31:*.jpg=01;35:*.jpeg=01;35:*.mjpg=01;35:*.mjpeg=01;35:*.gif=01;35:*.bmp=01;35:*.pbm=01;35:*.pgm=01;35:*.ppm=01;35:*.tga=01;35:*.xbm=01;35:*.xpm=01;35:*.tif=01;35:*.tiff=01;35:*.png=01;35:*.svg=01;35:*.svgz=01;35:*.mng=01;35:*.pcx=01;35:*.mov=01;35:*.mpg=01;35:*.mpeg=01;35:*.m2v=01;35:*.mkv=01;35:*.webm=01;35:*.webp=01;35:*.ogm=01;35:*.mp4=01;35:*.m4v=01;35:*.mp4v=01;35:*.vob=01;35:*.qt=01;35:*.nuv=01;35:*.wmv=01;35:*.asf=01;35:*.rm=01;35:*.rmvb=01;35:*.flc=01;35:*.avi=01;35:*.fli=01;35:*.flv=01;35:*.gl=01;35:*.dl=01;35:*.xcf=01;35:*.xwd=01;35:*.yuv=01;35:*.cgm=01;35:*.emf=01;35:*.ogv=01;35:*.ogx=01;35:*.aac=00;36:*.au=00;36:*.flac=00;36:*.m4a=00;36:*.mid=00;36:*.midi=00;36:*.mka=00;36:*.mp3=00;36:*.mpc=00;36:*.ogg=00;36:*.ra=00;36:*.wav=00;36:*.oga=00;36:*.opus=00;36:*.spx=00;36:*.xspf=00;36:
XDG_CURRENT_DESKTOP=ubuntu:GNOME
VIRTUAL_ENV=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/pigweed-venv
VTE_VERSION=6800
WAYLAND_DISPLAY=wayland-0
GNOME_TERMINAL_SCREEN=/org/gnome/Terminal/screen/d3854b16_1170_4de1_9928_ce6add0e22bc
PW_PYTHON_CIPD_INSTALL_DIR=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/python
_PW_ROSETTA=0
GNOME_SETUP_DISPLAY=:1
LESSCLOSE=/usr/bin/lesspipe %s %s
XDG_SESSION_CLASS=user
TERM=xterm-256color
LESSOPEN=| /usr/bin/lesspipe %s
USER=xxx
GNOME_TERMINAL_SERVICE=:1.107
ESPPORT=/dev/ttyACM0
DISPLAY=:0
SHLVL=2
QT_IM_MODULE=ibus
PW_PACKAGE_ROOT=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/packages
_PW_ENVIRONMENT_CONFIG_FILE=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/scripts/setup/environment.json
IDF_DEACTIVATE_FILE_PATH=/tmp/tmp_fsxhr91idf_4107
XDG_RUNTIME_DIR=/run/user/1000
_PW_ACTUAL_ENVIRONMENT_ROOT=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment
PW_BRANDING_BANNER=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/scripts/setup/banner.txt
PW_ARM_CIPD_INSTALL_DIR=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/arm
XDG_DATA_DIRS=/usr/share/ubuntu:/usr/local/share/:/usr/share/:/var/lib/snapd/desktop
PATH=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/third_party/pigweed/repo/out/host/host_tools:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/pigweed-venv/bin:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/arm/bin:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/arm:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/zap:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/pigweed/bin:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/pigweed:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd:/home/xxx/esp/esp-idf/components/espcoredump:/home/xxx/esp/esp-idf/components/partition_table:/home/xxx/esp/esp-idf/components/app_update:/home/xxx/esp/esp-idf/components/espcoredump:/home/xxx/esp/esp-idf/components/partition_table:/home/xxx/esp/esp-idf/components/app_update:/home/xxx/.espressif/tools/xtensa-esp-elf-gdb/12.1_20221002/xtensa-esp-elf-gdb/bin:/home/xxx/.espressif/tools/riscv32-esp-elf-gdb/12.1_20221002/riscv32-esp-elf-gdb/bin:/home/xxx/.espressif/tools/xtensa-esp-elf/esp-13.2.0_20230928/xtensa-esp-elf/bin:/home/xxx/.espressif/tools/riscv32-esp-elf/esp-13.2.0_20230928/riscv32-esp-elf/bin:/home/xxx/.espressif/tools/esp32ulp-elf/2.35_20220830/esp32ulp-elf/bin:/home/xxx/.espressif/tools/openocd-esp32/v0.12.0-esp32-20230921/openocd-esp32/bin:/home/xxx/.espressif/python_env/idf5.2_py3.10_env/bin:/home/xxx/esp/esp-idf/tools:/home/xxx/.local/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin:/usr/games:/usr/local/games:/snap/bin:/snap/bin:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/pigweed/:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/out/host:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/pigweed/:/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/out/host
IDF_TOOLS_EXPORT_CMD=/home/xxx/esp/esp-idf/export.sh
IDF_TOOLS_INSTALL_CMD=/home/xxx/esp/esp-idf/install.sh
GDMSESSION=ubuntu
ESP_MATTER_PATH=/home/xxx/esp/esp-matter
DBUS_SESSION_BUS_ADDRESS=unix:path=/run/user/1000/bus
PW_PIGWEED_CIPD_INSTALL_DIR=/home/xxx/esp/esp-matter/connectedhomeip/connectedhomeip/.environment/cipd/packages/pigweed
ESP_ROM_ELF_DIR=/home/xxx/.espressif/tools/esp-rom-elfs/20230320/
OLDPWD=/home/xxx/esp/esp-matter/connectedhomeip
_=/usr/bin/env
+ gn gen --check --fail-on-unused-args --root=examples/chip-tool/ BUILD_PATH --args=
Done. Made 297 targets from 233 files in 144ms
+ ninja -C BUILD_PATH
ninja: Entering directory `BUILD_PATH'
[656/656] stamp obj/default.stamp
BUILD_PATH 디렉토리 이동후 chip-tool 동작 확인하기
더보기
$ .chip-tool
$ ./chip-tool
[1704260009.794049][46194:46194] CHIP:TOO: Missing cluster or command set name
Usage:
chip-tool cluster_name command_name [param1 param2 ...]
or:
chip-tool command_set_name command_name [param1 param2 ...]
+-------------------------------------------------------------------------------------+
| Clusters: |
+-------------------------------------------------------------------------------------+
| * accesscontrol |
| * accountlogin |
| * actions |
| * activatedcarbonfiltermonitoring |
| * administratorcommissioning |
| * airquality |
| * applicationbasic |
| * applicationlauncher |
| * audiooutput |
| * ballastconfiguration |
| * barriercontrol |
| * basicinformation |
| * binaryinputbasic |
| * binding |
| * booleansensorconfiguration |
| * booleanstate |
| * bridgeddevicebasicinformation |
| * carbondioxideconcentrationmeasurement |
| * carbonmonoxideconcentrationmeasurement |
| * channel |
| * colorcontrol |
| * contentappobserver |
| * contentcontrol |
| * contentlauncher |
| * demandresponseloadcontrol |
| * descriptor |
| * deviceenergymanagement |
| * diagnosticlogs |
| * dishwasheralarm |
| * dishwashermode |
| * doorlock |
| * electricalenergymeasurement |
| * electricalmeasurement |
| * energyevse |
| * ethernetnetworkdiagnostics |
| * fancontrol |
| * faultinjection |
| * fixedlabel |
| * flowmeasurement |
| * formaldehydeconcentrationmeasurement |
| * generalcommissioning |
| * generaldiagnostics |
| * groupkeymanagement |
| * groups |
| * hepafiltermonitoring |
| * icdmanagement |
| * identify |
| * illuminancemeasurement |
| * keypadinput |
| * laundrydryercontrols |
| * laundrywashercontrols |
| * laundrywashermode |
| * levelcontrol |
| * localizationconfiguration |
| * lowpower |
| * mediainput |
| * mediaplayback |
| * microwaveovencontrol |
| * microwaveovenmode |
| * modeselect |
| * networkcommissioning |
| * nitrogendioxideconcentrationmeasurement |
| * occupancysensing |
| * onoff |
| * onoffswitchconfiguration |
| * operationalcredentials |
| * operationalstate |
| * otasoftwareupdateprovider |
| * otasoftwareupdaterequestor |
| * ovencavityoperationalstate |
| * ovenmode |
| * ozoneconcentrationmeasurement |
| * pm10concentrationmeasurement |
| * pm1concentrationmeasurement |
| * pm25concentrationmeasurement |
| * powersource |
| * powersourceconfiguration |
| * pressuremeasurement |
| * proxyconfiguration |
| * proxydiscovery |
| * proxyvalid |
| * pulsewidthmodulation |
| * pumpconfigurationandcontrol |
| * radonconcentrationmeasurement |
| * refrigeratoralarm |
| * refrigeratorandtemperaturecontrolledcabinetmode |
| * relativehumiditymeasurement |
| * rvccleanmode |
| * rvcoperationalstate |
| * rvcrunmode |
| * samplemei |
| * scenes |
| * smokecoalarm |
| * softwarediagnostics |
| * switch |
| * targetnavigator |
| * temperaturecontrol |
| * temperaturemeasurement |
| * thermostat |
| * thermostatuserinterfaceconfiguration |
| * threadnetworkdiagnostics |
| * timeformatlocalization |
| * timesynchronization |
| * timer |
| * totalvolatileorganiccompoundsconcentrationmeasurement |
| * unitlocalization |
| * unittesting |
| * userlabel |
| * valveconfigurationandcontrol |
| * wakeonlan |
| * wifinetworkdiagnostics |
| * windowcovering |
+-------------------------------------------------------------------------------------+
+-------------------------------------------------------------------------------------+
| Command sets: |
+-------------------------------------------------------------------------------------+
| * any |
| - Commands for sending IM messages based on cluster id, not cluster name. |
| * delay |
| - Commands for waiting for something to happen. |
| * discover |
| - Commands for device discovery. |
| * groupsettings |
| - Commands for manipulating group keys and memberships for chip-tool itself. |
| * icd |
| - Commands for client-side ICD management. |
| * pairing |
| - Commands for commissioning devices. |
| * payload |
| - Commands for parsing and generating setup payloads. |
| * sessionmanagement |
| - Commands for managing CASE and PASE session state. |
| * subscriptions |
| - Commands for shutting down subscriptions. |
| * interactive |
| - Commands for starting long-lived interactive modes. |
| * storage |
| - Commands for managing persistent data stored by chip-tool. |
+-------------------------------------------------------------------------------------+
[1704260009.794483][46194:46194] CHIP:TOO: Run command failure: examples/chip-tool/commands/common/Commands.cpp:230: Error 0x0000002F
문법 <Syntax>
: $ ./chip-tool cluster_name command_name [param1 param2 ...]
$ ./chip-tool command_set_name command_name [param1 param2 ...]
chip-tool interactive 모드로 시작하기
더보기
connectedhomeip/BUILD_PATH$ ./chip-tool interactive start
[1704260907.286410][46422:46422] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704260907.286791][46422:46422] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704260907.286804][46422:46422] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704260907.288589][46422:46422] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704260907.288630][46422:46422] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704260907.288653][46422:46422] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704260907.288759][46422:46422] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-rC2nVI)
[1704260907.288880][46422:46422] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704260907.288890][46422:46422] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
[1704260907.289033][46422:46422] CHIP:DL: Got Ethernet interface: enp3s0
[1704260907.289135][46422:46422] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704260907.289273][46422:46422] CHIP:DL: Failed to get WiFi interface
[1704260907.289279][46422:46422] CHIP:DL: Failed to reset WiFi statistic counts
[1704260907.289289][46422:46422] CHIP:IN: UDP::Init bind&listen port=0
[1704260907.289312][46422:46422] CHIP:IN: UDP::Init bound to port=33212
[1704260907.289317][46422:46422] CHIP:IN: UDP::Init bind&listen port=0
[1704260907.289336][46422:46422] CHIP:IN: UDP::Init bound to port=60756
[1704260907.289340][46422:46422] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704260907.289344][46422:46422] CHIP:IN: TransportMgr initialized
[1704260907.289352][46422:46422] CHIP:FP: Initializing FabricTable from persistent storage
[1704260907.289374][46422:46422] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704260907.290765][46422:46422] CHIP:ZCL: Using ZAP configuration...
[1704260907.291193][46422:46422] CHIP:IN: CASE Server enabling CASE session setups
[1704260907.291212][46422:46422] CHIP:IN: SecureSession[0x55cf23da2160]: Allocated Type:2 LSID:28797
[1704260907.291225][46422:46422] CHIP:SC: Allocated SecureSession (0x55cf23da2160) - waiting for Sigma1 msg
[1704260907.291234][46422:46422] CHIP:CTL: System State Initialized...
[1704260907.291275][46422:46422] CHIP:CTL: Setting attestation nonce to random value
[1704260907.291283][46422:46422] CHIP:CTL: Setting CSR nonce to random value
[1704260907.291296][46422:46422] CHIP:IN: UDP::Init bind&listen port=5550
[1704260907.291315][46422:46422] CHIP:IN: UDP::Init bound to port=5550
[1704260907.291324][46422:46422] CHIP:IN: UDP::Init bind&listen port=5550
[1704260907.291340][46422:46422] CHIP:IN: UDP::Init bound to port=5550
[1704260907.291345][46422:46422] CHIP:IN: TransportMgr initialized
[1704260907.291401][46422:46424] CHIP:DL: CHIP task running
[1704260907.291422][46422:46424] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
chip-tool 사용법
pairing ble-wifi
: wifi end 장치에 대한 커미션닝을 시작합니다.
: $ ./chip-tool pairing ble-wifi node-id ssid pasword setup-pin-code discriminator
node-id : 적당히 64bit 짜리로 만드시면 됩니다.
ssid : 사용하는 WIFI SSID
password : 사용하는 WIFI 패스워드
setup-pin-code , discriminator : matter config 명령으로 확인 할수 있습니다. (esp32 matter light 프로젝트)
참조 사이트
더보기
./chip-tool pairing ble-wifi 0x1234 NETGEAR xxxx0000 20202021 3840
[1704334400.617581][3448:3448] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704334400.618013][3448:3448] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704334400.618021][3448:3448] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704334400.619704][3448:3448] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704334400.619742][3448:3448] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704334400.619764][3448:3448] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704334400.619834][3448:3448] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-ycFd65)
[1704334400.619933][3448:3448] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704334400.619943][3448:3448] CHIP:DL: NVS set: chip-counters/reboot-count = 2 (0x2)
~~ 중략 ~~
[1704334405.300651][3448:3450] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1704334405.300681][3448:3450] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ReadCommissioningInfo2'
[1704334405.300706][3448:3450] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo2'
[1704334405.300738][3448:3450] CHIP:DMG: SendReadRequest ReadClient[0x7fe74800a6f0]: Sending Read Request
[1704334405.300851][3448:3450] CHIP:EM: <<< [E:27010i S:13553 M:191384177] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:02 (IM:ReadRequest)
[1704334405.301173][3448:3450] CHIP:DMG: MoveToState ReadClient[0x7fe74800a6f0]: Moving to [AwaitingIn]
[1704334405.387379][3448:3450] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1704334405.388026][3448:3449] CHIP:DL: Indication received, conn = 0x7fe74001ea10
[1704334405.388187][3448:3450] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1704334405.388347][3448:3450] CHIP:EM: >>> [E:27010i S:13553 M:145010076] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1704334405.388383][3448:3450] CHIP:EM: Found matching exchange: 27010i, Delegate: 0x7fe74800a700
[1704334405.388453][3448:3450] CHIP:DMG: ReportDataMessage =
[1704334405.388477][3448:3450] CHIP:DMG: {
[1704334405.388497][3448:3450] CHIP:DMG: AttributeReportIBs =
[1704334405.388526][3448:3450] CHIP:DMG: [
[1704334405.388545][3448:3450] CHIP:DMG: AttributeReportIB =
[1704334405.388576][3448:3450] CHIP:DMG: {
[1704334405.388595][3448:3450] CHIP:DMG: AttributeStatusIB =
[1704334405.388617][3448:3450] CHIP:DMG: {
[1704334405.388637][3448:3450] CHIP:DMG: AttributePathIB =
[1704334405.388658][3448:3450] CHIP:DMG: {
[1704334405.388681][3448:3450] CHIP:DMG: Endpoint = 0x0,
[1704334405.388702][3448:3450] CHIP:DMG: Cluster = 0x46,
[1704334405.388724][3448:3450] CHIP:DMG: Attribute = 0x0000_FFFC,
[1704334405.388743][3448:3450] CHIP:DMG: }
[1704334405.388770][3448:3450] CHIP:DMG:
[1704334405.388790][3448:3450] CHIP:DMG: StatusIB =
[1704334405.388811][3448:3450] CHIP:DMG: {
[1704334405.388833][3448:3450] CHIP:DMG: status = 0xc3 (UNSUPPORTED_CLUSTER),
[1704334405.388852][3448:3450] CHIP:DMG: },
[1704334405.388874][3448:3450] CHIP:DMG:
[1704334405.388894][3448:3450] CHIP:DMG: },
[1704334405.388920][3448:3450] CHIP:DMG:
[1704334405.388939][3448:3450] CHIP:DMG: },
[1704334405.388974][3448:3450] CHIP:DMG:
[1704334405.388993][3448:3450] CHIP:DMG: AttributeReportIB =
[1704334405.389019][3448:3450] CHIP:DMG: {
[1704334405.389039][3448:3450] CHIP:DMG: AttributeDataIB =
[1704334405.389059][3448:3450] CHIP:DMG: {
[1704334405.389080][3448:3450] CHIP:DMG: DataVersion = 0x218a75ae,
[1704334405.389100][3448:3450] CHIP:DMG: AttributePathIB =
[1704334405.389120][3448:3450] CHIP:DMG: {
[1704334405.389141][3448:3450] CHIP:DMG: Endpoint = 0x0,
[1704334405.389161][3448:3450] CHIP:DMG: Cluster = 0x30,
[1704334405.389182][3448:3450] CHIP:DMG: Attribute = 0x0000_0004,
[1704334405.389201][3448:3450] CHIP:DMG: }
[1704334405.389224][3448:3450] CHIP:DMG:
[1704334405.389246][3448:3450] CHIP:DMG: Data = true,
[1704334405.389266][3448:3450] CHIP:DMG: },
[1704334405.389291][3448:3450] CHIP:DMG:
[1704334405.389309][3448:3450] CHIP:DMG: },
[1704334405.389335][3448:3450] CHIP:DMG:
[1704334405.389354][3448:3450] CHIP:DMG: ],
[1704334405.389387][3448:3450] CHIP:DMG:
[1704334405.389408][3448:3450] CHIP:DMG: SuppressResponse = true,
[1704334405.389428][3448:3450] CHIP:DMG: InteractionModelRevision = 11
[1704334405.389447][3448:3450] CHIP:DMG: }
[1704334405.389852][3448:3450] CHIP:CTL: ----- NetworkCommissioning Features: has WiFi. endpointid = 0
[1704334405.389934][3448:3450] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo2'
[1704334405.389964][3448:3450] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo2' -> 'ArmFailSafe'
[1704334405.390018][3448:3450] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1704334405.390043][3448:3450] CHIP:CTL: Arming failsafe (60 seconds)
[1704334405.390099][3448:3450] CHIP:DMG: ICR moving to [AddingComm]
[1704334405.390128][3448:3450] CHIP:DMG: ICR moving to [AddedComma]
[1704334405.390218][3448:3450] CHIP:EM: <<< [E:27011i S:13553 M:191384178] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704334405.390833][3448:3450] CHIP:DMG: ICR moving to [CommandSen]
[1704334405.475362][3448:3450] CHIP:DL: HandlePlatformSpecificBLEEvent 16387
[1704334405.523900][3448:3449] CHIP:DL: Indication received, conn = 0x7fe74001ea10
[1704334405.524081][3448:3450] CHIP:DL: HandlePlatformSpecificBLEEvent 16389
[1704334405.524240][3448:3450] CHIP:EM: >>> [E:27011i S:13553 M:145010077] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704334405.524276][3448:3450] CHIP:EM: Found matching exchange: 27011i, Delegate: 0x7fe74800a6f8
[1704334405.524308][3448:3450] CHIP:DMG: ICR moving to [ResponseRe]
[1704334405.524359][3448:3450] CHIP:DMG: InvokeResponseMessage =
[1704334405.524380][3448:3450] CHIP:DMG: {
[1704334405.524402][3448:3450] CHIP:DMG: suppressResponse = false,
[1704334405.524421][3448:3450] CHIP:DMG: InvokeResponseIBs =
[1704334405.524454][3448:3450] CHIP:DMG: [
[1704334405.524473][3448:3450] CHIP:DMG: InvokeResponseIB =
[1704334405.524502][3448:3450] CHIP:DMG: {
[1704334405.524522][3448:3450] CHIP:DMG: CommandDataIB =
[1704334405.524543][3448:3450] CHIP:DMG: {
[1704334405.524562][3448:3450] CHIP:DMG: CommandPathIB =
[1704334405.524584][3448:3450] CHIP:DMG: {
[1704334405.524606][3448:3450] CHIP:DMG: EndpointId = 0x0,
[1704334405.524627][3448:3450] CHIP:DMG: ClusterId = 0x30,
[1704334405.524647][3448:3450] CHIP:DMG: CommandId = 0x1,
[1704334405.524666][3448:3450] CHIP:DMG: },
[1704334405.524689][3448:3450] CHIP:DMG:
[1704334405.524710][3448:3450] CHIP:DMG: CommandFields =
[1704334405.524731][3448:3450] CHIP:DMG: {
[1704334405.524754][3448:3450] CHIP:DMG: 0x0 = 0,
[1704334405.524777][3448:3450] CHIP:DMG: 0x1 = "" (0 chars),
[1704334405.524797][3448:3450] CHIP:DMG: },
[1704334405.524816][3448:3450] CHIP:DMG: },
[1704334405.524842][3448:3450] CHIP:DMG:
[1704334405.524861][3448:3450] CHIP:DMG: },
[1704334405.524888][3448:3450] CHIP:DMG:
[1704334405.524907][3448:3450] CHIP:DMG: ],
[1704334405.524935][3448:3450] CHIP:DMG:
[1704334405.524955][3448:3450] CHIP:DMG: InteractionModelRevision = 11
[1704334405.524974][3448:3450] CHIP:DMG: },
[1704334405.525049][3448:3450] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1704334405.525086][3448:3450] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1704334405.525117][3448:3450] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
~~ 중략 ~~
[1704334411.299308][3448:3450] CHIP:DMG: InvokeResponseMessage =
[1704334411.299330][3448:3450] CHIP:DMG: {
[1704334411.299351][3448:3450] CHIP:DMG: suppressResponse = false,
[1704334411.299371][3448:3450] CHIP:DMG: InvokeResponseIBs =
[1704334411.299400][3448:3450] CHIP:DMG: [
[1704334411.299419][3448:3450] CHIP:DMG: InvokeResponseIB =
[1704334411.299449][3448:3450] CHIP:DMG: {
[1704334411.299468][3448:3450] CHIP:DMG: CommandDataIB =
[1704334411.299489][3448:3450] CHIP:DMG: {
[1704334411.299509][3448:3450] CHIP:DMG: CommandPathIB =
[1704334411.299530][3448:3450] CHIP:DMG: {
[1704334411.299552][3448:3450] CHIP:DMG: EndpointId = 0x0,
[1704334411.299573][3448:3450] CHIP:DMG: ClusterId = 0x30,
[1704334411.299593][3448:3450] CHIP:DMG: CommandId = 0x5,
[1704334411.299639][3448:3450] CHIP:DMG: },
[1704334411.299664][3448:3450] CHIP:DMG:
[1704334411.299684][3448:3450] CHIP:DMG: CommandFields =
[1704334411.299705][3448:3450] CHIP:DMG: {
[1704334411.299728][3448:3450] CHIP:DMG: 0x0 = 0,
[1704334411.299750][3448:3450] CHIP:DMG: 0x1 = "" (0 chars),
[1704334411.299771][3448:3450] CHIP:DMG: },
[1704334411.299790][3448:3450] CHIP:DMG: },
[1704334411.299816][3448:3450] CHIP:DMG:
[1704334411.299835][3448:3450] CHIP:DMG: },
[1704334411.299861][3448:3450] CHIP:DMG:
[1704334411.299880][3448:3450] CHIP:DMG: ],
[1704334411.299909][3448:3450] CHIP:DMG:
[1704334411.299929][3448:3450] CHIP:DMG: InteractionModelRevision = 11
[1704334411.299947][3448:3450] CHIP:DMG: },
[1704334411.300034][3448:3450] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
[1704334411.300071][3448:3450] CHIP:CTL: Received CommissioningComplete response, errorCode=0
[1704334411.300100][3448:3450] CHIP:CTL: Successfully finished commissioning step 'SendComplete'
[1704334411.300120][3448:3450] CHIP:CTL: Commissioning stage next step: 'SendComplete' -> 'Cleanup'
[1704334411.300151][3448:3450] CHIP:CTL: Performing next commissioning step 'Cleanup'
[1704334411.300174][3448:3450] CHIP:DIS: Closing all BLE connections
[1704334411.300196][3448:3450] CHIP:IN: Clearing BLE pending packets.
[1704334411.300568][3448:3450] CHIP:BLE: Auto-closing end point's BLE connection.
[1704334411.300610][3448:3450] CHIP:DL: Closing BLE GATT connection (con 0x7fe74001ea10)
[1704334411.300762][3448:3449] CHIP:DL: BluezDisconnect peer=D9:E0:33:7D:DE:FA
[1704334413.887770][3448:3450] CHIP:IN: SecureSession[0x7fe7480100f0]: MarkForEviction Type:1 LSID:13553
[1704334413.887831][3448:3450] CHIP:SC: SecureSession[0x7fe7480100f0, LSID:13553]: State change 'kActive' --> 'kPendingEviction'
[1704334413.887776][3448:3449] CHIP:DL: No wifi interface name. Ignoring IP update event.
[1704334413.887897][3448:3450] CHIP:IN: SecureSession[0x7fe7480100f0]: Released - Type:1 LSID:13553
[1704334413.888043][3448:3450] CHIP:CTL: Successfully finished commissioning step 'Cleanup'
[1704334413.888085][3448:3450] CHIP:TOO: Device commissioning completed with success
[1704334413.888186][3448:3450] CHIP:DMG: ICR moving to [AwaitingDe]
[1704334413.888394][3448:3450] CHIP:EM: <<< [E:27023i S:13554 M:215105095 (Ack:176725486)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704334413.888498][3448:3450] CHIP:EM: Flushed pending ack for MessageCounter:176725486 on exchange 27023i
[1704334413.888537][3448:3449] CHIP:DL: Bluez disconnected
[1704334413.888579][3448:3449] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1704334413.888539][3448:3450] CHIP:DL: HandlePlatformSpecificBLEEvent 16388
[1704334413.888683][3448:3450] CHIP:BLE: no endpoint for unsub complete
[1704334413.888955][3448:3448] CHIP:CTL: Shutting down the commissioner
[1704334413.889056][3448:3448] CHIP:CTL: Shutting down the controller
[1704334413.889083][3448:3448] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704334413.889105][3448:3448] CHIP:IN: SecureSession[0x7fe748026390]: MarkForEviction Type:2 LSID:13554
[1704334413.889125][3448:3448] CHIP:SC: SecureSession[0x7fe748026390, LSID:13554]: State change 'kActive' --> 'kPendingEviction'
[1704334413.889146][3448:3448] CHIP:IN: SecureSession[0x7fe748026390]: Released - Type:2 LSID:13554
[1704334413.889170][3448:3448] CHIP:FP: Forgetting fabric 0x1
[1704334413.889199][3448:3448] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704334413.889354][3448:3448] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704334413.889377][3448:3448] CHIP:TS: Reverted Last Known Good Time to previous value
[1704334413.889415][3448:3448] CHIP:CTL: Shutting down the commissioner
[1704334413.889475][3448:3448] CHIP:CTL: Shutting down the controller
[1704334413.889494][3448:3448] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704334413.889630][3448:3448] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704334413.889708][3448:3448] CHIP:FP: Shutting down FabricTable
[1704334413.889732][3448:3448] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704334413.889839][3448:3448] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704334413.889860][3448:3448] CHIP:TS: Reverted Last Known Good Time to previous value
[1704334413.890054][3448:3448] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-UEFw7V)
[1704334413.890518][3448:3448] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704334413.890570][3448:3448] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704334413.890593][3448:3448] CHIP:DL: Inet Layer shutdown
[1704334413.890612][3448:3448] CHIP:DL: BLE shutdown
[1704334413.892273][3448:3448] CHIP:DL: System Layer shutdown
pairing unpair
더보기
$ ./chip-tool pairing unpair 0x1234
[1704337604.135827][7023:7023] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704337604.136263][7023:7023] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704337604.136275][7023:7023] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704337604.138008][7023:7023] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704337604.138045][7023:7023] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704337604.138067][7023:7023] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704337604.138146][7023:7023] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Zh4X5w)
[1704337604.138359][7023:7023] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704337604.138385][7023:7023] CHIP:DL: NVS set: chip-counters/reboot-count = 3 (0x3)
[1704337604.138538][7023:7023] CHIP:DL: Got Ethernet interface: enp3s0
[1704337604.138658][7023:7023] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704337604.138802][7023:7023] CHIP:DL: Failed to get WiFi interface
[1704337604.138807][7023:7023] CHIP:DL: Failed to reset WiFi statistic counts
[1704337604.138818][7023:7023] CHIP:IN: UDP::Init bind&listen port=0
[1704337604.138840][7023:7023] CHIP:IN: UDP::Init bound to port=36631
[1704337604.138844][7023:7023] CHIP:IN: UDP::Init bind&listen port=0
[1704337604.138862][7023:7023] CHIP:IN: UDP::Init bound to port=42794
[1704337604.138867][7023:7023] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704337604.138871][7023:7023] CHIP:IN: TransportMgr initialized
[1704337604.138878][7023:7023] CHIP:FP: Initializing FabricTable from persistent storage
[1704337604.138914][7023:7023] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704337604.139355][7023:7023] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7EC96ABB43EBB1E9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704337604.140136][7023:7023] CHIP:ZCL: Using ZAP configuration...
[1704337604.140552][7023:7023] CHIP:CTL: System State Initialized...
[1704337604.140618][7023:7023] CHIP:CTL: Setting attestation nonce to random value
[1704337604.140627][7023:7023] CHIP:CTL: Setting CSR nonce to random value
[1704337604.140639][7023:7023] CHIP:IN: UDP::Init bind&listen port=5550
[1704337604.140695][7023:7023] CHIP:IN: UDP::Init bound to port=5550
[1704337604.140705][7023:7023] CHIP:IN: UDP::Init bind&listen port=5550
[1704337604.140720][7023:7023] CHIP:IN: UDP::Init bound to port=5550
[1704337604.140747][7023:7023] CHIP:IN: TransportMgr initialized
[1704337604.140891][7023:7025] CHIP:DL: CHIP task running
[1704337604.140910][7023:7025] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704337604.140987][7023:7025] CHIP:CTL: Setting attestation nonce to random value
[1704337604.141012][7023:7025] CHIP:CTL: Setting CSR nonce to random value
[1704337604.141234][7023:7025] CHIP:CTL: Generating NOC
[1704337604.141451][7023:7025] CHIP:FP: Validating NOC chain
[1704337604.141806][7023:7025] CHIP:FP: NOC chain validation successful
[1704337604.141843][7023:7025] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704337604.141849][7023:7025] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704337604.141853][7023:7025] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704337604.141857][7023:7025] CHIP:TS: Retaining current Last Known Good Time
[1704337604.142688][7023:7025] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704337604.143005][7023:7025] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704337604.143306][7023:7025] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 7EC96ABB43EBB1E9)
[1704337604.143314][7023:7025] CHIP:IN: UDP::Init bind&listen port=5550
[1704337604.143334][7023:7025] CHIP:IN: UDP::Init bound to port=5550
[1704337604.143339][7023:7025] CHIP:IN: UDP::Init bind&listen port=5550
[1704337604.143355][7023:7025] CHIP:IN: UDP::Init bound to port=5550
[1704337604.143359][7023:7025] CHIP:IN: TransportMgr initialized
[1704337604.146360][7023:7025] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704337604.146368][7023:7025] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704337604.146375][7023:7025] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 2
[1704337604.231611][7023:7025] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704337604.231648][7023:7025] CHIP:DIS: Lookup clearing interface for non LL address
[1704337604.231702][7023:7025] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704337604.231725][7023:7025] CHIP:DIS: Checking node lookup status after 85 ms
[1704337604.231743][7023:7025] CHIP:DIS: Keeping DNSSD lookup active
[1704337604.231910][7023:7025] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704337604.231936][7023:7025] CHIP:DIS: Lookup clearing interface for non LL address
[1704337604.231983][7023:7025] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704337604.232005][7023:7025] CHIP:DIS: Checking node lookup status after 85 ms
[1704337604.232025][7023:7025] CHIP:DIS: Keeping DNSSD lookup active
[1704337604.347260][7023:7025] CHIP:DIS: Checking node lookup status after 201 ms
[1704337604.347357][7023:7025] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: Updating device address to UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540 while in state 2
[1704337604.347384][7023:7025] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 2 --> 3
[1704337604.347515][7023:7025] CHIP:IN: SecureSession[0x7f085800ed30]: Allocated Type:2 LSID:61170
[1704337604.347555][7023:7025] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000001234
[1704337604.348462][7023:7025] CHIP:EM: <<< [E:40989i S:0 M:189891856] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704337604.348587][7023:7025] CHIP:SC: Sent Sigma1 msg
[1704337604.348615][7023:7025] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 3 --> 4
[1704337604.438553][7023:7025] CHIP:EM: >>> [E:40989i S:0 M:175776569 (Ack:189891856)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704337604.438607][7023:7025] CHIP:EM: Found matching exchange: 40989i, Delegate: 0x7f085800ea88
[1704337604.438661][7023:7025] CHIP:EM: Rxd Ack; Removing MessageCounter:189891856 from Retrans Table on exchange 40989i
[1704337604.500810][7023:7025] CHIP:EM: >>> [E:40989i S:0 M:175776570 (Ack:189891856)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704337604.500862][7023:7025] CHIP:EM: Found matching exchange: 40989i, Delegate: 0x7f085800ea88
[1704337604.500901][7023:7025] CHIP:EM: CHIP MessageCounter:189891856 not in RetransTable on exchange 40989i
[1704337604.500969][7023:7025] CHIP:SC: Received Sigma2 msg
[1704337604.501014][7023:7025] CHIP:SC: Peer assigned session session ID 41401
[1704337604.505131][7023:7025] CHIP:SC: Found MRP parameters in the message
[1704337604.505199][7023:7025] CHIP:SC: Sending Sigma3
[1704337604.505901][7023:7025] CHIP:EM: <<< [E:40989i S:0 M:189891857 (Ack:175776570)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704337604.506058][7023:7025] CHIP:SC: Sent Sigma3 msg
[1704337604.537959][7023:7025] CHIP:EM: >>> [E:40989i S:0 M:175776571 (Ack:189891857)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704337604.537982][7023:7025] CHIP:EM: Found matching exchange: 40989i, Delegate: 0x7f085800ea88
[1704337604.538005][7023:7025] CHIP:EM: Rxd Ack; Removing MessageCounter:189891857 from Retrans Table on exchange 40989i
[1704337604.661689][7023:7025] CHIP:EM: >>> [E:40989i S:0 M:175776572 (Ack:189891857)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704337604.661739][7023:7025] CHIP:EM: Found matching exchange: 40989i, Delegate: 0x7f085800ea88
[1704337604.661776][7023:7025] CHIP:EM: CHIP MessageCounter:189891857 not in RetransTable on exchange 40989i
[1704337604.661845][7023:7025] CHIP:SC: Success status report received. Session was established
[1704337604.665777][7023:7025] CHIP:SC: SecureSession[0x7f085800ed30, LSID:61170]: State change 'kEstablishing' --> 'kActive'
[1704337604.665821][7023:7025] CHIP:IN: SecureSession[0x7f085800ed30]: Activated - Type:2 LSID:61170
[1704337604.665852][7023:7025] CHIP:IN: New secure session activated for device <0000000000001234, 1>, LSID:61170 PSID:41401!
[1704337604.665897][7023:7025] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 4 --> 5
[1704337604.666039][7023:7025] CHIP:DMG: SendReadRequest ReadClient[0x7f085800a6f0]: Sending Read Request
[1704337604.666342][7023:7025] CHIP:EM: <<< [E:40990i S:61170 M:251013544] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:02 (IM:ReadRequest)
[1704337604.666507][7023:7025] CHIP:DMG: MoveToState ReadClient[0x7f085800a6f0]: Moving to [AwaitingIn]
[1704337604.666654][7023:7025] CHIP:EM: <<< [E:40989i S:0 M:189891858 (Ack:175776572)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704337604.666752][7023:7025] CHIP:EM: Flushed pending ack for MessageCounter:175776572 on exchange 40989i
[1704337604.732004][7023:7025] CHIP:EM: >>> [E:40990i S:61170 M:30316462 (Ack:251013544)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0001:05 (IM:ReportData)
[1704337604.732055][7023:7025] CHIP:EM: Found matching exchange: 40990i, Delegate: 0x7f085800a700
[1704337604.732089][7023:7025] CHIP:EM: Rxd Ack; Removing MessageCounter:251013544 from Retrans Table on exchange 40990i
[1704337604.732153][7023:7025] CHIP:DMG: ReportDataMessage =
[1704337604.732177][7023:7025] CHIP:DMG: {
[1704337604.732197][7023:7025] CHIP:DMG: AttributeReportIBs =
[1704337604.732229][7023:7025] CHIP:DMG: [
[1704337604.732249][7023:7025] CHIP:DMG: AttributeReportIB =
[1704337604.732281][7023:7025] CHIP:DMG: {
[1704337604.732302][7023:7025] CHIP:DMG: AttributeDataIB =
[1704337604.732340][7023:7025] CHIP:DMG: {
[1704337604.732365][7023:7025] CHIP:DMG: DataVersion = 0xfeed88bb,
[1704337604.732399][7023:7025] CHIP:DMG: AttributePathIB =
[1704337604.732434][7023:7025] CHIP:DMG: {
[1704337604.732459][7023:7025] CHIP:DMG: Endpoint = 0x0,
[1704337604.732494][7023:7025] CHIP:DMG: Cluster = 0x3e,
[1704337604.732529][7023:7025] CHIP:DMG: Attribute = 0x0000_0005,
[1704337604.732641][7023:7025] CHIP:DMG: }
[1704337604.732675][7023:7025] CHIP:DMG:
[1704337604.732701][7023:7025] CHIP:DMG: Data = 1,
[1704337604.732724][7023:7025] CHIP:DMG: },
[1704337604.732753][7023:7025] CHIP:DMG:
[1704337604.732780][7023:7025] CHIP:DMG: },
[1704337604.732817][7023:7025] CHIP:DMG:
[1704337604.732838][7023:7025] CHIP:DMG: ],
[1704337604.732877][7023:7025] CHIP:DMG:
[1704337604.732944][7023:7025] CHIP:DMG: SuppressResponse = true,
[1704337604.732967][7023:7025] CHIP:DMG: InteractionModelRevision = 11
[1704337604.732990][7023:7025] CHIP:DMG: }
[1704337604.733172][7023:7025] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704337604.733197][7023:7025] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704337604.733228][7023:7025] CHIP:DIS: Found an existing secure session to [1:0000000000001234]!
[1704337604.733291][7023:7025] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 5
[1704337604.733376][7023:7025] CHIP:DMG: ICR moving to [AddingComm]
[1704337604.733443][7023:7025] CHIP:DMG: ICR moving to [AddedComma]
[1704337604.733654][7023:7025] CHIP:EM: <<< [E:40991i S:61170 M:251013545] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704337604.733795][7023:7025] CHIP:DMG: ICR moving to [CommandSen]
[1704337604.734024][7023:7025] CHIP:EM: <<< [E:40990i S:61170 M:251013546 (Ack:30316462)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704337604.734110][7023:7025] CHIP:EM: Flushed pending ack for MessageCounter:30316462 on exchange 40990i
[1704337604.791645][7023:7025] CHIP:EM: >>> [E:40991i S:61170 M:30316463 (Ack:251013545)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704337604.791694][7023:7025] CHIP:EM: Found matching exchange: 40991i, Delegate: 0x7f08580094f8
[1704337604.791729][7023:7025] CHIP:EM: Rxd Ack; Removing MessageCounter:251013545 from Retrans Table on exchange 40991i
[1704337604.908479][7023:7025] CHIP:EM: >>> [E:40991i S:61170 M:30316464 (Ack:251013545)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704337604.908530][7023:7025] CHIP:EM: Found matching exchange: 40991i, Delegate: 0x7f08580094f8
[1704337604.908555][7023:7025] CHIP:EM: CHIP MessageCounter:251013545 not in RetransTable on exchange 40991i
[1704337604.908589][7023:7025] CHIP:DMG: ICR moving to [ResponseRe]
[1704337604.908639][7023:7025] CHIP:DMG: InvokeResponseMessage =
[1704337604.908661][7023:7025] CHIP:DMG: {
[1704337604.908682][7023:7025] CHIP:DMG: suppressResponse = false,
[1704337604.908701][7023:7025] CHIP:DMG: InvokeResponseIBs =
[1704337604.908736][7023:7025] CHIP:DMG: [
[1704337604.908756][7023:7025] CHIP:DMG: InvokeResponseIB =
[1704337604.908785][7023:7025] CHIP:DMG: {
[1704337604.908804][7023:7025] CHIP:DMG: CommandDataIB =
[1704337604.908828][7023:7025] CHIP:DMG: {
[1704337604.908850][7023:7025] CHIP:DMG: CommandPathIB =
[1704337604.908876][7023:7025] CHIP:DMG: {
[1704337604.908902][7023:7025] CHIP:DMG: EndpointId = 0x0,
[1704337604.908927][7023:7025] CHIP:DMG: ClusterId = 0x3e,
[1704337604.908951][7023:7025] CHIP:DMG: CommandId = 0x8,
[1704337604.908974][7023:7025] CHIP:DMG: },
[1704337604.909117][7023:7025] CHIP:DMG:
[1704337604.909141][7023:7025] CHIP:DMG: CommandFields =
[1704337604.909166][7023:7025] CHIP:DMG: {
[1704337604.909193][7023:7025] CHIP:DMG: 0x0 = 0,
[1704337604.909218][7023:7025] CHIP:DMG: 0x1 = 1,
[1704337604.909242][7023:7025] CHIP:DMG: },
[1704337604.909265][7023:7025] CHIP:DMG: },
[1704337604.909294][7023:7025] CHIP:DMG:
[1704337604.909315][7023:7025] CHIP:DMG: },
[1704337604.909345][7023:7025] CHIP:DMG:
[1704337604.909365][7023:7025] CHIP:DMG: ],
[1704337604.909395][7023:7025] CHIP:DMG:
[1704337604.909417][7023:7025] CHIP:DMG: InteractionModelRevision = 11
[1704337604.909437][7023:7025] CHIP:DMG: },
[1704337604.909514][7023:7025] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1704337604.909598][7023:7025] CHIP:CTL: Remove Current Fabric Result : src/controller/CurrentFabricRemover.cpp:133: Success
[1704337604.909621][7023:7025] CHIP:TOO: Device unpair completed with success: 0000000000001234
[1704337604.909685][7023:7025] CHIP:DMG: ICR moving to [AwaitingDe]
[1704337604.909836][7023:7025] CHIP:EM: <<< [E:40991i S:61170 M:251013547 (Ack:30316464)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704337604.909932][7023:7025] CHIP:EM: Flushed pending ack for MessageCounter:30316464 on exchange 40991i
[1704337604.910210][7023:7023] CHIP:CTL: Shutting down the commissioner
[1704337604.910365][7023:7023] CHIP:CTL: Shutting down the controller
[1704337604.910411][7023:7023] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704337604.910432][7023:7023] CHIP:IN: SecureSession[0x7f085800ed30]: MarkForEviction Type:2 LSID:61170
[1704337604.910453][7023:7023] CHIP:SC: SecureSession[0x7f085800ed30, LSID:61170]: State change 'kActive' --> 'kPendingEviction'
[1704337604.910477][7023:7023] CHIP:IN: SecureSession[0x7f085800ed30]: Released - Type:2 LSID:61170
[1704337604.910501][7023:7023] CHIP:FP: Forgetting fabric 0x1
[1704337604.910531][7023:7023] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704337604.910697][7023:7023] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704337604.910720][7023:7023] CHIP:TS: Reverted Last Known Good Time to previous value
[1704337604.910758][7023:7023] CHIP:CTL: Shutting down the commissioner
[1704337604.910826][7023:7023] CHIP:CTL: Shutting down the controller
[1704337604.910857][7023:7023] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704337604.911010][7023:7023] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704337604.911088][7023:7023] CHIP:FP: Shutting down FabricTable
[1704337604.911114][7023:7023] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704337604.911270][7023:7023] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704337604.911301][7023:7023] CHIP:TS: Reverted Last Known Good Time to previous value
[1704337604.911507][7023:7023] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-rEdBOY)
[1704337604.914154][7023:7023] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704337604.914215][7023:7023] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704337604.914240][7023:7023] CHIP:DL: Inet Layer shutdown
[1704337604.914284][7023:7023] CHIP:DL: BLE shutdown
[1704337604.914307][7023:7023] CHIP:DL: System Layer shutdown
onoff toggle
: onoff 클러스터의 현재 LED 상태를 반전시켜 줍니다.
$ ./chip-tool onoff toggle <node-id> <endpoint-id>
더보기
$ ./chip-tool onoff toggle 0x1234 1
[1704338603.688942][9739:9739] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704338603.689319][9739:9739] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704338603.689331][9739:9739] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704338603.691114][9739:9739] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704338603.691151][9739:9739] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704338603.691174][9739:9739] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704338603.691249][9739:9739] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-QovExS)
[1704338603.691422][9739:9739] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704338603.691432][9739:9739] CHIP:DL: NVS set: chip-counters/reboot-count = 11 (0xB)
[1704338603.691621][9739:9739] CHIP:DL: Got Ethernet interface: enp3s0
[1704338603.691717][9739:9739] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704338603.691854][9739:9739] CHIP:DL: Failed to get WiFi interface
[1704338603.691859][9739:9739] CHIP:DL: Failed to reset WiFi statistic counts
[1704338603.691870][9739:9739] CHIP:IN: UDP::Init bind&listen port=0
[1704338603.691892][9739:9739] CHIP:IN: UDP::Init bound to port=58047
[1704338603.691897][9739:9739] CHIP:IN: UDP::Init bind&listen port=0
[1704338603.691915][9739:9739] CHIP:IN: UDP::Init bound to port=36460
[1704338603.691919][9739:9739] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704338603.691924][9739:9739] CHIP:IN: TransportMgr initialized
[1704338603.691933][9739:9739] CHIP:FP: Initializing FabricTable from persistent storage
[1704338603.691969][9739:9739] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704338603.692383][9739:9739] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7EC96ABB43EBB1E9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704338603.695355][9739:9739] CHIP:ZCL: Using ZAP configuration...
[1704338603.695805][9739:9739] CHIP:CTL: System State Initialized...
[1704338603.695844][9739:9739] CHIP:CTL: Setting attestation nonce to random value
[1704338603.695853][9739:9739] CHIP:CTL: Setting CSR nonce to random value
[1704338603.695866][9739:9739] CHIP:IN: UDP::Init bind&listen port=5550
[1704338603.695883][9739:9739] CHIP:IN: UDP::Init bound to port=5550
[1704338603.695892][9739:9739] CHIP:IN: UDP::Init bind&listen port=5550
[1704338603.695907][9739:9739] CHIP:IN: UDP::Init bound to port=5550
[1704338603.695911][9739:9739] CHIP:IN: TransportMgr initialized
[1704338603.695966][9739:9741] CHIP:DL: CHIP task running
[1704338603.695988][9739:9741] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704338603.696066][9739:9741] CHIP:CTL: Setting attestation nonce to random value
[1704338603.696092][9739:9741] CHIP:CTL: Setting CSR nonce to random value
[1704338603.696330][9739:9741] CHIP:CTL: Generating NOC
[1704338603.696563][9739:9741] CHIP:FP: Validating NOC chain
[1704338603.696934][9739:9741] CHIP:FP: NOC chain validation successful
[1704338603.696971][9739:9741] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704338603.696977][9739:9741] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704338603.696982][9739:9741] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704338603.696987][9739:9741] CHIP:TS: Retaining current Last Known Good Time
[1704338603.697859][9739:9741] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704338603.698213][9739:9741] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704338603.698577][9739:9741] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 7EC96ABB43EBB1E9)
[1704338603.698585][9739:9741] CHIP:IN: UDP::Init bind&listen port=5550
[1704338603.698605][9739:9741] CHIP:IN: UDP::Init bound to port=5550
[1704338603.698610][9739:9741] CHIP:IN: UDP::Init bind&listen port=5550
[1704338603.698641][9739:9741] CHIP:IN: UDP::Init bound to port=5550
[1704338603.698646][9739:9741] CHIP:IN: TransportMgr initialized
[1704338603.701714][9739:9741] CHIP:TOO: Sending command to node 0x1234
[1704338603.701808][9739:9741] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704338603.701827][9739:9741] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704338603.701834][9739:9741] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 2
[1704338603.749928][9739:9741] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704338603.749940][9739:9741] CHIP:DIS: Lookup clearing interface for non LL address
[1704338603.749957][9739:9741] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704338603.749964][9739:9741] CHIP:DIS: Checking node lookup status after 48 ms
[1704338603.749970][9739:9741] CHIP:DIS: Keeping DNSSD lookup active
[1704338603.750016][9739:9741] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704338603.750029][9739:9741] CHIP:DIS: Lookup clearing interface for non LL address
[1704338603.750045][9739:9741] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704338603.750052][9739:9741] CHIP:DIS: Checking node lookup status after 48 ms
[1704338603.750059][9739:9741] CHIP:DIS: Keeping DNSSD lookup active
[1704338603.902319][9739:9741] CHIP:DIS: Checking node lookup status after 201 ms
[1704338603.902422][9739:9741] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: Updating device address to UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540 while in state 2
[1704338603.902450][9739:9741] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 2 --> 3
[1704338603.902595][9739:9741] CHIP:IN: SecureSession[0x7ff5a800ed30]: Allocated Type:2 LSID:21174
[1704338603.902645][9739:9741] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000001234
[1704338603.903631][9739:9741] CHIP:EM: <<< [E:18889i S:0 M:218330495] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704338603.903770][9739:9741] CHIP:SC: Sent Sigma1 msg
[1704338603.903798][9739:9741] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 3 --> 4
[1704338603.945548][9739:9741] CHIP:EM: >>> [E:18889i S:0 M:240206979 (Ack:218330495)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704338603.945564][9739:9741] CHIP:EM: Found matching exchange: 18889i, Delegate: 0x7ff5a800ea88
[1704338603.945577][9739:9741] CHIP:EM: Rxd Ack; Removing MessageCounter:218330495 from Retrans Table on exchange 18889i
[1704338604.016851][9739:9741] CHIP:EM: >>> [E:18889i S:0 M:240206980 (Ack:218330495)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704338604.016924][9739:9741] CHIP:EM: Found matching exchange: 18889i, Delegate: 0x7ff5a800ea88
[1704338604.016963][9739:9741] CHIP:EM: CHIP MessageCounter:218330495 not in RetransTable on exchange 18889i
[1704338604.017024][9739:9741] CHIP:SC: Received Sigma2 msg
[1704338604.017075][9739:9741] CHIP:SC: Peer assigned session session ID 46681
[1704338604.021309][9739:9741] CHIP:SC: Found MRP parameters in the message
[1704338604.021363][9739:9741] CHIP:SC: Sending Sigma3
[1704338604.021868][9739:9741] CHIP:EM: <<< [E:18889i S:0 M:218330496 (Ack:240206980)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704338604.021905][9739:9741] CHIP:SC: Sent Sigma3 msg
[1704338604.055428][9739:9741] CHIP:EM: >>> [E:18889i S:0 M:240206981 (Ack:218330496)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704338604.055455][9739:9741] CHIP:EM: Found matching exchange: 18889i, Delegate: 0x7ff5a800ea88
[1704338604.055473][9739:9741] CHIP:EM: Rxd Ack; Removing MessageCounter:218330496 from Retrans Table on exchange 18889i
[1704338604.189409][9739:9741] CHIP:EM: >>> [E:18889i S:0 M:240206982 (Ack:218330496)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704338604.189469][9739:9741] CHIP:EM: Found matching exchange: 18889i, Delegate: 0x7ff5a800ea88
[1704338604.189503][9739:9741] CHIP:EM: CHIP MessageCounter:218330496 not in RetransTable on exchange 18889i
[1704338604.189569][9739:9741] CHIP:SC: Success status report received. Session was established
[1704338604.193550][9739:9741] CHIP:SC: SecureSession[0x7ff5a800ed30, LSID:21174]: State change 'kEstablishing' --> 'kActive'
[1704338604.193591][9739:9741] CHIP:IN: SecureSession[0x7ff5a800ed30]: Activated - Type:2 LSID:21174
[1704338604.193614][9739:9741] CHIP:IN: New secure session activated for device <0000000000001234, 1>, LSID:21174 PSID:46681!
[1704338604.193643][9739:9741] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 4 --> 5
[1704338604.193702][9739:9741] CHIP:TOO: Sending cluster (0x00000006) command (0x00000002) on endpoint 1
[1704338604.193752][9739:9741] CHIP:DMG: ICR moving to [AddingComm]
[1704338604.193777][9739:9741] CHIP:DMG: ICR moving to [AddedComma]
[1704338604.193975][9739:9741] CHIP:EM: <<< [E:18890i S:21174 M:104593236] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704338604.194162][9739:9741] CHIP:DMG: ICR moving to [CommandSen]
[1704338604.194339][9739:9741] CHIP:EM: <<< [E:18889i S:0 M:218330497 (Ack:240206982)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704338604.194431][9739:9741] CHIP:EM: Flushed pending ack for MessageCounter:240206982 on exchange 18889i
[1704338604.311154][9739:9741] CHIP:EM: >>> [E:18890i S:21174 M:140338731 (Ack:104593236)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704338604.311204][9739:9741] CHIP:EM: Found matching exchange: 18890i, Delegate: 0x7ff5a800a6f8
[1704338604.311239][9739:9741] CHIP:EM: Rxd Ack; Removing MessageCounter:104593236 from Retrans Table on exchange 18890i
[1704338604.311274][9739:9741] CHIP:DMG: ICR moving to [ResponseRe]
[1704338604.311322][9739:9741] CHIP:DMG: InvokeResponseMessage =
[1704338604.311344][9739:9741] CHIP:DMG: {
[1704338604.311368][9739:9741] CHIP:DMG: suppressResponse = false,
[1704338604.311390][9739:9741] CHIP:DMG: InvokeResponseIBs =
[1704338604.311420][9739:9741] CHIP:DMG: [
[1704338604.311441][9739:9741] CHIP:DMG: InvokeResponseIB =
[1704338604.311471][9739:9741] CHIP:DMG: {
[1704338604.311493][9739:9741] CHIP:DMG: CommandStatusIB =
[1704338604.311534][9739:9741] CHIP:DMG: {
[1704338604.311557][9739:9741] CHIP:DMG: CommandPathIB =
[1704338604.311592][9739:9741] CHIP:DMG: {
[1704338604.311618][9739:9741] CHIP:DMG: EndpointId = 0x1,
[1704338604.311643][9739:9741] CHIP:DMG: ClusterId = 0x6,
[1704338604.311673][9739:9741] CHIP:DMG: CommandId = 0x2,
[1704338604.311697][9739:9741] CHIP:DMG: },
[1704338604.311732][9739:9741] CHIP:DMG:
[1704338604.311755][9739:9741] CHIP:DMG: StatusIB =
[1704338604.311790][9739:9741] CHIP:DMG: {
[1704338604.311815][9739:9741] CHIP:DMG: status = 0x00 (SUCCESS),
[1704338604.311839][9739:9741] CHIP:DMG: },
[1704338604.311874][9739:9741] CHIP:DMG:
[1704338604.311897][9739:9741] CHIP:DMG: },
[1704338604.311930][9739:9741] CHIP:DMG:
[1704338604.311952][9739:9741] CHIP:DMG: },
[1704338604.311990][9739:9741] CHIP:DMG:
[1704338604.312010][9739:9741] CHIP:DMG: ],
[1704338604.312083][9739:9741] CHIP:DMG:
[1704338604.312105][9739:9741] CHIP:DMG: InteractionModelRevision = 11
[1704338604.312131][9739:9741] CHIP:DMG: },
[1704338604.312214][9739:9741] CHIP:DMG: Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0002 Status=0x0
[1704338604.312265][9739:9741] CHIP:DMG: ICR moving to [AwaitingDe]
[1704338604.312517][9739:9741] CHIP:EM: <<< [E:18890i S:21174 M:104593237 (Ack:140338731)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704338604.312623][9739:9741] CHIP:EM: Flushed pending ack for MessageCounter:140338731 on exchange 18890i
[1704338604.312855][9739:9739] CHIP:CTL: Shutting down the commissioner
[1704338604.312952][9739:9739] CHIP:CTL: Shutting down the controller
[1704338604.313001][9739:9739] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704338604.313023][9739:9739] CHIP:IN: SecureSession[0x7ff5a800ed30]: MarkForEviction Type:2 LSID:21174
[1704338604.313045][9739:9739] CHIP:SC: SecureSession[0x7ff5a800ed30, LSID:21174]: State change 'kActive' --> 'kPendingEviction'
[1704338604.313068][9739:9739] CHIP:IN: SecureSession[0x7ff5a800ed30]: Released - Type:2 LSID:21174
[1704338604.313094][9739:9739] CHIP:FP: Forgetting fabric 0x1
[1704338604.313124][9739:9739] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704338604.313325][9739:9739] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704338604.313350][9739:9739] CHIP:TS: Reverted Last Known Good Time to previous value
[1704338604.313391][9739:9739] CHIP:CTL: Shutting down the commissioner
[1704338604.313456][9739:9739] CHIP:CTL: Shutting down the controller
[1704338604.313476][9739:9739] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704338604.313592][9739:9739] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704338604.313670][9739:9739] CHIP:FP: Shutting down FabricTable
[1704338604.313694][9739:9739] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704338604.313798][9739:9739] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704338604.313819][9739:9739] CHIP:TS: Reverted Last Known Good Time to previous value
[1704338604.314018][9739:9739] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-VGjjuA)
[1704338604.314553][9739:9739] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704338604.314615][9739:9739] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704338604.314653][9739:9739] CHIP:DL: Inet Layer shutdown
[1704338604.314675][9739:9739] CHIP:DL: BLE shutdown
[1704338604.314702][9739:9739] CHIP:DL: System Layer shutdown
onoff on
: onoff 클러스터 LED 켜기
더보기
$ ./chip-tool onoff on 0x1234 1
[1704344350.592643][10182:10182] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704344350.593040][10182:10182] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704344350.593051][10182:10182] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704344350.594910][10182:10182] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704344350.594963][10182:10182] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704344350.594984][10182:10182] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704344350.595070][10182:10182] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-aXV34Q)
[1704344350.595200][10182:10182] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704344350.595211][10182:10182] CHIP:DL: NVS set: chip-counters/reboot-count = 19 (0x13)
[1704344350.595358][10182:10182] CHIP:DL: Got Ethernet interface: enp3s0
[1704344350.595473][10182:10182] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704344350.595612][10182:10182] CHIP:DL: Failed to get WiFi interface
[1704344350.595617][10182:10182] CHIP:DL: Failed to reset WiFi statistic counts
[1704344350.595631][10182:10182] CHIP:IN: UDP::Init bind&listen port=0
[1704344350.595654][10182:10182] CHIP:IN: UDP::Init bound to port=54653
[1704344350.595659][10182:10182] CHIP:IN: UDP::Init bind&listen port=0
[1704344350.595678][10182:10182] CHIP:IN: UDP::Init bound to port=40802
[1704344350.595682][10182:10182] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704344350.595687][10182:10182] CHIP:IN: TransportMgr initialized
[1704344350.595696][10182:10182] CHIP:FP: Initializing FabricTable from persistent storage
[1704344350.595735][10182:10182] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704344350.596174][10182:10182] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7EC96ABB43EBB1E9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704344350.597019][10182:10182] CHIP:ZCL: Using ZAP configuration...
[1704344350.597473][10182:10182] CHIP:CTL: System State Initialized...
[1704344350.597518][10182:10182] CHIP:CTL: Setting attestation nonce to random value
[1704344350.597527][10182:10182] CHIP:CTL: Setting CSR nonce to random value
[1704344350.597540][10182:10182] CHIP:IN: UDP::Init bind&listen port=5550
[1704344350.597558][10182:10182] CHIP:IN: UDP::Init bound to port=5550
[1704344350.597563][10182:10182] CHIP:IN: UDP::Init bind&listen port=5550
[1704344350.597579][10182:10182] CHIP:IN: UDP::Init bound to port=5550
[1704344350.597583][10182:10182] CHIP:IN: TransportMgr initialized
[1704344350.597682][10182:10184] CHIP:DL: CHIP task running
[1704344350.597702][10182:10184] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704344350.597798][10182:10184] CHIP:CTL: Setting attestation nonce to random value
[1704344350.597830][10182:10184] CHIP:CTL: Setting CSR nonce to random value
[1704344350.598056][10182:10184] CHIP:CTL: Generating NOC
[1704344350.598295][10182:10184] CHIP:FP: Validating NOC chain
[1704344350.598665][10182:10184] CHIP:FP: NOC chain validation successful
[1704344350.598702][10182:10184] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704344350.598708][10182:10184] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704344350.598713][10182:10184] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704344350.598717][10182:10184] CHIP:TS: Retaining current Last Known Good Time
[1704344350.599590][10182:10184] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704344350.600000][10182:10184] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704344350.600390][10182:10184] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 7EC96ABB43EBB1E9)
[1704344350.600400][10182:10184] CHIP:IN: UDP::Init bind&listen port=5550
[1704344350.600426][10182:10184] CHIP:IN: UDP::Init bound to port=5550
[1704344350.600433][10182:10184] CHIP:IN: UDP::Init bind&listen port=5550
[1704344350.600455][10182:10184] CHIP:IN: UDP::Init bound to port=5550
[1704344350.600460][10182:10184] CHIP:IN: TransportMgr initialized
[1704344350.604367][10182:10184] CHIP:TOO: Sending command to node 0x1234
[1704344350.604468][10182:10184] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704344350.604476][10182:10184] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704344350.604488][10182:10184] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 2
[1704344350.661160][10182:10184] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704344350.661181][10182:10184] CHIP:DIS: Lookup clearing interface for non LL address
[1704344350.661214][10182:10184] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704344350.661226][10182:10184] CHIP:DIS: Checking node lookup status after 56 ms
[1704344350.661238][10182:10184] CHIP:DIS: Keeping DNSSD lookup active
[1704344350.661311][10182:10184] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704344350.661326][10182:10184] CHIP:DIS: Lookup clearing interface for non LL address
[1704344350.661357][10182:10184] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704344350.661377][10182:10184] CHIP:DIS: Checking node lookup status after 57 ms
[1704344350.661386][10182:10184] CHIP:DIS: Keeping DNSSD lookup active
[1704344350.804653][10182:10184] CHIP:DIS: Checking node lookup status after 200 ms
[1704344350.804774][10182:10184] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: Updating device address to UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540 while in state 2
[1704344350.804802][10182:10184] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 2 --> 3
[1704344350.804933][10182:10184] CHIP:IN: SecureSession[0x7f55b400ed30]: Allocated Type:2 LSID:8035
[1704344350.804973][10182:10184] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000001234
[1704344350.805947][10182:10184] CHIP:EM: <<< [E:12519i S:0 M:103942423] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704344350.806092][10182:10184] CHIP:SC: Sent Sigma1 msg
[1704344350.806120][10182:10184] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 3 --> 4
[1704344350.852418][10182:10184] CHIP:EM: >>> [E:12519i S:0 M:240207011 (Ack:103942423)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344350.852470][10182:10184] CHIP:EM: Found matching exchange: 12519i, Delegate: 0x7f55b400ea88
[1704344350.852515][10182:10184] CHIP:EM: Rxd Ack; Removing MessageCounter:103942423 from Retrans Table on exchange 12519i
[1704344350.916990][10182:10184] CHIP:EM: >>> [E:12519i S:0 M:240207012 (Ack:103942423)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704344350.917065][10182:10184] CHIP:EM: Found matching exchange: 12519i, Delegate: 0x7f55b400ea88
[1704344350.917094][10182:10184] CHIP:EM: CHIP MessageCounter:103942423 not in RetransTable on exchange 12519i
[1704344350.917161][10182:10184] CHIP:SC: Received Sigma2 msg
[1704344350.917213][10182:10184] CHIP:SC: Peer assigned session session ID 46689
[1704344350.921439][10182:10184] CHIP:SC: Found MRP parameters in the message
[1704344350.921500][10182:10184] CHIP:SC: Sending Sigma3
[1704344350.922140][10182:10184] CHIP:EM: <<< [E:12519i S:0 M:103942424 (Ack:240207012)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704344350.922312][10182:10184] CHIP:SC: Sent Sigma3 msg
[1704344350.969586][10182:10184] CHIP:EM: >>> [E:12519i S:0 M:240207013 (Ack:103942424)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344350.969650][10182:10184] CHIP:EM: Found matching exchange: 12519i, Delegate: 0x7f55b400ea88
[1704344350.969704][10182:10184] CHIP:EM: Rxd Ack; Removing MessageCounter:103942424 from Retrans Table on exchange 12519i
[1704344351.083252][10182:10184] CHIP:EM: >>> [E:12519i S:0 M:240207014 (Ack:103942424)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704344351.083322][10182:10184] CHIP:EM: Found matching exchange: 12519i, Delegate: 0x7f55b400ea88
[1704344351.083359][10182:10184] CHIP:EM: CHIP MessageCounter:103942424 not in RetransTable on exchange 12519i
[1704344351.083424][10182:10184] CHIP:SC: Success status report received. Session was established
[1704344351.087444][10182:10184] CHIP:SC: SecureSession[0x7f55b400ed30, LSID:8035]: State change 'kEstablishing' --> 'kActive'
[1704344351.087489][10182:10184] CHIP:IN: SecureSession[0x7f55b400ed30]: Activated - Type:2 LSID:8035
[1704344351.087526][10182:10184] CHIP:IN: New secure session activated for device <0000000000001234, 1>, LSID:8035 PSID:46689!
[1704344351.087565][10182:10184] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 4 --> 5
[1704344351.087639][10182:10184] CHIP:TOO: Sending cluster (0x00000006) command (0x00000001) on endpoint 1
[1704344351.087697][10182:10184] CHIP:DMG: ICR moving to [AddingComm]
[1704344351.087754][10182:10184] CHIP:DMG: ICR moving to [AddedComma]
[1704344351.087945][10182:10184] CHIP:EM: <<< [E:12520i S:8035 M:260741777] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704344351.088100][10182:10184] CHIP:DMG: ICR moving to [CommandSen]
[1704344351.088231][10182:10184] CHIP:EM: <<< [E:12519i S:0 M:103942425 (Ack:240207014)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344351.088324][10182:10184] CHIP:EM: Flushed pending ack for MessageCounter:240207014 on exchange 12519i
[1704344351.242497][10182:10184] CHIP:EM: >>> [E:12520i S:8035 M:233296170 (Ack:260741777)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704344351.242548][10182:10184] CHIP:EM: Found matching exchange: 12520i, Delegate: 0x7f55b400a6f8
[1704344351.242583][10182:10184] CHIP:EM: Rxd Ack; Removing MessageCounter:260741777 from Retrans Table on exchange 12520i
[1704344351.242619][10182:10184] CHIP:DMG: ICR moving to [ResponseRe]
[1704344351.242668][10182:10184] CHIP:DMG: InvokeResponseMessage =
[1704344351.242689][10182:10184] CHIP:DMG: {
[1704344351.242710][10182:10184] CHIP:DMG: suppressResponse = false,
[1704344351.242729][10182:10184] CHIP:DMG: InvokeResponseIBs =
[1704344351.242760][10182:10184] CHIP:DMG: [
[1704344351.242780][10182:10184] CHIP:DMG: InvokeResponseIB =
[1704344351.242810][10182:10184] CHIP:DMG: {
[1704344351.242831][10182:10184] CHIP:DMG: CommandStatusIB =
[1704344351.242853][10182:10184] CHIP:DMG: {
[1704344351.242874][10182:10184] CHIP:DMG: CommandPathIB =
[1704344351.242899][10182:10184] CHIP:DMG: {
[1704344351.242924][10182:10184] CHIP:DMG: EndpointId = 0x1,
[1704344351.242949][10182:10184] CHIP:DMG: ClusterId = 0x6,
[1704344351.242973][10182:10184] CHIP:DMG: CommandId = 0x1,
[1704344351.242997][10182:10184] CHIP:DMG: },
[1704344351.243026][10182:10184] CHIP:DMG:
[1704344351.243048][10182:10184] CHIP:DMG: StatusIB =
[1704344351.243074][10182:10184] CHIP:DMG: {
[1704344351.243099][10182:10184] CHIP:DMG: status = 0x00 (SUCCESS),
[1704344351.243123][10182:10184] CHIP:DMG: },
[1704344351.243147][10182:10184] CHIP:DMG:
[1704344351.243169][10182:10184] CHIP:DMG: },
[1704344351.243198][10182:10184] CHIP:DMG:
[1704344351.243219][10182:10184] CHIP:DMG: },
[1704344351.243248][10182:10184] CHIP:DMG:
[1704344351.243269][10182:10184] CHIP:DMG: ],
[1704344351.243298][10182:10184] CHIP:DMG:
[1704344351.243319][10182:10184] CHIP:DMG: InteractionModelRevision = 11
[1704344351.243340][10182:10184] CHIP:DMG: },
[1704344351.243409][10182:10184] CHIP:DMG: Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0001 Status=0x0
[1704344351.243452][10182:10184] CHIP:DMG: ICR moving to [AwaitingDe]
[1704344351.243644][10182:10184] CHIP:EM: <<< [E:12520i S:8035 M:260741778 (Ack:233296170)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344351.243745][10182:10184] CHIP:EM: Flushed pending ack for MessageCounter:233296170 on exchange 12520i
[1704344351.243969][10182:10182] CHIP:CTL: Shutting down the commissioner
[1704344351.244109][10182:10182] CHIP:CTL: Shutting down the controller
[1704344351.244186][10182:10182] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704344351.244216][10182:10182] CHIP:IN: SecureSession[0x7f55b400ed30]: MarkForEviction Type:2 LSID:8035
[1704344351.244251][10182:10182] CHIP:SC: SecureSession[0x7f55b400ed30, LSID:8035]: State change 'kActive' --> 'kPendingEviction'
[1704344351.244296][10182:10182] CHIP:IN: SecureSession[0x7f55b400ed30]: Released - Type:2 LSID:8035
[1704344351.244340][10182:10182] CHIP:FP: Forgetting fabric 0x1
[1704344351.244379][10182:10182] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704344351.244698][10182:10182] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704344351.244736][10182:10182] CHIP:TS: Reverted Last Known Good Time to previous value
[1704344351.244792][10182:10182] CHIP:CTL: Shutting down the commissioner
[1704344351.244871][10182:10182] CHIP:CTL: Shutting down the controller
[1704344351.244897][10182:10182] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704344351.245068][10182:10182] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704344351.245203][10182:10182] CHIP:FP: Shutting down FabricTable
[1704344351.245240][10182:10182] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704344351.245387][10182:10182] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704344351.245412][10182:10182] CHIP:TS: Reverted Last Known Good Time to previous value
[1704344351.245670][10182:10182] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-j2nNqw)
[1704344351.246333][10182:10182] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704344351.246405][10182:10182] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704344351.246443][10182:10182] CHIP:DL: Inet Layer shutdown
[1704344351.246475][10182:10182] CHIP:DL: BLE shutdown
[1704344351.246505][10182:10182] CHIP:DL: System Layer shutdown
onoff off [node id] [endpoint id]
: onoff 클러스터 LED 끄기
더보기
$ ./chip-tool onoff off 0x1234 1
[1704344158.797820][10081:10081] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704344158.798199][10081:10081] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704344158.798206][10081:10081] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704344158.799913][10081:10081] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704344158.799949][10081:10081] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704344158.799969][10081:10081] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704344158.800073][10081:10081] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-eLshxh)
[1704344158.800193][10081:10081] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704344158.800203][10081:10081] CHIP:DL: NVS set: chip-counters/reboot-count = 18 (0x12)
[1704344158.800341][10081:10081] CHIP:DL: Got Ethernet interface: enp3s0
[1704344158.800433][10081:10081] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704344158.800567][10081:10081] CHIP:DL: Failed to get WiFi interface
[1704344158.800572][10081:10081] CHIP:DL: Failed to reset WiFi statistic counts
[1704344158.800582][10081:10081] CHIP:IN: UDP::Init bind&listen port=0
[1704344158.800604][10081:10081] CHIP:IN: UDP::Init bound to port=42931
[1704344158.800609][10081:10081] CHIP:IN: UDP::Init bind&listen port=0
[1704344158.800626][10081:10081] CHIP:IN: UDP::Init bound to port=47537
[1704344158.800631][10081:10081] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704344158.800635][10081:10081] CHIP:IN: TransportMgr initialized
[1704344158.800644][10081:10081] CHIP:FP: Initializing FabricTable from persistent storage
[1704344158.800676][10081:10081] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704344158.801074][10081:10081] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7EC96ABB43EBB1E9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704344158.801969][10081:10081] CHIP:ZCL: Using ZAP configuration...
[1704344158.802451][10081:10081] CHIP:CTL: System State Initialized...
[1704344158.802509][10081:10081] CHIP:CTL: Setting attestation nonce to random value
[1704344158.802517][10081:10081] CHIP:CTL: Setting CSR nonce to random value
[1704344158.802530][10081:10081] CHIP:IN: UDP::Init bind&listen port=5550
[1704344158.802562][10081:10081] CHIP:IN: UDP::Init bound to port=5550
[1704344158.802567][10081:10081] CHIP:IN: UDP::Init bind&listen port=5550
[1704344158.802582][10081:10081] CHIP:IN: UDP::Init bound to port=5550
[1704344158.802587][10081:10081] CHIP:IN: TransportMgr initialized
[1704344158.802667][10081:10083] CHIP:DL: CHIP task running
[1704344158.802685][10081:10083] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704344158.802761][10081:10083] CHIP:CTL: Setting attestation nonce to random value
[1704344158.802786][10081:10083] CHIP:CTL: Setting CSR nonce to random value
[1704344158.803007][10081:10083] CHIP:CTL: Generating NOC
[1704344158.803242][10081:10083] CHIP:FP: Validating NOC chain
[1704344158.803640][10081:10083] CHIP:FP: NOC chain validation successful
[1704344158.803678][10081:10083] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704344158.803685][10081:10083] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704344158.803689][10081:10083] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704344158.803693][10081:10083] CHIP:TS: Retaining current Last Known Good Time
[1704344158.804515][10081:10083] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704344158.804860][10081:10083] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704344158.805157][10081:10083] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 7EC96ABB43EBB1E9)
[1704344158.805165][10081:10083] CHIP:IN: UDP::Init bind&listen port=5550
[1704344158.805186][10081:10083] CHIP:IN: UDP::Init bound to port=5550
[1704344158.805191][10081:10083] CHIP:IN: UDP::Init bind&listen port=5550
[1704344158.805209][10081:10083] CHIP:IN: UDP::Init bound to port=5550
[1704344158.805213][10081:10083] CHIP:IN: TransportMgr initialized
[1704344158.808219][10081:10083] CHIP:TOO: Sending command to node 0x1234
[1704344158.808307][10081:10083] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704344158.808314][10081:10083] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704344158.808321][10081:10083] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 2
[1704344158.813560][10081:10083] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704344158.813568][10081:10083] CHIP:DIS: Lookup clearing interface for non LL address
[1704344158.813579][10081:10083] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704344158.813583][10081:10083] CHIP:DIS: Checking node lookup status after 5 ms
[1704344158.813587][10081:10083] CHIP:DIS: Keeping DNSSD lookup active
[1704344158.814755][10081:10083] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704344158.814763][10081:10083] CHIP:DIS: Lookup clearing interface for non LL address
[1704344158.814774][10081:10083] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704344158.814778][10081:10083] CHIP:DIS: Checking node lookup status after 6 ms
[1704344158.814782][10081:10083] CHIP:DIS: Keeping DNSSD lookup active
[1704344159.009100][10081:10083] CHIP:DIS: Checking node lookup status after 200 ms
[1704344159.009198][10081:10083] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: Updating device address to UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540 while in state 2
[1704344159.009225][10081:10083] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 2 --> 3
[1704344159.009455][10081:10083] CHIP:IN: SecureSession[0x7f10e800ed30]: Allocated Type:2 LSID:36617
[1704344159.009502][10081:10083] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000001234
[1704344159.010473][10081:10083] CHIP:EM: <<< [E:36851i S:0 M:184907628] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704344159.010599][10081:10083] CHIP:SC: Sent Sigma1 msg
[1704344159.010627][10081:10083] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 3 --> 4
[1704344159.055539][10081:10083] CHIP:EM: >>> [E:36851i S:0 M:240207007 (Ack:184907628)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344159.055588][10081:10083] CHIP:EM: Found matching exchange: 36851i, Delegate: 0x7f10e800ea88
[1704344159.055622][10081:10083] CHIP:EM: Rxd Ack; Removing MessageCounter:184907628 from Retrans Table on exchange 36851i
[1704344159.119726][10081:10083] CHIP:EM: >>> [E:36851i S:0 M:240207008 (Ack:184907628)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704344159.119777][10081:10083] CHIP:EM: Found matching exchange: 36851i, Delegate: 0x7f10e800ea88
[1704344159.119801][10081:10083] CHIP:EM: CHIP MessageCounter:184907628 not in RetransTable on exchange 36851i
[1704344159.119849][10081:10083] CHIP:SC: Received Sigma2 msg
[1704344159.119889][10081:10083] CHIP:SC: Peer assigned session session ID 46688
[1704344159.124783][10081:10083] CHIP:SC: Found MRP parameters in the message
[1704344159.124853][10081:10083] CHIP:SC: Sending Sigma3
[1704344159.125814][10081:10083] CHIP:EM: <<< [E:36851i S:0 M:184907629 (Ack:240207008)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704344159.125947][10081:10083] CHIP:SC: Sent Sigma3 msg
[1704344159.155248][10081:10083] CHIP:EM: >>> [E:36851i S:0 M:240207009 (Ack:184907629)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344159.155296][10081:10083] CHIP:EM: Found matching exchange: 36851i, Delegate: 0x7f10e800ea88
[1704344159.155330][10081:10083] CHIP:EM: Rxd Ack; Removing MessageCounter:184907629 from Retrans Table on exchange 36851i
[1704344159.282131][10081:10083] CHIP:EM: >>> [E:36851i S:0 M:240207010 (Ack:184907629)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704344159.282179][10081:10083] CHIP:EM: Found matching exchange: 36851i, Delegate: 0x7f10e800ea88
[1704344159.282203][10081:10083] CHIP:EM: CHIP MessageCounter:184907629 not in RetransTable on exchange 36851i
[1704344159.282248][10081:10083] CHIP:SC: Success status report received. Session was established
[1704344159.286115][10081:10083] CHIP:SC: SecureSession[0x7f10e800ed30, LSID:36617]: State change 'kEstablishing' --> 'kActive'
[1704344159.286249][10081:10083] CHIP:IN: SecureSession[0x7f10e800ed30]: Activated - Type:2 LSID:36617
[1704344159.286306][10081:10083] CHIP:IN: New secure session activated for device <0000000000001234, 1>, LSID:36617 PSID:46688!
[1704344159.286345][10081:10083] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 4 --> 5
[1704344159.286423][10081:10083] CHIP:TOO: Sending cluster (0x00000006) command (0x00000000) on endpoint 1
[1704344159.286473][10081:10083] CHIP:DMG: ICR moving to [AddingComm]
[1704344159.286521][10081:10083] CHIP:DMG: ICR moving to [AddedComma]
[1704344159.286686][10081:10083] CHIP:EM: <<< [E:36852i S:36617 M:1520594] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704344159.286828][10081:10083] CHIP:DMG: ICR moving to [CommandSen]
[1704344159.287042][10081:10083] CHIP:EM: <<< [E:36851i S:0 M:184907630 (Ack:240207010)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344159.287123][10081:10083] CHIP:EM: Flushed pending ack for MessageCounter:240207010 on exchange 36851i
[1704344159.402928][10081:10083] CHIP:EM: >>> [E:36852i S:36617 M:167533777 (Ack:1520594)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704344159.402980][10081:10083] CHIP:EM: Found matching exchange: 36852i, Delegate: 0x7f10e800a6f8
[1704344159.403033][10081:10083] CHIP:EM: Rxd Ack; Removing MessageCounter:1520594 from Retrans Table on exchange 36852i
[1704344159.403086][10081:10083] CHIP:DMG: ICR moving to [ResponseRe]
[1704344159.403147][10081:10083] CHIP:DMG: InvokeResponseMessage =
[1704344159.403174][10081:10083] CHIP:DMG: {
[1704344159.403211][10081:10083] CHIP:DMG: suppressResponse = false,
[1704344159.403240][10081:10083] CHIP:DMG: InvokeResponseIBs =
[1704344159.403289][10081:10083] CHIP:DMG: [
[1704344159.403316][10081:10083] CHIP:DMG: InvokeResponseIB =
[1704344159.403363][10081:10083] CHIP:DMG: {
[1704344159.403391][10081:10083] CHIP:DMG: CommandStatusIB =
[1704344159.403547][10081:10083] CHIP:DMG: {
[1704344159.403581][10081:10083] CHIP:DMG: CommandPathIB =
[1704344159.403620][10081:10083] CHIP:DMG: {
[1704344159.403655][10081:10083] CHIP:DMG: EndpointId = 0x1,
[1704344159.403691][10081:10083] CHIP:DMG: ClusterId = 0x6,
[1704344159.403726][10081:10083] CHIP:DMG: CommandId = 0x0,
[1704344159.403758][10081:10083] CHIP:DMG: },
[1704344159.403803][10081:10083] CHIP:DMG:
[1704344159.403834][10081:10083] CHIP:DMG: StatusIB =
[1704344159.403872][10081:10083] CHIP:DMG: {
[1704344159.403907][10081:10083] CHIP:DMG: status = 0x00 (SUCCESS),
[1704344159.403940][10081:10083] CHIP:DMG: },
[1704344159.403978][10081:10083] CHIP:DMG:
[1704344159.404007][10081:10083] CHIP:DMG: },
[1704344159.404050][10081:10083] CHIP:DMG:
[1704344159.404078][10081:10083] CHIP:DMG: },
[1704344159.404123][10081:10083] CHIP:DMG:
[1704344159.404149][10081:10083] CHIP:DMG: ],
[1704344159.404289][10081:10083] CHIP:DMG:
[1704344159.404321][10081:10083] CHIP:DMG: InteractionModelRevision = 11
[1704344159.404351][10081:10083] CHIP:DMG: },
[1704344159.404457][10081:10083] CHIP:DMG: Received Command Response Status for Endpoint=1 Cluster=0x0000_0006 Command=0x0000_0000 Status=0x0
[1704344159.404524][10081:10083] CHIP:DMG: ICR moving to [AwaitingDe]
[1704344159.404712][10081:10083] CHIP:EM: <<< [E:36852i S:36617 M:1520595 (Ack:167533777)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344159.404822][10081:10083] CHIP:EM: Flushed pending ack for MessageCounter:167533777 on exchange 36852i
[1704344159.405043][10081:10081] CHIP:CTL: Shutting down the commissioner
[1704344159.405141][10081:10081] CHIP:CTL: Shutting down the controller
[1704344159.405191][10081:10081] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704344159.405215][10081:10081] CHIP:IN: SecureSession[0x7f10e800ed30]: MarkForEviction Type:2 LSID:36617
[1704344159.405238][10081:10081] CHIP:SC: SecureSession[0x7f10e800ed30, LSID:36617]: State change 'kActive' --> 'kPendingEviction'
[1704344159.405261][10081:10081] CHIP:IN: SecureSession[0x7f10e800ed30]: Released - Type:2 LSID:36617
[1704344159.405287][10081:10081] CHIP:FP: Forgetting fabric 0x1
[1704344159.405321][10081:10081] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704344159.405513][10081:10081] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704344159.405543][10081:10081] CHIP:TS: Reverted Last Known Good Time to previous value
[1704344159.405595][10081:10081] CHIP:CTL: Shutting down the commissioner
[1704344159.405678][10081:10081] CHIP:CTL: Shutting down the controller
[1704344159.405705][10081:10081] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704344159.405864][10081:10081] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704344159.405973][10081:10081] CHIP:FP: Shutting down FabricTable
[1704344159.406019][10081:10081] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704344159.406181][10081:10081] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704344159.406212][10081:10081] CHIP:TS: Reverted Last Known Good Time to previous value
[1704344159.406512][10081:10081] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-Usn9KL)
[1704344159.407160][10081:10081] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704344159.407221][10081:10081] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704344159.407250][10081:10081] CHIP:DL: Inet Layer shutdown
[1704344159.407275][10081:10081] CHIP:DL: BLE shutdown
[1704344159.407303][10081:10081] CHIP:DL: System Layer shutdown
onoff read on-off
더보기
$ ./chip-tool onoff read on-off 0x1234 1
[1704344711.293596][10337:10337] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704344711.294003][10337:10337] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704344711.294011][10337:10337] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704344711.295772][10337:10337] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704344711.295809][10337:10337] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704344711.295830][10337:10337] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704344711.295903][10337:10337] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-OQcNTW)
[1704344711.296021][10337:10337] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704344711.296031][10337:10337] CHIP:DL: NVS set: chip-counters/reboot-count = 24 (0x18)
[1704344711.296169][10337:10337] CHIP:DL: Got Ethernet interface: enp3s0
[1704344711.296291][10337:10337] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704344711.296425][10337:10337] CHIP:DL: Failed to get WiFi interface
[1704344711.296430][10337:10337] CHIP:DL: Failed to reset WiFi statistic counts
[1704344711.296441][10337:10337] CHIP:IN: UDP::Init bind&listen port=0
[1704344711.296464][10337:10337] CHIP:IN: UDP::Init bound to port=56207
[1704344711.296468][10337:10337] CHIP:IN: UDP::Init bind&listen port=0
[1704344711.296486][10337:10337] CHIP:IN: UDP::Init bound to port=54360
[1704344711.296490][10337:10337] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704344711.296495][10337:10337] CHIP:IN: TransportMgr initialized
[1704344711.296503][10337:10337] CHIP:FP: Initializing FabricTable from persistent storage
[1704344711.296540][10337:10337] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704344711.296939][10337:10337] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7EC96ABB43EBB1E9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704344711.297808][10337:10337] CHIP:ZCL: Using ZAP configuration...
[1704344711.298275][10337:10337] CHIP:CTL: System State Initialized...
[1704344711.298330][10337:10337] CHIP:CTL: Setting attestation nonce to random value
[1704344711.298339][10337:10337] CHIP:CTL: Setting CSR nonce to random value
[1704344711.298352][10337:10337] CHIP:IN: UDP::Init bind&listen port=5550
[1704344711.298370][10337:10337] CHIP:IN: UDP::Init bound to port=5550
[1704344711.298379][10337:10337] CHIP:IN: UDP::Init bind&listen port=5550
[1704344711.298393][10337:10337] CHIP:IN: UDP::Init bound to port=5550
[1704344711.298398][10337:10337] CHIP:IN: TransportMgr initialized
[1704344711.298453][10337:10339] CHIP:DL: CHIP task running
[1704344711.298472][10337:10339] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704344711.298546][10337:10339] CHIP:CTL: Setting attestation nonce to random value
[1704344711.298572][10337:10339] CHIP:CTL: Setting CSR nonce to random value
[1704344711.298792][10337:10339] CHIP:CTL: Generating NOC
[1704344711.299012][10337:10339] CHIP:FP: Validating NOC chain
[1704344711.299367][10337:10339] CHIP:FP: NOC chain validation successful
[1704344711.299404][10337:10339] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704344711.299410][10337:10339] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704344711.299415][10337:10339] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704344711.299419][10337:10339] CHIP:TS: Retaining current Last Known Good Time
[1704344711.300240][10337:10339] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704344711.300609][10337:10339] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704344711.300908][10337:10339] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 7EC96ABB43EBB1E9)
[1704344711.300916][10337:10339] CHIP:IN: UDP::Init bind&listen port=5550
[1704344711.300937][10337:10339] CHIP:IN: UDP::Init bound to port=5550
[1704344711.300942][10337:10339] CHIP:IN: UDP::Init bind&listen port=5550
[1704344711.300958][10337:10339] CHIP:IN: UDP::Init bound to port=5550
[1704344711.300962][10337:10339] CHIP:IN: TransportMgr initialized
[1704344711.303922][10337:10339] CHIP:TOO: Sending command to node 0x1234
[1704344711.304011][10337:10339] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704344711.304018][10337:10339] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704344711.304026][10337:10339] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 2
[1704344711.311095][10337:10339] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704344711.311101][10337:10339] CHIP:DIS: Lookup clearing interface for non LL address
[1704344711.311112][10337:10339] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704344711.311116][10337:10339] CHIP:DIS: Checking node lookup status after 7 ms
[1704344711.311120][10337:10339] CHIP:DIS: Keeping DNSSD lookup active
[1704344711.311148][10337:10339] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704344711.311153][10337:10339] CHIP:DIS: Lookup clearing interface for non LL address
[1704344711.311164][10337:10339] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704344711.311168][10337:10339] CHIP:DIS: Checking node lookup status after 7 ms
[1704344711.311172][10337:10339] CHIP:DIS: Keeping DNSSD lookup active
[1704344711.504465][10337:10339] CHIP:DIS: Checking node lookup status after 201 ms
[1704344711.504563][10337:10339] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: Updating device address to UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540 while in state 2
[1704344711.504591][10337:10339] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 2 --> 3
[1704344711.504723][10337:10339] CHIP:IN: SecureSession[0x7f42dc00ed30]: Allocated Type:2 LSID:50578
[1704344711.504763][10337:10339] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000001234
[1704344711.505667][10337:10339] CHIP:EM: <<< [E:43120i S:0 M:252013215] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704344711.505791][10337:10339] CHIP:SC: Sent Sigma1 msg
[1704344711.505818][10337:10339] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 3 --> 4
[1704344711.648331][10337:10339] CHIP:EM: >>> [E:43120i S:0 M:240207031 (Ack:252013215)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344711.648350][10337:10339] CHIP:EM: Found matching exchange: 43120i, Delegate: 0x7f42dc00ea88
[1704344711.648362][10337:10339] CHIP:EM: Rxd Ack; Removing MessageCounter:252013215 from Retrans Table on exchange 43120i
[1704344711.720440][10337:10339] CHIP:EM: >>> [E:43120i S:0 M:240207032 (Ack:252013215)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704344711.720488][10337:10339] CHIP:EM: Found matching exchange: 43120i, Delegate: 0x7f42dc00ea88
[1704344711.720512][10337:10339] CHIP:EM: CHIP MessageCounter:252013215 not in RetransTable on exchange 43120i
[1704344711.720555][10337:10339] CHIP:SC: Received Sigma2 msg
[1704344711.720591][10337:10339] CHIP:SC: Peer assigned session session ID 46694
[1704344711.724552][10337:10339] CHIP:SC: Found MRP parameters in the message
[1704344711.724606][10337:10339] CHIP:SC: Sending Sigma3
[1704344711.725212][10337:10339] CHIP:EM: <<< [E:43120i S:0 M:252013216 (Ack:240207032)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704344711.725339][10337:10339] CHIP:SC: Sent Sigma3 msg
[1704344711.753397][10337:10339] CHIP:EM: >>> [E:43120i S:0 M:240207033 (Ack:252013216)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344711.753444][10337:10339] CHIP:EM: Found matching exchange: 43120i, Delegate: 0x7f42dc00ea88
[1704344711.753478][10337:10339] CHIP:EM: Rxd Ack; Removing MessageCounter:252013216 from Retrans Table on exchange 43120i
[1704344711.889016][10337:10339] CHIP:EM: >>> [E:43120i S:0 M:240207034 (Ack:252013216)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704344711.889064][10337:10339] CHIP:EM: Found matching exchange: 43120i, Delegate: 0x7f42dc00ea88
[1704344711.889088][10337:10339] CHIP:EM: CHIP MessageCounter:252013216 not in RetransTable on exchange 43120i
[1704344711.889131][10337:10339] CHIP:SC: Success status report received. Session was established
[1704344711.892974][10337:10339] CHIP:SC: SecureSession[0x7f42dc00ed30, LSID:50578]: State change 'kEstablishing' --> 'kActive'
[1704344711.893014][10337:10339] CHIP:IN: SecureSession[0x7f42dc00ed30]: Activated - Type:2 LSID:50578
[1704344711.893034][10337:10339] CHIP:IN: New secure session activated for device <0000000000001234, 1>, LSID:50578 PSID:46694!
[1704344711.893059][10337:10339] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 4 --> 5
[1704344711.893123][10337:10339] CHIP:TOO: Sending ReadAttribute to:
[1704344711.893194][10337:10339] CHIP:TOO: cluster 0x0000_0006, attribute: 0x0000_0000, endpoint 1
[1704344711.893229][10337:10339] CHIP:DMG: SendReadRequest ReadClient[0x7f42dc00a6f0]: Sending Read Request
[1704344711.893414][10337:10339] CHIP:EM: <<< [E:43121i S:50578 M:100273108] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:02 (IM:ReadRequest)
[1704344711.893547][10337:10339] CHIP:DMG: MoveToState ReadClient[0x7f42dc00a6f0]: Moving to [AwaitingIn]
[1704344711.893657][10337:10339] CHIP:EM: <<< [E:43120i S:0 M:252013217 (Ack:240207034)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344711.893730][10337:10339] CHIP:EM: Flushed pending ack for MessageCounter:240207034 on exchange 43120i
[1704344711.996473][10337:10339] CHIP:EM: >>> [E:43121i S:50578 M:93619140 (Ack:100273108)] (S) Msg RX from 1:0000000000001234 [B1E9] --- Type 0001:05 (IM:ReportData)
[1704344711.996521][10337:10339] CHIP:EM: Found matching exchange: 43121i, Delegate: 0x7f42dc00a700
[1704344711.996556][10337:10339] CHIP:EM: Rxd Ack; Removing MessageCounter:100273108 from Retrans Table on exchange 43121i
[1704344711.996621][10337:10339] CHIP:DMG: ReportDataMessage =
[1704344711.996646][10337:10339] CHIP:DMG: {
[1704344711.996667][10337:10339] CHIP:DMG: AttributeReportIBs =
[1704344711.996698][10337:10339] CHIP:DMG: [
[1704344711.996719][10337:10339] CHIP:DMG: AttributeReportIB =
[1704344711.996749][10337:10339] CHIP:DMG: {
[1704344711.996770][10337:10339] CHIP:DMG: AttributeDataIB =
[1704344711.996794][10337:10339] CHIP:DMG: {
[1704344711.996819][10337:10339] CHIP:DMG: DataVersion = 0x70fa187d,
[1704344711.996842][10337:10339] CHIP:DMG: AttributePathIB =
[1704344711.996867][10337:10339] CHIP:DMG: {
[1704344711.996891][10337:10339] CHIP:DMG: Endpoint = 0x1,
[1704344711.996918][10337:10339] CHIP:DMG: Cluster = 0x6,
[1704344711.996943][10337:10339] CHIP:DMG: Attribute = 0x0000_0000,
[1704344711.996967][10337:10339] CHIP:DMG: }
[1704344711.996993][10337:10339] CHIP:DMG:
[1704344711.997019][10337:10339] CHIP:DMG: Data = true,
[1704344711.997041][10337:10339] CHIP:DMG: },
[1704344711.997069][10337:10339] CHIP:DMG:
[1704344711.997090][10337:10339] CHIP:DMG: },
[1704344711.997119][10337:10339] CHIP:DMG:
[1704344711.997140][10337:10339] CHIP:DMG: ],
[1704344711.997168][10337:10339] CHIP:DMG:
[1704344711.997190][10337:10339] CHIP:DMG: SuppressResponse = true,
[1704344711.997212][10337:10339] CHIP:DMG: InteractionModelRevision = 11
[1704344711.997232][10337:10339] CHIP:DMG: }
[1704344711.997389][10337:10339] CHIP:TOO: Endpoint: 1 Cluster: 0x0000_0006 Attribute 0x0000_0000 DataVersion: 1895438461
[1704344711.997419][10337:10339] CHIP:TOO: OnOff: TRUE <-------------- 요기
[1704344711.997630][10337:10339] CHIP:EM: <<< [E:43121i S:50578 M:100273109 (Ack:93619140)] (S) Msg TX to 1:0000000000001234 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704344711.997725][10337:10339] CHIP:EM: Flushed pending ack for MessageCounter:93619140 on exchange 43121i
[1704344711.997926][10337:10337] CHIP:CTL: Shutting down the commissioner
[1704344711.998032][10337:10337] CHIP:CTL: Shutting down the controller
[1704344711.998091][10337:10337] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704344711.998227][10337:10337] CHIP:IN: SecureSession[0x7f42dc00ed30]: MarkForEviction Type:2 LSID:50578
[1704344711.998286][10337:10337] CHIP:SC: SecureSession[0x7f42dc00ed30, LSID:50578]: State change 'kActive' --> 'kPendingEviction'
[1704344711.998319][10337:10337] CHIP:IN: SecureSession[0x7f42dc00ed30]: Released - Type:2 LSID:50578
[1704344711.998355][10337:10337] CHIP:FP: Forgetting fabric 0x1
[1704344711.998398][10337:10337] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704344711.998617][10337:10337] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704344711.998644][10337:10337] CHIP:TS: Reverted Last Known Good Time to previous value
[1704344711.998700][10337:10337] CHIP:CTL: Shutting down the commissioner
[1704344711.998777][10337:10337] CHIP:CTL: Shutting down the controller
[1704344711.998803][10337:10337] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704344711.998931][10337:10337] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704344711.999022][10337:10337] CHIP:FP: Shutting down FabricTable
[1704344711.999057][10337:10337] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704344711.999252][10337:10337] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704344711.999382][10337:10337] CHIP:TS: Reverted Last Known Good Time to previous value
[1704344711.999628][10337:10337] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-sRoA8S)
[1704344712.000105][10337:10337] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704344712.000169][10337:10337] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704344712.000199][10337:10337] CHIP:DL: Inet Layer shutdown
[1704344712.000330][10337:10337] CHIP:DL: BLE shutdown
[1704344712.000362][10337:10337] CHIP:DL: System Layer shutdown
payload parse-setup-payload
: payload 에 들어오는 QR code (MT:Y.K9042C00KA0648G00) / manual code (34970112332) 파싱 ,
코드값 > MT:Y.K9042C00KA0648G00
$ ./chip-tool payload parse-setup-payload "MT:Y.K9042C00KA0648G00"
[1704418948.417347][5301:5301] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704418948.417415][5301:5301] CHIP:SPL: Parsing base38Representation: MT:Y.K9042C00KA0648G00
[1704418948.417475][5301:5301] CHIP:SPL: Version: 0
[1704418948.417480][5301:5301] CHIP:SPL: VendorID: 65521
[1704418948.417486][5301:5301] CHIP:SPL: ProductID: 32768
[1704418948.417492][5301:5301] CHIP:SPL: Custom flow: 0 (STANDARD)
[1704418948.417499][5301:5301] CHIP:SPL: Discovery Bitmask: 0x02 (BLE)
[1704418948.417506][5301:5301] CHIP:SPL: Long discriminator: 3840 (0xf00)
[1704418948.417513][5301:5301] CHIP:SPL: Passcode: 20202021
pairing onnetwork <node-id> <setup-pin-code>
: matter 장치가 네트워크에 연결된 상태에서 pin-code 만 알면 commission을 진행 할수 있습니다.
matter 장치는 ADV 하고 있는 상태이어야 합니다.
더보기
$ ./chip-tool pairing onnetwork 0x1234 20202021
[1704419563.279226][5315:5315] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704419563.279677][5315:5315] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704419563.279685][5315:5315] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704419563.281420][5315:5315] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704419563.281458][5315:5315] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704419563.281478][5315:5315] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704419563.281549][5315:5315] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-PQqKi2)
[1704419563.281669][5315:5315] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704419563.281679][5315:5315] CHIP:DL: NVS set: chip-counters/reboot-count = 9 (0x9)
[1704419563.281819][5315:5315] CHIP:DL: Got Ethernet interface: enp3s0
[1704419563.281913][5315:5315] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704419563.282047][5315:5315] CHIP:DL: Failed to get WiFi interface
[1704419563.282052][5315:5315] CHIP:DL: Failed to reset WiFi statistic counts
[1704419563.282062][5315:5315] CHIP:IN: UDP::Init bind&listen port=0
[1704419563.282089][5315:5315] CHIP:IN: UDP::Init bound to port=34705
[1704419563.282094][5315:5315] CHIP:IN: UDP::Init bind&listen port=0
[1704419563.282113][5315:5315] CHIP:IN: UDP::Init bound to port=33880
[1704419563.282117][5315:5315] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704419563.282122][5315:5315] CHIP:IN: TransportMgr initialized
[1704419563.282130][5315:5315] CHIP:FP: Initializing FabricTable from persistent storage
[1704419563.282160][5315:5315] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704419563.282558][5315:5315] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0xEC8B1014EB693A4D, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704419563.283487][5315:5315] CHIP:ZCL: Using ZAP configuration...
[1704419563.283909][5315:5315] CHIP:CTL: System State Initialized...
[1704419563.283953][5315:5315] CHIP:CTL: Setting attestation nonce to random value
[1704419563.283962][5315:5315] CHIP:CTL: Setting CSR nonce to random value
[1704419563.283974][5315:5315] CHIP:IN: UDP::Init bind&listen port=5550
[1704419563.284027][5315:5315] CHIP:IN: UDP::Init bound to port=5550
[1704419563.284032][5315:5315] CHIP:IN: UDP::Init bind&listen port=5550
[1704419563.284048][5315:5315] CHIP:IN: UDP::Init bound to port=5550
[1704419563.284052][5315:5315] CHIP:IN: TransportMgr initialized
[1704419563.284131][5315:5317] CHIP:DL: CHIP task running
[1704419563.284163][5315:5317] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704419563.284239][5315:5317] CHIP:CTL: Setting attestation nonce to random value
[1704419563.284264][5315:5317] CHIP:CTL: Setting CSR nonce to random value
[1704419563.284490][5315:5317] CHIP:CTL: Generating NOC
[1704419563.284716][5315:5317] CHIP:FP: Validating NOC chain
[1704419563.285075][5315:5317] CHIP:FP: NOC chain validation successful
[1704419563.285112][5315:5317] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704419563.285118][5315:5317] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704419563.285123][5315:5317] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704419563.285128][5315:5317] CHIP:TS: Retaining current Last Known Good Time
[1704419563.285503][5315:5317] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704419563.285882][5315:5317] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704419563.286239][5315:5317] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: EC8B1014EB693A4D)
[1704419563.286264][5315:5317] CHIP:IN: UDP::Init bind&listen port=5550
[1704419563.286298][5315:5317] CHIP:IN: UDP::Init bound to port=5550
[1704419563.286303][5315:5317] CHIP:IN: UDP::Init bind&listen port=5550
[1704419563.286319][5315:5317] CHIP:IN: UDP::Init bound to port=5550
[1704419563.286323][5315:5317] CHIP:IN: TransportMgr initialized
[1704419563.320834][5315:5317] CHIP:TOO: Discovered Device: fe80::424c:caff:fe43:1518:5540
[1704419563.321754][5315:5317] CHIP:IN: SecureSession[0x7f7e70010110]: Allocated Type:1 LSID:53377
[1704419563.321791][5315:5317] CHIP:SC: Assigned local session key ID 53377
[1704419563.321937][5315:5317] CHIP:EM: <<< [E:35793i S:0 M:63755940] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:20 (SecureChannel:PBKDFParamRequest)
[1704419563.322059][5315:5317] CHIP:SC: Sent PBKDF param request
[1704419563.322098][5315:5317] CHIP:CTL: Setting attestation nonce to random value
[1704419563.322128][5315:5317] CHIP:CTL: Setting CSR nonce to random value
[1704419563.322156][5315:5317] CHIP:CTL: Checking ICD registration parameters
[1704419563.322189][5315:5317] CHIP:CTL: Commission called for node ID 0x0000000000001234
[1704419563.322215][5315:5317] CHIP:CTL: Unknown filter type; all matches will fail
[1704419563.426525][5315:5317] CHIP:EM: >>> [E:35793i S:0 M:201993727 (Ack:63755940)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419563.426568][5315:5317] CHIP:EM: Found matching exchange: 35793i, Delegate: 0x7f7e700136b0
[1704419563.426600][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:63755940 from Retrans Table on exchange 35793i
[1704419563.495420][5315:5317] CHIP:EM: >>> [E:35793i S:0 M:201993728 (Ack:63755940)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:21 (SecureChannel:PBKDFParamResponse)
[1704419563.495464][5315:5317] CHIP:EM: Found matching exchange: 35793i, Delegate: 0x7f7e700136b0
[1704419563.495487][5315:5317] CHIP:EM: CHIP MessageCounter:63755940 not in RetransTable on exchange 35793i
[1704419563.495528][5315:5317] CHIP:SC: Received PBKDF param response
[1704419563.495565][5315:5317] CHIP:SC: Peer assigned session ID 31165
[1704419563.495594][5315:5317] CHIP:SC: Found MRP parameters in the message
[1704419563.501236][5315:5317] CHIP:EM: <<< [E:35793i S:0 M:63755941 (Ack:201993728)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:22 (SecureChannel:PASE_Pake1)
[1704419563.501261][5315:5317] CHIP:SC: Sent spake2p msg1
[1704419563.551655][5315:5317] CHIP:EM: >>> [E:35793i S:0 M:201993729 (Ack:63755941)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419563.551699][5315:5317] CHIP:EM: Found matching exchange: 35793i, Delegate: 0x7f7e700136b0
[1704419563.551730][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:63755941 from Retrans Table on exchange 35793i
[1704419563.702205][5315:5317] CHIP:EM: >>> [E:35793i S:0 M:201993730 (Ack:63755941)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:23 (SecureChannel:PASE_Pake2)
[1704419563.702248][5315:5317] CHIP:EM: Found matching exchange: 35793i, Delegate: 0x7f7e700136b0
[1704419563.702271][5315:5317] CHIP:EM: CHIP MessageCounter:63755941 not in RetransTable on exchange 35793i
[1704419563.702311][5315:5317] CHIP:SC: Received spake2p msg2
[1704419563.703526][5315:5317] CHIP:EM: <<< [E:35793i S:0 M:63755942 (Ack:201993730)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:24 (SecureChannel:PASE_Pake3)
[1704419563.703651][5315:5317] CHIP:SC: Sent spake2p msg3
[1704419563.906657][5315:5317] CHIP:EM: >>> [E:35793i S:0 M:201993731 (Ack:63755942)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419563.906701][5315:5317] CHIP:EM: Found matching exchange: 35793i, Delegate: 0x7f7e700136b0
[1704419563.906732][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:63755942 from Retrans Table on exchange 35793i
[1704419563.906812][5315:5317] CHIP:EM: >>> [E:35793i S:0 M:201993732 (Ack:63755942)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704419563.906839][5315:5317] CHIP:EM: Found matching exchange: 35793i, Delegate: 0x7f7e700136b0
[1704419563.906862][5315:5317] CHIP:EM: CHIP MessageCounter:63755942 not in RetransTable on exchange 35793i
[1704419563.907015][5315:5317] CHIP:SC: SecureSession[0x7f7e70010110, LSID:53377]: State change 'kEstablishing' --> 'kActive'
[1704419563.907042][5315:5317] CHIP:IN: SecureSession[0x7f7e70010110]: Activated - Type:1 LSID:53377
[1704419563.907063][5315:5317] CHIP:IN: New secure session activated for device <FFFFFFFB00000000, 0>, LSID:53377 PSID:31165!
[1704419563.907089][5315:5317] CHIP:CTL: Remote device completed SPAKE2+ handshake
[1704419563.907109][5315:5317] CHIP:TOO: Pairing Success
[1704419563.907128][5315:5317] CHIP:TOO: PASE establishment successful
[1704419563.907150][5315:5317] CHIP:CTL: Commissioning stage next step: 'SecurePairing' -> 'ReadCommissioningInfo'
[1704419563.907177][5315:5317] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo'
[1704419563.907195][5315:5317] CHIP:CTL: Sending read request for commissioning information
[1704419563.907232][5315:5317] CHIP:DMG: SendReadRequest ReadClient[0x7f7e7000a4c0]: Sending Read Request
[1704419563.907426][5315:5317] CHIP:EM: <<< [E:35794i S:53377 M:214323849] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:02 (IM:ReadRequest)
[1704419563.907546][5315:5317] CHIP:DMG: MoveToState ReadClient[0x7f7e7000a4c0]: Moving to [AwaitingIn]
[1704419563.907648][5315:5317] CHIP:EM: <<< [E:35793i S:0 M:63755943 (Ack:201993732)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419563.907719][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:201993732 on exchange 35793i
[1704419563.979132][5315:5317] CHIP:EM: >>> [E:35794i S:53377 M:215468094 (Ack:214323849)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1704419563.979175][5315:5317] CHIP:EM: Found matching exchange: 35794i, Delegate: 0x7f7e7000a4d0
[1704419563.979207][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323849 from Retrans Table on exchange 35794i
[1704419563.979310][5315:5317] CHIP:DMG: ReportDataMessage =
[1704419563.979333][5315:5317] CHIP:DMG: {
[1704419563.979354][5315:5317] CHIP:DMG: AttributeReportIBs =
[1704419563.979385][5315:5317] CHIP:DMG: [
[1704419563.979405][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.979435][5315:5317] CHIP:DMG: {
[1704419563.979456][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.979481][5315:5317] CHIP:DMG: {
[1704419563.979505][5315:5317] CHIP:DMG: DataVersion = 0xbc7c6af4,
[1704419563.979528][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.979552][5315:5317] CHIP:DMG: {
[1704419563.979577][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.979601][5315:5317] CHIP:DMG: Cluster = 0x31,
[1704419563.979627][5315:5317] CHIP:DMG: Attribute = 0x0000_0003,
[1704419563.979650][5315:5317] CHIP:DMG: }
[1704419563.979677][5315:5317] CHIP:DMG:
[1704419563.979703][5315:5317] CHIP:DMG: Data = 30,
[1704419563.979725][5315:5317] CHIP:DMG: },
[1704419563.979753][5315:5317] CHIP:DMG:
[1704419563.979774][5315:5317] CHIP:DMG: },
[1704419563.979811][5315:5317] CHIP:DMG:
[1704419563.979832][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.979861][5315:5317] CHIP:DMG: {
[1704419563.979882][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.979905][5315:5317] CHIP:DMG: {
[1704419563.979928][5315:5317] CHIP:DMG: DataVersion = 0xa4251638,
[1704419563.979950][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.979974][5315:5317] CHIP:DMG: {
[1704419563.980027][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.980051][5315:5317] CHIP:DMG: Cluster = 0x28,
[1704419563.980076][5315:5317] CHIP:DMG: Attribute = 0x0000_0004,
[1704419563.980099][5315:5317] CHIP:DMG: }
[1704419563.980125][5315:5317] CHIP:DMG:
[1704419563.980150][5315:5317] CHIP:DMG: Data = 32768,
[1704419563.980172][5315:5317] CHIP:DMG: },
[1704419563.980200][5315:5317] CHIP:DMG:
[1704419563.980221][5315:5317] CHIP:DMG: },
[1704419563.980255][5315:5317] CHIP:DMG:
[1704419563.980275][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.980303][5315:5317] CHIP:DMG: {
[1704419563.980323][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.980347][5315:5317] CHIP:DMG: {
[1704419563.980370][5315:5317] CHIP:DMG: DataVersion = 0xa4251638,
[1704419563.980392][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.980416][5315:5317] CHIP:DMG: {
[1704419563.980439][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.980464][5315:5317] CHIP:DMG: Cluster = 0x28,
[1704419563.980488][5315:5317] CHIP:DMG: Attribute = 0x0000_0002,
[1704419563.980512][5315:5317] CHIP:DMG: }
[1704419563.980538][5315:5317] CHIP:DMG:
[1704419563.980562][5315:5317] CHIP:DMG: Data = 65521,
[1704419563.980585][5315:5317] CHIP:DMG: },
[1704419563.980612][5315:5317] CHIP:DMG:
[1704419563.980633][5315:5317] CHIP:DMG: },
[1704419563.980668][5315:5317] CHIP:DMG:
[1704419563.980688][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.980716][5315:5317] CHIP:DMG: {
[1704419563.980736][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.980759][5315:5317] CHIP:DMG: {
[1704419563.980782][5315:5317] CHIP:DMG: DataVersion = 0xe1d4f7be,
[1704419563.980804][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.980828][5315:5317] CHIP:DMG: {
[1704419563.980851][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.980876][5315:5317] CHIP:DMG: Cluster = 0x30,
[1704419563.980900][5315:5317] CHIP:DMG: Attribute = 0x0000_0003,
[1704419563.980923][5315:5317] CHIP:DMG: }
[1704419563.980949][5315:5317] CHIP:DMG:
[1704419563.980973][5315:5317] CHIP:DMG: Data = 0,
[1704419563.980995][5315:5317] CHIP:DMG: },
[1704419563.981022][5315:5317] CHIP:DMG:
[1704419563.981043][5315:5317] CHIP:DMG: },
[1704419563.981079][5315:5317] CHIP:DMG:
[1704419563.981099][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.981127][5315:5317] CHIP:DMG: {
[1704419563.981148][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.981171][5315:5317] CHIP:DMG: {
[1704419563.981193][5315:5317] CHIP:DMG: DataVersion = 0xe1d4f7be,
[1704419563.981216][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.981241][5315:5317] CHIP:DMG: {
[1704419563.981264][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.981288][5315:5317] CHIP:DMG: Cluster = 0x30,
[1704419563.981313][5315:5317] CHIP:DMG: Attribute = 0x0000_0002,
[1704419563.981335][5315:5317] CHIP:DMG: }
[1704419563.981361][5315:5317] CHIP:DMG:
[1704419563.981385][5315:5317] CHIP:DMG: Data = 0,
[1704419563.981407][5315:5317] CHIP:DMG: },
[1704419563.981435][5315:5317] CHIP:DMG:
[1704419563.981456][5315:5317] CHIP:DMG: },
[1704419563.981494][5315:5317] CHIP:DMG:
[1704419563.981514][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.981544][5315:5317] CHIP:DMG: {
[1704419563.981565][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.981587][5315:5317] CHIP:DMG: {
[1704419563.981610][5315:5317] CHIP:DMG: DataVersion = 0xe1d4f7be,
[1704419563.981632][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.981656][5315:5317] CHIP:DMG: {
[1704419563.981680][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.981705][5315:5317] CHIP:DMG: Cluster = 0x30,
[1704419563.981729][5315:5317] CHIP:DMG: Attribute = 0x0000_0001,
[1704419563.981752][5315:5317] CHIP:DMG: }
[1704419563.981778][5315:5317] CHIP:DMG:
[1704419563.981801][5315:5317] CHIP:DMG: Data =
[1704419563.981825][5315:5317] CHIP:DMG: {
[1704419563.981850][5315:5317] CHIP:DMG: 0x0 = 60,
[1704419563.981875][5315:5317] CHIP:DMG: 0x1 = 900,
[1704419563.981900][5315:5317] CHIP:DMG: },
[1704419563.981922][5315:5317] CHIP:DMG: },
[1704419563.981951][5315:5317] CHIP:DMG:
[1704419563.981973][5315:5317] CHIP:DMG: },
[1704419563.982009][5315:5317] CHIP:DMG:
[1704419563.982030][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.982057][5315:5317] CHIP:DMG: {
[1704419563.982078][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.982101][5315:5317] CHIP:DMG: {
[1704419563.982124][5315:5317] CHIP:DMG: DataVersion = 0xe1d4f7be,
[1704419563.982146][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.982170][5315:5317] CHIP:DMG: {
[1704419563.982193][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.982217][5315:5317] CHIP:DMG: Cluster = 0x30,
[1704419563.982242][5315:5317] CHIP:DMG: Attribute = 0x0000_0000,
[1704419563.982264][5315:5317] CHIP:DMG: }
[1704419563.982290][5315:5317] CHIP:DMG:
[1704419563.982315][5315:5317] CHIP:DMG: Data = 0,
[1704419563.982336][5315:5317] CHIP:DMG: },
[1704419563.982363][5315:5317] CHIP:DMG:
[1704419563.982384][5315:5317] CHIP:DMG: },
[1704419563.982418][5315:5317] CHIP:DMG:
[1704419563.982439][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419563.982466][5315:5317] CHIP:DMG: {
[1704419563.982487][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419563.982509][5315:5317] CHIP:DMG: {
[1704419563.982514][5315:5317] CHIP:DMG: DataVersion = 0xbc7c6af4,
[1704419563.982518][5315:5317] CHIP:DMG: AttributePathIB =
[1704419563.982524][5315:5317] CHIP:DMG: {
[1704419563.982528][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419563.982534][5315:5317] CHIP:DMG: Cluster = 0x31,
[1704419563.982539][5315:5317] CHIP:DMG: Attribute = 0x0000_FFFC,
[1704419563.982544][5315:5317] CHIP:DMG: }
[1704419563.982549][5315:5317] CHIP:DMG:
[1704419563.982554][5315:5317] CHIP:DMG: Data = 1,
[1704419563.982559][5315:5317] CHIP:DMG: },
[1704419563.982565][5315:5317] CHIP:DMG:
[1704419563.982569][5315:5317] CHIP:DMG: },
[1704419563.982575][5315:5317] CHIP:DMG:
[1704419563.982579][5315:5317] CHIP:DMG: ],
[1704419563.982594][5315:5317] CHIP:DMG:
[1704419563.982599][5315:5317] CHIP:DMG: SuppressResponse = true,
[1704419563.982603][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419563.982607][5315:5317] CHIP:DMG: }
[1704419563.982798][5315:5317] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo'
[1704419563.982804][5315:5317] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo' -> 'ReadCommissioningInfo2'
[1704419563.982810][5315:5317] CHIP:CTL: Performing next commissioning step 'ReadCommissioningInfo2'
[1704419563.982817][5315:5317] CHIP:DMG: SendReadRequest ReadClient[0x7f7e7000a4c0]: Sending Read Request
[1704419563.982852][5315:5317] CHIP:EM: <<< [E:35795i S:53377 M:214323850] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:02 (IM:ReadRequest)
[1704419563.982877][5315:5317] CHIP:DMG: MoveToState ReadClient[0x7f7e7000a4c0]: Moving to [AwaitingIn]
[1704419563.982904][5315:5317] CHIP:EM: <<< [E:35794i S:53377 M:214323851 (Ack:215468094)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419563.982919][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468094 on exchange 35794i
[1704419564.058781][5315:5317] CHIP:EM: >>> [E:35795i S:53377 M:215468095 (Ack:214323850)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:05 (IM:ReportData)
[1704419564.058825][5315:5317] CHIP:EM: Found matching exchange: 35795i, Delegate: 0x7f7e7000a4d0
[1704419564.058856][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323850 from Retrans Table on exchange 35795i
[1704419564.058930][5315:5317] CHIP:DMG: ReportDataMessage =
[1704419564.058954][5315:5317] CHIP:DMG: {
[1704419564.058973][5315:5317] CHIP:DMG: AttributeReportIBs =
[1704419564.059003][5315:5317] CHIP:DMG: [
[1704419564.059023][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419564.059053][5315:5317] CHIP:DMG: {
[1704419564.059075][5315:5317] CHIP:DMG: AttributeStatusIB =
[1704419564.059099][5315:5317] CHIP:DMG: {
[1704419564.059120][5315:5317] CHIP:DMG: AttributePathIB =
[1704419564.059145][5315:5317] CHIP:DMG: {
[1704419564.059170][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419564.059195][5315:5317] CHIP:DMG: Cluster = 0x46,
[1704419564.059219][5315:5317] CHIP:DMG: Attribute = 0x0000_FFFC,
[1704419564.059244][5315:5317] CHIP:DMG: }
[1704419564.059273][5315:5317] CHIP:DMG:
[1704419564.059296][5315:5317] CHIP:DMG: StatusIB =
[1704419564.059321][5315:5317] CHIP:DMG: {
[1704419564.059345][5315:5317] CHIP:DMG: status = 0xc3 (UNSUPPORTED_CLUSTER),
[1704419564.059369][5315:5317] CHIP:DMG: },
[1704419564.059394][5315:5317] CHIP:DMG:
[1704419564.059416][5315:5317] CHIP:DMG: },
[1704419564.059444][5315:5317] CHIP:DMG:
[1704419564.059465][5315:5317] CHIP:DMG: },
[1704419564.059500][5315:5317] CHIP:DMG:
[1704419564.059521][5315:5317] CHIP:DMG: AttributeReportIB =
[1704419564.059549][5315:5317] CHIP:DMG: {
[1704419564.059570][5315:5317] CHIP:DMG: AttributeDataIB =
[1704419564.059594][5315:5317] CHIP:DMG: {
[1704419564.059617][5315:5317] CHIP:DMG: DataVersion = 0xe1d4f7be,
[1704419564.059640][5315:5317] CHIP:DMG: AttributePathIB =
[1704419564.059664][5315:5317] CHIP:DMG: {
[1704419564.059688][5315:5317] CHIP:DMG: Endpoint = 0x0,
[1704419564.059712][5315:5317] CHIP:DMG: Cluster = 0x30,
[1704419564.059737][5315:5317] CHIP:DMG: Attribute = 0x0000_0004,
[1704419564.059761][5315:5317] CHIP:DMG: }
[1704419564.059787][5315:5317] CHIP:DMG:
[1704419564.059813][5315:5317] CHIP:DMG: Data = true,
[1704419564.059835][5315:5317] CHIP:DMG: },
[1704419564.059862][5315:5317] CHIP:DMG:
[1704419564.059883][5315:5317] CHIP:DMG: },
[1704419564.059910][5315:5317] CHIP:DMG:
[1704419564.059930][5315:5317] CHIP:DMG: ],
[1704419564.059965][5315:5317] CHIP:DMG:
[1704419564.060014][5315:5317] CHIP:DMG: SuppressResponse = true,
[1704419564.060034][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.060052][5315:5317] CHIP:DMG: }
[1704419564.060439][5315:5317] CHIP:CTL: ----- NetworkCommissioning Features: has WiFi. endpointid = 0
[1704419564.060511][5315:5317] CHIP:CTL: Successfully finished commissioning step 'ReadCommissioningInfo2'
[1704419564.060538][5315:5317] CHIP:CTL: Commissioning stage next step: 'ReadCommissioningInfo2' -> 'ArmFailSafe'
[1704419564.060570][5315:5317] CHIP:CTL: Performing next commissioning step 'ArmFailSafe'
[1704419564.060591][5315:5317] CHIP:CTL: Arming failsafe (60 seconds)
[1704419564.060643][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.060669][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.060814][5315:5317] CHIP:EM: <<< [E:35796i S:53377 M:214323852] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.060935][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.061062][5315:5317] CHIP:EM: <<< [E:35795i S:53377 M:214323853 (Ack:215468095)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.061133][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468095 on exchange 35795i
[1704419564.215665][5315:5317] CHIP:EM: >>> [E:35796i S:53377 M:215468096 (Ack:214323852)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.215709][5315:5317] CHIP:EM: Found matching exchange: 35796i, Delegate: 0x7f7e7000a4c8
[1704419564.215740][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323852 from Retrans Table on exchange 35796i
[1704419564.215774][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.215820][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.215842][5315:5317] CHIP:DMG: {
[1704419564.215862][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.215884][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.215915][5315:5317] CHIP:DMG: [
[1704419564.215936][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.215967][5315:5317] CHIP:DMG: {
[1704419564.216013][5315:5317] CHIP:DMG: CommandDataIB =
[1704419564.216036][5315:5317] CHIP:DMG: {
[1704419564.216056][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.216081][5315:5317] CHIP:DMG: {
[1704419564.216106][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.216131][5315:5317] CHIP:DMG: ClusterId = 0x30,
[1704419564.216156][5315:5317] CHIP:DMG: CommandId = 0x1,
[1704419564.216179][5315:5317] CHIP:DMG: },
[1704419564.216205][5315:5317] CHIP:DMG:
[1704419564.216228][5315:5317] CHIP:DMG: CommandFields =
[1704419564.216253][5315:5317] CHIP:DMG: {
[1704419564.216279][5315:5317] CHIP:DMG: 0x0 = 0,
[1704419564.216306][5315:5317] CHIP:DMG: 0x1 = "" (0 chars),
[1704419564.216331][5315:5317] CHIP:DMG: },
[1704419564.216353][5315:5317] CHIP:DMG: },
[1704419564.216382][5315:5317] CHIP:DMG:
[1704419564.216403][5315:5317] CHIP:DMG: },
[1704419564.216432][5315:5317] CHIP:DMG:
[1704419564.216452][5315:5317] CHIP:DMG: ],
[1704419564.216482][5315:5317] CHIP:DMG:
[1704419564.216504][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.216524][5315:5317] CHIP:DMG: },
[1704419564.216597][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0001
[1704419564.216654][5315:5317] CHIP:CTL: Received ArmFailSafe response errorCode=0
[1704419564.216681][5315:5317] CHIP:CTL: Successfully finished commissioning step 'ArmFailSafe'
[1704419564.216702][5315:5317] CHIP:CTL: Commissioning stage next step: 'ArmFailSafe' -> 'ConfigRegulatory'
[1704419564.216733][5315:5317] CHIP:CTL: Performing next commissioning step 'ConfigRegulatory'
[1704419564.216753][5315:5317] CHIP:CTL: Setting Regulatory Config
[1704419564.216772][5315:5317] CHIP:CTL: Device does not support configurable regulatory location
[1704419564.216822][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.216851][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.216996][5315:5317] CHIP:EM: <<< [E:35797i S:53377 M:214323854] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.217115][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.217178][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.217293][5315:5317] CHIP:EM: <<< [E:35796i S:53377 M:214323855 (Ack:215468096)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.217365][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468096 on exchange 35796i
[1704419564.283127][5315:5317] CHIP:EM: >>> [E:35797i S:53377 M:215468097 (Ack:214323854)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.283171][5315:5317] CHIP:EM: Found matching exchange: 35797i, Delegate: 0x7f7e70009418
[1704419564.283203][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323854 from Retrans Table on exchange 35797i
[1704419564.283236][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.283281][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.283303][5315:5317] CHIP:DMG: {
[1704419564.283323][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.283344][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.283376][5315:5317] CHIP:DMG: [
[1704419564.283397][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.283428][5315:5317] CHIP:DMG: {
[1704419564.283449][5315:5317] CHIP:DMG: CommandDataIB =
[1704419564.283473][5315:5317] CHIP:DMG: {
[1704419564.283495][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.283521][5315:5317] CHIP:DMG: {
[1704419564.283545][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.283569][5315:5317] CHIP:DMG: ClusterId = 0x30,
[1704419564.283593][5315:5317] CHIP:DMG: CommandId = 0x3,
[1704419564.283617][5315:5317] CHIP:DMG: },
[1704419564.283643][5315:5317] CHIP:DMG:
[1704419564.283666][5315:5317] CHIP:DMG: CommandFields =
[1704419564.283692][5315:5317] CHIP:DMG: {
[1704419564.283718][5315:5317] CHIP:DMG: 0x0 = 0,
[1704419564.283745][5315:5317] CHIP:DMG: 0x1 = "" (0 chars),
[1704419564.283771][5315:5317] CHIP:DMG: },
[1704419564.283793][5315:5317] CHIP:DMG: },
[1704419564.283822][5315:5317] CHIP:DMG:
[1704419564.283843][5315:5317] CHIP:DMG: },
[1704419564.283872][5315:5317] CHIP:DMG:
[1704419564.283892][5315:5317] CHIP:DMG: ],
[1704419564.283922][5315:5317] CHIP:DMG:
[1704419564.283944][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.283964][5315:5317] CHIP:DMG: },
[1704419564.284065][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0003
[1704419564.284100][5315:5317] CHIP:CTL: Received SetRegulatoryConfig response errorCode=0
[1704419564.284127][5315:5317] CHIP:CTL: Successfully finished commissioning step 'ConfigRegulatory'
[1704419564.284148][5315:5317] CHIP:CTL: Commissioning stage next step: 'ConfigRegulatory' -> 'SendPAICertificateRequest'
[1704419564.284179][5315:5317] CHIP:CTL: Performing next commissioning step 'SendPAICertificateRequest'
[1704419564.284198][5315:5317] CHIP:CTL: Sending request for PAI certificate
[1704419564.284218][5315:5317] CHIP:CTL: Sending Certificate Chain request to 0x7f7e70013660 device
[1704419564.284266][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.284291][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.284450][5315:5317] CHIP:EM: <<< [E:35798i S:53377 M:214323856] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.284570][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.284634][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.284751][5315:5317] CHIP:EM: <<< [E:35797i S:53377 M:214323857 (Ack:215468097)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.284823][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468097 on exchange 35797i
[1704419564.353505][5315:5317] CHIP:EM: >>> [E:35798i S:53377 M:215468098 (Ack:214323856)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.353549][5315:5317] CHIP:EM: Found matching exchange: 35798i, Delegate: 0x7f7e7000a4c8
[1704419564.353581][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323856 from Retrans Table on exchange 35798i
[1704419564.353614][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.353661][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.353683][5315:5317] CHIP:DMG: {
[1704419564.353704][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.353726][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.353754][5315:5317] CHIP:DMG: [
[1704419564.353774][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.353805][5315:5317] CHIP:DMG: {
[1704419564.353826][5315:5317] CHIP:DMG: CommandDataIB =
[1704419564.353849][5315:5317] CHIP:DMG: {
[1704419564.353871][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.353896][5315:5317] CHIP:DMG: {
[1704419564.353921][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.353946][5315:5317] CHIP:DMG: ClusterId = 0x3e,
[1704419564.353970][5315:5317] CHIP:DMG: CommandId = 0x3,
[1704419564.353994][5315:5317] CHIP:DMG: },
[1704419564.354021][5315:5317] CHIP:DMG:
[1704419564.354044][5315:5317] CHIP:DMG: CommandFields =
[1704419564.354068][5315:5317] CHIP:DMG: {
[1704419564.354093][5315:5317] CHIP:DMG: 0x0 = [
[1704419564.354218][5315:5317] CHIP:DMG: 0x30, 0x82, 0x01, 0xcb, 0x30, 0x82, 0x01, 0x71, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x56, 0xad, 0x82, 0x22, 0xad, 0x94, 0x5b, 0x64, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x30, 0x31, 0x18, 0x30, 0x16, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x0f, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x54, 0x65, 0x73, 0x74, 0x20, 0x50, 0x41, 0x41, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x41, 0x9a, 0x93, 0x15, 0xc2, 0x17, 0x3e, 0x0c, 0x8c, 0x87, 0x6d, 0x03, 0xcc, 0xfc, 0x94, 0x48, 0x52, 0x64, 0x7f, 0x7f, 0xec, 0x5e, 0x50, 0x82, 0xf4, 0x05, 0x99, 0x28, 0xec, 0xa8, 0x94, 0xc5, 0x94, 0x15, 0x13, 0x09, 0xac, 0x63, 0x1e, 0x4c, 0xb0, 0x33, 0x92, 0xaf, 0x68, 0x4b, 0x0b, 0xaf, 0xb7, 0xe6, 0x5b, 0x3b, 0x81, 0x62, 0xc2, 0xf5, 0x2b, 0xf9, 0x31, 0xb8, 0xe7, 0x7a, 0xaa, 0x82, 0xa3, 0x66, 0x30, 0x64, 0x30, 0x12, 0x06, 0x03, 0x55, 0x1d, 0x
[1704419564.354291][5315:5317] CHIP:DMG: ] (463 bytes)
[1704419564.354316][5315:5317] CHIP:DMG: },
[1704419564.354338][5315:5317] CHIP:DMG: },
[1704419564.354367][5315:5317] CHIP:DMG:
[1704419564.354388][5315:5317] CHIP:DMG: },
[1704419564.354416][5315:5317] CHIP:DMG:
[1704419564.354436][5315:5317] CHIP:DMG: ],
[1704419564.354467][5315:5317] CHIP:DMG:
[1704419564.354487][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.354508][5315:5317] CHIP:DMG: },
[1704419564.354579][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1704419564.354613][5315:5317] CHIP:CTL: Received certificate chain from the device
[1704419564.354638][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendPAICertificateRequest'
[1704419564.354662][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendPAICertificateRequest' -> 'SendDACCertificateRequest'
[1704419564.354692][5315:5317] CHIP:CTL: Performing next commissioning step 'SendDACCertificateRequest'
[1704419564.354712][5315:5317] CHIP:CTL: Sending request for DAC certificate
[1704419564.354732][5315:5317] CHIP:CTL: Sending Certificate Chain request to 0x7f7e70013660 device
[1704419564.354779][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.354804][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.354947][5315:5317] CHIP:EM: <<< [E:35799i S:53377 M:214323858] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.355067][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.355129][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.355243][5315:5317] CHIP:EM: <<< [E:35798i S:53377 M:214323859 (Ack:215468098)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.355313][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468098 on exchange 35798i
[1704419564.417223][5315:5317] CHIP:EM: >>> [E:35799i S:53377 M:215468099 (Ack:214323858)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.417267][5315:5317] CHIP:EM: Found matching exchange: 35799i, Delegate: 0x7f7e70009418
[1704419564.417299][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323858 from Retrans Table on exchange 35799i
[1704419564.417331][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.417378][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.417400][5315:5317] CHIP:DMG: {
[1704419564.417420][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.417441][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.417471][5315:5317] CHIP:DMG: [
[1704419564.417493][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.417525][5315:5317] CHIP:DMG: {
[1704419564.417546][5315:5317] CHIP:DMG: CommandDataIB =
[1704419564.417569][5315:5317] CHIP:DMG: {
[1704419564.417591][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.417616][5315:5317] CHIP:DMG: {
[1704419564.417641][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.417666][5315:5317] CHIP:DMG: ClusterId = 0x3e,
[1704419564.417691][5315:5317] CHIP:DMG: CommandId = 0x3,
[1704419564.417713][5315:5317] CHIP:DMG: },
[1704419564.417740][5315:5317] CHIP:DMG:
[1704419564.417763][5315:5317] CHIP:DMG: CommandFields =
[1704419564.417788][5315:5317] CHIP:DMG: {
[1704419564.417813][5315:5317] CHIP:DMG: 0x0 = [
[1704419564.417937][5315:5317] CHIP:DMG: 0x30, 0x82, 0x01, 0xe9, 0x30, 0x82, 0x01, 0x8e, 0xa0, 0x03, 0x02, 0x01, 0x02, 0x02, 0x08, 0x23, 0x8a, 0x64, 0x7b, 0xbc, 0x4c, 0x30, 0xdd, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x30, 0x3d, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x50, 0x41, 0x49, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x20, 0x6e, 0x6f, 0x20, 0x50, 0x49, 0x44, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x30, 0x20, 0x17, 0x0d, 0x32, 0x32, 0x30, 0x32, 0x30, 0x35, 0x30, 0x30, 0x30, 0x30, 0x30, 0x30, 0x5a, 0x18, 0x0f, 0x39, 0x39, 0x39, 0x39, 0x31, 0x32, 0x33, 0x31, 0x32, 0x33, 0x35, 0x39, 0x35, 0x39, 0x5a, 0x30, 0x53, 0x31, 0x25, 0x30, 0x23, 0x06, 0x03, 0x55, 0x04, 0x03, 0x0c, 0x1c, 0x4d, 0x61, 0x74, 0x74, 0x65, 0x72, 0x20, 0x44, 0x65, 0x76, 0x20, 0x44, 0x41, 0x43, 0x20, 0x30, 0x78, 0x46, 0x46, 0x46, 0x31, 0x2f, 0x30, 0x78, 0x38, 0x30, 0x30, 0x30, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x01, 0x0c, 0x04, 0x46, 0x46, 0x46, 0x31, 0x31, 0x14, 0x30, 0x12, 0x06, 0x0a, 0x2b, 0x06, 0x01, 0x04, 0x01, 0x82, 0xa2, 0x7c, 0x02, 0x02, 0x0c, 0x04, 0x38, 0x30, 0x30, 0x30, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0x62, 0xdb, 0x16, 0xba, 0xde, 0xa3, 0x26, 0xa6, 0xdb, 0x84, 0x81, 0x4a, 0x06, 0x3f, 0xc6, 0xc7, 0xe9, 0xe2, 0xb1, 0x01, 0xb7, 0x21, 0x64, 0x8e, 0xba, 0x4e, 0x5a, 0xc8, 0x40, 0xf5, 0xda, 0x30, 0x1e, 0xe6, 0x18, 0x12, 0x4e, 0xb4, 0x18, 0x
[1704419564.418010][5315:5317] CHIP:DMG: ] (493 bytes)
[1704419564.418035][5315:5317] CHIP:DMG: },
[1704419564.418057][5315:5317] CHIP:DMG: },
[1704419564.418085][5315:5317] CHIP:DMG:
[1704419564.418106][5315:5317] CHIP:DMG: },
[1704419564.418135][5315:5317] CHIP:DMG:
[1704419564.418156][5315:5317] CHIP:DMG: ],
[1704419564.418186][5315:5317] CHIP:DMG:
[1704419564.418207][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.418227][5315:5317] CHIP:DMG: },
[1704419564.418303][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0003
[1704419564.418336][5315:5317] CHIP:CTL: Received certificate chain from the device
[1704419564.418362][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendDACCertificateRequest'
[1704419564.418387][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendDACCertificateRequest' -> 'SendAttestationRequest'
[1704419564.418418][5315:5317] CHIP:CTL: Performing next commissioning step 'SendAttestationRequest'
[1704419564.418437][5315:5317] CHIP:CTL: Sending Attestation Request to the device.
[1704419564.418457][5315:5317] CHIP:CTL: Sending Attestation request to 0x7f7e70013660 device
[1704419564.418506][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.418531][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.418675][5315:5317] CHIP:EM: <<< [E:35800i S:53377 M:214323860] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.418794][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.418825][5315:5317] CHIP:CTL: Sent Attestation request, waiting for the Attestation Information
[1704419564.418876][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.418990][5315:5317] CHIP:EM: <<< [E:35799i S:53377 M:214323861 (Ack:215468099)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.419062][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468099 on exchange 35799i
[1704419564.493804][5315:5317] CHIP:EM: >>> [E:35800i S:53377 M:215468100 (Ack:214323860)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.493848][5315:5317] CHIP:EM: Found matching exchange: 35800i, Delegate: 0x7f7e7000a4c8
[1704419564.493880][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323860 from Retrans Table on exchange 35800i
[1704419564.515481][5315:5317] CHIP:EM: >>> [E:35800i S:53377 M:215468101 (Ack:214323860)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.515526][5315:5317] CHIP:EM: Found matching exchange: 35800i, Delegate: 0x7f7e7000a4c8
[1704419564.515549][5315:5317] CHIP:EM: CHIP MessageCounter:214323860 not in RetransTable on exchange 35800i
[1704419564.515580][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.515627][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.515648][5315:5317] CHIP:DMG: {
[1704419564.515667][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.515686][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.515720][5315:5317] CHIP:DMG: [
[1704419564.515741][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.515772][5315:5317] CHIP:DMG: {
[1704419564.515793][5315:5317] CHIP:DMG: CommandDataIB =
[1704419564.515818][5315:5317] CHIP:DMG: {
[1704419564.515838][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.515863][5315:5317] CHIP:DMG: {
[1704419564.515887][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.515913][5315:5317] CHIP:DMG: ClusterId = 0x3e,
[1704419564.515937][5315:5317] CHIP:DMG: CommandId = 0x1,
[1704419564.515960][5315:5317] CHIP:DMG: },
[1704419564.516012][5315:5317] CHIP:DMG:
[1704419564.516036][5315:5317] CHIP:DMG: CommandFields =
[1704419564.516061][5315:5317] CHIP:DMG: {
[1704419564.516085][5315:5317] CHIP:DMG: 0x0 = [
[1704419564.516217][5315:5317] CHIP:DMG: 0x15, 0x31, 0x01, 0x1b, 0x02, 0x30, 0x82, 0x02, 0x17, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x02, 0xa0, 0x82, 0x02, 0x08, 0x30, 0x82, 0x02, 0x04, 0x02, 0x01, 0x03, 0x31, 0x0d, 0x30, 0x0b, 0x06, 0x09, 0x60, 0x86, 0x48, 0x01, 0x65, 0x03, 0x04, 0x02, 0x01, 0x30, 0x82, 0x01, 0x70, 0x06, 0x09, 0x2a, 0x86, 0x48, 0x86, 0xf7, 0x0d, 0x01, 0x07, 0x01, 0xa0, 0x82, 0x01, 0x61, 0x04, 0x82, 0x01, 0x5d, 0x15, 0x24, 0x00, 0x01, 0x25, 0x01, 0xf1, 0xff, 0x36, 0x02, 0x05, 0x00, 0x80, 0x05, 0x01, 0x80, 0x05, 0x02, 0x80, 0x05, 0x03, 0x80, 0x05, 0x04, 0x80, 0x05, 0x05, 0x80, 0x05, 0x06, 0x80, 0x05, 0x07, 0x80, 0x05, 0x08, 0x80, 0x05, 0x09, 0x80, 0x05, 0x0a, 0x80, 0x05, 0x0b, 0x80, 0x05, 0x0c, 0x80, 0x05, 0x0d, 0x80, 0x05, 0x0e, 0x80, 0x05, 0x0f, 0x80, 0x05, 0x10, 0x80, 0x05, 0x11, 0x80, 0x05, 0x12, 0x80, 0x05, 0x13, 0x80, 0x05, 0x14, 0x80, 0x05, 0x15, 0x80, 0x05, 0x16, 0x80, 0x05, 0x17, 0x80, 0x05, 0x18, 0x80, 0x05, 0x19, 0x80, 0x05, 0x1a, 0x80, 0x05, 0x1b, 0x80, 0x05, 0x1c, 0x80, 0x05, 0x1d, 0x80, 0x05, 0x1e, 0x80, 0x05, 0x1f, 0x80, 0x05, 0x20, 0x80, 0x05, 0x21, 0x80, 0x05, 0x22, 0x80, 0x05, 0x23, 0x80, 0x05, 0x24, 0x80, 0x05, 0x25, 0x80, 0x05, 0x26, 0x80, 0x05, 0x27, 0x80, 0x05, 0x28, 0x80, 0x05, 0x29, 0x80, 0x05, 0x2a, 0x80, 0x05, 0x2b, 0x80, 0x05, 0x2c, 0x80, 0x05, 0x2d, 0x80, 0x05, 0x2e, 0x80, 0x05, 0x2f, 0x80, 0x05, 0x30, 0x80, 0x05, 0x31, 0x80, 0x05, 0x32, 0x80, 0x05, 0x33, 0x80, 0x05, 0x34, 0x80, 0x05, 0x35, 0x80, 0x05, 0x36, 0x80, 0x05, 0x37, 0x80, 0x05, 0x38, 0x80, 0x05, 0x39, 0x80, 0x05, 0x3a, 0x80, 0x05, 0x3b, 0x80, 0x05, 0x3c, 0x80, 0x05, 0x3d, 0x80, 0x05, 0x3e, 0x80, 0x05, 0x3f, 0x80, 0x05, 0x40, 0x80, 0x05, 0x41, 0x80, 0x05, 0x42, 0x80, 0x05, 0x43, 0x80, 0x
[1704419564.516289][5315:5317] CHIP:DMG: ] (583 bytes)
[1704419564.516314][5315:5317] CHIP:DMG: 0x1 = [
[1704419564.516358][5315:5317] CHIP:DMG: 0x6d, 0xb7, 0xa6, 0x43, 0x23, 0x56, 0xa2, 0xcf, 0xcc, 0x96, 0x12, 0x8f, 0xbb, 0x3b, 0x58, 0x50, 0xcd, 0xa7, 0x0f, 0x39, 0x2f, 0x84, 0x94, 0xce, 0xf2, 0x1b, 0xe5, 0x33, 0x02, 0x59, 0x71, 0xa3, 0xc1, 0xcc, 0xda, 0xc4, 0x57, 0x42, 0xaf, 0x3e, 0x7c, 0x54, 0x81, 0x80, 0x27, 0xe8, 0x8e, 0x56, 0xc8, 0x98, 0x9c, 0x0f, 0xa1, 0x66, 0xd4, 0x5c, 0xa9, 0xb6, 0xdd, 0xe1, 0x25, 0x79, 0x71, 0x21,
[1704419564.516393][5315:5317] CHIP:DMG: ] (64 bytes)
[1704419564.516417][5315:5317] CHIP:DMG: },
[1704419564.516440][5315:5317] CHIP:DMG: },
[1704419564.516471][5315:5317] CHIP:DMG:
[1704419564.516493][5315:5317] CHIP:DMG: },
[1704419564.516523][5315:5317] CHIP:DMG:
[1704419564.516543][5315:5317] CHIP:DMG: ],
[1704419564.516574][5315:5317] CHIP:DMG:
[1704419564.516595][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.516615][5315:5317] CHIP:DMG: },
[1704419564.516689][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0001
[1704419564.516725][5315:5317] CHIP:CTL: Received Attestation Information from the device
[1704419564.516753][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendAttestationRequest'
[1704419564.516776][5315:5317] CHIP:CTL: AutoCommissioner setting attestationElements buffer size 583/583
[1704419564.516819][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendAttestationRequest' -> 'AttestationVerification'
[1704419564.516851][5315:5317] CHIP:CTL: Performing next commissioning step 'AttestationVerification'
[1704419564.516871][5315:5317] CHIP:CTL: Verifying attestation
[1704419564.527850][5315:5317] CHIP:CTL: Successfully validated 'Attestation Information' command received from the device.
[1704419564.527859][5315:5317] CHIP:CTL: Successfully finished commissioning step 'AttestationVerification'
[1704419564.527864][5315:5317] CHIP:CTL: Commissioning stage next step: 'AttestationVerification' -> 'SendOpCertSigningRequest'
[1704419564.527870][5315:5317] CHIP:CTL: Performing next commissioning step 'SendOpCertSigningRequest'
[1704419564.527874][5315:5317] CHIP:CTL: Sending CSR request to 0x7f7e70013660 device
[1704419564.527886][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.527892][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.527924][5315:5317] CHIP:EM: <<< [E:35801i S:53377 M:214323862] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.527949][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.527955][5315:5317] CHIP:CTL: Sent CSR request, waiting for the CSR
[1704419564.527967][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.527997][5315:5317] CHIP:EM: <<< [E:35800i S:53377 M:214323863 (Ack:215468101)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.528014][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468101 on exchange 35800i
[1704419564.590480][5315:5317] CHIP:EM: >>> [E:35801i S:53377 M:215468102 (Ack:214323862)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.590525][5315:5317] CHIP:EM: Found matching exchange: 35801i, Delegate: 0x7f7e70024d78
[1704419564.590556][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323862 from Retrans Table on exchange 35801i
[1704419564.678141][5315:5317] CHIP:EM: >>> [E:35801i S:53377 M:215468103 (Ack:214323862)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.678186][5315:5317] CHIP:EM: Found matching exchange: 35801i, Delegate: 0x7f7e70024d78
[1704419564.678209][5315:5317] CHIP:EM: CHIP MessageCounter:214323862 not in RetransTable on exchange 35801i
[1704419564.678241][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.678288][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.678310][5315:5317] CHIP:DMG: {
[1704419564.678331][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.678353][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.678383][5315:5317] CHIP:DMG: [
[1704419564.678404][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.678435][5315:5317] CHIP:DMG: {
[1704419564.678456][5315:5317] CHIP:DMG: CommandDataIB =
[1704419564.678479][5315:5317] CHIP:DMG: {
[1704419564.678501][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.678526][5315:5317] CHIP:DMG: {
[1704419564.678552][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.678577][5315:5317] CHIP:DMG: ClusterId = 0x3e,
[1704419564.678601][5315:5317] CHIP:DMG: CommandId = 0x5,
[1704419564.678626][5315:5317] CHIP:DMG: },
[1704419564.678652][5315:5317] CHIP:DMG:
[1704419564.678674][5315:5317] CHIP:DMG: CommandFields =
[1704419564.678700][5315:5317] CHIP:DMG: {
[1704419564.678724][5315:5317] CHIP:DMG: 0x0 = [
[1704419564.678831][5315:5317] CHIP:DMG: 0x15, 0x30, 0x01, 0xca, 0x30, 0x81, 0xc7, 0x30, 0x70, 0x02, 0x01, 0x00, 0x30, 0x0e, 0x31, 0x0c, 0x30, 0x0a, 0x06, 0x03, 0x55, 0x04, 0x0a, 0x0c, 0x03, 0x43, 0x53, 0x52, 0x30, 0x59, 0x30, 0x13, 0x06, 0x07, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x02, 0x01, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x03, 0x01, 0x07, 0x03, 0x42, 0x00, 0x04, 0xe3, 0x7d, 0x0a, 0x33, 0x14, 0x4d, 0xee, 0xcc, 0x63, 0x36, 0xcc, 0x69, 0x3f, 0x50, 0x02, 0x57, 0x7a, 0x01, 0xa7, 0x1f, 0xad, 0xe3, 0xd7, 0xd6, 0x1e, 0x80, 0x45, 0x02, 0x9d, 0x2e, 0x93, 0x5f, 0xf6, 0x41, 0x29, 0xfb, 0x72, 0x47, 0xb1, 0xd4, 0x1f, 0xc1, 0x88, 0x8b, 0x93, 0x2d, 0xcd, 0x82, 0xec, 0xf1, 0x5a, 0x66, 0x2d, 0x62, 0x9e, 0xea, 0x98, 0x48, 0x67, 0x6f, 0xac, 0x79, 0x8e, 0x60, 0xa0, 0x00, 0x30, 0x0a, 0x06, 0x08, 0x2a, 0x86, 0x48, 0xce, 0x3d, 0x04, 0x03, 0x02, 0x03, 0x47, 0x00, 0x30, 0x44, 0x02, 0x20, 0x7f, 0xfa, 0x81, 0xff, 0x62, 0x69, 0xed, 0x4c, 0xbb, 0xa4, 0xd2, 0xbf, 0xda, 0x31, 0x0b, 0x7f, 0x01, 0xa6, 0x8a, 0x4f, 0x79, 0x00, 0xa5, 0x24, 0x39, 0xfd, 0x3c, 0xf6, 0xa0, 0xf6, 0xce, 0x12, 0x02, 0x20, 0x01, 0xcd, 0xa0, 0x26, 0x38, 0x19, 0xa0, 0x60, 0xf3, 0x1e, 0x04, 0xc9, 0xc4, 0x79, 0x3c, 0x6d, 0xc2, 0x2a, 0x8d, 0x63, 0xa7, 0x76, 0x43, 0x43, 0x21, 0x0e, 0x48, 0x27, 0x67, 0x21, 0xe1, 0xb6, 0x30, 0x02, 0x20, 0x1b, 0x5b, 0x8f, 0x65, 0x6c, 0x38, 0x68, 0xaa, 0x9c, 0xba, 0x9f, 0x69, 0x34, 0xc2, 0x94, 0xc5, 0xd2, 0xb4, 0x46, 0x9d, 0x1a, 0xfc, 0xd3, 0xd8, 0x03, 0x12, 0x86, 0x14, 0xea, 0x10, 0x23, 0x8f, 0x18,
[1704419564.678897][5315:5317] CHIP:DMG: ] (242 bytes)
[1704419564.678923][5315:5317] CHIP:DMG: 0x1 = [
[1704419564.678967][5315:5317] CHIP:DMG: 0xbf, 0x3e, 0xed, 0x12, 0x18, 0xd8, 0xde, 0x5a, 0xde, 0x18, 0x74, 0x45, 0x14, 0x5e, 0xc6, 0xaa, 0x26, 0x0a, 0x06, 0xb8, 0x54, 0xfa, 0x6a, 0x68, 0x40, 0x1d, 0x49, 0x8b, 0xc0, 0x94, 0x46, 0xcf, 0x6a, 0x12, 0x0d, 0xe8, 0xc5, 0x28, 0x39, 0xd4, 0xd2, 0xac, 0xb4, 0xb2, 0xd9, 0xbc, 0x3a, 0x2f, 0xd7, 0xfd, 0x4a, 0xcb, 0x4a, 0xf6, 0x5b, 0xcb, 0xff, 0x6d, 0xc7, 0xe9, 0x0a, 0x12, 0x3e, 0x5f,
[1704419564.679000][5315:5317] CHIP:DMG: ] (64 bytes)
[1704419564.679025][5315:5317] CHIP:DMG: },
[1704419564.679048][5315:5317] CHIP:DMG: },
[1704419564.679078][5315:5317] CHIP:DMG:
[1704419564.679098][5315:5317] CHIP:DMG: },
[1704419564.679127][5315:5317] CHIP:DMG:
[1704419564.679147][5315:5317] CHIP:DMG: ],
[1704419564.679177][5315:5317] CHIP:DMG:
[1704419564.679198][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.679218][5315:5317] CHIP:DMG: },
[1704419564.679300][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0005
[1704419564.679336][5315:5317] CHIP:CTL: Received certificate signing request from the device
[1704419564.679362][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendOpCertSigningRequest'
[1704419564.679384][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendOpCertSigningRequest' -> 'ValidateCSR'
[1704419564.679414][5315:5317] CHIP:CTL: Performing next commissioning step 'ValidateCSR'
[1704419564.684991][5315:5317] CHIP:CTL: Successfully finished commissioning step 'ValidateCSR'
[1704419564.685025][5315:5317] CHIP:CTL: Commissioning stage next step: 'ValidateCSR' -> 'GenerateNOCChain'
[1704419564.685054][5315:5317] CHIP:CTL: Performing next commissioning step 'GenerateNOCChain'
[1704419564.685075][5315:5317] CHIP:CTL: Getting certificate chain for the device from the issuer
[1704419564.689835][5315:5317] CHIP:CTL: Verifying Certificate Signing Request
[1704419564.692382][5315:5317] CHIP:CTL: Generating NOC
[1704419564.692687][5315:5317] CHIP:CTL: Providing certificate chain to the commissioner
[1704419564.692719][5315:5317] CHIP:CTL: Received callback from the CA for NOC Chain generation. Status src/controller/ExampleOperationalCredentialsIssuer.cpp:395: Success
[1704419564.692746][5315:5317] CHIP:CTL: Successfully finished commissioning step 'GenerateNOCChain'
[1704419564.692929][5315:5317] CHIP:CTL: Performing next commissioning step 'SendTrustedRootCert'
[1704419564.692954][5315:5317] CHIP:CTL: Sending root certificate to the device
[1704419564.693013][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.693040][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.693188][5315:5317] CHIP:EM: <<< [E:35802i S:53377 M:214323864] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.693308][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.693339][5315:5317] CHIP:CTL: Sent root certificate to the device
[1704419564.693701][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.693837][5315:5317] CHIP:EM: <<< [E:35801i S:53377 M:214323865 (Ack:215468103)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.693923][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468103 on exchange 35801i
[1704419564.754697][5315:5317] CHIP:EM: >>> [E:35802i S:53377 M:215468104 (Ack:214323864)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.754742][5315:5317] CHIP:EM: Found matching exchange: 35802i, Delegate: 0x7f7e7000a4c8
[1704419564.754773][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323864 from Retrans Table on exchange 35802i
[1704419564.800428][5315:5317] CHIP:EM: >>> [E:35802i S:53377 M:215468105 (Ack:214323864)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419564.800472][5315:5317] CHIP:EM: Found matching exchange: 35802i, Delegate: 0x7f7e7000a4c8
[1704419564.800495][5315:5317] CHIP:EM: CHIP MessageCounter:214323864 not in RetransTable on exchange 35802i
[1704419564.800526][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419564.800571][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419564.800593][5315:5317] CHIP:DMG: {
[1704419564.800614][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419564.800635][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419564.800665][5315:5317] CHIP:DMG: [
[1704419564.800685][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419564.800714][5315:5317] CHIP:DMG: {
[1704419564.800735][5315:5317] CHIP:DMG: CommandStatusIB =
[1704419564.800761][5315:5317] CHIP:DMG: {
[1704419564.800781][5315:5317] CHIP:DMG: CommandPathIB =
[1704419564.800806][5315:5317] CHIP:DMG: {
[1704419564.800832][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419564.800857][5315:5317] CHIP:DMG: ClusterId = 0x3e,
[1704419564.800881][5315:5317] CHIP:DMG: CommandId = 0xb,
[1704419564.800905][5315:5317] CHIP:DMG: },
[1704419564.800934][5315:5317] CHIP:DMG:
[1704419564.800956][5315:5317] CHIP:DMG: StatusIB =
[1704419564.800980][5315:5317] CHIP:DMG: {
[1704419564.801005][5315:5317] CHIP:DMG: status = 0x00 (SUCCESS),
[1704419564.801028][5315:5317] CHIP:DMG: },
[1704419564.801054][5315:5317] CHIP:DMG:
[1704419564.801076][5315:5317] CHIP:DMG: },
[1704419564.801104][5315:5317] CHIP:DMG:
[1704419564.801125][5315:5317] CHIP:DMG: },
[1704419564.801152][5315:5317] CHIP:DMG:
[1704419564.801173][5315:5317] CHIP:DMG: ],
[1704419564.801202][5315:5317] CHIP:DMG:
[1704419564.801222][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419564.801242][5315:5317] CHIP:DMG: },
[1704419564.801318][5315:5317] CHIP:DMG: Received Command Response Status for Endpoint=0 Cluster=0x0000_003E Command=0x0000_000B Status=0x0
[1704419564.801344][5315:5317] CHIP:CTL: Device confirmed that it has received the root certificate
[1704419564.801370][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendTrustedRootCert'
[1704419564.801391][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendTrustedRootCert' -> 'SendNOC'
[1704419564.801421][5315:5317] CHIP:CTL: Performing next commissioning step 'SendNOC'
[1704419564.801473][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419564.801505][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419564.801650][5315:5317] CHIP:EM: <<< [E:35803i S:53377 M:214323866] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419564.801770][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419564.801801][5315:5317] CHIP:CTL: Sent operational certificate to the device
[1704419564.801852][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419564.801966][5315:5317] CHIP:EM: <<< [E:35802i S:53377 M:214323867 (Ack:215468105)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.802037][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468105 on exchange 35802i
[1704419564.864282][5315:5317] CHIP:EM: >>> [E:35803i S:53377 M:215468106 (Ack:214323866)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419564.864326][5315:5317] CHIP:EM: Found matching exchange: 35803i, Delegate: 0x7f7e70024d78
[1704419564.864357][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:214323866 from Retrans Table on exchange 35803i
[1704419565.033395][5315:5317] CHIP:EM: >>> [E:35803i S:53377 M:215468107 (Ack:214323866)] (S) Msg RX from 0:FFFFFFFB00000000 [0000] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419565.033440][5315:5317] CHIP:EM: Found matching exchange: 35803i, Delegate: 0x7f7e70024d78
[1704419565.033462][5315:5317] CHIP:EM: CHIP MessageCounter:214323866 not in RetransTable on exchange 35803i
[1704419565.033494][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419565.033539][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419565.033560][5315:5317] CHIP:DMG: {
[1704419565.033579][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419565.033598][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419565.033629][5315:5317] CHIP:DMG: [
[1704419565.033650][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419565.033680][5315:5317] CHIP:DMG: {
[1704419565.033702][5315:5317] CHIP:DMG: CommandDataIB =
[1704419565.033725][5315:5317] CHIP:DMG: {
[1704419565.033750][5315:5317] CHIP:DMG: CommandPathIB =
[1704419565.033777][5315:5317] CHIP:DMG: {
[1704419565.033802][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419565.033828][5315:5317] CHIP:DMG: ClusterId = 0x3e,
[1704419565.033852][5315:5317] CHIP:DMG: CommandId = 0x8,
[1704419565.033876][5315:5317] CHIP:DMG: },
[1704419565.033903][5315:5317] CHIP:DMG:
[1704419565.033926][5315:5317] CHIP:DMG: CommandFields =
[1704419565.033950][5315:5317] CHIP:DMG: {
[1704419565.033976][5315:5317] CHIP:DMG: 0x0 = 0,
[1704419565.034003][5315:5317] CHIP:DMG: 0x1 = 2,
[1704419565.034027][5315:5317] CHIP:DMG: },
[1704419565.034049][5315:5317] CHIP:DMG: },
[1704419565.034079][5315:5317] CHIP:DMG:
[1704419565.034100][5315:5317] CHIP:DMG: },
[1704419565.034130][5315:5317] CHIP:DMG:
[1704419565.034151][5315:5317] CHIP:DMG: ],
[1704419565.034180][5315:5317] CHIP:DMG:
[1704419565.034202][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419565.034222][5315:5317] CHIP:DMG: },
[1704419565.034295][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_003E Command=0x0000_0008
[1704419565.034354][5315:5317] CHIP:CTL: Device returned status 0 on receiving the NOC
[1704419565.034377][5315:5317] CHIP:CTL: Operational credentials provisioned on device 0x7f7e70013660
[1704419565.034398][5315:5317] CHIP:TOO: Secure Pairing Success
[1704419565.034417][5315:5317] CHIP:TOO: CASE establishment successful
[1704419565.034442][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendNOC'
[1704419565.034465][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendNOC' -> 'FindOperational'
[1704419565.034496][5315:5317] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1704419565.034516][5315:5317] CHIP:IN: Expiring all sessions for node <0000000000001234, 1>!!
[1704419565.034539][5315:5317] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000001234]
[1704419565.034560][5315:5317] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704419565.034590][5315:5317] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 1 --> 2
[1704419565.034802][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419565.034945][5315:5317] CHIP:EM: <<< [E:35803i S:53377 M:214323868 (Ack:215468107)] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419565.035024][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:215468107 on exchange 35803i
[1704419565.135332][5315:5317] CHIP:DIS: UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540: new best score: 7
[1704419565.135369][5315:5317] CHIP:DIS: Lookup clearing interface for non LL address
[1704419565.135422][5315:5317] CHIP:DIS: UDP:192.168.19.35%enp3s0:5540: new best score: 2
[1704419565.135445][5315:5317] CHIP:DIS: Checking node lookup status after 101 ms
[1704419565.135466][5315:5317] CHIP:DIS: Keeping DNSSD lookup active
[1704419565.135607][5315:5317] CHIP:DIS: UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540: new best score: 7
[1704419565.135632][5315:5317] CHIP:DIS: Lookup clearing interface for non LL address
[1704419565.135677][5315:5317] CHIP:DIS: UDP:192.168.19.35%enp3s0:5540: new best score: 2
[1704419565.135698][5315:5317] CHIP:DIS: Checking node lookup status after 101 ms
[1704419565.135717][5315:5317] CHIP:DIS: Keeping DNSSD lookup active
[1704419565.235086][5315:5317] CHIP:DIS: Checking node lookup status after 201 ms
[1704419565.235185][5315:5317] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: Updating device address to UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540 while in state 2
[1704419565.235212][5315:5317] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 2 --> 3
[1704419565.235297][5315:5317] CHIP:IN: SecureSession[0x7f7e7003f9c0]: Allocated Type:2 LSID:53378
[1704419565.235334][5315:5317] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000001234
[1704419565.236288][5315:5317] CHIP:EM: <<< [E:35804i S:0 M:63755944] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704419565.236412][5315:5317] CHIP:SC: Sent Sigma1 msg
[1704419565.236439][5315:5317] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 3 --> 4
[1704419565.311104][5315:5317] CHIP:EM: >>> [E:35804i S:0 M:201993733 (Ack:63755944)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419565.311147][5315:5317] CHIP:EM: Found matching exchange: 35804i, Delegate: 0x7f7e70043598
[1704419565.311179][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:63755944 from Retrans Table on exchange 35804i
[1704419565.380484][5315:5317] CHIP:EM: >>> [E:35804i S:0 M:201993734 (Ack:63755944)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704419565.380528][5315:5317] CHIP:EM: Found matching exchange: 35804i, Delegate: 0x7f7e70043598
[1704419565.380551][5315:5317] CHIP:EM: CHIP MessageCounter:63755944 not in RetransTable on exchange 35804i
[1704419565.380591][5315:5317] CHIP:SC: Received Sigma2 msg
[1704419565.380624][5315:5317] CHIP:SC: Peer assigned session session ID 31166
[1704419565.384490][5315:5317] CHIP:SC: Found MRP parameters in the message
[1704419565.384540][5315:5317] CHIP:SC: Sending Sigma3
[1704419565.385121][5315:5317] CHIP:EM: <<< [E:35804i S:0 M:63755945 (Ack:201993734)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704419565.385243][5315:5317] CHIP:SC: Sent Sigma3 msg
[1704419565.421535][5315:5317] CHIP:EM: >>> [E:35804i S:0 M:201993735 (Ack:63755945)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419565.421555][5315:5317] CHIP:EM: Found matching exchange: 35804i, Delegate: 0x7f7e70043598
[1704419565.421569][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:63755945 from Retrans Table on exchange 35804i
[1704419565.544100][5315:5317] CHIP:EM: >>> [E:35804i S:0 M:201993736 (Ack:63755945)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704419565.544143][5315:5317] CHIP:EM: Found matching exchange: 35804i, Delegate: 0x7f7e70043598
[1704419565.544166][5315:5317] CHIP:EM: CHIP MessageCounter:63755945 not in RetransTable on exchange 35804i
[1704419565.544205][5315:5317] CHIP:SC: Success status report received. Session was established
[1704419565.547886][5315:5317] CHIP:SC: SecureSession[0x7f7e7003f9c0, LSID:53378]: State change 'kEstablishing' --> 'kActive'
[1704419565.547924][5315:5317] CHIP:IN: SecureSession[0x7f7e7003f9c0]: Activated - Type:2 LSID:53378
[1704419565.547943][5315:5317] CHIP:IN: New secure session activated for device <0000000000001234, 1>, LSID:53378 PSID:31166!
[1704419565.547968][5315:5317] CHIP:DIS: OperationalSessionSetup[1:0000000000001234]: State change 4 --> 5
[1704419565.548062][5315:5317] CHIP:CTL: Successfully finished commissioning step 'FindOperational'
[1704419565.548086][5315:5317] CHIP:CTL: Commissioning stage next step: 'FindOperational' -> 'SendComplete'
[1704419565.548117][5315:5317] CHIP:CTL: Performing next commissioning step 'SendComplete'
[1704419565.548168][5315:5317] CHIP:DMG: ICR moving to [AddingComm]
[1704419565.548193][5315:5317] CHIP:DMG: ICR moving to [AddedComma]
[1704419565.548343][5315:5317] CHIP:EM: <<< [E:35805i S:53378 M:33793823] (S) Msg TX to 1:0000000000001234 [3A4D] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0001:08 (IM:InvokeCommandRequest)
[1704419565.548465][5315:5317] CHIP:DMG: ICR moving to [CommandSen]
[1704419565.548571][5315:5317] CHIP:EM: <<< [E:35804i S:0 M:63755946 (Ack:201993736)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419565.548642][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:201993736 on exchange 35804i
[1704419565.711787][5315:5317] CHIP:EM: >>> [E:35805i S:53378 M:207934198 (Ack:33793823)] (S) Msg RX from 1:0000000000001234 [3A4D] --- Type 0001:09 (IM:InvokeCommandResponse)
[1704419565.711832][5315:5317] CHIP:EM: Found matching exchange: 35805i, Delegate: 0x7f7e7000a4c8
[1704419565.711863][5315:5317] CHIP:EM: Rxd Ack; Removing MessageCounter:33793823 from Retrans Table on exchange 35805i
[1704419565.711895][5315:5317] CHIP:DMG: ICR moving to [ResponseRe]
[1704419565.711942][5315:5317] CHIP:DMG: InvokeResponseMessage =
[1704419565.711963][5315:5317] CHIP:DMG: {
[1704419565.712009][5315:5317] CHIP:DMG: suppressResponse = false,
[1704419565.712031][5315:5317] CHIP:DMG: InvokeResponseIBs =
[1704419565.712061][5315:5317] CHIP:DMG: [
[1704419565.712081][5315:5317] CHIP:DMG: InvokeResponseIB =
[1704419565.712111][5315:5317] CHIP:DMG: {
[1704419565.712132][5315:5317] CHIP:DMG: CommandDataIB =
[1704419565.712156][5315:5317] CHIP:DMG: {
[1704419565.712178][5315:5317] CHIP:DMG: CommandPathIB =
[1704419565.712202][5315:5317] CHIP:DMG: {
[1704419565.712227][5315:5317] CHIP:DMG: EndpointId = 0x0,
[1704419565.712252][5315:5317] CHIP:DMG: ClusterId = 0x30,
[1704419565.712276][5315:5317] CHIP:DMG: CommandId = 0x5,
[1704419565.712299][5315:5317] CHIP:DMG: },
[1704419565.712325][5315:5317] CHIP:DMG:
[1704419565.712348][5315:5317] CHIP:DMG: CommandFields =
[1704419565.712373][5315:5317] CHIP:DMG: {
[1704419565.712398][5315:5317] CHIP:DMG: 0x0 = 0,
[1704419565.712425][5315:5317] CHIP:DMG: 0x1 = "" (0 chars),
[1704419565.712450][5315:5317] CHIP:DMG: },
[1704419565.712472][5315:5317] CHIP:DMG: },
[1704419565.712501][5315:5317] CHIP:DMG:
[1704419565.712521][5315:5317] CHIP:DMG: },
[1704419565.712551][5315:5317] CHIP:DMG:
[1704419565.712571][5315:5317] CHIP:DMG: ],
[1704419565.712602][5315:5317] CHIP:DMG:
[1704419565.712623][5315:5317] CHIP:DMG: InteractionModelRevision = 11
[1704419565.712643][5315:5317] CHIP:DMG: },
[1704419565.712716][5315:5317] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0030 Command=0x0000_0005
[1704419565.712750][5315:5317] CHIP:CTL: Received CommissioningComplete response, errorCode=0
[1704419565.712777][5315:5317] CHIP:CTL: Successfully finished commissioning step 'SendComplete'
[1704419565.712798][5315:5317] CHIP:CTL: Commissioning stage next step: 'SendComplete' -> 'Cleanup'
[1704419565.712829][5315:5317] CHIP:CTL: Performing next commissioning step 'Cleanup'
[1704419565.712853][5315:5317] CHIP:IN: SecureSession[0x7f7e70010110]: MarkForEviction Type:1 LSID:53377
[1704419565.712875][5315:5317] CHIP:SC: SecureSession[0x7f7e70010110, LSID:53377]: State change 'kActive' --> 'kPendingEviction'
[1704419565.712918][5315:5317] CHIP:IN: SecureSession[0x7f7e70010110]: Released - Type:1 LSID:53377
[1704419565.712949][5315:5317] CHIP:CTL: Successfully finished commissioning step 'Cleanup'
[1704419565.712975][5315:5317] CHIP:TOO: Device commissioning completed with success
[1704419565.713062][5315:5317] CHIP:DMG: ICR moving to [AwaitingDe]
[1704419565.713212][5315:5317] CHIP:EM: <<< [E:35805i S:53378 M:33793824 (Ack:207934198)] (S) Msg TX to 1:0000000000001234 [3A4D] [UDP:[fe80::424c:caff:fe43:1518%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704419565.713299][5315:5317] CHIP:EM: Flushed pending ack for MessageCounter:207934198 on exchange 35805i
[1704419565.713516][5315:5315] CHIP:CTL: Shutting down the commissioner
[1704419565.713606][5315:5315] CHIP:CTL: Shutting down the controller
[1704419565.713631][5315:5315] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704419565.713652][5315:5315] CHIP:IN: SecureSession[0x7f7e7003f9c0]: MarkForEviction Type:2 LSID:53378
[1704419565.713673][5315:5315] CHIP:SC: SecureSession[0x7f7e7003f9c0, LSID:53378]: State change 'kActive' --> 'kPendingEviction'
[1704419565.713696][5315:5315] CHIP:IN: SecureSession[0x7f7e7003f9c0]: Released - Type:2 LSID:53378
[1704419565.713718][5315:5315] CHIP:FP: Forgetting fabric 0x1
[1704419565.713747][5315:5315] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704419565.713903][5315:5315] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704419565.713925][5315:5315] CHIP:TS: Reverted Last Known Good Time to previous value
[1704419565.713960][5315:5315] CHIP:CTL: Shutting down the commissioner
[1704419565.714022][5315:5315] CHIP:CTL: Shutting down the controller
[1704419565.714042][5315:5315] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704419565.714143][5315:5315] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704419565.714217][5315:5315] CHIP:FP: Shutting down FabricTable
[1704419565.714242][5315:5315] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704419565.714342][5315:5315] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704419565.714363][5315:5315] CHIP:TS: Reverted Last Known Good Time to previous value
[1704419565.714538][5315:5315] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-wuLyQn)
[1704419565.714956][5315:5315] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704419565.715006][5315:5315] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704419565.715029][5315:5315] CHIP:DL: Inet Layer shutdown
[1704419565.715049][5315:5315] CHIP:DL: BLE shutdown
[1704419565.715070][5315:5315] CHIP:DL: System Layer shutdown
accesscontrol
→ accesscontrol write acl
: acl ( access control list) 에 쓰기
더보기
$ ./chip-tool accesscontrol write acl '[{"privilege": 5, "authMode": 2, "subjects": [ 112233, 29315 ], "targets": null}]' 0x5164 0x0
[1704366664.892208][14099:14099] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_tool_kvs
[1704366664.892605][14099:14099] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_kvs
[1704366664.892613][14099:14099] CHIP:DL: ChipLinuxStorage::Init: Attempt to re-initialize with KVS config file: /tmp/chip_kvs
[1704366664.894292][14099:14099] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_factory.ini
[1704366664.894359][14099:14099] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_config.ini
[1704366664.894383][14099:14099] CHIP:DL: ChipLinuxStorage::Init: Using KVS config file: /tmp/chip_counters.ini
[1704366664.894466][14099:14099] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-wuqCaQ)
[1704366664.894603][14099:14099] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704366664.894614][14099:14099] CHIP:DL: NVS set: chip-counters/reboot-count = 37 (0x25)
[1704366664.894755][14099:14099] CHIP:DL: Got Ethernet interface: enp3s0
[1704366664.894848][14099:14099] CHIP:DL: Found the primary Ethernet interface:enp3s0
[1704366664.894985][14099:14099] CHIP:DL: Failed to get WiFi interface
[1704366664.894991][14099:14099] CHIP:DL: Failed to reset WiFi statistic counts
[1704366664.895001][14099:14099] CHIP:IN: UDP::Init bind&listen port=0
[1704366664.895023][14099:14099] CHIP:IN: UDP::Init bound to port=33759
[1704366664.895028][14099:14099] CHIP:IN: UDP::Init bind&listen port=0
[1704366664.895046][14099:14099] CHIP:IN: UDP::Init bound to port=33078
[1704366664.895050][14099:14099] CHIP:IN: BLEBase::Init - setting/overriding transport
[1704366664.895054][14099:14099] CHIP:IN: TransportMgr initialized
[1704366664.895063][14099:14099] CHIP:FP: Initializing FabricTable from persistent storage
[1704366664.895091][14099:14099] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704366664.895500][14099:14099] CHIP:FP: Fabric index 0x1 was retrieved from storage. Compressed FabricId 0x7EC96ABB43EBB1E9, FabricId 0x0000000000000001, NodeId 0x000000000001B669, VendorId 0xFFF1
[1704366664.896491][14099:14099] CHIP:ZCL: Using ZAP configuration...
[1704366664.896912][14099:14099] CHIP:CTL: System State Initialized...
[1704366664.896955][14099:14099] CHIP:CTL: Setting attestation nonce to random value
[1704366664.896965][14099:14099] CHIP:CTL: Setting CSR nonce to random value
[1704366664.896979][14099:14099] CHIP:IN: UDP::Init bind&listen port=5550
[1704366664.896997][14099:14099] CHIP:IN: UDP::Init bound to port=5550
[1704366664.897002][14099:14099] CHIP:IN: UDP::Init bind&listen port=5550
[1704366664.897018][14099:14099] CHIP:IN: UDP::Init bound to port=5550
[1704366664.897023][14099:14099] CHIP:IN: TransportMgr initialized
[1704366664.897116][14099:14101] CHIP:DL: CHIP task running
[1704366664.897136][14099:14101] CHIP:DL: HandlePlatformSpecificBLEEvent 32786
[1704366664.897252][14099:14101] CHIP:CTL: Setting attestation nonce to random value
[1704366664.897307][14099:14101] CHIP:CTL: Setting CSR nonce to random value
[1704366664.897566][14099:14101] CHIP:CTL: Generating NOC
[1704366664.897809][14099:14101] CHIP:FP: Validating NOC chain
[1704366664.898204][14099:14101] CHIP:FP: NOC chain validation successful
[1704366664.898241][14099:14101] CHIP:FP: Updated fabric at index: 0x1, Node ID: 0x000000000001B669
[1704366664.898285][14099:14101] CHIP:TS: Last Known Good Time: 2023-10-14T01:16:48
[1704366664.898290][14099:14101] CHIP:TS: New proposed Last Known Good Time: 2021-01-01T00:00:00
[1704366664.898307][14099:14101] CHIP:TS: Retaining current Last Known Good Time
[1704366664.899167][14099:14101] CHIP:FP: Metadata for Fabric 0x1 persisted to storage.
[1704366664.899516][14099:14101] CHIP:TS: Committing Last Known Good Time to storage: 2023-10-14T01:16:48
[1704366664.899894][14099:14101] CHIP:CTL: Joined the fabric at index 1. Fabric ID is 0x0000000000000001 (Compressed Fabric ID: 7EC96ABB43EBB1E9)
[1704366664.899904][14099:14101] CHIP:IN: UDP::Init bind&listen port=5550
[1704366664.899953][14099:14101] CHIP:IN: UDP::Init bound to port=5550
[1704366664.899958][14099:14101] CHIP:IN: UDP::Init bind&listen port=5550
[1704366664.899975][14099:14101] CHIP:IN: UDP::Init bound to port=5550
[1704366664.899993][14099:14101] CHIP:IN: TransportMgr initialized
[1704366664.903073][14099:14101] CHIP:TOO: Sending command to node 0x5164
[1704366664.903190][14099:14101] CHIP:CSM: FindOrEstablishSession: PeerId = [1:0000000000005164]
[1704366664.903197][14099:14101] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1704366664.903204][14099:14101] CHIP:DIS: OperationalSessionSetup[1:0000000000005164]: State change 1 --> 2
[1704366664.912268][14099:14101] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704366664.912276][14099:14101] CHIP:DIS: Lookup clearing interface for non LL address
[1704366664.912288][14099:14101] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704366664.912292][14099:14101] CHIP:DIS: Checking node lookup status after 10 ms
[1704366664.912296][14099:14101] CHIP:DIS: Keeping DNSSD lookup active
[1704366664.912556][14099:14101] CHIP:DIS: UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540: new best score: 7
[1704366664.912564][14099:14101] CHIP:DIS: Lookup clearing interface for non LL address
[1704366664.912575][14099:14101] CHIP:DIS: UDP:192.168.19.34%enp3s0:5540: new best score: 2
[1704366664.912579][14099:14101] CHIP:DIS: Checking node lookup status after 10 ms
[1704366664.912583][14099:14101] CHIP:DIS: Keeping DNSSD lookup active
[1704366665.102875][14099:14101] CHIP:DIS: Checking node lookup status after 200 ms
[1704366665.102971][14099:14101] CHIP:DIS: OperationalSessionSetup[1:0000000000005164]: Updating device address to UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540 while in state 2
[1704366665.102998][14099:14101] CHIP:DIS: OperationalSessionSetup[1:0000000000005164]: State change 2 --> 3
[1704366665.103113][14099:14101] CHIP:IN: SecureSession[0x7f710c00ed30]: Allocated Type:2 LSID:53616
[1704366665.103154][14099:14101] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x0000000000005164
[1704366665.104056][14099:14101] CHIP:EM: <<< [E:32462i S:0 M:96523752] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1704366665.104178][14099:14101] CHIP:SC: Sent Sigma1 msg
[1704366665.104206][14099:14101] CHIP:DIS: OperationalSessionSetup[1:0000000000005164]: State change 3 --> 4
[1704366665.187222][14099:14101] CHIP:EM: >>> [E:32462i S:0 M:81579763 (Ack:96523752)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704366665.187265][14099:14101] CHIP:EM: Found matching exchange: 32462i, Delegate: 0x7f710c00ea88
[1704366665.187297][14099:14101] CHIP:EM: Rxd Ack; Removing MessageCounter:96523752 from Retrans Table on exchange 32462i
[1704366665.257902][14099:14101] CHIP:EM: >>> [E:32462i S:0 M:81579764 (Ack:96523752)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:31 (SecureChannel:CASE_Sigma2)
[1704366665.257945][14099:14101] CHIP:EM: Found matching exchange: 32462i, Delegate: 0x7f710c00ea88
[1704366665.257968][14099:14101] CHIP:EM: CHIP MessageCounter:96523752 not in RetransTable on exchange 32462i
[1704366665.258010][14099:14101] CHIP:SC: Received Sigma2 msg
[1704366665.258042][14099:14101] CHIP:SC: Peer assigned session session ID 33820
[1704366665.261879][14099:14101] CHIP:SC: Found MRP parameters in the message
[1704366665.261930][14099:14101] CHIP:SC: Sending Sigma3
[1704366665.262549][14099:14101] CHIP:EM: <<< [E:32462i S:0 M:96523753 (Ack:81579764)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:32 (SecureChannel:CASE_Sigma3)
[1704366665.262670][14099:14101] CHIP:SC: Sent Sigma3 msg
[1704366665.298385][14099:14101] CHIP:EM: >>> [E:32462i S:0 M:81579765 (Ack:96523753)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704366665.298428][14099:14101] CHIP:EM: Found matching exchange: 32462i, Delegate: 0x7f710c00ea88
[1704366665.298460][14099:14101] CHIP:EM: Rxd Ack; Removing MessageCounter:96523753 from Retrans Table on exchange 32462i
[1704366665.423228][14099:14101] CHIP:EM: >>> [E:32462i S:0 M:81579766 (Ack:96523753)] (U) Msg RX from 0:0000000000000000 [0000] --- Type 0000:40 (SecureChannel:StatusReport)
[1704366665.423271][14099:14101] CHIP:EM: Found matching exchange: 32462i, Delegate: 0x7f710c00ea88
[1704366665.423295][14099:14101] CHIP:EM: CHIP MessageCounter:96523753 not in RetransTable on exchange 32462i
[1704366665.423335][14099:14101] CHIP:SC: Success status report received. Session was established
[1704366665.426989][14099:14101] CHIP:SC: SecureSession[0x7f710c00ed30, LSID:53616]: State change 'kEstablishing' --> 'kActive'
[1704366665.427025][14099:14101] CHIP:IN: SecureSession[0x7f710c00ed30]: Activated - Type:2 LSID:53616
[1704366665.427045][14099:14101] CHIP:IN: New secure session activated for device <0000000000005164, 1>, LSID:53616 PSID:33820!
[1704366665.427070][14099:14101] CHIP:DIS: OperationalSessionSetup[1:0000000000005164]: State change 4 --> 5
[1704366665.427165][14099:14101] CHIP:TOO: cluster 0x0000_001F, attribute: 0x0000_0000, endpoint 0
[1704366665.427242][14099:14101] CHIP:DMG: WriteClient moving to [AddAttribu]
[1704366665.427316][14099:14101] CHIP:DMG: WriteClient moving to [AddAttribu]
[1704366665.427473][14099:14101] CHIP:EM: <<< [E:32463i S:53616 M:69275124] (S) Msg TX to 1:0000000000005164 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0001:06 (IM:WriteRequest)
[1704366665.427593][14099:14101] CHIP:DMG: WriteClient moving to [AwaitingRe]
[1704366665.427699][14099:14101] CHIP:EM: <<< [E:32462i S:0 M:96523754 (Ack:81579766)] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704366665.427769][14099:14101] CHIP:EM: Flushed pending ack for MessageCounter:81579766 on exchange 32462i
[1704366665.474779][14099:14101] CHIP:EM: >>> [E:32463i S:53616 M:100477587 (Ack:69275124)] (S) Msg RX from 1:0000000000005164 [B1E9] --- Type 0001:07 (IM:WriteResponse)
[1704366665.474823][14099:14101] CHIP:EM: Found matching exchange: 32463i, Delegate: 0x7f710c00a700
[1704366665.474855][14099:14101] CHIP:EM: Rxd Ack; Removing MessageCounter:69275124 from Retrans Table on exchange 32463i
[1704366665.474889][14099:14101] CHIP:DMG: WriteClient moving to [ResponseRe]
[1704366665.474941][14099:14101] CHIP:DMG: WriteResponseMessage =
[1704366665.474964][14099:14101] CHIP:DMG: {
[1704366665.474982][14099:14101] CHIP:DMG: AttributeStatusIBs =
[1704366665.475010][14099:14101] CHIP:DMG: [
[1704366665.475035][14099:14101] CHIP:DMG: AttributeStatusIB =
[1704366665.475058][14099:14101] CHIP:DMG: {
[1704366665.475080][14099:14101] CHIP:DMG: AttributePathIB =
[1704366665.475106][14099:14101] CHIP:DMG: {
[1704366665.475135][14099:14101] CHIP:DMG: Endpoint = 0x0,
[1704366665.475161][14099:14101] CHIP:DMG: Cluster = 0x1f,
[1704366665.475183][14099:14101] CHIP:DMG: Attribute = 0x0000_0000,
[1704366665.475206][14099:14101] CHIP:DMG: }
[1704366665.475236][14099:14101] CHIP:DMG:
[1704366665.475259][14099:14101] CHIP:DMG: StatusIB =
[1704366665.475282][14099:14101] CHIP:DMG: {
[1704366665.475306][14099:14101] CHIP:DMG: status = 0x00 (SUCCESS),
[1704366665.475328][14099:14101] CHIP:DMG: },
[1704366665.475353][14099:14101] CHIP:DMG:
[1704366665.475374][14099:14101] CHIP:DMG: },
[1704366665.475409][14099:14101] CHIP:DMG:
[1704366665.475430][14099:14101] CHIP:DMG: AttributeStatusIB =
[1704366665.475451][14099:14101] CHIP:DMG: {
[1704366665.475472][14099:14101] CHIP:DMG: AttributePathIB =
[1704366665.475494][14099:14101] CHIP:DMG: {
[1704366665.475518][14099:14101] CHIP:DMG: Endpoint = 0x0,
[1704366665.475541][14099:14101] CHIP:DMG: Cluster = 0x1f,
[1704366665.475566][14099:14101] CHIP:DMG: Attribute = 0x0000_0000,
[1704366665.475589][14099:14101] CHIP:DMG: ListIndex = Null,
[1704366665.475611][14099:14101] CHIP:DMG: }
[1704366665.475640][14099:14101] CHIP:DMG:
[1704366665.475662][14099:14101] CHIP:DMG: StatusIB =
[1704366665.475685][14099:14101] CHIP:DMG: {
[1704366665.475706][14099:14101] CHIP:DMG: status = 0x00 (SUCCESS),
[1704366665.475728][14099:14101] CHIP:DMG: },
[1704366665.475752][14099:14101] CHIP:DMG:
[1704366665.475773][14099:14101] CHIP:DMG: },
[1704366665.475800][14099:14101] CHIP:DMG:
[1704366665.475821][14099:14101] CHIP:DMG: ],
[1704366665.475855][14099:14101] CHIP:DMG:
[1704366665.475876][14099:14101] CHIP:DMG: InteractionModelRevision = 11
[1704366665.475896][14099:14101] CHIP:DMG: }
[1704366665.476021][14099:14101] CHIP:DMG: WriteClient moving to [AwaitingDe]
[1704366665.476167][14099:14101] CHIP:EM: <<< [E:32463i S:53616 M:69275125 (Ack:100477587)] (S) Msg TX to 1:0000000000005164 [B1E9] [UDP:[fe80::424c:caff:fe43:9c90%enp3s0]:5540] --- Type 0000:10 (SecureChannel:StandaloneAck)
[1704366665.476254][14099:14101] CHIP:EM: Flushed pending ack for MessageCounter:100477587 on exchange 32463i
[1704366665.476425][14099:14099] CHIP:CTL: Shutting down the commissioner
[1704366665.476517][14099:14099] CHIP:CTL: Shutting down the controller
[1704366665.476542][14099:14099] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1704366665.476564][14099:14099] CHIP:IN: SecureSession[0x7f710c00ed30]: MarkForEviction Type:2 LSID:53616
[1704366665.476586][14099:14099] CHIP:SC: SecureSession[0x7f710c00ed30, LSID:53616]: State change 'kActive' --> 'kPendingEviction'
[1704366665.476606][14099:14099] CHIP:IN: SecureSession[0x7f710c00ed30]: Released - Type:2 LSID:53616
[1704366665.476632][14099:14099] CHIP:FP: Forgetting fabric 0x1
[1704366665.476660][14099:14099] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704366665.476787][14099:14099] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704366665.476808][14099:14099] CHIP:TS: Reverted Last Known Good Time to previous value
[1704366665.476842][14099:14099] CHIP:CTL: Shutting down the commissioner
[1704366665.476901][14099:14099] CHIP:CTL: Shutting down the controller
[1704366665.476921][14099:14099] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1704366665.477024][14099:14099] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1704366665.477099][14099:14099] CHIP:FP: Shutting down FabricTable
[1704366665.477123][14099:14099] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1704366665.477225][14099:14099] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1704366665.477246][14099:14099] CHIP:TS: Reverted Last Known Good Time to previous value
[1704366665.477545][14099:14099] CHIP:DL: writing settings to file (/tmp/chip_counters.ini-4yJkiF)
[1704366665.478007][14099:14099] CHIP:DL: renamed tmp file to file (/tmp/chip_counters.ini)
[1704366665.478063][14099:14099] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1704366665.478098][14099:14099] CHIP:DL: Inet Layer shutdown
[1704366665.478120][14099:14099] CHIP:DL: BLE shutdown
[1704366665.478143][14099:14099] CHIP:DL: System Layer shutdown
간단히 chip-tool 을 빌드 해서 사용해 보았습니다.
참고하세요.
반응형