Skip to content

Commit

Permalink
Add message-level logging context
Browse files Browse the repository at this point in the history
  • Loading branch information
@georgii-borovinskikh-sonarsource
georgii-borovinskikh-sonarsource committed Jan 6, 2025
1 parent dc2b4c0 commit 62dc2fa
Show file tree
Hide file tree
Showing 8 changed files with 154 additions and 68 deletions.
36 changes: 18 additions & 18 deletions src/Core.UnitTests/Logging/LoggerBaseTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -50,8 +50,8 @@ public void ForContext_CreatesNewLoggerWithUpdatedContextManager()
contextManager.Received(1).CreateAugmentedContext(Arg.Is<IEnumerable<string>>(x => x.SequenceEqual(new[] { "ctx" })));
newLogger.Should().NotBeSameAs(testSubject);
newLogger.WriteLine("msg");
_ = contextManager.DidNotReceive().FormatedContext;
_ = newContextManager.Received().FormatedContext;
contextManager.DidNotReceiveWithAnyArgs().GetFormattedContextOrNull(default);
newContextManager.ReceivedWithAnyArgs().GetFormattedContextOrNull(default);
writer.Received().WriteLine(Arg.Any<string>());
_ = settingsProvider.Received().IsVerboseEnabled;
}
Expand All @@ -78,8 +78,8 @@ public void ForVerboseContext_CreatesNewLoggerWithUpdatedContextManager()
contextManager.Received(1).CreateAugmentedVerboseContext(Arg.Is<IEnumerable<string>>(x => x.SequenceEqual(new[] { "ctx" })));
newLogger.Should().NotBeSameAs(testSubject);
newLogger.WriteLine("msg");
_ = contextManager.DidNotReceive().FormatedContext;
_ = newContextManager.Received().FormatedContext;
contextManager.DidNotReceiveWithAnyArgs().GetFormattedContextOrNull(default);
newContextManager.ReceivedWithAnyArgs().GetFormattedContextOrNull(default);
writer.Received().WriteLine(Arg.Any<string>());
_ = settingsProvider.Received().IsVerboseEnabled;
}
Expand Down Expand Up @@ -130,7 +130,7 @@ public void LogVerbose_ThreadIdLoggingEnabled_AddsThreadIdProperty()
public void LogVerbose_Context_AddsContextProperty()
{
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedContext.Returns("context");
contextManager.GetFormattedContextOrNull(default).Returns("context");

testSubject.LogVerbose("msg {0}", "sent");

Expand All @@ -141,7 +141,7 @@ public void LogVerbose_Context_AddsContextProperty()
public void LogVerbose_VerboseContext_AddsVerboseContextProperty()
{
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.LogVerbose("msg {0}", "sent");

Expand All @@ -153,8 +153,8 @@ public void LogVerbose_AllContextsEnabled_AddsInCorrectOrder()
{
settingsProvider.IsThreadIdEnabled.Returns(true);
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedContext.Returns("context");
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedContextOrNull(default).Returns("context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.LogVerbose("msg {0}", "sent");

Expand Down Expand Up @@ -227,7 +227,7 @@ public void WriteLineFormatted_ThreadIdLoggingEnabled_AddsThreadIdProperty()
public void WriteLine_Context_AddsContextProperty(bool isVerboseEnabled)
{
settingsProvider.IsVerboseEnabled.Returns(isVerboseEnabled);
contextManager.FormatedContext.Returns("context");
contextManager.GetFormattedContextOrNull(default).Returns("context");

testSubject.WriteLine("msg sent");

Expand All @@ -240,7 +240,7 @@ public void WriteLine_Context_AddsContextProperty(bool isVerboseEnabled)
public void WriteLineFormatted_Context_AddsContextProperty(bool isVerboseEnabled)
{
settingsProvider.IsVerboseEnabled.Returns(isVerboseEnabled);
contextManager.FormatedContext.Returns("context");
contextManager.GetFormattedContextOrNull(default).Returns("context");

testSubject.WriteLine("msg {0}", "sent");

Expand All @@ -251,7 +251,7 @@ public void WriteLineFormatted_Context_AddsContextProperty(bool isVerboseEnabled
public void WriteLine_VerboseContext_VerboseLoggingDisabled_DoesNotAddVerboseContextProperty()
{
settingsProvider.IsVerboseEnabled.Returns(false);
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.WriteLine("msg sent");

Expand All @@ -262,7 +262,7 @@ public void WriteLine_VerboseContext_VerboseLoggingDisabled_DoesNotAddVerboseCon
public void WriteLineFormatted_VerboseContext_VerboseLoggingDisabled_DoesNotAddVerboseContextProperty()
{
settingsProvider.IsVerboseEnabled.Returns(false);
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.WriteLine("msg {0}", "sent");

Expand All @@ -273,7 +273,7 @@ public void WriteLineFormatted_VerboseContext_VerboseLoggingDisabled_DoesNotAddV
public void WriteLine_VerboseContext_VerboseLoggingEnabled_AddsVerboseContextProperty()
{
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.WriteLine("msg sent");

Expand All @@ -284,7 +284,7 @@ public void WriteLine_VerboseContext_VerboseLoggingEnabled_AddsVerboseContextPro
public void WriteLineFormatted_VerboseContext_VerboseLoggingEnabled_AddsVerboseContextProperty()
{
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.WriteLine("msg {0}", "sent");

Expand All @@ -296,8 +296,8 @@ public void WriteLine_AllContextsEnabled_AddsInCorrectOrder()
{
settingsProvider.IsThreadIdEnabled.Returns(true);
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedContext.Returns("context");
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedContextOrNull(default).Returns("context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.WriteLine("msg sent");

Expand All @@ -309,8 +309,8 @@ public void WriteLineFormatted_AllContextsEnabled_AddsInCorrectOrder()
{
settingsProvider.IsThreadIdEnabled.Returns(true);
settingsProvider.IsVerboseEnabled.Returns(true);
contextManager.FormatedContext.Returns("context");
contextManager.FormatedVerboseContext.Returns("verbose context");
contextManager.GetFormattedContextOrNull(default).Returns("context");
contextManager.GetFormattedVerboseContextOrNull(default).Returns("verbose context");

testSubject.WriteLine("msg {0}", "sent");

Expand Down
80 changes: 64 additions & 16 deletions src/Core.UnitTests/Logging/LoggerContextManagerTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -39,8 +39,8 @@ public void EmptyContext()
{
var testSubject = new LoggerContextManager();

testSubject.FormatedContext.Should().BeNull();
testSubject.FormatedVerboseContext.Should().BeNull();
testSubject.GetFormattedContextOrNull(default).Should().BeNull();
testSubject.GetFormattedVerboseContextOrNull(default).Should().BeNull();
}

[TestMethod]
Expand All @@ -51,55 +51,103 @@ public void Augmented_Immutable()
var verboseContextualized = testSubject.CreateAugmentedVerboseContext(["b"]);
var doubleContextualized = testSubject.CreateAugmentedContext(["c"]).CreateAugmentedVerboseContext(["d"]);

testSubject.FormatedContext.Should().BeNull();
testSubject.FormatedVerboseContext.Should().BeNull();
contextualized.FormatedContext.Should().Be("a");
contextualized.FormatedVerboseContext.Should().BeNull();
verboseContextualized.FormatedContext.Should().BeNull();
verboseContextualized.FormatedVerboseContext.Should().Be("b");
doubleContextualized.FormatedContext.Should().Be("c");
doubleContextualized.FormatedVerboseContext.Should().Be("d");
testSubject.GetFormattedContextOrNull(default).Should().BeNull();
testSubject.GetFormattedVerboseContextOrNull(default).Should().BeNull();
contextualized.GetFormattedContextOrNull(default).Should().Be("a");
contextualized.GetFormattedVerboseContextOrNull(default).Should().BeNull();
verboseContextualized.GetFormattedContextOrNull(default).Should().BeNull();
verboseContextualized.GetFormattedVerboseContextOrNull(default).Should().Be("b");
doubleContextualized.GetFormattedContextOrNull(default).Should().Be("c");
doubleContextualized.GetFormattedVerboseContextOrNull(default).Should().Be("d");
}

[TestMethod]
public void Augmented_MultipleAtOnce_Combines() =>
new LoggerContextManager()
.CreateAugmentedContext(["a", "b"])
.FormatedContext.Should().Be("a > b");
.GetFormattedContextOrNull(default).Should().Be("a > b");

[TestMethod]
public void Augmented_MultipleInSequence_Combines() =>
new LoggerContextManager()
.CreateAugmentedContext(["a"])
.CreateAugmentedContext(["b"])
.FormatedContext.Should().Be("a > b");
.GetFormattedContextOrNull(default).Should().Be("a > b");

[TestMethod]
public void Augmented_AtOnceAndInSequence_CombinesInCorrectOrder() =>
new LoggerContextManager()
.CreateAugmentedContext(["a"])
.CreateAugmentedContext(["b", "c"])
.CreateAugmentedContext(["d"])
.FormatedContext.Should().Be("a > b > c > d");
.GetFormattedContextOrNull(default).Should().Be("a > b > c > d");

[TestMethod]
public void AugmentedVerbose_MultipleAtOnce_Combines() =>
new LoggerContextManager()
.CreateAugmentedVerboseContext(["a", "b"])
.FormatedVerboseContext.Should().Be("a > b");
.GetFormattedVerboseContextOrNull(default).Should().Be("a > b");

[TestMethod]
public void AugmentedVerbose_MultipleInSequence_Combines() =>
new LoggerContextManager()
.CreateAugmentedVerboseContext(["a"])
.CreateAugmentedVerboseContext(["b"])
.FormatedVerboseContext.Should().Be("a > b");
.GetFormattedVerboseContextOrNull(default).Should().Be("a > b");

[TestMethod]
public void AugmentedVerbose_AtOnceAndInSequence_CombinesInCorrectOrder() =>
new LoggerContextManager()
.CreateAugmentedVerboseContext(["a"])
.CreateAugmentedVerboseContext(["b", "c"])
.CreateAugmentedVerboseContext(["d"])
.FormatedVerboseContext.Should().Be("a > b > c > d");
.GetFormattedVerboseContextOrNull(default).Should().Be("a > b > c > d");

[TestMethod]
public void Get_NoContext_ReturnsNull() =>
new LoggerContextManager().GetFormattedContextOrNull(new MessageLevelContext{Context = null, VerboseContext = ["c", "d"]}).Should().BeNull();

[TestMethod]
public void Get_NoBaseContext_ReturnsMessageLevelContextOnly() =>
new LoggerContextManager().GetFormattedContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = ["c", "d"]}).Should().Be("a > b");

[TestMethod]
public void Get_MessageLevelContextNotCached()
{
var testSubject = new LoggerContextManager();
testSubject.GetFormattedContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = ["c", "d"]}).Should().Be("a > b");
testSubject.GetFormattedContextOrNull(new MessageLevelContext{Context = ["a2", "b2"], VerboseContext = ["c", "d"]}).Should().Be("a2 > b2");
}

[TestMethod]
public void Get_NoMessageLevelContext_ReturnsBaseContextOnly() =>
new LoggerContextManager().CreateAugmentedContext(["x", "y"]).GetFormattedContextOrNull(new MessageLevelContext{Context = null, VerboseContext = ["c", "d"]}).Should().Be("x > y");

[TestMethod]
public void Get_BothContexts_CombinesInOrder() =>
new LoggerContextManager().CreateAugmentedContext(["x", "y"]).GetFormattedContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = ["c", "d"]}).Should().Be("x > y > a > b");

[TestMethod]
public void GetVerbose_NoContext_ReturnsNull() =>
new LoggerContextManager().GetFormattedVerboseContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = null}).Should().BeNull();

[TestMethod]
public void GetVerbose_NoBaseContext_ReturnsMessageLevelContextOnly() =>
new LoggerContextManager().GetFormattedVerboseContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = ["c", "d"]}).Should().Be("c > d");

[TestMethod]
public void GetVerbose_MessageLevelContextNotCached()
{
var testSubject = new LoggerContextManager();
testSubject.GetFormattedVerboseContextOrNull(new MessageLevelContext { Context = ["a", "b"], VerboseContext = ["c", "d"] }).Should().Be("c > d");
testSubject.GetFormattedVerboseContextOrNull(new MessageLevelContext { Context = ["a", "b"], VerboseContext = ["c2", "d2"] }).Should().Be("c2 > d2");
}

[TestMethod]
public void GetVerbose_NoMessageLevelContext_ReturnsBaseContextOnly() =>
new LoggerContextManager().CreateAugmentedVerboseContext(["v", "w"]).GetFormattedVerboseContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = null}).Should().Be("v > w");

[TestMethod]
public void GetVerbose_BothContexts_CombinesInOrder() =>
new LoggerContextManager().CreateAugmentedVerboseContext(["v", "w"]).GetFormattedVerboseContextOrNull(new MessageLevelContext{Context = ["a", "b"], VerboseContext = ["c", "d"]}).Should().Be("v > w > c > d");
}
2 changes: 1 addition & 1 deletion src/Core.UnitTests/Logging/LoggerFactoryTests.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -56,7 +56,7 @@ public void Create_ReturnsLoggerConfiguredWithCorrectDependencies()

