ALL

For reading and verification only. You may not copy, use, modify or redistribute this code. Full notice on the main page.

tunnel/outage_test.go

SHA-256: 935a950e3a5eb8ec98b5ecd582e0248cbcea241168705cf9a731137f71c76f5c
358 lines · 15299 bytes · View on GitHub

1package main
2
3import (
4 "strings"
5 "testing"
6 "time"
7)
8
9// What a node does when its control plane does not answer (the design plan, section 5): what is already authenticated goes on until
10// valid_until, a paid device gets 15 minutes more, a trial or a gated device gets none, and nothing new is admitted without a good authorize. Every
11// test runs the whole stack (HTTPS client, JWKS cache, feed) against a fake control plane on a clock the test moves by hand.
12
13// pass moves the node's clock forward by d in steps of at most step, giving the node's timers and loops a moment after each.
14func (e *testEnv) pass(d, step time.Duration) {
15 for d > 0 {
16 s := min(d, step)
17 e.clk.Advance(s)
18 time.Sleep(12 * time.Millisecond)
19 d -= s
20 }
21}
22
23// outageDevice is a device with its connection up, its read loop running and a stream of a client open on it.
24type outageDevice struct {
25 d *testDevice
26 conn *devConn
27 ds *devServer
28 stream *tlsClient
29}
30
31func connectWithStream(t *testing.T, e *testEnv, plan devicePlan) *outageDevice {
32 t.Helper()
33 d := e.newDeviceNoPlan()
34 plan.host = d.host
35 e.cp.set(d.id, &plan)
36 dc := e.connectOK(d)
37 ds := dc.serve(nil)
38 return &outageDevice{d: d, conn: dc, ds: ds, stream: streamOpen(t, e, d)}
39}
40
41// validUntil is the moment the OK gave the connection.
42func (o *outageDevice) validUntil() time.Time {
43 return time.Unix(int64(o.conn.ok["body"].(map[string]any)["valid_until"].(float64)), 0)
44}
45
46func (o *outageDevice) closed(want string) bool { return containsLine(o.ds.otherLines(), want) }
47
48func (o *outageDevice) renewFails(t *testing.T) {
49 t.Helper()
50 if line := o.conn.renew(); line != "ERR control_unavailable" {
51 t.Fatalf("a RENEW while the control plane is down: %q", line)
52 }
53}
54
55func TestOutage_ADownControlPlaneFor14MinutesKeepsPaidTunnelsAndRefusesNewAttaches(t *testing.T) {
56 clk := newFakeClock()
57 e, cp := httpNode(t, clk, nil)
58 paid := connectWithStream(t, e, devicePlan{validFor: 4 * time.Hour})
59
60 cp.setDown(503)
61 e.pass(14*time.Minute, time.Minute)
62
63 // the paid tunnel and its stream are untouched, and the host still serves new clients
64 if !e.srv.Online(paid.d.host) || paid.stream.dead(50*time.Millisecond) || paid.closed("CLOSE") {
65 t.Fatal("a paid tunnel did not survive 14 minutes of a down control plane")
66 }
67 if c, err := e.clientTLS(paid.d); err != nil {
68 t.Fatalf("a client of a device that is authenticated: %v", err)
69 } else {
70 _ = c.Close()
71 }
72 // a NEW attach needs a good authorize: it is refused with a word that says "try later", and nothing was relayed
73 newcomer := e.newDevice()
74 conn := e.connect(newcomer)
75 line := conn.hello(func() string { return e.session(newcomer, nil) }, func(s, n string) string { return e.proof(newcomer, s, n, nil) })
76 if line != "ERR control_unavailable" {
77 t.Fatalf("a new attach during the outage: %q", line)
78 }
79 if e.srv.Online(newcomer.host) {
80 t.Fatal("a device that nothing authorized is served")
81 }
82 // and the same device that was already attached may RENEW later, when the control plane is back; until then its renewals keep the connection
83 paid.renewFails(t)
84 if !e.srv.Online(paid.d.host) {
85 t.Fatal("a refused RENEW closed the connection")
86 }
87 cp.setDown(0)
88 clk.Advance(2 * time.Second)
89 if line := e.connect(newcomer).hello(func() string { return e.session(newcomer, nil) }, func(s, n string) string { return e.proof(newcomer, s, n, nil) }); !strings.HasPrefix(line, "OK ") {
90 t.Fatalf("a new attach once the control plane is back: %q", line)
91 }
92 if r := paid.conn.renew(); !strings.HasPrefix(r, "OK ") {
93 t.Fatalf("renew after the outage: %q", r)
94 }
95}
96
97func TestOutage_ATrialAndAGatedTunnelAreNotExtended(t *testing.T) {
98 clk := newFakeClock()
99 e, cp := httpNode(t, clk, nil)
100 trial := connectWithStream(t, e, devicePlan{plan: "trial", validFor: 15 * time.Minute})
101 gated := connectWithStream(t, e, devicePlan{status: statusGated, plan: "trial", validFor: 15 * time.Minute})
102 if gated.conn.ok["body"].(map[string]any)["status"] != "gated" {
103 t.Fatalf("OK %v", gated.conn.ok)
104 }
105
106 cp.setDown(503)
107 e.pass(10*time.Minute, time.Minute) // the moment a device renews: valid_until minus 5 minutes
108 trial.renewFails(t)
109 gated.renewFails(t)
110 // gated opens streams like any other device: the card is served by the device
111 if c, err := e.clientTLS(gated.d); err != nil {
112 t.Fatalf("a client of a gated device: %v", err)
113 } else {
114 _ = c.Close()
115 }
116
117 // five minutes later the grants are over, the control plane still down: no grace for either
118 e.pass(5*time.Minute+2*time.Second, 30*time.Second)
119 for name, o := range map[string]*outageDevice{"trial": trial, "gated": gated} {
120 o := o
121 eventually(t, name+" CLOSE expired", 3*time.Second, func() bool { return o.closed("CLOSE expired") })
122 if !o.stream.dead(2 * time.Second) {
123 t.Errorf("%s: the stream outlived the grant", name)
124 }
125 if e.srv.Online(o.d.host) {
126 t.Errorf("%s: still online", name)
127 }
128 }
129}
130
131func TestOutage_APaidTunnelOutlivesItsValidUntilByTheGraceAndNotOneSecondMore(t *testing.T) {
132 if policyData.Authorization.GracePaidS != 900 {
133 t.Fatalf("the plan says 15 minutes of grace, the policy says %d s", policyData.Authorization.GracePaidS)
134 }
135 clk := newFakeClock()
136 e, cp := httpNode(t, clk, nil)
137 paid := connectWithStream(t, e, devicePlan{validFor: 15 * time.Minute})
138 validUntil := paid.validUntil()
139
140 cp.setDown(503)
141 e.pass(10*time.Minute, time.Minute)
142 paid.renewFails(t)
143 e.pass(validUntil.Sub(e.now())+time.Second, 30*time.Second)
144
145 // past valid_until: the connection and its stream live (grace), but no NEW stream is opened
146 if paid.closed("CLOSE") || paid.stream.dead(50*time.Millisecond) {
147 t.Fatal("a paid tunnel was cut at valid_until although the control plane is down")
148 }
149 if e.srv.Online(paid.d.host) {
150 t.Fatal("a stream may be opened after valid_until")
151 }
152 if _, err := e.clientTLS(paid.d); err == nil {
153 t.Fatal("a new client got a stream after valid_until")
154 }
155 if !strings.Contains(e.logs.String(), `"msg":"control_grace"`) {
156 t.Fatal("the grace is not logged")
157 }
158 // (the contracts' transcript checker has no notion of the grace, so this test does not run it; the rule it enforces, no OPEN at or after
159 // valid_until, is the two refusals above)
160
161 // just before the grace ends it still lives
162 e.pass(validUntil.Add(policyDataGrace()).Sub(e.now())-10*time.Second, 30*time.Second)
163 if paid.closed("CLOSE") || paid.stream.dead(50*time.Millisecond) {
164 t.Fatal("cut before the grace was over")
165 }
166 // and when it is over, the connection and the streams are closed
167 e.pass(20*time.Second, 5*time.Second)
168 eventually(t, "CLOSE expired", 3*time.Second, func() bool { return paid.closed("CLOSE expired") })
169 if !paid.stream.dead(2 * time.Second) {
170 t.Fatal("the stream outlived the grace")
171 }
172}
173
174func policyDataGrace() time.Duration { return secs(policyData.Authorization.GracePaidS) }
175
176func TestOutage_APaidDeviceTheControlPlaneRefusedGetsNoGrace(t *testing.T) {
177 clk := newFakeClock()
178 e, _ := httpNode(t, clk, nil)
179 // The control plane is UP and says no: a license that ended. The paid plan does not matter, there is nothing to be graceful about.
180 refused := connectWithStream(t, e, devicePlan{validFor: 15 * time.Minute})
181 e.pass(10*time.Minute, time.Minute)
182 e.cp.set(refused.d.id, &devicePlan{host: refused.d.host, err: &ControlError{Status: 402, Code: codeLicenseInactive}})
183 if r := refused.conn.renew(); r != "ERR license_inactive" {
184 t.Fatalf("%q", r)
185 }
186 e.pass(5*time.Minute+2*time.Second, 30*time.Second)
187 eventually(t, "CLOSE expired", 3*time.Second, func() bool { return refused.closed("CLOSE expired") })
188 if !refused.stream.dead(2 * time.Second) {
189 t.Fatal("the stream outlived the grant of a device the control plane refused")
190 }
191 if strings.Contains(e.logs.String(), `"msg":"control_grace"`) {
192 t.Fatal("a grace was given while the control plane was answering")
193 }
194}
195
196func TestOutage_ADeviceWhoseOwnRenewalHadNoAnswerGetsTheGraceEvenWhileTheRestOfTheControlPlaneWorks(t *testing.T) {
197 // "subscription_verification_unavailable": the control plane is up but cannot tell whether the subscription is paid. Nothing is granted, and a
198 // paying device's connection is not cut for it.
199 clk := newFakeClock()
200 e, _ := httpNode(t, clk, nil)
201 o := connectWithStream(t, e, devicePlan{validFor: 15 * time.Minute})
202 validUntil := o.validUntil()
203 e.pass(10*time.Minute, time.Minute)
204 e.cp.set(o.d.id, &devicePlan{host: o.d.host, err: &ControlError{Status: 503, Code: "subscription_verification_unavailable"}})
205 o.renewFails(t)
206 e.pass(validUntil.Sub(e.now())+time.Second, 30*time.Second)
207 if o.closed("CLOSE") || o.stream.dead(50*time.Millisecond) {
208 t.Fatal("a paying device was cut because the subscription could not be verified")
209 }
210 e.pass(policyDataGrace(), time.Minute)
211 eventually(t, "CLOSE expired", 3*time.Second, func() bool { return o.closed("CLOSE expired") })
212}
213
214func TestOutage_ARenewInsideTheGraceEndsItAndTheNewGrantIsTheControlPlanes(t *testing.T) {
215 clk := newFakeClock()
216 e, cp := httpNode(t, clk, nil)
217 o := connectWithStream(t, e, devicePlan{validFor: 15 * time.Minute})
218 validUntil := o.validUntil()
219 cp.setDown(503)
220 e.pass(10*time.Minute, time.Minute)
221 o.renewFails(t)
222 e.pass(validUntil.Sub(e.now())+time.Minute, 30*time.Second) // a minute into the grace
223 if o.closed("CLOSE") {
224 t.Fatal("closed inside the grace")
225 }
226 // the control plane is back: the next RENEW works, and the connection has a new valid_until with no grace attached
227 cp.setDown(0)
228 clk.Advance(2 * time.Second)
229 if r := o.conn.renew(); !strings.HasPrefix(r, "OK ") {
230 t.Fatalf("renew inside the grace: %q", r)
231 }
232 if !e.srv.Online(o.d.host) {
233 t.Fatal("not served after the renewal")
234 }
235 // the old end of the grace passes: nothing happens (the new grant is a minute longer than that)
236 e.pass(o.validUntil().Add(policyDataGrace()).Sub(e.now())+10*time.Second, 30*time.Second)
237 if o.closed("CLOSE") || o.stream.dead(50*time.Millisecond) || !e.srv.Online(o.d.host) {
238 t.Fatal("the old grace closed a connection that was renewed")
239 }
240 e.checkTranscript()
241}
242
243func TestOutage_APaidTunnelSurvivesATwoHourControlPlaneOutage(t *testing.T) {
244 clk := newFakeClock()
245 e, cp := httpNode(t, clk, nil)
246 paid := connectWithStream(t, e, devicePlan{validFor: 4 * time.Hour})
247 other := connectWithStream(t, e, devicePlan{validFor: 4 * time.Hour})
248 validUntil := paid.validUntil()
249
250 cp.setDown(503)
251 e.pass(2*time.Hour, 5*time.Minute)
252
253 for name, o := range map[string]*outageDevice{"first": paid, "second": other} {
254 if !e.srv.Online(o.d.host) || o.closed("CLOSE") || o.stream.dead(50*time.Millisecond) {
255 t.Fatalf("%s: a paid tunnel did not survive two hours of a down control plane", name)
256 }
257 if c, err := e.clientTLS(o.d); err != nil {
258 t.Fatalf("%s: a new client during the outage: %v", name, err)
259 } else {
260 _ = c.Close()
261 }
262 }
263 // by now the node no longer vouches for the control plane's keys (30 minutes), so even a good session is refused as "try later"
264 newcomer := e.newDevice()
265 if line := e.connect(newcomer).hello(func() string { return e.session(newcomer, nil) }, func(s, n string) string { return e.proof(newcomer, s, n, nil) }); line != "ERR control_unavailable" {
266 t.Fatalf("a new attach after two hours of outage: %q", line)
267 }
268
269 // the control plane comes back: the connection renews when it is due, and gets a fresh four hours
270 cp.setDown(0)
271 e.pass(validUntil.Add(-5*time.Minute).Sub(e.now()), 20*time.Minute)
272 if r := paid.conn.renew(); !strings.HasPrefix(r, "OK ") {
273 t.Fatalf("renew after the outage: %q", r)
274 }
275 e.pass(30*time.Minute, 10*time.Minute) // past the old valid_until
276 if !e.srv.Online(paid.d.host) || paid.closed("CLOSE") {
277 t.Fatal("the renewed connection was closed at the old valid_until")
278 }
279 e.checkTranscript()
280}
281
282func TestGated_ATrialThatEndsBecomesGatedAtItsRenewalWithoutAnyEvent(t *testing.T) {
283 clk := newFakeClock()
284 e, _ := httpNode(t, clk, nil)
285 o := connectWithStream(t, e, devicePlan{plan: "trial", validFor: 15 * time.Minute})
286 if o.conn.ok["body"].(map[string]any)["status"] != "active" {
287 t.Fatalf("OK %v", o.conn.ok)
288 }
289 e.pass(10*time.Minute, time.Minute)
290 // the trial ended: the control plane now says gated (and never beyond its cutoff)
291 e.cp.set(o.d.id, &devicePlan{host: o.d.host, status: statusGated, plan: "trial", validFor: 15 * time.Minute})
292 r := o.conn.renew()
293 if !strings.HasPrefix(r, "OK ") || !strings.Contains(r, `"status":"gated"`) {
294 t.Fatalf("renew of a trial that ended: %q", r)
295 }
296 if c, err := e.clientTLS(o.d); err != nil {
297 t.Fatalf("a gated device serves streams (the card is the device's): %v", err)
298 } else {
299 _ = c.Close()
300 }
301 // and it is not extended by anything the node thinks: with the control plane down at the next end, it closes
302 e.cpDownThrough(15 * time.Minute)
303 eventually(t, "CLOSE expired", 3*time.Second, func() bool { return o.closed("CLOSE expired") })
304 e.checkTranscript()
305}
306
307// cpDownThrough takes the control plane down (every call of the node answers 503) and lets d pass.
308func (e *testEnv) cpDownThrough(d time.Duration) {
309 e.cp.mu.Lock()
310 for _, p := range e.cp.plans {
311 p.err = &ControlError{Status: 503, Code: "end_to_end_unavailable"}
312 }
313 e.cp.mu.Unlock()
314 e.pass(d+2*time.Second, time.Minute)
315}
316
317func TestOutage_APaidDeviceTheControlPlaneRefusedGetsNoGraceWhenTheControlPlaneGoesDownLater(t *testing.T) {
318 clk := newFakeClock()
319 e, cp := httpNode(t, clk, nil)
320 o := connectWithStream(t, e, devicePlan{validFor: 15 * time.Minute})
321 validUntil := o.validUntil()
322 e.pass(2*time.Minute, time.Minute)
323 e.cp.set(o.d.id, &devicePlan{host: o.d.host, err: &ControlError{Status: 402, Code: codeLicenseInactive}})
324 if r := o.conn.renew(); r != "ERR license_inactive" {
325 t.Fatalf("%q", r)
326 }
327 // the whole control plane goes down afterwards: the node cannot tell one device from another, but it has been told no for this one
328 cp.setDown(503)
329 e.pass(validUntil.Sub(e.now())+2*time.Second, time.Minute)
330 eventually(t, "CLOSE expired", 3*time.Second, func() bool { return o.closed("CLOSE expired") })
331 if strings.Contains(e.logs.String(), `"msg":"control_grace"`) {
332 t.Fatal("a device the control plane refused was given the grace")
333 }
334}
335
336func TestOutage_ARenewTheNodeItselfCouldNotSendIsNotTheControlPlaneBeingDown(t *testing.T) {
337 // The node's own queue for authorize is full: the control plane was never asked, and answers everyone else. The device gets no grace for it.
338 clk := newFakeClock()
339 e, _ := httpNode(t, clk, func(c *Config) { c.MaxUnauth = 1 })
340 o := connectWithStream(t, e, devicePlan{validFor: 15 * time.Minute})
341 validUntil := o.validUntil()
342 e.pass(2*time.Minute, time.Minute)
343
344 slow := e.newDevice()
345 e.cp.set(slow.id, &devicePlan{host: slow.host, validFor: time.Hour, delay: 2 * time.Second})
346 hello := e.helloAsync(slow)
347 eventually(t, "the other device's authorize in flight", 3*time.Second, func() bool { return e.cp.callsFor(slow.id, "hello") == 1 })
348 o.renewFails(t)
349 if n := e.cp.callsFor(o.d.id, "renew"); n != 0 {
350 t.Fatalf("the control plane was asked %d times: the queue was not full", n)
351 }
352 <-hello
353 e.pass(validUntil.Sub(e.now())+2*time.Second, time.Minute)
354 eventually(t, "CLOSE expired", 3*time.Second, func() bool { return o.closed("CLOSE expired") })
355 if strings.Contains(e.logs.String(), `"msg":"control_grace"`) {
356 t.Fatal("a RENEW that never left the node was taken for a control plane that does not answer")
357 }
358}