Skip to content

Commit 7c9a3bc

Browse files
committed
refactor: replace wall-clock time with monotonic nanoseconds for request eviction
- Add `created` timestamp to Jaws struct and capture it in New() - Introduce nowNano() method returning monotonic elapsed nanoseconds since creation - Update oldestEvictablePendingLocked to use nowNano instead of time.Time, and check lastWriteNano against 2*maintenanceInterval window - Replace all time.Now() calls with jw.nowNano() in pending eviction and maintenance logic - Switch from Rendering flag + lastWrite time comparison to direct lastWriteNano recency check - Update tests to simulate writes via MarkWritten instead of setting Rendering flag - Add BenchmarkRequestMarkWritten for write stamping performance tracking Signed-off-by: Johan Lindh <johan@linkdata.se>
1 parent 231424a commit 7c9a3bc

3 files changed

Lines changed: 133 additions & 63 deletions

File tree

‎jaws.go‎

Lines changed: 44 additions & 38 deletions
Original file line numberDiff line numberDiff line change
@@ -155,6 +155,7 @@ type Jaws struct {
155155
MaxPendingRequestsPerIP int // Maximum number of unclaimed Requests per client IP. Defaults to DefaultMaxPendingRequestsPerIP. Set <=0 to disable the cap.
156156
webSocketTimeout time.Duration // timeout duration passed to ServeWith
157157
maintenanceInterval time.Duration // Serve maintenance tick interval; set by ServeWithTimeout and read under mu, zero until Serve starts
158+
created time.Time // monotonic base captured in New(); read-only after construction, basis for nowNano
158159
bcastCh chan wire.Message
159160
subCh chan subscription
160161
unsubCh chan chan wire.Message
@@ -196,6 +197,7 @@ func New() (jw *Jaws, err error) {
196197
WebSocketPingInterval: DefaultWebSocketPingInterval,
197198
MaxPendingRequestsPerIP: DefaultMaxPendingRequestsPerIP,
198199
webSocketTimeout: DefaultWebSocketTimeout,
200+
created: time.Now(),
199201
serveJS: serveJS,
200202
serveCSS: serveCSS,
201203
bcastCh: make(chan wire.Message, 1),
@@ -407,15 +409,24 @@ func (jw *Jaws) NewRequest(r *http.Request) (rq *Request) {
407409
return
408410
}
409411

412+
// nowNano returns monotonic nanoseconds elapsed since the [Jaws] was created.
413+
//
414+
// It is the basis for [Request.MarkWritten] and the pending-eviction recency check.
415+
// Because it derives from [time.Since] on a [time.Time] carrying the monotonic clock,
416+
// the value is immune to wall-clock and NTP adjustments.
417+
func (jw *Jaws) nowNano() int64 {
418+
return int64(time.Since(jw.created))
419+
}
420+
410421
// limitPendingRequestsLocked evicts pending Requests for remoteIP until the cap is
411422
// satisfied, returning the eviction causes for the caller to log after releasing
412423
// jw.mu (see the package locking contract). Caller must hold jw.mu.
413424
func (jw *Jaws) limitPendingRequestsLocked(remoteIP netip.Addr) (toLog []error) {
414425
limit := jw.MaxPendingRequestsPerIP
415426
if limit > 0 {
416-
now := time.Now()
427+
nowNano := jw.nowNano()
417428
for len(jw.pending[remoteIP]) >= limit {
418-
victim := jw.oldestEvictablePendingLocked(remoteIP, now)
429+
victim := jw.oldestEvictablePendingLocked(remoteIP, nowNano)
419430
if victim == nil {
420431
// Every pending Request for this IP is rendering or rendered too
421432
// recently to evict safely. Recycling a still-rendering one would
@@ -437,42 +448,37 @@ func (jw *Jaws) limitPendingRequestsLocked(remoteIP netip.Addr) (toLog []error)
437448
}
438449

439450
// oldestEvictablePendingLocked returns the oldest pending [Request] for remoteIP
440-
// that is safe to recycle, or nil if every one of them might still be rendering.
441-
// now is the reference time for the recency check; the caller passes a single value
442-
// so all candidates are judged against the same instant. Caller must hold jw.mu.
443-
//
444-
// A Request is spared when its Rendering flag is set (it has been written to by
445-
// [RequestWriter] and may still be assembling its initial HTML, which recycling would
446-
// corrupt — see [Jaws.limitPendingRequestsLocked]), OR when it last wrote within
447-
// 2*maintenanceInterval. The recency check is required because [Request.maintenance]
448-
// clears Rendering once per maintenance interval: between that clear and the render
449-
// goroutine's next write the flag reads false even though the HTML is still in flight,
450-
// so keying eviction on the flag alone would recycle a live render.
451-
//
452-
// lastWrite tracks write activity, not render duration. Each [RequestWriter] write
453-
// re-arms Rendering, and the next [Request.maintenance] pass that observes it set
454-
// advances lastWrite to that pass's time. A render that keeps writing therefore keeps
455-
// refreshing lastWrite and stays spared; a render that produces no write for more than
456-
// two maintenance intervals — whether it has finished or has merely stalled between
457-
// writes — falls outside the window and becomes evictable. Reading lastWrite takes
458-
// rq.mu beneath jw.mu, the order documented in the package "Locking" section.
459-
//
460-
// maintenanceInterval is zero until [Jaws.ServeWithTimeout] starts. With no maintenance
461-
// pass running nothing clears Rendering, so the flag alone is authoritative and the
462-
// recency window is correctly skipped.
463-
func (jw *Jaws) oldestEvictablePendingLocked(remoteIP netip.Addr, now time.Time) *Request {
451+
// that is safe to recycle, or nil if every one of them was written too recently to
452+
// evict safely. nowNano is the reference instant (see [Jaws.nowNano]); the caller
453+
// passes a single value so all candidates are judged against the same instant.
454+
// Caller must hold jw.mu.
455+
//
456+
// A Request is spared while its initial HTML may still be in flight. Recycling a
457+
// Request whose render goroutine is still writing would let a later [Jaws.NewRequest]
458+
// reuse the pooled pointer under a new key while that goroutine keeps appending
459+
// elements (see [Jaws.limitPendingRequestsLocked]). [RequestWriter.Write] stamps the
460+
// write instant on every write via [Request.MarkWritten], so a Request is treated as
461+
// possibly-rendering, and spared, while its last write is within 2*maintenanceInterval.
462+
//
463+
// The timestamp is the exact instant of the last write, not a value sampled once per
464+
// maintenance pass, so an actively writing render is always fresh and only a render
465+
// that has produced no write for two intervals — whether finished or merely stalled
466+
// between writes — becomes evictable. lastWriteNano is read lock-free, so this scan
467+
// takes no Request lock.
468+
//
469+
// maintenanceInterval is zero until [Jaws.ServeWithTimeout] starts; the window then
470+
// falls back to [DefaultUpdateInterval] so an in-flight render is still protected
471+
// before the maintenance pass begins running.
472+
func (jw *Jaws) oldestEvictablePendingLocked(remoteIP netip.Addr, nowNano int64) *Request {
473+
interval := jw.maintenanceInterval
474+
if interval <= 0 {
475+
interval = DefaultUpdateInterval
476+
}
477+
spareWindow := int64(2 * interval)
464478
for _, rq := range jw.pending[remoteIP] {
465-
if rq.Rendering.Load() {
479+
if nowNano-rq.lastWriteNano.Load() <= spareWindow {
466480
continue
467481
}
468-
if jw.maintenanceInterval > 0 {
469-
rq.mu.RLock()
470-
recentlyRendered := now.Sub(rq.lastWrite) <= 2*jw.maintenanceInterval
471-
rq.mu.RUnlock()
472-
if recentlyRendered {
473-
continue
474-
}
475-
}
476482
return rq
477483
}
478484
return nil
@@ -744,9 +750,9 @@ func (jw *Jaws) unsubscribe(msgCh chan wire.Message) {
744750
func (jw *Jaws) maintenance(requestTimeout time.Duration) {
745751
var toLog []error
746752
jw.mu.Lock()
747-
now := time.Now()
753+
nowNano := jw.nowNano()
748754
for _, rq := range jw.requests {
749-
if expired, cause := rq.maintenance(now, requestTimeout); expired {
755+
if expired, cause := rq.maintenance(nowNano, requestTimeout); expired {
750756
if cause != nil {
751757
toLog = append(toLog, cause)
752758
}
@@ -833,7 +839,7 @@ func (jw *Jaws) getRequestLocked(jawsKey key.Key, r *http.Request, remoteIP neti
833839
rq.mu.Lock()
834840
defer rq.mu.Unlock()
835841
rq.JawsKey = jawsKey
836-
rq.lastWrite = time.Now()
842+
rq.lastWriteNano.Store(jw.nowNano())
837843
rq.initial = r
838844
rq.remoteIP = remoteIP
839845
rq.ctx, rq.cancelFn = context.WithCancelCause(jw.BaseContext)

‎jaws_benchmark_test.go‎

Lines changed: 20 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -51,7 +51,7 @@ func newUnpooledBenchRequest(jw *Jaws) (rq *Request) {
5151
}
5252
rq.mu.Lock()
5353
rq.JawsKey = jawsKey
54-
rq.lastWrite = time.Now()
54+
rq.lastWriteNano.Store(jw.nowNano())
5555
rq.remoteIP = remoteIP
5656
rq.ctx, rq.cancelFn = context.WithCancelCause(jw.BaseContext)
5757
rq.mu.Unlock()
@@ -405,3 +405,22 @@ func BenchmarkDistributeDirtSort(b *testing.B) {
405405
})
406406
}
407407
}
408+
409+
// BenchmarkRequestMarkWritten measures the per-write cost of recording the write
410+
// instant, which RequestWriter.Write incurs on every write during initial render.
411+
// It runs in parallel because the realistic load is many Requests rendering at
412+
// once; the operation must stay cheap and allocation-free under contention.
413+
func BenchmarkRequestMarkWritten(b *testing.B) {
414+
jw, err := New()
415+
if err != nil {
416+
b.Fatal(err)
417+
}
418+
b.Cleanup(func() { jw.Close() })
419+
rq := &Request{Jaws: jw}
420+
b.ReportAllocs()
421+
b.RunParallel(func(pb *testing.PB) {
422+
for pb.Next() {
423+
rq.MarkWritten()
424+
}
425+
})
426+
}

‎jaws_test.go‎

Lines changed: 69 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -234,12 +234,16 @@ func TestJaws_MaxPendingRequestsPerIPSparesRenderingRequest(t *testing.T) {
234234
renderingReq := newPendingLimitRequest("192.0.2.1:1000")
235235
renderingRq := jw.NewRequest(renderingReq)
236236
renderingKey := renderingRq.JawsKey
237-
// Simulate an in-flight initial render on the oldest pending Request.
238-
renderingRq.Rendering.Store(true)
237+
// Simulate an in-flight initial render on the oldest pending Request: a fresh
238+
// write timestamp. maintenanceInterval is zero here, so the spare window uses
239+
// the DefaultUpdateInterval floor.
240+
renderingRq.MarkWritten()
239241

240242
idleReq := newPendingLimitRequest("192.0.2.1:1001")
241243
idleRq := jw.NewRequest(idleReq)
242244
idleKey := idleRq.JawsKey
245+
// Age the idle Request well past the spare window so it is the eviction victim.
246+
setPendingLimitLastWrite(t, idleRq, time.Now().Add(-time.Hour))
243247

244248
// Creating a third same-IP Request trips the cap (pending == 2).
245249
newReq := newPendingLimitRequest("192.0.2.1:1002")
@@ -258,14 +262,10 @@ func TestJaws_MaxPendingRequestsPerIPSparesRenderingRequest(t *testing.T) {
258262
}
259263
}
260264

261-
// TestJaws_MaxPendingRequestsPerIPSparesRecentlyRenderedRequest verifies that the
262-
// pending cap does not evict a Request whose initial render is still in flight even
263-
// after a maintenance pass has cleared its Rendering flag. [Request.maintenance]
264-
// clears Rendering once per interval, so between that clear and the render goroutine's
265-
// next write the flag reads false while the HTML is still being assembled; keying
266-
// eviction on the flag alone would recycle the live render. oldestEvictablePendingLocked
267-
// therefore also spares a Request that rendered within 2*maintenanceInterval and falls
268-
// through to evict a genuinely idle one instead.
265+
// TestJaws_MaxPendingRequestsPerIPSparesRecentlyRenderedRequest verifies that with a
266+
// configured maintenanceInterval the pending cap spares a Request written within the
267+
// 2*maintenanceInterval recency window and falls through to evict a genuinely idle one
268+
// instead.
269269
func TestJaws_MaxPendingRequestsPerIPSparesRecentlyRenderedRequest(t *testing.T) {
270270
jw, err := New()
271271
if err != nil {
@@ -274,23 +274,17 @@ func TestJaws_MaxPendingRequestsPerIPSparesRecentlyRenderedRequest(t *testing.T)
274274
defer jw.Close()
275275
jw.MaxPendingRequestsPerIP = 2
276276
// Pretend the Serve loop is running with a one-minute maintenance interval so the
277-
// recency window is active (it is zero until ServeWithTimeout sets it).
277+
// recency window is 2*maintenanceInterval (it falls back to DefaultUpdateInterval
278+
// until ServeWithTimeout sets it).
278279
jw.mu.Lock()
279280
jw.maintenanceInterval = time.Minute
280281
jw.mu.Unlock()
281282

282-
// The oldest pending Request is mid-render...
283+
// The oldest pending Request wrote recently (its render is still in flight).
283284
renderingReq := newPendingLimitRequest("192.0.2.1:1000")
284285
renderingRq := jw.NewRequest(renderingReq)
285286
renderingKey := renderingRq.JawsKey
286-
renderingRq.Rendering.Store(true)
287-
288-
// ...and a maintenance pass clears its Rendering flag (refreshing lastWrite) while
289-
// the render is still in flight on its HTTP goroutine.
290-
jw.maintenance(time.Hour)
291-
if renderingRq.Rendering.Load() {
292-
t.Fatal("maintenance did not clear Rendering")
293-
}
287+
renderingRq.MarkWritten()
294288

295289
// A genuinely idle Request that rendered long ago is the correct eviction victim.
296290
idleReq := newPendingLimitRequest("192.0.2.1:1001")
@@ -316,6 +310,55 @@ func TestJaws_MaxPendingRequestsPerIPSparesRecentlyRenderedRequest(t *testing.T)
316310
}
317311
}
318312

313+
// TestJaws_MaxPendingRequestsPerIPSparesStalledLiveRender proves the eviction decision
314+
// tracks the actual last write, not a value sampled by the maintenance pass: a render
315+
// that wrote once and then stalled (no further writes) is still spared while that write
316+
// is within 2*maintenanceInterval, even across a maintenance pass — closing the gap
317+
// where clearing a flag on a tick could expose a live render to recycling.
318+
func TestJaws_MaxPendingRequestsPerIPSparesStalledLiveRender(t *testing.T) {
319+
jw, err := New()
320+
if err != nil {
321+
t.Fatal(err)
322+
}
323+
defer jw.Close()
324+
jw.MaxPendingRequestsPerIP = 2
325+
jw.mu.Lock()
326+
jw.maintenanceInterval = time.Minute
327+
jw.mu.Unlock()
328+
329+
// Oldest pending: a single write, then silence. Its timestamp stays fresh.
330+
stalledReq := newPendingLimitRequest("192.0.2.1:1000")
331+
stalledRq := jw.NewRequest(stalledReq)
332+
stalledKey := stalledRq.JawsKey
333+
stalledRq.MarkWritten()
334+
335+
// A maintenance pass must not disturb the write timestamp (generous timeout so the
336+
// stalled render is not idle-expired). Under a flag-cleared-by-tick scheme this is
337+
// where protection could be lost.
338+
jw.maintenance(time.Hour)
339+
340+
// A genuinely idle sibling is the correct victim.
341+
idleReq := newPendingLimitRequest("192.0.2.1:1001")
342+
idleRq := jw.NewRequest(idleReq)
343+
idleKey := idleRq.JawsKey
344+
setPendingLimitLastWrite(t, idleRq, time.Now().Add(-time.Hour))
345+
346+
// A third same-IP Request trips the cap (pending == 2).
347+
newReq := newPendingLimitRequest("192.0.2.1:1002")
348+
newRq := jw.NewRequest(newReq)
349+
newKey := newRq.JawsKey
350+
351+
if claimed := jw.UseRequest(stalledKey, stalledReq); claimed != stalledRq {
352+
t.Fatalf("stalled-but-recently-written render claim = %v, want it to survive eviction", claimed)
353+
}
354+
if claimed := jw.UseRequest(idleKey, idleReq); claimed != nil {
355+
t.Fatalf("idle request should have been evicted, got %v", claimed)
356+
}
357+
if claimed := jw.UseRequest(newKey, newReq); claimed != newRq {
358+
t.Fatalf("new request claim = %v, want %v", claimed, newRq)
359+
}
360+
}
361+
319362
// TestJaws_MaxPendingRequestsPerIPOvershootsWhenAllRendering verifies that when
320363
// every pending request for an IP is mid-render, the cap is not enforced by
321364
// recycling one of them: oldestEvictablePendingLocked finds no idle victim, so the
@@ -331,7 +374,7 @@ func TestJaws_MaxPendingRequestsPerIPOvershootsWhenAllRendering(t *testing.T) {
331374

332375
rq1 := jw.NewRequest(newPendingLimitRequest("192.0.2.1:1000"))
333376
rq1Key := rq1.JawsKey
334-
rq1.Rendering.Store(true)
377+
rq1.MarkWritten()
335378

336379
// A second same-IP request trips the cap, but the only pending request is
337380
// rendering, so nothing is evicted and the cap overshoots to 2.
@@ -621,9 +664,11 @@ func newPendingLimitRequest(remoteAddr string) *http.Request {
621664

622665
func setPendingLimitLastWrite(t *testing.T, rq *Request, lastWrite time.Time) {
623666
t.Helper()
624-
rq.mu.Lock()
625-
rq.lastWrite = lastWrite
626-
rq.mu.Unlock()
667+
// lastWriteNano holds monotonic nanos since rq.Jaws.created; convert the wall
668+
// time the test wants relative to that base. A past instant yields a negative
669+
// value, which reads as far older than any spare/idle window — exactly what an
670+
// "aged" request should look like.
671+
rq.lastWriteNano.Store(int64(lastWrite.Sub(rq.Jaws.created)))
627672
}
628673

629674
func TestCoverage_GenerateHeadAndConvenienceBroadcasts(t *testing.T) {

0 commit comments

Comments
 (0)