1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
427

package logic

import (
	"net/http"
	"rss_parrot/shared"
	"slices"
	"testing"
	"time"
)

// Scenarios over simulated days and weeks: a feed follower polls feeds served
// by simFeed while the clock moves on. See sim_harness_test.go.
//
// Unless a test says otherwise, the update schedule is 1h for feeds that
// changed in the last day, 4h in the last week, 12h in the last 4 weeks and
// 24h for older ones, each ±20%.

const (
	hour = time.Hour
	day  = 24 * time.Hour
)

// loopRequests are the requests of the check loop, i.e. all but the one made
// when following the feed.
func loopRequests(t *testing.T, f *simFeed) []simRequest {
	t.Helper()
	reqs := f.requests()
	if len(reqs) == 0 {
		t.Fatal("the feed was never requested")
	}
	return reqs[1:]
}

func TestSimNewPostIsTootedOnceAtTheNextCheck(t *testing.T) {
	s := newSim(t, nil)
	feed := newSimFeed(t, s.clock,
		simPost{title: "old 1", published: simStart.Add(-4 * day)},
		simPost{title: "old 2", published: simStart.Add(-3 * day)},
		simPost{title: "old 3", published: simStart.Add(-2 * day)},
	)
	acct := s.follow(feed)

	// Following stores the existing posts, but toots none of them to anyone.
	if toots, _ := s.repo.GetTootExtracts(acct.Id); len(toots) != 3 {
		t.Fatalf("after following: %d toots, want 3", len(toots))
	}
	if b := s.msgr.broadcasts(); len(b) != 0 {
		t.Fatalf("following broadcast %d posts, want none", len(b))
	}

	fresh := simPost{title: "fresh", published: simStart.Add(3 * hour)}
	feed.addPost(fresh)
	s.runUntil(simStart.Add(2 * day))

	b := s.msgr.broadcasts()
	if len(b) != 1 || b[0].content != "fresh" {
		t.Fatalf("broadcasts = %v, want just \"fresh\"", s.msgr.titles())
	}
	// Idle for 2 days, the feed was on the 4h schedule: the post goes out at
	// the first check after it appeared, at most 4h ±20% later.
	if lag := b[0].at.Sub(fresh.published); lag < 0 || lag > 4*hour*12/10 {
		t.Errorf("tooted %s after publication, want within 4.8h", lag)
	}
	if !b[0].tootedAt.Equal(b[0].at) {
		t.Errorf("tooted_at %s, want the time of the check, %s", b[0].tootedAt, b[0].at)
	}
	if toots, _ := s.repo.GetTootExtracts(acct.Id); len(toots) != 4 {
		t.Errorf("%d toots in the database, want 4", len(toots))
	}
	// Having just changed, the feed is now on the 1h schedule.
	var after []simRequest
	for _, r := range loopRequests(t, feed) {
		if r.at.After(b[0].at) && r.at.Before(b[0].at.Add(day)) {
			after = append(after, r)
		}
	}
	if len(after) < 18 {
		t.Errorf("%d checks in the day after the new post, want about 24 (1h schedule)", len(after))
	}
}

func TestSimUnchangedFeedIsPolledConditionally(t *testing.T) {
	s := newSim(t, nil)
	feed := newSimFeed(t, s.clock,
		simPost{title: "old", published: simStart.Add(-10 * day)},
	)
	s.follow(feed)
	s.runUntil(simStart.Add(3 * day))

	reqs := loopRequests(t, feed)
	// 10-13 days idle is the 12h schedule: about 6 checks in 3 days.
	if len(reqs) < 5 || len(reqs) > 8 {
		t.Fatalf("%d checks in 3 days, want about 6", len(reqs))
	}
	// Following does not keep the validators, so the first check fetches the
	// feed in full; every later one is conditional, and answered with a 304.
	etag := reqs[0].header.Get("If-None-Match")
	for i, r := range reqs[1:] {
		if r.header.Get("If-None-Match") == "" || r.header.Get("If-Modified-Since") == "" {
			t.Errorf("check %d was not conditional: %v", i+2, r.header)
		}
		if r.status != http.StatusNotModified {
			t.Errorf("check %d got %d, want 304", i+2, r.status)
		}
		_ = etag
	}
	for i := 1; i < len(reqs); i++ {
		if gap := reqs[i].at.Sub(reqs[i-1].at); gap < 12*hour*8/10 || gap > 12*hour*12/10 {
			t.Errorf("gap before check %d is %s, want 12h ±20%%", i+1, gap)
		}
	}
	if b := s.msgr.broadcasts(); len(b) != 0 {
		t.Errorf("an unchanged feed broadcast %v", s.msgr.titles())
	}
}