logger.Should().NotBeNull();
logger.WriteLine("msg");
_ = logContextManager.Received().FormatedContext;
logContextManager.Received().GetFormattedContextOrNull(default);
_ = logVerbosityIndicator.Received().IsVerboseEnabled;
logWriter.Received().WriteLine(Arg.Is<string>(x => x.Contains("msg")));
}
Expand Down
36 changes: 20 additions & 16 deletions src/Core/Logging/ILogger.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -18,26 +18,30 @@
* Inc., 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301, USA.
*/

using System.ComponentModel.Composition;
namespace SonarLint.VisualStudio.Core;

namespace SonarLint.VisualStudio.Core
public interface ILogger
{
public interface ILogger
{
/// <summary>
/// Logs a message and appends a new line.
/// </summary>
void WriteLine(string message);
/// <summary>
/// Logs a message and appends a new line.
/// </summary>
void WriteLine(string message);
void WriteLine(string messageFormat, params object[] args);
void WriteLine(MessageLevelContext context, string messageFormat, params object[] args);

void WriteLine(string messageFormat, params object[] args);
/// <summary>
/// Logs a message and appends a new line if logging is set to verbose. Otherwise does nothing.
/// </summary>
void LogVerbose(string messageFormat, params object[] args);
void LogVerbose(MessageLevelContext context, string messageFormat, params object[] args);

/// <summary>
/// Logs a message and appends a new line if logging is set to verbose. Otherwise does nothing.
/// </summary>
void LogVerbose(string messageFormat, params object[] args);
ILogger ForContext(params string[] context);

ILogger ForContext(params string[] context);
ILogger ForVerboseContext(params string[] context);
}

ILogger ForVerboseContext(params string[] context);
}
public readonly struct MessageLevelContext
{
public IReadOnlyCollection<string> Context { get; init; }
public IReadOnlyCollection<string> VerboseContext { get; init; }
}
4 changes: 2 additions & 2 deletions src/Core/Logging/ILoggerContextManager.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,8 +22,8 @@ namespace SonarLint.VisualStudio.Core.Logging;

