Skip to content

Commit 7202102

Browse files
committed
feat(logging): Add visual indentation to scoped operations
Improves log readability by visually nesting output for scoped operations. This is achieved by introducing an `IndentationEnricher` and managing scope depth with `AsyncLocal` within `StartIndentedScope`.
1 parent 4b391c1 commit 7202102

13 files changed

Lines changed: 65 additions & 21 deletions

src/GitVersion.Core/Core/BranchesContainingCommitFinder.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -23,7 +23,7 @@ public IEnumerable<IBranch> GetBranchesContainingCommit(ICommit commit, IEnumera
2323

2424
private IEnumerable<IBranch> InnerGetBranchesContainingCommit(ICommit commit, IEnumerable<IBranch> branches, bool onlyTrackedBranches)
2525
{
26-
using (this.logger.BeginTimedOperation($"Getting branches containing the commit '{commit.Id}'."))
26+
using (this.logger.StartIndentedScope($"Getting branches containing the commit '{commit.Id}'."))
2727
{
2828
var directBranchHasBeenFound = false;
2929
this.logger.LogInformation("Trying to find direct branches.");

src/GitVersion.Core/Core/GitPreparer.cs

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -110,7 +110,7 @@ private void CreateDynamicRepository(string? targetBranch)
110110

111111
var gitDirectory = this.repositoryInfo.DynamicGitRepositoryPath;
112112

113-
using (this.logger.BeginTimedOperation($"Creating dynamic repository at '{gitDirectory}'"))
113+
using (this.logger.StartIndentedScope($"Creating dynamic repository at '{gitDirectory}'"))
114114
{
115115
var gitVersionOptions = this.options.Value;
116116
var authentication = gitVersionOptions.AuthenticationInfo;
@@ -131,7 +131,7 @@ private void CreateDynamicRepository(string? targetBranch)
131131

132132
private void NormalizeGitDirectory(string? targetBranch, bool isDynamicRepository)
133133
{
134-
using (this.logger.BeginTimedOperation($"Normalizing git directory for branch '{targetBranch}'"))
134+
using (this.logger.StartIndentedScope($"Normalizing git directory for branch '{targetBranch}'"))
135135
{
136136
// Normalize (download branches) before using the branch
137137
NormalizeGitDirectory(this.options.Value.Settings.NoFetch, targetBranch, isDynamicRepository);
@@ -140,7 +140,7 @@ private void NormalizeGitDirectory(string? targetBranch, bool isDynamicRepositor
140140

141141
private void CloneRepository(string? repositoryUrl, string? gitDirectory, AuthenticationInfo auth)
142142
{
143-
using (this.logger.BeginTimedOperation($"Cloning repository from url '{repositoryUrl}'"))
143+
using (this.logger.StartIndentedScope($"Cloning repository from url '{repositoryUrl}'"))
144144
{
145145
this.retryAction.Execute(() => this.repository.Clone(repositoryUrl, gitDirectory, auth));
146146
}

src/GitVersion.Core/Core/MergeBaseFinder.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -24,7 +24,7 @@ internal class MergeBaseFinder(IRepositoryStore repositoryStore, ILogger logger)
2424
return mergeBase;
2525
}
2626

27-
using (this.logger.BeginTimedOperation($"Finding merge base between '{first}' and '{second}'."))
27+
using (this.logger.StartIndentedScope($"Finding merge base between '{first}' and '{second}'."))
2828
{
2929
// Other branch tip is a forward merge
3030
var commitToFindCommonBase = second.Tip;

src/GitVersion.Core/Core/RepositoryStore.cs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -174,7 +174,7 @@ public BranchCommit FindCommitBranchBranchedFrom(IBranch? branch, IGitVersionCon
174174
{
175175
branch = branch.NotNull();
176176

177-
using (this.logger.BeginTimedOperation($"Finding branch source of '{branch}'"))
177+
using (this.logger.StartIndentedScope($"Finding branch source of '{branch}'"))
178178
{
179179
if (branch.Tip == null)
180180
{
@@ -272,7 +272,7 @@ public bool IsCommitOnBranch(ICommit? baseVersionSource, IBranch branch, ICommit
272272
private List<BranchCommit> FindCommitBranchesBranchedFrom(
273273
IBranch branch, IGitVersionConfiguration configuration, IEnumerable<IBranch> excludedBranches)
274274
{
275-
using (this.logger.BeginTimedOperation($"Finding branches source of '{branch}'"))
275+
using (this.logger.StartIndentedScope($"Finding branches source of '{branch}'"))
276276
{
277277
if (branch.Tip != null) return [.. new MergeCommitFinder(this, configuration, excludedBranches, logger).FindMergeCommitsFor(branch)];
278278
this.logger.LogWarning("Branch {Branch} has no tip.", branch);

src/GitVersion.Core/Core/TaggedSemanticVersionRepository.cs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -45,7 +45,7 @@ public ILookup<ICommit, SemanticVersionWithTag> GetTaggedSemanticVersionsOfBranc
4545

4646
IEnumerable<SemanticVersionWithTag> GetElements()
4747
{
48-
using (this.logger.BeginTimedOperation($"Getting tagged semantic versions on branch '{branch.Name.Canonical}'. " +
48+
using (this.logger.StartIndentedScope($"Getting tagged semantic versions on branch '{branch.Name.Canonical}'. " +
4949
$"TagPrefix: {tagPrefix} and Format: {format}"))
5050
{
5151
var semanticVersions = GetTaggedSemanticVersions(tagPrefix, format, ignore);
@@ -87,7 +87,7 @@ public ILookup<ICommit, SemanticVersionWithTag> GetTaggedSemanticVersionsOfMerge
8787

8888
IEnumerable<(ICommit Key, SemanticVersionWithTag Value)> GetElements()
8989
{
90-
using (this.logger.BeginTimedOperation($"Getting tagged semantic versions by track merge target '{branch.Name.Canonical}'. " +
90+
using (this.logger.StartIndentedScope($"Getting tagged semantic versions by track merge target '{branch.Name.Canonical}'. " +
9191
$"TagPrefix: {tagPrefix} and Format: {format}"))
9292
{
9393
var shaHashSet = new HashSet<string>(ignore.Filter(branch.Commits.ToArray()).Select(element => element.Id.Sha));

src/GitVersion.Core/Extensions/ServiceCollectionExtensions.cs

Lines changed: 4 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -41,7 +41,8 @@ public TService GetServiceForType<TService, TType>() =>
4141

4242
private static Serilog.Core.Logger CreateLogger()
4343
{
44-
const string outputTemplate = "{Level:u4} [{Timestamp:yy-MM-dd HH:mm:ss:ff}] {Message:lj}{NewLine}{Exception}";
44+
// Output template includes {Indent} for visual nesting of scoped operations
45+
const string outputTemplate = "{Level:u4} [{Timestamp:yy-MM-dd HH:mm:ss:ff}] {Indent}{Message:lj}{NewLine}{Exception}";
4546
var formatProvider = CultureInfo.InvariantCulture;
4647
var logger = new LoggerConfiguration()
4748
// Log level is dynamically controlled by LoggingEnricher.LogLevelSwitch
@@ -50,6 +51,8 @@ private static Serilog.Core.Logger CreateLogger()
5051
.Enrich.With<LoggingEnricher>()
5152
// Add sensitive data masking for URL passwords
5253
.Enrich.With<SensitiveDataEnricher>()
54+
// Add indentation for scoped operations (BeginTimedOperation)
55+
.Enrich.With<IndentationEnricher>()
5356
// Console output with timestamp - controlled by IsConsoleEnabled flag
5457
.WriteTo.Conditional(
5558
_ => LoggingEnricher.IsConsoleEnabled,
Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,24 @@
1+
using Serilog.Core;
2+
using Serilog.Events;
3+
4+
namespace GitVersion.Logging;
5+
6+
/// <summary>
7+
/// Serilog enricher that adds indentation to log messages based on the current scope depth.
8+
/// Works with <see cref="LoggerExtensions.StartIndentedScope"/> to provide visual nesting.
9+
/// </summary>
10+
internal sealed class IndentationEnricher : ILogEventEnricher
11+
{
12+
/// <summary>
13+
/// The property name used to store the indentation.
14+
/// </summary>
15+
public const string IndentPropertyName = "Indent";
16+
17+
/// <inheritdoc />
18+
public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory)
19+
{
20+
var indentation = LoggerExtensions.GetIndentation();
21+
var indentProperty = propertyFactory.CreateProperty(IndentPropertyName, indentation);
22+
logEvent.AddPropertyIfAbsent(indentProperty);
23+
}
24+
}

src/GitVersion.Core/Logging/LoggerExtensions.cs

Lines changed: 20 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -8,28 +8,45 @@ namespace GitVersion.Logging;
88
/// </summary>
99
internal static class LoggerExtensions
1010
{
11+
private const string Indentation = "│ ";
12+
private static readonly AsyncLocal<string> CurrentIndentation = new();
13+
14+
/// <summary>
15+
/// Gets the current indentation string for log messages.
16+
/// Used by IndentationEnricher to add indentation to all log messages within a scope.
17+
/// </summary>
18+
internal static string GetIndentation() => CurrentIndentation.Value ?? string.Empty;
19+
1120
/// <summary>
1221
/// Provides extension methods for <see cref="ILogger"/> instances.
1322
/// </summary>
1423
extension(ILogger logger)
1524
{
1625
/// <summary>
1726
/// Begins a timed operation scope that logs the start and end times with duration.
27+
/// All log messages within this scope will be indented.
1828
/// </summary>
1929
/// <param name="operationDescription">A description of the operation being timed.</param>
2030
/// <returns>An <see cref="IDisposable"/> that logs the end of the operation when disposed.</returns>
21-
public IDisposable BeginTimedOperation(string operationDescription)
31+
public IDisposable StartIndentedScope(string operationDescription)
2232
{
2333
ArgumentNullException.ThrowIfNull(logger);
2434

2535
var start = TimeProvider.System.GetTimestamp();
26-
logger.LogInformation("-< Begin: {OperationDescription} >-", operationDescription);
36+
logger.LogInformation("┌─── Begin: {OperationDescription}", operationDescription);
37+
38+
// Capture current indentation and increase it for nested logs
39+
var previousIndentation = CurrentIndentation.Value ?? string.Empty;
40+
CurrentIndentation.Value = previousIndentation + Indentation;
2741

2842
return Disposable.Create(() =>
2943
{
44+
// Restore previous indentation before logging the End message
45+
CurrentIndentation.Value = previousIndentation;
46+
3047
var end = TimeProvider.System.GetTimestamp();
3148
var duration = TimeProvider.System.GetElapsedTime(start, end).TotalMilliseconds;
32-
logger.LogInformation("-< End: {OperationDescription} (Took: {Duration:N}ms) >-", operationDescription, duration);
49+
logger.LogInformation("└─── End: {OperationDescription} (Took: {Duration:N}ms)", operationDescription, duration);
3350
});
3451
}
3552

src/GitVersion.Core/VersionCalculation/Caching/GitVersionCacheProvider.cs

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -27,7 +27,7 @@ public void WriteVariablesToDiskCache(GitVersionVariables versionVariables)
2727
{
2828
var cacheKey = GetCacheKey();
2929
var cacheFileName = GetCacheFileName(cacheKey);
30-
using (this.logger.BeginTimedOperation($"Write version variables to cache file {cacheFileName}"))
30+
using (this.logger.StartIndentedScope($"Write version variables to cache file {cacheFileName}"))
3131
{
3232
try
3333
{
@@ -44,7 +44,7 @@ public void WriteVariablesToDiskCache(GitVersionVariables versionVariables)
4444
{
4545
var cacheKey = GetCacheKey();
4646
var cacheFileName = GetCacheFileName(cacheKey);
47-
using (this.logger.BeginTimedOperation($"Loading version variables from disk cache file {cacheFileName}"))
47+
using (this.logger.StartIndentedScope($"Loading version variables from disk cache file {cacheFileName}"))
4848
{
4949
if (!this.fileSystem.File.Exists(cacheFileName))
5050
{

src/GitVersion.Core/VersionCalculation/VersionCalculators/ContinuousDeliveryVersionCalculator.cs

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -9,7 +9,7 @@ internal sealed class ContinuousDeliveryVersionCalculator(
99
{
1010
public SemanticVersion Calculate(SemanticVersion semanticVersion, IBaseVersion baseVersion)
1111
{
12-
using (this.logger.BeginTimedOperation("Using continuous delivery workflow to calculate the incremented version."))
12+
using (this.logger.StartIndentedScope("Using continuous delivery workflow to calculate the incremented version."))
1313
{
1414
var preReleaseTag = semanticVersion.PreReleaseTag;
1515
if (!preReleaseTag.HasTag() || !preReleaseTag.Number.HasValue)

0 commit comments

Comments
 (0)