|
| 1 | +// Copyright 2026 Google LLC |
| 2 | +// |
| 3 | +// Licensed under the Apache License, Version 2.0 (the "License"); |
| 4 | +// you may not use this file except in compliance with the License. |
| 5 | +// You may obtain a copy of the License at |
| 6 | +// |
| 7 | +// http://www.apache.org/licenses/LICENSE-2.0 |
| 8 | +// |
| 9 | +// Unless required by applicable law or agreed to in writing, software |
| 10 | +// distributed under the License is distributed on an "AS IS" BASIS, |
| 11 | +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. |
| 12 | +// See the License for the specific language governing permissions and |
| 13 | +// limitations under the License. |
| 14 | + |
| 15 | +// debug_tracer.go — counter for "this branch shouldn't be reached" |
| 16 | +// sites in the session pool, session, and configuration manager. One |
| 17 | +// atomic add plus one OTel Int64Counter increment per emission, so it's |
| 18 | +// cheap enough to sprinkle on cold paths. The metric name matches |
| 19 | +// java-bigtable's ClientDebugTagCount so cross-language dashboards can |
| 20 | +// join on the tag column. |
| 21 | +// |
| 22 | +// # Entry points |
| 23 | +// |
| 24 | +// - recordDebugTag(name) — Warn-level observation. |
| 25 | +// - recordDebugTagAt(level, name) — same, non-Warn level. |
| 26 | +// - assertDebugTag(expr, name) — invariant check, no format args. |
| 27 | +// - assertDebugTagf(expr, name, fmt…) — invariant check with log context. |
| 28 | +// |
| 29 | +// The assert forms return `expr` and never panic; use as `if !assert…` |
| 30 | +// so the site records + logs + bails in one line. |
| 31 | +// |
| 32 | +// # Rules |
| 33 | +// |
| 34 | +// - `name` is always a constant from the catalog below — never a |
| 35 | +// format string. Dynamic context belongs in the log message. |
| 36 | +// - Emission is additive: keep whatever log/err/return the branch |
| 37 | +// already does. |
| 38 | +// - Default to recordDebugTag (Warn). Reserve Error for assert |
| 39 | +// failures and the rare "this is really wrong" observation. |
| 40 | + |
| 41 | +package internal |
| 42 | + |
| 43 | +import ( |
| 44 | + "context" |
| 45 | + "fmt" |
| 46 | + "sort" |
| 47 | + "sync" |
| 48 | + "sync/atomic" |
| 49 | + "time" |
| 50 | + |
| 51 | + btopt "cloud.google.com/go/bigtable/internal/option" |
| 52 | + "go.opentelemetry.io/otel/attribute" |
| 53 | + "go.opentelemetry.io/otel/metric" |
| 54 | +) |
| 55 | + |
| 56 | +// debugLevel gates whether an emission is admitted. Values match |
| 57 | +// Java's TelemetryConfiguration.Level so future wire-config plumbing |
| 58 | +// is a straight cast. |
| 59 | +type debugLevel int32 |
| 60 | + |
| 61 | +// lvl namespaces the two levels so call sites read as `lvl.Warn` / |
| 62 | +// `lvl.Error`. Named `lvl` (not `tag`) so it doesn't collide visually |
| 63 | +// with the `tag…` catalog constants at call sites. |
| 64 | +var lvl = struct { |
| 65 | + Warn debugLevel |
| 66 | + Error debugLevel |
| 67 | +}{ |
| 68 | + Warn: 1, |
| 69 | + Error: 2, |
| 70 | +} |
| 71 | + |
| 72 | +// debugTagCounterName is the OTel instrument name. Kept short because |
| 73 | +// the Cloud Monitoring exporter prepends |
| 74 | +// `bigtable.googleapis.com/internal/client/` itself; a fully-qualified |
| 75 | +// name here would double-prefix and Cloud Monitoring would reject it. |
| 76 | +const debugTagCounterName = "debug_tags" |
| 77 | + |
| 78 | +// debugTagAttrKey is the sole OTel attribute carrying the tag string. |
| 79 | +// Cardinality is bounded by the catalog below. |
| 80 | +const debugTagAttrKey = "tag" |
| 81 | + |
| 82 | +// Debug-tag catalog. Every emission site passes one of these constants; |
| 83 | +// inline literals are never used. Wire names are snake_case (matching |
| 84 | +// java-bigtable); Go identifiers are camelCase. Grep either form to |
| 85 | +// jump between the definition and its emission sites. |
| 86 | +const ( |
| 87 | + // Session-lifecycle observations. |
| 88 | + tagSessionUnknownResponse = "session_unknown_response" |
| 89 | + tagSessionOpenWrongState = "session_open_wrong_state" |
| 90 | + tagSessionGoawayAfterClose = "session_goaway_after_close" |
| 91 | + tagSessionGoawayBeforeStart = "session_goaway_before_start" |
| 92 | + tagSessionAbnormalClose = "session_abnormal_close" |
| 93 | + tagSessionHeartbeatMissed = "session_heartbeat_missed" |
| 94 | + tagSessionForceCloseNeverStarted = "session_force_close_never_started" |
| 95 | + tagSessionCloseNoReason = "session_close_no_reason" |
| 96 | + |
| 97 | + // vRPC dispatch observations. |
| 98 | + tagSessionVRPCNil = "session_vrpc_nil" |
| 99 | + tagSessionVRPCErrorNil = "session_vrpc_error_nil" |
| 100 | + tagSessionVRPCIDMismatch = "session_vrpc_id_mismatch" |
| 101 | + tagSessionVRPCResponseWrongState = "session_vrpc_response_wrong_state" |
| 102 | + tagSessionVRPCDuplicateResult = "session_vrpc_duplicate_result" |
| 103 | + |
| 104 | + // Pool-scoped anomalies. |
| 105 | + tagSessionPoolStuckSessionSwept = "session_pool_stuck_session_swept" |
| 106 | + tagSessionPoolDrainTimeout = "session_pool_drain_timeout" |
| 107 | + tagSessionPoolCreateFailed = "session_pool_create_failed" |
| 108 | + tagSessionPoolPickLostRace = "session_pool_pick_lost_race" |
| 109 | + |
| 110 | + // Client configuration polling. |
| 111 | + tagClientConfigPollFailed = "client_config_poll_failed" |
| 112 | + tagClientConfigPollCtxExpired = "client_config_poll_ctx_expired" |
| 113 | +) |
| 114 | + |
| 115 | +var ( |
| 116 | + // debugTagCounter is the OTel Int64Counter registered by |
| 117 | + // registerDebugTagCounter. Held in an atomic.Value so the |
| 118 | + // register-once write and every-emission reads don't race on the |
| 119 | + // two-word interface value. Load returns nil until initialization |
| 120 | + // runs, so the tracer is safe to call before InitializeSessionMetrics |
| 121 | + // or in tests that don't wire OTel. |
| 122 | + debugTagCounter atomic.Value |
| 123 | + |
| 124 | + // debugTagLevelFloor drops any emission with level < floor before it |
| 125 | + // touches the counter or the in-memory map. Defaults to Warn. |
| 126 | + debugTagLevelFloor atomic.Int32 |
| 127 | + |
| 128 | + // debugTagCountsMu guards debugTagStats. Contention is negligible: |
| 129 | + // emissions are cold-path and reads (tests, /debugtagsz/) are rare. |
| 130 | + debugTagCountsMu sync.RWMutex |
| 131 | + // debugTagStats is the in-process view of every tag seen since |
| 132 | + // process start. Kept alongside the OTel counter so tests and |
| 133 | + // /debugtagsz/ can read state without an exporter wired up. |
| 134 | + debugTagStats = map[string]*tagStat{} |
| 135 | +) |
| 136 | + |
| 137 | +// tagStat holds one tag's counters. Fields are atomic so the emission |
| 138 | +// path stays lock-free after the map entry exists (RLock the map, then |
| 139 | +// bump atomics). |
| 140 | +type tagStat struct { |
| 141 | + count atomic.Int64 // total emissions since process start |
| 142 | + firstSeen atomic.Int64 // unix-nano of first emission; write-once |
| 143 | + lastSeen atomic.Int64 // unix-nano of most-recent emission |
| 144 | +} |
| 145 | + |
| 146 | +// DebugTagSnapshot is one row of DebugTags output — a tag's count plus |
| 147 | +// its first- and last-seen timestamps. Exported for /debugtagsz/. |
| 148 | +type DebugTagSnapshot struct { |
| 149 | + Name string |
| 150 | + Count int64 |
| 151 | + FirstSeen time.Time |
| 152 | + LastSeen time.Time |
| 153 | +} |
| 154 | + |
| 155 | +func init() { |
| 156 | + debugTagLevelFloor.Store(int32(lvl.Warn)) |
| 157 | +} |
| 158 | + |
| 159 | +// registerDebugTagCounter is called once from InitializeSessionMetrics |
| 160 | +// after the meter provider is validated non-nil. |
| 161 | +func registerDebugTagCounter(meter metric.Meter) error { |
| 162 | + c, err := meter.Int64Counter( |
| 163 | + debugTagCounterName, |
| 164 | + metric.WithDescription("Count of unexpected events tagged by call site — the Go client's parity with java-bigtable's ClientDebugTagCount."), |
| 165 | + ) |
| 166 | + if err != nil { |
| 167 | + return fmt.Errorf("create debug_tags counter: %w", err) |
| 168 | + } |
| 169 | + debugTagCounter.Store(c) |
| 170 | + return nil |
| 171 | +} |
| 172 | + |
| 173 | +// setDebugTagLevelFloor sets the emission floor. Intended for future |
| 174 | +// wiring from TelemetryConfiguration.debug_tag_level. |
| 175 | +func setDebugTagLevelFloor(l debugLevel) { |
| 176 | + debugTagLevelFloor.Store(int32(l)) |
| 177 | +} |
| 178 | + |
| 179 | +// recordDebugTag increments the debug_tags counter for `name` at Warn. |
| 180 | +// Safe to call before InitializeSessionMetrics — only the in-memory |
| 181 | +// map increments until the OTel counter is registered. |
| 182 | +func recordDebugTag(name string) { |
| 183 | + recordDebugTagAt(lvl.Warn, name) |
| 184 | +} |
| 185 | + |
| 186 | +// recordDebugTagAt is the level-explicit form. Prefer recordDebugTag |
| 187 | +// for ordinary observations; use this only when a site needs a |
| 188 | +// non-Warn level outside an assertDebugTag. |
| 189 | +func recordDebugTagAt(level debugLevel, name string) { |
| 190 | + if int32(level) < debugTagLevelFloor.Load() { |
| 191 | + return |
| 192 | + } |
| 193 | + bumpDebugTagCount(name) |
| 194 | + if c, ok := debugTagCounter.Load().(metric.Int64Counter); ok && c != nil { |
| 195 | + c.Add(context.Background(), 1, |
| 196 | + metric.WithAttributes(attribute.String(debugTagAttrKey, name))) |
| 197 | + } |
| 198 | +} |
| 199 | + |
| 200 | +// assertDebugTag returns `expr`. On false it records an Error tag and |
| 201 | +// logs "debug-tag assertion failed [name]". Never panics — the caller |
| 202 | +// decides whether to bail, drop, or continue. |
| 203 | +func assertDebugTag(expr bool, name string) bool { |
| 204 | + if expr { |
| 205 | + return true |
| 206 | + } |
| 207 | + recordDebugTagAt(lvl.Error, name) |
| 208 | + btopt.Debugf(nil, "bigtable: debug-tag assertion failed [%s]", name) |
| 209 | + return false |
| 210 | +} |
| 211 | + |
| 212 | +// assertDebugTagf is the format-string form of assertDebugTag. Use it |
| 213 | +// when the site has diagnostic context (state, ids, timing) worth |
| 214 | +// putting in the log line; the counter increment is identical. |
| 215 | +func assertDebugTagf(expr bool, name, format string, args ...interface{}) bool { |
| 216 | + if expr { |
| 217 | + return true |
| 218 | + } |
| 219 | + recordDebugTagAt(lvl.Error, name) |
| 220 | + btopt.Debugf(nil, "bigtable: debug-tag assertion failed [%s]: "+format, append([]interface{}{name}, args...)...) |
| 221 | + return false |
| 222 | +} |
| 223 | + |
| 224 | +// bumpDebugTagCount bumps the in-memory count for `name` and stamps |
| 225 | +// its emission timestamps. The first emission creates the entry under |
| 226 | +// the write lock; subsequent ones take the RLock and touch atomics. |
| 227 | +// The function handles its own locking; the name deliberately avoids |
| 228 | +// the "…Locked" suffix (which by convention means the caller holds |
| 229 | +// the lock). |
| 230 | +func bumpDebugTagCount(name string) { |
| 231 | + now := time.Now().UnixNano() |
| 232 | + debugTagCountsMu.RLock() |
| 233 | + s, ok := debugTagStats[name] |
| 234 | + debugTagCountsMu.RUnlock() |
| 235 | + if ok { |
| 236 | + s.count.Add(1) |
| 237 | + s.lastSeen.Store(now) |
| 238 | + return |
| 239 | + } |
| 240 | + debugTagCountsMu.Lock() |
| 241 | + if s, ok = debugTagStats[name]; !ok { |
| 242 | + s = &tagStat{} |
| 243 | + s.firstSeen.Store(now) |
| 244 | + debugTagStats[name] = s |
| 245 | + } |
| 246 | + s.count.Add(1) |
| 247 | + s.lastSeen.Store(now) |
| 248 | + debugTagCountsMu.Unlock() |
| 249 | +} |
| 250 | + |
| 251 | +// DebugTags returns every tag emitted since process start, sorted by |
| 252 | +// LastSeen descending. The catalog is small (bounded by the const |
| 253 | +// block above) so callers can render the whole slice without paging. |
| 254 | +func DebugTags() []DebugTagSnapshot { |
| 255 | + debugTagCountsMu.RLock() |
| 256 | + out := make([]DebugTagSnapshot, 0, len(debugTagStats)) |
| 257 | + for name, s := range debugTagStats { |
| 258 | + out = append(out, DebugTagSnapshot{ |
| 259 | + Name: name, |
| 260 | + Count: s.count.Load(), |
| 261 | + FirstSeen: time.Unix(0, s.firstSeen.Load()), |
| 262 | + LastSeen: time.Unix(0, s.lastSeen.Load()), |
| 263 | + }) |
| 264 | + } |
| 265 | + debugTagCountsMu.RUnlock() |
| 266 | + // Sort after releasing the lock — `out` is a local slice of value |
| 267 | + // copies, so the sort touches no shared state. |
| 268 | + sort.Slice(out, func(i, j int) bool { |
| 269 | + return out[i].LastSeen.After(out[j].LastSeen) |
| 270 | + }) |
| 271 | + return out |
| 272 | +} |
| 273 | + |
| 274 | +// snapshotDebugTagCounts returns a bare name→count map for tests that |
| 275 | +// only care about counts. New callers should prefer DebugTags. |
| 276 | +func snapshotDebugTagCounts() map[string]int64 { |
| 277 | + debugTagCountsMu.RLock() |
| 278 | + defer debugTagCountsMu.RUnlock() |
| 279 | + out := make(map[string]int64, len(debugTagStats)) |
| 280 | + for name, s := range debugTagStats { |
| 281 | + out[name] = s.count.Load() |
| 282 | + } |
| 283 | + return out |
| 284 | +} |
| 285 | + |
| 286 | +// resetDebugTagCountsForTest wipes the map so a test can assert on a |
| 287 | +// specific tag's count without cross-test contamination. Test-only. |
| 288 | +func resetDebugTagCountsForTest() { |
| 289 | + debugTagCountsMu.Lock() |
| 290 | + debugTagStats = map[string]*tagStat{} |
| 291 | + debugTagCountsMu.Unlock() |
| 292 | +} |
0 commit comments