func TestSimOutageBacksOffAndCatchesUp(t *testing.T) {
	const maxRetryHours = 6
	s := newSim(t, func(cfg *shared.Config) { cfg.MaxRetryDelayHours = maxRetryHours })
	feed := newSimFeed(t, s.clock,
		simPost{title: "before", published: simStart.Add(-hour)},
	)
	acct := s.follow(feed)

	outageFrom, outageTo := simStart.Add(2*hour), simStart.Add(14*hour)
	feed.setFail(func(now time.Time) (int, string) {
		if !now.Before(outageFrom) && now.Before(outageTo) {
			return http.StatusInternalServerError, ""
		}
		return 0, ""
	})
	feed.addPost(simPost{title: "during 1", published: simStart.Add(4 * hour)})
	feed.addPost(simPost{title: "during 2", published: simStart.Add(8 * hour)})

	s.runUntil(outageTo.Add(-time.Minute))
	reqs := loopRequests(t, feed)
	var refused []simRequest
	for _, r := range reqs {
		if r.refused {
			refused = append(refused, r)
		}
	}
	if len(refused) < 3 {
		t.Fatalf("%d checks during the 12h outage, want at least 3", len(refused))
	}
	// The feed changed an hour before following, so it is on the 1h
	// schedule: the wait after the n-th failure is 2^n × 1h ±20%, but at most
	// max_retry_delay_hours.
	for n := 1; n < len(refused); n++ {
		gap := refused[n].at.Sub(refused[n-1].at)
		want := time.Duration(1<<n) * hour
		lo, hi := min(want*8/10, maxRetryHours*hour), min(want*12/10, maxRetryHours*hour)
		// Each check runs dueSlack after it falls due, so each gap is
		// the scheduled wait plus that.
		if gap -= dueSlack; gap < lo || gap > hi {
			t.Errorf("wait after failure %d is %s, want %s–%s", n, gap, lo, hi)
		}
	}
	for i, r := range refused {
		if r.header.Get("If-None-Match") == "" {
			t.Errorf("failed check %d did not send the validators: a failure must keep them", i+1)
		}
	}
	if b := s.msgr.broadcasts(); len(b) != 0 {
		t.Errorf("broadcast %v during the outage", s.msgr.titles())
	}

	s.runUntil(outageTo.Add(day))
	if got, want := s.msgr.titles(), []string{"during 1", "during 2"}; !slices.Equal(got, want) {
		t.Errorf("after the outage broadcast %v, want %v (once each, oldest first)", got, want)
	}
	if st := s.state(acct.Handle); st.FetchFailures != 0 {
		t.Errorf("fetch_failures is %d after recovery, want 0", st.FetchFailures)
	}
}

// retryOnce makes the first check from `from` on fail with status and
// whatever Retry-After the given function computes, and returns a pointer to
// the time it did.
func retryOnce(feed *simFeed, from time.Time, status int, retryAfter func(now time.Time) string) *time.Time {
	var failedAt time.Time
	feed.setFail(func(now time.Time) (int, string) {
		if now.Before(from) || !failedAt.IsZero() {
			return 0, ""
		}
		failedAt = now
		return status, retryAfter(now)
	})
	return &failedAt
}

// nextRequestAfter is the first request after t.
func nextRequestAfter(t *testing.T, f *simFeed, at time.Time) simRequest {
	t.Helper()
	for _, r := range f.requests() {
		if r.at.After(at) {
			return r
		}
	}
	t.Fatalf("no request after %s", at)
	return simRequest{}
}

func TestSimRetryAfter(t *testing.T) {
	cases := []struct {
		name       string
		status     int
		retryAfter func(now time.Time) string
		// wantAt is when the next request must happen.
		wantAt func(failedAt time.Time) time.Time
	}{
		{"seconds", http.StatusTooManyRequests,
			func(time.Time) string { return "18000" },
			func(f time.Time) time.Time { return f.Add(5 * hour) }},
		{"HTTP date", http.StatusServiceUnavailable,
			func(now time.Time) string { return now.Add(7 * hour).UTC().Format(http.TimeFormat) },
			// The date is to the second, so the wait is that, minus the
			// fraction of a second the check ran past the full second.
			func(f time.Time) time.Time { return f.Add(7 * hour).Truncate(time.Second) }},
		{"five weeks, capped at a day", http.StatusTooManyRequests,
			func(time.Time) string { return "3024000" },
			func(f time.Time) time.Time { return f.Add(day) }},
	}
	for _, c := range cases {
		t.Run(c.name, func(t *testing.T) {
			s := newSim(t, nil)
			feed := newSimFeed(t, s.clock,
				simPost{title: "recent", published: simStart.Add(-hour)},
			)
			s.follow(feed)
			failedAt := retryOnce(feed, simStart.Add(3*hour), c.status, c.retryAfter)
			s.runUntil(simStart.Add(3 * day))
			if failedAt.IsZero() {
				t.Fatal("the feed was never refused")
			}
			next := nextRequestAfter(t, feed, *failedAt)
			// The harness runs a check dueSlack after it falls due.
			if want := c.wantAt(*failedAt).Add(dueSlack); !next.at.Equal(want) {
				t.Errorf("next request %s after the refusal, want %s",
					next.at.Sub(*failedAt), want.Sub(*failedAt))
			}
		})
	}
}

