From b406880bf31f8f218d84e0dc662385c196aec6db Mon Sep 17 00:00:00 2001 From: Farshid Tavakolizadeh Date: Fri, 5 Jul 2024 10:50:08 +0300 Subject: [PATCH] Fix tests by changing log assertions (#69) * Fix time reference for log queries * Move "Upgrade snap" to a subtest so it doesn't run when a previous subtest fails in failfast mode * Set unique names for subtest logs to avoid overriding others * Update reference log message for the assertions - the SDK has changed the log prefixes * Remove obsolete log dump for chip tool, as it has no service that writes logs to the journal * The CHIP logs are now buffered. Change the assertions to seek a reference that is produced prior to the buffering of request handling debug info. * Comment out bluetooth setup on remote device in thread tests as bluetooth isn't needed. --- tests/common.go | 17 +++++++++++ tests/thread_tests/remote.go | 4 +-- tests/thread_tests/thread_test.go | 5 +++- tests/upgrade_test.go | 50 +++++++++++++------------------ tests/wifi_test.go | 17 ++++------- 5 files changed, 48 insertions(+), 45 deletions(-) diff --git a/tests/common.go b/tests/common.go index e3c26b0..7b65f4f 100644 --- a/tests/common.go +++ b/tests/common.go @@ -1,9 +1,13 @@ package tests import ( + "os" + "strings" "testing" + "time" "github.com/canonical/matter-snap-testing/utils" + "github.com/stretchr/testify/assert" "github.com/stretchr/testify/require" ) @@ -33,3 +37,16 @@ func InstallChipTool(t *testing.T) { utils.SnapConnect(t, chipToolSnap+":bluez", "") utils.SnapConnect(t, chipToolSnap+":process-control", "") } + +func writeLogFile(t *testing.T, label string, b []byte) { + assert.NoError(t, + os.WriteFile(strings.ReplaceAll(t.Name(), "/", "-")+"-"+label+".log", b, 0644), + ) +} + +func waitForOnOffHandlingByAllClustersApp(t *testing.T, start time.Time) { + // 0x6 is the Matter Cluster ID for on-off + // Using cluster ID here because of a buffering issue in the log stream: + // https://github.com/canonical/chip-tool-snap/pull/69#issuecomment-2207189962 + utils.WaitForLogMessage(t, allClustersSnap, "ClusterId = 0x6", start) +} diff --git a/tests/thread_tests/remote.go b/tests/thread_tests/remote.go index 67c672f..75370b3 100644 --- a/tests/thread_tests/remote.go +++ b/tests/thread_tests/remote.go @@ -119,12 +119,12 @@ func remote_deployAllClustersApp(t *testing.T) { start := time.Now().UTC() commands := []string{ - "sudo apt install bluez", + // "sudo apt install -y bluez", "sudo snap remove --purge matter-all-clusters-app", "sudo snap install matter-all-clusters-app --edge", "sudo snap set matter-all-clusters-app args='--thread'", "sudo snap connect matter-all-clusters-app:avahi-control", - "sudo snap connect matter-all-clusters-app:bluez", + // "sudo snap connect matter-all-clusters-app:bluez", "sudo snap connect matter-all-clusters-app:otbr-dbus-wpan0 openthread-border-router:dbus-wpan0", "sudo snap start matter-all-clusters-app", } diff --git a/tests/thread_tests/thread_test.go b/tests/thread_tests/thread_test.go index 2b54743..d770d81 100644 --- a/tests/thread_tests/thread_test.go +++ b/tests/thread_tests/thread_test.go @@ -30,7 +30,10 @@ func TestAllClustersAppThread(t *testing.T) { os.WriteFile("chip-tool-thread-onoff.log", []byte(stdout), 0644), ) - remote_waitForLogMessage(t, "matter-all-clusters-app", "CHIP:ZCL: Toggle ep1 on/off", start) + // 0x6 is the Matter Cluster ID for on-off + // Using cluster ID here because of a buffering issue in the log stream: + // https://github.com/canonical/chip-tool-snap/pull/69#issuecomment-2209530275 + remote_waitForLogMessage(t, "matter-all-clusters-app", "ClusterId = 0x6", start) }) } diff --git a/tests/upgrade_test.go b/tests/upgrade_test.go index 0f1c2eb..a008e82 100644 --- a/tests/upgrade_test.go +++ b/tests/upgrade_test.go @@ -1,23 +1,21 @@ package tests import ( - "github.com/canonical/matter-snap-testing/utils" - "github.com/stretchr/testify/assert" "log" - "os" "testing" "time" + + "github.com/canonical/matter-snap-testing/utils" ) func TestUpgrade(t *testing.T) { start := time.Now() - // Remove snaps and logs at end of test, even if it failed t.Cleanup(func() { utils.SnapRemove(nil, allClustersSnap) utils.SnapDumpLogs(nil, start, allClustersSnap) + utils.SnapRemove(nil, chipToolSnap) - utils.SnapDumpLogs(nil, start, chipToolSnap) }) // Start clean @@ -45,49 +43,41 @@ func TestUpgrade(t *testing.T) { utils.WaitForLogMessage(t, allClustersSnap, "CHIP minimal mDNS started advertising", start) - // Pair device t.Run("Commission", func(t *testing.T) { stdout, _, _ := utils.Exec(t, "sudo chip-tool pairing onnetwork 110 20202021 2>&1") - assert.NoError(t, - os.WriteFile("chip-tool-pairing.log", []byte(stdout), 0644), - ) + writeLogFile(t, "chip-tool-pairing", []byte(stdout)) }) - // Control device - t.Run("Control with stable snap", func(t *testing.T) { + t.Run("Control before upgrade", func(t *testing.T) { snapVersion := utils.SnapVersion(t, chipToolSnap) snapRevision := utils.SnapRevision(t, chipToolSnap) log.Printf("%s installed version %s build %s\n", chipToolSnap, snapVersion, snapRevision) - stdout, _, _ := utils.Exec(t, "sudo chip-tool onoff toggle 110 1 2>&1") - assert.NoError(t, - os.WriteFile("chip-tool-onoff.log", []byte(stdout), 0644), - ) + start := time.Now() + stdout, _, _ := utils.Exec(t, "sudo chip-tool onoff on 110 1 2>&1") + writeLogFile(t, "chip-tool-onoff", []byte(stdout)) - utils.WaitForLogMessage(t, - allClustersSnap, "CHIP:ZCL: Toggle ep1 on/off", start) + waitForOnOffHandlingByAllClustersApp(t, start) }) - // Upgrade chip-tool to local snap or edge - if utils.LocalServiceSnap() { - utils.SnapInstallFromFile(t, utils.LocalServiceSnapPath) - } else { - utils.SnapRefresh(t, chipToolSnap, "latest/edge") - } + t.Run("Upgrade snap", func(t *testing.T) { + if utils.LocalServiceSnap() { + utils.SnapInstallFromFile(t, utils.LocalServiceSnapPath) + } else { + utils.SnapRefresh(t, chipToolSnap, "latest/edge") + } + }) - // Control device again t.Run("Control upgraded snap", func(t *testing.T) { snapVersion := utils.SnapVersion(t, chipToolSnap) snapRevision := utils.SnapRevision(t, chipToolSnap) log.Printf("%s installed version %s build %s\n", chipToolSnap, snapVersion, snapRevision) - stdout, _, _ := utils.Exec(t, "sudo chip-tool onoff toggle 110 1 2>&1") - assert.NoError(t, - os.WriteFile("chip-tool-onoff.log", []byte(stdout), 0644), - ) + start := time.Now() + stdout, _, _ := utils.Exec(t, "sudo chip-tool onoff off 110 1 2>&1") + writeLogFile(t, "chip-tool-onoff", []byte(stdout)) - utils.WaitForLogMessage(t, - allClustersSnap, "CHIP:ZCL: Toggle ep1 on/off", start) + waitForOnOffHandlingByAllClustersApp(t, start) }) } diff --git a/tests/wifi_test.go b/tests/wifi_test.go index 35bbb54..5b63acc 100644 --- a/tests/wifi_test.go +++ b/tests/wifi_test.go @@ -1,12 +1,10 @@ package tests import ( - "os" "testing" "time" "github.com/canonical/matter-snap-testing/utils" - "github.com/stretchr/testify/assert" ) func TestAllClustersAppWiFi(t *testing.T) { @@ -19,11 +17,11 @@ func TestAllClustersAppWiFi(t *testing.T) { t.Cleanup(func() { utils.SnapRemove(t, allClustersSnap) - utils.SnapDumpLogs(nil, start, allClustersSnap) + utils.SnapDumpLogs(t, start, allClustersSnap) }) // Install all clusters app - utils.SnapInstallFromStore(t, allClustersSnap, utils.ServiceChannel) + utils.SnapInstallFromStore(t, allClustersSnap, "latest/edge") // Setup all clusters app utils.SnapSet(t, allClustersSnap, "args", "--wifi") @@ -37,19 +35,14 @@ func TestAllClustersAppWiFi(t *testing.T) { t.Run("Commission", func(t *testing.T) { stdout, _, _ := utils.Exec(t, "sudo chip-tool pairing onnetwork 110 20202021 2>&1") - assert.NoError(t, - os.WriteFile("chip-tool-pairing.log", []byte(stdout), 0644), - ) + writeLogFile(t, "chip-tool-pairing", []byte(stdout)) }) t.Run("Control", func(t *testing.T) { stdout, _, _ := utils.Exec(t, "sudo chip-tool onoff toggle 110 1 2>&1") - assert.NoError(t, - os.WriteFile("chip-tool-onoff.log", []byte(stdout), 0644), - ) + writeLogFile(t, "chip-tool-toggle", []byte(stdout)) - utils.WaitForLogMessage(t, - allClustersSnap, "CHIP:ZCL: Toggle ep1 on/off", start) + waitForOnOffHandlingByAllClustersApp(t, start) }) }