Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

is there a way to dynamically change interface of otbr-agent #2152

Open
gadekula1 opened this issue Jan 2, 2024 · 5 comments
Open

is there a way to dynamically change interface of otbr-agent #2152

gadekula1 opened this issue Jan 2, 2024 · 5 comments

Comments

@gadekula1
Copy link

Use case : started otbr-agent with interface eth0, but due to some reason eth0 down, then without restarting or crash otbr-agent should continue with other available interfaces like wlan0. please confirm this feasibility is available in existing codebase.

below ways tried to achieve changing interfaces dynamically :
started service with below parameters
/usr/sbin/otbr-agent -I wpan0 -B eth0 -B wlan0 spinel+hdlc+uart:///dev/ttyThreadRCP?uart-baudrate=460800/

`2023-01-01T00:20:56.930278Z [1257.920526200] user.notice otbr-agent [NOTE]-AGENT---: Backbone interface: eth0
2023-01-01T00:20:56.930703Z [1257.920946720] user.notice otbr-agent [NOTE]-AGENT---: Backbone interface: wlan0
2023-01-01T00:20:56.930812Z [1257.921052440] user.notice otbr-agent[15689] [NOTE]-AGENT---: Running 0.3.0-22d4f4e488-dirty
2023-01-01T00:20:56.930897Z [1257.921137060] user.notice otbr-agent[15689] [NOTE]-AGENT---: Thread version: 1.3.0
2023-01-01T00:20:56.930961Z [1257.921199000] user.notice otbr-agent[15689] [NOTE]-AGENT---: Thread interface: wpan0
2023-01-01T00:20:56.931019Z [1257.921257740] user.notice otbr-agent[15689] [NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyThreadRCP?uart-baudrate=460800/
2023-01-01T00:20:56.931164Z [1257.921403400] user.info otbr-agent[15689] [INFO]-ILS-----: Evaluating infra link among 2 netifs:
2023-01-01T00:20:56.931225Z [1257.921464580] user.info otbr-agent[15689] [INFO]-ILS-----: ^IInfra link eth0 is in state UP+RUNNING
2023-01-01T00:20:56.931300Z [1257.921538200] user.info otbr-agent[15689] [INFO]-ILS-----: ^IInfra link wlan0 is in state UP
2023-01-01T00:20:56.931357Z [1257.921595100] user.notice otbr-agent[15689] [NOTE]-ILS-----: Infra link selected: eth0

Infra link selected: eth0

commissioned end device.

then made the interface eth0 down.

service restarted with interface change :
{
const char *newInfraLink = mInfraLinkSelector.Select();

            if (mBackboneInterfaceName != newInfraLink)
            {
                error = **OTBR_ERROR_INFRA_LINK_CHANGED**;
                break;
            }
        }`

due to restart service service selected Infra link selected: wlan0

but unable to control commissioned end device previously.

later made the eth0 up , able to control commissioned end device

@jwhui
Copy link
Member

jwhui commented Jan 30, 2024

OpenThread process will restart when it detects a need to change to a different infrastructure interface.

The Thread network should be reachable on the new infrastructure link after restart. Are you sure that the commissioner is attached to the same Wi-Fi network when it switches to wlan0?

@gadekula1
Copy link
Author

gadekula1 commented Jan 31, 2024

Thanks @jwhui for reply,
Yes, we didn't disturb the setup of matter devices (android chip-tool and OTBR device connected to same N/W).
once again we give setup details:
Android chip-tool app mobile and OTBR device connected to same N/W
Started otbr-agent with eth0 interface.
Used android chip-tool to commission the mater enabled thread device (nrf DK)
Able to commission and control the end device with android chip-tool via OTBR
Then ifconfig down eth0
otbr-agent restarted with wlan0 interface (as per your earlier comments).

but we are unable to control already commissioned end device earlier with eth0 interface

Please let us know if any extra procedure/steps required to control end device with android chip-tool via OTBR after changing interface dynamically (from eth0 to wlan0)?

@jwhui
Copy link
Member

jwhui commented Jan 31, 2024

Can you check whether the appropriate DNS-SD records are being published on wlan0? In other words, is the Matter device discoverable after switching to wlan0?

If DNS-SD discovery is working, can you check whether IPv6 reachability is working?

@gadekula1
Copy link
Author

gadekula1 commented Feb 6, 2024

Logs of otbr-agent when lan goes down and started with wlan0 able to see wlan0 publishing service

tail -f /var/log/legacy-log | grep otbr
2024-02-06T12:08:05.459016Z [268.661805500] user.info otbr-agent[2704] 00:02:41.119 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:05.459042Z [268.661831240] user.info otbr-agent[2704] 00:02:41.119 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:05.459064Z [268.661853520] user.info otbr-agent[2704] 00:02:41.119 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c4e4:9a9d:dd3e:fa11,0x3800)





