Skip to content

Commit 400d524

Browse files
pmachapmanmarksvc
authored andcommitted
drafting metrics: record SF request id to help find related events
Drafting event metrics that are associated with the same NMT draft generation request have a 'tags.draftGenerationRequestId' written to them with an SF-specific id. This id is transferred around by Activity.Current.Tags, by method arguments, and looked up by finding a BuildProjectAsync event with a Serval build id. When SMT is used, `null` is passed for draftGenerationRequestId method arguments.
1 parent 7edc5b8 commit 400d524

File tree

11 files changed

+579
-35
lines changed

11 files changed

+579
-35
lines changed

src/SIL.XForge.Scripture/ClientApp/src/app/event-metrics/event-metric.ts

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -9,6 +9,7 @@ export interface EventMetric {
99
timeStamp: string;
1010
userId?: string;
1111
executionTime?: string;
12+
tags?: { [key: string]: any | undefined };
1213
}
1314

1415
export enum EventScope {

src/SIL.XForge.Scripture/Services/IMachineProjectService.cs

Lines changed: 2 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -15,7 +15,8 @@ Task BuildProjectForBackgroundJobAsync(
1515
string curUserId,
1616
BuildConfig buildConfig,
1717
bool preTranslate,
18-
CancellationToken cancellationToken
18+
string? draftGenerationRequestId = null,
19+
CancellationToken cancellationToken = default
1920
);
2021
Task<string> GetProjectZipAsync(string sfProjectId, Stream outputStream, CancellationToken cancellationToken);
2122
Task RemoveProjectAsync(string sfProjectId, bool preTranslate, CancellationToken cancellationToken);

src/SIL.XForge.Scripture/Services/MachineApiService.cs

Lines changed: 64 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
using System;
22
using System.Collections.Generic;
3+
using System.Diagnostics;
34
using System.Linq;
45
using System.Security.Cryptography;
56
using System.Text;
@@ -584,6 +585,12 @@ public async Task BuildCompletedAsync(string sfProjectId, string buildId, string
584585
{
585586
try
586587
{
588+
string? draftGenerationRequestId = await GetDraftGenerationRequestIdForBuildAsync(buildId);
589+
if (!string.IsNullOrEmpty(draftGenerationRequestId))
590+
{
591+
Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
592+
}
593+
587594
// Retrieve the build started from the event metric. We do this as there may be multiple builds started,
588595
// and this ensures that only builds that want to send an email will have one sent.
589596
var eventMetrics = await eventMetricService.GetEventMetricsAsync(
@@ -680,8 +687,15 @@ await projectSecrets.UpdateAsync(
680687
cancellationToken
681688
);
682689

690+
string buildId = translationBuild.Id;
691+
string? draftGenerationRequestId = await GetDraftGenerationRequestIdForBuildAsync(buildId);
692+
if (!string.IsNullOrEmpty(draftGenerationRequestId))
693+
{
694+
Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
695+
}
696+
683697
// Return the build id so it can be logged
684-
return translationBuild.Id;
698+
return buildId;
685699
}
686700
catch (ServalApiException e) when (e.StatusCode == StatusCodes.Status404NotFound)
687701
{
@@ -765,6 +779,13 @@ public async Task ExecuteWebhookAsync(string json, string signature)
765779
return;
766780
}
767781

782+
// Add the draftGenerationRequestId to associate with other events.
783+
string? draftGenerationRequestId = await GetDraftGenerationRequestIdForBuildAsync(buildId);
784+
if (!string.IsNullOrEmpty(draftGenerationRequestId))
785+
{
786+
Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
787+
}
788+
768789
// Record that the webhook was run successfully
769790
var arguments = new Dictionary<string, object>
770791
{
@@ -1800,17 +1821,23 @@ await projectSecrets.UpdateAsync(
18001821
);
18011822

18021823
// Notify any SignalR clients subscribed to the project
1824+
string? buildId = translationBuild?.Id;
18031825
await hubContext.NotifyBuildProgress(
18041826
sfProjectId,
1805-
new ServalBuildState
1827+
new ServalBuildState { BuildId = buildId, State = nameof(ServalData.PreTranslationsRetrieved) }
1828+
);
1829+
1830+
if (!string.IsNullOrEmpty(buildId))
1831+
{
1832+
string? draftGenerationRequestId = await GetDraftGenerationRequestIdForBuildAsync(buildId);
1833+
if (!string.IsNullOrEmpty(draftGenerationRequestId))
18061834
{
1807-
BuildId = translationBuild?.Id,
1808-
State = nameof(ServalData.PreTranslationsRetrieved),
1835+
Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
18091836
}
1810-
);
1837+
}
18111838

18121839
// Return the build id
1813-
return translationBuild?.Id;
1840+
return buildId;
18141841
}
18151842
}
18161843
catch (TaskCanceledException e) when (e.InnerException is not TimeoutException)
@@ -1879,6 +1906,7 @@ public async Task StartBuildAsync(string curUserId, string sfProjectId, Cancella
18791906
curUserId,
18801907
new BuildConfig { ProjectId = sfProjectId },
18811908
false,
1909+
null,
18821910
CancellationToken.None
18831911
),
18841912
null,
@@ -1904,6 +1932,8 @@ public async Task StartPreTranslationBuildAsync(
19041932
CancellationToken cancellationToken
19051933
)
19061934
{
1935+
string draftGenerationRequestId = ObjectId.GenerateNewId().ToString();
1936+
Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
19071937
// Load the project from the realtime service
19081938
await using IConnection conn = await realtimeService.ConnectAsync(curUserId);
19091939
IDocument<SFProject> projectDoc = await conn.FetchAsync<SFProject>(buildConfig.ProjectId);
@@ -2018,7 +2048,14 @@ await projectDoc.SubmitJson0OpAsync(op =>
20182048
// so that the interceptor functions for BuildProjectAsync().
20192049
jobId = backgroundJobClient.ContinueJobWith<MachineProjectService>(
20202050
jobId,
2021-
r => r.BuildProjectForBackgroundJobAsync(curUserId, buildConfig, true, CancellationToken.None)
2051+
r =>
2052+
r.BuildProjectForBackgroundJobAsync(
2053+
curUserId,
2054+
buildConfig,
2055+
true,
2056+
draftGenerationRequestId,
2057+
CancellationToken.None
2058+
)
20222059
);
20232060

20242061
// Set the pre-translation queued date and time, and hang fire job id
@@ -2586,6 +2623,26 @@ CancellationToken cancellationToken
25862623
return project;
25872624
}
25882625

2626+
/// <summary>
2627+
/// Gets the SF-specific draft generation request identifier for a build by looking up the BuildProjectAsync event.
2628+
/// </summary>
2629+
/// <param name="buildId">The Serval build identifier.</param>
2630+
/// <returns>The draft generation request identifier, or null if not found.</returns>
2631+
private async Task<string?> GetDraftGenerationRequestIdForBuildAsync(string buildId)
2632+
{
2633+
// BuildProjectAsync events serve as a record of what Serval build id corresponds to what draft generation
2634+
// request id.
2635+
QueryResults<EventMetric> buildProjectEvents = await eventMetricService.GetEventMetricsAsync(
2636+
projectId: null,
2637+
scopes: [EventScope.Drafting],
2638+
eventTypes: [nameof(MachineProjectService.BuildProjectAsync)]
2639+
);
2640+
EventMetric? buildEvent = buildProjectEvents.Results.FirstOrDefault(e => e.Result?.ToString() == buildId);
2641+
return (buildEvent?.Tags?.TryGetValue("draftGenerationRequestId", out BsonValue? requestId) == true)
2642+
? requestId?.AsString
2643+
: null;
2644+
}
2645+
25892646
private async Task<string> GetTranslationIdAsync(
25902647
string sfProjectId,
25912648
bool preTranslate,

src/SIL.XForge.Scripture/Services/MachineProjectService.cs

Lines changed: 22 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -106,6 +106,9 @@ public async Task<string> AddSmtProjectAsync(string sfProjectId, CancellationTok
106106
/// <param name="curUserId">The current user identifier.</param>
107107
/// <param name="buildConfig">The build configuration.</param>
108108
/// <param name="preTranslate">If <c>true</c> use NMT; otherwise if <c>false</c> use SMT.</param>
109+
/// <param name="draftGenerationRequestId">
110+
/// The draft generation request identifier (NMT only). Pass null for SMT builds.
111+
/// </param>
109112
/// <param name="cancellationToken">The cancellation token.</param>
110113
/// <returns>An asynchronous task.</returns>
111114
/// <remarks>
@@ -115,12 +118,18 @@ public async Task BuildProjectForBackgroundJobAsync(
115118
string curUserId,
116119
BuildConfig buildConfig,
117120
bool preTranslate,
118-
CancellationToken cancellationToken
121+
string? draftGenerationRequestId = null,
122+
CancellationToken cancellationToken = default
119123
)
120124
{
125+
if (!string.IsNullOrEmpty(draftGenerationRequestId))
126+
{
127+
System.Diagnostics.Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
128+
}
129+
121130
try
122131
{
123-
await BuildProjectAsync(curUserId, buildConfig, preTranslate, cancellationToken);
132+
await BuildProjectAsync(curUserId, buildConfig, preTranslate, draftGenerationRequestId, cancellationToken);
124133
}
125134
catch (TaskCanceledException e) when (e.InnerException is not TimeoutException)
126135
{
@@ -598,8 +607,11 @@ await projectDoc.SubmitJson0OpAsync(op =>
598607
/// <param name="curUserId">The current user identifier.</param>
599608
/// <param name="buildConfig">The build configuration.</param>
600609
/// <param name="preTranslate">If <c>true</c> use NMT; otherwise if <c>false</c> use SMT.</param>
610+
/// <param name="draftGenerationRequestId">
611+
/// The draft generation request identifier (NMT only). Pass null for SMT builds.
612+
/// </param>
601613
/// <param name="cancellationToken">The cancellation token.</param>
602-
/// <returns>An asynchronous task.</returns>
614+
/// <returns>Serval build id</returns>
603615
/// <exception cref="DataNotFoundException">The project or project secret could not be found.</exception>
604616
/// <exception cref="InvalidDataException">The language of the source project was not specified.</exception>
605617
/// <remarks>
@@ -616,9 +628,15 @@ public virtual async Task<string> BuildProjectAsync(
616628
string curUserId,
617629
BuildConfig buildConfig,
618630
bool preTranslate,
619-
CancellationToken cancellationToken
631+
string? draftGenerationRequestId = null,
632+
CancellationToken cancellationToken = default
620633
)
621634
{
635+
if (!string.IsNullOrEmpty(draftGenerationRequestId))
636+
{
637+
System.Diagnostics.Activity.Current?.AddTag("draftGenerationRequestId", draftGenerationRequestId);
638+
}
639+
622640
// Load the target project secrets, so we can get the translation engine ID
623641
if (
624642
!(await projectSecrets.TryGetAsync(buildConfig.ProjectId, cancellationToken)).TryResult(

src/SIL.XForge.Scripture/Services/SyncService.cs

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -198,6 +198,7 @@ await projectSecrets.UpdateAsync(
198198
syncConfig.UserId,
199199
new BuildConfig { ProjectId = syncConfig.ProjectId },
200200
false,
201+
null,
201202
CancellationToken.None
202203
),
203204
null,

src/SIL.XForge/EventMetrics/EventMetric.cs

Lines changed: 9 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -36,7 +36,7 @@ public class EventMetric : IIdentifiable
3636
public string Id { get; set; } = string.Empty;
3737

3838
/// <summary>
39-
/// Gets or sets the event payload.
39+
/// Gets or sets the event payload, which contains the arguments given to the RPC or method call being recorded.
4040
/// </summary>
4141
/// <remarks>
4242
/// <para>If you are querying by projectId or userId, that will be done here.</para>
@@ -73,4 +73,12 @@ public class EventMetric : IIdentifiable
7373
/// Gets or sets the event user identifier.
7474
/// </summary>
7575
public string? UserId { get; set; }
76+
77+
/// <summary>
78+
/// Additional event metadata. For example, from items in an Activity Tags.
79+
/// </summary>
80+
/// <remarks>
81+
/// <para>Keys should be normalized to lowerCamelCase.</para>
82+
/// </remarks>
83+
public Dictionary<string, BsonValue?>? Tags { get; set; }
7684
}

src/SIL.XForge/EventMetrics/EventMetricLogger.cs

Lines changed: 12 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -56,6 +56,10 @@ public void Intercept(IInvocation invocation)
5656
is LogEventMetricAttribute logEventMetricAttribute
5757
)
5858
{
59+
// Start an activity so additional information can be logged via tags
60+
Activity activity = new Activity("log_event_metric").Start();
61+
Activity.Current = activity;
62+
5963
// Invoke the method, then record its event metrics
6064
Task task;
6165
Stopwatch stopwatch = Stopwatch.StartNew();
@@ -68,21 +72,21 @@ is LogEventMetricAttribute logEventMetricAttribute
6872
task = methodTask.ContinueWith(t =>
6973
{
7074
stopwatch.Stop();
71-
return SaveEventMetricAsync(stopwatch.Elapsed, t.Exception);
75+
return SaveEventMetricAsync(stopwatch.Elapsed, activity, t.Exception);
7276
});
7377
}
7478
else
7579
{
7680
// Save the event metric in another thread after the method has executed
7781
stopwatch.Stop();
78-
task = Task.Run(() => SaveEventMetricAsync(stopwatch.Elapsed));
82+
task = Task.Run(() => SaveEventMetricAsync(stopwatch.Elapsed, activity));
7983
}
8084
}
8185
catch (Exception e)
8286
{
8387
// Save the error in the event metric, as the Proceed() will have faulted
8488
stopwatch.Stop();
85-
task = Task.Run(() => SaveEventMetricAsync(stopwatch.Elapsed, e));
89+
task = Task.Run(() => SaveEventMetricAsync(stopwatch.Elapsed, activity, e));
8690

8791
// Notify observers of the task of immediate completion
8892
TaskStarted?.Invoke(task);
@@ -97,7 +101,7 @@ is LogEventMetricAttribute logEventMetricAttribute
97101

98102
// Run as a separate task so we do not slow down the method execution
99103
// Unless we want the return value, in which case we will not write the metric until the method returns
100-
async Task SaveEventMetricAsync(TimeSpan executionTime, Exception? exception = null)
104+
async Task SaveEventMetricAsync(TimeSpan executionTime, Activity activity, Exception? exception = null)
101105
{
102106
string methodName = invocation.Method.Name;
103107
try
@@ -194,6 +198,10 @@ await eventMetricService.SaveEventMetricAsync(
194198
// Just log any errors rather than throwing
195199
logger.LogError(e, "Error logging event metric for {methodName}", methodName);
196200
}
201+
finally
202+
{
203+
activity.Dispose();
204+
}
197205
}
198206
}
199207

src/SIL.XForge/Services/EventMetricService.cs

Lines changed: 31 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -1,5 +1,6 @@
11
using System;
22
using System.Collections.Generic;
3+
using System.Diagnostics;
34
using System.Linq;
45
using System.Threading;
56
using System.Threading.Tasks;
@@ -93,6 +94,35 @@ public async Task SaveEventMetricAsync(
9394
payload[kvp.Key] = GetBsonValue(kvp.Value);
9495
}
9596

97+
// Collect tags from Activity.Current and all parent activities
98+
// Child activity tags override parent tags with the same key
99+
Dictionary<string, BsonValue?>? tags = null;
100+
var collectedTags = new Dictionary<string, string?>();
101+
102+
// Walk up the activity chain collecting tags (parent first, so child overrides)
103+
var activity = Activity.Current;
104+
var activityChain = new Stack<Activity>();
105+
while (activity is not null)
106+
{
107+
activityChain.Push(activity);
108+
activity = activity.Parent;
109+
}
110+
111+
// Apply tags from root to current (so child overrides parent)
112+
while (activityChain.Count > 0)
113+
{
114+
activity = activityChain.Pop();
115+
foreach (var kvp in activity.Tags)
116+
{
117+
collectedTags[kvp.Key] = kvp.Value;
118+
}
119+
}
120+
121+
if (collectedTags.Count > 0)
122+
{
123+
tags = collectedTags.ToDictionary(kvp => kvp.Key, kvp => GetBsonValue(kvp.Value));
124+
}
125+
96126
// Generate the event metric
97127
var eventMetric = new EventMetric
98128
{
@@ -103,6 +133,7 @@ public async Task SaveEventMetricAsync(
103133
ProjectId = projectId,
104134
Scope = scope,
105135
UserId = userId,
136+
Tags = tags,
106137
};
107138

108139
// Do not set Result if it is null, or the document will contain "result: null"

0 commit comments

Comments
 (0)