From 7ce2d7c3b06a616794511525817f45f9259fb6bc Mon Sep 17 00:00:00 2001 From: Ruben Bartelink Date: Sun, 23 Jan 2022 22:13:26 +0000 Subject: [PATCH] Make logging of byte counts conditional --- CHANGELOG.md | 3 +++ src/Equinox.CosmosStore/CosmosStore.fs | 24 +++++++++++++----------- 2 files changed, 16 insertions(+), 11 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 03e7be2d3..f1a399cea 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -12,6 +12,9 @@ The `Unreleased` section name is replaced by the expected version of next releas ### Changed - Remove explicit `net461` handling; minimum target now `netstandard 2.1` / `net5.0` [#310](https://github.com/jet/equinox/pull/310) +- `CosmosStore`: Switch to natively using `JsonElement` event bodies [#305](https://github.com/jet/equinox/pull/305) :pray: [@ylibrach](https://github.com/ylibrach) +- `CosmosStore`: Switch to natively using `System.Text.Json` for serialization of all `Microsoft.Azure.Cosmos` round-trips [#305](https://github.com/jet/equinox/pull/305) :pray: [@ylibrach](https://github.com/ylibrach) +- `CosmosStore`: Only log `bytes` when log level is `Debug` [#305](https://github.com/jet/equinox/pull/305) ### Removed ### Fixed diff --git a/src/Equinox.CosmosStore/CosmosStore.fs b/src/Equinox.CosmosStore/CosmosStore.fs index 0ecdc7175..945809eda 100644 --- a/src/Equinox.CosmosStore/CosmosStore.fs +++ b/src/Equinox.CosmosStore/CosmosStore.fs @@ -230,10 +230,10 @@ module Log = let internal event (value : Metric) (log : ILogger) = let enrich (e : Serilog.Events.LogEvent) = e.AddPropertyIfAbsent(Serilog.Events.LogEventProperty(PropertyTag, Serilog.Events.ScalarValue(value))) - log.ForContext({ new Serilog.Core.ILogEventEnricher with member _.Enrich(evt, _) = enrich evt }) + log.ForContext({ new Serilog.Core.ILogEventEnricher with member __.Enrich(evt,_) = enrich evt }) let internal (|BlobLen|) (x : EventBody) = if x.ValueKind = JsonValueKind.Null then 0 else x.GetRawText().Length - let internal (|EventLen|) (x : #IEventData<_>) = let BlobLen bytes, BlobLen metaBytes = x.Data, x.Meta in bytes + metaBytes + 80 - let internal (|BatchLen|) = Seq.sumBy (|EventLen|) + let internal eventLen (x: #IEventData<_>) = let BlobLen bytes, BlobLen metaBytes = x.Data, x.Meta in bytes + metaBytes + 80 + let internal batchLen = Seq.sumBy eventLen let internal (|SerilogScalar|_|) : Serilog.Events.LogEventPropertyValue -> obj option = function | :? Serilog.Events.ScalarValue as x -> Some x.Value | _ -> None @@ -479,11 +479,12 @@ module internal Sync = let private logged (container, stream) (maxEventsInTip, maxStringifyLen) (exp : SyncExp, req : Tip) (log : ILogger) : Async = async { let! t, (ru, result) = run (container, stream) (maxEventsInTip, maxStringifyLen) (exp, req) |> Stopwatch.Time - let Log.BatchLen bytes, count = Enum.Events req, req.e.Length + let verbose = log.IsEnabled Serilog.Events.LogEventLevel.Debug + let count, bytes = req.e.Length, if verbose then Enum.Events req |> Log.batchLen else 0 let log = - let inline mkMetric ru : Log.Measurement = { database = container.Database.Id; container = container.Id; stream = stream; interval = t; bytes = bytes; count = count; ru = ru } + let inline mkMetric ru : Log.Measurement = + { database = container.Database.Id; container = container.Id; stream = stream; interval = t; bytes = bytes; count = count; ru = ru } let inline propConflict log = log |> Log.prop "conflict" true |> Log.prop "eventTypes" (Seq.truncate 5 (seq { for x in req.e -> x.c })) - let verbose = log.IsEnabled Events.LogEventLevel.Debug if verbose then log |> Log.propEvents (Enum.Events req) |> Log.propDataUnfolds req.u else log |> match exp with | SyncExp.Etag et -> Log.prop "expectedEtag" et @@ -612,7 +613,7 @@ module internal Tip = (log 0 0 Log.Metric.TipNotFound).Information("EqxCosmos {action:l} {stream} {res} {ms}ms rc={ru}", "Tip", stream, 404, (let e = t.Elapsed in e.TotalMilliseconds), ru) | ReadResult.Found tip -> let log = - let Log.BatchLen bytes, count = Enum.Unfolds tip.u, tip.u.Length + let count, bytes = tip.u.Length, if verbose then Enum.Unfolds tip.u |> Log.batchLen else 0 log bytes count Log.Metric.Tip let log = if verbose then log |> Log.propDataUnfolds tip.u else log let log = match maybePos with Some p -> log |> Log.propStartPos p |> Log.propStartEtag p | None -> log @@ -675,10 +676,10 @@ module internal Query = Enum.Events(b, ?minIndex = minIndex, ?maxIndex = maxIndex) |> if direction = Direction.Backward then System.Linq.Enumerable.Reverse else id let events = batches |> Seq.collect unwrapBatch |> Array.ofSeq - let Log.BatchLen bytes, count = events, events.Length + let verbose = log.IsEnabled Events.LogEventLevel.Debug + let count, bytes = events.Length, if verbose then events |> Log.batchLen else 0 let reqMetric : Log.Measurement = { database = container.Database.Id; container = container.Id; stream = streamName; interval = t; bytes = bytes; count = count; ru = ru } let log = let evt = Log.Metric.QueryResponse (direction, reqMetric) in log |> Log.event evt - let verbose = log.IsEnabled Events.LogEventLevel.Debug let log = if verbose then log |> Log.propEvents events else log let index = if count = 0 then Nullable () else Nullable <| Seq.min (seq { for x in batches -> x.i }) (log|> Log.prop "bytes" bytes @@ -690,7 +691,8 @@ module internal Query = events, maybePosition, ru let private logQuery direction queryMaxItems (container : Container, streamName) interval (responsesCount, events : ITimelineEvent[]) n (ru : float) (log : ILogger) = - let Log.BatchLen bytes, count = events, events.Length + let verbose = log.IsEnabled Events.LogEventLevel.Debug + let count, bytes = events.Length, if verbose then events |> Log.batchLen else 0 let reqMetric : Log.Measurement = { database = container.Database.Id; container = container.Id; stream = streamName; interval = interval; bytes = bytes; count = count; ru = ru } let evt = Log.Metric.Query (direction, responsesCount, reqMetric) let action = match direction with Direction.Forward -> "QueryF" | Direction.Backward -> "QueryB" @@ -702,7 +704,7 @@ module internal Query = let mutable used, dropped = 0, 0 let mutable found = false for x in xs do - let (Log.EventLen bytes) = x + let bytes = Log.eventLen x if found then dropped <- dropped + bytes else used <- used + bytes if x.Index = stopIndex then found <- true