Openthread: [github-actions] expect/tun-realm-local-multicast.exp fails intermittently

[jwhui]

Describe the bug

tests/scripts/expect/tun-realm-local-multicast.exp fails intermittently

Console/log output

Log archive: logs_36395.zip

# 1 rcp
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-posix-1.1/src/posix/ot-cli spinel+hdlc+uart:///home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/ncp/ot-rcp?forkpty-arg=1
routerselectionjitter 1
Done

> panid 0xface
Done

> ifconfig up
Done

> thread start
Done

> state
detached

Done

> state
detached

Done

> state
detached

Done

> state
leader

Done

> extaddr
9284c96b9a2aa25e

Done

> 
# 2 cli
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/cli/ot-cli-ftd 2
routerselectionjitter 1
routerselectionjitter 1
Done
> panid 0xface
Done
> ifconfig up
Done
> thread start
Done
> state
detached
Done
> state
child
Done
> state
router
Done
> 
# 3 cli
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/cli/ot-cli-ftd 3
routerselectionjitter 1
Done
> panid 0xface
Done
> macfilter addr add 9284c96b9a2aa25e
Done
> macfilter addr denylist
Done
> ifconfig up
Done
> thread start
Done
> state
detached
Done
> state
detached
Done
> state
router
Done
> extaddr
8acae7de11e9c473
Done
> 
# 4 cli
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/cli/ot-cli-ftd 4
routerselectionjitter 1
Done
> panid 0xface
Done
> mode rn
Done
> macfilter addr add 8acae7de11e9c473
Done
> macfilter addr allowlist
Done
> ifconfig up
Done
> thread start
Done
> state
detached
Done
> state
detached
Done
> state
child
Done
> ipaddr mleid
fdde:ad00:beef:0:f55a:fcc0:f244:81fe
Done
> 
# 1
ping fdde:ad00:beef:0:f55a:fcc0:f244:81fe
Done

expect version 5.45.4
argv[0] = expect  argv[1] = -df  argv[2] = tests/scripts/expect/tun-realm-local-multicast.exp  
set argc 0
set argv0 "tests/scripts/expect/tun-realm-local-multicast.exp"
set argv ""
executing commands from command file tests/scripts/expect/tun-realm-local-multicast.exp
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {19357}
send: sending "routerselectionjitter 1\n" to { exp3 }

expect: does "" (spawn_id exp3) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "routerselectionjitter 1\r\nDone"
send: sending "panid 0xface\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> panid 0xface\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> panid 0xface\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> panid 0xface\r\nDone"
send: sending "ifconfig up\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> ifconfig up\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> ifconfig up\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> ifconfig up\r\nDone"
send: sending "thread start\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> thread start\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> thread start\r\nDone"
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\n" (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\nleader\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=yes re=yes
expect: set expect_out(0,string) "leader"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\nleader"

expect: does "\r\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\nDone"
send: sending "extaddr\n" to { exp3 }
Gate keeper glob pattern for '([0-9a-fA-F]{16})' is ''. Not usable, disabling the performance booster.

expect: does "\r\r\n> " (spawn_id exp3) match regular expression "([0-9a-fA-F]{16})"? (No Gate, RE only) gate=yes re=no

expect: does "\r\r\n> extaddr\r\n9284c96b9a2aa25e\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "([0-9a-fA-F]{16})"? (No Gate, RE only) gate=yes re=yes
expect: set expect_out(0,string) "9284c96b9a2aa25e"
expect: set expect_out(1,string) "9284c96b9a2aa25e"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> extaddr\r\n9284c96b9a2aa25e"

expect: does "\r\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\nDone"
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {19373}
send: sending "routerselectionjitter 1\n" to { exp6 }

expect: does "" (spawn_id exp6) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\n" (spawn_id exp6) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\nrouterselectionjitter 1\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "routerselectionjitter 1\r\nrouterselectionjitter 1\r\nDone"
send: sending "panid 0xface\n" to { exp6 }

