Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Akka.Event: restore missing log data #7256

Merged
merged 16 commits into from
Jun 14, 2024
Merged
Show file tree
Hide file tree
Changes from 12 commits
Commits
File filter

Filter by extension

Filter by extension


Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
9 changes: 9 additions & 0 deletions build-system/azure-pipeline.template.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -55,10 +55,19 @@ jobs:
contents: '**'
targetFolder: $(Build.ArtifactStagingDirectory)
continueOnError: boolean # 'true' if future steps should run even if this step fails; defaults to 'false'

- task: CopyFiles@2
inputs:
SourceFolder: '$(Build.SourcesDirectory)'
Contents: '**/*.received.*'
TargetFolder: '$(Build.ArtifactStagingDirectory)/verify'
displayName: 'Copy .received. files to artifact staging directory'

- task: PublishBuildArtifacts@1
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Add .received files from Verify as a build output whenever we have a test failure.

inputs:
pathtoPublish: '$(Build.ArtifactStagingDirectory)'
artifactName: ${{ parameters.artifactName }}

- script: 'echo 1>&2'
failOnStderr: true
displayName: 'If above is partially succeeded, then fail'
Expand Down
2 changes: 2 additions & 0 deletions build-system/pr-validation.yaml
Original file line number Diff line number Diff line change
Expand Up @@ -80,10 +80,12 @@ jobs:
contents: "*"
targetFolder: $(Build.ArtifactStagingDirectory)
continueOnError: boolean # 'true' if future steps should run even if this step fails; defaults to 'false'

- task: PublishBuildArtifacts@1
inputs:
pathtoPublish: $(Build.ArtifactStagingDirectory)
artifactName: "incrementalistOutput-$(Build.BuildId)"

- script: "echo 1>&2"
failOnStderr: true
displayName: "If above is partially succeeded, then fail"
Expand Down
2 changes: 1 addition & 1 deletion build.fsx
Original file line number Diff line number Diff line change
Expand Up @@ -55,7 +55,7 @@ let runIncrementally = hasBuildParam "incremental"
let incrementalistReport = output @@ "incrementalist.txt"

// Configuration values for tests
let testNetFrameworkVersion = "net471"
let testNetFrameworkVersion = "net48"
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Upgraded to .NET 4.8 so we could use newer versions of Verify, which had DateTime scrubbing. I ended up not needing it but I don't think it hurts anything given that this only affects the test suite.

let testNetVersion = "net8.0"

Target "Clean" (fun _ ->
Expand Down
2 changes: 1 addition & 1 deletion src/Directory.Build.props
Original file line number Diff line number Diff line change
Expand Up @@ -29,7 +29,7 @@
<BenchmarkDotNetVersion>0.13.12</BenchmarkDotNetVersion>
<NetTestVersion>net8.0</NetTestVersion>
<FsharpVersion>6.0.5</FsharpVersion>
<NetFrameworkTestVersion>net471</NetFrameworkTestVersion>
<NetFrameworkTestVersion>net48</NetFrameworkTestVersion>
<NetStandardLibVersion>netstandard2.0</NetStandardLibVersion>
<NetLibVersion>net6.0</NetLibVersion>
<FluentAssertionsVersion>5.10.3</FluentAssertionsVersion>
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -204,7 +204,7 @@ public void Hyperion_serializer_should_read_cross_platform_package_name_override
Assert.NotEmpty(overrides);
var @override = overrides[0];

#if NET471
#if NET48
Assert.Equal("acc", @override("abc"));
Assert.Equal("bcd", @override("bcd"));
#elif NETCOREAPP3_1
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -225,7 +225,7 @@ public static IEnumerable<object[]> DangerousObjectFactory()
yield return new object[]{ Serialize(WindowsIdentity.GetAnonymous()), typeof(WindowsIdentity) };
yield return new object[]{ Serialize(new WindowsPrincipal(WindowsIdentity.GetAnonymous())), typeof(WindowsPrincipal)};
}
#if NET471
#if NET48
yield return new object[]{ Serialize(new Process()), typeof(Process)};
#endif
yield return new object[]{ Serialize(new ClaimsIdentity()), typeof(ClaimsIdentity)};
Expand Down
4 changes: 2 additions & 2 deletions src/core/Akka.API.Tests/Akka.API.Tests.csproj
Original file line number Diff line number Diff line change
Expand Up @@ -30,8 +30,8 @@
<PackageReference Include="xunit" Version="$(XunitVersion)" />
<PackageReference Include="xunit.runner.visualstudio" Version="$(XunitVersion)" />
<PackageReference Include="PublicApiGenerator" Version="9.3.0" />
<PackageReference Include="Verify.Xunit" Version="20.8.2" />
<PackageReference Include="Verify.DiffPlex" Version="2.2.1" />
<PackageReference Include="Verify.Xunit" Version="25.0.2" />
<PackageReference Include="Verify.DiffPlex" Version="3.0.0" />
</ItemGroup>