2024-02-06T12:08:30.971826Z [294.174621680] user.info otbr-agent[2704] 00:03:06.632 [I] InfraIf-------: State changed: RUNNING -> NOT RUNNING
2024-02-06T12:08:30.971912Z [294.174701500] user.info otbr-agent[2704] 00:03:06.632 [I] RoutingManager: Preparing RA
2024-02-06T12:08:30.971938Z [294.174727020] user.info otbr-agent[2704] 00:03:06.632 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1704, preferred:0)
2024-02-06T12:08:30.971960Z [294.174749480] user.info otbr-agent[2704] 00:03:06.632 [I] RoutingManager: - RIO fd11:22:0:0::/64 (lifetime:0, prf:medium)
2024-02-06T12:08:30.971981Z [294.174770460] user.info otbr-agent[2704] 00:03:06.632 [I] RoutingManager: Sent RA on infra netif 2
2024-02-06T12:08:30.972002Z [294.174791260] user.info otbr-agent[2704] 00:03:06.632 [I] NetDataPublshr: Unpublishing fc00::/7
2024-02-06T12:08:30.972022Z [294.174811600] user.info otbr-agent[2704] 00:03:06.632 [I] NetDataPublshr: ExternalRoute fc00::/7 - State: Added -> NoEntry
2024-02-06T12:08:30.972046Z [294.174834900] user.info otbr-agent[2704] 00:03:06.632 [I] RoutingManager: Stopped
2024-02-06T12:08:30.972067Z [294.174855740] user.info otbr-agent[2704] 00:03:06.632 [I] NetDataPublshr: Unpublishing DNS/SRP service
2024-02-06T12:08:30.972087Z [294.174876500] user.info otbr-agent[2704] 00:03:06.632 [I] SrpServer-----: Fully remove host C6E49A9DDD3EFA11.default.service.arpa.
2024-02-06T12:08:30.972108Z [294.174897260] user.info otbr-agent[2704] 00:03:06.632 [I] SrpServer-----: SRP update handler is notified (updatedId = 924676776)
2024-02-06T12:08:30.972129Z [294.174917940] user.info otbr-agent[2704] [INFO]-ADPROXY-: Advertise SRP service updates: host=C6E49A9DDD3EFA11.default.service.arpa.
2024-02-06T12:08:30.972149Z [294.174938380] user.info otbr-agent[2704] [INFO]-MDNS----: Removing service CD262F6D7C36CCC4-000000000000000F._matter._tcp
2024-02-06T12:08:30.972170Z [294.174958600] user.info otbr-agent[2704] [INFO]-MDNS----: Releasing avahi entry group @0x125f308
2024-02-06T12:08:30.977771Z [294.180568340] user.info otbr-agent[2704] [INFO]-ADPROXY-: Handle unpublish SRP service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.': OK
2024-02-06T12:08:30.977855Z [294.180645620] user.info otbr-agent[2704] [INFO]-ADPROXY-: Waiting for more publishing callbacks 2
2024-02-06T12:08:30.977884Z [294.180673560] user.info otbr-agent[2704] [INFO]-MDNS----: Removing service 13D4CAB52E738C5D._matterc._udp
2024-02-06T12:08:30.977906Z [294.180695680] user.info otbr-agent[2704] [INFO]-MDNS----: Releasing avahi entry group @0x1258de0
2024-02-06T12:08:30.981158Z [294.183952900] user.info otbr-agent[2704] [INFO]-ADPROXY-: Handle unpublish SRP service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.': OK
2024-02-06T12:08:30.981225Z [294.184014700] user.info otbr-agent[2704] [INFO]-ADPROXY-: Waiting for more publishing callbacks 1
2024-02-06T12:08:30.981253Z [294.184042560] user.info otbr-agent[2704] [INFO]-MDNS----: Removing host C6E49A9DDD3EFA11
2024-02-06T12:08:30.981275Z [294.184064260] user.info otbr-agent[2704] [INFO]-MDNS----: Removed host C6E49A9DDD3EFA11
2024-02-06T12:08:30.981296Z [294.184084680] user.info otbr-agent[2704] [INFO]-MDNS----: Releasing avahi entry group @0x1262238
2024-02-06T12:08:30.983621Z [294.186417180] user.info otbr-agent[2704] [INFO]-ADPROXY-: Handle unpublish SRP host 'C6E49A9DDD3EFA11.default.service.arpa.': OK
2024-02-06T12:08:30.983703Z [294.186492700] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Delayed SRP host update result, the SRP update has been committed (updateId = 924676776)
2024-02-06T12:08:30.983731Z [294.186520920] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Fully remove service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.' subtype:_ICD262F6D7C36CCC4
2024-02-06T12:08:30.983753Z [294.186542560] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Fully remove service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.'
2024-02-06T12:08:30.983776Z [294.186565520] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Fully remove service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_L3840
2024-02-06T12:08:30.983798Z [294.186586900] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Fully remove service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_S15
2024-02-06T12:08:30.983819Z [294.186607940] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Fully remove service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_V65521
2024-02-06T12:08:30.983858Z [294.186646940] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Fully remove service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.'
2024-02-06T12:08:30.983881Z [294.186670240] user.info otbr-agent[2704] 00:03:06.643 [I] SrpServer-----: Stop listening on 53535
2024-02-06T12:08:30.983902Z [294.186691480] user.info otbr-agent[2704] 00:03:06.643 [I] NetDataPublshr: DNS/SRP service - State: Added -> NoEntry
2024-02-06T12:08:30.983924Z [294.186713100] user.info otbr-agent[2704] [INFO]-ILS-----: Infra link name eth0 index 2 state changed: UP+RUNNING -> DOWN
2024-02-06T12:08:30.983945Z [294.186733740] user.info otbr-agent[2704] 00:03:06.644 [I] NetworkData---: Sent ServerData
2024-02-06T12:08:30.983966Z [294.186754840] user.info otbr-agent[2704] [INFO]-ILS-----: Evaluating infra link among 2 netifs:
2024-02-06T12:08:30.983987Z [294.186776180] user.info otbr-agent[2704] [INFO]-ILS-----: ^**IInfra link eth0 is in state DOWN**
2024-02-06T12:08:30.984008Z [294.186797500] user.info otbr-agent[2704] [INFO]-ILS-----: ^IInfra link wlan0 is in state UP+RUNNING
2024-02-06T12:08:30.984030Z [294.186818740] user.info otbr-agent[2704] [INFO]-ILS-----: Infra link eth0 was running 0ms ago, wait for 10000ms to recheck.
2024-02-06T12:08:30.984051Z [294.186840300] user.info otbr-agent[2704] [INFO]-ILS-----: Infra link unchanged: eth0
2024-02-06T12:08:30.984072Z [294.186861320] user.info otbr-agent[2704] 00:03:06.644 [I] NetworkData---: Received ServerData
2024-02-06T12:08:30.984093Z [294.186882380] user.info otbr-agent[2704] 00:03:06.644 [I] NetworkData---: Sent ServerData ack
2024-02-06T12:08:30.984114Z [294.186902960] user.info otbr-agent[2704] 00:03:06.644 [I] Notifier------: StateChanged (0x00000200) [NetData]
2024-02-06T12:08:30.984135Z [294.186923660] user.info otbr-agent[2704] 00:03:06.644 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:30.984156Z [294.186944540] user.info otbr-agent[2704] 00:03:06.644 [I] BbrLeader-----: PBBR state: Unchanged
2024-02-06T12:08:30.984176Z [294.186965300] user.info otbr-agent[2704] 00:03:06.644 [I] BbrLeader-----: Rloc16:0xd800, seqno:85, delay:5, timeout:3600
2024-02-06T12:08:30.985405Z [294.188199840] user.info otbr-agent[2704] 00:03:06.645 [I] Platform------: [netif] Sent request#10 to remove fd2c:a1e8:439e:29c6:0:ff:fe00:fc11/64
2024-02-06T12:08:30.985473Z [294.188262520] user.info otbr-agent[2704] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:30.985498Z [294.188287100] user.info otbr-agent[2704] [INFO]-MDNS----: Removing existing service OpenThread BorderRouter #7C11._meshcop._udp: outdated
2024-02-06T12:08:30.985522Z [294.188310960] user.info otbr-agent[2704] [INFO]-MDNS----: Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:30.985543Z [294.188332180] user.info otbr-agent[2704] [INFO]-MDNS----: Releasing avahi entry group @0x125ca28
2024-02-06T12:08:31.000653Z [294.203448500] user.info otbr-agent[2704] [INFO]-MDNS----: Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:31.003039Z [294.205832820] user.info otbr-agent[2704] 00:03:06.663 [I] Notifier------: StateChanged (0x00000002) [Ip6-]
2024-02-06T12:08:31.003111Z [294.205900660] user.info otbr-agent[2704] 00:03:06.663 [I] Platform------: [netif] DEL [U] fd2c:a1e8:439e:29c6:0:ff:fe00:fc11 (not found, ignored)
2024-02-06T12:08:31.003136Z [294.205925340] user.info otbr-agent[2704] 00:03:06.663 [I] Platform------: [netif] Succeeded to process request#10
2024-02-06T12:08:31.010994Z [294.213788620] user.info otbr-agent[2704] 00:03:06.671 [I] MeshForwarder-: Sent IPv6 UDP msg, len:134, chksum:f6ef, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:31.011068Z [294.213858280] user.info otbr-agent[2704] 00:03:06.671 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:31.011094Z [294.213883280] user.info otbr-agent[2704] 00:03:06.671 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:31.032382Z [294.235177220] user.info otbr-agent[2704] 00:03:06.693 [I] MeshForwarder-: Received IPv6 UDP msg, len:134, chksum:e671, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:08:31.032466Z [294.235255920] user.info otbr-agent[2704] 00:03:06.693 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:31.032493Z [294.235282520] user.info otbr-agent[2704] 00:03:06.693 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:31.032515Z [294.235304500] user.info otbr-agent[2704] 00:03:06.693 [I] Mle-----------: Receive Data Response (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:31.824349Z [295.027147320] user.info otbr-agent[2704] [INFO]-MDNS----: Avahi group (@0x125f308) is established
2024-02-06T12:08:31.824442Z [295.027232300] user.info otbr-agent[2704] [INFO]-BA------: Result of publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local: OK
2024-02-06T12:08:34.120746Z [297.323540780] user.info otbr-agent[2704] 00:03:09.781 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:34.127833Z [297.330627240] user.info otbr-agent[2704] 00:03:09.788 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:c4f6, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:34.127904Z [297.330694620] user.info otbr-agent[2704] 00:03:09.788 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:34.127949Z [297.330738540] user.info otbr-agent[2704] 00:03:09.788 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:38.668117Z [301.870913180] user.info otbr-agent[2704] 00:03:14.328 [I] MeshForwarder-: Received IPv6 UDP msg, len:91, chksum:0111, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:08:38.668206Z [301.870996700] user.info otbr-agent[2704] 00:03:14.328 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:38.668240Z [301.871030140] user.info otbr-agent[2704] 00:03:14.328 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:38.668265Z [301.871054620] user.info otbr-agent[2704] 00:03:14.328 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c4e4:9a9d:dd3e:fa11,0x3800)
2024-02-06T12:08:40.983692Z [304.186488220] user.info otbr-agent[2704] [INFO]-ILS-----: Evaluating infra link among 2 netifs:
2024-02-06T12:08:40.983777Z [304.186567140] user.info otbr-agent[2704] [INFO]-ILS-----: ^**IInfra link eth0 is in state DOWN**
2024-02-06T12:08:40.983809Z [304.186599040] user.info otbr-agent[2704] [INFO]-ILS-----: ^**IInfra link wlan0 is in state UP+RUNNING**
2024-02-06T12:08:40.983840Z [304.186629280] user.warning otbr-agent[2704] [WARN]-ILS-----: **Infra link switched from eth0 to wlan0**
2024-02-06T12:08:40.983864Z [304.186653680] user.info otbr-agent[2704] [INFO]-BA------: Stop Thread Border Agent
2024-02-06T12:08:40.983885Z [304.186674820] user.info otbr-agent[2704] [INFO]-ADPROXY-: Stopped
2024-02-06T12:08:40.983907Z [304.186695700] user.info otbr-agent[2704] [INFO]-DPROXY--: Stopped
2024-02-06T12:08:40.983928Z [304.186717580] user.info otbr-agent[2704] [INFO]-BA------: Unpublish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:40.983951Z [304.186739700] user.info otbr-agent[2704] [INFO]-MDNS----: **Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:40.983972Z [304.186760620] user.info otbr-agent[2704] [INFO]-MDNS----: Releasing avahi entry group @0x125f308**
2024-02-06T12:08:40.985794Z [304.188590900] user.info otbr-agent[2704] [INFO]-BA------: Result of unpublish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local: OK
2024-02-06T12:08:40.985875Z [304.188665220] user.info otbr-agent[2704] 00:03:16.646 [I] BbrLocal------: Remove BBR Service: seqno (85), delay (5s), timeout (3600s), OK
2024-02-06T12:08:40.986678Z [304.189471440] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Sent request#11 to remove fd2c:a1e8:439e:29c6:0:ff:fe00:fc38/64
2024-02-06T12:08:40.986742Z [304.189531820] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Sent request#12 to remove fd2c:a1e8:439e:29c6:0:ff:fe00:fc00/64
2024-02-06T12:08:40.986768Z [304.189557720] user.notice otbr-agent[2704] 00:03:16.646 [N] Mle-----------: Role leader -> detached
2024-02-06T12:08:40.986791Z [304.189580300] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Removed multicast address ff02::2
2024-02-06T12:08:40.986813Z [304.189602280] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Removed multicast address ff03::2
2024-02-06T12:08:40.986835Z [304.189624500] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Removed multicast address ff33:40:fd2c:a1e8:439e:29c6:0:1
2024-02-06T12:08:40.986858Z [304.189647140] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Removed multicast address ff32:40:fd2c:a1e8:439e:29c6:0:1
2024-02-06T12:08:40.986880Z [304.189668860] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Sent request#13 to remove fd2c:a1e8:439e:29c6:0:ff:fe00:d800/64
2024-02-06T12:08:40.986902Z [304.189691020] user.info otbr-agent[2704] 00:03:16.646 [I] Platform------: [netif] Sent request#14 to remove fd2c:a1e8:439e:29c6:428f:f75c:340d:d2a8/64
2024-02-06T12:08:40.986925Z [304.189713780] user.notice otbr-agent[2704] 00:03:16.646 [N] Mle-----------: Role detached -> disabled
2024-02-06T12:08:40.986946Z [304.189735160] user.info otbr-agent[2704] 00:03:16.647 [I] DnssdServer---: stopped
2024-02-06T12:08:40.986967Z [304.189756400] user.info otbr-agent[2704] 00:03:16.647 [I] Platform------: [netif] Sent request#15 to remove fe80::a8fc:9096:946c:7c11/64
2024-02-06T12:08:40.986988Z [304.189777460] user.info otbr-agent[2704] 00:03:16.647 [I] Platform------: [netif] Removed multicast address ff02::1
2024-02-06T12:08:40.987009Z [304.189798300] user.info otbr-agent[2704] 00:03:16.647 [I] Platform------: [netif] Removed multicast address ff03::1
2024-02-06T12:08:40.987030Z [304.189819040] user.info otbr-agent[2704] 00:03:16.647 [I] Platform------: [netif] Removed multicast address ff03::fc
2024-02-06T12:08:41.277823Z [304.480619780] daemon.notice kernel systemd[1]: otbr-agent.service: **Main process exited,** code=exited, status=242/NUMA_POLICY
2024-02-06T12:08:41.277901Z [304.480691840] daemon.warning kernel systemd[1]: otbr-agent.service: **Failed with result 'exit-code'.**
2024-02-06T12:08:46.441833Z [309.644630380] daemon.info kernel systemd[1]: otbr-agent.service: Scheduled restart job, restart counter is at 1.
2024-02-06T12:08:46.454707Z [309.657502580] user.notice otbr-agent [NOTE]-AGENT---: Backbone interface: eth0
2024-02-06T12:08:46.454785Z [309.657575900] user.notice otbr-agent [NOTE]-AGENT---: Backbone interface: wlan0
2024-02-06T12:08:46.454817Z [309.657606660] user.notice otbr-agent[7889] [NOTE]-AGENT---: Running 0.3.0-thread-reference-20230710-dirty
2024-02-06T12:08:46.454841Z [309.657629700] user.notice otbr-agent[7889] [NOTE]-AGENT---: Thread version: 1.3.0
2024-02-06T12:08:46.454862Z [309.657650840] user.notice otbr-agent[7889] [NOTE]-AGENT---: Thread interface: wpan0
2024-02-06T12:08:46.454882Z [309.657671480] user.notice otbr-agent[7889] [NOTE]-AGENT---: Radio URL: spinel+hdlc+uart:///dev/ttyAMA1?uart-baudrate=921600/
2024-02-06T12:08:46.454904Z [309.657692740] user.info otbr-agent[7889] [INFO]-ILS-----: Evaluating infra link among 2 netifs:
2024-02-06T12:08:46.454927Z [309.657715740] user.info otbr-agent[7889] [INFO]-ILS-----: ^**IInfra link eth0 is in state DOWN**
2024-02-06T12:08:46.454947Z [309.657736220] user.info otbr-agent[7889] [INFO]-ILS-----: ^IInfra link wlan0 is in state UP+RUNNING
2024-02-06T12:08:46.454968Z [309.657757060] user.notice otbr-agent[7889] [NOTE]-ILS-----: **Infra link selected: wlan0**
2024-02-06T12:08:46.454989Z [309.657777840] user.info otbr-agent[7889] [INFO]-NCP-----: OpenThread log level changed to 4
2024-02-06T12:08:46.457820Z [309.660612520] user.info otbr-agent[7889] 49d.17:07:56.956 [I] Platform------: RCP reset: RESET_POWER_ON
2024-02-06T12:08:46.457858Z [309.660647140] user.info otbr-agent[7889] 49d.17:07:56.956 [I] Platform------: Software reset RCP successfully
2024-02-06T12:08:46.462283Z [309.665075020] user.info otbr-agent[7889] 49d.17:07:56.961 [I] Platform------: Backbone **interface is configured to wlan0 (5)**
2024-02-06T12:08:46.465312Z [309.668104860] user.info otbr-agent[7889] 49d.17:07:56.963 [I] Platform------: [netif] Sent request#1 to set addr_gen_mode to 1
2024-02-06T12:08:46.476974Z [309.679770600] user.info otbr-agent[7889] 00:00:00.011 [I] ChildSupervsn-: Timeout: 0 -> 190
2024-02-06T12:08:46.479038Z [309.681834320] user.info otbr-agent[7889] 00:00:00.014 [I] Settings------: Read NetworkInfo {rloc:0xd800, extaddr:aafc9096946c7c11, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
2024-02-06T12:08:46.479116Z [309.681906400] user.info otbr-agent[7889] 00:00:00.014 [I] Settings------: ... pid:0xa028dcc, mlecntr:0x3ef, maccntr:0x3e8, mliid:428ff75c340dd2a8}
2024-02-06T12:08:46.482423Z [309.685217680] user.info otbr-agent[7889] 00:00:00.018 [I] RoutingManager: Initializing - InfraIfIndex:5
2024-02-06T12:08:46.482489Z [309.685278840] user.info otbr-agent[7889] 00:00:00.018 [I] InfraIf-------: Init infra netif 5
2024-02-06T12:08:46.482515Z [309.685304640] user.info otbr-agent[7889] 00:00:00.018 [I] Settings------: Read BrUlaPrefix fd03:bd42:5612::/48
2024-02-06T12:08:46.482538Z [309.685327300] user.notice otbr-agent[7889] 00:00:00.018 [N] RoutingManager: BR ULA prefix: fd03:bd42:5612::/48 (loaded)
2024-02-06T12:08:46.482560Z [309.685349280] user.info otbr-agent[7889] 00:00:00.018 [I] RoutingManager: Generated local OMR prefix: fd03:bd42:5612:1::/64
2024-02-06T12:08:46.482582Z [309.685371300] user.info otbr-agent[7889] 00:00:00.018 [I] RoutingManager: Restored old prefix fd11:1111:1122:2222::/64, lifetime:1800
2024-02-06T12:08:46.482604Z [309.685393320] user.notice otbr-agent[7889] 00:00:00.018 [N] RoutingManager: Local on-link prefix: fd11:1111:1122:2222::/64
2024-02-06T12:08:46.482625Z [309.685414580] user.info otbr-agent[7889] 00:00:00.018 [I] InfraIf-------: **State changed: NOT RUNNING -> RUNNING**
2024-02-06T12:08:46.482649Z [309.685438500] user.info otbr-agent[7889] 00:00:00.018 [I] RoutingManager: Enabling
2024-02-06T12:08:46.482670Z [309.685459240] user.info otbr-agent[7889] [INFO]-UTILS---: Set state callback: OK
2024-02-06T12:08:46.487621Z [309.690417020] user.info otbr-agent[7889] [INFO]-MDNS----: Avahi client state changed to 2
2024-02-06T12:08:46.487700Z [309.690489280] user.info otbr-agent[7889] [INFO]-MDNS----: Avahi client is ready
2024-02-06T12:08:46.487726Z [309.690515280] user.info otbr-agent[7889] [INFO]-BA------: **Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.**
2024-02-06T12:08:46.487754Z [309.690543200] user.info otbr-agent[7889] 00:00:00.023 [I] Settings------: Read BorderAgentId {id:107e5a17b8bb1937bd1ba77e0301030b}
2024-02-06T12:08:46.490306Z [309.693101260] user.info otbr-agent[7889] [INFO]-MDNS----: **Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp**
2024-02-06T12:08:46.491213Z [309.694006800] user.info otbr-agent[7889] [INFO]-ADPROXY-: Publish all hosts and services
2024-02-06T12:08:46.491268Z [309.694057580] user.info otbr-agent[7889] [INFO]-ADPROXY-: Started
2024-02-06T12:08:46.491307Z [309.694095980] user.info otbr-agent[7889] [INFO]-DPROXY--: Started
2024-02-06T12:08:46.491330Z [309.694118900] user.info otbr-agent[7889] [INFO]-BA------: Start Thread Border Agent: OK
2024-02-06T12:08:46.491352Z [309.694140940] user.info otbr-agent[7889] 00:00:00.027 [I] BbrLocal------: Add Domain Prefix: ::/0, NotFound
2024-02-06T12:08:46.491379Z [309.694167900] user.info otbr-agent[7889] 00:00:00.027 [I] BbrLocal------: Add BBR Service: seqno (12), delay (5s), timeout (3600s), InvalidState
2024-02-06T12:08:46.493861Z [309.696654820] user.info otbr-agent[7889] [INFO]-APP-----: **Thread Border Router started on AIL wlan0.**
2024-02-06T12:08:46.493927Z [309.696717120] user.info otbr-agent[7889] [INFO]-APP-----: Notify systemd the service is ready.
2024-02-06T12:08:46.493997Z [309.696788800] user.info otbr-agent[7889] 00:00:00.029 [I] Notifier------: StateChanged (0x121fc300) [KeySeqCntr NetData Channel PanId NetName ExtPanId NetworkKey PSKc SecPolicy ...
2024-02-06T12:08:46.494033Z [309.696823200] user.info otbr-agent[7889] 00:00:00.029 [I] Notifier------: StateChanged (0x121fc300) ... BbrState ActDset]
2024-02-06T12:08:46.494061Z [309.696849920] user.info otbr-agent[7889] 00:00:00.029 [I] Bbr-----------: Start listening on port 61631
2024-02-06T12:08:46.494083Z [309.696872300] user.info otbr-agent[7889] 00:00:00.029 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd2c:a1e8:439e:29c6:0:3: OK
2024-02-06T12:08:46.494105Z [309.696894580] user.info otbr-agent[7889] 00:00:00.029 [I] BbrManager----: Start Backbone TMF agent: OK
2024-02-06T12:08:46.494127Z [309.696916220] user.info otbr-agent[7889] 00:00:00.029 [I] AnnounceSender: ChannelMask:{ 11-26 }, period:21500
2024-02-06T12:08:46.494149Z [309.696937900] user.info otbr-agent[7889] 00:00:00.029 [I] AnnounceSender: StartingChannel:15
2024-02-06T12:08:46.494170Z [309.696958700] user.info otbr-agent[7889] 00:00:00.029 [I] AnnounceSender: StartingChannel:15
2024-02-06T12:08:46.494191Z [309.696980300] user.info otbr-agent[7889] [INFO]-BA------: **Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.**
2024-02-06T12:08:46.494406Z [309.697198640] user.info otbr-agent[7889] 00:00:00.030 [I] RouterTable---: Route table
2024-02-06T12:08:46.495368Z [309.698160480] user.info otbr-agent[7889] 00:00:00.031 [I] Platform------: [netif] Host netif is down
2024-02-06T12:08:46.496422Z [309.699213900] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Added multicast address ff02::1
2024-02-06T12:08:46.496460Z [309.699249640] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Added multicast address ff03::1
2024-02-06T12:08:46.496483Z [309.699272020] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Added multicast address ff03::fc
2024-02-06T12:08:46.496860Z [309.699652300] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Sent request#2 to add fe80::a8fc:9096:946c:7c11/64
2024-02-06T12:08:46.496901Z [309.699689920] user.info otbr-agent[7889] 00:00:00.032 [I] DnssdServer---: started: OK
2024-02-06T12:08:46.497016Z [309.699805840] user.info otbr-agent[7889] 00:00:00.032 [I] BbrLocal------: Remove BBR Service: seqno (12), delay (5s), timeout (3600s), NotFound
2024-02-06T12:08:46.497046Z [309.699835600] user.notice otbr-agent[7889] 00:00:00.032 [N] Mle-----------: Role disabled -> detached
2024-02-06T12:08:46.497071Z [309.699860420] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Sent request#3 to add fd2c:a1e8:439e:29c6:428f:f75c:340d:d2a8/64
2024-02-06T12:08:46.497093Z [309.699882440] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Added multicast address ff32:40:fd2c:a1e8:439e:29c6:0:1
2024-02-06T12:08:46.497120Z [309.699908640] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Added multicast address ff33:40:fd2c:a1e8:439e:29c6:0:1
2024-02-06T12:08:46.497141Z [309.699930600] user.info otbr-agent[7889] 00:00:00.032 [I] Bbr-----------: Backbone TMF unsubscribes ff32:40:fd2c:a1e8:439e:29c6:0:3: OK
2024-02-06T12:08:46.497177Z [309.699966320] user.info otbr-agent[7889] 00:00:00.032 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd2c:a1e8:439e:29c6:0:3: OK
2024-02-06T12:08:46.497199Z [309.699988560] user.info otbr-agent[7889] 00:00:00.032 [I] Platform------: [netif] Sent request#4 to add fd2c:a1e8:439e:29c6:0:ff:fe00:d800/64
2024-02-06T12:08:46.497222Z [309.700010720] user.info otbr-agent[7889] 00:00:00.032 [I] Mle-----------: Attempt to become router
2024-02-06T12:08:46.497244Z [309.700032740] user.info otbr-agent[7889] 00:00:00.032 [I] Settings------: Read NetworkInfo {rloc:0xd800, extaddr:aafc9096946c7c11, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
2024-02-06T12:08:46.497266Z [309.700054880] user.info otbr-agent[7889] 00:00:00.032 [I] Settings------: ... pid:0xa028dcc, mlecntr:0x3ef, maccntr:0x3e8, mliid:428ff75c340dd2a8}
2024-02-06T12:08:46.502373Z [309.705168740] user.info otbr-agent[7889] 00:00:00.038 [I] Settings------: Saved NetworkInfo {rloc:0xd800, extaddr:aafc9096946c7c11, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
2024-02-06T12:08:46.502449Z [309.705238900] user.info otbr-agent[7889] 00:00:00.038 [I] Settings------: ... pid:0xa028dcc, mlecntr:0x7d8, maccntr:0x7d0, mliid:428ff75c340dd2a8}
2024-02-06T12:08:46.502474Z [309.705263260] user.info otbr-agent[7889] 00:00:00.038 [I] Mle-----------: Send Link Request (ff02:0:0:0:0:0:0:2)
2024-02-06T12:08:46.502701Z [309.705492120] user.info otbr-agent[7889] 00:00:00.038 [I] Notifier------: StateChanged (0x0100103d) [Ip6+ Role LLAddr MLAddr Rloc+ Ip6Mult+ NetifState]
2024-02-06T12:08:46.502734Z [309.705523220] user.info otbr-agent[7889] 00:00:00.038 [I] AnnounceSender: Stopped
2024-02-06T12:08:46.502756Z [309.705545100] user.notice otbr-agent[7889] 00:00:00.038 [N] Platform------: [netif] Changing interface state to up.
2024-02-06T12:08:46.503460Z [309.706252840] user.info otbr-agent[7889] [INFO]-BA------: Thread is down
2024-02-06T12:08:46.503511Z [309.706300900] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:46.503601Z [309.706390620] user.info otbr-agent[7889] [INFO]-MDNS----: Removing existing service OpenThread BorderRouter #7C11._meshcop._udp: outdated
2024-02-06T12:08:46.503623Z [309.706412000] user.info otbr-agent[7889] [INFO]-MDNS----: Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:46.503644Z [309.706433040] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:46.503666Z [309.706455140] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:46.503708Z [309.706496740] user.info otbr-agent[7889] [INFO]-MDNS----: Releasing avahi entry group @0x2346e38
2024-02-06T12:08:46.507870Z [309.710665640] user.info otbr-agent[7889] [INFO]-MDNS----: **Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp**
2024-02-06T12:08:46.509500Z [309.712294880] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] Succeeded to process request#1
2024-02-06T12:08:46.509799Z [309.712591520] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] ADD [U] fe80:0:0:0:a8fc:9096:946c:7c11 (already subscribed, ignored)
2024-02-06T12:08:46.509908Z [309.712698060] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] Succeeded to process request#2
2024-02-06T12:08:46.510034Z [309.712823580] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] Succeeded to process request#3
2024-02-06T12:08:46.510094Z [309.712883780] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] Succeeded to process request#4
2024-02-06T12:08:46.510128Z [309.712917640] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] ADD [U] fd2c:a1e8:439e:29c6:428f:f75c:340d:d2a8 (already subscribed, ignored)
2024-02-06T12:08:46.510156Z [309.712945440] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] ADD [U] fd2c:a1e8:439e:29c6:0:ff:fe00:d800 (already subscribed, ignored)
2024-02-06T12:08:46.510179Z [309.712967740] user.info otbr-agent[7889] 00:00:00.045 [I] Platform------: [netif] Host netif is up
2024-02-06T12:08:46.517419Z [309.720215240] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:46.517506Z [309.720296160] user.info otbr-agent[7889] 00:00:00.053 [I] MeshForwarder-: Sent IPv6 UDP msg, len:82, chksum:2709, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:46.517533Z [309.720322660] user.info otbr-agent[7889] 00:00:00.053 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:46.517555Z [309.720344560] user.info otbr-agent[7889] 00:00:00.053 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:2]:19788
2024-02-06T12:08:46.517961Z [309.720763280] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.518023Z [309.720812600] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.518052Z [309.720841300] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:46.518074Z [309.720863220] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.518095Z [309.720884160] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16
2024-02-06T12:08:46.518123Z [309.720912060] user.info otbr-agent[7889] 00:00:00.053 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (rejected)
2024-02-06T12:08:46.518144Z [309.720933020] user.info otbr-agent[7889] 00:00:00.053 [I] Notifier------: StateChanged (0x00001000) [Ip6Mult+]
2024-02-06T12:08:46.721399Z [309.924194900] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:46.721849Z [309.924643240] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.721911Z [309.924701160] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.721935Z [309.924724260] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:46.721956Z [309.924745580] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.721977Z [309.924766200] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:46.721999Z [309.924787600] user.info otbr-agent[7889] 00:00:00.257 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (rejected)
2024-02-06T12:08:46.973403Z [310.176199420] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:46.973662Z [310.176453840] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.973700Z [310.176489080] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.973734Z [310.176523700] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:46.973758Z [310.176546660] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:46.973779Z [310.176568220] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:46.973800Z [310.176588660] user.info otbr-agent[7889] 00:00:00.509 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (rejected)
2024-02-06T12:08:47.198683Z [310.401478900] user.info otbr-agent[7889] 00:00:00.734 [I] MeshForwarder-: Received IPv6 UDP msg, len:124, chksum:6083, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:08:47.198766Z [310.401556180] user.info otbr-agent[7889] 00:00:00.734 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:47.198792Z [310.401581700] user.info otbr-agent[7889] 00:00:00.734 [I] MeshForwarder-:     dst:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.198814Z [310.401603220] user.info otbr-agent[7889] 00:00:00.734 [I] Mle-----------: Receive Link Accept (fe80:0:0:0:c4e4:9a9d:dd3e:fa11,0x3800)
2024-02-06T12:08:47.198835Z [310.401624120] user.notice otbr-agent[7889] 00:00:00.734 [N] Mle-----------: Role detached -> leader
2024-02-06T12:08:47.198857Z [310.401645540] user.info otbr-agent[7889] 00:00:00.734 [I] Platform------: [netif] Added multicast address ff02::2
2024-02-06T12:08:47.198877Z [310.401666380] user.info otbr-agent[7889] 00:00:00.734 [I] Platform------: [netif] Added multicast address ff03::2
2024-02-06T12:08:47.198917Z [310.401706480] user.info otbr-agent[7889] 00:00:00.734 [I] Platform------: [netif] Sent request#5 to add fd2c:a1e8:439e:29c6:0:ff:fe00:fc00/64
2024-02-06T12:08:47.198942Z [310.401731180] user.notice otbr-agent[7889] 00:00:00.734 [N] Mle-----------: Partition ID 0xa028dcc
2024-02-06T12:08:47.198965Z [310.401754040] user.info otbr-agent[7889] 00:00:00.734 [I] Mle-----------: Send Data Request (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:47.199004Z [310.401793240] user.info otbr-agent[7889] 00:00:00.734 [I] RouterTable---: Route table
2024-02-06T12:08:47.199027Z [310.401816200] user.info otbr-agent[7889] 00:00:00.734 [I] RouterTable---:     14 0x3800 - nbr{lq[i/o]:3/3 cost:1}
2024-02-06T12:08:47.199049Z [310.401838400] user.info otbr-agent[7889] 00:00:00.734 [I] RouterTable---:     54 0xd800 - me - leader
2024-02-06T12:08:47.199071Z [310.401860160] user.info otbr-agent[7889] 00:00:00.734 [I] Notifier------: StateChanged (0x10001085) [Ip6+ Role PartitionId Ip6Mult+ ActDset]
2024-02-06T12:08:47.203372Z [310.406165800] user.info otbr-agent[7889] 00:00:00.739 [I] Settings------: Saved NetworkInfo {rloc:0xd800, extaddr:aafc9096946c7c11, role:leader, mode:0x0f, version:4, keyseq:0x0, ...
2024-02-06T12:08:47.203436Z [310.406225580] user.info otbr-agent[7889] 00:00:00.739 [I] Settings------: ... pid:0xa028dcc, mlecntr:0x7d9, maccntr:0x7d0, mliid:428ff75c340dd2a8}
2024-02-06T12:08:47.203463Z [310.406251960] user.info otbr-agent[7889] 00:00:00.739 [I] AnnounceSender: Started
2024-02-06T12:08:47.203485Z [310.406274440] user.info otbr-agent[7889] 00:00:00.739 [I] BorderAgent---: Border Agent start listening on port 49154
2024-02-06T12:08:47.203506Z [310.406295520] user.info otbr-agent[7889] 00:00:00.739 [I] RoutingManager: RIO Preference changed: low -> medium
2024-02-06T12:08:47.203539Z [310.406328720] user.info otbr-agent[7889] 00:00:00.739 [I] RoutingManager: Starting
2024-02-06T12:08:47.203561Z [310.406350480] user.info otbr-agent[7889] 00:00:00.739 [I] RoutingManager: RoutePublisher state: none -> ula
2024-02-06T12:08:47.203583Z [310.406371760] user.info otbr-agent[7889] 00:00:00.739 [I] NetDataPublshr: Publishing ExternalRoute fc00::/7
2024-02-06T12:08:47.203604Z [310.406392700] user.info otbr-agent[7889] 00:00:00.739 [I] NetDataPublshr: ExternalRoute fc00::/7 - State: NoEntry -> ToAdd
2024-02-06T12:08:47.203625Z [310.406413680] user.info otbr-agent[7889] 00:00:00.739 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:ToAdd) in netdata - total:0, preferred:0, desired:10
2024-02-06T12:08:47.203647Z [310.406435900] user.info otbr-agent[7889] 00:00:00.739 [I] NetDataPublshr: ExternalRoute fc00::/7 - State: ToAdd -> Adding
2024-02-06T12:08:47.203668Z [310.406456940] user.info otbr-agent[7889] 00:00:00.739 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) - update in 381 msec
2024-02-06T12:08:47.203690Z [310.406478680] user.info otbr-agent[7889] 00:00:00.739 [I] RoutingManager: RsSender: Starting - will send first RS in 406 msec
2024-02-06T12:08:47.203711Z [310.406499680] user.info otbr-agent[7889] 00:00:00.739 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) in netdata - total:0, preferred:0, desired:10
2024-02-06T12:08:47.203731Z [310.406520520] user.info otbr-agent[7889] [INFO]-BA------: Thread is up
2024-02-06T12:08:47.203752Z [310.406541520] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:47.203781Z [310.406570460] user.info otbr-agent[7889] [INFO]-MDNS----: Removing existing service OpenThread BorderRouter #7C11._meshcop._udp: outdated
2024-02-06T12:08:47.203803Z [310.406591880] user.info otbr-agent[7889] [INFO]-MDNS----: Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:47.203825Z [310.406613980] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:47.203846Z [310.406634880] user.info otbr-agent[7889] [INFO]-MDNS----: Releasing avahi entry group @0x23483c0
2024-02-06T12:08:47.208339Z [310.411135300] user.info otbr-agent[7889] [INFO]-MDNS----: Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:47.209709Z [310.412515500] user.info otbr-agent[7889] 00:00:00.745 [I] Platform------: [netif] Succeeded to process request#5
2024-02-06T12:08:47.209899Z [310.412689500] user.info otbr-agent[7889] 00:00:00.745 [I] Platform------: [netif] ADD [U] fd2c:a1e8:439e:29c6:0:ff:fe00:fc00 (already subscribed, ignored)
2024-02-06T12:08:47.213339Z [310.416130680] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:47.213466Z [310.416255620] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:47.213492Z [310.416281420] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.213514Z [310.416303680] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.213536Z [310.416324960] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:47.213558Z [310.416347000] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.213582Z [310.416370960] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:47.213604Z [310.416392920] user.info otbr-agent[7889] 00:00:00.749 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:47.216493Z [310.419284860] user.info otbr-agent[7889] 00:00:00.752 [I] MeshForwarder-: Sent IPv6 UDP msg, len:77, chksum:7d35, ecn:no, to:c6e49a9ddd3efa11, sec:no, prio:net
2024-02-06T12:08:47.216531Z [310.419320480] user.info otbr-agent[7889] 00:00:00.752 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.216554Z [310.419343220] user.info otbr-agent[7889] 00:00:00.752 [I] MeshForwarder-:     dst:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:47.227034Z [310.429827900] user.info otbr-agent[7889] 00:00:00.762 [I] MeshForwarder-: Received IPv6 UDP msg, len:134, chksum:383f, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:08:47.227079Z [310.429868980] user.info otbr-agent[7889] 00:00:00.762 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:47.227103Z [310.429891900] user.info otbr-agent[7889] 00:00:00.762 [I] MeshForwarder-:     dst:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.227124Z [310.429913220] user.info otbr-agent[7889] 00:00:00.762 [I] Mle-----------: Receive Data Response (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:47.227145Z [310.429934140] user.info otbr-agent[7889] 00:00:00.762 [I] Notifier------: StateChanged (0x00000200) [NetData]
2024-02-06T12:08:47.227166Z [310.429955160] user.info otbr-agent[7889] 00:00:00.762 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:47.227187Z [310.429976560] user.info otbr-agent[7889] 00:00:00.762 [I] BbrLeader-----: PBBR state: Added
2024-02-06T12:08:47.227209Z [310.429997820] user.info otbr-agent[7889] 00:00:00.762 [I] BbrLeader-----: Rloc16:0xd800, seqno:85, delay:5, timeout:3600
2024-02-06T12:08:47.227230Z [310.430018940] user.info otbr-agent[7889] 00:00:00.762 [I] BbrLocal------: Add BBR Service: seqno (86), delay (5s), timeout (3600s), OK
2024-02-06T12:08:47.227467Z [310.430256400] user.info otbr-agent[7889] 00:00:00.763 [I] Platform------: [netif] Sent request#6 to add fd2c:a1e8:439e:29c6:0:ff:fe00:fc10/64
2024-02-06T12:08:47.227503Z [310.430292360] user.info otbr-agent[7889] 00:00:00.763 [I] NetworkData---: Sent ServerData
2024-02-06T12:08:47.227526Z [310.430315460] user.info otbr-agent[7889] 00:00:00.763 [I] Settings------: Read SlaacIidSecretKey
2024-02-06T12:08:47.227548Z [310.430337220] user.info otbr-agent[7889] 00:00:00.763 [I] Slaac---------: Adding address fd11:22:0:0:95e8:6419:fd15:2259
2024-02-06T12:08:47.227640Z [310.430429020] user.info otbr-agent[7889] 00:00:00.763 [I] Platform------: [netif] Sent request#7 to add fd11:22::95e8:6419:fd15:2259/64
2024-02-06T12:08:47.227663Z [310.430452040] user.info otbr-agent[7889] 00:00:00.763 [I] RoutingManager: Will evaluate routing policy in 00:02.676 (2676 msec)
2024-02-06T12:08:47.227685Z [310.430473540] user.info otbr-agent[7889] 00:00:00.763 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) in netdata - total:0, preferred:0, desired:10
2024-02-06T12:08:47.227726Z [310.430515380] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:47.227933Z [310.430724820] user.info otbr-agent[7889] [INFO]-MDNS----: Removing existing service OpenThread BorderRouter #7C11._meshcop._udp: outdated
2024-02-06T12:08:47.227965Z [310.430754860] user.info otbr-agent[7889] [INFO]-MDNS----: Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:47.228018Z [310.430807820] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:47.228044Z [310.430832980] user.info otbr-agent[7889] [INFO]-MDNS----: Releasing avahi entry group @0x234d660
2024-02-06T12:08:47.231989Z [310.434782020] user.info otbr-agent[7889] [INFO]-MDNS----: Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:47.232947Z [310.435766820] user.info otbr-agent[7889] 00:00:00.768 [I] NetworkData---: Received ServerData
2024-02-06T12:08:47.233061Z [310.435852540] user.info otbr-agent[7889] 00:00:00.768 [I] NetworkData---: Allocated Service ID = 0
2024-02-06T12:08:47.233092Z [310.435881940] user.info otbr-agent[7889] 00:00:00.768 [I] NetworkData---: Sent ServerData ack
2024-02-06T12:08:47.233117Z [310.435906520] user.info otbr-agent[7889] 00:00:00.768 [I] Notifier------: StateChanged (0x04000201) [Ip6+ NetData BbrLocal]
2024-02-06T12:08:47.233138Z [310.435927380] user.info otbr-agent[7889] 00:00:00.768 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:47.233159Z [310.435947940] user.info otbr-agent[7889] 00:00:00.768 [I] BbrLeader-----: PBBR state: Rereg triggered
2024-02-06T12:08:47.233185Z [310.435973940] user.info otbr-agent[7889] 00:00:00.768 [I] BbrLeader-----: Rloc16:0xd800, seqno:86, delay:5, timeout:3600
2024-02-06T12:08:47.233536Z [310.436328940] user.info otbr-agent[7889] 00:00:00.769 [I] Platform------: [netif] Sent request#8 to add fd2c:a1e8:439e:29c6:0:ff:fe00:fc38/64
2024-02-06T12:08:47.233581Z [310.436370840] user.info otbr-agent[7889] 00:00:00.769 [I] Slaac---------: Removing address fd11:22:0:0:95e8:6419:fd15:2259
2024-02-06T12:08:47.233628Z [310.436417020] user.info otbr-agent[7889] 00:00:00.769 [I] Platform------: [netif] Sent request#9 to remove fd11:22::95e8:6419:fd15:2259/64
2024-02-06T12:08:47.233650Z [310.436438800] user.info otbr-agent[7889] 00:00:00.769 [I] RoutingManager: Will evaluate routing policy in 00:02.112 (2112 msec)
2024-02-06T12:08:47.233692Z [310.436481500] user.info otbr-agent[7889] 00:00:00.769 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Adding) in netdata - total:0, preferred:0, desired:10
2024-02-06T12:08:47.233733Z [310.436522060] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:47.233779Z [310.436568200] user.info otbr-agent[7889] [INFO]-MDNS----: Removing existing service OpenThread BorderRouter #7C11._meshcop._udp: outdated
2024-02-06T12:08:47.233800Z [310.436589500] user.info otbr-agent[7889] [INFO]-MDNS----: Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:47.233824Z [310.436613280] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:47.233846Z [310.436634700] user.info otbr-agent[7889] [INFO]-MDNS----: Releasing avahi entry group @0x23470f8
2024-02-06T12:08:47.237863Z [310.440657520] user.info otbr-agent[7889] [INFO]-MDNS----: Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:47.239020Z [310.441813620] user.info otbr-agent[7889] 00:00:00.774 [I] Platform------: [netif] ADD [U] fd2c:a1e8:439e:29c6:0:ff:fe00:fc10 (already subscribed, ignored)
2024-02-06T12:08:47.239099Z [310.441889660] user.info otbr-agent[7889] 00:00:00.774 [I] Notifier------: StateChanged (0x02000003) [Ip6+ Ip6- BbrState]
2024-02-06T12:08:47.239129Z [310.441918260] user.info otbr-agent[7889] 00:00:00.774 [I] Bbr-----------: Start listening on port 61631
2024-02-06T12:08:47.239151Z [310.441939820] user.info otbr-agent[7889] 00:00:00.774 [I] Bbr-----------: Backbone TMF subscribes ff32:40:fd2c:a1e8:439e:29c6:0:3: OK
2024-02-06T12:08:47.239185Z [310.441974060] user.info otbr-agent[7889] 00:00:00.774 [I] BbrManager----: Start Backbone TMF agent: OK
2024-02-06T12:08:47.239207Z [310.441996460] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:47.239229Z [310.442018060] user.notice otbr-agent[7889] [NOTE]-BBA-----: BackboneAgent: Backbone Router becomes Primary!
2024-02-06T12:08:47.239342Z [310.442131640] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] Succeeded to process request#6
2024-02-06T12:08:47.239538Z [310.442327860] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] Succeeded to process request#7
2024-02-06T12:08:47.239679Z [310.442468380] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] ADD [U] fd11:22:0:0:95e8:6419:fd15:2259
2024-02-06T12:08:47.239702Z [310.442490860] user.info otbr-agent[7889] 00:00:00.775 [I] Notifier------: StateChanged (0x00000001) [Ip6+]
2024-02-06T12:08:47.239724Z [310.442512580] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] ADD [U] fd2c:a1e8:439e:29c6:0:ff:fe00:fc38 (already subscribed, ignored)
2024-02-06T12:08:47.239746Z [310.442535060] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] Succeeded to process request#8
2024-02-06T12:08:47.239778Z [310.442567280] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] DEL [U] fd11:22:0:0:95e8:6419:fd15:2259
2024-02-06T12:08:47.239801Z [310.442589560] user.info otbr-agent[7889] 00:00:00.775 [I] Notifier------: StateChanged (0x00000002) [Ip6-]
2024-02-06T12:08:47.239822Z [310.442610680] user.info otbr-agent[7889] 00:00:00.775 [I] Platform------: [netif] Succeeded to process request#9
2024-02-06T12:08:47.241323Z [310.444112440] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:47.241428Z [310.444217460] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:47.241452Z [310.444240720] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.241473Z [310.444261940] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.241495Z [310.444283960] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:47.241517Z [310.444306080] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.241538Z [310.444327160] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:47.241559Z [310.444348020] user.info otbr-agent[7889] 00:00:00.777 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:47.247952Z [310.450744460] user.info otbr-agent[7889] 00:00:00.783 [I] MeshForwarder-: Sent IPv6 UDP msg, len:134, chksum:9dd8, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:47.247997Z [310.450786520] user.info otbr-agent[7889] 00:00:00.783 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.248020Z [310.450809740] user.info otbr-agent[7889] 00:00:00.783 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:47.256634Z [310.459427260] user.info otbr-agent[7889] 00:00:00.792 [I] MeshForwarder-: Sent IPv6 UDP msg, len:128, chksum:7cca, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:47.256680Z [310.459469400] user.info otbr-agent[7889] 00:00:00.792 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.256703Z [310.459492560] user.info otbr-agent[7889] 00:00:00.792 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:47.360226Z [310.563022420] user.info otbr-agent[7889] 00:00:00.895 [I] MeshForwarder-: Received IPv6 UDP msg, len:128, chksum:fcff, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:08:47.360312Z [310.563101340] user.info otbr-agent[7889] 00:00:00.895 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:47.360337Z [310.563125880] user.info otbr-agent[7889] 00:00:00.895 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:47.360358Z [310.563147000] user.info otbr-agent[7889] 00:00:00.896 [I] Mle-----------: Receive Data Response (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:47.584453Z [310.787248820] user.info otbr-agent[7889] 00:00:01.120 [I] NetDataPublshr: ExternalRoute fc00::/7 - State: Adding -> Added
2024-02-06T12:08:47.584540Z [310.787329760] user.info otbr-agent[7889] 00:00:01.120 [I] NetworkData---: Sent ServerData
2024-02-06T12:08:47.584566Z [310.787355940] user.info otbr-agent[7889] 00:00:01.120 [I] NetworkData---: Received ServerData
2024-02-06T12:08:47.584589Z [310.787378300] user.info otbr-agent[7889] 00:00:01.120 [I] NetworkData---: Sent ServerData ack
2024-02-06T12:08:47.584610Z [310.787399420] user.info otbr-agent[7889] 00:00:01.120 [I] Notifier------: StateChanged (0x00000200) [NetData]
2024-02-06T12:08:47.584631Z [310.787420500] user.info otbr-agent[7889] 00:00:01.120 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:47.584652Z [310.787441140] user.info otbr-agent[7889] 00:00:01.120 [I] BbrLeader-----: PBBR state: Unchanged
2024-02-06T12:08:47.584673Z [310.787462100] user.info otbr-agent[7889] 00:00:01.120 [I] BbrLeader-----: Rloc16:0xd800, seqno:86, delay:5, timeout:3600
2024-02-06T12:08:47.584694Z [310.787482660] user.info otbr-agent[7889] 00:00:01.120 [I] RoutingManager: Will evaluate routing policy in 00:03.005 (3005 msec)
2024-02-06T12:08:47.584715Z [310.787503740] user.info otbr-agent[7889] 00:00:01.120 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Added) in netdata - total:1, preferred:0, desired:10
2024-02-06T12:08:47.584735Z [310.787524180] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:47.593833Z [310.796625820] user.info otbr-agent[7889] 00:00:01.129 [I] MeshForwarder-: Sent IPv6 UDP msg, len:138, chksum:85a9, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:47.593890Z [310.796679920] user.info otbr-agent[7889] 00:00:01.129 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.593914Z [310.796703240] user.info otbr-agent[7889] 00:00:01.129 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:47.609456Z [310.812249660] user.info otbr-agent[7889] 00:00:01.145 [I] RoutingManager: RsSender: Sent RS 1/3
2024-02-06T12:08:47.609518Z [310.812307660] user.info otbr-agent[7889] 00:00:01.145 [I] RoutingManager: Received RS from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:47.609543Z [310.812331680] user.info otbr-agent[7889] 00:00:01.145 [I] RoutingManager: Will evaluate routing policy in 00:00.497 (497 msec)
2024-02-06T12:08:47.759504Z [310.962299780] user.info otbr-agent[7889] 00:00:01.295 [I] DuaManager----: PerformNextRegistration: NotFound
2024-02-06T12:08:47.888480Z [311.091275760] user.info otbr-agent[7889] 00:00:01.424 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:47.895325Z [311.098119340] user.info otbr-agent[7889] 00:00:01.431 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:f0fc, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:47.895390Z [311.098180200] user.info otbr-agent[7889] 00:00:01.431 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:47.895417Z [311.098206080] user.info otbr-agent[7889] 00:00:01.431 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:47.897333Z [311.100122260] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:47.897498Z [311.100287880] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:47.897539Z [311.100328220] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.897562Z [311.100350960] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.897591Z [311.100380580] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:47.897613Z [311.100401960] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:47.897634Z [311.100423500] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:47.897656Z [311.100445260] user.info otbr-agent[7889] 00:00:01.433 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:47.951610Z [311.154405580] user.info otbr-agent[7889] 00:00:01.487 [I] MeshForwarder-: Received IPv6 UDP msg, len:138, chksum:398b, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:08:47.951687Z [311.154476620] user.info otbr-agent[7889] 00:00:01.487 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:47.951712Z [311.154501120] user.info otbr-agent[7889] 00:00:01.487 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:47.951734Z [311.154522860] user.info otbr-agent[7889] 00:00:01.487 [I] Mle-----------: Receive Data Response (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:48.106513Z [311.309308720] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Evaluating routing policy
2024-02-06T12:08:48.106603Z [311.309393380] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Setting local OMR prefix to generated prefix: fd03:bd42:5612:1::/64
2024-02-06T12:08:48.106644Z [311.309432980] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: No favored OMR prefix found in Thread network.
2024-02-06T12:08:48.106667Z [311.309456420] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Added local OMR prefix fd03:bd42:5612:1::/64 (def-route:no) in Thread Network Data
2024-02-06T12:08:48.106688Z [311.309477500] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Preparing RA
2024-02-06T12:08:48.106710Z [311.309498800] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1798, preferred:0)
2024-02-06T12:08:48.106731Z [311.309519900] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: - RIO fd03:bd42:5612:1::/64 (lifetime:1800, prf:medium)
2024-02-06T12:08:48.107103Z [311.309895280] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Sent RA on infra netif 5
2024-02-06T12:08:48.107156Z [311.309945300] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Will evaluate routing policy in 00:16.000 (16000 msec)
2024-02-06T12:08:48.107181Z [311.309969960] user.info otbr-agent[7889] 00:00:01.642 [I] NetworkData---: Sent ServerData
2024-02-06T12:08:48.107203Z [311.309992500] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: Received RA from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:48.107226Z [311.310015400] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: - RA Header - default route - lifetime:0
2024-02-06T12:08:48.107249Z [311.310037580] user.info otbr-agent[7889] 00:00:01.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1798, preferred:0)
2024-02-06T12:08:48.107375Z [311.310164540] user.info otbr-agent[7889] 00:00:01.643 [I] NetworkData---: Received ServerData
2024-02-06T12:08:48.107400Z [311.310189000] user.info otbr-agent[7889] 00:00:01.643 [I] NetworkData---: Sent ServerData ack
2024-02-06T12:08:48.107520Z [311.310309080] user.info otbr-agent[7889] 00:00:01.643 [I] Notifier------: StateChanged (0x00000200) [NetData]
2024-02-06T12:08:48.107552Z [311.310341420] user.info otbr-agent[7889] 00:00:01.643 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:48.107574Z [311.310363340] user.info otbr-agent[7889] 00:00:01.643 [I] BbrLeader-----: PBBR state: Unchanged
2024-02-06T12:08:48.107596Z [311.310384720] user.info otbr-agent[7889] 00:00:01.643 [I] BbrLeader-----: Rloc16:0xd800, seqno:86, delay:5, timeout:3600
2024-02-06T12:08:48.107618Z [311.310407020] user.info otbr-agent[7889] 00:00:01.643 [I] Settings------: Read SlaacIidSecretKey
2024-02-06T12:08:48.107639Z [311.310427660] user.info otbr-agent[7889] 00:00:01.643 [I] Slaac---------: Adding address fd03:bd42:5612:1:f8b1:e060:736f:5304
2024-02-06T12:08:48.107989Z [311.310778520] user.info otbr-agent[7889] 00:00:01.643 [I] Platform------: [netif] Sent request#10 to add fd03:bd42:5612:1:f8b1:e060:736f:5304/64
2024-02-06T12:08:48.108011Z [311.310800400] user.info otbr-agent[7889] 00:00:01.643 [I] RoutingManager: Will evaluate routing policy in 00:02.999 (2999 msec)
2024-02-06T12:08:48.108034Z [311.310823040] user.info otbr-agent[7889] 00:00:01.643 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Added) in netdata - total:1, preferred:0, desired:10
2024-02-06T12:08:48.108057Z [311.310845680] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:48.108077Z [311.310866440] user.info otbr-agent[7889] [INFO]-MDNS----: Removing existing service OpenThread BorderRouter #7C11._meshcop._udp: outdated
2024-02-06T12:08:48.108098Z [311.310887380] user.info otbr-agent[7889] [INFO]-MDNS----: Removing service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:48.108119Z [311.310908080] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:48.108140Z [311.310928900] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:48.108169Z [311.310957840] user.info otbr-agent[7889] [INFO]-BA------: Cancelled previous publishing meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local
2024-02-06T12:08:48.108189Z [311.310978480] user.info otbr-agent[7889] [INFO]-MDNS----: Releasing avahi entry group @0x23470f8
2024-02-06T12:08:48.112432Z [311.315227220] user.info otbr-agent[7889] [INFO]-MDNS----: Commit avahi service OpenThread BorderRouter #7C11._meshcop._udp
2024-02-06T12:08:48.113448Z [311.316241800] user.info otbr-agent[7889] 00:00:01.648 [I] Notifier------: StateChanged (0x00000001) [Ip6+]
2024-02-06T12:08:48.113518Z [311.316308200] user.info otbr-agent[7889] 00:00:01.649 [I] Platform------: [netif] ADD [U] fd03:bd42:5612:1:f8b1:e060:736f:5304 (already subscribed, ignored)
2024-02-06T12:08:48.113614Z [311.316404040] user.info otbr-agent[7889] 00:00:01.649 [I] Platform------: [netif] Succeeded to process request#10
2024-02-06T12:08:48.117333Z [311.320125440] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:48.117483Z [311.320272380] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:48.117508Z [311.320296960] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:48.117531Z [311.320320160] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:48.117553Z [311.320342220] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:48.117585Z [311.320374520] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:48.117607Z [311.320396660] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:48.117628Z [311.320417220] user.info otbr-agent[7889] 00:00:01.653 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:48.141890Z [311.344684980] user.info otbr-agent[7889] 00:00:01.677 [I] MeshForwarder-: Sent IPv6 UDP msg, len:160, chksum:45a6, ecn:no, to:0xffff, sec:yes, prio:net
2024-02-06T12:08:48.141961Z [311.344751260] user.info otbr-agent[7889] 00:00:01.677 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:48.141986Z [311.344774880] user.info otbr-agent[7889] 00:00:01.677 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:48.197396Z [311.400192160] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:48.197534Z [311.400323880] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:48.197563Z [311.400351860] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:48.197585Z [311.400374560] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:48.197606Z [311.400395600] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:48.197627Z [311.400416600] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:48.197649Z [311.400438160] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:48.197670Z [311.400459500] user.info otbr-agent[7889] 00:00:01.733 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:48.649842Z [311.852639720] user.info otbr-agent[7889] 00:00:02.185 [I] MeshForwarder-: Received IPv6 UDP msg, len:160, chksum:64c0, ecn:no, from:c6e49a9ddd3efa11, sec:yes, prio:net, rss:-41.0
2024-02-06T12:08:48.649971Z [311.852762400] user.info otbr-agent[7889] 00:00:02.185 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:48.650009Z [311.852798260] user.info otbr-agent[7889] 00:00:02.185 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:48.650034Z [311.852823060] user.info otbr-agent[7889] 00:00:02.185 [I] Mle-----------: Receive Data Response (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:48.758567Z [311.961366060] user.info otbr-agent[7889] 00:00:02.294 [I] DuaManager----: PerformNextRegistration: NotFound
2024-02-06T12:08:49.061003Z [312.263799420] user.info otbr-agent[7889] [INFO]-MDNS----: Avahi group (@0x234d6b8) is established
2024-02-06T12:08:49.061092Z [312.263883560] user.info otbr-agent[7889] [INFO]-BA------: Result of publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local: OK
2024-02-06T12:08:49.912529Z [313.115323040] user.info otbr-agent[7889] 00:00:03.448 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:49.919044Z [313.121836840] user.info otbr-agent[7889] 00:00:03.454 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:755a, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:49.919091Z [313.121880900] user.info otbr-agent[7889] 00:00:03.454 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:49.919129Z [313.121918700] user.info otbr-agent[7889] 00:00:03.454 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:50.756637Z [313.959434800] user.info otbr-agent[7889] 00:00:04.292 [I] MlrManager----: MLR Reregister!
2024-02-06T12:08:51.106593Z [314.309388940] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: Evaluating routing policy
2024-02-06T12:08:51.106692Z [314.309482980] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: Preparing RA
2024-02-06T12:08:51.106736Z [314.309525520] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1795, preferred:0)
2024-02-06T12:08:51.106764Z [314.309552700] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: - RIO fd03:bd42:5612:1::/64 (lifetime:1800, prf:medium)
2024-02-06T12:08:51.106787Z [314.309575900] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: Sent RA on infra netif 5
2024-02-06T12:08:51.106808Z [314.309597520] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: Will evaluate routing policy in 00:16.000 (16000 msec)
2024-02-06T12:08:51.107660Z [314.310454260] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: Received RA from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:51.107732Z [314.310521420] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: - RA Header - default route - lifetime:0
2024-02-06T12:08:51.107757Z [314.310546560] user.info otbr-agent[7889] 00:00:04.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1795, preferred:0)
2024-02-06T12:08:51.609544Z [314.812340540] user.info otbr-agent[7889] 00:00:05.145 [I] RoutingManager: RsSender: Sent RS 2/3
2024-02-06T12:08:51.609636Z [314.812426780] user.info otbr-agent[7889] 00:00:05.145 [I] RoutingManager: Received RS from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:51.609663Z [314.812452720] user.info otbr-agent[7889] 00:00:05.145 [I] RoutingManager: Will evaluate routing policy in 00:02.497 (2497 msec)
2024-02-06T12:08:52.573478Z [315.776277080] user.info otbr-agent[7889] 00:00:06.109 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:52.580558Z [315.783352420] user.info otbr-agent[7889] 00:00:06.116 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:138f, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:08:52.580623Z [315.783412560] user.info otbr-agent[7889] 00:00:06.116 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:52.580649Z [315.783437940] user.info otbr-agent[7889] 00:00:06.116 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:54.106726Z [317.309523260] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: Evaluating routing policy
2024-02-06T12:08:54.106829Z [317.309619780] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: Preparing RA
2024-02-06T12:08:54.106861Z [317.309650440] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1792, preferred:0)
2024-02-06T12:08:54.106884Z [317.309673520] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: - RIO fd03:bd42:5612:1::/64 (lifetime:1800, prf:medium)
2024-02-06T12:08:54.106906Z [317.309695100] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: Sent RA on infra netif 5
2024-02-06T12:08:54.106927Z [317.309716160] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: Will evaluate routing policy in 00:16.000 (16000 msec)
2024-02-06T12:08:54.107421Z [317.310214100] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: Received RA from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:54.107475Z [317.310264860] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: - RA Header - default route - lifetime:0
2024-02-06T12:08:54.107501Z [317.310290360] user.info otbr-agent[7889] 00:00:07.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1792, preferred:0)
2024-02-06T12:08:55.609663Z [318.812459060] user.info otbr-agent[7889] 00:00:09.145 [I] RoutingManager: RsSender: Sent RS 3/3
2024-02-06T12:08:55.609752Z [318.812541740] user.info otbr-agent[7889] 00:00:09.145 [I] RoutingManager: Received RS from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:55.609785Z [318.812574880] user.info otbr-agent[7889] 00:00:09.145 [I] RoutingManager: Will evaluate routing policy in 00:01.497 (1497 msec)
2024-02-06T12:08:56.609547Z [319.812343580] user.info otbr-agent[7889] 00:00:10.145 [I] RoutingManager: RsSender: Finished sending RS msgs and waiting for RAs
2024-02-06T12:08:56.609637Z [319.812427500] user.info otbr-agent[7889] 00:00:10.145 [I] RoutingManager: Will evaluate routing policy in 00:00.497 (497 msec)
2024-02-06T12:08:57.106994Z [320.309789240] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Evaluating routing policy
2024-02-06T12:08:57.107077Z [320.309867740] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Publishing route for local on-link prefix fd11:1111:1122:2222::/64
2024-02-06T12:08:57.107106Z [320.309895240] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Advertising local on-link prefix fd11:1111:1122:2222::/64
2024-02-06T12:08:57.107129Z [320.309918020] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Preparing RA
2024-02-06T12:08:57.107151Z [320.309939820] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1800, preferred:1800)
2024-02-06T12:08:57.107173Z [320.309961800] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: - RIO fd03:bd42:5612:1::/64 (lifetime:1800, prf:medium)
2024-02-06T12:08:57.107194Z [320.309983540] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Sent RA on infra netif 5
2024-02-06T12:08:57.107215Z [320.310004520] user.info otbr-agent[7889] 00:00:10.642 [I] Settings------: Read SrpServerInfo {port:53535}
2024-02-06T12:08:57.107239Z [320.310028240] user.info otbr-agent[7889] 00:00:10.642 [I] SrpServer-----: Selected port 53536
2024-02-06T12:08:57.107261Z [320.310050000] user.info otbr-agent[7889] 00:00:10.642 [I] NetDataPublshr: Publishing DNS/SRP service unicast (ml-eid, port:53536)
2024-02-06T12:08:57.107282Z [320.310071200] user.info otbr-agent[7889] 00:00:10.642 [I] NetDataPublshr: DNS/SRP service - State: NoEntry -> ToAdd
2024-02-06T12:08:57.107303Z [320.310092180] user.info otbr-agent[7889] 00:00:10.642 [I] NetDataPublshr: DNS/SRP service (state:ToAdd) in netdata - total:0, preferred:0, desired:2
2024-02-06T12:08:57.107325Z [320.310113540] user.info otbr-agent[7889] 00:00:10.642 [I] NetDataPublshr: DNS/SRP service - State: ToAdd -> Adding
2024-02-06T12:08:57.107345Z [320.310134460] user.info otbr-agent[7889] 00:00:10.642 [I] NetDataPublshr: DNS/SRP service (state:Adding) - update in 97 msec
2024-02-06T12:08:57.107366Z [320.310155300] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Will evaluate routing policy in 08:20.908 (500908 msec)
2024-02-06T12:08:57.107387Z [320.310175760] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: Received RA from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:08:57.107408Z [320.310197340] user.info otbr-agent[7889] 00:00:10.642 [I] RoutingManager: - RA Header - default route - lifetime:0
2024-02-06T12:08:57.203470Z [320.406268940] user.info otbr-agent[7889] 00:00:10.739 [I] NetDataPublshr: DNS/SRP service - State: Adding -> Added
2024-02-06T12:08:57.203560Z [320.406349780] user.info otbr-agent[7889] 00:00:10.739 [I] SrpServer-----: Start listening on port 53536
2024-02-06T12:08:57.203602Z [320.406391560] user.info otbr-agent[7889] 00:00:10.739 [I] NetworkData---: Sent ServerData
2024-02-06T12:08:57.203644Z [320.406433580] user.info otbr-agent[7889] 00:00:10.739 [I] NetworkData---: Received ServerData
2024-02-06T12:08:57.203667Z [320.406455840] user.info otbr-agent[7889] 00:00:10.739 [I] NetworkData---: Allocated Service ID = 1
2024-02-06T12:08:57.203688Z [320.406477560] user.info otbr-agent[7889] 00:00:10.739 [I] NetworkData---: Sent ServerData ack
2024-02-06T12:08:57.203710Z [320.406499200] user.info otbr-agent[7889] 00:00:10.739 [I] Notifier------: StateChanged (0x00000200) [NetData]
2024-02-06T12:08:57.203744Z [320.406532820] user.info otbr-agent[7889] 00:00:10.739 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1)
2024-02-06T12:08:57.203766Z [320.406555440] user.info otbr-agent[7889] 00:00:10.739 [I] BbrLeader-----: PBBR state: Unchanged
2024-02-06T12:08:57.203787Z [320.406576500] user.info otbr-agent[7889] 00:00:10.739 [I] BbrLeader-----: Rloc16:0xd800, seqno:86, delay:5, timeout:3600
2024-02-06T12:08:57.203849Z [320.406638100] user.info otbr-agent[7889] 00:00:10.739 [I] Platform------: [netif] Sent request#11 to add fd2c:a1e8:439e:29c6:0:ff:fe00:fc11/64
2024-02-06T12:08:57.203872Z [320.406661120] user.info otbr-agent[7889] 00:00:10.739 [I] RoutingManager: Will evaluate routing policy in 00:02.903 (2903 msec)
2024-02-06T12:08:57.203894Z [320.406682960] user.info otbr-agent[7889] 00:00:10.739 [I] NetDataPublshr: DNS/SRP service (state:Added) in netdata - total:1, preferred:0, desired:2
2024-02-06T12:08:57.203917Z [320.406705640] user.info otbr-agent[7889] 00:00:10.739 [I] NetDataPublshr: ExternalRoute fc00::/7 (state:Added) in netdata - total:1, preferred:0, desired:10
2024-02-06T12:08:57.203938Z [320.406727560] user.info otbr-agent[7889] [INFO]-BA------: Publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local.
2024-02-06T12:08:57.203968Z [320.406757040] user.info otbr-agent[7889] [INFO]-BA------: Result of publish meshcop service OpenThread BorderRouter #7C11._meshcop._udp.local: OK
2024-02-06T12:08:57.204020Z [320.406809620] user.info otbr-agent[7889] 00:00:10.739 [I] Notifier------: StateChanged (0x00000001) [Ip6+]
2024-02-06T12:08:57.204043Z [320.406832740] user.info otbr-agent[7889] 00:00:10.739 [I] Platform------: [netif] Succeeded to process request#11
2024-02-06T12:08:57.204807Z [320.407600060] user.info otbr-agent[7889] 00:00:10.740 [I] Platform------: [netif] ADD [U] fd2c:a1e8:439e:29c6:0:ff:fe00:fc11 (already subscribed, ignored)
2024-02-06T12:08:57.214405Z [320.417201880] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:57.214660Z [320.417451880] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:57.214692Z [320.417481720] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:57.214715Z [320.417504160] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:57.214736Z [320.417525540] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:57.214757Z [320.417546340] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:57.214778Z [320.417567340] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:57.214813Z [320.417602220] user.info otbr-agent[7889] 00:00:10.750 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:57.229885Z [320.432680200] user.info otbr-agent[7889] 00:00:10.765 [I] MeshForwarder-: Sent IPv6 UDP msg, len:187, chksum:45a6, ecn:no, to:0xffff, sec:yes, prio:net
2024-02-06T12:08:57.229974Z [320.432763520] user.info otbr-agent[7889] 00:00:10.765 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:08:57.230000Z [320.432788780] user.info otbr-agent[7889] 00:00:10.765 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:57.594406Z [320.797202420] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] Message dropped by Thread
2024-02-06T12:08:57.594638Z [320.797428580] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:57.594671Z [320.797460960] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff33:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:57.594695Z [320.797484060] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff32:40:fd2c:a1e8:439e:29c6:0:1 (already subscribed, ignored)
2024-02-06T12:08:57.594717Z [320.797506460] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:fc (already subscribed, ignored)
2024-02-06T12:08:57.594738Z [320.797527020] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff03:0:0:0:0:0:0:1 (already subscribed, ignored)
2024-02-06T12:08:57.594759Z [320.797547640] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:16 (already subscribed, ignored)
2024-02-06T12:08:57.594780Z [320.797569020] user.info otbr-agent[7889] 00:00:11.130 [I] Platform------: [netif] ADD [M] ff02:0:0:0:0:0:0:2 (already subscribed, ignored)
2024-02-06T12:08:57.703489Z [320.906284800] user.info otbr-agent[7889] 00:00:11.239 [I] MeshForwarder-: Received IPv6 UDP msg, len:187, chksum:318b, ecn:no, from:c6e49a9ddd3efa11, sec:yes, prio:net, rss:-41.0
2024-02-06T12:08:57.703574Z [320.906364180] user.info otbr-agent[7889] 00:00:11.239 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:08:57.703599Z [320.906388460] user.info otbr-agent[7889] 00:00:11.239 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:08:57.703621Z [320.906409780] user.info otbr-agent[7889] 00:00:11.239 [I] Mle-----------: Receive Data Response (fe80:0:0:0:c4e4:9a9d:dd3e:fa11)
2024-02-06T12:08:57.764449Z [320.967245200] user.info otbr-agent[7889] 00:00:11.300 [I] DuaManager----: PerformNextRegistration: NotFound
2024-02-06T12:08:57.970966Z [321.173762640] user.info otbr-agent[7889] 00:00:11.506 [I] AddrResolver--: Cache entry added: fd2c:a1e8:439e:29c6:ad2c:cb6f:8435:9f74, 0x3800 - snoop
2024-02-06T12:08:58.014500Z [321.217295520] user.info otbr-agent[7889] 00:00:11.550 [I] MeshForwarder-: Received IPv6 UDP msg, len:721, chksum:ec00, ecn:no, from:0x3800, sec:yes, prio:normal, rss:-41.0
2024-02-06T12:08:58.014581Z [321.217370520] user.info otbr-agent[7889] 00:00:11.550 [I] MeshForwarder-:     src:[fd2c:a1e8:439e:29c6:ad2c:cb6f:8435:9f74]:49156
2024-02-06T12:08:58.014608Z [321.217396860] user.info otbr-agent[7889] 00:00:11.550 [I] MeshForwarder-:     dst:[fd2c:a1e8:439e:29c6:428f:f75c:340d:d2a8]:53536
2024-02-06T12:08:58.014629Z [321.217417920] user.info otbr-agent[7889] 00:00:11.550 [I] SrpServer-----: Received DNS update from fd2c:a1e8:439e:29c6:ad2c:cb6f:8435:9f74
2024-02-06T12:08:58.022100Z [321.224892280] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----: Processed DNS update info
2024-02-06T12:08:58.022146Z [321.224935220] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Host:C6E49A9DDD3EFA11.default.service.arpa.
2024-02-06T12:08:58.022180Z [321.224969720] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Lease:7200, key-lease:1209600, ttl:7200
2024-02-06T12:08:58.022203Z [321.224991780] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     1 host address(es):
2024-02-06T12:08:58.022225Z [321.225014180] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:       fd03:bd42:5612:1:7171:334e:a54:7418
2024-02-06T12:08:58.022247Z [321.225035720] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.' subtype:_ICD262F6D7C36CCC4
2024-02-06T12:08:58.022268Z [321.225057400] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.'
2024-02-06T12:08:58.022290Z [321.225079140] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_L3840
2024-02-06T12:08:58.022314Z [321.225103120] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_S15
2024-02-06T12:08:58.022343Z [321.225132440] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_V65521
2024-02-06T12:08:58.022365Z [321.225153920] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.'
2024-02-06T12:08:58.022387Z [321.225175620] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----: SRP update handler is notified (updatedId = 1996159337)
2024-02-06T12:08:58.022718Z [321.225509840] user.info otbr-agent[7889] [INFO]-ADPROXY-: Advertise SRP service updates: host=C6E49A9DDD3EFA11.default.service.arpa.
2024-02-06T12:08:58.024929Z [321.227721440] user.info otbr-agent[7889] [INFO]-MDNS----: Add subtype _ICD262F6D7C36CCC4 for service CD262F6D7C36CCC4-000000000000000F._matter._tcp
2024-02-06T12:08:58.025906Z [321.228698540] user.info otbr-agent[7889] [INFO]-MDNS----: **Commit avahi service CD262F6D7C36CCC4-000000000000000F._matter._tcp**
2024-02-06T12:08:58.029083Z [321.231875440] user.info otbr-agent[7889] [INFO]-MDNS----: Add subtype _L3840 for service 13D4CAB52E738C5D._matterc._udp
2024-02-06T12:08:58.030024Z [321.232816800] user.info otbr-agent[7889] [INFO]-MDNS----: Add subtype _S15 for service 13D4CAB52E738C5D._matterc._udp
2024-02-06T12:08:58.030921Z [321.233713380] user.info otbr-agent[7889] [INFO]-MDNS----: Add subtype _V65521 for service 13D4CAB52E738C5D._matterc._udp
2024-02-06T12:08:58.031841Z [321.234633320] user.info otbr-agent[7889] [INFO]-MDNS----: **Commit avahi service 13D4CAB52E738C5D._matterc._udp**
2024-02-06T12:08:58.034969Z [321.237762100] user.info otbr-agent[7889] [INFO]-MDNS----: **Commit avahi host C6E49A9DDD3EFA11**
2024-02-06T12:08:58.975529Z [322.178325880] user.info otbr-agent[7889] [INFO]-MDNS----: Avahi group **(@0x234f1e0) is established**
2024-02-06T12:08:58.975615Z [322.178405800] user.info otbr-agent[7889] [INFO]-ADPROXY-: **Handle publish SRP service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.': OK**
2024-02-06T12:08:58.975651Z [322.178440280] user.info otbr-agent[7889] [INFO]-ADPROXY-: Waiting for more publishing callbacks 2
2024-02-06T12:08:58.981729Z [322.184524220] user.info otbr-agent[7889] [INFO]-MDNS----: Avahi group (@0x2349c38) is established
2024-02-06T12:08:58.981804Z [322.184593400] user.info otbr-agent[7889] [INFO]-ADPROXY-: Handle publish SRP service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.': OK
2024-02-06T12:08:58.981843Z [322.184632540] user.info otbr-agent[7889] [INFO]-ADPROXY-: Waiting for more publishing callbacks 1
2024-02-06T12:08:58.984523Z [322.187315740] user.info otbr-agent[7889] [INFO]-MDNS----: Avahi group (@0x234fc00) is established
2024-02-06T12:08:58.984581Z [322.187370560] user.info otbr-agent[7889] [INFO]-ADPROXY-: Handle publish SRP host 'C6E49A9DDD3EFA11.default.service.arpa.': OK
2024-02-06T12:08:58.984608Z [322.187397400] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Handler result of SRP update (id = 1996159337) is received: OK
2024-02-06T12:08:58.984631Z [322.187419980] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new host C6E49A9DDD3EFA11.default.service.arpa.
2024-02-06T12:08:58.984653Z [322.187442480] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.' subtype:_ICD262F6D7C36CCC4
2024-02-06T12:08:58.984675Z [322.187464260] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.'
2024-02-06T12:08:58.984697Z [322.187485780] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_L3840
2024-02-06T12:08:58.984718Z [322.187506800] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_S15
2024-02-06T12:08:58.984739Z [322.187527920] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_V65521
2024-02-06T12:08:58.984760Z [322.187549700] user.info otbr-agent[7889] 00:00:12.520 [I] SrpServer-----: Add new service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.'
2024-02-06T12:08:58.988086Z [322.190878500] user.info otbr-agent[7889] 00:00:12.523 [I] Settings------: Saved SrpServerInfo {port:53536}
2024-02-06T12:08:58.988142Z [322.190931700] user.info otbr-agent[7889] 00:00:12.523 [I] SrpServer-----: Lease timer is scheduled for 7199 seconds
2024-02-06T12:08:58.988169Z [322.190958660] user.info otbr-agent[7889] 00:00:12.523 [I] SrpServer-----: Send success response with granted lease: 7200 and key lease: 680400
2024-02-06T12:08:59.002490Z [322.205283240] user.info otbr-agent[7889] 00:00:12.538 [I] MeshForwarder-: Sent IPv6 UDP msg, len:83, chksum:8edf, ecn:no, to:0x3800, sec:yes, prio:low
2024-02-06T12:08:59.002548Z [322.205337840] user.info otbr-agent[7889] 00:00:12.538 [I] MeshForwarder-:     src:[fd2c:a1e8:439e:29c6:428f:f75c:340d:d2a8]:53536
2024-02-06T12:08:59.002574Z [322.205364040] user.info otbr-agent[7889] 00:00:12.538 [I] MeshForwarder-:     dst:[fd2c:a1e8:439e:29c6:ad2c:cb6f:8435:9f74]:49156
2024-02-06T12:09:00.106724Z [323.309520380] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: Evaluating routing policy
2024-02-06T12:09:00.106811Z [323.309602020] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: Preparing RA
2024-02-06T12:09:00.106856Z [323.309646140] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: - PIO fd11:1111:1122:2222::/64 (valid:1800, preferred:1800)
2024-02-06T12:09:00.106887Z [323.309676200] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: - RIO fd03:bd42:5612:1::/64 (lifetime:1800, prf:medium)
2024-02-06T12:09:00.106914Z [323.309702800] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: Sent RA on infra netif 5
2024-02-06T12:09:00.106937Z [323.309725800] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: Will evaluate routing policy in 09:54.683 (594683 msec)
2024-02-06T12:09:00.107037Z [323.309829840] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: Received RA from fe80:0:0:0:4ebc:e9ff:feff:e138 on infra netif 5
2024-02-06T12:09:00.107080Z [323.309869500] user.info otbr-agent[7889] 00:00:13.642 [I] RoutingManager: - RA Header - default route - lifetime:0
2024-02-06T12:09:00.401695Z [323.604490820] user.info otbr-agent[7889] 00:00:13.937 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:09:00.410450Z [323.613243940] user.info otbr-agent[7889] 00:00:13.946 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:28ee, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:09:00.410507Z [323.613296700] user.info otbr-agent[7889] 00:00:13.946 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:09:00.410531Z [323.613319900] user.info otbr-agent[7889] 00:00:13.946 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:09:11.330888Z [334.533685600] user.info otbr-agent[7889] 00:00:24.866 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:09:11.335929Z [334.538722720] user.info otbr-agent[7889] 00:00:24.871 [I] MeshForwarder-: Received IPv6 UDP msg, len:91, chksum:b5f9, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:09:11.336000Z [334.538790460] user.info otbr-agent[7889] 00:00:24.871 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:09:11.336034Z [334.538824080] user.info otbr-agent[7889] 00:00:24.871 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:09:11.336058Z [334.538847940] user.info otbr-agent[7889] 00:00:24.871 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c4e4:9a9d:dd3e:fa11,0x3800)
2024-02-06T12:09:11.338795Z [334.541585380] user.info otbr-agent[7889] 00:00:24.874 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:ce0c, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:09:11.338830Z [334.541619440] user.info otbr-agent[7889] 00:00:24.874 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:09:11.338853Z [334.541642240] user.info otbr-agent[7889] 00:00:24.874 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:09:37.688310Z [360.891106960] user.info otbr-agent[7889] 00:00:51.224 [I] MeshForwarder-: Received IPv6 UDP msg, len:91, chksum:9c4e, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:09:37.688402Z [360.891192340] user.info otbr-agent[7889] 00:00:51.224 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:09:37.688437Z [360.891226140] user.info otbr-agent[7889] 00:00:51.224 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:09:37.688461Z [360.891250380] user.info otbr-agent[7889] 00:00:51.224 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c4e4:9a9d:dd3e:fa11,0x3800)
2024-02-06T12:09:45.592505Z [368.795301620] user.info otbr-agent[7889] 00:00:59.128 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:09:45.598611Z [368.801403780] user.info otbr-agent[7889] 00:00:59.134 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:aa14, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:09:45.598671Z [368.801460940] user.info otbr-agent[7889] 00:00:59.134 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:09:45.598697Z [368.801486400] user.info otbr-agent[7889] 00:00:59.134 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:10:05.719918Z [388.922713180] user.info otbr-agent[7889] 00:01:19.255 [I] MeshForwarder-: Received IPv6 UDP msg, len:91, chksum:e58a, ecn:no, from:c6e49a9ddd3efa11, sec:no, prio:net, rss:-41.0
2024-02-06T12:10:05.719987Z [388.922777120] user.info otbr-agent[7889] 00:01:19.255 [I] MeshForwarder-:     src:[fe80:0:0:0:c4e4:9a9d:dd3e:fa11]:19788
2024-02-06T12:10:05.720012Z [388.922800880] user.info otbr-agent[7889] 00:01:19.255 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788
2024-02-06T12:10:05.720034Z [388.922823240] user.info otbr-agent[7889] 00:01:19.255 [I] Mle-----------: Receive Advertisement (fe80:0:0:0:c4e4:9a9d:dd3e:fa11,0x3800)
2024-02-06T12:10:20.541588Z [403.744386340] user.info otbr-agent[7889] 00:01:34.077 [I] Mle-----------: Send Advertisement (ff02:0:0:0:0:0:0:1)
2024-02-06T12:10:20.548509Z [403.751304780] user.info otbr-agent[7889] 00:01:34.083 [I] MeshForwarder-: Sent IPv6 UDP msg, len:91, chksum:573e, ecn:no, to:0xffff, sec:no, prio:net
2024-02-06T12:10:20.548587Z [403.751377700] user.info otbr-agent[7889] 00:01:34.084 [I] MeshForwarder-:     src:[fe80:0:0:0:a8fc:9096:946c:7c11]:19788
2024-02-06T12:10:20.548621Z [403.751410700] user.info otbr-agent[7889] 00:01:34.084 [I] MeshForwarder-:     dst:[ff02:0:0:0:0:0:0:1]:19788