expect: does "\r\n> " (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> panid 0xface\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> panid 0xface\r\nDone"
send: sending "ifconfig up\n" to { exp6 }

expect: does "\r\n> " (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> ifconfig up\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> ifconfig up\r\nDone"
send: sending "thread start\n" to { exp6 }

expect: does "\r\n> " (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> thread start\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> thread start\r\nDone"
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> state\r\nrouter\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=yes re=yes
expect: set expect_out(0,string) "router"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> state\r\nrouter"
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {19381}
send: sending "routerselectionjitter 1\n" to { exp7 }

expect: does "" (spawn_id exp7) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "routerselectionjitter 1\r\nDone"
send: sending "panid 0xface\n" to { exp7 }

expect: does "\r\n> " (spawn_id exp7) match glob pattern "Done"? no

expect: does "\r\n> panid 0xface\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\n> panid 0xface\r\nDone"
send: sending "macfilter addr add 9284c96b9a2aa25e\n" to { exp7 }

expect: does "\r\n> " (spawn_id exp7) match glob pattern "Done"? no

expect: does "\r\n> macfilter addr add 9284c96b9a2aa25e\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\n> macfilter addr add 9284c96b9a2aa25e\r\nDone"
send: sending "macfilter addr denylist\n" to { exp7 }

expect: does "\r\n> " (spawn_id exp7) match glob pattern "Done"? no

expect: does "\r\n> macfilter addr denylist\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\n> macfilter addr denylist\r\nDone"
send: sending "ifconfig up\n" to { exp7 }

expect: does "\r\n> " (spawn_id exp7) match glob pattern "Done"? no

expect: does "\r\n> ifconfig up\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\n> ifconfig up\r\nDone"
send: sending "thread start\n" to { exp7 }

expect: does "\r\n> " (spawn_id exp7) match glob pattern "Done"? no

expect: does "\r\n> thread start\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\n> thread start\r\nDone"
send: sending "state\n" to { exp7 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> " (spawn_id exp7) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp7) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp7 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp7) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp7) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp7 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp7) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nrouter\r\nDone\r\n> " (spawn_id exp7) match regular expression "router"? Gate "router"? gate=yes re=yes
expect: set expect_out(0,string) "router"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nrouter"
send: sending "extaddr\n" to { exp7 }
Gate keeper glob pattern for '([0-9a-fA-F]{16})' is ''. Not usable, disabling the performance booster.

expect: does "\r\nDone\r\n> " (spawn_id exp7) match regular expression "([0-9a-fA-F]{16})"? (No Gate, RE only) gate=yes re=no

expect: does "\r\nDone\r\n> extaddr\r\n8acae7de11e9c473\r\nDone\r\n> " (spawn_id exp7) match regular expression "([0-9a-fA-F]{16})"? (No Gate, RE only) gate=yes re=yes
expect: set expect_out(0,string) "8acae7de11e9c473"
expect: set expect_out(1,string) "8acae7de11e9c473"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\nDone\r\n> extaddr\r\n8acae7de11e9c473"

expect: does "\r\nDone\r\n> " (spawn_id exp7) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp7"
expect: set expect_out(buffer) "\r\nDone"
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {19384}
send: sending "routerselectionjitter 1\n" to { exp8 }

expect: does "" (spawn_id exp8) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "routerselectionjitter 1\r\nDone"
send: sending "panid 0xface\n" to { exp8 }

expect: does "\r\n> " (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> panid 0xface\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> panid 0xface\r\nDone"
send: sending "mode rn\n" to { exp8 }

expect: does "\r\n> " (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> mode rn\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> mode rn\r\nDone"
send: sending "macfilter addr add 8acae7de11e9c473\n" to { exp8 }

expect: does "\r\n> " (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> macfilter addr add 8acae7de11e9c473\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> macfilter addr add 8acae7de11e9c473\r\nDone"
send: sending "macfilter addr allowlist\n" to { exp8 }

expect: does "\r\n> " (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> macfilter addr allowlist\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> macfilter addr allowlist\r\nDone"
send: sending "ifconfig up\n" to { exp8 }

expect: does "\r\n> " (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> ifconfig up\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> ifconfig up\r\nDone"
send: sending "thread start\n" to { exp8 }

expect: does "\r\n> " (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> t" (spawn_id exp8) match glob pattern "Done"? no

expect: does "\r\n> thread start\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> thread start\r\nDone"
send: sending "state\n" to { exp8 }
Gate keeper glob pattern for 'child' is 'child'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> " (spawn_id exp8) match regular expression "child"? Gate "child"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp8) match regular expression "child"? Gate "child"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp8 }
Gate keeper glob pattern for 'child' is 'child'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp8) match regular expression "child"? Gate "child"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp8) match regular expression "child"? Gate "child"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp8 }
Gate keeper glob pattern for 'child' is 'child'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp8) match regular expression "child"? Gate "child"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> " (spawn_id exp8) match regular expression "child"? Gate "child"? gate=yes re=yes
expect: set expect_out(0,string) "child"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild"
send: sending "ipaddr mleid\n" to { exp8 }

expect: does "\r\nDone\r\n> " (spawn_id exp8) match glob pattern "ipaddr mleid"? no

expect: does "\r\nDone\r\n> ipaddr mleid\r\nfdde:ad00:beef:0:f55a:fcc0:f244:81fe\r\nDone\r\n> " (spawn_id exp8) match glob pattern "ipaddr mleid"? yes
expect: set expect_out(0,string) "ipaddr mleid"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\nDone\r\n> ipaddr mleid"
Gate keeper glob pattern for '(([0-9a-fA-F]{1,4}:){7,7}[0-9a-fA-F]{1,4})' is ''. Not usable, disabling the performance booster.

expect: does "\r\nfdde:ad00:beef:0:f55a:fcc0:f244:81fe\r\nDone\r\n> " (spawn_id exp8) match regular expression "(([0-9a-fA-F]{1,4}:){7,7}[0-9a-fA-F]{1,4})"? (No Gate, RE only) gate=yes re=yes
expect: set expect_out(0,string) "fdde:ad00:beef:0:f55a:fcc0:f244:81fe"
expect: set expect_out(1,string) "fdde:ad00:beef:0:f55a:fcc0:f244:81fe"
expect: set expect_out(2,string) "f244:"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\nfdde:ad00:beef:0:f55a:fcc0:f244:81fe"

expect: does "\r\nDone\r\n> " (spawn_id exp8) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp8"
expect: set expect_out(buffer) "\r\nDone"
send: sending "ping fdde:ad00:beef:0:f55a:fcc0:f244:81fe\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> ping fdde:ad00:beef:0:f55a:fcc0:f244:81fe\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> ping fdde:ad00:beef:0:f55a:fcc0:f244:81fe\r\nDone" (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> ping fdde:ad00:beef:0:f55a:fcc0:f244:81fe\r\nDone"

expect: does "" (spawn_id exp3) match glob pattern "16 bytes from fdde:ad00:beef:0:f55a:fcc0:f244:81fe: icmp_seq=1"? no

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "16 bytes from fdde:ad00:beef:0:f55a:fcc0:f244:81fe: icmp_seq=1"? no
expect: timed out
> FAIL tests/scripts/expect/tun-realm-local-multicast.exp
Error: Process completed with exit code 1.

[bukepo]

still debugging.

[librasungirl]

The root cause is ping (R2->E4) traffic occurs before thread links are synced given the linear topology R1/L - R2 - R3- E4.

Observations:
1) For the multicast Link Request from R3 when it newly becomes Router, R2 fails to process it here
https://github.com/openthread/openthread/blob/ebb2fd53efe465fc253dd884794d909836070311/src/core/thread/mle_router.cpp#L604

It is because R2 hasn't get the updated route info from Leader yet (Leader resets the advertise trickle timer, the first MLE advertisement happens around 1s after leader allocates router id for R3), while R3 send multicast Link Request immediately after receiving the a/as response.

2) routing info not established between R3 and Leader. In some failing runs, noticing that

• R3 may not forward a/aq and not send a/an
• R3 may resend a/an as it doesn't receive ack for the first a/an
• Leader may still drop the ping after acked a/an from R3

5776 introduces some time delay to allow route info propagation before ping for now.

However there should be general issues for linear topology,
a) new router(R3) knows the latest active routers (via a/as response) earlier than its attaching parent (R2) which should wait MLE advertisement
b) the initial application traffic for the newly attached device may fail as the route information might not be propagated fully yet. the time required depends on the topology.

It seems to me the simple intuitive suggestion is just wait for application on top of linear topology.

Thoughts?

@jwhui @bukepo

[bukepo]

Fixed by #5776

[jwhui]

It appears intermittent failures are still occuring:

https://github.com/openthread/openthread/runs/1380481216

logs_37203.zip

# 1 rcp
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-posix-1.1/src/posix/ot-cli spinel+hdlc+uart:///home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/ncp/ot-rcp?forkpty-arg=1
routerselectionjitter 1
Done

> panid 0xface
Done

> ifconfig up
Done

> thread start
Done

> state
detached

Done

> state
detached

Done

> state
detached

Done

> state
leader

Done

> extaddr
1ada4bd496a8877a

Done

> 
# 2 cli
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/cli/ot-cli-ftd 2
routerselectionjitter 1
Done
> panid 0xface
Done
> ifconfig up
Done
> thread start
Done
> state
detached
Done
> state
detached
Done
> state
child
Done
> state
router
Done
> 
# 3 cli
spawn /home/runner/work/openthread/openthread/build/cmake/openthread-simulation-1.1/examples/apps/cli/ot-cli-ftd 3
routerselectionjitter 1
expect version 5.45.4
argv[0] = expect  argv[1] = -df  argv[2] = tests/scripts/expect/tun-realm-local-multicast.exp  
FAIL tests/scripts/expect/tun-realm-local-multicast.exp
set argc 0
set argv0 "tests/scripts/expect/tun-realm-local-multicast.exp"
set argv ""
executing commands from command file tests/scripts/expect/tun-realm-local-multicast.exp
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {18853}
send: sending "routerselectionjitter 1\n" to { exp3 }

expect: does "" (spawn_id exp3) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "routerselectionjitter 1\r\nDone"
send: sending "panid 0xface\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> panid 0xface\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> panid 0xface\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> panid 0xface\r\nDone"
send: sending "ifconfig up\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> ifconfig up\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> ifconfig up\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> ifconfig up\r\nDone"
send: sending "thread start\n" to { exp3 }

expect: does "\r\r\n> " (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\n> thread start\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> thread start\r\nDone"
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp3 }
Gate keeper glob pattern for 'leader' is 'leader'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\nleader\r\r\nDone\r\r\n> " (spawn_id exp3) match regular expression "leader"? Gate "leader"? gate=yes re=yes
expect: set expect_out(0,string) "leader"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\ndetached\r\r\nDone\r\r\n> state\r\nleader"

expect: does "\r\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\nDone"
send: sending "extaddr\n" to { exp3 }
Gate keeper glob pattern for '([0-9a-fA-F]{16})' is ''. Not usable, disabling the performance booster.

expect: does "\r\r\n> " (spawn_id exp3) match regular expression "([0-9a-fA-F]{16})"? (No Gate, RE only) gate=yes re=no

expect: does "\r\r\n> extaddr\r\n1ada4bd496a8877a\r\r\n" (spawn_id exp3) match regular expression "([0-9a-fA-F]{16})"? (No Gate, RE only) gate=yes re=yes
expect: set expect_out(0,string) "1ada4bd496a8877a"
expect: set expect_out(1,string) "1ada4bd496a8877a"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\n> extaddr\r\n1ada4bd496a8877a"

expect: does "\r\r\n" (spawn_id exp3) match glob pattern "Done"? no

expect: does "\r\r\nDone\r\r\n> " (spawn_id exp3) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp3"
expect: set expect_out(buffer) "\r\r\nDone"
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {18870}
send: sending "routerselectionjitter 1\n" to { exp6 }

expect: does "" (spawn_id exp6) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "routerselectionjitter 1\r\nDone"
send: sending "panid 0xface\n" to { exp6 }

expect: does "\r\n> " (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> panid 0xface\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> panid 0xface\r\nDone"
send: sending "ifconfig up\n" to { exp6 }

expect: does "\r\n> " (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> i" (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> ifconfig up\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> ifconfig up\r\nDone"
send: sending "thread start\n" to { exp6 }

expect: does "\r\n> " (spawn_id exp6) match glob pattern "Done"? no

expect: does "\r\n> thread start\r\nDone\r\n> " (spawn_id exp6) match glob pattern "Done"? yes
expect: set expect_out(0,string) "Done"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> thread start\r\nDone"
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> s" (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no
expect: timed out
send: sending "state\n" to { exp6 }
Gate keeper glob pattern for 'router' is 'router'. Activating booster.
Gate keeper glob pattern for '[\r\n]FAILURE_NOT_EXPECTED[\r\n]' is '?FAILURE_NOT_EXPECTED?'. Activating booster.

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=no
"[\r\n]FAILURE_NOT_EXPECTED[\r\n]"? Gate "?FAILURE_NOT_EXPECTED?"? gate=no

expect: does "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> state\r\nrouter\r\nDone\r\n> " (spawn_id exp6) match regular expression "router"? Gate "router"? gate=yes re=yes
expect: set expect_out(0,string) "router"
expect: set expect_out(spawn_id) "exp6"
expect: set expect_out(buffer) "\r\n> state\r\ndetached\r\nDone\r\n> state\r\ndetached\r\nDone\r\n> state\r\nchild\r\nDone\r\n> state\r\nrouter"
parent: waiting for sync byte
parent: telling child to go ahead
parent: now unsynchronized from child
spawn: returns {18880}
send: sending "routerselectionjitter 1\n" to { exp7 }

expect: does "" (spawn_id exp7) match glob pattern "Done"? no

expect: does "routerselectionjitter 1\r\n" (spawn_id exp7) match glob pattern "Done"? no
expect: timed out
Error: Process completed with exit code 1.

[librasungirl]

Updated the test script and will submit after more runs of local verification.

[librasungirl]

5821 is submitted after all ( >500 runs) pass over ~ 3 hours