diff --git a/src/CouponHubBot/Services/BatchDebounce.fs b/src/CouponHubBot/Services/BatchDebounce.fs index 3beb511c..234accc9 100644 --- a/src/CouponHubBot/Services/BatchDebounce.fs +++ b/src/CouponHubBot/Services/BatchDebounce.fs @@ -2,9 +2,12 @@ namespace CouponHubBot.Services open System open System.Collections.Concurrent +open System.Diagnostics open System.Threading open System.Threading.Tasks open Microsoft.Extensions.Logging +open BotInfra +open CouponHubBot.Telemetry /// Per-batch debounce timer for the album upload flow. Re-arming an existing /// batch cancels the previous timer and starts fresh — this is how we "wait @@ -19,6 +22,10 @@ type BatchDebounce(logger: ILogger, time: TimeProvider) = let pending = ConcurrentDictionary() member _.Schedule(batchId: int64, debounceMs: int, work: Func) : unit = + let scheduledAt = DateTimeOffset.UtcNow + let parentContext = + if isNull Activity.Current then ActivityContext() + else Activity.Current.Context let cts = new CancellationTokenSource() match pending.TryGetValue batchId with | true, existing -> @@ -28,13 +35,24 @@ type BatchDebounce(logger: ILogger, time: TimeProvider) = pending[batchId] <- cts let runLoop () : Task = task { - try - do! Task.Delay(TimeSpan.FromMilliseconds(float debounceMs), time, cts.Token) + let! elapsed = task { + use wait = botActivity.StartActivity("batchDebounce.wait", ActivityKind.Internal, parentContext, startTime = scheduledAt) + if not (isNull wait) then + %wait.SetTag("batchId", batchId) + %wait.SetTag("debounce.delay_ms", debounceMs) + try + do! Task.Delay(TimeSpan.FromMilliseconds(float debounceMs), time, cts.Token) + if not (isNull wait) then %wait.SetTag("debounce.outcome", "elapsed") + return true + with :? OperationCanceledException -> + if not (isNull wait) then %wait.SetTag("debounce.outcome", "superseded") + return false + } + if elapsed then pending.TryRemove batchId |> ignore try do! work.Invoke() with ex -> logger.LogError(ex, "FinalizeBatch failed for batch {BatchId}", batchId) - with :? OperationCanceledException -> () } :> Task Task.Run(Func(runLoop)) |> ignore diff --git a/src/CouponHubBot/Services/CouponFlowHandler.fs b/src/CouponHubBot/Services/CouponFlowHandler.fs index a6226204..4fa8ca90 100644 --- a/src/CouponHubBot/Services/CouponFlowHandler.fs +++ b/src/CouponHubBot/Services/CouponFlowHandler.fs @@ -716,11 +716,16 @@ type CouponFlowHandler( | _ -> None if deferForMs.IsSome then + if not (isNull a) then + %a.SetTag("outcome", "deferred") + %a.SetTag("debounce.delay_ms", deferForMs.Value) batchDebounce.Schedule(batchId, deferForMs.Value, Func(fun () -> this.FinalizeBatch batchId)) else let! won = db.TryFlipBatchToAwaiting batchId - if not won then () else + if not won then + if not (isNull a) then %a.SetTag("outcome", "not_claimed") + else let! claimedCount = db.ClaimPendingItemsAsTimeout batchId if claimedCount > 0 then @@ -728,10 +733,12 @@ type CouponFlowHandler( let! batchOpt = db.GetBatchById batchId match batchOpt with - | None -> () + | None -> + if not (isNull a) then %a.SetTag("outcome", "batch_missing") | Some batch -> let! isMember = membership.IsMember(batch.user_id) if not isMember then + if not (isNull a) then %a.SetTag("outcome", "not_member") logger.LogWarning("Batch {BatchId} dropped: user {UserId} is not a community member", batchId, batch.user_id) do! db.ClearBatch batchId else diff --git a/src/CouponHubBot/docs/OBSERVABILITY.md b/src/CouponHubBot/docs/OBSERVABILITY.md index a31091e4..58794845 100644 --- a/src/CouponHubBot/docs/OBSERVABILITY.md +++ b/src/CouponHubBot/docs/OBSERVABILITY.md @@ -35,6 +35,8 @@ All custom metrics are defined in `src/CouponHubBot/Telemetry.fs` under the `Cou - OpenTelemetry traces configured in `Telemetry.fs` - OCR spans cover full photo download (`couponOcr.download`), recognition, image loading/preprocessing/resizing, each ZXing decode attempt, Azure SDK execution including retries, and text parsing. +- Album timers emit `batchDebounce.wait` from scheduling through elapsed or superseded waits; `batchId` joins these spans to OCR and finalization across traces. +- `finalizeBatch` records `outcome` for completion, fallback, deferral, an unclaimed batch, a missing batch, or failed membership; deferred waits include `debounce.delay_ms`. - `couponOcr.barcode.decode` tags identify the strategy, image dimensions, and success; `couponOcr.barcode` records the attempt count and outcome without recording barcode values. - Includes Npgsql instrumentation for database query tracing - Traces shipped to **Tempo**. Query directly over the VPN (no auth) at