diff --git a/src/ApiService/ApiService/FeatureFlags.cs b/src/ApiService/ApiService/FeatureFlags.cs index c9894d997..7855df922 100644 --- a/src/ApiService/ApiService/FeatureFlags.cs +++ b/src/ApiService/ApiService/FeatureFlags.cs @@ -4,4 +4,5 @@ public static class FeatureFlagConstants { public const string RenderOnlyScribanTemplates = "RenderOnlyScribanTemplates"; public const string EnableNodeDecommissionStrategy = "EnableNodeDecommissionStrategy"; public const string SemanticNotificationConfigValidation = "SemanticNotificationConfigValidation"; + public const string EnableCustomMetricTelemetry = "EnableCustomMetricTelemetry"; } diff --git a/src/ApiService/ApiService/Functions/QueueNodeHeartbeat.cs b/src/ApiService/ApiService/Functions/QueueNodeHeartbeat.cs index 1d0d9dea9..544dcc823 100644 --- a/src/ApiService/ApiService/Functions/QueueNodeHeartbeat.cs +++ b/src/ApiService/ApiService/Functions/QueueNodeHeartbeat.cs @@ -17,10 +17,12 @@ public class QueueNodeHearbeat { [Function("QueueNodeHeartbeat")] public async Async.Task Run([QueueTrigger("node-heartbeat", Connection = "AzureWebJobsStorage")] string msg) { - _log.Info($"heartbeat: {msg}"); + var nodes = _context.NodeOperations; var events = _context.Events; + var metrics = _context.Metrics; + _log.Info($"heartbeat: {msg}"); var hb = JsonSerializer.Deserialize(msg, EntityConverter.GetJsonSerializerOptions()).EnsureNotNull($"wrong data {msg}"); var node = await nodes.GetByMachineId(hb.NodeId); @@ -35,7 +37,12 @@ public class QueueNodeHearbeat { _log.WithHttpStatus(r.ErrorV).Error($"Failed to replace heartbeat: {hb.NodeId:Tag:NodeId}"); } + var nodeHeartbeatEvent = new EventNodeHeartbeat(node.MachineId, node.ScalesetId, node.PoolName, node.State); // TODO: do we still send event if we fail do update the table ? - await events.SendEvent(new EventNodeHeartbeat(node.MachineId, node.ScalesetId, node.PoolName)); + await events.SendEvent(nodeHeartbeatEvent); + if (await _context.FeatureManagerSnapshot.IsEnabledAsync(FeatureFlagConstants.EnableCustomMetricTelemetry)) { + metrics.SendMetric(1, nodeHeartbeatEvent); + } + } } diff --git a/src/ApiService/ApiService/Functions/QueueTaskHeartbeat.cs b/src/ApiService/ApiService/Functions/QueueTaskHeartbeat.cs index bd7bbe784..d9f8daa67 100644 --- a/src/ApiService/ApiService/Functions/QueueTaskHeartbeat.cs +++ b/src/ApiService/ApiService/Functions/QueueTaskHeartbeat.cs @@ -7,34 +7,45 @@ namespace Microsoft.OneFuzz.Service.Functions; public class QueueTaskHearbeat { private readonly ILogTracer _log; + private readonly IOnefuzzContext _context; - private readonly IEvents _events; - private readonly ITaskOperations _tasks; - - public QueueTaskHearbeat(ILogTracer logTracer, ITaskOperations tasks, IEvents events) { + public QueueTaskHearbeat(ILogTracer logTracer, IOnefuzzContext context) { _log = logTracer; - _tasks = tasks; - _events = events; + _context = context; } [Function("QueueTaskHeartbeat")] public async Async.Task Run([QueueTrigger("task-heartbeat", Connection = "AzureWebJobsStorage")] string msg) { - _log.Info($"heartbeat: {msg}"); + var _tasks = _context.TaskOperations; + var _jobs = _context.JobOperations; + var _events = _context.Events; + var _metrics = _context.Metrics; + + _log.Info($"heartbeat: {msg}"); var hb = JsonSerializer.Deserialize(msg, EntityConverter.GetJsonSerializerOptions()).EnsureNotNull($"wrong data {msg}"); var task = await _tasks.GetByTaskId(hb.TaskId); - if (task == null) { _log.Warning($"invalid {hb.TaskId:Tag:TaskId}"); return; } + var job = await _jobs.Get(task.JobId); + if (job == null) { + _log.Warning($"invalid {task.JobId:Tag:JobId}"); + return; + } var newTask = task with { Heartbeat = DateTimeOffset.UtcNow }; var r = await _tasks.Replace(newTask); if (!r.IsOk) { _log.WithHttpStatus(r.ErrorV).Error($"failed to replace with new task {hb.TaskId:Tag:TaskId}"); } - await _events.SendEvent(new EventTaskHeartbeat(newTask.JobId, newTask.TaskId, newTask.Config)); + + var taskHeartBeatEvent = new EventTaskHeartbeat(newTask.JobId, newTask.TaskId, job.Config.Project, job.Config.Name, newTask.State, newTask.Config); + await _events.SendEvent(taskHeartBeatEvent); + if (await _context.FeatureManagerSnapshot.IsEnabledAsync(FeatureFlagConstants.EnableCustomMetricTelemetry)) { + _metrics.SendMetric(1, taskHeartBeatEvent); + } } } diff --git a/src/ApiService/ApiService/Log.cs b/src/ApiService/ApiService/Log.cs index 1f4bcd6b5..6a6b5ed1b 100644 --- a/src/ApiService/ApiService/Log.cs +++ b/src/ApiService/ApiService/Log.cs @@ -57,6 +57,8 @@ public struct LogStringHandler { public interface ILog { void Log(Guid correlationId, LogStringHandler message, SeverityLevel level, IReadOnlyDictionary tags, string? caller); void LogEvent(Guid correlationId, LogStringHandler evt, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller); + void LogMetric(Guid correlationId, LogStringHandler metric, int value, IReadOnlyDictionary? customDimensions, IReadOnlyDictionary tags, string? caller); + void LogException(Guid correlationId, Exception ex, LogStringHandler message, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller); void Flush(); } @@ -103,6 +105,17 @@ sealed class AppInsights : ILog { _telemetryClient.TrackEvent(telemetry); } + public void LogMetric(Guid correlationId, LogStringHandler metric, int value, IReadOnlyDictionary? customDimensions, IReadOnlyDictionary tags, string? caller) { + var telemetry = new MetricTelemetry(metric.ToString(), value, value, value, value, value); + // copy properties + Copy(telemetry.Properties, customDimensions); + telemetry.Properties["CorrelationId"] = correlationId.ToString(); + if (caller is not null) telemetry.Properties["CalledBy"] = caller; + Copy(telemetry.Properties, metric.Tags); + + _telemetryClient.TrackMetric(telemetry); + } + public void LogException(Guid correlationId, Exception ex, LogStringHandler message, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { { var telemetry = new ExceptionTelemetry(ex); @@ -160,11 +173,17 @@ sealed class Console : ILog { } } + public void LogMetric(Guid correlationId, LogStringHandler metric, int value, IReadOnlyDictionary? customDimensions, IReadOnlyDictionary tags, string? caller) { + System.Console.Out.WriteLine($"[{correlationId}][Metric] {metric}"); + LogTags(correlationId, tags); + } + public void LogEvent(Guid correlationId, LogStringHandler evt, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { System.Console.Out.WriteLine($"[{correlationId}][Event] {evt}"); LogTags(correlationId, tags); LogMetrics(correlationId, metrics); } + public void LogException(Guid correlationId, Exception ex, LogStringHandler message, IReadOnlyDictionary tags, IReadOnlyDictionary? metrics, string? caller) { System.Console.Out.WriteLine($"[{correlationId}][Exception] {message}:{ex}"); LogTags(correlationId, tags); @@ -183,6 +202,7 @@ public interface ILogTracer { void Error(Error error); void Event(LogStringHandler evt, IReadOnlyDictionary? metrics = null); + void Metric(LogStringHandler metric, int value, IReadOnlyDictionary? customDimensions); void Exception(Exception ex, LogStringHandler message = $"", IReadOnlyDictionary? metrics = null); void ForceFlush(); void Info(LogStringHandler message); @@ -327,6 +347,13 @@ public class LogTracer : ILogTracerInternal { } } + public void Metric(LogStringHandler metric, int value, IReadOnlyDictionary? customDimensions) { + var caller = GetCaller(); + foreach (var logger in _loggers) { + logger.LogMetric(CorrelationId, metric, value, customDimensions, Tags, caller); + } + } + public void Exception(Exception ex, LogStringHandler message, IReadOnlyDictionary? metrics) { var caller = GetCaller(); foreach (var logger in _loggers) { diff --git a/src/ApiService/ApiService/OneFuzzTypes/Events.cs b/src/ApiService/ApiService/OneFuzzTypes/Events.cs index 519855a4a..265035e68 100644 --- a/src/ApiService/ApiService/OneFuzzTypes/Events.cs +++ b/src/ApiService/ApiService/OneFuzzTypes/Events.cs @@ -167,12 +167,14 @@ public record EventTaskStateUpdated( TaskConfig Config ) : BaseEvent(); - [EventType(EventType.TaskHeartbeat)] public record EventTaskHeartbeat( Guid JobId, Guid TaskId, - TaskConfig Config + string? Project, + string? Name, + TaskState? State, + TaskConfig? Config ) : BaseEvent(); [EventType(EventType.Ping)] @@ -273,7 +275,8 @@ public record EventNodeCreated( public record EventNodeHeartbeat( Guid MachineId, Guid? ScalesetId, - PoolName PoolName + PoolName PoolName, + NodeState state ) : BaseEvent(); diff --git a/src/ApiService/ApiService/Program.cs b/src/ApiService/ApiService/Program.cs index 1b53f12bd..a9a71d48e 100644 --- a/src/ApiService/ApiService/Program.cs +++ b/src/ApiService/ApiService/Program.cs @@ -85,6 +85,7 @@ public class Program { }) .AddScoped() .AddScoped() + .AddScoped() .AddScoped() .AddScoped() .AddScoped() diff --git a/src/ApiService/ApiService/host.json b/src/ApiService/ApiService/host.json index beb2e4020..0a60d6e92 100644 --- a/src/ApiService/ApiService/host.json +++ b/src/ApiService/ApiService/host.json @@ -3,8 +3,8 @@ "logging": { "applicationInsights": { "samplingSettings": { - "isEnabled": true, - "excludedTypes": "Request" + "isEnabled": false, + "excludedTypes": "Request;Trace;Dependency;Event;Exception" } } } diff --git a/src/ApiService/ApiService/onefuzzlib/Events.cs b/src/ApiService/ApiService/onefuzzlib/Events.cs index 395034ec7..c37411773 100644 --- a/src/ApiService/ApiService/onefuzzlib/Events.cs +++ b/src/ApiService/ApiService/onefuzzlib/Events.cs @@ -21,7 +21,6 @@ namespace Microsoft.OneFuzz.Service { public interface IEvents { Async.Task SendEvent(BaseEvent anEvent); - Async.Task QueueSignalrEvent(DownloadableEventMessage message); void LogEvent(BaseEvent anEvent); diff --git a/src/ApiService/ApiService/onefuzzlib/Metrics.cs b/src/ApiService/ApiService/onefuzzlib/Metrics.cs new file mode 100644 index 000000000..e40a9cc97 --- /dev/null +++ b/src/ApiService/ApiService/onefuzzlib/Metrics.cs @@ -0,0 +1,54 @@ +using System.Text.Json; +using System.Text.Json.Serialization; +using Microsoft.OneFuzz.Service.OneFuzzLib.Orm; + +namespace Microsoft.OneFuzz.Service { + + public record CustomMetric( + string name, + int value, + Dictionary customDimensions + ); + + + public interface IMetrics { + void SendMetric(int metricValue, BaseEvent customDimensions); + + void LogMetric(BaseEvent metric); + } + + public class Metrics : IMetrics { + private readonly ILogTracer _log; + private readonly IOnefuzzContext _context; + private readonly JsonSerializerOptions _options; + + public Metrics(ILogTracer log, IOnefuzzContext context) { + _context = context; + _log = log; + _options = new JsonSerializerOptions(EntityConverter.GetJsonSerializerOptions()) { + DefaultIgnoreCondition = JsonIgnoreCondition.WhenWritingNull + }; + _options.Converters.Add(new RemoveUserInfo()); + } + + public void SendMetric(int metricValue, BaseEvent customDimensions) { + var metricType = customDimensions.GetEventType(); + + _ = _options.PropertyNamingPolicy ?? throw new ArgumentException("Serializer _options not available."); + + var metricTypeSnakeCase = _options.PropertyNamingPolicy.ConvertName($"{metricType}"); + + var dimensionNode = JsonSerializer.SerializeToNode(customDimensions, customDimensions.GetType(), _options); + _ = dimensionNode ?? throw new JsonException("Was not able to properly serialize the custom dimensions."); + var dimensionDict = dimensionNode.AsObject().ToDictionary(kvp => kvp.Key.ToString(), kvp => kvp.Value is not null ? kvp.Value.ToString() : ""); + + _log.Metric($"{metricTypeSnakeCase}", metricValue, dimensionDict); + LogMetric(customDimensions); + } + + public void LogMetric(BaseEvent metric) { + var serializedMetric = JsonSerializer.Serialize(metric, metric.GetType(), _options); + _log.Info($"sending metric: {metric.GetEventType():Tag:MetricType} - {serializedMetric}"); + } + } +} diff --git a/src/ApiService/ApiService/onefuzzlib/OnefuzzContext.cs b/src/ApiService/ApiService/onefuzzlib/OnefuzzContext.cs index ac463e641..95a599452 100644 --- a/src/ApiService/ApiService/onefuzzlib/OnefuzzContext.cs +++ b/src/ApiService/ApiService/onefuzzlib/OnefuzzContext.cs @@ -15,6 +15,7 @@ public interface IOnefuzzContext { ICreds Creds { get; } IDiskOperations DiskOperations { get; } IEvents Events { get; } + IMetrics Metrics { get; } IExtensions Extensions { get; } IIpOperations IpOperations { get; } IJobOperations JobOperations { get; } @@ -62,6 +63,7 @@ public class OnefuzzContext : IOnefuzzContext { public IAutoScaleOperations AutoScaleOperations => _serviceProvider.GetRequiredService(); public INodeOperations NodeOperations => _serviceProvider.GetRequiredService(); public IEvents Events => _serviceProvider.GetRequiredService(); + public IMetrics Metrics => _serviceProvider.GetRequiredService(); public IWebhookOperations WebhookOperations => _serviceProvider.GetRequiredService(); public IWebhookMessageLogOperations WebhookMessageLogOperations => _serviceProvider.GetRequiredService(); public ITaskOperations TaskOperations => _serviceProvider.GetRequiredService(); diff --git a/src/ApiService/IntegrationTests/Fakes/TestContext.cs b/src/ApiService/IntegrationTests/Fakes/TestContext.cs index 92d36bf15..127f9a04e 100644 --- a/src/ApiService/IntegrationTests/Fakes/TestContext.cs +++ b/src/ApiService/IntegrationTests/Fakes/TestContext.cs @@ -45,6 +45,7 @@ public sealed class TestContext : IOnefuzzContext { FeatureManagerSnapshot = new TestFeatureManagerSnapshot(); WebhookOperations = new TestWebhookOperations(httpClientFactory, logTracer, this); Events = new TestEvents(logTracer, this); + Metrics = new TestMetrics(logTracer, this); WebhookMessageLogOperations = new TestWebhookMessageLogOperations(logTracer, this); } @@ -67,6 +68,7 @@ public sealed class TestContext : IOnefuzzContext { // Implementations: public IEvents Events { get; } + public IMetrics Metrics { get; } public IServiceConfig ServiceConfiguration { get; } diff --git a/src/ApiService/IntegrationTests/Fakes/TestMetrics.cs b/src/ApiService/IntegrationTests/Fakes/TestMetrics.cs new file mode 100644 index 000000000..53a6c9ace --- /dev/null +++ b/src/ApiService/IntegrationTests/Fakes/TestMetrics.cs @@ -0,0 +1,12 @@ +using System.Collections.Generic; +using Microsoft.OneFuzz.Service; + +namespace IntegrationTests.Fakes; + +public sealed class TestMetrics : Metrics { + + public List Metrics { get; } = new(); + public List CustomMetrics { get; } = new(); + public TestMetrics(ILogTracer log, IOnefuzzContext context) + : base(log, context) { } +} diff --git a/src/ApiService/IntegrationTests/TestLogTracer.cs b/src/ApiService/IntegrationTests/TestLogTracer.cs index d83e1db66..59bac855e 100644 --- a/src/ApiService/IntegrationTests/TestLogTracer.cs +++ b/src/ApiService/IntegrationTests/TestLogTracer.cs @@ -28,6 +28,11 @@ sealed class TestLogTracer : ILogTracer { _output.WriteLine($"[Event] [{evt}]"); } + public void Metric(LogStringHandler metric, int value, IReadOnlyDictionary? customDimensions) { + // TODO: metrics + _output.WriteLine($"[Event] [{metric}]"); + } + public void Exception(Exception ex, LogStringHandler message = $"", IReadOnlyDictionary? metrics = null) { // TODO: metrics _output.WriteLine($"[Error] {message} {ex}"); diff --git a/src/ApiService/Tests/OrmTest.cs b/src/ApiService/Tests/OrmTest.cs index 6e6f77272..656acf409 100644 --- a/src/ApiService/Tests/OrmTest.cs +++ b/src/ApiService/Tests/OrmTest.cs @@ -236,7 +236,7 @@ namespace Tests { [Fact] public void TestEventSerialization() { - var expectedEvent = new EventMessage(Guid.NewGuid(), EventType.NodeHeartbeat, new EventNodeHeartbeat(Guid.NewGuid(), Guid.NewGuid(), PoolName.Parse("test-Poool")), Guid.NewGuid(), "test", DateTime.UtcNow); + var expectedEvent = new EventMessage(Guid.NewGuid(), EventType.NodeHeartbeat, new EventNodeHeartbeat(Guid.NewGuid(), Guid.NewGuid(), PoolName.Parse("test-Poool"), NodeState.Busy), Guid.NewGuid(), "test", DateTime.UtcNow); var serialized = JsonSerializer.Serialize(expectedEvent, EntityConverter.GetJsonSerializerOptions()); var actualEvent = JsonSerializer.Deserialize((string)serialized, EntityConverter.GetJsonSerializerOptions()); Assert.Equal(expectedEvent, actualEvent); diff --git a/src/deployment/bicep-templates/feature-flags.bicep b/src/deployment/bicep-templates/feature-flags.bicep index 415d3f069..43e05daba 100644 --- a/src/deployment/bicep-templates/feature-flags.bicep +++ b/src/deployment/bicep-templates/feature-flags.bicep @@ -37,4 +37,17 @@ resource validateNotificationConfigSemantics 'Microsoft.AppConfiguration/configu } } +resource enableCustomMetricFeatureFlag 'Microsoft.AppConfiguration/configurationStores/keyValues@2021-10-01-preview' = { + parent: featureFlags + name: '.appconfig.featureflag~2FEnableCustomMetricTelemetry' + properties: { + value: string({ + id: 'EnableCustomMetricTelemetry' + description: 'Allow custom metrics to be sent.' + enabled: false + }) + contentType: 'application/vnd.microsoft.appconfig.ff+json;charset=utf-8' + } +} + output AppConfigEndpoint string = 'https://${appConfigName}.azconfig.io' diff --git a/src/deployment/bicep-templates/storageAccounts.bicep b/src/deployment/bicep-templates/storageAccounts.bicep index 0fdc78275..6a96cea6a 100644 --- a/src/deployment/bicep-templates/storageAccounts.bicep +++ b/src/deployment/bicep-templates/storageAccounts.bicep @@ -33,6 +33,7 @@ var storageAccountFuncQueuesParams = [ 'update-queue' 'webhooks' 'signalr-events' + 'custom-metrics' ] var fileChangesQueueIndex = 0