mirror of
https://github.com/tailscale/tailscale.git
synced 2026-09-16 07:52:22 -04:00
tsnet: deflake TestUserMetricsByteCounters
TestUserMetricsByteCounters is currently our top flake at http://flakes/ The test waited for a direct path between its two localhost nodes by polling s1's status until CurAddr was set, then asserted that the transferred bytes appeared in the path="direct_ipv4" counters. Both steps were flaky: - CurAddr is only reported while magicsock has a confirmed, currently trusted UDP address for the peer, which depends on a heartbeat ping and CallMeMaybe cycle that can lag arbitrarily under CI load. In the CI failure logs the transfer itself went direct and the byte counter assertions passed; the only failure was the polling helper's t.Error. - On a machine where localhost has both IPv4 and IPv6, magicsock can pick ::1 (it prefers IPv6 on latency ties), so the transfer lands in the direct_ipv6 counters instead. - If no direct path is established yet, the transfer goes over DERP, whose wire-byte total (relay framing, plus TCP retransmissions inside the tunnel under load) can exceed any fixed tolerance; one flakestress run counted 33% more than the payload sent. Drop the direct-path wait and the hardcoded path label, and assert the one invariant the test actually cares about: at least the number of bytes sent must be counted across all path counters combined. There is deliberately no upper bound, since the counters legitimately include overhead, retransmissions, and the duplicate copies magicsock sends on several paths while a direct path is being confirmed. Verified with flakestress: the old test failed within 7 runs, while the fixed test passed 33,521 runs with no failures. See http://flakes/analyze-test?name=tailscale.com%2ftsnet.TestUserMetricsByteCounters Updates #deflake Signed-off-by: Brad Fitzpatrick <bradfitz@tailscale.com> Change-Id: I4d8a9bfb9549ea9d8d33d3a3b55b4d03f9b9be78
This commit is contained in:
1 parent
5c939a8560
commit
daafc49acd
1 file changed
+27
-50
+27
-50
@@ -44,7 +44,6 @@
|
||||
"github.com/tailscale/wireguard-go/tun"
|
||||
"golang.org/x/net/proxy"
|
||||
|
||||
"tailscale.com/client/local"
|
||||
"tailscale.com/cmd/testwrapper/flakytest"
|
||||
"tailscale.com/internal/client/tailscale"
|
||||
"tailscale.com/ipn"
|
||||
@@ -2460,8 +2459,6 @@ func TestUserMetricsByteCounters(t *testing.T) {
|
||||
}
|
||||
t.Logf("ping success: %#+v", res)
|
||||
|
||||
mustDirect(t, t.Logf, lc1, lc2)
|
||||
|
||||
// 1 megabytes
|
||||
bytesToSend := 1 * 1024 * 1024
|
||||
|
||||
@@ -2486,21 +2483,14 @@ func TestUserMetricsByteCounters(t *testing.T) {
|
||||
t.Fatal(err)
|
||||
}
|
||||
|
||||
// Allow the metrics for the bytes sent to be off by 15%.
|
||||
bytesSentTolerance := 1.15
|
||||
|
||||
t.Logf("Metrics1:\n%s\n", metrics1)
|
||||
|
||||
// Verify that the amount of data recorded in bytes is higher or equal to the data sent
|
||||
inboundBytes1 := parsedMetrics1[`tailscaled_inbound_bytes_total{path="direct_ipv4"}`]
|
||||
if inboundBytes1 < float64(bytesToSend) {
|
||||
t.Errorf(`metrics1, tailscaled_inbound_bytes_total{path="direct_ipv4"}: expected higher (or equal) than %d, got: %f`, bytesToSend, inboundBytes1)
|
||||
}
|
||||
|
||||
// But ensure that it is not too much higher than the data sent.
|
||||
if inboundBytes1 > float64(bytesToSend)*bytesSentTolerance {
|
||||
t.Errorf(`metrics1, tailscaled_inbound_bytes_total{path="direct_ipv4"}: expected lower than %f, got: %f`, float64(bytesToSend)*bytesSentTolerance, inboundBytes1)
|
||||
}
|
||||
// The transferred bytes can be counted on any path: on a machine where
|
||||
// localhost has both IPv4 and IPv6, magicsock may pick either (it prefers
|
||||
// IPv6 on latency ties), and if no direct path has been established yet
|
||||
// the traffic rides DERP. So assert on the bytes recorded across all
|
||||
// paths rather than on a specific path label.
|
||||
checkBytesCounted(t, "metrics1", "tailscaled_inbound_bytes_total", parsedMetrics1, bytesToSend)
|
||||
|
||||
metrics2, err := lc2.UserMetrics(ctx)
|
||||
if err != nil {
|
||||
@@ -2514,16 +2504,7 @@ func TestUserMetricsByteCounters(t *testing.T) {
|
||||
|
||||
t.Logf("Metrics2:\n%s\n", metrics2)
|
||||
|
||||
// Verify that the amount of data recorded in bytes is higher or equal than the data sent.
|
||||
outboundBytes2 := parsedMetrics2[`tailscaled_outbound_bytes_total{path="direct_ipv4"}`]
|
||||
if outboundBytes2 < float64(bytesToSend) {
|
||||
t.Errorf(`metrics2, tailscaled_outbound_bytes_total{path="direct_ipv4"}: expected higher (or equal) than %d, got: %f`, bytesToSend, outboundBytes2)
|
||||
}
|
||||
|
||||
// But ensure that it is not too much higher than the data sent.
|
||||
if outboundBytes2 > float64(bytesToSend)*bytesSentTolerance {
|
||||
t.Errorf(`metrics2, tailscaled_outbound_bytes_total{path="direct_ipv4"}: expected lower than %f, got: %f`, float64(bytesToSend)*bytesSentTolerance, outboundBytes2)
|
||||
}
|
||||
checkBytesCounted(t, "metrics2", "tailscaled_outbound_bytes_total", parsedMetrics2, bytesToSend)
|
||||
}
|
||||
|
||||
func TestUserMetricsRouteGauges(t *testing.T) {
|
||||
@@ -2652,34 +2633,30 @@ func waitForCondition(t *testing.T, msg string, waitTime time.Duration, f func()
|
||||
t.Fatalf("waiting for condition: %s", msg)
|
||||
}
|
||||
|
||||
// mustDirect ensures there is a direct connection between LocalClient 1 and 2
|
||||
func mustDirect(t *testing.T, logf logger.Logf, lc1, lc2 *local.Client) {
|
||||
// checkBytesCounted verifies that the labeled byte counter metric (for
|
||||
// example tailscaled_inbound_bytes_total, which carries a path label)
|
||||
// accounted for a transfer of bytesToSend bytes: at least bytesToSend
|
||||
// bytes must be counted across all paths combined.
|
||||
//
|
||||
// There is deliberately no upper bound. The counters record wire bytes,
|
||||
// which legitimately exceed the payload (WireGuard overhead, relay
|
||||
// framing, TCP retransmissions inside the tunnel under load, and the
|
||||
// several copies of each packet that magicsock sends while a direct path
|
||||
// is still being confirmed), and none of that variance is a bug in the
|
||||
// counters. A payload byte that fails to appear is.
|
||||
func checkBytesCounted(t *testing.T, label, metric string, parsed map[string]float64, bytesToSend int) {
|
||||
t.Helper()
|
||||
lastLog := time.Now().Add(-time.Minute)
|
||||
// See https://github.com/tailscale/tailscale/issues/654
|
||||
// and https://github.com/tailscale/tailscale/issues/3247 for discussions of this deadline.
|
||||
for deadline := time.Now().Add(30 * time.Second); time.Now().Before(deadline); time.Sleep(10 * time.Millisecond) {
|
||||
ctx, cancel := context.WithTimeout(context.Background(), 5*time.Second)
|
||||
defer cancel()
|
||||
status1, err := lc1.Status(ctx)
|
||||
if err != nil {
|
||||
prefix := metric + `{path="`
|
||||
var total float64
|
||||
for k, v := range parsed {
|
||||
if _, ok := strings.CutPrefix(k, prefix); !ok {
|
||||
continue
|
||||
}
|
||||
status2, err := lc2.Status(ctx)
|
||||
if err != nil {
|
||||
continue
|
||||
}
|
||||
pst := status1.Peer[status2.Self.PublicKey]
|
||||
if pst.CurAddr != "" {
|
||||
logf("direct link %s->%s found with addr %s", status1.Self.HostName, status2.Self.HostName, pst.CurAddr)
|
||||
return
|
||||
}
|
||||
if now := time.Now(); now.Sub(lastLog) > time.Second {
|
||||
logf("no direct path %s->%s yet, addrs %v", status1.Self.HostName, status2.Self.HostName, pst.Addrs)
|
||||
lastLog = now
|
||||
}
|
||||
total += v
|
||||
}
|
||||
if total < float64(bytesToSend) {
|
||||
t.Errorf("%s: %s counted %f bytes across all paths, want at least %d", label, metric, total, bytesToSend)
|
||||
}
|
||||
t.Error("magicsock did not find a direct path from lc1 to lc2")
|
||||
}
|
||||
|
||||
// chanTUN is a tun.Device for testing that uses channels for packet I/O.
|
||||
|
||||
Reference in new issue
Block a user