Reg ping between otbr and end device.

ipaddress of end device
uart:~$ ot ipaddr fd03:bd42:5612:1:7171:334e:a54:7418 fd2c:a1e8:439e:29c6:0:ff:fe00:3800 fd2c:a1e8:439e:29c6:ad2c:cb6f:8435:9f74 fe80:0:0:0:c4e4:9a9d:dd3e:fa11 Done uart:~$

ping from otbr to end device:

ot-ctl ping fd03:bd42:5612:1:7171:334e:a54:7418 16 bytes from fd03:bd42:5612:1:7171:334e:a54:7418: icmp_seq=1 hlim=64 time=46ms 1 packets transmitted, 1 packets received. Packet loss = 0.0%. Round-trip min/avg/max = 46/46.0/46 ms. Done

ipaddr of otbr-agent

ot-ctl ipaddr fd2c:a1e8:439e:29c6:0:ff:fe00:fc11 fd03:bd42:5612:1:f8b1:e060:736f:5304 fd2c:a1e8:439e:29c6:0:ff:fe00:fc38 fd2c:a1e8:439e:29c6:0:ff:fe00:fc10 fd2c:a1e8:439e:29c6:0:ff:fe00:fc00 fd2c:a1e8:439e:29c6:0:ff:fe00:d800 fd2c:a1e8:439e:29c6:428f:f75c:340d:d2a8 fe80:0:0:0:a8fc:9096:946c:7c11 Done

