search

openthread / ot-br-posix

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

otbr-agent restarting after linux pc coming out of sleep mode #2139

Closed gadekula1 closed 4 days ago

gadekula1 commented 11 months ago

otbr-agent restarting after linux pc coming out of sleep mode

pid before sleep:

` systemctl status otbr-agent

pid after sleep:

`systemctl status otbr-agent

[5854] 00:13:23.666 [I] InfraIf-------: State changed: RUNNING -> NOT RUNNING 2023-01-01T00:14:37.905537Z [878.887989480] user.info otbr-agent[5854] 00:13:23.666 [I] BorderRouter--: Removed local OMR prefix fd51:a5e:23c3:1::/64 from Thread Network Data 2023-01-01T00:14:37.905950Z [878.888405140] user.info otbr-agent[5854] 00:13:23.666 [I] NetDataPublshr: Unpublishing fd11:1111:1122:2222::/64 2023-01-01T00:14:37.906003Z [878.888455560] user.info otbr-agent[5854] 00:13:23.666 [I] NetDataPublshr: ExternalRoute fd11:1111:1122:2222::/64 - State: Added -> NoEntry 2023-01-01T00:14:37.906029Z [878.888481400] user.info otbr-agent[5854] 00:13:23.666 [I] BorderRouter--: RouterAdvert: Added PIO for fd11:1111:1122:2222::/64 (valid=1543, preferred=0) 2023-01-01T00:14:37.906053Z [878.888505000] user.info otbr-agent[5854] 00:13:23.666 [I] BorderRouter--: RouterAdvert: Added PIO for fd11:1111:1122:2222::/64 (valid=995, preferred=0) 2023-01-01T00:14:37.906301Z [878.888755520] user.info otbr-agent[5854] 00:13:23.666 [I] BorderRouter--: RouterAdvert: Added RIO for fd51:a5e:23c3:1::/64 (lifetime=0) 2023-01-01T00:14:37.906360Z [878.888813100] user.info otbr-agent[5854] 00:13:23.666 [I] BorderRouter--: Sent Router Advertisement on infra netif 2 2023-01-01T00:14:37.906412Z [878.888875700] user.info otbr-agent[5854] 00:13:23.666 [I] BorderRouter--: Border Routing manager stopped 2023-01-01T00:14:37.906453Z [878.888905200] user.info otbr-agent[5854] 00:13:23.666 [I] MeshForwarder-: Received IPv6 UDP msg, len:96, chksum:7962, ecn:no, from:061c676a3ea7a782, sec:no, prio:net, rss:0.0 2023-01-01T00:14:37.906494Z [878.888948200] user.info otbr-agent[5854] 00:13:23.666 [I] MeshForwarder-: src:[fe80:0:0:0:41c:676a:3ea7:a782]:19788 2023-01-01T00:14:37.906542Z [878.888995480] user.info otbr-agent[5854] 00:13:23.666 [I] MeshForwarder-: dst:[fe80:0:0:0:a8fe:737d:13d1:62d1]:19788 2023-01-01T00:14:37.906583Z [878.889035800] user.info otbr-agent[5854] 00:13:23.666 [I] Mle-----------: Receive Link Request (fe80:0:0:0:41c:676a:3ea7:a782) 2023-01-01T00:14:37.906619Z [878.889072100] user.info otbr-agent[5854] 00:13:23.666 [I] Mle-----------: Send Link Accept (fe80:0:0:0:41c:676a:3ea7:a782) 2023-01-01T00:14:37.906644Z [878.889096340] user.info otbr-agent[5854] 00:13:23.666 [I] NetworkData---: Sent server data notification 2023-01-01T00:14:37.906710Z [878.889164860] user.info otbr-agent[5854] 00:13:23.666 [I] NetworkData---: Received network data registration 2023-01-01T00:14:37.907477Z [878.889935340] user.info otbr-agent[5854] 00:13:23.666 [I] NetworkData---: Sent network data registration acknowledgment 2023-01-01T00:14:37.907568Z [878.890021060] user.info otbr-agent[5854] 00:13:23.666 [I] Notifier------: StateChanged (0x00000200) [NetData] 2023-01-01T00:14:37.907645Z [878.890099480] user.info otbr-agent[5854] 00:13:23.667 [I] Mle-----------: Send Data Response (ff02:0:0:0:0:0:0:1) 2023-01-01T00:14:37.907673Z [878.890125360] user.info otbr-agent[5854] 00:13:23.667 [I] BbrLeader-----: PBBR state: Unchanged 2023-01-01T00:14:37.907695Z [878.890147200] user.info otbr-agent[5854] 00:13:23.667 [I] BbrLeader-----: Rloc16:0x2400, seqno:40, delay:5, timeout:3600 2023-01-01T00:14:37.907716Z [878.890167980] user.info otbr-agent[5854] 00:13:23.667 [I] BbrLeader-----: Domain Prefix: ::/0, state: None 2023-01-01T00:14:37.907749Z [878.890201680] user.info otbr-agent[5854] 00:13:23.667 [I] Slaac---------: Removing address fd51:a5e:23c3:1:8142:9b60:720f:bff3 2023-01-01T00:14:37.907790Z [878.890243300] user.info otbr-agent[5854] 00:13:23.667 [I] Platform------: [netif] Sent request#11 to remove fd51:a5e:23c3:1:8142:9b60:720f:bff3/64 2023-01-01T00:14:37.907823Z [878.890275900] user.info otbr-agent[5854] 00:13:23.667 [I] NetDataPublshr: DNS/SRP service (state:Added) in netdata - total:1, preferred:0, desired:2 2023-01-01T00:14:37.907845Z [878.890297700] user.info otbr-agent[5854] 00:13:23.667 [I] Notifier------: StateChanged (0x00000002) [Ip6-] 2023-01-01T00:14:37.907866Z [878.890318460] user.info otbr-agent[5854] 00:13:23.667 [I] Platform------: [netif] DEL [U] fd51:a5e:23c3:1:8142:9b60:720f:bff3 (not found, ignored) 2023-01-01T00:14:37.907887Z [878.890339240] user.info otbr-agent[5854] 00:13:23.667 [I] Platform------: [netif] Succeeded to process request#11 2023-01-01T00:14:37.908046Z [878.890498500] user.warning otbr-agent[5854] 00:13:23.669 [W] Platform------: Handle transmit done failed: Parse 2023-01-01T00:14:39.121696Z [880.104157700] daemon.notice kernel systemd[1]: otbr-agent.service: Main process exited, code=exited, status=134/n/a 2023-01-01T00:14:39.121782Z [880.104235740] daemon.warning kernel systemd[1]: otbr-agent.service: Failed with result 'exit-code'. 2023-01-01T00:14:44.194204Z [885.176664840] daemon.info kernel systemd[1]: otbr-agent.service: Scheduled restart job, restart counter is at 1.