// A post dated into the future is recorded when it shows up, and tooted when
// its date comes, however far ahead that is and whether or not the feed
// changes again in between.

func TestSimFutureDatedPostIsTootedWhenItIsDue(t *testing.T) {
	s := newSim(t, nil)
	feed := newSimFeed(t, s.clock,
		simPost{title: "old", published: simStart.Add(-2 * day)},
	)
	s.follow(feed)
	// Appears at +1h, dated three days ahead. The feed does not change after
	// that, so every later check is a 304.
	future := simPost{title: "future", published: simStart.Add(3 * day), visibleFrom: simStart.Add(hour)}
	feed.addPost(future)

	s.runUntil(future.published.Add(-time.Minute))
	if b := s.msgr.broadcasts(); len(b) != 0 {
		t.Fatalf("broadcast %v before its date", s.msgr.titles())
	}
	s.runUntil(simStart.Add(4 * day))
	b := s.msgr.broadcasts()
	if len(b) != 1 || b[0].content != "future" {
		t.Fatalf("broadcasts = %v, want [future]", s.msgr.titles())
	}
	// The harness wakes when an item is due; the real loop within a minute.
	if lag := b[0].at.Sub(future.published); lag < 0 || lag > time.Minute {
		t.Errorf("tooted %s after its date, want at it", lag)
	}
}

func TestSimPostAfterAFutureDatedPostIsNotLost(t *testing.T) {
	s := newSim(t, nil)
	feed := newSimFeed(t, s.clock,
		simPost{title: "old", published: simStart.Add(-2 * day)},
	)
	s.follow(feed)
	// Dated further ahead than the backdate grace (48h), so that if it moved
	// feed_last_updated to its date, "today" would be too far before that.
	later := simPost{title: "later", published: simStart.Add(5 * day), visibleFrom: simStart.Add(hour)}
	feed.addPost(later)
	s.runUntil(simStart.Add(5 * hour))
	if st := s.state(simHandle); st.FeedLastUpdated.After(s.clock.Now()) {
		t.Errorf("feed_last_updated is %s, after now (%s)", st.FeedLastUpdated, s.clock.Now())
	}
	// An ordinary post, published now, which is before "later".
	feed.addPost(simPost{title: "today", published: simStart.Add(6 * hour)})
	s.runUntil(simStart.Add(6 * day))
	if got := s.msgr.titles(); !slices.Equal(got, []string{"today", "later"}) {
		t.Errorf("broadcasts = %v, want [today later]", got)
	}
}

