canonical / openthread-border-router-snap

BSD 3-Clause "New" or "Revised" License
8 stars 2 forks source link

Upgrade OTBR snap to thread-reference-20230710 #41

Closed MonicaisHer closed 6 months ago

MonicaisHer commented 9 months ago

This PR upgrades OTBR snap to use the latest/stable(thread-reference-20230710) release.

This snap could be installed by the following command:

snap install openthread-border-router --channel=edge/pr-41

Checklists for upgrade: /openthread-border-router-snap/snap/local$ tree . . ├── build │ └── bin │ ├── _initrc (no update) │ └── otbr-build.sh (already updated) └── stage └── bin ├── _initrc_install (no update) ├── otbr-agent.sh (not applicable) ├── otbr-setup.sh (no update) └── otbr-web.sh (not applicable)

Testing

farshidtz commented 9 months ago

The upgrade is from to thread-reference-20230119 to thread-reference-20230710. Here is the diff: https://github.com/openthread/ot-br-posix/compare/thread-reference-20230119...thread-reference-20230710

There may be more relevant changes that need to incorporated. Here is the diff for the script directory (best generated and viewed locally to have highlighting):

$ git diff thread-reference-20230119...thread-reference-20230710 script
warning: refname 'thread-reference-20230710' is ambiguous.
diff --git a/script/_border_routing b/script/_border_routing
index cd9e2dddfb..f17c8fe690 100644
--- a/script/_border_routing
+++ b/script/_border_routing
@@ -30,10 +30,17 @@
 #       This script sets up border routing configurations.
 #