Analysis:

analysis on above logs:

changing lan state to InfraIf-------: State changed: RUNNING -> NOT RUNNING Unpublishing ip addr Border Routing manager stopped Platform------: [netif] DEL [U] fd51:a5e:23c3:1:8142:9b60:720f:bff3 Platform------: Handle transmit done failed:

if (err->error == 0)
{
    otLogInfoPlat("[netif] Succeeded to process request#%u", requestSeq);
    ExitNow();
}

triggering exit

define ExitNow(...) \

do               \
{                \
    __VA_ARGS__; \
    goto exit;   \
} while (false)

finally returning fromprocessNetlinkEvent

from platformNetifProcess

void otSysMainloopProcess(otInstance aInstance, const otSysMainloopContext aMainloop) { ot::Posix::Mainloop::Manager::Get().Process(*aMainloop);

if OPENTHREAD_POSIX_VIRTUAL_TIME

virtualTimeProcess(aInstance, aMainloop);

else

platformRadioProcess(aInstance, aMainloop);

endif

if OPENTHREAD_CONFIG_RADIO_LINK_TREL_ENABLE

platformTrelProcess(aInstance, aMainloop);

endif

platformAlarmProcess(aInstance);

if OPENTHREAD_CONFIG_PLATFORM_NETIF_ENABLE

platformNetifProcess(aMainloop);

endif

}

    if (otSysMainloopPoll(&mainloop) >= 0)
    {
        otSysMainloopProcess(instance, &mainloop);

if !OPENTHREAD_POSIX_CONFIG_DAEMON_ENABLE

        otAppCliProcess(&mainloop);

endif

finally its existing from main method

while parsing NetlinkEvent (Received IPv6 UDP msg and trying to forward on non existing ip) its going for the toss and exiting from main

jwhui commented 4 days ago

Closing stale issue.