From 59cf7ffcde209d3b83ac5d2550fceef9668c4284 Mon Sep 17 00:00:00 2001 From: Abdullah Atta Date: Fri, 7 Jun 2024 15:41:44 +0500 Subject: [PATCH] notesnook: add opentelemetry based metric logging --- .../EventSources/SyncEventCounterSource.cs | 49 +++++++++ Notesnook.API/Hubs/SyncHub.cs | 4 + Notesnook.API/Hubs/SyncV2Hub.cs | 100 +++++++++++------- Notesnook.API/Notesnook.API.csproj | 2 + Notesnook.API/Program.cs | 3 + Notesnook.API/Startup.cs | 11 ++ 6 files changed, 133 insertions(+), 36 deletions(-) create mode 100644 Notesnook.API/EventSources/SyncEventCounterSource.cs diff --git a/Notesnook.API/EventSources/SyncEventCounterSource.cs b/Notesnook.API/EventSources/SyncEventCounterSource.cs new file mode 100644 index 0000000..e8db5be --- /dev/null +++ b/Notesnook.API/EventSources/SyncEventCounterSource.cs @@ -0,0 +1,49 @@ +using System; +using System.Diagnostics.Metrics; +using System.Diagnostics.Tracing; + +[EventSource(Name = "Notesnook.API.EventCounter.Sync")] +public sealed class SyncEventCounterSource : EventSource +{ + public static readonly SyncEventCounterSource Log = new(); + + private Meter meter = new("Notesnook.API.Metrics.Sync", "1.0.0"); + private Counter fetchCounter; + private Counter pushCounter; + private Counter legacyFetchCounter; + private Counter pushV2Counter; + private Counter fetchV2Counter; + private Histogram fetchV2Duration; + private Histogram pushV2Duration; + private SyncEventCounterSource() + { + fetchCounter = meter.CreateCounter("sync.fetches", "fetches", "Total fetches"); + pushCounter = meter.CreateCounter("sync.pushes", "pushes", "Total pushes"); + legacyFetchCounter = meter.CreateCounter("sync.legacy-fetches", "fetches", "Total legacy fetches"); + fetchV2Counter = meter.CreateCounter("sync.v2.fetches", "fetches", "Total v2 fetches"); + pushV2Counter = meter.CreateCounter("sync.v2.pushes", "pushes", "Total v2 pushes"); + fetchV2Duration = meter.CreateHistogram("sync.v2.fetch_duration"); + pushV2Duration = meter.CreateHistogram("sync.v2.push_duration"); + } + + public void Fetch() => fetchCounter.Add(1); + public void LegacyFetch() => legacyFetchCounter.Add(1); + public void FetchV2() => fetchV2Counter.Add(1); + public void PushV2() => pushV2Counter.Add(1); + public void Push() => pushCounter.Add(1); + public void RecordFetchDuration(long durationMs) => fetchV2Duration.Record(durationMs); + public void RecordPushDuration(long durationMs) => pushV2Duration.Record(durationMs); + + protected override void Dispose(bool disposing) + { + legacyFetchCounter = null; + fetchV2Counter = null; + pushV2Counter = null; + pushCounter = null; + fetchCounter = null; + meter.Dispose(); + meter = null; + + base.Dispose(disposing); + } +} \ No newline at end of file diff --git a/Notesnook.API/Hubs/SyncHub.cs b/Notesnook.API/Hubs/SyncHub.cs index 2ca6c7a..fe84dfd 100644 --- a/Notesnook.API/Hubs/SyncHub.cs +++ b/Notesnook.API/Hubs/SyncHub.cs @@ -230,6 +230,8 @@ namespace Notesnook.API.Hubs var userId = Context.User.FindFirstValue("sub"); if (string.IsNullOrEmpty(userId)) return 0; + SyncEventCounterSource.Log.Push(); + try { var others = Clients.OthersInGroup(userId); @@ -347,6 +349,8 @@ namespace Notesnook.API.Hubs throw new HubException("Cannot fetch data while another sync is in progress. Please try again later."); } + SyncEventCounterSource.Log.Fetch(); + var userSettings = await Repositories.UsersSettings.FindOneAsync((u) => u.UserId == userId); if (userSettings.LastSynced > 0 && lastSyncedTimestamp > userSettings.LastSynced) { diff --git a/Notesnook.API/Hubs/SyncV2Hub.cs b/Notesnook.API/Hubs/SyncV2Hub.cs index 6e05255..3b54b25 100644 --- a/Notesnook.API/Hubs/SyncV2Hub.cs +++ b/Notesnook.API/Hubs/SyncV2Hub.cs @@ -19,6 +19,8 @@ along with this program. If not, see . using System; using System.Collections.Generic; +using System.Diagnostics; +using System.Diagnostics.Metrics; using System.Linq; using System.Security.Claims; using System.Text.Json.Serialization; @@ -26,6 +28,8 @@ using System.Threading.Tasks; using Microsoft.AspNetCore.Authorization; using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.SignalR; +using MongoDB.Bson; +using MongoDB.Bson.Serialization; using MongoDB.Driver; using Notesnook.API.Authorization; using Notesnook.API.Interfaces; @@ -121,18 +125,28 @@ namespace Notesnook.API.Hubs public async Task PushItems(string deviceId, SyncTransferItemV2 pushItem) { var userId = Context.User.FindFirstValue("sub"); - if (string.IsNullOrEmpty(userId)) return 0; + if (string.IsNullOrEmpty(userId)) throw new HubException("Please login to sync."); - var UpsertItem = MapTypeToUpsertAction(pushItem.Type) ?? throw new Exception($"Invalid item type: {pushItem.Type}."); - foreach (var item in pushItem.Items) + SyncEventCounterSource.Log.PushV2(); + + var stopwatch = new Stopwatch(); + stopwatch.Start(); + try { - UpsertItem(item, userId, 1); - } - if (!await unit.Commit()) return 0; + var UpsertItems = MapTypeToUpsertAction(pushItem.Type) ?? throw new Exception($"Invalid item type: {pushItem.Type}."); + UpsertItems(pushItem.Items, userId, 1); + + if (!await unit.Commit()) return 0; await new SyncDeviceService(new SyncDevice(ref userId, ref deviceId)).AddIdsToOtherDevicesAsync(pushItem.Items.Select((i) => $"{i.ItemId}:{pushItem.Type}").ToList()); return 1; + } + finally + { + stopwatch.Stop(); + SyncEventCounterSource.Log.RecordPushDuration(stopwatch.ElapsedMilliseconds); + } } public async Task PushCompleted() @@ -193,6 +207,10 @@ namespace Notesnook.API.Hubs public async Task RequestFetch(string deviceId) { var userId = Context.User.FindFirstValue("sub"); + if (string.IsNullOrEmpty(userId)) throw new HubException("Please login to sync."); + + SyncEventCounterSource.Log.FetchV2(); + var deviceService = new SyncDeviceService(new SyncDevice(ref userId, ref deviceId)); if (!deviceService.IsDeviceRegistered()) deviceService.RegisterDevice(); @@ -202,11 +220,15 @@ namespace Notesnook.API.Hubs !isResetSync) return new SyncV2Metadata { Synced = true }; - string[] ids = await SyncDeviceService.FetchUnsyncedIdsAsync(userId, deviceId); + var stopwatch = new Stopwatch(); + stopwatch.Start(); + try + { + string[] ids = await deviceService.FetchUnsyncedIdsAsync(); - var chunks = PrepareChunks( - collections: [ - Repositories.Settings.FindItemsById, + var chunks = PrepareChunks( + collections: [ + Repositories.Settings.FindItemsById, Repositories.Attachments.FindItemsById, Repositories.Notes.FindItemsById, Repositories.Notebooks.FindItemsById, @@ -217,39 +239,45 @@ namespace Notesnook.API.Hubs Repositories.Tags.FindItemsById, Repositories.Vaults.FindItemsById, Repositories.Relations.FindItemsById, - ], - types: CollectionKeys, - userId, - ids, - size: 1000, - resetSync: isResetSync, - maxBytes: 7 * 1024 * 1024 - ); + ], + types: CollectionKeys, + userId, + ids, + size: 1000, + resetSync: isResetSync, + maxBytes: 7 * 1024 * 1024 + ); - var userSettings = await Repositories.UsersSettings.FindOneAsync((u) => u.UserId.Equals(userId)); - if (userSettings.VaultKey != null) - { - if (!await Clients.Caller.SendVaultKey(userSettings.VaultKey).WaitAsync(TimeSpan.FromMinutes(10))) throw new HubException("Client rejected vault key."); - } - - await foreach (var chunk in chunks) - { - if (!await Clients.Caller.SendItems(chunk).WaitAsync(TimeSpan.FromMinutes(10))) throw new HubException("Client rejected sent items."); - - if (!isResetSync) + var userSettings = await Repositories.UsersSettings.FindOneAsync((u) => u.UserId.Equals(userId)); + if (userSettings.VaultKey != null) { - var syncedIds = chunk.Items.Select((i) => $"{i.ItemId}:{chunk.Type}").ToHashSet(); - ids = ids.Where((id) => !syncedIds.Contains(id)).ToArray(); - await deviceService.WritePendingIdsAsync(ids); + if (!await Clients.Caller.SendVaultKey(userSettings.VaultKey).WaitAsync(TimeSpan.FromMinutes(10))) throw new HubException("Client rejected vault key."); + } + + await foreach (var chunk in chunks) + { + if (!await Clients.Caller.SendItems(chunk).WaitAsync(TimeSpan.FromMinutes(10))) throw new HubException("Client rejected sent items."); + + if (!isResetSync) + { + var syncedIds = chunk.Items.Select((i) => $"{i.ItemId}:{chunk.Type}").ToHashSet(); + ids = ids.Where((id) => !syncedIds.Contains(id)).ToArray(); + await deviceService.WritePendingIdsAsync(ids); + } } - } deviceService.Reset(); - return new SyncV2Metadata + return new SyncV2Metadata + { + Synced = true, + }; + } + finally { - Synced = true, - }; + stopwatch.Stop(); + SyncEventCounterSource.Log.RecordFetchDuration(stopwatch.ElapsedMilliseconds); + } } } diff --git a/Notesnook.API/Notesnook.API.csproj b/Notesnook.API/Notesnook.API.csproj index 5737d93..732a891 100644 --- a/Notesnook.API/Notesnook.API.csproj +++ b/Notesnook.API/Notesnook.API.csproj @@ -15,6 +15,8 @@ + + diff --git a/Notesnook.API/Program.cs b/Notesnook.API/Program.cs index 735d93f..47b127a 100644 --- a/Notesnook.API/Program.cs +++ b/Notesnook.API/Program.cs @@ -26,6 +26,8 @@ using Microsoft.AspNetCore.Hosting; using Microsoft.Extensions.Hosting; using Streetwriters.Common; using System.Linq; +using Microsoft.Extensions.Logging; +using System.Net; namespace Notesnook.API { @@ -59,6 +61,7 @@ namespace Notesnook.API listenerOptions.UseHttps(Servers.NotesnookAPI.SSLCertificate); }); } + options.Listen(IPAddress.Parse("127.0.0.1"), 5067); }); }); } diff --git a/Notesnook.API/Startup.cs b/Notesnook.API/Startup.cs index 3bcc7b0..39397d2 100644 --- a/Notesnook.API/Startup.cs +++ b/Notesnook.API/Startup.cs @@ -51,6 +51,8 @@ using Notesnook.API.Interfaces; using Notesnook.API.Models; using Notesnook.API.Repositories; using Notesnook.API.Services; +using OpenTelemetry.Metrics; +using OpenTelemetry.Resources; using Streetwriters.Common; using Streetwriters.Common.Extensions; using Streetwriters.Common.Messages; @@ -208,6 +210,13 @@ namespace Notesnook.API { options.Level = CompressionLevel.Fastest; }); + + services.AddOpenTelemetry() + .ConfigureResource(resource => resource + .AddService(serviceName: "Notesnook.API")) + .WithMetrics((builder) => builder + .AddMeter("Notesnook.API.Metrics.Sync") + .AddPrometheusExporter()); } // This method gets called by the runtime. Use this method to configure the HTTP request pipeline. @@ -221,6 +230,7 @@ namespace Notesnook.API }); } + app.UseOpenTelemetryPrometheusScrapingEndpoint((context) => context.Request.Path == "/metrics" && context.Connection.LocalPort == 5067); app.UseResponseCompression(); app.UseCors("notesnook"); @@ -248,6 +258,7 @@ namespace Notesnook.API app.UseEndpoints(endpoints => { + endpoints.MapPrometheusScrapingEndpoint(); endpoints.MapControllers(); endpoints.MapHealthChecks("/health"); endpoints.MapHub("/hubs/sync", options =>