1
0
mirror of https://github.com/juanfont/headscale.git synced 2025-09-16 17:50:44 +02:00

integration: make timestamp const

Signed-off-by: Kristoffer Dalby <kristoffer@tailscale.com>
This commit is contained in:
Kristoffer Dalby 2025-09-08 11:18:42 +02:00 committed by Kristoffer Dalby
parent 476f30ab20
commit 4893cdac74
5 changed files with 42 additions and 29 deletions

View File

@ -592,7 +592,7 @@ func TestOIDCReloginSameNodeNewUser(t *testing.T) {
assertNoErr(t, err)
t.Logf("Logged out take one")
t.Log("timestamp: " + time.Now().Format("2006-01-02T15-04-05.999999999") + "\n")
t.Log("timestamp: " + time.Now().Format(TimestampFormat) + "\n")
// TODO(kradalby): Not sure why we need to logout twice, but it fails and
// logs in immediately after the first logout and I cannot reproduce it
@ -601,7 +601,7 @@ func TestOIDCReloginSameNodeNewUser(t *testing.T) {
assertNoErr(t, err)
t.Logf("Logged out take two")
t.Log("timestamp: " + time.Now().Format("2006-01-02T15-04-05.999999999") + "\n")
t.Log("timestamp: " + time.Now().Format(TimestampFormat) + "\n")
// Wait for logout to complete and then do second logout
assert.EventuallyWithT(t, func(ct *assert.CollectT) {
@ -627,7 +627,7 @@ func TestOIDCReloginSameNodeNewUser(t *testing.T) {
}, 30*time.Second, 1*time.Second)
t.Logf("Logged back in")
t.Log("timestamp: " + time.Now().Format("2006-01-02T15-04-05.999999999") + "\n")
t.Log("timestamp: " + time.Now().Format(TimestampFormat) + "\n")
assert.EventuallyWithT(t, func(ct *assert.CollectT) {
listUsers, err := headscale.ListUsers()

View File

@ -10,6 +10,12 @@ import (
"github.com/ory/dockertest/v3"
)
const (
// TimestampFormatRunID is used for generating unique run identifiers
// Format: "20060102-150405" provides compact date-time for file/directory names.
TimestampFormatRunID = "20060102-150405"
)
// GetIntegrationRunID returns the run ID for the current integration test session.
// This is set by the hi tool and passed through environment variables.
func GetIntegrationRunID() string {
@ -36,7 +42,7 @@ func DockerAddIntegrationLabels(opts *dockertest.RunOptions, testType string) {
// Format: YYYYMMDD-HHMMSS-HASH (e.g., 20250619-143052-a1b2c3).
func GenerateRunID() string {
now := time.Now()
timestamp := now.Format("20060102-150405")
timestamp := now.Format(TimestampFormatRunID)
// Add a short random hash to ensure uniqueness
randomHash := util.MustGenerateRandomStringDNSSafe(6)

View File

@ -1009,7 +1009,7 @@ func TestPingAllByIPManyUpDown(t *testing.T) {
t.Logf("%d successful pings out of %d", success, len(allClients)*len(allIps))
for run := range 3 {
t.Logf("Starting DownUpPing run %d at %s", run+1, time.Now().Format("2006-01-02T15-04-05.999999999"))
t.Logf("Starting DownUpPing run %d at %s", run+1, time.Now().Format(TimestampFormat))
// Create fresh errgroup with timeout for each run
ctx, cancel := context.WithTimeout(context.Background(), 30*time.Second)
@ -1026,7 +1026,7 @@ func TestPingAllByIPManyUpDown(t *testing.T) {
if err := wg.Wait(); err != nil {
t.Fatalf("failed to take down all nodes: %s", err)
}
t.Logf("All nodes taken down at %s", time.Now().Format("2006-01-02T15-04-05.999999999"))
t.Logf("All nodes taken down at %s", time.Now().Format(TimestampFormat))
// After taking down all nodes, verify all systems show nodes offline
requireAllClientsOnline(t, headscale, expectedNodes, false, fmt.Sprintf("Run %d: all nodes should be offline after Down()", run+1), 120*time.Second)
@ -1042,7 +1042,7 @@ func TestPingAllByIPManyUpDown(t *testing.T) {
if err := wg.Wait(); err != nil {
t.Fatalf("failed to bring up all nodes: %s", err)
}
t.Logf("All nodes brought up at %s", time.Now().Format("2006-01-02T15-04-05.999999999"))
t.Logf("All nodes brought up at %s", time.Now().Format(TimestampFormat))
// After bringing up all nodes, verify batcher shows all reconnected
requireAllClientsOnline(t, headscale, expectedNodes, true, fmt.Sprintf("Run %d: all nodes should be reconnected after Up()", run+1), 120*time.Second)
@ -1051,7 +1051,7 @@ func TestPingAllByIPManyUpDown(t *testing.T) {
err = scenario.WaitForTailscaleSync()
assert.NoError(t, err)
t.Logf("All nodes synced up %s", time.Now().Format("2006-01-02T15-04-05.999999999"))
t.Logf("All nodes synced up %s", time.Now().Format(TimestampFormat))
requireAllClientsOnline(t, headscale, expectedNodes, true, fmt.Sprintf("Run %d: all systems should show nodes online after reconnection", run+1), 60*time.Second)
@ -1184,7 +1184,7 @@ func requireAllClientsOnline(t *testing.T, headscale ControlServer, expectedNode
t.Helper()
startTime := time.Now()
t.Logf("requireAllSystemsOnline: Starting validation at %s - %s", startTime.Format("2006-01-02T15:04:05.000"), message)
t.Logf("requireAllSystemsOnline: Starting validation at %s - %s", startTime.Format(TimestampFormat), message)
var prevReport string
require.EventuallyWithT(t, func(c *assert.CollectT) {
@ -1306,11 +1306,11 @@ func requireAllClientsOnline(t *testing.T, headscale ControlServer, expectedNode
t.Log("Diff between reports:")
t.Logf("Prev report: \n%s\n", prevReport)
t.Logf("New report: \n%s\n", failureReport.String())
t.Log("timestamp: " + time.Now().Format("2006-01-02T15-04-05.999999999") + "\n")
t.Log("timestamp: " + time.Now().Format(TimestampFormat) + "\n")
prevReport = failureReport.String()
}
failureReport.WriteString("timestamp: " + time.Now().Format("2006-01-02T15-04-05.999999999") + "\n")
failureReport.WriteString("timestamp: " + time.Now().Format(TimestampFormat) + "\n")
assert.Fail(c, failureReport.String())
}
@ -1324,5 +1324,5 @@ func requireAllClientsOnline(t *testing.T, headscale ControlServer, expectedNode
endTime := time.Now()
duration := endTime.Sub(startTime)
t.Logf("requireAllSystemsOnline: Completed validation at %s - Duration: %v - %s", endTime.Format("2006-01-02T15:04:05.000"), duration, message)
t.Logf("requireAllSystemsOnline: Completed validation at %s - Duration: %v - %s", endTime.Format(TimestampFormat), duration, message)
}

View File

@ -34,8 +34,6 @@ import (
"tailscale.com/wgengine/filter"
)
const timestampFormat = "15:04:05.000"
var allPorts = filter.PortRange{First: 0, Last: 0xffff}
// This test is both testing the routes command and the propagation of
@ -305,7 +303,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
t.Logf("%s (%s) picked as client", client.Hostname(), client.MustID())
t.Logf("=== Initial Route Advertisement - Setting up HA configuration with 3 routers ===")
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" - Router 1 (%s): Advertising route %s - will become PRIMARY when approved", subRouter1.Hostname(), pref.String())
t.Logf(" - Router 2 (%s): Advertising route %s - will be STANDBY when approved", subRouter2.Hostname(), pref.String())
t.Logf(" - Router 3 (%s): Advertising route %s - will be STANDBY when approved", subRouter3.Hostname(), pref.String())
@ -363,7 +361,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Helper function to check test failure and print route map if needed
checkFailureAndPrintRoutes := func(t *testing.T, client TailscaleClient) {
if t.Failed() {
t.Logf("[%s] Test failed at this checkpoint", time.Now().Format(timestampFormat))
t.Logf("[%s] Test failed at this checkpoint", time.Now().Format(TimestampFormat))
status, err := client.Status()
if err == nil {
printCurrentRouteMap(t, xmaps.Values(status.Peer)...)
@ -382,7 +380,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Enable route on node 1
t.Logf("=== Approving route on router 1 (%s) - Single router mode (no HA yet) ===", subRouter1.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Expected: Router 1 becomes PRIMARY with route %s active", pref.String())
t.Logf(" Expected: Routers 2 & 3 remain with advertised but unapproved routes")
t.Logf(" Expected: Client can access webservice through router 1 only")
@ -445,7 +443,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
}, propagationTime, 200*time.Millisecond, "Verifying Router 1 is PRIMARY with routes after approval")
t.Logf("=== Validating connectivity through PRIMARY router 1 (%s) to webservice at %s ===", must.Get(subRouter1.IPv4()).String(), webip.String())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Expected: Traffic flows through router 1 as it's the only approved route")
assert.EventuallyWithT(t, func(c *assert.CollectT) {
result, err := client.Curl(weburl)
@ -478,7 +476,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Enable route on node 2, now we will have a HA subnet router
t.Logf("=== Enabling High Availability by approving route on router 2 (%s) ===", subRouter2.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 is PRIMARY and actively serving traffic")
t.Logf(" Expected: Router 2 becomes STANDBY (approved but not primary)")
t.Logf(" Expected: Router 1 remains PRIMARY (no flapping - stability preferred)")
@ -556,7 +554,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
checkFailureAndPrintRoutes(t, client)
t.Logf("=== Validating HA configuration - Router 1 PRIMARY, Router 2 STANDBY ===")
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current routing: Traffic through router 1 (%s) to %s", must.Get(subRouter1.IPv4()), webip.String())
t.Logf(" Expected: Router 1 continues to handle all traffic (no change from before)")
t.Logf(" Expected: Router 2 is ready to take over if router 1 fails")
@ -593,7 +591,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Enable route on node 3, now we will have a second standby and all will
// be enabled.
t.Logf("=== Adding second STANDBY router by approving route on router 3 (%s) ===", subRouter3.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 PRIMARY, Router 2 STANDBY")
t.Logf(" Expected: Router 3 becomes second STANDBY (approved but not primary)")
t.Logf(" Expected: Router 1 remains PRIMARY, Router 2 remains first STANDBY")
@ -699,7 +697,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Take down the current primary
t.Logf("=== FAILOVER TEST: Taking down PRIMARY router 1 (%s) ===", subRouter1.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 PRIMARY (serving traffic), Router 2 & 3 STANDBY")
t.Logf(" Action: Shutting down router 1 to simulate failure")
t.Logf(" Expected: Router 2 (%s) should automatically become new PRIMARY", subRouter2.Hostname())
@ -777,7 +775,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Take down subnet router 2, leaving none available
t.Logf("=== FAILOVER TEST: Taking down NEW PRIMARY router 2 (%s) ===", subRouter2.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 OFFLINE, Router 2 PRIMARY (serving traffic), Router 3 STANDBY")
t.Logf(" Action: Shutting down router 2 to simulate cascading failure")
t.Logf(" Expected: Router 3 (%s) should become new PRIMARY (last remaining router)", subRouter3.Hostname())
@ -847,7 +845,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Bring up subnet router 1, making the route available from there.
t.Logf("=== RECOVERY TEST: Bringing router 1 (%s) back online ===", subRouter1.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 OFFLINE, Router 2 OFFLINE, Router 3 PRIMARY (only router)")
t.Logf(" Action: Starting router 1 to restore HA capability")
t.Logf(" Expected: Router 3 remains PRIMARY (stability - no unnecessary failover)")
@ -925,7 +923,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Bring up subnet router 2, should result in no change.
t.Logf("=== FULL RECOVERY TEST: Bringing router 2 (%s) back online ===", subRouter2.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 STANDBY, Router 2 OFFLINE, Router 3 PRIMARY")
t.Logf(" Action: Starting router 2 to restore full HA (3 routers)")
t.Logf(" Expected: Router 3 (%s) remains PRIMARY (stability - avoid unnecessary failovers)", subRouter3.Hostname())
@ -1004,7 +1002,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
checkFailureAndPrintRoutes(t, client)
t.Logf("=== ROUTE DISABLE TEST: Removing approved route from PRIMARY router 3 (%s) ===", subRouter3.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 STANDBY, Router 2 STANDBY, Router 3 PRIMARY")
t.Logf(" Action: Disabling route approval on router 3 (route still advertised but not approved)")
t.Logf(" Expected: Router 1 (%s) should become new PRIMARY (lowest ID with approved route)", subRouter1.Hostname())
@ -1090,7 +1088,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Disable the route of subnet router 1, making it failover to 2
t.Logf("=== ROUTE DISABLE TEST: Removing approved route from NEW PRIMARY router 1 (%s) ===", subRouter1.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 PRIMARY, Router 2 STANDBY, Router 3 advertised-only")
t.Logf(" Action: Disabling route approval on router 1")
t.Logf(" Expected: Router 2 (%s) should become new PRIMARY (only remaining approved route)", subRouter2.Hostname())
@ -1176,7 +1174,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// enable the route of subnet router 1, no change expected
t.Logf("=== ROUTE RE-ENABLE TEST: Re-approving route on router 1 (%s) ===", subRouter1.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 advertised-only, Router 2 PRIMARY, Router 3 advertised-only")
t.Logf(" Action: Re-enabling route approval on router 1")
t.Logf(" Expected: Router 2 (%s) remains PRIMARY (stability - no unnecessary flapping)", subRouter2.Hostname())
@ -1260,7 +1258,7 @@ func TestHASubnetRouterFailover(t *testing.T) {
// Enable route on node 3, we now have all routes re-enabled
t.Logf("=== ROUTE RE-ENABLE TEST: Re-approving route on router 3 (%s) - Full HA Restoration ===", subRouter3.Hostname())
t.Logf("[%s] Starting test section", time.Now().Format(timestampFormat))
t.Logf("[%s] Starting test section", time.Now().Format(TimestampFormat))
t.Logf(" Current state: Router 1 STANDBY, Router 2 PRIMARY, Router 3 advertised-only")
t.Logf(" Action: Re-enabling route approval on router 3")
t.Logf(" Expected: Router 2 (%s) remains PRIMARY (stability preferred)", subRouter2.Hostname())

View File

@ -28,6 +28,15 @@ const (
// derpPingCount defines the number of ping attempts for DERP connectivity tests
// Higher count provides better reliability assessment of DERP connectivity.
derpPingCount = 10
// TimestampFormat is the standard timestamp format used across all integration tests
// Format: "2006-01-02T15-04-05.999999999" provides high precision timestamps
// suitable for debugging and log correlation in integration tests.
TimestampFormat = "2006-01-02T15-04-05.999999999"
// TimestampFormatRunID is used for generating unique run identifiers
// Format: "20060102-150405" provides compact date-time for file/directory names.
TimestampFormatRunID = "20060102-150405"
)
func assertNoErr(t *testing.T, err error) {