Skip to content

Commit 7df48cc

Browse files
authored
Merge pull request #10 from dappnode/fix/keep-credit-holds-alive
feat: keep the credit hold alive while inference runs
2 parents 7ed69cb + 5592ed1 commit 7df48cc

6 files changed

Lines changed: 321 additions & 3 deletions

File tree

‎apps/gateway/internal/adapters/metering/client.go‎

Lines changed: 12 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -11,6 +11,7 @@ import (
1111
"reflect"
1212
"strconv"
1313
"strings"
14+
"sync"
1415
"time"
1516

1617
"github.com/dappnode/dappnode-nexus-gateway/apps/gateway/internal/adapters/observability/metrics"
@@ -19,9 +20,10 @@ import (
1920
)
2021

2122
type Client struct {
22-
baseURL string
23-
token string
24-
http *http.Client
23+
baseURL string
24+
token string
25+
http *http.Client
26+
reservations sync.Map // Unclaimed leases by reservation ID, removed by KeepReservation.
2527
}
2628

2729
func NewClient(baseURL, token string, timeout time.Duration) *Client {
@@ -58,12 +60,16 @@ func (c *Client) Reserve(ctx context.Context, auth domain.AuthContext, endpoint
5860
MaxOutputTokens: req.MaxOutputTokens,
5961
}
6062
var res reserveResponse
63+
sent := time.Now() // A lease measured from here never outlasts Metering's.
6164
if err := c.postJSON(ctx, "/internal/metering/reservations", payload, &res, 2); err != nil {
6265
return "", err
6366
}
6467
if res.ReservationID == "" {
6568
return "", meteringInternalError("reason", "missing reservation_id")
6669
}
70+
if res.LeaseMS > 0 {
71+
c.reservations.Store(res.ReservationID, newLease(sent, res.LeaseMS))
72+
}
6773
return res.ReservationID, nil
6874
}
6975

@@ -365,6 +371,8 @@ func meteringOperation(method, path string) string {
365371
return "reserve"
366372
case method == http.MethodPost && strings.Contains(requestPath, "/reservations/") && strings.HasSuffix(requestPath, "/complete"):
367373
return "complete"
374+
case method == http.MethodPost && strings.Contains(requestPath, "/reservations/") && strings.HasSuffix(requestPath, "/renew"):
375+
return "renew"
368376
case method == http.MethodPost && strings.HasSuffix(requestPath, "/usage-failures"):
369377
return "record_failure"
370378
case method == http.MethodPost && strings.HasSuffix(requestPath, "/authenticate"):
@@ -413,6 +421,7 @@ type reserveRequest struct {
413421

414422
type reserveResponse struct {
415423
ReservationID string `json:"reservation_id"`
424+
LeaseMS int64 `json:"lease_ms,omitempty"`
416425
}
417426

418427
type completeRequest struct {
Lines changed: 88 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,88 @@
1+
package metering
2+
3+
import (
4+
"context"
5+
"errors"
6+
"time"
7+
8+
"github.com/dappnode/dappnode-nexus-gateway/pkg/domain"
9+
)
10+
11+
// lease is a credit hold measured on this process's clock. Metering sends a
12+
// duration rather than a timestamp, so clock skew (an enclave) cannot make a
13+
// hold look expired or valid when it is not.
14+
type lease struct {
15+
expires time.Time
16+
length time.Duration
17+
}
18+
19+
func newLease(sent time.Time, ms int64) lease {
20+
length := time.Duration(ms) * time.Millisecond
21+
return lease{expires: sent.Add(length), length: length}
22+
}
23+
24+
// KeepReservation renews a hold at a third of its remaining time until stop is
25+
// called. Transient failures retry within the lease, never more often than a
26+
// tenth of it or once per second. onLost runs when Metering says the hold is
27+
// gone, or when it expires without a successful renewal.
28+
func (c *Client) KeepReservation(parent context.Context, id string, onLost func()) func() {
29+
value, ok := c.reservations.LoadAndDelete(id)
30+
if !ok {
31+
return func() {} // Older Metering responses do not advertise leases.
32+
}
33+
held := value.(lease)
34+
floor := min(time.Second, held.length/10)
35+
ctx, cancel := context.WithCancel(parent)
36+
done := make(chan struct{})
37+
lost := func() {
38+
if ctx.Err() == nil {
39+
onLost()
40+
}
41+
}
42+
go func() {
43+
defer close(done)
44+
for {
45+
remaining := time.Until(held.expires)
46+
if remaining <= 0 {
47+
lost()
48+
return
49+
}
50+
timer := time.NewTimer(min(max(remaining/3, floor), remaining))
51+
select {
52+
case <-ctx.Done():
53+
timer.Stop()
54+
return
55+
case <-timer.C:
56+
}
57+
if time.Until(held.expires) <= 0 {
58+
continue
59+
}
60+
requestCtx, stop := context.WithDeadline(ctx, held.expires)
61+
var result reserveResponse
62+
sent := time.Now()
63+
err := c.postJSON(requestCtx, "/internal/metering/reservations/"+id+"/renew", struct{}{}, &result, 0)
64+
stop()
65+
switch {
66+
case err == nil && result.ReservationID == id && result.LeaseMS > 0:
67+
if renewed := newLease(sent, result.LeaseMS); renewed.expires.After(held.expires) {
68+
held = renewed
69+
}
70+
case rejectedByMetering(err):
71+
lost() // Completed, expired, or unknown: retrying cannot restore it.
72+
return
73+
}
74+
}
75+
}()
76+
return func() { cancel(); <-done }
77+
}
78+
79+
// rejectedByMetering reports a 4xx answer; transport errors and 5xx are
80+
// transient and retried while the lease lasts.
81+
func rejectedByMetering(err error) bool {
82+
var gwErr *domain.GatewayError
83+
if !errors.As(err, &gwErr) {
84+
return false
85+
}
86+
status, ok := gwErr.Metadata["metering_status"].(int)
87+
return ok && status >= 400 && status < 500
88+
}
Lines changed: 137 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,137 @@
1+
package metering
2+
3+
import (
4+
"context"
5+
"encoding/json"
6+
"net/http"
7+
"net/http/httptest"
8+
"sync/atomic"
9+
"testing"
10+
"time"
11+
12+
"github.com/dappnode/dappnode-nexus-gateway/pkg/domain"
13+
)
14+
15+
func TestReservationRenewsBeyondOriginalExpiryAndStops(t *testing.T) {
16+
var calls atomic.Int32
17+
var lost atomic.Bool
18+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
19+
if calls.Add(1) == 1 {
20+
w.WriteHeader(503)
21+
return
22+
}
23+
json.NewEncoder(w).Encode(reserveResponse{ReservationID: "lease", LeaseMS: 300})
24+
}))
25+
defer server.Close()
26+
client := NewClient(server.URL, "fixture", time.Second)
27+
client.reservations.Store("lease", newLease(time.Now(), 300))
28+
stop := client.KeepReservation(context.Background(), "lease", func() { lost.Store(true) })
29+
time.Sleep(600 * time.Millisecond)
30+
stop()
31+
if lost.Load() || calls.Load() < 3 {
32+
t.Fatalf("renewal did not preserve hold: lost=%v calls=%d", lost.Load(), calls.Load())
33+
}
34+
before := calls.Load()
35+
time.Sleep(150 * time.Millisecond)
36+
if calls.Load() != before {
37+
t.Fatal("renewal continued after stop")
38+
}
39+
}
40+
41+
func TestLostReservationStopsOnlyWhenLeaseExpires(t *testing.T) {
42+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) { w.WriteHeader(503) }))
43+
defer server.Close()
44+
client := NewClient(server.URL, "fixture", time.Second)
45+
client.reservations.Store("lease", newLease(time.Now(), 120))
46+
lost := make(chan struct{})
47+
stop := client.KeepReservation(context.Background(), "lease", func() { close(lost) })
48+
defer stop()
49+
select {
50+
case <-lost:
51+
t.Fatal("temporary error canceled a valid lease")
52+
case <-time.After(50 * time.Millisecond):
53+
}
54+
select {
55+
case <-lost:
56+
case <-time.After(time.Second):
57+
t.Fatal("lost hold did not stop inference")
58+
}
59+
}
60+
61+
// Metering refusing a renewal means the hold is gone; retrying cannot help.
62+
func TestRejectedRenewalIsLostImmediately(t *testing.T) {
63+
var calls atomic.Int32
64+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
65+
calls.Add(1)
66+
w.WriteHeader(http.StatusConflict)
67+
json.NewEncoder(w).Encode(map[string]any{"error": map[string]string{"code": "conflict", "message": "reservation is no longer active"}})
68+
}))
69+
defer server.Close()
70+
client := NewClient(server.URL, "fixture", time.Second)
71+
client.reservations.Store("lease", newLease(time.Now(), 3000))
72+
lost := make(chan struct{})
73+
stop := client.KeepReservation(context.Background(), "lease", func() { close(lost) })
74+
defer stop()
75+
select {
76+
case <-lost:
77+
case <-time.After(1500 * time.Millisecond):
78+
t.Fatal("rejected renewal waited for the lease to run out")
79+
}
80+
if calls.Load() != 1 {
81+
t.Fatalf("retried a rejected renewal: %d calls", calls.Load())
82+
}
83+
}
84+
85+
// During a Metering outage each request renews a bounded number of times
86+
// instead of an accelerating burst as the lease runs out.
87+
func TestRenewalRetriesAreSpacedDuringOutage(t *testing.T) {
88+
var calls atomic.Int32
89+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
90+
calls.Add(1)
91+
w.WriteHeader(503)
92+
}))
93+
defer server.Close()
94+
client := NewClient(server.URL, "fixture", time.Second)
95+
client.reservations.Store("lease", newLease(time.Now(), 1000))
96+
lost := make(chan struct{})
97+
stop := client.KeepReservation(context.Background(), "lease", func() { close(lost) })
98+
defer stop()
99+
select {
100+
case <-lost:
101+
case <-time.After(3 * time.Second):
102+
t.Fatal("lease never expired")
103+
}
104+
// One tenth of a 1 s lease is 100 ms, so at most about ten attempts.
105+
if got := calls.Load(); got > 11 {
106+
t.Fatalf("renewal attempts were not spaced: %d", got)
107+
}
108+
}
109+
110+
// The lease is measured on the Gateway's clock from before the request, so a
111+
// skewed Metering or enclave clock cannot shorten or extend it.
112+
func TestReserveStoresLeaseRelativeToGatewayClock(t *testing.T) {
113+
server := httptest.NewServer(http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
114+
json.NewEncoder(w).Encode(reserveResponse{ReservationID: "lease", LeaseMS: 60_000})
115+
}))
116+
defer server.Close()
117+
client := NewClient(server.URL, "fixture", time.Second)
118+
before := time.Now()
119+
id, err := client.Reserve(context.Background(), domain.AuthContext{Account: domain.Account{ID: "a"}, APIKey: domain.APIKey{ID: "k"}}, "chat/completions", domain.GenerateRequest{}, domain.PublicModel{PublicModelID: "m"}, "request")
120+
if err != nil || id != "lease" {
121+
t.Fatalf("reserve = %q, %v", id, err)
122+
}
123+
value, ok := client.reservations.Load("lease")
124+
if !ok {
125+
t.Fatal("lease not stored")
126+
}
127+
held := value.(lease)
128+
if held.length != time.Minute || held.expires.Before(before.Add(time.Minute)) || held.expires.After(time.Now().Add(time.Minute)) {
129+
t.Fatalf("lease = %+v", held)
130+
}
131+
}
132+
133+
func TestRenewalMetricsDoNotIncludeReservationIDs(t *testing.T) {
134+
if got := meteringOperation(http.MethodPost, "/internal/metering/reservations/private-id/renew"); got != "renew" {
135+
t.Fatalf("renewal metric operation = %q", got)
136+
}
137+
}