public interface ILoggerContextManager
{
public string FormatedContext { get; }
public string FormatedVerboseContext { get; }
public string GetFormattedContextOrNull(MessageLevelContext messageLevelContext);
public string GetFormattedVerboseContextOrNull(MessageLevelContext messageLevelContext);

ILoggerContextManager CreateAugmentedContext(IEnumerable<string> additionalContexts);

Expand Down
31 changes: 19 additions & 12 deletions src/Core/Logging/LoggerBase.cs
View file
Original file line number Diff line number Diff line change
Expand Up @@ -28,6 +28,7 @@ internal class LoggerBase(
ILoggerWriter writer,
ILoggerSettingsProvider settingsProvider) : ILogger
{

public ILogger ForContext(params string[] context) =>
new LoggerBase(
contextManager.CreateAugmentedContext(context.Where(x => !string.IsNullOrEmpty(x))),
Expand All @@ -44,43 +45,49 @@ public void WriteLine(string message) =>
writer.WriteLine(CreateStandardLogPrefix().Append(message).ToString());

public void WriteLine(string messageFormat, params object[] args) =>
writer.WriteLine(CreateStandardLogPrefix().AppendFormat(CultureInfo.CurrentCulture, messageFormat, args).ToString());
WriteLine(default, messageFormat, args);

public void WriteLine(MessageLevelContext context, string messageFormat, params object[] args) =>
writer.WriteLine(CreateStandardLogPrefix(context).AppendFormat(CultureInfo.CurrentCulture, messageFormat, args).ToString());

public void LogVerbose(string messageFormat, params object[] args) =>
LogVerbose(default, messageFormat, args);

public void LogVerbose(string messageFormat, params object[] args)
public void LogVerbose(MessageLevelContext context, string messageFormat, params object[] args)
{
if (!settingsProvider.IsVerboseEnabled)
{
return;
}

var debugLogPrefix = CreateDebugLogPrefix();
var debugLogPrefix = CreateDebugLogPrefix(context);
var logLine = args.Length > 0
? debugLogPrefix.AppendFormat(CultureInfo.CurrentCulture, messageFormat, args)
: debugLogPrefix.Append(messageFormat);
writer.WriteLine(logLine.ToString());
}

private StringBuilder CreateStandardLogPrefix() =>
AddStandardProperties(new StringBuilder());
private StringBuilder CreateStandardLogPrefix(MessageLevelContext context = default) =>
AddStandardProperties(new StringBuilder(), context);

private StringBuilder CreateDebugLogPrefix() =>
AddStandardProperties(AppendProperty(new StringBuilder(), "DEBUG"));
private StringBuilder CreateDebugLogPrefix(MessageLevelContext context = default) =>
AddStandardProperties(AppendProperty(new StringBuilder(), "DEBUG"), context);

private StringBuilder AddStandardProperties(StringBuilder builder)
private StringBuilder AddStandardProperties(StringBuilder builder, MessageLevelContext context)
{
if (settingsProvider.IsThreadIdEnabled)
{
AppendPropertyFormat(builder, "ThreadId {0}", Thread.CurrentThread.ManagedThreadId);
}

if (!string.IsNullOrEmpty(contextManager.FormatedContext))
if (contextManager.GetFormattedContextOrNull(context) is var formatedContext && !string.IsNullOrEmpty(formatedContext))
{
AppendProperty(builder, contextManager.FormatedContext);
AppendProperty(builder, formatedContext);
}

if (settingsProvider.IsVerboseEnabled && !string.IsNullOrEmpty(contextManager.FormatedVerboseContext))
if (settingsProvider.IsVerboseEnabled && contextManager.GetFormattedVerboseContextOrNull(context) is var formattedVerboseContext && !string.IsNullOrEmpty(formattedVerboseContext))
{
AppendProperty(builder, contextManager.FormatedVerboseContext);
AppendProperty(builder, formattedVerboseContext);
}

return builder;
Expand Down
Loading

0 comments on commit 62dc2fa

Please sign in to comment.