diff --git a/PLAN.md b/PLAN.md index 848fd79..4bcc5f5 100644 --- a/PLAN.md +++ b/PLAN.md @@ -611,10 +611,17 @@ Decisions worth keeping: in, it reported 31 ms for a 7 ms line. Jitter is the mean change between consecutive probes, not a standard deviation, so one slow probe doesn't run away with it. - **A refused phase is not a number.** The far end rate-limits by volume, and a test moves a - few hundred megabytes; several in a row earn 429s. So: a 20-second cooldown between tests, - a stream that retries twice before giving up, the rate computed over the window in which - bytes were actually still arriving, and a plain sentence when it was cut short. Coasting to - the end of the clock with nothing arriving reported a third of the truth. + few hundred megabytes; several in a row earn 429s, and the block observed while building this + lasted over twenty minutes. So: a 20-second cooldown counted from the last *attempt* (a + refused test still used the line), a stream that retries twice before giving up, the rate + computed over the window in which bytes were actually still arriving, and a plain sentence + when it was cut short. Coasting to the end of the clock with nothing arriving reported a + third of the truth. +- **A second download source, for when the first refuses.** A plain 100 MB file on Linode's + Seattle mirror, which has no opinion about volume. It is only reached after a refusal, and + every result names the source it used — that mirror is in one place, so on a machine far from + Seattle it would read low, and a number that quietly came from somewhere else would be a lie. + Upload stays on Cloudflare, which has never been the one to refuse. - **The last result is published as sensors** (`net.internet.*`), so the line is a widget, a graph, an alert or a Prometheus series like anything else. Each carries the time the test ran, not the time it was asked for. diff --git a/internal/network/network_test.go b/internal/network/network_test.go index b962114..3a7eec2 100644 --- a/internal/network/network_test.go +++ b/internal/network/network_test.go @@ -8,7 +8,6 @@ import ( "net/http" "net/http/httptest" "os" - "strings" "sync/atomic" "testing" "time" @@ -180,16 +179,16 @@ func TestPhaseMeasuresTheWindow(t *testing.T) { })) defer srv.Close() - restore := func(u, up string, w, d, mw time.Duration, m int64) { - downURL, upURL, warmUp, downFor, minWindow, measureBytes = u, up, w, d, mw, m - } - defer restore(downURL, upURL, warmUp, downFor, minWindow, measureBytes) - downURL, upURL = srv.URL+"/down?bytes=%d", srv.URL+"/up" + defer func(up string, w, d, mw time.Duration, m int64) { + upURL, warmUp, downFor, minWindow, measureBytes = up, w, d, mw, m + }(upURL, warmUp, downFor, minWindow, measureBytes) + upURL = srv.URL + "/up" warmUp, downFor, minWindow, measureBytes = 100*time.Millisecond, 3*time.Second, 200*time.Millisecond, 8<<20 + here := Source{"local", func(int) string { return srv.URL + "/down" }} tr := NewTester(nil) began := time.Now() - mbps, moved, note, err := tr.phase(context.Background(), srv.Client(), "download", 2, downFor, 0, 1) + mbps, moved, note, err := tr.phase(context.Background(), srv.Client(), "download", 2, downFor, 0, 1, here) took := time.Since(began) if err != nil { t.Fatalf("phase: %v", err) @@ -216,11 +215,12 @@ func TestPhaseMeasuresTheWindow(t *testing.T) { // A phase whose server refuses outright fails, and says what it was told. bad := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { w.WriteHeader(429) })) defer bad.Close() - downURL = bad.URL + "/down?bytes=%d" - if _, _, _, err := tr.phase(context.Background(), bad.Client(), "download", 2, 300*time.Millisecond, 0, 1); err == nil { + refuser := Source{"refuser", func(int) string { return bad.URL + "/down" }} + _, _, _, err = tr.phase(context.Background(), bad.Client(), "download", 2, 300*time.Millisecond, 0, 1, refuser) + if err == nil { t.Error("a phase against a server that refuses everything should fail") - } else if !strings.Contains(err.Error(), "rate-limiting") { - t.Errorf("error = %q, want it to name the rate limit", err) + } else if !refused(err) { + t.Errorf("error = %q, want the refusal that makes the fallback kick in", err) } } @@ -241,15 +241,77 @@ func TestCancelIsReportedAsCancelled(t *testing.T) { } })) defer srv.Close() - defer func(u string, w, d time.Duration) { downURL, warmUp, downFor = u, w, d }(downURL, warmUp, downFor) - downURL, warmUp, downFor = srv.URL+"/down?bytes=%d", 10*time.Millisecond, 10*time.Second + defer func(w, d time.Duration) { warmUp, downFor = w, d }(warmUp, downFor) + warmUp, downFor = 10*time.Millisecond, 10*time.Second + here := Source{"local", func(int) string { return srv.URL + "/down" }} tr := NewTester(nil) ctx, cancel := context.WithCancel(context.Background()) go func() { time.Sleep(200 * time.Millisecond); cancel() }() - _, _, _, err := tr.phase(ctx, srv.Client(), "download", 1, downFor, 0, 1) + _, _, _, err := tr.phase(ctx, srv.Client(), "download", 1, downFor, 0, 1, here) // Cancelled after bytes moved: the figure stands, and the phase does not claim an error. if err != nil && !errors.Is(err, context.Canceled) { t.Errorf("err = %v, want nil or a cancellation", err) } } + +// When the first source refuses, the download is taken from the next one and the result says +// so. This is the whole reason there is more than one. +func TestDownloadFallsBackWhenRefused(t *testing.T) { + serving := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { + if r.URL.Path == "/up" { + _, _ = io.Copy(io.Discard, r.Body) + w.WriteHeader(204) + return + } + // paced, so the phase is governed by its window and not by a loopback moving a + // gibibyte before the first tick + buf := make([]byte, 1<<20) + fl, _ := w.(http.Flusher) + for i := 0; i < 64; i++ { + if _, err := w.Write(buf); err != nil { + return + } + if fl != nil { + fl.Flush() + } + select { + case <-time.After(2 * time.Millisecond): + case <-r.Context().Done(): + return + } + } + })) + defer serving.Close() + refusing := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, _ *http.Request) { w.WriteHeader(429) })) + defer refusing.Close() + + defer func(srcs []Source, up string, w, d, mw time.Duration, m int64) { + downSources, upURL, warmUp, downFor, minWindow, measureBytes = srcs, up, w, d, mw, m + }(downSources, upURL, warmUp, downFor, minWindow, measureBytes) + downSources = []Source{ + {"refuser", func(int) string { return refusing.URL + "/down" }}, + {"the-other-one", func(int) string { return serving.URL + "/down" }}, + } + upURL = serving.URL + "/up" + warmUp, downFor, upFor, minWindow, measureBytes = 50*time.Millisecond, time.Second, 300*time.Millisecond, 100*time.Millisecond, 4<<20 + + tr := NewTester(nil) + if _, err := tr.Start(); err != nil { + t.Fatal(err) + } + deadline := time.Now().Add(30 * time.Second) + for tr.Running() && time.Now().Before(deadline) { + time.Sleep(50 * time.Millisecond) + } + res := tr.State().Result + if res == nil { + t.Fatal("no result") + } + if res.Source != "the-other-one" { + t.Errorf("source = %q, want the second one — the first refused", res.Source) + } + if res.DownMbps <= 0 { + t.Errorf("download = %v, want a figure from the source that did serve: %+v", res.DownMbps, res) + } +} diff --git a/internal/network/speedtest.go b/internal/network/speedtest.go index 3a181e6..c667b30 100644 --- a/internal/network/speedtest.go +++ b/internal/network/speedtest.go @@ -35,6 +35,7 @@ import ( "errors" "fmt" "io" + "log" "math" "net" "net/http" @@ -47,9 +48,27 @@ import ( // The endpoints, and the shape of a phase. Variables rather than constants only so the tests // can point them at a local server and shrink the windows; nothing else rebinds them. +// Source is somewhere to pull bytes from. Cloudflare's endpoint is the first choice because +// it is anycast — near wherever Ham Lab is running — and because the same host answers for +// upload and for the trace. The fallback exists because that endpoint rate-limits by volume +// and will refuse a connection that has been tested hard: a plain 100 MB file on a public +// mirror has no such opinion. It is in Seattle, so on a machine far from there it will read +// low, which is exactly why every result names the source it used. +type Source struct { + Name string + // URL takes the number of bytes wanted, where the source can be asked; a fixed file + // ignores it and is fetched again each time round. + URL func(bytes int) string +} + +var downSources = []Source{ + {"cloudflare", func(b int) string { return fmt.Sprintf(cfDownURL, b) }}, + {"linode-seattle", func(int) string { return "https://speedtest.seattle.linode.com/100MB-seattle.bin" }}, +} + var ( - downURL = "https://speed.cloudflare.com/__down?bytes=%d" - upURL = "https://speed.cloudflare.com/__up" + cfDownURL = "https://speed.cloudflare.com/__down?bytes=%d" + upURL = "https://speed.cloudflare.com/__up" // traceURL is Cloudflare's standard trace: a few lines of key=value naming the address it // sees, the edge that answered and the country. A few hundred bytes. traceURL = "https://speed.cloudflare.com/cdn-cgi/trace" @@ -100,6 +119,9 @@ type Result struct { // address as that edge saw it. Colo string `json:"colo,omitempty"` IP string `json:"ip,omitempty"` + // Source is where the download came from, which matters because the fallback is not in the + // same place as the anycast one. Empty means the usual. + Source string `json:"source,omitempty"` // Note is set when the figures are real but something went wrong along the way — a stream // that was refused part-way, most often. The number is what was actually seen; the note is // why it may be low. @@ -230,12 +252,21 @@ func (t *Tester) measure(ctx context.Context, cancel context.CancelFunc) { var note string if err == nil { t.set(func(r *Run) { r.Phase, r.Done, r.Mbps = "download", 0.1, 0 }) - res.DownMbps, res.DownBytes, note, err = t.phase(ctx, client, "download", downStreams, downFor, 0.1, 0.6) + // Each source in turn: a refusal from the first is exactly what the second is for, and + // anything else (no route, no DNS) would fail the same way twice, so it stops there. + for i, src := range downSources { + res.Source = src.Name + res.DownMbps, res.DownBytes, note, err = t.phase(ctx, client, "download", downStreams, downFor, 0.1, 0.6, src) + if err == nil || !refused(err) || i == len(downSources)-1 { + break + } + log.Printf("speed test: %s refused the download, trying %s", src.Name, downSources[i+1].Name) + } res.Note = join(res.Note, note) } if err == nil { t.set(func(r *Run) { r.Phase, r.Done, r.Mbps = "upload", 0.7, 0 }) - res.UpMbps, res.UpBytes, note, err = t.phase(ctx, client, "upload", upStreams, upFor, 0.7, 1.0) + res.UpMbps, res.UpBytes, note, err = t.phase(ctx, client, "upload", upStreams, upFor, 0.7, 1.0, Source{Name: "cloudflare"}) res.Note = join(res.Note, note) } res.TookSec = round(time.Since(started).Seconds(), 1) @@ -307,7 +338,7 @@ func (t *Tester) latency(ctx context.Context, client *http.Client) ([]float64, m var out []float64 for i := 0; i <= latencyProbes; i++ { // the first is the handshake, and is not counted start := time.Now() - req, err := http.NewRequestWithContext(ctx, "GET", fmt.Sprintf(downURL, 0), nil) + req, err := http.NewRequestWithContext(ctx, "GET", fmt.Sprintf(cfDownURL, 0), nil) if err != nil { return nil, m, err } @@ -344,7 +375,7 @@ func (t *Tester) latency(ctx context.Context, client *http.Client) ([]float64, m // refusing part-way, the figure is what was actually moved while it was moving, and the note // says what happened. Coasting to the end of the clock with no bytes arriving would report a // number a third of the truth. -func (t *Tester) phase(parent context.Context, client *http.Client, dir string, streams int, forHow time.Duration, from, to float64) (float64, int64, string, error) { +func (t *Tester) phase(parent context.Context, client *http.Client, dir string, streams int, forHow time.Duration, from, to float64, src Source) (float64, int64, string, error) { // parent is the test's own context, which is cancelled when somebody presses Stop. ctx is // this phase's, which *this function* cancels to shut the streams down — so the two are // kept apart: asking ctx whether the test was cancelled would always say yes by then, and @@ -371,7 +402,7 @@ func (t *Tester) phase(parent context.Context, client *http.Client, dir string, for ctx.Err() == nil && moved.Load() < phaseBudget { var err error if dir == "download" { - err = stream(ctx, client, &moved) + err = stream(ctx, client, src, &moved) } else { err = upstream(ctx, client, &moved) } @@ -446,7 +477,8 @@ func (t *Tester) phase(parent context.Context, client *http.Client, dir string, } return 0, moved.Load(), "", fmt.Errorf("nothing moved in the %s phase", dir) } - if secs < 0.1 { // too short a window to divide by + if secs < 0.02 { // too short a window to divide by; the guard is against dividing by zero, + // not a judgement about how long a good measurement takes return 0, moved.Load(), "", fmt.Errorf("the %s phase was over before it could be measured", dir) } note := "" @@ -467,9 +499,9 @@ func join(a, b string) string { return a + "; " + b } -// stream fetches one chunk, counting bytes as they arrive. -func stream(ctx context.Context, client *http.Client, n *atomic.Int64) error { - req, err := http.NewRequestWithContext(ctx, "GET", fmt.Sprintf(downURL, downChunk), nil) +// stream fetches one chunk from src, counting bytes as they arrive. +func stream(ctx context.Context, client *http.Client, src Source, n *atomic.Int64) error { + req, err := http.NewRequestWithContext(ctx, "GET", src.URL(downChunk), nil) if err != nil { return err } @@ -522,11 +554,18 @@ func upstream(ctx context.Context, client *http.Client, n *atomic.Int64) error { // the only failure of this test anyone here is likely to meet. func answered(code int, status string) error { if code == 429 || code == 403 { - return errors.New("the speed endpoint is rate-limiting this connection — it does that after a lot of testing; leave it a few minutes") + return errRefused } return fmt.Errorf("the speed endpoint answered %s", status) } +// errRefused is the far end rate-limiting this connection, which is the only failure of this +// test anyone here is likely to meet: it limits by volume, and a test moves a few hundred +// megabytes. It is recognisable so the download phase can try its other source. +var errRefused = errors.New("the speed endpoint is rate-limiting this connection — it does that after a lot of testing; leave it a few minutes") + +func refused(err error) bool { return errors.Is(err, errRefused) } + // zeros is a request body of a fixed size that costs nothing to produce, counting itself as // it is read out onto the wire. type zeros struct { diff --git a/web/src/Network.tsx b/web/src/Network.tsx index de6fa90..de02c80 100644 --- a/web/src/Network.tsx +++ b/web/src/Network.tsx @@ -18,6 +18,12 @@ const scenery = (f: Iface) => const KIND: Record = { ethernet: 'wired', wifi: 'Wi-Fi', bridge: 'bridge', bond: 'bond', loopback: 'loopback', virtual: 'virtual', vlan: 'VLAN', wlan: 'Wi-Fi' } +// Where the bytes came from. The usual source is anycast and its edge is the interesting +// part; a fallback source is somewhere fixed, and then *which* one is the interesting part, +// because a mirror far away reads low and the figure should not pretend otherwise. +const where = (r: SpeedResult) => + r.source && r.source !== 'cloudflare' ? ` from ${r.source}` : r.colo ? ` via ${r.colo}` : '' + // A round number of megabits, which is how a line is sold and how it should be read. const mbps = (v: number) => (v >= 100 ? v.toFixed(0) : v.toFixed(1)) const ago = (iso: string) => { @@ -121,7 +127,7 @@ export default function Network() { {running ? <>Stoprunning on {d.report.host} — it carries on if you close this : <>Run speed test - {last ? `${fmtBytes((last.down_bytes ?? 0) + (last.up_bytes ?? 0))} moved in ${last.took_sec}s${last.colo ? ` via ${last.colo}` : ''}` : 'about 15 seconds'}} + {last ? `${fmtBytes((last.down_bytes ?? 0) + (last.up_bytes ?? 0))} moved in ${last.took_sec}s${where(last)}` : 'about ten seconds'}} {failed &&
{failed === 'cancelled' ? 'Stopped.' : failed}
} {!failed && last?.note &&
{last.note}
} diff --git a/web/src/api.ts b/web/src/api.ts index efe0213..0d3c985 100644 --- a/web/src/api.ts +++ b/web/src/api.ts @@ -182,7 +182,7 @@ export interface NetReport { at: string; host?: string; ifaces: Iface[]; gateway export interface Outside { at: string; ip?: string; colo?: string; country?: string; error?: string } export interface SpeedResult { at: string; down_mbps: number; up_mbps: number; latency_ms: number; jitter_ms: number - down_bytes: number; up_bytes: number; took_sec: number; colo?: string; ip?: string; note?: string; error?: string + down_bytes: number; up_bytes: number; took_sec: number; colo?: string; ip?: string; source?: string; note?: string; error?: string } // A test in progress, or the last one to have finished. `done` is 0–1 across the whole test // and `mbps` is the live figure for the phase under way.