ping from end device to otbr
`ot ping fd2c:a1e8:439e:29c6:0:ff:fe00:fc11
16 bytes from fd2c:a1e8:439e:29c6:0:ff:fe00:fc11: icmp_seq=1 hlim=64 time=16msua

1 packets transmitted, 1 packets received. Packet loss = 0.0%. Round-trip min/avg/max = 16/16.0/16 ms.
Done`

@jwhui
Copy link
Member

jwhui commented Feb 6, 2024

From the log, it looks like the Matter-related services are being registered:

2024-02-06T12:08:58.014629Z [321.217417920] user.info otbr-agent[7889] 00:00:11.550 [I] SrpServer-----: Received DNS update from fd2c:a1e8:439e:29c6:ad2c:cb6f:8435:9f74
2024-02-06T12:08:58.022100Z [321.224892280] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----: Processed DNS update info
2024-02-06T12:08:58.022146Z [321.224935220] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Host:C6E49A9DDD3EFA11.default.service.arpa.
2024-02-06T12:08:58.022180Z [321.224969720] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Lease:7200, key-lease:1209600, ttl:7200
2024-02-06T12:08:58.022203Z [321.224991780] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     1 host address(es):
2024-02-06T12:08:58.022225Z [321.225014180] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:       fd03:bd42:5612:1:7171:334e:a54:7418
2024-02-06T12:08:58.022247Z [321.225035720] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.' subtype:_ICD262F6D7C36CCC4
2024-02-06T12:08:58.022268Z [321.225057400] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service 'CD262F6D7C36CCC4-000000000000000F._matter._tcp.default.service.arpa.'
2024-02-06T12:08:58.022290Z [321.225079140] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_L3840
2024-02-06T12:08:58.022314Z [321.225103120] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_S15
2024-02-06T12:08:58.022343Z [321.225132440] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.' subtype:_V65521
2024-02-06T12:08:58.022365Z [321.225153920] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----:     Adding service '13D4CAB52E738C5D._matterc._udp.default.service.arpa.'
2024-02-06T12:08:58.022387Z [321.225175620] user.info otbr-agent[7889] 00:00:11.557 [I] SrpServer-----: SRP update handler is notified (updatedId = 1996159337)

Can you view them when you browse on the Wi-Fi link?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants