search

openthread / ot-br-posix

OpenThread Border Router, a Thread border router for POSIX-based platforms.
https://openthread.io/
BSD 3-Clause "New" or "Revised" License
403 stars 228 forks source link

multicast routing failed using openwrt #1672

Open seba0506 opened 1 year ago

seba0506 commented 1 year ago

Hi,

I have enabled the below-mentioned feature in my application. After enabling the "OTBR_BACKBONE_ROUTER=ON" feautre otbr-agent was stopped.


**Configuration Makefile**

#
#  Copyright (c) 2020, The OpenThread Authors.
#  All rights reserved.
#
#  Redistribution and use in source and binary forms, with or without
#  modification, are permitted provided that the following conditions are met:
#  1. Redistributions of source code must retain the above copyright
#     notice, this list of conditions and the following disclaimer.
#  2. Redistributions in binary form must reproduce the above copyright
#     notice, this list of conditions and the following disclaimer in the
#     documentation and/or other materials provided with the distribution.
#  3. Neither the name of the copyright holder nor the
#     names of its contributors may be used to endorse or promote products
#     derived from this software without specific prior written permission.
#
#  THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS "AS IS"
#  AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
#  IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
#  ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT HOLDER OR CONTRIBUTORS BE
#  LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR
#  CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF
#  SUBSTITUTE GOODS OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS
#  INTERRUPTION) HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN
#  CONTRACT, STRICT LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE)
#  ARISING IN ANY WAY OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE
#  POSSIBILITY OF SUCH DAMAGE.
#

LOCAL_SOURCE_DIR:=$(abspath $(realpath $(dir $(lastword $(MAKEFILE_LIST))))/../../..)

include $(TOPDIR)/rules.mk

PKG_NAME:=openthread-br
PKG_LICENSE:=BSD-3-Clause
PKG_LICENSE_FILES:=LICENSE
PKG_RELEASE:=1
PKG_VERSION:=1.0

#PKG_SOURCE_PROTO:=git
#PKG_SOURCE_URL:=https://github.com/openthread/ot-br-posix.git
#PKG_MIRROR_HASH:=skip

#PKG_SOURCE:=$(PKG_NAME)-$(PKG_SOURCE_DATE).tar.gz
#PKG_SOURCE_SUBDIR:=$(PKG_NAME)
#PKG_BUILD_DIR:=$(BUILD_DIR)/$(PKG_NAME)

include $(INCLUDE_DIR)/package.mk
include $(INCLUDE_DIR)/cmake.mk

CMAKE_SOURCE_DIR=$(LOCAL_SOURCE_DIR)
CMAKE_OPTIONS+= \
        -DBUILD_TESTING=OFF \
        -DCMAKE_INSTALL_PREFIX=/usr \
        -DOTBR_OPENWRT=ON \
        -DOTBR_BORDER_AGENT=ON \
        -DOTBR_BORDER_ROUTING=ON \
        -DOTBR_SRP_ADVERTISING_PROXY=ON \
        -DOTBR_INFRA_IF_NAME=br-lan \
        -DOT_POSIX_SETTINGS_PATH=\"/etc/openthread\" \
        -DOT_READLINE=OFF \
        -DOT_FIREWALL=OFF \
        -DOTBR_BACKBONE_ROUTER=ON \
        -DOTBR_DBUS_SERVER=OFF \
        -DOTBR_DNSSD_DISCOVERY_PROXY=ON \
        -DOTBR_FEATURE_FLAGS=OFF \
        -DOTBR_NAT64=ON \
        -DOTBR_NOTIFY_UPSTART=ON \
        -DOTBR_REST=OFF \
        -DOTBR_VENDOR_INFRA_LINK_SELECT=OFF \
        -DOTBR_VENDOR_NAME=OpenThread \
        -DOTBR_PRODUCT_NAME=BorderRouter \
        -DOTBR_PACKAGE_NAME=OpenThread_BorderRouter \
        -DOTBR_MESHCOP_SERVICE_INSTANCE_NAME=OpenThreadBorderRouter \
        -DOTBR_SRP_SERVER=ON \
        -DOTBR_DUA_ROUTING=OFF

TARGET_CFLAGS += -DOPENTHREAD_POSIX_CONFIG_DAEMON_SOCKET_BASENAME=\\\"/var/run/openthread-%s\\\"

define Package/openthread-br
        SECTION:=base
        CATEGORY:=Network
        TITLE:=OpenThread Border Router
        DEPENDS:=+libstdcpp +libjson-c +libubus +libblobmsg-json +libavahi-client +libavahi-compat-libdnssd +ipset +iptables-mod-extra