func TestSimOldTootsArePurgedAndUnfollowedFeedsDeleted(t *testing.T) {
	s := newSim(t, func(cfg *shared.Config) {
		cfg.PostsMinCountKept = 2
		cfg.PostsMinDaysKept = 3
	})
	feed := newSimFeed(t, s.clock)
	acct := s.follow(feed)
	for d := 1; d <= 10; d++ {
		feed.addPost(simPost{title: "day " + string(rune('0'+d/10)) + string(rune('0'+d%10)),
			published: simStart.Add(time.Duration(d) * day)})
	}
	s.runUntil(simStart.Add(10*day + 12*hour))

	b := s.msgr.broadcasts()
	if len(b) != 10 {
		t.Fatalf("%d posts tooted, want 10", len(b))
	}
	s.assertNoDuplicateBroadcasts()
	// Purges run after every check that got new posts; the last such check
	// is the one that tooted the last post. It deleted every toot at least
	// 3 days older than itself, but kept the 2 newest regardless.
	lastPurge := b[len(b)-1].at
	var want []time.Time
	for _, x := range b {
		if lastPurge.Sub(x.at) < 3*day {
			want = append(want, x.at)
		}
	}
	toots, err := s.repo.GetTootExtracts(acct.Id)
	if err != nil {
		t.Fatal(err)
	}
	var got []time.Time
	for _, x := range toots {
		got = append(got, x.TootedAt)
	}
	slices.SortFunc(got, func(a, b time.Time) int { return a.Compare(b) })
	if len(got) != len(want) {
		t.Fatalf("%d toots left, want %d (tooted at %v)", len(got), len(want), want)
	}
	for i := range got {
		if !got[i].Equal(want[i]) {
			t.Errorf("toot %d left was tooted at %s, want %s", i, got[i], want[i])
		}
	}
	if len(got) >= 10 || len(got) < 2 {
		t.Errorf("%d toots left: nothing was purged, or too much", len(got))
	}

	// The last follower leaves: at its next check the account is deleted,
	// and the feed is never requested again.
	if err := s.repo.RemoveFollower(acct.Handle, simFollowerUrl); err != nil {
		t.Fatal(err)
	}
	if !s.step(s.clock.Now().Add(day)) {
		t.Fatal("the feed was not checked again")
	}
	if a, err := s.repo.GetAccount(acct.Handle); err != nil || a != nil {
		t.Fatalf("account still there after its last follower left: %+v, %v", a, err)
	}
	if toots, _ := s.repo.GetTootExtracts(acct.Id); len(toots) != 0 {
		t.Errorf("%d toots of the deleted account left", len(toots))
	}
	n := len(feed.requests())
	s.runUntil(s.clock.Now().Add(7 * day))
	if m := len(feed.requests()); m != n {
		t.Errorf("deleted feed requested %d more times", m-n)
	}
}

func TestSimMissingScheduleFallsBackToDefaults(t *testing.T) {
	// No update_schedule at all, but for weeks4: the other intervals would be
	// 0, and a 0 interval meant checking the feed as fast as the loop ran.
	s := newSim(t, func(cfg *shared.Config) {
		cfg.UpdateSchedule = shared.UpdateSchedule{Weeks4: 8}
	})
	feed := newSimFeed(t, s.clock,
		simPost{title: "ancient", published: simStart.Add(-60 * day)},
	)
	s.follow(feed)
	s.runUntil(simStart.Add(4 * day))

	// Idle for two months: the older tier, by default 12h ±20%.
	reqs := loopRequests(t, feed)
	if len(reqs) < 6 || len(reqs) > 10 {
		t.Fatalf("%d checks in 4 days, want about 8 (every 12h)", len(reqs))
	}
	for i := 1; i < len(reqs); i++ {
		if gap := reqs[i].at.Sub(reqs[i-1].at) - dueSlack; gap < 12*hour*8/10 || gap > 12*hour*12/10 {
			t.Errorf("gap before check %d is %s, want 12h ±20%%", i+1, gap)
		}
	}

	// A post makes the feed active: until a day after its date, the day
	// tier, by default 1h; a week after it, the configured weeks4 tier, 8h.
	news := s.clock.Now()
	feed.addPost(simPost{title: "news", published: news})
	s.runUntil(s.clock.Now().Add(15 * hour))
	b := s.msgr.broadcasts()
	if len(b) != 1 {
		t.Fatalf("broadcasts = %v, want [news]", s.msgr.titles())
	}
	seen := b[0].at
	s.runUntil(seen.Add(10 * day))
	var dayTier, weeks4Tier []simRequest
	for _, r := range loopRequests(t, feed) {
		switch {
		case r.at.After(seen) && r.at.Before(news.Add(day)):
			dayTier = append(dayTier, r)
		case r.at.After(news.Add(8 * day)):
			weeks4Tier = append(weeks4Tier, r)
		}
	}
	if len(dayTier) < 5 {
		t.Fatalf("%d checks in the day after the post, want one about every hour", len(dayTier))
	}
	for i := 1; i < len(dayTier); i++ {
		if gap := dayTier[i].at.Sub(dayTier[i-1].at) - dueSlack; gap < hour*8/10 || gap > hour*12/10 {
			t.Errorf("gap in the day after the post is %s, want the default 1h ±20%%", gap)
		}
	}
	if len(weeks4Tier) < 2 {
		t.Fatalf("%d checks a week after the post, want several", len(weeks4Tier))
	}
	for i := 1; i < len(weeks4Tier); i++ {
		if gap := weeks4Tier[i].at.Sub(weeks4Tier[i-1].at) - dueSlack; gap < 8*hour*8/10 || gap > 8*hour*12/10 {
			t.Errorf("gap a week after the post is %s, want the configured 8h ±20%%", gap)
		}
	}
}