</Project>
4 changes: 0 additions & 4 deletions src/core/Akka.API.Tests/CoreAPISpec.cs
Original file line number Diff line number Diff line change
Expand Up @@ -5,9 +5,6 @@
// </copyright>
//-----------------------------------------------------------------------

using System;
using System.IO;
using System.Reflection;
using System.Threading.Tasks;
using Akka.Actor;
using Akka.Cluster;
Expand All @@ -28,7 +25,6 @@

namespace Akka.API.Tests
{
[UsesVerify]
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Obsolete in the latest version of Verify

public class CoreAPISpec
{
static Task VerifyAssembly<T>()
Expand Down
98 changes: 98 additions & 0 deletions src/core/Akka.API.Tests/LogFormatSpec.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,98 @@
// -----------------------------------------------------------------------
// <copyright file="LogFormatSpec.cs" company="Akka.NET Project">
// Copyright (C) 2009-2024 Lightbend Inc. <http://www.lightbend.com>
// Copyright (C) 2013-2024 .NET Foundation <https://github.com/akkadotnet/akka.net>
// </copyright>
// -----------------------------------------------------------------------

using System;
using System.IO;
using System.Linq;
using System.Text.RegularExpressions;
using System.Threading.Tasks;
using Akka.Event;
using VerifyXunit;
using Xunit;

namespace Akka.API.Tests;

/// <summary>
/// Regression test for https://github.com/akkadotnet/akka.net/issues/7255
///
/// Need to assert that the default log format is still working as expected.
/// </summary>
public sealed class DefaultLogFormatSpec : TestKit.Xunit2.TestKit
{
public DefaultLogFormatSpec() : base("akka.loglevel = DEBUG")
{
}

public class OutputRedirector : IDisposable
{
private readonly TextWriter _originalOutput;
private readonly StreamWriter _writer;

public OutputRedirector(string filePath)
{
_originalOutput = Console.Out;
_writer = new StreamWriter(filePath) { AutoFlush = true };
Console.SetOut(_writer);
}

public void Dispose()
{
Console.SetOut(_originalOutput);
_writer.Dispose();
}
}

[Fact]
public async Task ShouldUseDefaultLogFormat()
{
// arrange
var filePath = Path.GetTempFileName();
var probe = CreateTestProbe();
Sys.EventStream.Subscribe(probe.Ref, typeof(LogEvent));

// act
using (new OutputRedirector(filePath))
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

The error in #7255 was caused not by the formatter on the message changing, but by the fact that we started calling .ToString on the wrong thing in v1.5.21. This test is designed to capture STDOUT and verify against that, so either type of mistake will be caught in the future should it occur again.

{
Sys.Log.Debug("This is a test {0} {1}", 1, "cheese");
Sys.Log.Info("This is a test {0}", 1);
Sys.Log.Warning("This is a test {0}", 1);
Sys.Log.Error("This is a test {0}", 1);

// force all logs to be received
await probe.ReceiveNAsync(4).ToListAsync();
}

// assert
// ReSharper disable once MethodHasAsyncOverload
var text = File.ReadAllText(filePath);

// need to sanitize the thread id
text = SanitizeDateTime(text);
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Scrub thread ids and datetimes, since these are unstable run-per-run even if everything is working normally.

text = SanitizeThreadNumber(text);

await Verifier.Verify(text);
}

static string SanitizeThreadNumber(string log)
{
string pattern = @"(\[Thread )\d+(\])";
string replacement = "[Thread 0001]";
string result = Regex.Replace(log, pattern, replacement);
return result;
}

static string SanitizeDateTime(string logs, string replacement = "DateTime")
{
// Regular expression to match the datetime
string pattern = @"\[\d{2}/\d{2}/\d{4} \d{2}:\d{2}:\d{2}\.\d{3}Z\]";

// Replace all occurrences of the datetime with the constant value
string result = Regex.Replace(logs, pattern, $"[{replacement}]", RegexOptions.Multiline);

return result;
}
}
1 change: 1 addition & 0 deletions src/core/Akka.API.Tests/ModuleInit.cs
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ public static class ModuleInit
[ModuleInitializer]
public static void Init()
{
VerifyDiffPlex.Initialize();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Force DiffPlex to start once at boot.

VerifierSettings.ScrubLinesContaining("[assembly: ReleaseDateAttribute(");
Verifier.UseProjectRelativeDirectory("verify");
VerifierSettings.UniqueForRuntime();
Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
[DEBUG][DateTime][Thread 0001][ActorSystem(test)] This is a test 1 cheese
[INFO][DateTime][Thread 0001][ActorSystem(test)] This is a test 1
[WARNING][DateTime][Thread 0001][ActorSystem(test)] This is a test 1
[ERROR][DateTime][Thread 0001][ActorSystem(test)] This is a test 1
Original file line number Diff line number Diff line change
@@ -0,0 +1,4 @@
[DEBUG][DateTime][Thread 0001][ActorSystem(test)] This is a test 1 cheese
[INFO][DateTime][Thread 0001][ActorSystem(test)] This is a test 1
[WARNING][DateTime][Thread 0001][ActorSystem(test)] This is a test 1
[ERROR][DateTime][Thread 0001][ActorSystem(test)] This is a test 1
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No idea why the stack trace logs don't show up on .NET Framework, but they do on .NET 8

2 changes: 2 additions & 0 deletions src/core/Akka.Docs.Tests/Streams/RestartDocTests.cs
Original file line number Diff line number Diff line change
Expand Up @@ -16,6 +16,7 @@

namespace DocsExamples.Streams
{
#if NETCOREAPP
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Caused a grumble on Linux, which caused DocFx validation to fail

public class RestartDocTests : TestKit
{
private ActorMaterializer Materializer { get; }
Expand Down Expand Up @@ -65,4 +66,5 @@ public void Restart_stages_should_demonstrate_a_restart_with_backoff_source()
#endregion
}
}
#endif
}
4 changes: 2 additions & 2 deletions src/core/Akka/Event/LogFilter.cs
Original file line number Diff line number Diff line change
Expand Up @@ -191,7 +191,7 @@ public virtual bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMes
else
{
// allocate the message just once
var nullCheck = evt.Message.ToString();
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

These are the fixes here - we were only looking at the message, not the entire log string.

var nullCheck = evt.ToString();

if (nullCheck == null)
return false; // no message to filter
Expand Down Expand Up @@ -225,7 +225,7 @@ private EmptyLogFilterEvaluator() : base(Array.Empty<LogFilterBase>())

public override bool ShouldTryKeepMessage(LogEvent evt, out string expandedLogMessage)
{
expandedLogMessage = evt.Message.ToString()!;
Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is the fix for most use cases, when users don't have any log filtering enabled.

expandedLogMessage = evt.ToString()!;
return true;
}
}
Expand Down
Loading