-readonly INFRA_IF_NAME="${INFRA_IF_NAME:-wlan0}"
-readonly SYSCTL_ACCEPT_RA_FILE="/etc/sysctl.d/60-otbr-accept-ra.conf"
-readonly DHCPCD_CONF_FILE="/etc/dhcpcd.conf"
-readonly DHCPCD_CONF_BACKUP_FILE="$DHCPCD_CONF_FILE.orig"
+INFRA_IF_NAME="${INFRA_IF_NAME:-wlan0}"
+readonly INFRA_IF_NAME
+
+SYSCTL_ACCEPT_RA_FILE="/etc/sysctl.d/60-otbr-accept-ra.conf"
+readonly SYSCTL_ACCEPT_RA_FILE
+
+DHCPCD_CONF_FILE="/etc/dhcpcd.conf"
+readonly DHCPCD_CONF_FILE
+
+DHCPCD_CONF_BACKUP_FILE="$DHCPCD_CONF_FILE.orig"
+readonly DHCPCD_CONF_BACKUP_FILE

 accept_ra_install()
 {
diff --git a/script/_disable_services b/script/_disable_services
index 130c70e7d4..d5697978f7 100644
--- a/script/_disable_services
+++ b/script/_disable_services
@@ -44,13 +44,15 @@ bbb_disable_services()
     SERVICE_LIST="${SERVICE_LIST} nodered.service"
     SERVICE_LIST="${SERVICE_LIST} dnsmasq.service" # Disable well before bind9

-    for service in $SERVICE_LIST; do
-        if [ "$(sudo systemctl is-active "$service")" != "inactive" ]; then
-            for action in stop disable; do
-                sudo systemctl "$action" "$service"
-            done
-        fi
-    done
+    if have systemctl; then
+        for service in $SERVICE_LIST; do
+            if [ "$(sudo systemctl is-active "$service")" != "inactive" ]; then
+                for action in stop disable; do
+                    sudo systemctl "$action" "$service"
+                done
+            fi
+        done
+    fi

     # stop avahi from advertising for cloud9 and nodered
     sudo rm -rf /etc/avahi/services
diff --git a/script/_nat64 b/script/_nat64
index 9268134e45..521c4d2216 100644
--- a/script/_nat64
+++ b/script/_nat64
@@ -40,6 +40,7 @@ NAT64_PREFIX=64:ff9b::/96
 DYNAMIC_POOL="${NAT64_DYNAMIC_POOL:-192.168.255.0/24}"
 NAT44_SERVICE=/etc/init.d/otbr-nat44
 WLAN_IFNAMES="${INFRA_IF_NAME:-eth0}"
+THREAD_IF="${THREAD_IF:-wpan0}"

 # Currently solution was verified only on raspbian and ubuntu.
 #
@@ -156,7 +157,9 @@ EOF
             echo "        iptables -t nat -A POSTROUTING -o $IFNAME -j MASQUERADE" | sudo tee -a $NAT44_SERVICE
         done
     else
-        echo "        iptables -t nat -A POSTROUTING -s \"$DYNAMIC_POOL\" -j MASQUERADE" | sudo tee -a $NAT44_SERVICE
+        # Just a random fwmark bits.
+        echo "        iptables -t mangle -A PREROUTING -i $THREAD_IF -j MARK --set-mark 0x1001" | sudo tee -a $NAT44_SERVICE
+        echo "        iptables -t nat -A POSTROUTING -m mark --mark 0x1001 -j MASQUERADE" | sudo tee -a $NAT44_SERVICE
         for IFNAME in $WLAN_IFNAMES; do
             echo "        iptables -t filter -A FORWARD -o $IFNAME -j ACCEPT" | sudo tee -a $NAT44_SERVICE
             echo "        iptables -t filter -A FORWARD -i $IFNAME -j ACCEPT" | sudo tee -a $NAT44_SERVICE
diff --git a/script/_otbr b/script/_otbr
index 71317079e1..790ab10ae9 100644
--- a/script/_otbr
+++ b/script/_otbr
@@ -27,9 +27,14 @@
 #  POSSIBILITY OF SUCH DAMAGE.
 #

-readonly OTBR_TOP_BUILDDIR="${BUILD_DIR}/otbr"
-readonly OTBR_OPTIONS="${OTBR_OPTIONS:-}"
-readonly REFERENCE_DEVICE="${REFERENCE_DEVICE:-0}"
+OTBR_TOP_BUILDDIR="${BUILD_DIR}/otbr"
+readonly OTBR_TOP_BUILDDIR
+
+OTBR_OPTIONS="${OTBR_OPTIONS-}"
+readonly OTBR_OPTIONS
+
+REFERENCE_DEVICE="${REFERENCE_DEVICE:-0}"
+readonly REFERENCE_DEVICE

 otbr_uninstall()
 {
@@ -66,7 +71,6 @@ otbr_install()
         "-DBUILD_TESTING=OFF"
         "-DCMAKE_INSTALL_PREFIX=/usr"
         "-DOTBR_DBUS=ON"
-        "-DOTBR_FEATURE_FLAGS=ON"
         "-DOTBR_DNSSD_DISCOVERY_PROXY=ON"
         "-DOTBR_SRP_ADVERTISING_PROXY=ON"
         "-DOTBR_INFRA_IF_NAME=${INFRA_IF_NAME}"
@@ -111,13 +115,19 @@ otbr_install()
         )
     fi

-    if with NAT64 && [[ ${NAT64_SERVICE:-} == "openthread" ]]; then
+    if with NAT64 && [[ ${NAT64_SERVICE-} == "openthread" ]]; then
         otbr_options+=(
             "-DOTBR_NAT64=ON"
             "-DOT_POSIX_NAT64_CIDR=${NAT64_DYNAMIC_POOL:-192.168.255.0/24}"
         )
     fi

+    if with NAT64; then
+        otbr_options+=(
+            "-DOTBR_DNS_UPSTREAM_QUERY=ON"
+        )
+    fi
+
     (./script/cmake-build "${otbr_options[@]}" \
         && cd "${OTBR_TOP_BUILDDIR}" \
         && ninja \
diff --git a/script/bootstrap b/script/bootstrap
index 1aaeff5b87..0b72aa4971 100755
--- a/script/bootstrap
+++ b/script/bootstrap
@@ -58,7 +58,7 @@ install_packages_apt()
     sudo apt-get install --no-install-recommends -y libavahi-client3 libavahi-common-dev libavahi-client-dev avahi-daemon
     (MDNS_RESPONDER_SOURCE_NAME=mDNSResponder-1310.80.1 \
         && cd /tmp \
-        && wget -4 --no-check-certificate https://github.com/apple-oss-distributions/mDNSResponder/archive/refs/tags/$MDNS_RESPONDER_SOURCE_NAME.tar.gz \
+        && wget --no-check-certificate https://github.com/apple-oss-distributions/mDNSResponder/archive/refs/tags/$MDNS_RESPONDER_SOURCE_NAME.tar.gz \
         && mkdir -p $MDNS_RESPONDER_SOURCE_NAME \
         && tar xvf $MDNS_RESPONDER_SOURCE_NAME.tar.gz -C $MDNS_RESPONDER_SOURCE_NAME --strip-components=1 \
         && cd /tmp/$MDNS_RESPONDER_SOURCE_NAME/Clients \
@@ -100,7 +100,7 @@ install_packages_apt()
     sudo apt-get install --no-install-recommends -y libjsoncpp-dev

     # reference device
-    without REFERENCE_DEVICE || sudo apt-get install --no-install-recommends -y radvd dnsutils
+    without REFERENCE_DEVICE || sudo apt-get install --no-install-recommends -y radvd dnsutils avahi-utils

     # backbone-router
     without BACKBONE_ROUTER || sudo apt-get install --no-install-recommends -y libnetfilter-queue1 libnetfilter-queue-dev
diff --git a/script/clang-format b/script/clang-format
index 01b9535e0c..e31466d22b 100755
--- a/script/clang-format
+++ b/script/clang-format
@@ -27,7 +27,7 @@
 #  POSSIBILITY OF SUCH DAMAGE.
 #

-CLANG_FORMAT_VERSION="clang-format version 9.0"
+CLANG_FORMAT_VERSION="clang-format version 14.0"

 die()
 {
@@ -39,36 +39,41 @@ die()
 # expand_aliases shell option is set using shopt.
 shopt -s expand_aliases

-if command -v clang-format-9 >/dev/null; then
-    alias clang-format=clang-format-9
+if command -v clang-format-14 >/dev/null; then
+    alias clang-format=clang-format-14
 elif command -v clang-format >/dev/null; then
     case "$(clang-format --version)" in
         "$CLANG_FORMAT_VERSION"*) ;;

         *)
-            die "$(clang-format --version); clang-format 9.0 required"
+            die "$(clang-format --version); clang-format 14.0 required"
             ;;
     esac
 else
-    die "clang-format 9.0 required"
+    die "clang-format 14.0 required"
 fi

 clang-format "$@" || die

 # ensure EOF newline
 REPLACE=no
+FILES=()
 for arg; do
     case $arg in
         -i)
             REPLACE=yes
             ;;
+        -*) ;;
+        *)
+            FILES+=("$arg")
+            ;;
     esac
 done

-file=$arg
-
 [ $REPLACE != yes ] || {
-    [ -n "$(tail -c1 "$file")" ] && echo >>"$file"
+    for file in "${FILES[@]}"; do
+        [ -n "$(tail -c1 "$file")" ] && echo >>"$file"
+    done
 }

 exit 0
diff --git a/script/cmake-build b/script/cmake-build
index 799e955e97..19679381b5 100755
--- a/script/cmake-build
+++ b/script/cmake-build
@@ -58,10 +58,13 @@
 # shellcheck source=script/_initrc
 . "$(dirname "$0")"/_initrc

