Skip to content

Commit

Permalink
Source generators/track values etw (dotnet#68830)
Browse files Browse the repository at this point in the history 
* Log generator exceptions
* Instrument most nodes
  • Loading branch information
@chsienki
chsienki authored Jul 25, 2023
1 parent e40e44e commit 692d17e
Show file tree
Hide file tree
Showing 10 changed files with 128 additions and 38 deletions.
4 changes: 2 additions & 2 deletions src/Compilers/CSharp/Test/Semantic/SourceGeneration/StateTableTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -90,12 +90,12 @@ public void Node_Builder_Can_Add_Entries_From_Previous_Table()

var expected = ImmutableArray.Create((10, EntryState.Modified, 0), (11, EntryState.Added, 1), (2, EntryState.Cached, 0), (3, EntryState.Cached, 1), (20, EntryState.Modified, 0), (21, EntryState.Modified, 1), (22, EntryState.Added, 2), (6, EntryState.Removed, 0));
AssertTableEntries(newTable, expected);
Assert.Equal(new[] { 2, 3 }, YieldItems(cachedEntries.Items));
Assert.Equal(new[] { 2, 3 }, yieldItems(cachedEntries.Items));
Assert.Equal(1, removedEntries.Count);
Assert.Equal(6, removedEntries[0]);
Assert.True(didRemoveEntries);

static IEnumerable<int> YieldItems(OneOrMany<int> items)
static IEnumerable<int> yieldItems(OneOrMany<int> items)
{
foreach (var value in items)
yield return value;
Expand Down
8 changes: 8 additions & 0 deletions src/Compilers/Core/Portable/CodeAnalysisEventSource.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -16,12 +16,14 @@ internal sealed class CodeAnalysisEventSource : EventSource
public static class Keywords
{
public const EventKeywords Performance = (EventKeywords)1;
public const EventKeywords Correctness = (EventKeywords)2;
}

public static class Tasks
{
public const EventTask GeneratorDriverRunTime = (EventTask)1;
public const EventTask SingleGeneratorRunTime = (EventTask)2;
public const EventTask BuildStateTable = (EventTask)3;
}

private CodeAnalysisEventSource() { }
Expand All @@ -37,5 +39,11 @@ private CodeAnalysisEventSource() { }

[Event(4, Message = "Generator {0} ran for {2} ticks", Keywords = Keywords.Performance, Level = EventLevel.Informational, Opcode = EventOpcode.Stop, Task = Tasks.SingleGeneratorRunTime)]
internal void StopSingleGeneratorRunTime(string generatorName, string assemblyPath, long elapsedTicks, string id) => WriteEvent(4, generatorName, assemblyPath, elapsedTicks, id);

[Event(5, Message = "Generator '{0}' failed with exception: {1}", Level = EventLevel.Error)]
internal void GeneratorException(string generatorName, string exception) => WriteEvent(5, generatorName, exception);

[Event(6, Message = "Node {0} transformed", Keywords = Keywords.Correctness, Level = EventLevel.Verbose, Task = Tasks.BuildStateTable)]
internal void NodeTransform(int nodeHashCode, string name, string tableType, int previousTable, string previousTableContent, int newTable, string newTableContent, int input1, int input2) => WriteEvent(6, nodeHashCode, name, tableType, previousTable, previousTableContent, newTable, newTableContent, input1, input2);
}
}
5 changes: 5 additions & 0 deletions src/Compilers/Core/Portable/SourceGeneration/GeneratorDriver.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -341,6 +341,11 @@ private ImmutableArray<GeneratedSyntaxTree> ParseAdditionalSources(ISourceGenera

private static GeneratorState SetGeneratorException(Compilation compilation, CommonMessageProvider provider, GeneratorState generatorState, ISourceGenerator generator, Exception e, DiagnosticBag? diagnosticBag, CancellationToken cancellationToken, TimeSpan? runTime = null, bool isInit = false)
{
if (CodeAnalysisEventSource.Log.IsEnabled())
{
CodeAnalysisEventSource.Log.GeneratorException(generator.GetGeneratorType().Name, e.ToString());
}

var errorCode = isInit ? provider.WRN_GeneratorFailedDuringInitialization : provider.WRN_GeneratorFailedDuringGeneration;

// ISSUE: Diagnostics don't currently allow descriptions with arguments, so we have to manually create the diagnostic description
Expand Down
18 changes: 10 additions & 8 deletions src/Compilers/Core/Portable/SourceGeneration/Nodes/BatchNode.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -119,28 +119,30 @@ public NodeStateTable<ImmutableArray<TInput>> UpdateStateTable(DriverStateTable.
// - Modified otherwise

// update the table
var newTable = builder.CreateTableBuilder(previousTable, _name, _comparer);
var tableBuilder = builder.CreateTableBuilder(previousTable, _name, _comparer);

// If this execution is tracking steps, then the source table should have also tracked steps or be the empty table.
Debug.Assert(!newTable.TrackIncrementalSteps || (sourceTable.HasTrackedSteps || sourceTable.IsEmpty));
Debug.Assert(!tableBuilder.TrackIncrementalSteps || (sourceTable.HasTrackedSteps || sourceTable.IsEmpty));

var stopwatch = SharedStopwatch.StartNew();

var (sourceValues, sourceInputs) = GetValuesAndInputs(sourceTable, previousTable, newTable);
var (sourceValues, sourceInputs) = GetValuesAndInputs(sourceTable, previousTable, tableBuilder);

if (previousTable is null || previousTable.IsEmpty)
{
newTable.AddEntry(sourceValues, EntryState.Added, stopwatch.Elapsed, sourceInputs, EntryState.Added);
tableBuilder.AddEntry(sourceValues, EntryState.Added, stopwatch.Elapsed, sourceInputs, EntryState.Added);
}
else if (!sourceTable.IsCached || !newTable.TryUseCachedEntries(stopwatch.Elapsed, sourceInputs))
else if (!sourceTable.IsCached || !tableBuilder.TryUseCachedEntries(stopwatch.Elapsed, sourceInputs))
{
if (!newTable.TryModifyEntry(sourceValues, _comparer, stopwatch.Elapsed, sourceInputs, EntryState.Modified))
if (!tableBuilder.TryModifyEntry(sourceValues, _comparer, stopwatch.Elapsed, sourceInputs, EntryState.Modified))
{
newTable.AddEntry(sourceValues, EntryState.Added, stopwatch.Elapsed, sourceInputs, EntryState.Added);
tableBuilder.AddEntry(sourceValues, EntryState.Added, stopwatch.Elapsed, sourceInputs, EntryState.Added);
}
}

return newTable.ToImmutableAndFree();
var newTable = tableBuilder.ToImmutableAndFree();
this.LogTables(_name, previousTable, newTable, sourceTable);
return newTable;
}

public void RegisterOutput(IIncrementalGeneratorOutputNode output) => _sourceNode.RegisterOutput(output);
Expand Down
17 changes: 10 additions & 7 deletions src/Compilers/Core/Portable/SourceGeneration/Nodes/CombineNode.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -34,6 +34,7 @@ public CombineNode(IIncrementalGeneratorNode<TInput1> input1, IIncrementalGenera

if (input1Table.IsCached && input2Table.IsCached && previousTable is not null)
{
this.LogTables(_name, previousTable, previousTable, input1Table, input2Table);
if (graphState.DriverState.TrackIncrementalSteps)
{
return RecordStepsForCachedTable(graphState, previousTable, input1Table, input2Table);
Expand All @@ -42,8 +43,7 @@ public CombineNode(IIncrementalGeneratorNode<TInput1> input1, IIncrementalGenera
}

var totalEntryItemCount = input1Table.GetTotalEntryItemCount();
var builder = graphState.CreateTableBuilder(previousTable, _name, _comparer, totalEntryItemCount);

var tableBuilder = graphState.CreateTableBuilder(previousTable, _name, _comparer, totalEntryItemCount);
// Semantics of a join:
//
// When input1[i] is cached:
Expand All @@ -60,7 +60,7 @@ public CombineNode(IIncrementalGeneratorNode<TInput1> input1, IIncrementalGenera
{
var stopwatch = SharedStopwatch.StartNew();

var stepInputs = builder.TrackIncrementalSteps ? ImmutableArray.Create((entry1.Step!, entry1.OutputIndex), (input2Step!, 0)) : default;
var stepInputs = tableBuilder.TrackIncrementalSteps ? ImmutableArray.Create((entry1.Step!, entry1.OutputIndex), (input2Step!, 0)) : default;

var state = (entry1.State, isInput2Cached) switch
{
Expand All @@ -70,14 +70,17 @@ public CombineNode(IIncrementalGeneratorNode<TInput1> input1, IIncrementalGenera
};

var entry = (entry1.Item, input2);
if (state != EntryState.Modified || _comparer is null || !builder.TryModifyEntry(entry, _comparer, stopwatch.Elapsed, stepInputs, state))
if (state != EntryState.Modified || _comparer is null || !tableBuilder.TryModifyEntry(entry, _comparer, stopwatch.Elapsed, stepInputs, state))
{
builder.AddEntry(entry, state, stopwatch.Elapsed, stepInputs, state);
tableBuilder.AddEntry(entry, state, stopwatch.Elapsed, stepInputs, state);
}
}

Debug.Assert(builder.Count == totalEntryItemCount);
return builder.ToImmutableAndFree();
Debug.Assert(tableBuilder.Count == totalEntryItemCount);

var newTable = tableBuilder.ToImmutableAndFree();
this.LogTables(_name, previousTable, newTable, input1Table, input2Table);
return newTable;
}

private NodeStateTable<(TInput1, TInput2)> RecordStepsForCachedTable(DriverStateTable.Builder graphState, NodeStateTable<(TInput1, TInput2)> previousTable, NodeStateTable<TInput1> input1Table, NodeStateTable<TInput2> input2Table)
Expand Down
35 changes: 28 additions & 7 deletions src/Compilers/Core/Portable/SourceGeneration/Nodes/InputNode.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -52,10 +52,10 @@ public NodeStateTable<T> UpdateStateTable(DriverStateTable.Builder graphState, N
Debug.Assert(added);
}

var builder = graphState.CreateTableBuilder(previousTable, _name, _comparer);
var tableBuilder = graphState.CreateTableBuilder(previousTable, _name, _comparer);

// We always have no inputs steps into an InputNode, but we track the difference between "no inputs" (empty collection) and "no step information" (default value)
var noInputStepsStepInfo = builder.TrackIncrementalSteps ? ImmutableArray<(IncrementalGeneratorRunStep, int)>.Empty : default;
var noInputStepsStepInfo = tableBuilder.TrackIncrementalSteps ? ImmutableArray<(IncrementalGeneratorRunStep, int)>.Empty : default;

if (previousTable is not null)
{
Expand All @@ -66,7 +66,7 @@ public NodeStateTable<T> UpdateStateTable(DriverStateTable.Builder graphState, N
if (itemsSet.Remove(oldItem))
{
// we're iterating the table, so know that it has entries
var usedCache = builder.TryUseCachedEntries(elapsedTime, noInputStepsStepInfo);
var usedCache = tableBuilder.TryUseCachedEntries(elapsedTime, noInputStepsStepInfo);
Debug.Assert(usedCache);
}
else if (inputItems.Length == previousTable.Count)
Expand All @@ -75,13 +75,13 @@ public NodeStateTable<T> UpdateStateTable(DriverStateTable.Builder graphState, N
// This allows us to correctly 'replace' items even when they aren't actually the same. In the case that the
// item really isn't modified, but a new item, we still function correctly as we mostly treat them the same,
// but will perform an extra comparison that is omitted in the pure 'added' case.
var modified = builder.TryModifyEntry(inputItems[itemIndex], _comparer, elapsedTime, noInputStepsStepInfo, EntryState.Modified);
var modified = tableBuilder.TryModifyEntry(inputItems[itemIndex], _comparer, elapsedTime, noInputStepsStepInfo, EntryState.Modified);
Debug.Assert(modified);
itemsSet.Remove(inputItems[itemIndex]);
}
else
{
var removed = builder.TryRemoveEntries(elapsedTime, noInputStepsStepInfo);
var removed = tableBuilder.TryRemoveEntries(elapsedTime, noInputStepsStepInfo);
Debug.Assert(removed);
}
itemIndex++;
Expand All @@ -91,10 +91,13 @@ public NodeStateTable<T> UpdateStateTable(DriverStateTable.Builder graphState, N
// any remaining new items are added
foreach (var newItem in itemsSet)
{
builder.AddEntry(newItem, EntryState.Added, elapsedTime, noInputStepsStepInfo, EntryState.Added);
tableBuilder.AddEntry(newItem, EntryState.Added, elapsedTime, noInputStepsStepInfo, EntryState.Added);
}

return builder.ToImmutableAndFree();
var newTable = tableBuilder.ToImmutableAndFree();
this.LogTables(previousTable, newTable, inputItems);
return newTable;

}

public IIncrementalGeneratorNode<T> WithComparer(IEqualityComparer<T> comparer) => new InputNode<T>(_getInput, _registerOutput, _inputComparer, comparer, _name);
Expand All @@ -104,5 +107,23 @@ public NodeStateTable<T> UpdateStateTable(DriverStateTable.Builder graphState, N
public InputNode<T> WithRegisterOutput(Action<IIncrementalGeneratorOutputNode> registerOutput) => new InputNode<T>(_getInput, registerOutput, _inputComparer, _comparer, _name);

public void RegisterOutput(IIncrementalGeneratorOutputNode output) => _registerOutput(output);

private void LogTables(NodeStateTable<T>? previousTable, NodeStateTable<T> newTable, ImmutableArray<T> inputs)
{
if (!CodeAnalysisEventSource.Log.IsEnabled())
{
// don't bother building the dummy table if we're not going to log anyway
return;
}

var tableBuilder = NodeStateTable<T>.Empty.ToBuilder(_name, stepTrackingEnabled: false);
foreach (var input in inputs)
{
tableBuilder.AddEntry(input, EntryState.Added, TimeSpan.Zero, stepInputs: default, EntryState.Added);
}
var inputTable = tableBuilder.ToImmutableAndFree();

this.LogTables(_name, previousTable, newTable, inputTable);
}
}
}
31 changes: 31 additions & 0 deletions src/Compilers/Core/Portable/SourceGeneration/Nodes/NodeExtensions.cs
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,31 @@
// Licensed to the .NET Foundation under one or more agreements.
// The .NET Foundation licenses this file to you under the MIT license.
// See the LICENSE file in the project root for more information.

namespace Microsoft.CodeAnalysis
{
internal static class NodeExtensions
{
public static void LogTables<TSelf, TInput>(this IIncrementalGeneratorNode<TSelf> self, string? name, NodeStateTable<TSelf>? previousTable, NodeStateTable<TSelf> newTable, NodeStateTable<TInput> inputTable)
=> LogTables<TSelf, TInput, TInput>(self, name, previousTable, newTable, inputTable, inputNode2: null);

public static void LogTables<TSelf, TInput1, TInput2>(this IIncrementalGeneratorNode<TSelf> self, string? name, NodeStateTable<TSelf>? previousTable, NodeStateTable<TSelf> newTable, NodeStateTable<TInput1> inputNode1, NodeStateTable<TInput2>? inputNode2)
{
if (CodeAnalysisEventSource.Log.IsEnabled())
{
// don't log the new table if we skipped creating a new one
var newTableOpt = newTable != previousTable ? newTable : null;

CodeAnalysisEventSource.Log.NodeTransform(self.GetHashCode(),
name ?? "<anonymous>",
typeof(TSelf).FullName ?? "<unknown>",
previousTable?.GetHashCode() ?? -1,
previousTable?.GetPackedStates() ?? "",
newTableOpt?.GetHashCode() ?? -1,
newTableOpt?.GetPackedStates() ?? "",
inputNode1.GetHashCode(),
inputNode2?.GetHashCode() ?? -1);
}
}
}
}
14 changes: 14 additions & 0 deletions src/Compilers/Core/Portable/SourceGeneration/Nodes/NodeStateTable.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -154,6 +154,20 @@ public NodeStateTable<T> CreateCachedTableWithUpdatedSteps<TInput>(NodeStateTabl
return builder.ToImmutableAndFree();
}

public string GetPackedStates()
{
var pooled = PooledStringBuilder.GetInstance();
foreach (var state in _states)
{
for (int i = 0; i < state.Count; i++)
{
pooled.Builder.Append(state.GetState(i).ToString()[0]);
}
pooled.Builder.Append(',');
}
return pooled.ToStringAndFree();
}

/// <remarks>
/// The builder is <b>not</b> threadsafe.
/// </remarks>
Expand Down
17 changes: 10 additions & 7 deletions src/Compilers/Core/Portable/SourceGeneration/Nodes/SourceOutputNode.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -41,22 +41,23 @@ public NodeStateTable<TOutput> UpdateStateTable(DriverStateTable.Builder graphSt
var sourceTable = graphState.GetLatestStateTableForNode(_source);
if (sourceTable.IsCached && previousTable is not null)
{
this.LogTables(stepName, previousTable, previousTable, sourceTable);
if (graphState.DriverState.TrackIncrementalSteps)
{
return previousTable.CreateCachedTableWithUpdatedSteps(sourceTable, stepName, EqualityComparer<TOutput>.Default);
}
return previousTable;
}

var nodeTable = graphState.CreateTableBuilder(previousTable, stepName, EqualityComparer<TOutput>.Default);
var tableBuilder = graphState.CreateTableBuilder(previousTable, stepName, EqualityComparer<TOutput>.Default);
foreach (var entry in sourceTable)
{
var inputs = nodeTable.TrackIncrementalSteps ? ImmutableArray.Create((entry.Step!, entry.OutputIndex)) : default;
var inputs = tableBuilder.TrackIncrementalSteps ? ImmutableArray.Create((entry.Step!, entry.OutputIndex)) : default;
if (entry.State == EntryState.Removed)
{
nodeTable.TryRemoveEntries(TimeSpan.Zero, inputs);
tableBuilder.TryRemoveEntries(TimeSpan.Zero, inputs);
}
else if (entry.State != EntryState.Cached || !nodeTable.TryUseCachedEntries(TimeSpan.Zero, inputs))
else if (entry.State != EntryState.Cached || !tableBuilder.TryUseCachedEntries(TimeSpan.Zero, inputs))
{
var sourcesBuilder = new AdditionalSourcesCollection(_sourceExtension);
var diagnostics = DiagnosticBag.GetInstance();
Expand All @@ -68,9 +69,9 @@ public NodeStateTable<TOutput> UpdateStateTable(DriverStateTable.Builder graphSt
_action(context, entry.Item, cancellationToken);
var sourcesAndDiagnostics = (sourcesBuilder.ToImmutable(), diagnostics.ToReadOnly());

if (entry.State != EntryState.Modified || !nodeTable.TryModifyEntry(sourcesAndDiagnostics, EqualityComparer<TOutput>.Default, stopwatch.Elapsed, inputs, entry.State))
if (entry.State != EntryState.Modified || !tableBuilder.TryModifyEntry(sourcesAndDiagnostics, EqualityComparer<TOutput>.Default, stopwatch.Elapsed, inputs, entry.State))
{
nodeTable.AddEntry(sourcesAndDiagnostics, EntryState.Added, stopwatch.Elapsed, inputs, EntryState.Added);
tableBuilder.AddEntry(sourcesAndDiagnostics, EntryState.Added, stopwatch.Elapsed, inputs, EntryState.Added);
}
}
finally
Expand All @@ -81,7 +82,9 @@ public NodeStateTable<TOutput> UpdateStateTable(DriverStateTable.Builder graphSt
}
}

return nodeTable.ToImmutableAndFree();
var newTable = tableBuilder.ToImmutableAndFree();
this.LogTables(stepName, previousTable, newTable, sourceTable);
return newTable;
}

IIncrementalGeneratorNode<TOutput> IIncrementalGeneratorNode<TOutput>.WithComparer(IEqualityComparer<TOutput> comparer) => throw ExceptionUtilities.Unreachable();
Expand Down
Loading

0 comments on commit 692d17e

Please sign in to comment.