Skip to content

Commit 4ca0b65

Browse files
martincostellomartincostello
authored
Merge pull request #215 from gkinsman/detect-keyvaluepairs
Detect IEnumerable<KeyValuePair<string, object>> in log scopes
2 parents 6a2f6c5 + 2d38c4e commit 4ca0b65

File tree

3 files changed

+233
-21
lines changed

3 files changed

+233
-21
lines changed

‎src/Logging.XUnit/XUnitLogScope.cs‎

Lines changed: 7 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -16,20 +16,20 @@ internal sealed class XUnitLogScope
1616
/// </summary>
1717
private static readonly AsyncLocal<XUnitLogScope> _value = new AsyncLocal<XUnitLogScope>();
1818

19-
/// <summary>
20-
/// The state object for the scope.
21-
/// </summary>
22-
private readonly object _state;
23-
2419
/// <summary>
2520
/// Initializes a new instance of the <see cref="XUnitLogScope"/> class.
2621
/// </summary>
2722
/// <param name="state">The state object for the scope.</param>
2823
internal XUnitLogScope(object state)
2924
{
30-
_state = state;
25+
State = state;
3126
}
3227

28+
/// <summary>
29+
/// Gets the state object for the scope.
30+
/// </summary>
31+
public object State { get; }
32+
3333
/// <summary>
3434
/// Gets or sets the current scope.
3535
/// </summary>
@@ -46,7 +46,7 @@ internal static XUnitLogScope Current
4646

4747
/// <inheritdoc />
4848
public override string ToString()
49-
=> _state.ToString();
49+
=> State.ToString();
5050

5151
/// <summary>
5252
/// Pushes a new value into the scope.

‎src/Logging.XUnit/XUnitLogger.cs‎

Lines changed: 45 additions & 13 deletions
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,9 @@
22
// Licensed under the Apache 2.0 license. See the LICENSE file in the project root for full license information.
33

44
using System;
5+
using System.Collections;
6+
using System.Collections.Generic;
7+
using System.Linq;
58
using System.Text;
69
using Microsoft.Extensions.Logging;
710
using Xunit.Abstractions;
@@ -264,28 +267,57 @@ private static string GetLogLevelString(LogLevel logLevel)
264267
private static void GetScopeInformation(StringBuilder builder)
265268
{
266269
var current = XUnitLogScope.Current;
267-
string scopeLog;
268-
int length = builder.Length;
269270

271+
var stack = new Stack<XUnitLogScope>();
270272
while (current != null)
271273
{
272-
if (length == builder.Length)
273-
{
274-
scopeLog = $"=> {current}";
275-
}
276-
else
274+
stack.Push(current);
275+
current = current.Parent;
276+
}
277+
278+
var depth = 0;
279+
static string DepthPadding(int depth) => new string(' ', depth * 2);
280+
281+
while (stack.Count > 0)
282+
{
283+
var elem = stack.Pop();
284+
foreach (var property in StringifyScope(elem))
277285
{
278-
scopeLog = $"=> {current} ";
286+
builder.Append(MessagePadding)
287+
.Append(DepthPadding(depth))
288+
.Append("=> ")
289+
.Append(property)
290+
.AppendLine();
279291
}
280292

281-
builder.Insert(length, scopeLog);
282-
current = current.Parent;
293+
depth++;
283294
}
295+
}
284296

285-
if (builder.Length > length)
297+
/// <summary>
298+
/// Returns one or more stringified properties from the log scope.
299+
/// </summary>
300+
/// <param name="scope">The <see cref="XUnitLogScope"/> to stringify.</param>
301+
/// <returns>An enumeration of scope properties from the current scope.</returns>
302+
private static IEnumerable<string> StringifyScope(XUnitLogScope scope)
303+
{
304+
if (scope.State is IEnumerable<KeyValuePair<string, object>> pairs)
305+
{
306+
foreach (var pair in pairs)
307+
{
308+
yield return pair.Key + ": " + pair.Value;
309+
}
310+
}
311+
else if (scope.State is IEnumerable<string> entries)
312+
{
313+
foreach (var entry in entries)
314+
{
315+
yield return entry;
316+
}
317+
}
318+
else
286319
{
287-
builder.Insert(length, MessagePadding);
288-
builder.AppendLine();
320+
yield return scope.ToString();
289321
}
290322
}
291323
}

