private static string GetBucket(AugmentedTimelineIssue augIssue)
{
string message = augIssue?.Raw?.Message;
if (string.IsNullOrEmpty(message))
{
return(null);
}
Match match = Regex.Match(message, @"\(NETCORE_ENGINEERING_TELEMETRY=([^)]*)\)");
if (!match.Success)
{
return(null);
}
return(match.Groups[1].Value);
}
public async Task RunProject(
string project,
int buildBatchSize,
CancellationToken cancellationToken)
{
DateTimeOffset latest;
DateTimeOffset?latestCandidate = await _timelineTelemetryRepository.GetLatestTimelineBuild(project);
if (latestCandidate.HasValue)
{
latest = latestCandidate.Value;
}
else
{
latest = _systemClock.UtcNow.Subtract(TimeSpan.FromDays(30));
_logger.LogWarning($"No previous time found, using {latest.LocalDateTime:O}");
}
_logger.LogInformation("Reading project {project}", project);
Build[] builds = await GetBuildsAsync(_azureServer, project, latest, buildBatchSize, cancellationToken);
_logger.LogTrace("... found {builds} builds...", builds.Length);
if (builds.Length == 0)
{
_logger.LogTrace("No work to do");
return;
}
List <(int buildId, BuildRequestValidationResult validationResult)> validationResults = builds
.SelectMany(
build => build.ValidationResults,
(build, validationResult) => (build.Id, validationResult))
.ToList();
_logger.LogTrace("Fetching timeline...");
Dictionary <Build, Task <Timeline> > tasks = builds
.ToDictionary(
build => build,
build => _azureServer.GetTimelineAsync(project, build.Id, cancellationToken)
);
await Task.WhenAll(tasks.Select(s => s.Value));
// Identify additional timelines by inspecting each record for a "PreviousAttempt"
// object, then fetching the "timelineId" field.
List <(Build build, Task <Timeline> timelineTask)> retriedTimelineTasks = new List <(Build, Task <Timeline>)>();
foreach ((Build build, Task <Timeline> timelineTask) in tasks)
{
Timeline timeline = await timelineTask;
if (timeline is null)
{
_logger.LogDebug("No timeline found for buildid {buildid}", build.Id);
continue;
}
IEnumerable <string> additionalTimelineIds = timeline.Records
.Where(record => record.PreviousAttempts != null)
.SelectMany(record => record.PreviousAttempts)
.Select(attempt => attempt.TimelineId)
.Distinct();
retriedTimelineTasks.AddRange(
additionalTimelineIds.Select(
timelineId => (build, _azureServer.GetTimelineAsync(project, build.Id, timelineId, cancellationToken))));
}
await Task.WhenAll(retriedTimelineTasks.Select(o => o.timelineTask));
// Only record timelines where their "lastChangedOn" field is after the last
// recorded date. Anything before has already been recorded.
List <(Build build, Task <Timeline> timeline)> allNewTimelines = new List <(Build build, Task <Timeline> timeline)>();
allNewTimelines.AddRange(tasks.Select(t => (t.Key, t.Value)));
allNewTimelines.AddRange(retriedTimelineTasks
.Where(t => t.timelineTask.Result.LastChangedOn > latest));
_logger.LogTrace("... finished timeline");
var records = new List <AugmentedTimelineRecord>();
var issues = new List <AugmentedTimelineIssue>();
var augmentedBuilds = new List <AugmentedBuild>();
_logger.LogTrace("Aggregating results...");
foreach ((Build build, Task <Timeline> timelineTask) in allNewTimelines)
{
using IDisposable buildScope = _logger.BeginScope(KeyValuePair.Create("buildId", build.Id));
augmentedBuilds.Add(CreateAugmentedBuild(build));
Timeline timeline = await timelineTask;
if (timeline?.Records == null)
{
continue;
}
var recordCache =
new Dictionary <string, AugmentedTimelineRecord>();
var issueCache = new List <AugmentedTimelineIssue>();
foreach (TimelineRecord record in timeline.Records)
{
var augRecord = new AugmentedTimelineRecord(build.Id, timeline.Id, record);
recordCache.Add(record.Id, augRecord);
records.Add(augRecord);
if (record.Issues == null)
{
continue;
}
for (int iIssue = 0; iIssue < record.Issues.Length; iIssue++)
{
var augIssue =
new AugmentedTimelineIssue(build.Id, timeline.Id, record.Id, iIssue, record.Issues[iIssue]);
augIssue.Bucket = GetBucket(augIssue);
issueCache.Add(augIssue);
issues.Add(augIssue);
}
}
foreach (AugmentedTimelineRecord record in recordCache.Values)
{
FillAugmentedOrder(record, recordCache);
}
foreach (AugmentedTimelineIssue issue in issueCache)
{
if (recordCache.TryGetValue(issue.RecordId, out AugmentedTimelineRecord record))
{
issue.AugmentedIndex = record.AugmentedOrder + "." + issue.Index.ToString("D3");
}
else
{
issue.AugmentedIndex = "999." + issue.Index.ToString("D3");
}
}
}
_logger.LogInformation("Saving TimelineBuilds...");
await _timelineTelemetryRepository.WriteTimelineBuilds(augmentedBuilds);
_logger.LogInformation("Saving TimelineValidationMessages...");
await _timelineTelemetryRepository.WriteTimelineValidationMessages(validationResults);
_logger.LogInformation("Saving TimelineRecords...");
await _timelineTelemetryRepository.WriteTimelineRecords(records);
_logger.LogInformation("Saving TimelineIssues...");
await _timelineTelemetryRepository.WriteTimelineIssues(issues);
}
private async Task RunProject(
AzureDevOpsClient azureServer,
string project,
int buildBatchSize,
AzureDevOpsTimelineOptions options,
CancellationToken cancellationToken)
{
DateTimeOffset latest;
try
{
using (ICslQueryProvider query =
KustoClientFactory.CreateCslQueryProvider(options.KustoQueryConnectionString))
using (IDataReader result = await query.ExecuteQueryAsync(
options.KustoDatabase,
// This isn't use controlled, so I'm not worried about the Kusto injection
$"TimelineBuilds | where Project == '{project}' | summarize max(FinishTime)",
new ClientRequestProperties()
))
{
if (!result.Read())
{
latest = DateTimeOffset.UtcNow.Subtract(TimeSpan.FromDays(30));
_logger.LogWarning($"No previous time found, using {latest.LocalDateTime:O}");
}
else
{
latest = result.GetDateTime(0);
_logger.LogInformation($"... fetched previous time of {latest.LocalDateTime:O}");
}
}
}
catch (SemanticException e) when(e.SemanticErrors == "'where' operator: Failed to resolve column or scalar expression named 'Project'")
{
// The Project column isn't there, we probably reinitalized the tables
latest = DateTimeOffset.UtcNow.Subtract(TimeSpan.FromDays(30));
_logger.LogWarning($"No table column 'Project' found, assumed reinialization: using {latest.LocalDateTime:O}");
}
_logger.LogInformation("Reading project {project}", project);
Build[] builds = await GetBuildsAsync(azureServer, project, latest, buildBatchSize, cancellationToken);
_logger.LogTrace("... found {builds} builds...", builds.Length);
if (builds.Length == 0)
{
_logger.LogTrace("No work to do");
return;
}
List <(int buildId, BuildRequestValidationResult validationResult)> validationResults = builds
.SelectMany(
build => build.ValidationResults,
(build, validationResult) => (build.Id, validationResult))
.ToList();
_logger.LogTrace("Fetching timeline...");
Dictionary <Build, Task <Timeline> > tasks = builds
.ToDictionary(
build => build,
build => azureServer.GetTimelineAsync(project, build.Id, cancellationToken)
);
await Task.WhenAll(tasks.Select(s => s.Value));
_logger.LogTrace("... finished timeline");
var records = new List <AugmentedTimelineRecord>();
var issues = new List <AugmentedTimelineIssue>();
_logger.LogTrace("Aggregating results...");
foreach ((Build build, Task <Timeline> timelineTask) in tasks)
{
Timeline timeline = await timelineTask;
if (timeline?.Records == null)
{
continue;
}
var recordCache =
new Dictionary <string, AugmentedTimelineRecord>();
var issueCache = new List <AugmentedTimelineIssue>();
foreach (TimelineRecord record in timeline.Records)
{
var augRecord = new AugmentedTimelineRecord(build.Id, record);
recordCache.Add(record.Id, augRecord);
records.Add(augRecord);
if (record.Issues == null)
{
continue;
}
for (int iIssue = 0; iIssue < record.Issues.Length; iIssue++)
{
var augIssue =
new AugmentedTimelineIssue(build.Id, record.Id, iIssue, record.Issues[iIssue]);
augIssue.Bucket = GetBucket(augIssue);
issueCache.Add(augIssue);
issues.Add(augIssue);
}
}
foreach (AugmentedTimelineRecord record in recordCache.Values)
{
FillAugmentedOrder(record, recordCache);
}
foreach (AugmentedTimelineIssue issue in issueCache)
{
if (recordCache.TryGetValue(issue.RecordId, out AugmentedTimelineRecord record))
{
issue.AugmentedIndex = record.AugmentedOrder + "." + issue.Index.ToString("D3");
}
else
{
issue.AugmentedIndex = "999." + issue.Index.ToString("D3");
}
}
}
if (string.IsNullOrEmpty(options.KustoIngestConnectionString))
{
_logger.LogError("No KustoIngestConnectionString set");
return;
}
IKustoIngestClient ingest =
KustoIngestFactory.CreateQueuedIngestClient(options.KustoIngestConnectionString);
_logger.LogInformation("Saving TimelineBuilds...");
await KustoHelpers.WriteDataToKustoInMemoryAsync(
ingest,
options.KustoDatabase,
"TimelineBuilds",
_logger,
builds,
b => new[]
{
new KustoValue("BuildId", b.Id.ToString(), KustoDataTypes.Int),
new KustoValue("Status", b.Status, KustoDataTypes.String),
new KustoValue("Result", b.Result, KustoDataTypes.String),
new KustoValue("Repository", b.Repository?.Name ?? b.Repository?.Id, KustoDataTypes.String),
new KustoValue("Reason", b.Reason, KustoDataTypes.String),
new KustoValue("BuildNumber", b.BuildNumber, KustoDataTypes.String),
new KustoValue("QueueTime", b.QueueTime, KustoDataTypes.DateTime),
new KustoValue("StartTime", b.StartTime, KustoDataTypes.DateTime),
new KustoValue("FinishTime", b.FinishTime, KustoDataTypes.DateTime),
new KustoValue("Project", b.Project?.Name, KustoDataTypes.String),
new KustoValue("DefinitionId", b.Definition?.Id.ToString(), KustoDataTypes.String),
new KustoValue("Definition", $"{b.Definition?.Path}\\{b.Definition?.Name}", KustoDataTypes.String),
});
_logger.LogInformation("Saving TimelineValidationMessages...");
await KustoHelpers.WriteDataToKustoInMemoryAsync(
ingest,
options.KustoDatabase,
"TimelineIssues",
_logger,
validationResults,
b => new[]
{
new KustoValue("BuildId", b.buildId.ToString(), KustoDataTypes.Int),
new KustoValue("RecordId", null, KustoDataTypes.String),
new KustoValue("Index", null, KustoDataTypes.Int),
new KustoValue("Path", null, KustoDataTypes.String),
new KustoValue("Type", b.validationResult.Result, KustoDataTypes.String),
new KustoValue("Category", "ValidationResult", KustoDataTypes.String),
new KustoValue("Message", b.validationResult.Message, KustoDataTypes.String),
new KustoValue("Bucket", "ValidationResult", KustoDataTypes.String),
});
_logger.LogInformation("Saving TimelineRecords...");
await KustoHelpers.WriteDataToKustoInMemoryAsync(
ingest,
options.KustoDatabase,
"TimelineRecords",
_logger,
records,
b => new[]
{
new KustoValue("BuildId", b.BuildId.ToString(), KustoDataTypes.Int),
new KustoValue("RecordId", b.Raw.Id, KustoDataTypes.String),
new KustoValue("Order", b.Raw.Order.ToString(), KustoDataTypes.Int),
new KustoValue("Path", b.AugmentedOrder, KustoDataTypes.String),
new KustoValue("ParentId", b.Raw.ParentId, KustoDataTypes.String),
new KustoValue("Name", b.Raw.Name, KustoDataTypes.String),
new KustoValue("StartTime", b.Raw.StartTime, KustoDataTypes.DateTime),
new KustoValue("FinishTime", b.Raw.FinishTime, KustoDataTypes.DateTime),
new KustoValue("Result", b.Raw.Result, KustoDataTypes.String),
new KustoValue("ResultCode", b.Raw.ResultCode, KustoDataTypes.String),
new KustoValue("ChangeId", b.Raw.ChangeId.ToString(), KustoDataTypes.Int),
new KustoValue("LastModified", b.Raw.LastModified, KustoDataTypes.DateTime),
new KustoValue("WorkerName", b.Raw.WorkerName, KustoDataTypes.String),
new KustoValue("Details", b.Raw.Details?.Url, KustoDataTypes.String),
new KustoValue("ErrorCount", b.Raw.ErrorCount.ToString(), KustoDataTypes.Int),
new KustoValue("WarningCount", b.Raw.WarningCount.ToString(), KustoDataTypes.Int),
new KustoValue("Url", b.Raw.Url, KustoDataTypes.String),
new KustoValue("LogId", b.Raw.Log?.Id.ToString(), KustoDataTypes.Int),
new KustoValue("LogUri", b.Raw.Log?.Url, KustoDataTypes.String),
new KustoValue("TaskId", b.Raw.Task?.Id, KustoDataTypes.Int),
new KustoValue("TaskName", b.Raw.Task?.Name, KustoDataTypes.String),
new KustoValue("TaskVersion", b.Raw.Task?.Version, KustoDataTypes.String),
new KustoValue("Attempt", b.Raw.Attempt.ToString(), KustoDataTypes.Int),
});
_logger.LogInformation("Saving TimelineIssues...");
await KustoHelpers.WriteDataToKustoInMemoryAsync(
ingest,
options.KustoDatabase,
"TimelineIssues",
_logger,
issues,
b => new[]
{
new KustoValue("BuildId", b.BuildId.ToString(), KustoDataTypes.Int),
new KustoValue("RecordId", b.RecordId, KustoDataTypes.String),
new KustoValue("Index", b.Index.ToString(), KustoDataTypes.Int),
new KustoValue("Path", b.AugmentedIndex, KustoDataTypes.String),
new KustoValue("Type", b.Raw.Type, KustoDataTypes.String),
new KustoValue("Category", b.Raw.Category, KustoDataTypes.String),
new KustoValue("Message", b.Raw.Message, KustoDataTypes.String),
new KustoValue("Bucket", b.Bucket, KustoDataTypes.String),
});
}
