Fix tests by changing log assertions #69
Merged
Conversation
This file contains bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
|
The journal doesn't report logs from when the Matter request is received up until when the stop signal is sent (starting from 16:26:22 in the logs below). The CHIP logs timestamp show that the logs are produced on time but the journal does not receive them. Strangely, this only sometimes happens and in the TestAllClustersApp, but not the TestUpgrade. Adding a 30 seconds delay in tests did not help either. |
|
Everyone contributing to this PR have now signed the CLA. Thanks! |
farshidtz
changed the title
jpm-canonical
requested changes
Jul 4, 2024
|
Using this branch, running the tests in the naive way, using the command provided in the readme, fails. |
|
@jpm-canonical so I believe the other instances of asserting the log message should be replaced with checking the cluster ID. |
jpm-canonical
requested changes
Jul 4, 2024
|
Similar issue in thread tests: Failing tests: |
|
Thread tests: $ LOCAL_INFRA_IF="enp2s0" REMOTE_INFRA_IF="eth0" REMOTE_USER="ubuntu" REMOTE_PASSWORD="raspberry" REMOTE_HOST="192.168.1.24" go test -v -failfast -count 1 ./thread_tests
=== RUN TestAllClustersAppThread
snap.go:62: [exec] sudo snap remove --purge chip-tool
exec.go:140: [stderr] snap "chip-tool" is not installed
2024/07/04 22:26:18 [exec] sudo snap install chip-tool --channel=latest/edge
2024/07/04 22:26:21 [stdout] chip-tool (edge) cde0b92d+snap from Canonical IoT Labs installed
snap.go:81: [exec] sudo snap connect chip-tool:avahi-observe
snap.go:81: [exec] sudo snap connect chip-tool:bluez
snap.go:81: [exec] sudo snap connect chip-tool:process-control
snap.go:62: [exec] sudo snap remove --purge openthread-border-router
exec.go:140: [stderr] snap "openthread-border-router" is not installed
snap.go:28: [exec] sudo snap install openthread-border-router --channel=latest/edge
exec.go:140: [stdout] openthread-border-router (edge) thread-reference-20230710+snap from Canonical IoT Labs installed
2024/07/04 22:26:26 [exec] sudo snap connect openthread-border-router:avahi-control
2024/07/04 22:26:27 [exec] sudo snap connect openthread-border-router:firewall-control
2024/07/04 22:26:27 [exec] sudo snap connect openthread-border-router:raw-usb
2024/07/04 22:26:28 [exec] sudo snap connect openthread-border-router:network-control
2024/07/04 22:26:29 [exec] sudo snap connect openthread-border-router:bluetooth-control
2024/07/04 22:26:30 [exec] sudo snap connect openthread-border-router:bluez
2024/07/04 22:26:31 [exec] sudo snap set openthread-border-router infra-if='enp2s0'
2024/07/04 22:26:31 [exec] sudo snap set openthread-border-router radio-url='spinel+hdlc+uart:///dev/ttyACM0'
snap.go:161: [exec] sudo snap start --enable openthread-border-router
exec.go:140: [stdout] Started.
local.go:76: Retry 1/10: Waiting for expected content in logs: Start Thread Border Agent: OK
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
local.go:80: Found expected content in logs: Start Thread Border Agent: OK
local.go:55: [exec] sudo openthread-border-router.ot-ctl dataset init new
local.go:56: [exec] sudo openthread-border-router.ot-ctl dataset commit active
local.go:57: [exec] sudo openthread-border-router.ot-ctl ifconfig up
local.go:58: [exec] sudo openthread-border-router.ot-ctl thread start
config.go:59: Retry 1/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 2/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 3/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 4/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 5/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 6/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 7/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:59: Retry 8/10: Waiting for expected content in logs: Thread Network
snap.go:138: [exec] sudo journalctl --since "2024-07-04 22:26:31" --no-pager | grep "openthread-border-router"|| true
config.go:63: Found expected content in logs: Thread Network
local.go:63: [exec] sudo openthread-border-router.ot-ctl dataset active -x | awk '{print $NF}' | grep --invert-match "Done"
remote.go:81: SSH: connected to 192.168.1.24
remote.go:106: [exec-ssh] sudo snap remove --purge openthread-border-router
remote.go:106: [exec-ssh] sudo snap install openthread-border-router --edge
remote.go:106: [exec-ssh] sudo snap set openthread-border-router infra-if='eth0'
remote.go:106: [exec-ssh] sudo snap set openthread-border-router radio-url='spinel+hdlc+uart:///dev/ttyACM0'
remote.go:106: [exec-ssh] sudo snap connect openthread-border-router:firewall-control
remote.go:106: [exec-ssh] sudo snap connect openthread-border-router:raw-usb
remote.go:106: [exec-ssh] sudo snap connect openthread-border-router:network-control
remote.go:106: [exec-ssh] sudo snap start openthread-border-router
remote.go:109: Retry 1/10: Waiting for expected content in logs: 'Start Thread Border Agent: OK'
remote.go:109: [exec-ssh] sudo journalctl --utc --since "2024-07-04 20:26:42" --no-pager | grep "openthread-border-router"|| true
remote.go:109: Found expected content in logs: 'Start Thread Border Agent: OK'
remote.go:110: OTBR on remote device is ready
remote.go:132: [exec-ssh] sudo snap remove --purge matter-all-clusters-app
remote.go:132: [exec-ssh] sudo snap install matter-all-clusters-app --edge
remote.go:132: [exec-ssh] sudo snap set matter-all-clusters-app args='--thread'
remote.go:132: [exec-ssh] sudo snap connect matter-all-clusters-app:avahi-control
remote.go:132: [exec-ssh] sudo snap connect matter-all-clusters-app:otbr-dbus-wpan0 openthread-border-router:dbus-wpan0
remote.go:132: [exec-ssh] sudo snap start matter-all-clusters-app
remote.go:135: Retry 1/10: Waiting for expected content in logs: 'CHIP minimal mDNS started advertising'
remote.go:135: [exec-ssh] sudo journalctl --utc --since "2024-07-04 20:26:56" --no-pager | grep "matter-all-clusters-app"|| true
remote.go:135: Found expected content in logs: 'CHIP minimal mDNS started advertising'
remote.go:136: Matter All Clusters App is ready
=== RUN TestAllClustersAppThread/Commission
thread_test.go:20: [exec] sudo chip-tool pairing code-thread 110 hex:0e080000000000010000000300001335060004001fffe00208656c2f1b40199e910708fd417409cd1004560510c2c69eebfe413338285161957078bed1030f4f70656e5468726561642d3362353101023b510410dfa02658645e6f8da538d5dd39d6ec590c0402a0f7f8 34970112332 2>&1
=== RUN TestAllClustersAppThread/Control
thread_test.go:28: [exec] sudo chip-tool onoff toggle 110 1 2>&1
thread_test.go:36: Retry 1/10: Waiting for expected content in logs: 'ClusterId = 0x6'
thread_test.go:36: [exec-ssh] sudo journalctl --utc --since "2024-07-04 20:27:06" --no-pager | grep "matter-all-clusters-app"|| true
thread_test.go:36: Found expected content in logs: 'ClusterId = 0x6'
=== NAME TestAllClustersAppThread
remote.go:116: [exec-ssh] sudo snap remove --purge matter-all-clusters-app
remote.go:87: [exec-ssh] sudo snap remove --purge openthread-border-router
snap.go:62: [exec] sudo snap remove --purge openthread-border-router
exec.go:140: [stdout] openthread-border-router removed
snap.go:62: [exec] sudo snap remove --purge chip-tool
exec.go:140: [stdout] chip-tool removed
--- PASS: TestAllClustersAppThread (76.01s)
--- PASS: TestAllClustersAppThread/Commission (1.02s)
--- PASS: TestAllClustersAppThread/Control (1.44s)
PASS
ok chip-tool-snap-tests/thread_tests 76.012s |
|
Standard tests run successfully: Thread test runs successfully: |
jpm-canonical
approved these changes
Jul 5, 2024
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
Summary