endef

define Package/openthread-br/description
    A Thread border router for POSIX-based platforms.
endef

define Package/openthread-br/install
        $(INSTALL_DIR) $(1)/usr/sbin
        $(INSTALL_BIN) $(PKG_INSTALL_DIR)/usr/sbin/otbr-agent $(1)/usr/sbin
        $(INSTALL_BIN) $(PKG_INSTALL_DIR)/usr/sbin/ot-ctl $(1)/usr/sbin

        $(INSTALL_DIR) $(1)/etc/init.d
        $(INSTALL_BIN) $(PKG_INSTALL_DIR)/etc/init.d/* $(1)/etc/init.d

        $(INSTALL_DIR) $(1)/usr/lib/lua/luci/controller/admin
        $(INSTALL_BIN) $(LOCAL_SOURCE_DIR)/src/openwrt/controller/thread.lua $(1)/usr/lib/lua/luci/controller/admin

        $(INSTALL_DIR) $(1)/usr/lib/lua/luci/view
        $(CP) $(LOCAL_SOURCE_DIR)/src/openwrt/view/admin_thread $(1)/usr/lib/lua/luci/view

        $(INSTALL_DIR) $(1)/www/luci-static/resources
        $(CP) $(LOCAL_SOURCE_DIR)/src/openwrt/handle_error.js $(1)/www/luci-static/resources
endef

$(eval $(call BuildPackage,openthread-br))

**log file**

Tue Dec 20 17:29:52 2022 daemon.notice procd: start /etc/init.d/otbr-agent running
Tue Dec 20 17:29:52 2022 user.notice otbr-agent: [NOTE]-AGENT---: Backbone interface: br-lan
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: [NOTE]-AGENT---: Running 0.3.0-73a7d0c
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: [NOTE]-AGENT---: Thread version: 1.3.0
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: [NOTE]-AGENT---: Thread interface: wpan0
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: [NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyUSB1
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: [NOTE]-AGENT---: Radio URL: trel://br-lan
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: [NOTE]-ILS-----: Infra link selected: br-lan
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-NCP-----: OpenThread log level changed to 5
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 49d.17:11:06.085 [I] Platform------: RCP reset: RESET_POWER_ON
Tue Dec 20 17:29:52 2022 daemon.notice procd: stop /etc/init.d/otbr-agent running - took 0.065644180s
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 49d.17:11:06.113 [I] Platform------: Backbone interface is configured to br-lan (24)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.059 [I] Settings------: Read NetworkInfo {rloc:0x0000, extaddr:c2cb7eeddda8b288, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.059 [I] Settings------: ... pid:0x57960b93, mlecntr:0x332f, maccntr:0x32c8, mliid:6b5980d2973f213c}
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.074 [I] InfraIf-------: Init infra netif 24
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.074 [I] Settings------: Read BrUlaPrefix fd66:1ad2:63ae::/48
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: 00:00:00.074 [N] BorderRouter--: BR ULA prefix: fd66:1ad2:63ae::/48 (loaded)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.075 [I] BorderRouter--: Generated OMR prefix: fd66:1ad2:63ae:1::/64
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.075 [I] BorderRouter--: Generated local NAT64 prefix: fd66:1ad2:63ae:2:0:0::/96
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.075 [I] BorderRouter--: Restored old prefix fd9d:e9bc:617c:5574::/64, lifetime:1800
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: 00:00:00.075 [N] BorderRouter--: Local on-link prefix: fd9d:e9bc:617c:5574::/64
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.075 [I] InfraIf-------: State changed: NOT RUNNING -> RUNNING
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-UTILS---: Set state callback: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.075 [I] Nat64---------: NAT64 translator enabled
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Avahi client state changed to 2
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Avahi client is ready
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local.
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Commit avahi service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-ADPROXY-: Publish all hosts and services
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-ADPROXY-: Started
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-DPROXY--: Started
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Start Thread Border Agent: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.090 [I] BbrLocal------: Add Domain Prefix: ::/0, NotFound
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.090 [I] BbrLocal------: Add BBR Service: seqno (97), delay (5s), timeout (3600s), InvalidState
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-APP-----: Thread Border Router started on AIL br-lan.
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] Notifier------: StateChanged (0x121fc300) [KeySeqCntr NetData Channel PanId NetName ExtPanId NetworkKey PSKc SecPolicy ...
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] Notifier------: StateChanged (0x121fc300) ... BbrState ActDset]
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd7f:cb27:8c58:29a7:0:3: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] BbrManager----: Start Backbone TMF agent: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] AnnounceSender: ChannelMask:{ 11-26 }, period:21500
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] AnnounceSender: StartingChannel:23
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] AnnounceSender: StartingChannel:23
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.092 [I] Platform------: MulticastRoutingManager: Disable: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local.
Tue Dec 20 17:29:52 2022 user.debug otbr-agent[13947]: [DEBG]-BBA-----: BackboneAgent: HandleBackboneRouterState: state=1, mBackboneRouterState=0
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-UBUS----: Connected as 1969bc84
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-UBUS----: Uloop run
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.105 [I] Platform------: [netif] Host netif is down
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.112 [I] Platform------: [netif] Added multicast address ff02::1
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.112 [I] Platform------: [netif] Added multicast address ff03::1
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.112 [I] Platform------: [netif] Added multicast address ff03::fc
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.112 [I] Platform------: [netif] Sent request#1 to add fe80::c0cb:7eed:dda8:b288/64
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] DnssdServer---: started: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] BbrLocal------: Remove BBR Service: seqno (97), delay (5s), timeout (3600s), NotFound
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: 00:00:00.113 [N] Mle-----------: Role disabled -> detached
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] Platform------: [netif] Sent request#2 to add fd7f:cb27:8c58:29a7:6b59:80d2:973f:213c/64
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] Platform------: [netif] Added multicast address ff32:40:fd7f:cb27:8c58:29a7:0:1
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] Platform------: [netif] Added multicast address ff33:40:fd7f:cb27:8c58:29a7:0:1
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] Bbr-----------: Backbone TMF unsubscribes ff32:40:fd7f:cb27:8c58:29a7:0:3: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.113 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd7f:cb27:8c58:29a7:0:3: OK
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.115 [I] Platform------: [netif] Sent request#3 to add fd7f:cb27:8c58:29a7:0:ff:fe00:0/64
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.115 [I] Mle-----------: Attempt to become router
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.115 [I] Settings------: Read NetworkInfo {rloc:0x0000, extaddr:c2cb7eeddda8b288, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.115 [I] Settings------: ... pid:0x57960b93, mlecntr:0x332f, maccntr:0x32c8, mliid:6b5980d2973f213c}
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.190 [I] Settings------: Saved NetworkInfo {rloc:0x0000, extaddr:c2cb7eeddda8b288, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.190 [I] Settings------: ... pid:0x57960b93, mlecntr:0x3718, maccntr:0x36b0, mliid:6b5980d2973f213c}
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.190 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.191 [I] Notifier------: StateChanged (0x0100103d) [Ip6+ Role LLAddr MLAddr Rloc+ Ip6Mult+ NetifState]
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.191 [I] AnnounceSender: Stopped
Tue Dec 20 17:29:52 2022 user.notice otbr-agent[13947]: 00:00:00.191 [N] Platform------: [netif] Changing interface state to up.
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Thread is down
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local.
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing existing service OpenThreadBorderRouter #B288._meshcop._udp: outdated
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Cancelled previous publishing meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-BA------: Cancelled previous publishing meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Releasing avahi entry group @0x7c1f00
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Commit avahi service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.213 [I] Platform------: [netif] Message dropped by Thread
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.213 [I] Platform------: [netif] Succeeded to process request#1
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.219 [I] Platform------: [netif] Succeeded to process request#2
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.222 [I] Platform------: [netif] ADD [U] fe80:0:0:0:c0cb:7eed:dda8:b288 (already subscribed, ignored)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.226 [I] Platform------: [netif] ADD [U] fd7f:cb27:8c58:29a7:6b59:80d2:973f:213c (already subscribed, ignored)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.226 [I] Platform------: [netif] Succeeded to process request#3
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.226 [I] Platform------: [netif] ADD [U] fd7f:cb27:8c58:29a7:0:ff:fe00:0 (already subscribed, ignored)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.226 [I] Platform------: [netif] Host netif is up
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.226 [I] Nat64---------: IPv4 CIDR for NAT64: 192.168.255.0/24 (actual address pool: 192.168.255.1 - 192.168.255.254, 254 addresses)
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.227 [I] Platform------: [netif] Succeeded to enable NAT64
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.227 [I] Platform------: [netif] Succeeded to process request#4
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.231 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:a443, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.231 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:29:52 2022 user.info otbr-agent[13947]: 00:00:00.231 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:29:53 2022 user.info otbr-agent[13947]: 00:00:00.475 [I] Platform------: [netif] Message dropped by Thread
Tue Dec 20 17:29:53 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Avahi group (@0x7c2830) is established
Tue Dec 20 17:29:53 2022 user.info otbr-agent[13947]: [INFO]-BA------: Result of publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local: OK
Tue Dec 20 17:29:53 2022 user.info otbr-agent[13947]: 00:00:01.043 [I] Platform------: [netif] Message dropped by Thread
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:01.613 [I] BbrLocal------: Remove BBR Service: seqno (97), delay (5s), timeout (3600s), NotFound
Tue Dec 20 17:29:54 2022 user.notice otbr-agent[13947]: 00:00:01.613 [N] Mle-----------: RLOC16 0000 -> fffe
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:01.613 [I] Platform------: [netif] Sent request#5 to remove fd7f:cb27:8c58:29a7:0:ff:fe00:0/64
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:01.617 [I] Mle-----------: AttachState Idle -> Start
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:01.617 [I] Notifier------: StateChanged (0x10000040) [Rloc- ActDset]
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:01.619 [I] Platform------: [netif] DEL [U] fd7f:cb27:8c58:29a7:0:ff:fe00:0 (not found, ignored)
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:01.620 [I] Platform------: [netif] Succeeded to process request#5
Tue Dec 20 17:29:54 2022 user.notice otbr-agent[13947]: 00:00:02.194 [N] Mle-----------: Attach attempt 1, AnyPartition reattaching with Active Dataset
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:02.194 [I] Mle-----------: AttachState Start -> ParentReq
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:02.194 [I] Mle-----------: Send Parent Request to routers (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:02.211 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:9b8a, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:02.211 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:29:54 2022 user.info otbr-agent[13947]: 00:00:02.211 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:29:55 2022 user.info otbr-agent[13947]: 00:00:02.944 [I] Mle-----------: Send Parent Request to routers (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:29:55 2022 user.info otbr-agent[13947]: 00:00:02.961 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:5f81, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:29:55 2022 user.info otbr-agent[13947]: 00:00:02.961 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:29:55 2022 user.info otbr-agent[13947]: 00:00:02.961 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:29:56 2022 user.info otbr-agent[13947]: 00:00:03.694 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:29:56 2022 user.info otbr-agent[13947]: 00:00:03.712 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:3881, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:29:56 2022 user.info otbr-agent[13947]: 00:00:03.712 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:29:56 2022 user.info otbr-agent[13947]: 00:00:03.712 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:29:57 2022 user.info otbr-agent[13947]: 00:00:04.944 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:29:57 2022 user.info otbr-agent[13947]: 00:00:04.963 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:ffb4, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:29:57 2022 user.info otbr-agent[13947]: 00:00:04.963 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:29:57 2022 user.info otbr-agent[13947]: 00:00:04.963 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:29:58 2022 user.info otbr-agent[13947]: 00:00:06.194 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:29:58 2022 user.info otbr-agent[13947]: 00:00:06.213 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:3c25, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:29:58 2022 user.info otbr-agent[13947]: 00:00:06.213 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:29:58 2022 user.info otbr-agent[13947]: 00:00:06.213 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:30:00 2022 user.info otbr-agent[13947]: 00:00:07.444 [I] Mle-----------: Send Parent Request to routers and REEDs (ff02:0:0:0:0:0:0:2)
Tue Dec 20 17:30:00 2022 user.info otbr-agent[13947]: 00:00:07.461 [I] MeshForwarder-: Sent IPv6 UDP msg, len:84, chksum:17b5, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:30:00 2022 user.info otbr-agent[13947]: 00:00:07.461 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:30:00 2022 user.info otbr-agent[13947]: 00:00:07.461 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.694 [I] Mle-----------: AttachState ParentReq -> Idle
Tue Dec 20 17:30:01 2022 user.notice otbr-agent[13947]: 00:00:08.694 [N] RouterTable---: Allocate router id 0
Tue Dec 20 17:30:01 2022 user.notice otbr-agent[13947]: 00:00:08.694 [N] Mle-----------: RLOC16 fffe -> 0000
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.698 [I] Platform------: [netif] Sent request#6 to add fd7f:cb27:8c58:29a7:0:ff:fe00:0/64
Tue Dec 20 17:30:01 2022 user.notice otbr-agent[13947]: 00:00:08.698 [N] Mle-----------: Role detached -> leader
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.698 [I] Platform------: [netif] Sent request#7 to add fd7f:cb27:8c58:29a7:0:ff:fe00:fc00/64
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.698 [I] Platform------: [netif] Added multicast address ff02::2
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.698 [I] Platform------: [netif] Added multicast address ff03::2
Tue Dec 20 17:30:01 2022 user.notice otbr-agent[13947]: 00:00:08.698 [N] Mle-----------: Leader partition id 0x1ffc678f
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.698 [I] Notifier------: StateChanged (0x100012a5) [Ip6+ Role Rloc+ PartitionId NetData Ip6Mult+ ActDset]
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.698 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.699 [I] BbrLeader-----: PBBR state: None
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.699 [I] BbrLeader-----: Domain Prefix: ::/0, state: None
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.725 [I] Settings------: Saved NetworkInfo {rloc:0x0000, extaddr:c2cb7eeddda8b288, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.725 [I] Settings------: ... pid:0x1ffc678f, mlecntr:0x371f, maccntr:0x36b0, mliid:6b5980d2973f213c}
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.725 [I] AnnounceSender: Started
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.725 [I] BorderAgent---: Border Agent start listening on port 49155
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.725 [I] BorderRouter--: Border Routing manager started
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] NetDataPublshr: Publishing ExternalRoute fd9d:e9bc:617c:5574::/64
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 - State: NoEntry -> ToAdd
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 (state:ToAdd) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 - State: ToAdd -> Adding
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 (state:Adding) - update in 1970 msec
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] BorderRouter--: Scheduled Router Solicitation in 57 milliseconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] BorderRouter--: Starting Nat64PrefixManager
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] BorderRouter--: Start evaluating routing policy, scheduled in 3392 milliseconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.726 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-BA------: Thread is up
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-BA------: Publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local.
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing existing service OpenThreadBorderRouter #B288._meshcop._udp: outdated
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Releasing avahi entry group @0x7c2830
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Commit avahi service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:30:01 2022 user.warn otbr-agent[13947]: 00:00:08.733 [W] BorderRouter--: Failed to discover infraif NAT64 prefix: Drop
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.733 [I] BorderRouter--: NAT64 prefix timer scheduled in 300 seconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.733 [I] Platform------: [netif] Succeeded to process request#6
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.736 [I] Platform------: [netif] Message dropped by Thread
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.736 [I] Platform------: [netif] Succeeded to process request#7
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.738 [I] Platform------: [netif] ADD [U] fd7f:cb27:8c58:29a7:0:ff:fe00:0 (already subscribed, ignored)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.738 [I] Platform------: [netif] ADD [U] fd7f:cb27:8c58:29a7:0:ff:fe00:fc00 (already subscribed, ignored)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.756 [I] MeshForwarder-: Sent IPv6 UDP msg, len:96, chksum:a429, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.756 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.756 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.783 [I] BorderRouter--: Successfully sent RS 1/3
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.783 [I] BorderRouter--: Received Router Solicitation from fe80:0:0:0:a2b5:3cff:fea3:881f on infra netif 24
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.784 [I] BorderRouter--: Start evaluating routing policy, scheduled in 132 milliseconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.785 [I] BorderRouter--: Received Router Advertisement from fe80:0:0:0:a2b5:3cff:fea3:881f on infra netif 24
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.785 [I] BorderRouter--: Processing PIO (2001:db8:1:0::/64, 4294967295 seconds)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.785 [I] NetDataPublshr: Publishing ExternalRoute 2001:db8:1:0::/64
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.785 [I] NetDataPublshr: ExternalRoute 2001:db8:1:0::/64 - State: NoEntry -> ToAdd
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.786 [I] NetDataPublshr: ExternalRoute 2001:db8:1:0::/64 (state:ToAdd) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.786 [I] NetDataPublshr: ExternalRoute 2001:db8:1:0::/64 - State: ToAdd -> Adding
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.786 [I] NetDataPublshr: ExternalRoute 2001:db8:1:0::/64 (state:Adding) - update in 3247 msec
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.786 [I] BorderRouter--: Ignore RIO prefix 2001:db8:1::/48 since not a valid OMR prefix
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.788 [I] BorderRouter--: Start evaluating routing policy, scheduled in 3220 milliseconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.796 [I] BorderRouter--: Received Router Advertisement from fe80:0:0:0:0:0:0:1 on infra netif 24
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] BorderRouter--: Evaluating routing policy
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] BorderRouter--: EvaluateOmrPrefix: No preferred OMR prefix found in Thread network
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] BorderRouter--: Added local OMR prefix fd66:1ad2:63ae:1::/64 in Thread Network Data
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] BorderRouter--: Evaluating NAT64 prefix
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] NetDataPublshr: Publishing ExternalRoute fd66:1ad2:63ae:2:0:0::/96
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] NetDataPublshr: ExternalRoute fd66:1ad2:63ae:2:0:0::/96 - State: NoEntry -> ToAdd
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] NetDataPublshr: ExternalRoute fd66:1ad2:63ae:2:0:0::/96 (state:ToAdd) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] NetDataPublshr: ExternalRoute fd66:1ad2:63ae:2:0:0::/96 - State: ToAdd -> Adding
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] NetDataPublshr: ExternalRoute fd66:1ad2:63ae:2:0:0::/96 (state:Adding) - update in 2021 msec
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] Nat64---------: IPv6 Prefix for NAT64 updated to fd66:1ad2:63ae:2:0:0::/96
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] BorderRouter--: RouterAdvert: Added PIO for fd9d:e9bc:617c:5574::/64 (valid=1791, preferred=0)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.916 [I] BorderRouter--: RouterAdvert: Added RIO for fd66:1ad2:63ae:1::/64 (lifetime=1800)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] BorderRouter--: Sent Router Advertisement on infra netif 24
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] BorderRouter--: Start evaluating routing policy, scheduled in 16000 milliseconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] NetworkData---: Sent server data notification
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] BorderRouter--: Received Router Advertisement from fe80:0:0:0:a2b5:3cff:fea3:881f on infra netif 24
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] BorderRouter--: Processing PIO (fd9d:e9bc:617c:5574::/64, 1791 seconds)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] NetDataPublshr: Publishing ExternalRoute fd9d:e9bc:617c:5574::/64
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.917 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] NetworkData---: Received network data registration
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] NetworkData---: Allocated Context ID = 1
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] NetworkData---: Sent network data registration acknowledgment
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] Notifier------: StateChanged (0x00000200) [NetData]
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] BbrLeader-----: PBBR state: None
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] BbrLeader-----: Domain Prefix: ::/0, state: None
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] Settings------: Read SlaacIidSecretKey
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.921 [I] Slaac---------: Adding address fd66:1ad2:63ae:1:98a2:221e:e3d:f972
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.922 [I] Platform------: [netif] Sent request#8 to add fd66:1ad2:63ae:1:98a2:221e:e3d:f972/64
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.922 [I] BorderRouter--: Start evaluating routing policy, scheduled in 2995 milliseconds
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.922 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.923 [I] NetDataPublshr: ExternalRoute 2001:db8:1:0::/64 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.923 [I] NetDataPublshr: ExternalRoute fd66:1ad2:63ae:2:0:0::/96 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-BA------: Publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local.
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing existing service OpenThreadBorderRouter #B288._meshcop._udp: outdated
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-BA------: Cancelled previous publishing meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Releasing avahi entry group @0x7bfa20
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Commit avahi service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.930 [I] Notifier------: StateChanged (0x00000001) [Ip6+]
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.932 [I] Platform------: [netif] Message dropped by Thread
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.933 [I] Platform------: [netif] Succeeded to process request#8
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.933 [I] Platform------: [netif] ADD [U] fd66:1ad2:63ae:1:98a2:221e:e3d:f972 (already subscribed, ignored)
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.955 [I] MeshForwarder-: Sent IPv6 UDP msg, len:118, chksum:ab49, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.955 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:30:01 2022 user.info otbr-agent[13947]: 00:00:08.955 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.275 [I] Platform------: [netif] Message dropped by Thread
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.503 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.523 [I] MeshForwarder-: Sent IPv6 UDP msg, len:90, chksum:8103, ecn:no, to:0xffff, sec:no, prio:net
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.523 [I] MeshForwarder-:     src:[fe80:0:0:0:c0cb:7eed:dda8:b288]:19788
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.523 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.574 [I] BbrLocal------: Add BBR Service: seqno (97), delay (5s), timeout (3600s), OK
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.574 [I] NetworkData---: Sent server data notification
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.575 [I] NetworkData---: Received network data registration
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.575 [I] NetworkData---: Allocated Service ID = 0
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.575 [I] NetworkData---: Sent network data registration acknowledgment
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.575 [I] Notifier------: StateChanged (0x00000200) [NetData]
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.575 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.575 [I] BbrLeader-----: PBBR state: Added
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.576 [I] BbrLeader-----: Rloc16:0x   0, seqno:97, delay:5, timeout:3600
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.576 [I] Platform------: [netif] Sent request#9 to add fd7f:cb27:8c58:29a7:0:ff:fe00:fc38/64
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.576 [I] BbrLeader-----: Domain Prefix: ::/0, state: None
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.577 [I] Platform------: [netif] Sent request#10 to add fd7f:cb27:8c58:29a7:0:ff:fe00:fc10/64
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.577 [I] BorderRouter--: Start evaluating routing policy, scheduled in 2870 milliseconds
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.577 [I] NetDataPublshr: ExternalRoute fd9d:e9bc:617c:5574::/64 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.578 [I] NetDataPublshr: ExternalRoute 2001:db8:1:0::/64 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.578 [I] NetDataPublshr: ExternalRoute fd66:1ad2:63ae:2:0:0::/96 (state:Adding) in netdata - total:0, preferred:0, desired:10
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: [INFO]-BA------: Publish meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local.
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing existing service OpenThreadBorderRouter #B288._meshcop._udp: outdated
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Removing service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: [INFO]-BA------: Cancelled previous publishing meshcop service OpenThreadBorderRouter #B288._meshcop._udp.local
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Releasing avahi entry group @0x7c20c8
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: [INFO]-MDNS----: Commit avahi service OpenThreadBorderRouter #B288._meshcop._udp
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.585 [I] Notifier------: StateChanged (0x02000001) [Ip6+ BbrState]
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.585 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd7f:cb27:8c58:29a7:0:3: OK
Tue Dec 20 17:30:02 2022 user.info otbr-agent[13947]: 00:00:09.586 [I] BbrManager----: Start Backbone TMF agent: OK
Tue Dec 20 17:30:02 2022 user.crit otbr-agent[13947]: 00:00:09.586 [C] Platform------: InitMulticastRouterSock() at multicast_routing.cpp:225: Address already in use
Tue Dec 20 17:30:02 2022 daemon.notice procd: Instance otbr-agent::instance1 exit with error code 1280 after 10 seconds
root@CP2235RA916:~#

**netstat log**

root@CP2235RA916:~# netstat -tupln
Active Internet connections (only servers)
Proto Recv-Q Send-Q Local Address           Foreign Address         State       PID/Program name
tcp        0      0 127.0.0.1:55000         0.0.0.0:*               LISTEN      11117/ceventd
tcp        0      0 0.0.0.0:443             0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 127.0.0.1:5916          0.0.0.0:*               LISTEN      11231/acsd2
tcp        0      0 0.0.0.0:51007           0.0.0.0:*               LISTEN      7333/cwmpd
tcp        0      0 192.168.1.9:49152       0.0.0.0:*               LISTEN      11242/hostapd
tcp        0      0 192.168.1.9:49152       0.0.0.0:*               LISTEN      11239/hostapd
tcp        0      0 127.0.0.1:55555         0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 0.0.0.0:9443            0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 127.0.0.1:45065         0.0.0.0:*               LISTEN      11128/bsd
tcp        0      0 0.0.0.0:6698            0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 0.0.0.0:6699            0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 0.0.0.0:8080            0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 0.0.0.0:80              0.0.0.0:*               LISTEN      7568/nginx.conf
tcp        0      0 127.0.0.1:50257         0.0.0.0:*               LISTEN      11250/wbd_slave
tcp        0      0 127.0.0.1:50259         0.0.0.0:*               LISTEN      11250/wbd_slave
tcp        0      0 127.0.0.1:50260         0.0.0.0:*               LISTEN      11250/wbd_slave
tcp        0      0 0.0.0.0:22              0.0.0.0:*               LISTEN      5276/dropbear
tcp        0      0 :::443                  :::*                    LISTEN      7568/nginx.conf
tcp        0      0 :::51007                :::*                    LISTEN      7333/cwmpd
tcp        0      0 :::9443                 :::*                    LISTEN      7568/nginx.conf
tcp        0      0 :::6698                 :::*                    LISTEN      7568/nginx.conf
tcp        0      0 :::6699                 :::*                    LISTEN      7568/nginx.conf
tcp        0      0 :::8080                 :::*                    LISTEN      7568/nginx.conf
tcp        0      0 :::80                   :::*                    LISTEN      7568/nginx.conf
tcp        0      0 :::22                   :::*                    LISTEN      5276/dropbear
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           11242/hostapd
udp        0      0 0.0.0.0:1900            0.0.0.0:*                           11239/hostapd
udp        0      0 0.0.0.0:36718           0.0.0.0:*                           7225/avahi-daemon:
udp        0      0 127.0.0.1:50032         0.0.0.0:*                           11250/wbd_slave
udp        0      0 127.0.0.1:38000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:48000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:37000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:58000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:58032         0.0.0.0:*                           11247/wps_pbcd
udp        0      0 127.0.0.1:46000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:45000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:44000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:45032         0.0.0.0:*                           11128/bsd
udp        0      0 0.0.0.0:5353            0.0.0.0:*                           7225/avahi-daemon:
udp        0      0 127.0.0.1:43000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:44032         0.0.0.0:*                           2733/wlssk
udp        0      0 127.0.0.1:40200         0.0.0.0:*                           8672/mesh_broker
udp        0      0 127.0.0.1:42000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:52000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:42032         0.0.0.0:*                           11231/acsd2
udp        0      0 127.0.0.1:51000         0.0.0.0:*                           11115/eapd
udp        0      0 127.0.0.1:52032         0.0.0.0:*                           11117/ceventd
udp        0      0 0.0.0.0:68              0.0.0.0:*                           12528/odhcpc
udp        0      0 127.0.0.1:50000         0.0.0.0:*                           11115/eapd
udp        0      0 :::123                  :::*                                8002/ntpd
udp        0      0 :::40888                :::*                                7225/avahi-daemon:
udp        0      0 :::5353                 :::*                                7225/avahi-daemon:
udp        0      0 :::546                  :::*                                12660/odhcp6c
udp        0      0 :::547                  :::*                                6866/odhcpd
root@CP2235RA916:~#

Did I miss anything? please suggest

seba0506 commented 1 year ago

Hi,

I have changed the below-mentioned code, and after that backbone, and router working fine without any issues. Please confirm from your end.

void MulticastRoutingManager::InitMulticastRouterSock(void) { int one = 1; struct icmp6_filter filter; struct mif6ctl mif6ctl;

// Create a Multicast Routing socket
mMulticastRouterSock = SocketWithCloseExec(AF_INET6, SOCK_RAW, IPPROTO_ICMPV6, kSocketBlock);
VerifyOrDie(mMulticastRouterSock != -1, OT_EXIT_ERROR_ERRNO);

// Enable Multicast Forwarding in Kernel
//VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_IPV6, MRT6_INIT, &one, sizeof(one)), OT_EXIT_ERROR_ERRNO);
VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_IPV6, SO_REUSEADDR, &one, sizeof(one)), OT_EXIT_ERROR_ERRNO);

// Filter all ICMPv6 messages
ICMP6_FILTER_SETBLOCKALL(&filter);
VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_ICMPV6, ICMP6_FILTER, (void *)&filter, sizeof(filter)),
            OT_EXIT_ERROR_ERRNO);

memset(&mif6ctl, 0, sizeof(mif6ctl));
mif6ctl.mif6c_flags     = 0;
mif6ctl.vifc_threshold  = 1;
mif6ctl.vifc_rate_limit = 0;

// Add Thread network interface to MIF
mif6ctl.mif6c_mifi = kMifIndexThread;
mif6ctl.mif6c_pifi = if_nametoindex(gNetifName);
VerifyOrDie(mif6ctl.mif6c_pifi > 0, OT_EXIT_ERROR_ERRNO);
//VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_IPV6, MRT6_ADD_MIF, &mif6ctl, sizeof(mif6ctl)),OT_EXIT_ERROR_ERRNO);
 VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_IPV6, SO_REUSEADDR, &mif6ctl, sizeof(mif6ctl)),OT_EXIT_ERROR_ERRNO);

// Add Backbone network interface to MIF
mif6ctl.mif6c_mifi = kMifIndexBackbone;
mif6ctl.mif6c_pifi = if_nametoindex(gBackboneNetifName);
VerifyOrDie(mif6ctl.mif6c_pifi > 0, OT_EXIT_ERROR_ERRNO);
//VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_IPV6, MRT6_ADD_MIF, &mif6ctl, sizeof(mif6ctl)),OT_EXIT_ERROR_ERRNO);

VerifyOrDie(0 == setsockopt(mMulticastRouterSock, IPPROTO_IPV6, SO_REUSEADDR, &mif6ctl, sizeof(mif6ctl)),OT_EXIT_ERROR_ERRNO); }