‎tests/Logging.XUnit.Tests/XUnitLoggerTests.cs‎

Lines changed: 181 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22
// Licensed under the Apache 2.0 license. See the LICENSE file in the project root for full license information.
33

44
using System;
5+
using System.Collections.Generic;
56
using Microsoft.Extensions.Logging;
67
using Moq;
78
using Shouldly;
@@ -452,7 +453,12 @@ public static void XUnitLogger_Log_Logs_Message_If_Scopes_Included_And_There_Are
452453

453454
string expected = string.Join(
454455
Environment.NewLine,
455-
new[] { "[2018-08-19 16:12:16Z] info: MyName[0]", " => _ => __ => ___ => [null]", " Message|False|False" });
456+
"[2018-08-19 16:12:16Z] info: MyName[0]",
457+
" => _",
458+
" => __",
459+
" => ___",
460+
" => {OriginalFormat}: [null]",
461+
" Message|False|False");
456462

457463
// Act
458464
using (logger.BeginScope("_"))
@@ -473,6 +479,180 @@ public static void XUnitLogger_Log_Logs_Message_If_Scopes_Included_And_There_Are
473479
mock.Verify((p) => p.WriteLine(expected), Times.Once());
474480
}
475481

482+
[Fact]
483+
public static void XUnitLogger_Log_Logs_Message_If_Scopes_Included_And_There_Is_Scope_Of_KeyValuePair()
484+
{
485+
// Arrange
486+
var mock = new Mock<ITestOutputHelper>();
487+
488+
string name = "MyName";
489+
var outputHelper = mock.Object;
490+
491+
var options = new XUnitLoggerOptions()
492+
{
493+
Filter = FilterTrue,
494+
IncludeScopes = true,
495+
};
496+
497+
var logger = new XUnitLogger(name, outputHelper, options)
498+
{
499+
Clock = StaticClock,
500+
};
501+
502+
string expected = string.Join(
503+
Environment.NewLine,
504+
"[2018-08-19 16:12:16Z] info: MyName[0]",
505+
" => ScopeKey: ScopeValue",
506+
" Message|False|False");
507+
508+
// Act
509+
using (logger.BeginScope(new[]
510+
{
511+
new KeyValuePair<string, object>("ScopeKey", "ScopeValue"),
512+
}))
513+
{
514+
logger.Log<string>(LogLevel.Information, 0, null, null, Formatter);
515+
}
516+
517+
// Assert
518+
mock.Verify((p) => p.WriteLine(expected), Times.Once());
519+
}
520+
521+
[Fact]
522+
public static void XUnitLogger_Log_Logs_Message_If_Scopes_Included_And_There_Is_Scope_Of_KeyValuePairs()
523+
{
524+
// Arrange
525+
var mock = new Mock<ITestOutputHelper>();
526+
527+
string name = "MyName";
528+
var outputHelper = mock.Object;
529+
530+
var options = new XUnitLoggerOptions()
531+
{
532+
Filter = FilterTrue,
533+
IncludeScopes = true,
534+
};
535+
536+
var logger = new XUnitLogger(name, outputHelper, options)
537+
{
538+
Clock = StaticClock,
539+
};
540+
541+
string expected = string.Join(
542+
Environment.NewLine,
543+
"[2018-08-19 16:12:16Z] info: MyName[0]",
544+
" => ScopeKeyOne: ScopeValueOne",
545+
" => ScopeKeyTwo: ScopeValueTwo",
546+
" => ScopeKeyThree: ScopeValueThree",
547+
" Message|False|False");
548+
549+
// Act
550+
using (logger.BeginScope(new[]
551+
{
552+
new KeyValuePair<string, object>("ScopeKeyOne", "ScopeValueOne"),
553+
new KeyValuePair<string, object>("ScopeKeyTwo", "ScopeValueTwo"),
554+
new KeyValuePair<string, object>("ScopeKeyThree", "ScopeValueThree"),
555+
}))
556+
{
557+
logger.Log<string>(LogLevel.Information, 0, null, null, Formatter);
558+
}
559+
560+
// Assert
561+
mock.Verify((p) => p.WriteLine(expected), Times.Once());
562+
}
563+
564+
[Fact]
565+
public static void XUnitLogger_Log_Logs_Message_If_Scopes_Included_And_There_Are_Scopes_Of_KeyValuePairs()
566+
{
567+
// Arrange
568+
var mock = new Mock<ITestOutputHelper>();
569+
570+
string name = "MyName";
571+
var outputHelper = mock.Object;
572+
573+
var options = new XUnitLoggerOptions()
574+
{
575+
Filter = FilterTrue,
576+
IncludeScopes = true,
577+
};
578+
579+
var logger = new XUnitLogger(name, outputHelper, options)
580+
{
581+
Clock = StaticClock,
582+
};
583+
584+
string expected = string.Join(
585+
Environment.NewLine,
586+
"[2018-08-19 16:12:16Z] info: MyName[0]",
587+
" => ScopeKeyOne: ScopeValueOne",
588+
" => ScopeKeyTwo: ScopeValueTwo",
589+
" => ScopeKeyThree: ScopeValueThree",
590+
" => ScopeKeyFour: ScopeValueFour",
591+
" => ScopeKeyFive: ScopeValueFive",
592+
" => ScopeKeySix: ScopeValueSix",
593+
" Message|False|False");
594+
595+
// Act
596+
using (logger.BeginScope(new[]
597+
{
598+
new KeyValuePair<string, object>("ScopeKeyOne", "ScopeValueOne"),
599+
new KeyValuePair<string, object>("ScopeKeyTwo", "ScopeValueTwo"),
600+
new KeyValuePair<string, object>("ScopeKeyThree", "ScopeValueThree"),
601+
}))
602+
{
603+
using (logger.BeginScope(new[]
604+
{
605+
new KeyValuePair<string, object>("ScopeKeyFour", "ScopeValueFour"),
606+
new KeyValuePair<string, object>("ScopeKeyFive", "ScopeValueFive"),
607+
new KeyValuePair<string, object>("ScopeKeySix", "ScopeValueSix"),
608+
}))
609+
{
610+
logger.Log<string>(LogLevel.Information, 0, null, null, Formatter);
611+
}
612+
}
613+
614+
// Assert
615+
mock.Verify((p) => p.WriteLine(expected), Times.Once());
616+
}
617+
618+
[Fact]
619+
public static void XUnitLogger_Log_Logs_Message_If_Scopes_Included_And_There_Is_Scope_Of_IEnumerable()
620+
{
621+
// Arrange
622+
var mock = new Mock<ITestOutputHelper>();
623+
624+
string name = "MyName";
625+
var outputHelper = mock.Object;
626+
627+
var options = new XUnitLoggerOptions()
628+
{
629+
Filter = FilterTrue,
630+
IncludeScopes = true,
631+
};
632+
633+
var logger = new XUnitLogger(name, outputHelper, options)
634+
{
635+
Clock = StaticClock,
636+
};
637+
638+
string expected = string.Join(
639+
Environment.NewLine,
640+
"[2018-08-19 16:12:16Z] info: MyName[0]",
641+
" => ScopeKeyOne",
642+
" => ScopeKeyTwo",
643+
" => ScopeKeyThree",
644+
" Message|False|False");
645+
646+
// Act
647+
using (logger.BeginScope(new[] { "ScopeKeyOne", "ScopeKeyTwo", "ScopeKeyThree" }))
648+
{
649+
logger.Log<string>(LogLevel.Information, 0, null, null, Formatter);
650+
}
651+
652+
// Assert
653+
mock.Verify((p) => p.WriteLine(expected), Times.Once());
654+
}
655+
476656
private static DateTimeOffset StaticClock() => new DateTimeOffset(2018, 08, 19, 17, 12, 16, TimeSpan.FromHours(1));
477657

478658
private static bool FilterTrue(string categoryName, LogLevel level) => true;

0 commit comments

Comments
 (0)