From ad0c00c419a1c5e2e4a558cc9563a756e222f148 Mon Sep 17 00:00:00 2001 From: Ismael Hamed <1279846+ismaelhamed@users.noreply.github.com> Date: Tue, 7 Jul 2020 19:54:24 +0200 Subject: [PATCH] Cluster event listener that logs all events (#4502) --- .../clustering/cluster-configuration.md | 14 ++ .../CoreAPISpec.ApproveCluster.approved.txt | 1 + src/core/Akka.Cluster.Tests/ClusterLogSpec.cs | 126 ++++++++++++++++++ src/core/Akka.Cluster/ClusterDaemon.cs | 12 ++ src/core/Akka.Cluster/ClusterReadView.cs | 8 +- src/core/Akka.Cluster/ClusterSettings.cs | 8 +- .../Akka.Cluster/Configuration/Cluster.conf | 4 + 7 files changed, 171 insertions(+), 2 deletions(-) create mode 100644 src/core/Akka.Cluster.Tests/ClusterLogSpec.cs diff --git a/docs/articles/clustering/cluster-configuration.md b/docs/articles/clustering/cluster-configuration.md index db4505448..abd7bc15e 100644 --- a/docs/articles/clustering/cluster-configuration.md +++ b/docs/articles/clustering/cluster-configuration.md @@ -33,6 +33,20 @@ akka { } ``` +### Cluster Info Logging + +You can silence the logging of cluster events at info level with configuration property: + +``` +akka.cluster.log-info = off +``` + +You can enable verbose logging of cluster events at info level, e.g. for temporary troubleshooting, with configuration property: + +``` +akka.cluster.log-info-verbose = on +``` + ## Specifying Minimum Cluster Sizes One feature of Akka.Cluster that can be useful in a number of scenarios is the ability to specify a minimum cluster size, i.e. "this cluster must have at least 3 nodes present before it can be considered 'up'." diff --git a/src/core/Akka.API.Tests/CoreAPISpec.ApproveCluster.approved.txt b/src/core/Akka.API.Tests/CoreAPISpec.ApproveCluster.approved.txt index 697488c73..d18e1772b 100644 --- a/src/core/Akka.API.Tests/CoreAPISpec.ApproveCluster.approved.txt +++ b/src/core/Akka.API.Tests/CoreAPISpec.ApproveCluster.approved.txt @@ -197,6 +197,7 @@ namespace Akka.Cluster public System.TimeSpan HeartbeatInterval { get; } public System.TimeSpan LeaderActionsInterval { get; } public bool LogInfo { get; } + public bool LogInfoVerbose { get; } public int MinNrOfMembers { get; } public System.Collections.Immutable.ImmutableDictionary MinNrOfMembersOfRole { get; } public int MonitoredByNrOfMembers { get; } diff --git a/src/core/Akka.Cluster.Tests/ClusterLogSpec.cs b/src/core/Akka.Cluster.Tests/ClusterLogSpec.cs new file mode 100644 index 000000000..16a61904a --- /dev/null +++ b/src/core/Akka.Cluster.Tests/ClusterLogSpec.cs @@ -0,0 +1,126 @@ +//----------------------------------------------------------------------- +// +// Copyright (C) 2009-2020 Lightbend Inc. +// Copyright (C) 2013-2020 .NET Foundation +// +//----------------------------------------------------------------------- + +using System.Linq; +using Akka.Actor; +using Akka.Configuration; +using Akka.TestKit; +using Akka.Util.Internal; +using Xunit; +using Xunit.Abstractions; +using Xunit.Sdk; + +namespace Akka.Cluster.Tests +{ + public abstract class ClusterLogSpec : AkkaSpec + { + public const string Config = @" + akka.cluster { + auto-down-unreachable-after = 0s + publish-stats-interval = 0s # always, when it happens + run-coordinated-shutdown-when-down = off + } + akka.actor.provider = ""cluster"" + akka.remote.log-remote-lifecycle-events = off + akka.remote.dot-netty.tcp.port = 0 + akka.loglevel = ""INFO"" + akka.loggers = [""Akka.TestKit.TestEventListener, Akka.TestKit""]"; + + protected const string upLogMessage = " - event MemberUp"; + protected const string downLogMessage = " - event MemberDowned"; + protected readonly Address _selfAddress; + protected readonly Cluster _cluster; + + internal ClusterReadView ClusterView { get { return _cluster.ReadView; } } + + protected ClusterLogSpec(ITestOutputHelper output, Config config = null) + : base(config ?? Config, output) + { + _selfAddress = Sys.AsInstanceOf().Provider.DefaultAddress; + _cluster = Cluster.Get(Sys); + } + + protected void AwaitUp() + { + AwaitCondition(() => ClusterView.IsSingletonCluster); + ClusterView.Self.Address.ShouldBe(_selfAddress); + ClusterView.Members.Select(m => m.Address).ShouldBe(new Address[] { _selfAddress }); + AwaitAssert(() => ClusterView.Status.ShouldBe(MemberStatus.Up)); + } + /// + /// The expected log info pattern to intercept after a . + /// + protected void Join(string expected) + { + EventFilter + .Info(contains: expected) + .ExpectOne(() => _cluster.Join(_selfAddress)); + } + + /// + /// The expected log info pattern to intercept after a . + /// + /// + protected void Down(string expected) + { + EventFilter + .Info(contains: expected) + .ExpectOne(() => _cluster.Down(_selfAddress)); + } + } + + public class ClusterLogDefaultSpec : ClusterLogSpec + { + public ClusterLogDefaultSpec(ITestOutputHelper output) + : base(output) + { } + + [Fact] + public void A_cluster_must_log_a_message_when_becoming_and_stopping_being_a_leader() + { + _cluster.Settings.LogInfo.ShouldBeTrue(); + _cluster.Settings.LogInfoVerbose.ShouldBeFalse(); + Join("is the new leader"); + AwaitUp(); + Down("is no longer leader"); + } + } + + public class ClusterLogVerboseDefaultSpec : ClusterLogSpec + { + public ClusterLogVerboseDefaultSpec(ITestOutputHelper output) + : base(output) + { } + + [Fact] + public void A_cluster_must_not_log_verbose_cluster_events_by_default() + { + _cluster.Settings.LogInfoVerbose.ShouldBeFalse(); + Intercept(() => Join(upLogMessage)); + AwaitUp(); + Intercept(() => Down(downLogMessage)); + } + } + + public class ClusterLogVerboseEnabledSpec : ClusterLogSpec + { + public ClusterLogVerboseEnabledSpec(ITestOutputHelper output) + : base(output, ConfigurationFactory + .ParseString("akka.cluster.log-info-verbose = on") + .WithFallback(ConfigurationFactory.ParseString(Config))) + { } + + [Fact] + public void A_cluster_must_log_verbose_cluster_events_when_log_info_verbose_is_on() + { + _cluster.Settings.LogInfoVerbose.ShouldBeTrue(); + Join(upLogMessage); + AwaitUp(); + Down(downLogMessage); + } + } +} diff --git a/src/core/Akka.Cluster/ClusterDaemon.cs b/src/core/Akka.Cluster/ClusterDaemon.cs index 929e9ca31..ff549e616 100644 --- a/src/core/Akka.Cluster/ClusterDaemon.cs +++ b/src/core/Akka.Cluster/ClusterDaemon.cs @@ -993,6 +993,8 @@ namespace Akka.Cluster return node.Address + "-" + node.Uid; } + private bool _isCurrentlyLeader; + // note that self is not initially member, // and the SendGossip is not versioned for this 'Node' yet private Gossip _latestGossip = Gossip.Empty; @@ -2125,6 +2127,11 @@ namespace Akka.Cluster if (_latestGossip.IsLeader(SelfUniqueAddress, SelfUniqueAddress)) { // only run the leader actions if we are the LEADER + if (!_isCurrentlyLeader) + { + _cluster.LogInfo("is the new leader among reachable nodes (more leaders may exist)"); + _isCurrentlyLeader = true; + } const int firstNotice = 20; const int periodicNotice = 60; if (_latestGossip.Convergence(SelfUniqueAddress, _exitingConfirmed)) @@ -2154,6 +2161,11 @@ namespace Akka.Cluster } } } + else if (_isCurrentlyLeader) + { + _cluster.LogInfo("is no longer leader"); + _isCurrentlyLeader = false; + } CleanupExitingConfirmed(); ShutdownSelfWhenDown(); diff --git a/src/core/Akka.Cluster/ClusterReadView.cs b/src/core/Akka.Cluster/ClusterReadView.cs index 5bf53a772..7c3671fdf 100644 --- a/src/core/Akka.Cluster/ClusterReadView.cs +++ b/src/core/Akka.Cluster/ClusterReadView.cs @@ -153,6 +153,12 @@ namespace Akka.Cluster readView._latestStats = stats; }) .With(_ => { }); + + // once captured, optional verbose logging of event + if (!(clusterDomainEvent is ClusterEvent.SeenChanged) && _cluster.Settings.LogInfoVerbose) + { + _cluster.LogInfo("event {0}", clusterDomainEvent.GetType().Name); + } }); Receive(state => @@ -164,7 +170,7 @@ namespace Akka.Cluster protected override void PreStart() { //subscribe to all cluster domain events - _cluster.Subscribe(Self, new []{ typeof(ClusterEvent.IClusterDomainEvent) }); + _cluster.Subscribe(Self, new[] { typeof(ClusterEvent.IClusterDomainEvent) }); } protected override void PostStop() diff --git a/src/core/Akka.Cluster/ClusterSettings.cs b/src/core/Akka.Cluster/ClusterSettings.cs index 57aafcf27..870012286 100644 --- a/src/core/Akka.Cluster/ClusterSettings.cs +++ b/src/core/Akka.Cluster/ClusterSettings.cs @@ -35,7 +35,8 @@ namespace Akka.Cluster if (clusterConfig.IsNullOrEmpty()) throw ConfigurationException.NullOrEmptyConfig("akka.cluster"); - LogInfo = clusterConfig.GetBoolean("log-info", false); + LogInfoVerbose = clusterConfig.GetBoolean("log-info-verbose", false); + LogInfo = LogInfoVerbose || clusterConfig.GetBoolean("log-info", false); _failureDetectorConfig = clusterConfig.GetConfig("failure-detector"); FailureDetectorImplementationClass = _failureDetectorConfig.GetString("implementation-class", null); HeartbeatInterval = _failureDetectorConfig.GetTimeSpan("heartbeat-interval", null); @@ -93,6 +94,11 @@ namespace Akka.Cluster AllowWeaklyUpMembers = clusterConfig.GetBoolean("allow-weakly-up-members", false); } + /// + /// Determine whether to log verbose messages for temporary troubleshooting. + /// + public bool LogInfoVerbose { get; } + /// /// Determine whether to log messages. /// diff --git a/src/core/Akka.Cluster/Configuration/Cluster.conf b/src/core/Akka.Cluster/Configuration/Cluster.conf index 15fb03332..8f24cef4f 100644 --- a/src/core/Akka.Cluster/Configuration/Cluster.conf +++ b/src/core/Akka.Cluster/Configuration/Cluster.conf @@ -102,6 +102,10 @@ akka { # Enable/disable info level logging of cluster events log-info = on + # Enable/disable verbose info-level logging of cluster events + # for temporary troubleshooting. Defaults to 'off'. + log-info-verbose = off + # how long should the node wait before starting the periodic tasks # maintenance tasks? periodic-tasks-initial-delay = 1s