‎apps/gateway/internal/application/ports/usage.go‎

Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -14,3 +14,9 @@ type UsageMeter interface {
1414
RecordSuccess(ctx context.Context, reservationID string, auth domain.AuthContext, endpoint string, req domain.GenerateRequest, resp domain.GenerateResult, model domain.PublicModel, latencyMs int64) error
1515
RecordFailure(ctx context.Context, reservationID *string, auth *domain.AuthContext, endpoint string, req *domain.GenerateRequest, model *domain.PublicModel, err error, partialUsage *domain.Usage, latencyMs int64) error
1616
}
17+
18+
// ReservationKeeper maintains a live credit hold while inference progresses.
19+
// onLost stops inference only when renewal cannot preserve the hold.
20+
type ReservationKeeper interface {
21+
KeepReservation(context.Context, string, func()) func()
22+
}

‎apps/gateway/internal/application/services/proxy.go‎

Lines changed: 15 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ import (
1313

1414
"github.com/dappnode/dappnode-nexus-gateway/apps/gateway/internal/adapters/http/middleware"
1515
"github.com/dappnode/dappnode-nexus-gateway/apps/gateway/internal/adapters/observability/metrics"
16+
"github.com/dappnode/dappnode-nexus-gateway/apps/gateway/internal/application/ports"
1617
"github.com/dappnode/dappnode-nexus-gateway/pkg/domain"
1718
"github.com/dappnode/dappnode-nexus-gateway/pkg/observability/logfields"
1819
"github.com/google/uuid"
@@ -72,7 +73,17 @@ func (s *GenerateService) Proxy(ctx context.Context, endpoint string, raw []byte
7273
s.recordTerminalOutcome(metrics.OutcomeError, endpoint, execReq, &model, time.Since(start).Milliseconds())
7374
return nil, err
7475
}
76+
ctx, cancelInference := context.WithCancelCause(ctx)
77+
stopRenewal := func() {}
78+
if keeper, ok := s.metering.(ports.ReservationKeeper); ok {
79+
stopRenewal = keeper.KeepReservation(ctx, reservationID, func() { cancelInference(domain.ErrInternal("credit reservation could not be maintained")) })
80+
}
81+
stopLease := func() { stopRenewal(); cancelInference(nil) }
7582
finish := func(target domain.PublicModel, o outcome) {
83+
defer stopLease()
84+
if cause, ok := context.Cause(ctx).(*domain.GatewayError); ok && o.err != nil {
85+
o.err = cause
86+
}
7687
o.err = sanitizeErrorWithPIIMapping(o.err, mapping)
7788
s.finishProxy(ctx, authCtx, endpoint, execReq, target, requestID, reservationID, start, o)
7889
}
@@ -138,6 +149,10 @@ func (s *GenerateService) Proxy(ctx context.Context, endpoint string, raw []byte
138149
call, err = attempt(executed)
139150
}
140151
if err != nil {
152+
defer stopLease()
153+
if cause, ok := context.Cause(ctx).(*domain.GatewayError); ok {
154+
err = cause
155+
}
141156
err = sanitizeErrorWithPIIMapping(err, mapping)
142157
fields := s.buildErrorLogFields(ctx, requestID, &authCtx, endpoint, execReq.PublicModelID, executed, err, time.Since(start).Milliseconds())
143158
s.logger.Error("provider request failed", fields...)
Lines changed: 63 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,63 @@
1+
package services
2+
3+
import (
4+
"context"
5+
"strings"
6+
"testing"
7+
8+
"github.com/dappnode/dappnode-nexus-gateway/apps/gateway/internal/application/ports"
9+
"github.com/dappnode/dappnode-nexus-gateway/pkg/domain"
10+
)
11+
12+
// keeperMeter is a meter whose credit hold can be lost before inference ends.
13+
type keeperMeter struct {
14+
stubUsageMeter
15+
lose bool
16+
stopped bool
17+
}
18+
19+
func (m *keeperMeter) KeepReservation(_ context.Context, _ string, onLost func()) func() {
20+
if m.lose {
21+
onLost()
22+
}
23+
return func() { m.stopped = true }
24+
}
25+
26+
// waitingProvider answers only when its request is canceled, like a slow
27+
// upstream that is still working.
28+
type waitingProvider struct{ stubProvider }
29+
30+
func (p *waitingProvider) Complete(ctx context.Context, _ []byte, _ domain.PublicModel) ([]byte, *domain.TinfoilTransportProof, error) {
31+
<-ctx.Done()
32+
return nil, nil, ctx.Err()
33+
}
34+
35+
func keeperService(meter *keeperMeter, provider ports.Provider) *GenerateService {
36+
return NewGenerateService(
37+
&stubAuthService{authCtx: domain.AuthContext{Account: domain.Account{ID: "acc1", Status: domain.AccountStatusActive}, APIKey: domain.APIKey{ID: "key1", Active: true}}},
38+
&stubModelCatalog{model: domain.PublicModel{PublicModelID: "model", ProviderModelID: "provider-model", ProviderConfig: domain.ProviderConfig{ProviderName: "openai"}, SupportsChatCompletions: true, MaxContextWindow: 1000, MaxOutputTokens: 100}},
39+
nil, &stubProviderRegistry{providers: map[string]ports.Provider{"openai": provider}}, meter, nil, stubLogger{},
40+
)
41+
}
42+
43+
func TestProxy_StopsInferenceWhenCreditHoldIsLost(t *testing.T) {
44+
meter := &keeperMeter{lose: true}
45+
_, err := keeperService(meter, &waitingProvider{}).Proxy(context.Background(), domain.EndpointChatCompletions, []byte(`{}`), domain.GenerateRequest{PublicModelID: "model"}, "sk-test")
46+
gwErr, ok := err.(*domain.GatewayError)
47+
if !ok || gwErr.Code != domain.ErrCodeInternalError || !strings.Contains(gwErr.Message, "credit reservation") {
48+
t.Fatalf("lost hold reported as %v, want an internal error, not a user cancellation", err)
49+
}
50+
if meter.failureCalls != 1 || !meter.stopped {
51+
t.Fatalf("failure recorded %d times, keeper stopped %v", meter.failureCalls, meter.stopped)
52+
}
53+
}
54+
55+
func TestProxy_StopsKeepingHoldAfterCompletion(t *testing.T) {
56+
meter := &keeperMeter{}
57+
if _, err := keeperService(meter, &stubProvider{}).Proxy(context.Background(), domain.EndpointChatCompletions, []byte(`{}`), domain.GenerateRequest{PublicModelID: "model"}, "sk-test"); err != nil {
58+
t.Fatal(err)
59+
}
60+
if meter.successCalls != 1 || !meter.stopped {
61+
t.Fatalf("success recorded %d times, keeper stopped %v", meter.successCalls, meter.stopped)
62+
}
63+
}

0 commit comments

Comments
 (0)