-readonly OTBR_TOP_SRCDIR="$PWD"
-readonly OTBR_TOP_BUILD_DIR="${BUILD_DIR}/otbr"
+OTBR_TOP_SRCDIR="$PWD"
+readonly OTBR_TOP_SRCDIR

-OTBR_TARGET=${OTBR_TARGET:-}
+OTBR_TOP_BUILD_DIR="${BUILD_DIR}/otbr"
+readonly OTBR_TOP_BUILD_DIR
+
+OTBR_TARGET=${OTBR_TARGET-}

 main()
 {
@@ -72,7 +75,7 @@ main()
     (
         cd "${builddir}" || die "Failed to enter ${builddir}"

-        cmake -GNinja "${OTBR_TOP_SRCDIR}" "$@"
+        cmake -GNinja -DCMAKE_EXPORT_COMPILE_COMMANDS=ON "${OTBR_TOP_SRCDIR}" "$@"

         if [[ -n ${OTBR_TARGET[*]} ]]; then
             ninja "${OTBR_TARGET[@]}"
diff --git a/script/console b/script/console
index 47e08911a7..416dd024ab 100755
--- a/script/console
+++ b/script/console
@@ -37,8 +37,11 @@
 # shellcheck source=script/_border_routing
 . script/_border_routing

-readonly TUN="${TUN:-wpan0}"
-readonly RADIO_URL="${RADIO_URL:-spinel+hdlc+uart:///dev/ttyUSB0}"
+TUN="${TUN:-wpan0}"
+readonly TUN
+
+RADIO_URL="${RADIO_URL:-spinel+hdlc+uart:///dev/ttyUSB0}"
+readonly RADIO_URL

 killall_services()
 {
diff --git a/script/make-pretty b/script/make-pretty
index 0624776296..7b4dcb44b3 100755
--- a/script/make-pretty
+++ b/script/make-pretty
@@ -60,12 +60,20 @@

 set -euo pipefail

-readonly OT_BUILD_JOBS=$(getconf _NPROCESSORS_ONLN)
-readonly OT_EXCLUDE_DIRS=(third_party doc/site)
+OT_BUILD_JOBS=$(getconf _NPROCESSORS_ONLN)
+readonly OT_BUILD_JOBS

-readonly OT_CLANG_SOURCES=('*.c' '*.cc' '*.cpp' '*.h' '*.hpp')
-readonly OT_MARKDOWN_SOURCES=('*.md')
-readonly OT_PYTHON_SOURCES=('*.py')
+OT_EXCLUDE_DIRS=(third_party doc/site)
+readonly OT_EXCLUDE_DIRS
+
+OT_CLANG_SOURCES=('*.c' '*.cc' '*.cpp' '*.h' '*.hpp')
+readonly OT_CLANG_SOURCES
+
+OT_MARKDOWN_SOURCES=('*.md')
+readonly OT_MARKDOWN_SOURCES
+
+OT_PYTHON_SOURCES=('*.py')
+readonly OT_PYTHON_SOURCES

 do_clang_format()
 {
diff --git a/script/server b/script/server
index ce7a981707..b4eaedfb9a 100755
--- a/script/server
+++ b/script/server
@@ -36,7 +36,7 @@
 . script/_dns64
 . script/_firewall

-main()
+startup()
 {
     # shellcheck source=/dev/null
     . "$BEFORE_HOOK"
@@ -65,4 +65,37 @@ main()
     . "$AFTER_HOOK"
 }

-main
+shutdown()
+{
+    nat64_stop || echo 'Failed to stop NAT64!'
+    dns64_stop || echo 'Failed to stop DNS64!'
+    firewall_stop || echo 'Failed to stop firewall'
+    if have systemctl; then
+        systemctl is-active rsyslog && sudo systemctl stop rsyslog || echo 'Failed to stop rsyslog!'
+        systemctl is-active dbus && sudo systemctl stop dbus || echo 'Failed to stop dbus!'
+        systemctl is-active avahi-daemon && sudo systemctl stop avahi-daemon || echo 'Failed to stop avahi!'
+        without WEB_GUI || systemctl is-active otbr-web && sudo systemctl stop otbr-web || echo 'Failed to stop otbr-web!'
+        systemctl is-active otbr-agent && sudo systemctl stop otbr-agent || echo 'Failed to stop otbr-agent!'
+    elif have service; then
+        sudo service rsyslog status && sudo service rsyslog stop || echo 'Failed to stop rsyslog!'
+        sudo service dbus status && sudo service dbus stop || echo 'Failed to stop dbus!'
+        sudo service mdns status && sudo service mdns stop || echo "service mdns is not available!"
+        sudo service avahi-daemon status && sudo service avahi-daemon stop || echo 'Failed to stop avahi!'
+        sudo service otbr-agent status && sudo service otbr-agent stop || echo 'Failed to stop otbr-agent!'
+        without WEB_GUI || sudo service otbr-web status && sudo service otbr-web stop || echo 'Failed to stop otbr-web!'
+    else
+        echo 'Unable to find service manager. Try script/console to stop in console mode!'
+    fi
+}
+
+main()
+{
+    if [[ ${1-} == "shutdown" ]]; then
+        shift
+        shutdown "$@"
+    else
+        startup "$@"
+    fi
+}
+
+main "$@"
diff --git a/script/standalone_ipv6 b/script/standalone_ipv6
index fe6cfc086e..65266b1ba4 100755
--- a/script/standalone_ipv6
+++ b/script/standalone_ipv6
@@ -45,7 +45,7 @@ ETH0_IPV6_BASE_PREFIX=fd11:33

 debug_echo()
 {
-    if [ x"${_DEBUG_IPV6}" == x"true" ]; then
+    if [ "${_DEBUG_IPV6}" == "true" ]; then
         echo "${@}"
     fi
 }
diff --git a/script/test b/script/test
index 764c941da6..f5b955cbe9 100755
--- a/script/test
+++ b/script/test
@@ -33,17 +33,37 @@
 # shellcheck source=script/_initrc
 . "$(dirname "$0")"/_initrc

-readonly OTBR_COLOR_PASS='\033[0;32m'
-readonly OTBR_COLOR_FAIL='\033[0;31m'
-readonly OTBR_COLOR_NONE='\033[0m'
-readonly QUIET=${QUIET:-1}
-
-readonly OTBR_BUILD_TYPE="${OTBR_BUILD_TYPE:-Debug}"
-readonly OTBR_COVERAGE="${OTBR_COVERAGE:-0}"
-readonly OTBR_MDNS="${OTBR_MDNS:-}"
-readonly OTBR_REST="${OTBR_REST:-}"
-readonly OTBR_OPTIONS="${OTBR_OPTIONS:-}"
-readonly OTBR_TOP_BUILDDIR="${BUILD_DIR}/otbr"
+readonly OTBR_VERBOSE=${OTBR_VERBOSE:-0}
+
+OTBR_COLOR_PASS='\033[0;32m'
+readonly OTBR_COLOR_PASS
+
+OTBR_COLOR_FAIL='\033[0;31m'
+readonly OTBR_COLOR_FAIL
+
+OTBR_COLOR_NONE='\033[0m'
+readonly OTBR_COLOR_NONE
+
+QUIET=${QUIET:-1}
+readonly QUIET
+
+OTBR_BUILD_TYPE="${OTBR_BUILD_TYPE:-Debug}"
+readonly OTBR_BUILD_TYPE
+
+OTBR_COVERAGE="${OTBR_COVERAGE:-0}"
+readonly OTBR_COVERAGE
+
+OTBR_MDNS="${OTBR_MDNS-}"
+readonly OTBR_MDNS
+
+OTBR_REST="${OTBR_REST-}"
+readonly OTBR_REST
+
+OTBR_OPTIONS="${OTBR_OPTIONS-}"
+readonly OTBR_OPTIONS
+
+OTBR_TOP_BUILDDIR="${BUILD_DIR}/otbr"
+readonly OTBR_TOP_BUILDDIR

 #######################################
 # Run test and print result.
@@ -63,7 +83,7 @@ print_result()

     echo -e "$(date) Running $*"

-    if [[ ${QUIET} == 1 ]]; then
+    if [[ ${OTBR_VERBOSE} == 0 ]]; then
         "$@" &>test.log || exit_code=$?
     else
         "$@" || exit_code=$?
@@ -78,7 +98,7 @@ print_result()
     echo -e "${prefix} $*"

     # only output log on failure
-    if [[ ${QUIET} == 1 && ${exit_code} != 0 ]]; then
+    if [[ ${OTBR_VERBOSE} == 0 && ${exit_code} != 0 ]]; then
         cat test.log
     fi

@@ -111,6 +131,7 @@ do_build()
         "-DOT_THREAD_VERSION=1.3"
         "-DOTBR_DBUS=ON"
         "-DOTBR_FEATURE_FLAGS=ON"
+        "-DOTBR_TELEMETRY_DATA_API=ON"
         "-DOTBR_WEB=ON"
         "-DOTBR_UNSECURE_JOIN=ON"
         "-DOTBR_TREL=ON"
MonicaisHer commented 9 months ago

The PR is ready for review @farshidtz.

farshidtz commented 9 months ago

With this revision, I'm unable to pair the chip Lighting app for nRF52840. Here are the Chip Tool logs:

$ sudo chip-tool pairing ble-thread 110 hex:0e080000000000010000000300001035060004001fffe00208b6d151e823a15ce40708fd271f6cceac6b46051002303239cc3ad1224ffb7c119be5d627030f4f70656e5468726561642d3065653801020ee804101898d9f94307eaca866336747e3e1f240c0402a0f7f8 20202021 3840 --ble-adapter 1
...
[1708349851.018454][97586:97615] CHIP:EM: Found matching exchange: 45522i, Delegate: 0x7f0690008818
[1708349851.018465][97586:97615] CHIP:DMG: ICR moving to [ResponseRe]
[1708349851.018487][97586:97615] CHIP:DMG: InvokeResponseMessage =
[1708349851.018492][97586:97615] CHIP:DMG: {
[1708349851.018496][97586:97615] CHIP:DMG:  suppressResponse = false, 
[1708349851.018501][97586:97615] CHIP:DMG:  InvokeResponseIBs =
[1708349851.018511][97586:97615] CHIP:DMG:  [
[1708349851.018517][97586:97615] CHIP:DMG:      InvokeResponseIB =
[1708349851.018528][97586:97615] CHIP:DMG:      {
[1708349851.018534][97586:97615] CHIP:DMG:          CommandDataIB =
[1708349851.018542][97586:97615] CHIP:DMG:          {
[1708349851.018548][97586:97615] CHIP:DMG:              CommandPathIB =
[1708349851.018558][97586:97615] CHIP:DMG:              {
[1708349851.018565][97586:97615] CHIP:DMG:                  EndpointId = 0x0,
[1708349851.018574][97586:97615] CHIP:DMG:                  ClusterId = 0x31,
[1708349851.018582][97586:97615] CHIP:DMG:                  CommandId = 0x7,
[1708349851.018590][97586:97615] CHIP:DMG:              },
[1708349851.018600][97586:97615] CHIP:DMG:              
[1708349851.018607][97586:97615] CHIP:DMG:              CommandFields = 
[1708349851.018614][97586:97615] CHIP:DMG:              {
[1708349851.018622][97586:97615] CHIP:DMG:                  0x0 = 0, 
[1708349851.018631][97586:97615] CHIP:DMG:                  0x2 = NULL
[1708349851.018637][97586:97615] CHIP:DMG:              },
[1708349851.018644][97586:97615] CHIP:DMG:          },
[1708349851.018653][97586:97615] CHIP:DMG:          
[1708349851.018658][97586:97615] CHIP:DMG:      },
[1708349851.018665][97586:97615] CHIP:DMG:      
[1708349851.018671][97586:97615] CHIP:DMG:  ],
[1708349851.018681][97586:97615] CHIP:DMG:  
[1708349851.018686][97586:97615] CHIP:DMG:  InteractionModelRevision = 1
[1708349851.018691][97586:97615] CHIP:DMG: },
[1708349851.018715][97586:97615] CHIP:DMG: Received Command Response Data, Endpoint=0 Cluster=0x0000_0031 Command=0x0000_0007
[1708349851.018728][97586:97615] CHIP:CTL: Received ConnectNetwork response, networkingStatus=0
[1708349851.018736][97586:97615] CHIP:CTL: Successfully finished commissioning step 'ThreadNetworkEnable'
[1708349851.018743][97586:97615] CHIP:CTL: Commissioning stage next step: 'ThreadNetworkEnable' -> 'FindOperational'
[1708349851.018751][97586:97615] CHIP:CTL: Performing next commissioning step 'FindOperational'
[1708349851.018756][97586:97615] CHIP:IN: Expiring all sessions for node <000000000000006E, 1>!!
[1708349851.018763][97586:97615] CHIP:CSM: FindOrEstablishSession: PeerId = [1:000000000000006E]
[1708349851.018768][97586:97615] CHIP:CSM: FindOrEstablishSession: No existing OperationalSessionSetup instance found
[1708349851.018779][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: State change 1 --> 2
[1708349851.019017][97586:97615] CHIP:DMG: ICR moving to [AwaitingDe]
[1708349851.019318][97586:97615] CHIP:DIS: Lookup clearing interface for non LL address
[1708349851.019337][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%enp2s0]:5540: new best score: 5
[1708349851.019341][97586:97615] CHIP:DIS: Checking node lookup status after 0 ms
[1708349851.019347][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.019708][97586:97615] CHIP:DIS: Lookup clearing interface for non LL address
[1708349851.019724][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%enp2s0]:5540: new best score: 5
[1708349851.019728][97586:97615] CHIP:DIS: Checking node lookup status after 1 ms
[1708349851.019733][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.020239][97586:97615] CHIP:DIS: Lookup clearing interface for non LL address
[1708349851.020252][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%lxdbr0]:5540: new best score: 5
[1708349851.020256][97586:97615] CHIP:DIS: Checking node lookup status after 1 ms
[1708349851.020259][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.020823][97586:97615] CHIP:DIS: Lookup clearing interface for non LL address
[1708349851.020839][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%br-074f9c7867fb]:5540: new best score: 5
[1708349851.020843][97586:97615] CHIP:DIS: Checking node lookup status after 2 ms
[1708349851.020846][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.021549][97586:97615] CHIP:DIS: Lookup clearing interface for non LL address
[1708349851.021564][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%docker0]:5540: new best score: 5
[1708349851.021566][97586:97615] CHIP:DIS: Checking node lookup status after 3 ms
[1708349851.021568][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.022377][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%lxdbr0]:5540: score has not improved: 5
[1708349851.022382][97586:97615] CHIP:DIS: Checking node lookup status after 3 ms
[1708349851.022386][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.084457][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084475][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084618][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084633][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084644][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084655][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084780][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084794][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084804][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084815][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084825][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084835][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084849][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.084982][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.086052][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%enp2s0]:5540: score has not improved: 5
[1708349851.086058][97586:97615] CHIP:DIS: Checking node lookup status after 67 ms
[1708349851.086063][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.086941][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%br-074f9c7867fb]:5540: score has not improved: 5
[1708349851.086947][97586:97615] CHIP:DIS: Checking node lookup status after 68 ms
[1708349851.086950][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.087767][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%docker0]:5540: score has not improved: 5
[1708349851.087772][97586:97615] CHIP:DIS: Checking node lookup status after 69 ms
[1708349851.087774][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.088589][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%lxdbr0]:5540: score has not improved: 5
[1708349851.088594][97586:97615] CHIP:DIS: Checking node lookup status after 70 ms
[1708349851.088598][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.088707][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.088718][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.088728][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.088900][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.088920][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.088932][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.088945][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349851.089912][97586:97615] CHIP:DIS: UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa%lxdbr0]:5540: score has not improved: 5
[1708349851.089917][97586:97615] CHIP:DIS: Checking node lookup status after 71 ms
[1708349851.089922][97586:97615] CHIP:DIS: Keeping DNSSD lookup active
[1708349851.218755][97586:97615] CHIP:DIS: Checking node lookup status after 200 ms
[1708349851.218777][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: Updating device address to UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa]:5540 while in state 2
[1708349851.218783][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: State change 2 --> 3
[1708349851.218831][97586:97615] CHIP:IN: SecureSession[0x7f069003f680]: Allocated Type:2 LSID:12166
[1708349851.218842][97586:97615] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x000000000000006E
[1708349851.219133][97586:97615] CHIP:EM: <<< [E:45523i S:0 M:50670898] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1708349851.219204][97586:97615] CHIP:SC: Sent Sigma1 msg
[1708349851.219210][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: State change 3 --> 4
[1708349851.599270][97586:97614] CHIP:DL: Bluez disconnected
[1708349851.599285][97586:97614] CHIP:DL: Bluez notify CHIPoBluez connection disconnected
[1708349851.599335][97586:97615] CHIP:IN: Clearing BLE pending packets.
[1708349857.398256][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670898 on exchange 45523i Send Cnt 1
[1708349863.133551][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670898 on exchange 45523i Send Cnt 2
[1708349872.141582][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670898 on exchange 45523i Send Cnt 3
[1708349886.749577][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670898 on exchange 45523i Send Cnt 4
[1708349909.836912][97586:97615] CHIP:EM: Failed to Send CHIP MessageCounter:50670898 on exchange 45523i sendCount: 4 max retries: 4
[1708349923.705625][97586:97615] CHIP:SC: CASESession timed out while waiting for a response from the peer. Current state was 1
[1708349923.705668][97586:97615] CHIP:IN: SecureSession[0x7f069003f680]: Released - Type:2 LSID:12166
[1708349923.705700][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: State change 4 --> 2
[1708349923.705720][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: Updating device address to UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa]:5540 while in state 2
[1708349923.705724][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: State change 2 --> 3
[1708349923.705782][97586:97615] CHIP:IN: SecureSession[0x7f069003f680]: Allocated Type:2 LSID:12167
[1708349923.705793][97586:97615] CHIP:SC: Initiating session on local FabricIndex 1 from 0x000000000001B669 -> 0x000000000000006E
[1708349923.706154][97586:97615] CHIP:EM: <<< [E:45524i S:0 M:50670899] (U) Msg TX to 0:0000000000000000 [0000] [UDP:[fda8:d7a:acdd:1:99d8:1b2e:88a6:43aa]:5540] --- Type 0000:30 (SecureChannel:CASE_Sigma1)
[1708349923.706254][97586:97615] CHIP:SC: Sent Sigma1 msg
[1708349923.706258][97586:97615] CHIP:DIS: OperationalSessionSetup[1:000000000000006E]: State change 3 --> 4
[1708349923.706280][97586:97615] CHIP:CTL: Session establishment failed for <000000000000006E, 1>, error: src/app/OperationalSessionSetup.cpp:257: CHIP Error 0x00000032: Timeout.  Next retry expected to get a response to Sigma1 or fail within 73 seconds
[1708349923.706289][97586:97615] CHIP:CTL: Arming failsafe (133 seconds)
[1708349923.706311][97586:97615] CHIP:DMG: ICR moving to [AddingComm]
[1708349923.706319][97586:97615] CHIP:DMG: ICR moving to [AddedComma]
[1708349923.706345][97586:97615] CHIP:EM: <<< [E:45525i S:12165 M:260549506] (S) Msg TX to 0:FFFFFFFB00000000 [0000] [BLE] --- Type 0001:08 (IM:InvokeCommandRequest)
[1708349923.706356][97586:97615] CHIP:CTL: Failed to extend fail-safe for CASE retry: src/transport/raw/BLE.cpp:102: CHIP Error 0x00000003: Incorrect state
[1708349930.509253][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670899 on exchange 45524i Send Cnt 1
[1708349933.554587][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349933.554635][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349933.554663][97586:97615] CHIP:DIS: SRV record already actively processed.
[1708349937.083618][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670899 on exchange 45524i Send Cnt 2
[1708349946.945588][97586:97615] CHIP:EM: Retransmitting MessageCounter:50670899 on exchange 45524i Send Cnt 3
[1708349961.145008][97586:97586] CHIP:CTL: Shutting down the commissioner
[1708349961.145083][97586:97586] CHIP:DIS: Closing all BLE connections
[1708349961.145097][97586:97586] CHIP:IN: SecureSession[0x7f069000fcf0]: MarkForEviction Type:1 LSID:12165
[1708349961.145101][97586:97586] CHIP:SC: SecureSession[0x7f069000fcf0, LSID:12165]: State change 'kActive' --> 'kPendingEviction'
[1708349961.145130][97586:97586] CHIP:IN: SecureSession[0x7f069000fcf0]: Released - Type:1 LSID:12165
[1708349961.145143][97586:97586] CHIP:CTL: Shutting down the controller
[1708349961.145175][97586:97586] CHIP:IN: SecureSession[0x7f069003f680]: Released - Type:2 LSID:12167
[1708349961.145214][97586:97586] CHIP:CTL: Device connection failed. Error src/app/OperationalSessionSetup.cpp:540: CHIP Error 0x00000074: The operation has been cancelled
[1708349961.145221][97586:97586] CHIP:IN: Expiring all sessions for fabric 0x1!!
[1708349961.145225][97586:97586] CHIP:FP: Forgetting fabric 0x1
[1708349961.145237][97586:97586] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1708349961.145327][97586:97586] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1708349961.145331][97586:97586] CHIP:TS: Reverted Last Known Good Time to previous value
[1708349961.145339][97586:97586] CHIP:CTL: Shutting down the commissioner
[1708349961.145357][97586:97586] CHIP:CTL: Shutting down the controller
[1708349961.145361][97586:97586] CHIP:CTL: Shutting down the System State, this will teardown the CHIP Stack
[1708349961.145490][97586:97586] CHIP:DMG: All ReadHandler-s are clean, clear GlobalDirtySet
[1708349961.145541][97586:97586] CHIP:FP: Shutting down FabricTable
[1708349961.145552][97586:97586] CHIP:TS: Pending Last Known Good Time: 2023-10-14T01:16:48
[1708349961.145573][97586:97586] CHIP:TS: Previous Last Known Good Time: 2023-10-14T01:16:48
[1708349961.145577][97586:97586] CHIP:TS: Reverted Last Known Good Time to previous value
[1708349961.145762][97586:97586] CHIP:DL: writing settings to file (/mnt/chip_counters.ini-JffpIB)
[1708349961.145996][97586:97586] CHIP:DL: renamed tmp file to file (/mnt/chip_counters.ini)
[1708349961.146007][97586:97586] CHIP:DL: NVS set: chip-counters/total-operational-hours = 0 (0x0)
[1708349961.146011][97586:97586] CHIP:DL: Inet Layer shutdown
[1708349961.146015][97586:97586] CHIP:DL: BLE shutdown
[1708349961.146530][97586:97586] CHIP:DL: System Layer shutdown
[1708349961.146757][97586:97586] CHIP:TOO: Run command failure: ../examples/chip-tool/commands/common/CHIPCommand.cpp:614: CHIP Error 0x00000032: Timeout

No useful error message in the OTBR and applications logs.

I will try with other RCP firmware versions / Thread devices / controllers.

MonicaisHer commented 9 months ago

Testing Thread commissioning with matter-pi-gpio-commander snap:

Commissioning the GPIO snap into the Thread network encountered an error during the 'SendComplete' step. Here are the logs: chip-tool logs: https://pastebin.canonical.com/p/nSWm8qQWMC/ matter-pi-gpio-commander logs: https://pastebin.canonical.com/p/rTT4w4txJ4/

Error:

$ sudo chip-tool pairing ble-thread 110 hex:<active-dataset> 20202021 3840
CHIP:CTL: Received CommissioningComplete response, errorCode=3
CHIP:CTL: Error on commissioning step 'SendComplete': 'src/controller/CHIPDeviceController.cpp:2480: CHIP Error 0x000000AC: Internal error'
CHIP:CTL: Failed to perform commissioning step 30
MonicaisHer commented 9 months ago

Testing Thread commissioning with native chip-all-clusters-minimal-app:

Built OTBR natively with release thread-reference-20230710 on both Machine A (amd64) and Machine B (arm64), the thread commission failed at commissioning step 28, ThreadNetworkEnable. Here are the detailed setup and logs:

Error:

$ sudo chip-tool pairing ble-thread 110 hex:<active-dataset> 20202021 3840
CHIP:CTL: Received ConnectNetwork response, networkingStatus=12
CHIP:CTL: Error on commissioning step 'ThreadNetworkEnable': 'src/controller/CHIPDeviceController.cpp:2425: CHIP Error 0x000000AC: Internal error'
CHIP:CTL: Failed to perform commissioning step 28

It might be worth replacing the all-cluster-app with another Thread-supported device, as this issue also failed at the step ThreadNetworkEnable during Thread commissioning.

MonicaisHer commented 9 months ago

Testing Thread commissioning with native lighting app:

The thread commission still failed at commissioning step 28, ThreadNetworkEnable, after replacing all-cluster-app with lighting-app. Here are the detailed setup and logs:

MonicaisHer commented 8 months ago

Testing Thread commissioning with matter-all-clusters-app snap:

Built OTBR natively with release thread-reference-20230710 on both Machine A (amd64) and Machine B (arm64), the thread commission failed at commissioning step 28, ThreadNetworkEnable. Here are the detailed setup and logs:

It might be worth replacing the all-cluster-app with another Thread-supported device, as this issue also failed at the step ThreadNetworkEnable during Thread commissioning.

openthread related error found in all-clusters-minimal-app log during Thread commissioning:

CHIP:DL: openthread: _SetThreadEnabled calling Reset failed: 
GDBus.Error:org.freedesktop.DBus.Error.ServiceUnknown:
The name io.openthread.BorderRouter.wpan0 was not provided by any .service files
MonicaisHer commented 8 months ago

Testing Thread commissioning with matter-pi-gpio-commander snap:

$ sudo chip-tool pairing ble-thread 110 hex:<active-dataset> 20202021 3840
CHIP:BLE: New device scanned: 00:1A:7D:DA:71:15
CHIP:BLE: Device discriminator match. Attempting to connect.
CHIP:DIS: Closing all BLE connections
CHIP:TOO: Pairing Failure: src/platform/Linux/bluez/ChipDeviceScanner.cpp:173: CHIP Error 0x00000032: Timeout
CHIP:BLE: BLE scan error: src/platform/Linux/bluez/ChipDeviceScanner.cpp:173: CHIP Error 0x00000032: Timeout
farshidtz commented 6 months ago

Using a modified version of chip-tool tests to use the snap from this branch, it works as expected. The tests use the manual pairing code for commissioning, instead of BLE. I believe the BLE issue is from a misconfiguration; these instructions mention the need to enable experimental BlueZ features.

chip-tool-snap/tests$ LOCAL_INFRA_IF="enp2s0" REMOTE_INFRA_IF="wlan0" REMOTE_USER="ubuntu" REMOTE_PASSWORD="raspberry" REMOTE_HOST="neptune.local" go test -v -failfast -count 1 ./thread_tests
=== RUN   TestAllClustersAppThread
    snap.go:62: [exec] sudo snap remove --purge chip-tool
    exec.go:140: [stderr] snap "chip-tool" is not installed
2024/05/31 16:59:36 [exec] sudo snap install chip-tool --channel=latest/edge
2024/05/31 16:59:39 [stdout] chip-tool (edge) master+snap from Canonical IoT Labs installed
    snap.go:81: [exec] sudo snap connect chip-tool:avahi-observe 
    snap.go:81: [exec] sudo snap connect chip-tool:bluez 
    snap.go:81: [exec] sudo snap connect chip-tool:process-control 
    snap.go:62: [exec] sudo snap remove --purge openthread-border-router
    exec.go:140: [stderr] snap "openthread-border-router" is not installed
    snap.go:28: [exec] sudo snap install openthread-border-router --channel=edge/pr-41
    exec.go:140: [stdout] openthread-border-router (edge/pr-41) thread-reference-20230710+snap from Canonical IoT Labs installed
2024/05/31 16:59:46 [exec] sudo snap connect openthread-border-router:avahi-control 
2024/05/31 16:59:47 [exec] sudo snap connect openthread-border-router:firewall-control 
2024/05/31 16:59:47 [exec] sudo snap connect openthread-border-router:raw-usb 
2024/05/31 16:59:48 [exec] sudo snap connect openthread-border-router:network-control 
2024/05/31 16:59:49 [exec] sudo snap connect openthread-border-router:bluetooth-control 
2024/05/31 16:59:50 [exec] sudo snap connect openthread-border-router:bluez 
2024/05/31 16:59:51 [exec] sudo snap set openthread-border-router infra-if='enp2s0'
    snap.go:161: [exec] sudo snap start --enable openthread-border-router
    exec.go:140: [stdout] Started.
    local.go:79: Retry 1/10: Waiting for expected content in logs: Start Thread Border Agent: OK
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    local.go:83: Found expected content in logs: Start Thread Border Agent: OK
    local.go:58: [exec] sudo openthread-border-router.ot-ctl dataset init new
    local.go:59: [exec] sudo openthread-border-router.ot-ctl dataset commit active
    local.go:60: [exec] sudo openthread-border-router.ot-ctl ifconfig up
    local.go:61: [exec] sudo openthread-border-router.ot-ctl thread start
    config.go:59: Retry 1/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 2/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 3/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 4/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 5/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 6/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 7/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:59: Retry 8/10: Waiting for expected content in logs: Thread Network
    snap.go:138: [exec] sudo journalctl --since "2024-05-31 16:59:52" --no-pager | grep "openthread-border-router"|| true
    config.go:63: Found expected content in logs: Thread Network
    local.go:66: [exec] sudo openthread-border-router.ot-ctl dataset active -x | awk '{print $NF}' | grep --invert-match "Done"
    remote.go:82: SSH: connected to neptune.local
    remote.go:106: [exec-ssh] sudo snap remove --purge openthread-border-router
    remote.go:106: [exec-ssh] sudo snap install openthread-border-router --channel=edge/pr-41
    remote.go:106: [exec-ssh] sudo snap set openthread-border-router infra-if='wlan0'
    remote.go:106: [exec-ssh] sudo snap connect openthread-border-router:firewall-control
    remote.go:106: [exec-ssh] sudo snap connect openthread-border-router:raw-usb
    remote.go:106: [exec-ssh] sudo snap connect openthread-border-router:network-control
    remote.go:106: [exec-ssh] sudo snap start openthread-border-router
    remote.go:109: Retry 1/10: Waiting for expected content in logs: 'Start Thread Border Agent: OK'
    remote.go:109: [exec-ssh] sudo journalctl --utc --since "2024-05-31 15:00:04" --no-pager | grep "openthread-border-router"|| true
    remote.go:109: Found expected content in logs: 'Start Thread Border Agent: OK'
    remote.go:110: OTBR on remote device is ready
    remote.go:132: [exec-ssh] sudo apt install bluez
    remote.go:132: [exec-ssh] sudo snap remove --purge matter-all-clusters-app
    remote.go:132: [exec-ssh] sudo snap install matter-all-clusters-app --edge
    remote.go:132: [exec-ssh] sudo snap set matter-all-clusters-app args='--thread'
    remote.go:132: [exec-ssh] sudo snap connect matter-all-clusters-app:avahi-control
    remote.go:132: [exec-ssh] sudo snap connect matter-all-clusters-app:bluez
    remote.go:132: [exec-ssh] sudo snap connect matter-all-clusters-app:otbr-dbus-wpan0 openthread-border-router:dbus-wpan0
    remote.go:132: [exec-ssh] sudo snap start matter-all-clusters-app
    remote.go:135: Retry 1/10: Waiting for expected content in logs: 'CHIP minimal mDNS started advertising'
    remote.go:135: [exec-ssh] sudo journalctl --utc --since "2024-05-31 15:00:18" --no-pager | grep "matter-all-clusters-app"|| true
    remote.go:135: Found expected content in logs: 'CHIP minimal mDNS started advertising'
    remote.go:136: Matter All Clusters App is ready
=== RUN   TestAllClustersAppThread/Commission
    thread_test.go:20: [exec] sudo chip-tool pairing code-thread 110 hex:0e080000000000010000000300001035060004001fffe00208fd6d683b73b89e3e0708fdffa7d91d3e586a0510ef5e3a27d1cd7a160e88763e8a6104e3030f4f70656e5468726561642d32363932010226920410fe2233e4370e6c7a5ba4082ac9fc7c100c0402a0f7f8 34970112332 2>&1
=== RUN   TestAllClustersAppThread/Control
    thread_test.go:28: [exec] sudo chip-tool onoff toggle 110 1 2>&1
    thread_test.go:33: Retry 1/10: Waiting for expected content in logs: 'CHIP:ZCL: Toggle ep1 on/off'
    thread_test.go:33: [exec-ssh] sudo journalctl --utc --since "2024-05-31 15:00:40" --no-pager | grep "matter-all-clusters-app"|| true
    thread_test.go:33: Found expected content in logs: 'CHIP:ZCL: Toggle ep1 on/off'
=== NAME  TestAllClustersAppThread
    remote.go:116: [exec-ssh] sudo snap remove --purge matter-all-clusters-app
    remote.go:88: [exec-ssh] sudo snap remove --purge openthread-border-router
    snap.go:62: [exec] sudo snap remove --purge openthread-border-router
    exec.go:140: [stdout] openthread-border-router removed
    snap.go:62: [exec] sudo snap remove --purge chip-tool
    exec.go:140: [stdout] chip-tool removed
--- PASS: TestAllClustersAppThread (99.44s)
    --- PASS: TestAllClustersAppThread/Commission (2.12s)
    --- PASS: TestAllClustersAppThread/Control (1.55s)
PASS
ok      chip-tool-snap-tests/thread_tests       99.445s