|
| 1 | +package wirelog |
| 2 | + |
| 3 | +import ( |
| 4 | + "net/http" |
| 5 | + "strconv" |
| 6 | + "strings" |
| 7 | + "sync" |
| 8 | + "time" |
| 9 | +) |
| 10 | + |
| 11 | +// The ledger exists because a span is not an answer. |
| 12 | +// |
| 13 | +// Every provider round-trip already emits an OTel span event, and those events |
| 14 | +// carried enough to diagnose a 77-minute stall AFTER the fact - but only after |
| 15 | +// someone wrote a JSON scanner against traces.jsonl, and only for turns that |
| 16 | +// had already ENDED, because spans export on end. The one question an operator |
| 17 | +// actually asks - "what is this aria doing right now, and what did the provider |
| 18 | +// last say to it" - had no surface at all: an in-flight request is invisible to |
| 19 | +// tracing by construction. |
| 20 | +// |
| 21 | +// So the transport keeps its own bounded ring of recent round-trips, recorded |
| 22 | +// at REQUEST START (in flight) and completed in place. It costs a few kilobytes |
| 23 | +// and answers the question directly. `figaro doctor provider` reads it. |
| 24 | + |
| 25 | +// Round is one provider HTTP round-trip as the transport saw it. |
| 26 | +// |
| 27 | +// A Round appears in the ledger the moment the request leaves, with InFlight |
| 28 | +// true and Status zero; the same record is completed on return. That ordering |
| 29 | +// is the point: a request that never comes back is the interesting one. |
| 30 | +type Round struct { |
| 31 | + Seq uint64 `json:"seq"` |
| 32 | + Aria string `json:"aria,omitempty"` |
| 33 | + |
| 34 | + Method string `json:"method"` |
| 35 | + URL string `json:"url"` |
| 36 | + |
| 37 | + StartedAt time.Time `json:"started_at"` |
| 38 | + DurationMS int64 `json:"duration_ms"` // 0 while in flight |
| 39 | + InFlight bool `json:"in_flight"` |
| 40 | + |
| 41 | + // Status is the HTTP status, 0 when the round-trip failed below HTTP or |
| 42 | + // has not returned. |
| 43 | + Status int `json:"status,omitempty"` |
| 44 | + RequestID string `json:"request_id,omitempty"` |
| 45 | + ReqBytes int64 `json:"req_bytes,omitempty"` |
| 46 | + |
| 47 | + // RetryAfterS is the Retry-After the server asked for, in seconds, EXACTLY |
| 48 | + // as sent. This is the number that explains an apparent hang - an |
| 49 | + // hour-long value on a 429 is a usage-window reset, not a throttle - and |
| 50 | + // until now it was recorded in no log, metric or span anywhere in figaro. |
| 51 | + RetryAfterS int64 `json:"retry_after_s,omitempty"` |
| 52 | + // RateLimit is the provider's own account of the limit that was hit, |
| 53 | + // gathered from its ratelimit response headers. Empty when it said |
| 54 | + // nothing. |
| 55 | + RateLimit map[string]string `json:"rate_limit,omitempty"` |
| 56 | + |
| 57 | + Err string `json:"err,omitempty"` |
| 58 | +} |
| 59 | + |
| 60 | +// RateLimited reports whether the provider refused this round-trip for quota |
| 61 | +// reasons. 529 is anthropic's "overloaded", which is the same shape of answer. |
| 62 | +func (r Round) RateLimited() bool { return r.Status == http.StatusTooManyRequests || r.Status == 529 } |
| 63 | + |
| 64 | +const defaultLedgerSize = 256 |
| 65 | + |
| 66 | +var ledger = struct { |
| 67 | + mu sync.Mutex |
| 68 | + buf []Round |
| 69 | + next int // write cursor |
| 70 | + seq uint64 |
| 71 | +}{buf: make([]Round, 0, defaultLedgerSize)} |
| 72 | + |
| 73 | +// ResizeLedger sets how many recent round-trips are retained, dropping the |
| 74 | +// current contents. Zero disables recording. |
| 75 | +func ResizeLedger(n int) { |
| 76 | + if n < 0 { |
| 77 | + n = 0 |
| 78 | + } |
| 79 | + ledger.mu.Lock() |
| 80 | + defer ledger.mu.Unlock() |
| 81 | + ledger.buf = make([]Round, 0, n) |
| 82 | + ledger.next = 0 |
| 83 | +} |
| 84 | + |
| 85 | +// open records a departing request and returns its sequence number, or 0 when |
| 86 | +// recording is off. The seq is how complete finds the row again: an index |
| 87 | +// would be wrong the moment the ring wrapped. |
| 88 | +func open(aria, method, url string, reqBytes int64) uint64 { |
| 89 | + ledger.mu.Lock() |
| 90 | + defer ledger.mu.Unlock() |
| 91 | + if cap(ledger.buf) == 0 { |
| 92 | + return 0 |
| 93 | + } |
| 94 | + ledger.seq++ |
| 95 | + r := Round{ |
| 96 | + Seq: ledger.seq, |
| 97 | + Aria: aria, |
| 98 | + Method: method, |
| 99 | + URL: url, |
| 100 | + StartedAt: time.Now(), |
| 101 | + InFlight: true, |
| 102 | + ReqBytes: reqBytes, |
| 103 | + } |
| 104 | + if len(ledger.buf) < cap(ledger.buf) { |
| 105 | + ledger.buf = append(ledger.buf, r) |
| 106 | + } else { |
| 107 | + ledger.buf[ledger.next] = r |
| 108 | + ledger.next = (ledger.next + 1) % cap(ledger.buf) |
| 109 | + } |
| 110 | + return r.Seq |
| 111 | +} |
| 112 | + |
| 113 | +// complete fills in the answer for a round opened earlier. A row that has |
| 114 | +// already been evicted by the ring is simply dropped: the request outlived our |
| 115 | +// retention, which is itself visible as a gap in seq. |
| 116 | +func complete(seq uint64, resp *http.Response, d time.Duration, err error) { |
| 117 | + if seq == 0 { |
| 118 | + return |
| 119 | + } |
| 120 | + ledger.mu.Lock() |
| 121 | + defer ledger.mu.Unlock() |
| 122 | + for i := range ledger.buf { |
| 123 | + if ledger.buf[i].Seq != seq { |
| 124 | + continue |
| 125 | + } |
| 126 | + r := &ledger.buf[i] |
| 127 | + r.InFlight = false |
| 128 | + r.DurationMS = d.Milliseconds() |
| 129 | + if err != nil { |
| 130 | + r.Err = err.Error() |
| 131 | + } |
| 132 | + if resp != nil { |
| 133 | + r.Status = resp.StatusCode |
| 134 | + r.RequestID = requestID(resp.Header) |
| 135 | + r.RetryAfterS = int64(RetryAfter(resp.Header) / time.Second) |
| 136 | + r.RateLimit = rateLimitHeaders(resp.Header) |
| 137 | + } |
| 138 | + return |
| 139 | + } |
| 140 | +} |
| 141 | + |
| 142 | +// Recent returns up to n round-trips, newest last. n <= 0 returns all retained. |
| 143 | +func Recent(n int) []Round { |
| 144 | + ledger.mu.Lock() |
| 145 | + defer ledger.mu.Unlock() |
| 146 | + if len(ledger.buf) == 0 { |
| 147 | + return nil |
| 148 | + } |
| 149 | + out := make([]Round, 0, len(ledger.buf)) |
| 150 | + // Walk oldest-first: entries live in write order from next, once wrapped. |
| 151 | + if len(ledger.buf) < cap(ledger.buf) { |
| 152 | + out = append(out, ledger.buf...) |
| 153 | + } else { |
| 154 | + out = append(out, ledger.buf[ledger.next:]...) |
| 155 | + out = append(out, ledger.buf[:ledger.next]...) |
| 156 | + } |
| 157 | + if n > 0 && len(out) > n { |
| 158 | + out = out[len(out)-n:] |
| 159 | + } |
| 160 | + return out |
| 161 | +} |
| 162 | + |
| 163 | +// RetryAfter reads a Retry-After header expressed in seconds. The HTTP-date |
| 164 | +// form is not honored (no provider we speak to uses it) and reads as absent. |
| 165 | +func RetryAfter(h http.Header) time.Duration { |
| 166 | + v := strings.TrimSpace(h.Get("Retry-After")) |
| 167 | + if v == "" { |
| 168 | + return 0 |
| 169 | + } |
| 170 | + secs, err := strconv.Atoi(v) |
| 171 | + if err != nil || secs < 0 { |
| 172 | + return 0 |
| 173 | + } |
| 174 | + return time.Duration(secs) * time.Second |
| 175 | +} |
| 176 | + |
| 177 | +// rateLimitHeaders harvests the provider's own limit accounting. Anthropic |
| 178 | +// sends anthropic-ratelimit-*; the x-ratelimit-* spelling is common elsewhere. |
| 179 | +// Whatever it is called, it names WHICH limit was hit, which "429" does not. |
| 180 | +func rateLimitHeaders(h http.Header) map[string]string { |
| 181 | + var out map[string]string |
| 182 | + for k, vs := range h { |
| 183 | + lk := strings.ToLower(k) |
| 184 | + if !strings.Contains(lk, "ratelimit") || len(vs) == 0 { |
| 185 | + continue |
| 186 | + } |
| 187 | + if out == nil { |
| 188 | + out = make(map[string]string, 4) |
| 189 | + } |
| 190 | + // Keep the distinguishing tail ("requests-remaining"), not the vendor |
| 191 | + // prefix, so the same key means the same thing across providers. |
| 192 | + key := lk |
| 193 | + for _, pfx := range []string{"anthropic-ratelimit-", "x-ratelimit-", "ratelimit-"} { |
| 194 | + if strings.HasPrefix(lk, pfx) { |
| 195 | + key = strings.TrimPrefix(lk, pfx) |
| 196 | + break |
| 197 | + } |
| 198 | + } |
| 199 | + out[key] = vs[0] |
| 200 | + } |
| 201 | + return out |
| 202 | +} |
| 203 | + |
| 204 | +func requestID(h http.Header) string { |
| 205 | + if v := h.Get("request-id"); v != "" { |
| 206 | + return v |
| 207 | + } |
| 208 | + return h.Get("x-request-id") |
| 209 | +} |
0 commit comments