From be5ce7b7f27c215ddd50b9585f4d42223ba9b70a Mon Sep 17 00:00:00 2001 From: Roger Johansson Date: Sun, 2 Jul 2023 18:15:21 +0200 Subject: [PATCH] Startup context decorator (#2028) * add startup deadline timer * startup deadline --- src/Proto.Actor/Context/ActorContext.cs | 35 ++++++++- .../StartupDeadlineContextDecorator.cs | 76 +++++++++++++++++++ src/Proto.Actor/Props/Props.cs | 7 ++ src/Proto.Remote/BlockList.cs | 2 - 4 files changed, 117 insertions(+), 3 deletions(-) create mode 100644 src/Proto.Actor/Context/StartupDeadlineContextDecorator.cs diff --git a/src/Proto.Actor/Context/ActorContext.cs b/src/Proto.Actor/Context/ActorContext.cs index 3fed704b8c..fbed4fcaf4 100644 --- a/src/Proto.Actor/Context/ActorContext.cs +++ b/src/Proto.Actor/Context/ActorContext.cs @@ -17,6 +17,7 @@ using Proto.Future; using Proto.Mailbox; using Proto.Metrics; +using Proto.Utils; namespace Proto.Context; @@ -30,6 +31,12 @@ public class ActorContext : IMessageInvoker, IContext, ISupervisor private ActorContextExtras? _extras; private object? _messageOrEnvelope; private ContextState _state; + + private ShouldThrottle shouldThrottleStartLogs = Throttle.Create(1000,TimeSpan.FromSeconds(1), droppedLogs => + { + Logger.LogInformation("[ActorContext] Throttled {LogCount} logs", droppedLogs); + } ); + public ActorContext(ActorSystem system, Props props, PID? parent, PID self, IMailbox mailbox) { @@ -383,7 +390,7 @@ public ValueTask InvokeSystemMessageAsync(SystemMessage msg) { return msg switch { - Started s => InvokeUserMessageAsync(s), + Started s => HandleStartedAsync(), Stop _ => HandleStopAsync(), Terminated t => HandleTerminatedAsync(t), Watch w => HandleWatch(w), @@ -405,6 +412,32 @@ public ValueTask InvokeSystemMessageAsync(SystemMessage msg) } } + private ValueTask HandleStartedAsync() + { + if (_props.StartDeadline != TimeSpan.Zero) + { + return Await(); + } + + return InvokeUserMessageAsync(Started.Instance); + + async ValueTask Await() + { + var sw = Stopwatch.StartNew(); + await InvokeUserMessageAsync(Started.Instance); + sw.Stop(); + if (sw.Elapsed > _props.StartDeadline) + { + if (shouldThrottleStartLogs().IsOpen()) + { + Logger.LogCritical( + "Actor {Self} took too long to start, deadline is {Deadline}, actual start time is {ActualStart}, your system might suffer from incorrect design, please consider reaching out to https://proto.actor/docs/training/ for help", + Self, _props.StartDeadline, sw.Elapsed); + } + } + } + } + public ValueTask InvokeUserMessageAsync(object msg) { if (!System.Metrics.Enabled) diff --git a/src/Proto.Actor/Context/StartupDeadlineContextDecorator.cs b/src/Proto.Actor/Context/StartupDeadlineContextDecorator.cs new file mode 100644 index 0000000000..b6b3307fbf --- /dev/null +++ b/src/Proto.Actor/Context/StartupDeadlineContextDecorator.cs @@ -0,0 +1,76 @@ +// ----------------------------------------------------------------------- +// +// Copyright (C) 2015-2022 Asynkron AB All rights reserved +// +// ----------------------------------------------------------------------- + +using System; +using System.Threading.Tasks; +using JetBrains.Annotations; +using Microsoft.Extensions.Logging; +using Proto.Utils; + +namespace Proto.Context; + +[PublicAPI] +public static class StartupDeadlineContextExtensions +{ + /// + /// Adds a decorator for a that logs warning message if Receive takes more time than + /// specified timeout. + /// + /// + /// The timeout for Receive to complete + /// + /// + public static Props WithStartupDeadlineDecorator( + this Props props, + TimeSpan deadline, + ILogger logger + ) => + props.WithContextDecorator(ctx => new StartupDeadlineContextDecorator(ctx, deadline, logger)); +} + +/// +/// A decorator for a that logs warning message if Receive takes more time than specified +/// timeout. +/// +public class StartupDeadlineContextDecorator : ActorContextDecorator +{ + private readonly IContext _context; + private readonly TimeSpan _deadline; + private readonly ILogger _logger; + + public StartupDeadlineContextDecorator(IContext context, TimeSpan deadline, ILogger logger) : base(context) + { + _deadline = deadline; + _logger = logger; + _context = context; + } + + public override async Task Receive(MessageEnvelope envelope) + { + var (m,_,_) = MessageEnvelope.Unwrap(envelope); + if (m is Started) + { + var t = base.Receive(envelope); + + if (t.IsCompleted) + { + return; + } + + var ok = await t.WaitUpTo(_deadline).ConfigureAwait(false); + + if (!ok) + { + _logger.LogWarning("Actor {Self} deadline {Deadline}, exceeded on actor Started", + _context.Self, _deadline); + + // keep waiting, we cannot just ignore and continue as an async task might still be running and updating state of the actor + // if we return here, actor concurrency guarantees could break + await t.ConfigureAwait(false); + } + } + } +} \ No newline at end of file diff --git a/src/Proto.Actor/Props/Props.cs b/src/Proto.Actor/Props/Props.cs index 3b77ea6c3d..d7a7bb49c5 100644 --- a/src/Proto.Actor/Props/Props.cs +++ b/src/Proto.Actor/Props/Props.cs @@ -26,6 +26,11 @@ public sealed record Props /// public ProducerWithSystemAndContext Producer { get; init; } = NullProducer; + /// + /// Time to wait for the actor to start before logging warning message. + /// + public TimeSpan StartDeadline { get; init; } = TimeSpan.FromMilliseconds(100); + /// /// Delegate used to create the mailbox. /// @@ -146,6 +151,8 @@ public static PID SystemSpawner(ActorSystem system, string name, Props props, PI /// Delegate used to create the actor. /// public Props WithProducer(Producer producer) => this with { Producer = (_, _) => producer() }; + + public Props PropsWithStartDeadline(TimeSpan deadline) => this with { StartDeadline = deadline }; /// /// Delegate used to create the actor. diff --git a/src/Proto.Remote/BlockList.cs b/src/Proto.Remote/BlockList.cs index 20ab8dba0d..0cd9a46eef 100644 --- a/src/Proto.Remote/BlockList.cs +++ b/src/Proto.Remote/BlockList.cs @@ -8,7 +8,6 @@ using System.Collections.Generic; using System.Collections.Immutable; using System.Linq; -using Microsoft.Extensions.Logging; namespace Proto.Remote; @@ -22,7 +21,6 @@ public class BlockList { private readonly object _lock = new(); private readonly ActorSystem _system; - private static readonly ILogger Logger = Log.CreateLogger(); private ImmutableDictionary _blockedMembers = ImmutableDictionary.Empty;