Running 1st and 2nd level retry forever not calling IErrorHandler

527 views Asked by At

The code below enables 2nd level retry and IErrorHandler.

The problem is that IErrorHandler is never invoked.

    var activator = new BuiltinHandlerActivator();

   activator.Register((bus, mc) => new Handler(mc, bus));
        Configure.With(activator)
           .Transport(t => t.UseAzureServiceBus(Consts.ServiceBusConnectionString, Consts.Subscriber1))
           .Options(o =>
                    {

              o.SimpleRetryStrategy(maxDeliveryAttempts: 2,
                                              secondLevelRetriesEnabled: true,
                                              errorQueueAddress: "poison");

             o.Decorate<IErrorHandler>(c => new MyErrorHandler(c.Get<IErrorHandler>()));


                    }).Start();

Handler

class Handler : IHandleMessages<string>,
          IHandleMessages<IFailed<object>>
    {
        readonly IBus _bus;
        readonly IMessageContext _messageContext;
        public Handler(IMessageContext messageContext, IBus bus)
        {
            _messageContext = messageContext;
            _bus = bus;
        }

        public async Task Handle(string message)
        {
            Console.WriteLine("Handle(string message): {0}", message);
            throw new Exception("Handle(string message)");
        }

        public async Task Handle(IFailed<Object> message)
        {
            Console.WriteLine("Handle(IFailed<Object> message): {0}", message);
            await _bus.Advanced.TransportMessage.Defer(TimeSpan.FromSeconds(2));

        }

    }

Specifically, below is the sequence of running 1st and 2nd level retry:

Calling sequences based on maxDeliveryAttempts is 2:

1 calling Handle(string message), throw exception within Handle(string message)

2 calling Handle(string message) throw exception within Handle(string message)

3 calling Handle(IFailed message)

4 calling Handle(IFailed message)

5 calling Handle(string message), throw exception within Handle(string message)

6 calling Handle(IFailed message)

Repeat 5 and 6 forever

Question A:

Why is IErrorHandler not invoked?

How to invoke IErrorHandler after calling Handle(IFailed message) 2 times based on maxDeliveryAttempts of 2.

That is:

Calling sequences based on maxDeliveryAttempts is 2:

1 calling Handle(string message), throw exception within Handle(string message)

2 calling Handle(string message) throw exception within Handle(string message)

3 calling Handle(IFailed message)

4 calling Handle(IFailed message)

5 calling IErrorHandler

6 Move to next message

Update

The same issue occurs on IHandleMessages<IFailed<string>>.

Update 2

Error below:

 Severity   Code    Description Project File    Line    Suppression State
 Error      Unable to locate repository containing directory
 'C:\ReBus\Rebus-master\Rebus'. Rebus   C:\Users\username\.nuget\packages\microsoft.build.tasks.git\1.0.0-beta-63127-02\build\Microsoft.Build.Tasks.Git.targets 20

Clicking the error above shows this in VS

<Microsoft.Build.Tasks.Git.LocateRepository Directory="$(MSBuildProjectDirectory)" >
  <Output TaskParameter="Id" PropertyName="_GitRepositoryRoot" />
</Microsoft.Build.Tasks.Git.LocateRepository>

Update 3 Result below of running this https://github.com/rebus-org/Rebus/blob/master/Rebus.Tests/Bugs/VerifyThisParticularThingAboutSecondLevelRetries.cs

[INF] Rebus.Threading.TaskParallelLibrary.TplAsyncTask (Worker#3): Starting periodic task "CleanupTrackedErrors" with interval 00:00:10
[INF] Rebus.Threading.TaskParallelLibrary.TplAsyncTask (Worker#3): Starting periodic task "DueMessagesSender" with interval 00:00:01
[INF] Rebus.Bus.RebusBus (Worker#3): Bus "Rebus 1" setting number of workers to 1
[DBG] Rebus.Bus.RebusBus (Worker#3): Adding worker "Rebus 1 worker 1"
[INF] Rebus.Bus.RebusBus (Worker#3): Bus "Rebus 1" started
[DBG] Rebus.Workers.ThreadPoolBased.ThreadPoolWorker (Rebus 1 worker 1): Starting (threadpool-based) worker "Rebus 1 worker 1"
[DBG] Rebus.Pipeline.Send.SendOutgoingMessageStep (Worker#3): Sending "HEJ MED DIG" -> "whatever"
Handle(string message): HEJ MED DIG
[WRN] Rebus.Retry.ErrorTracking.InMemErrorTracker (Rebus 1 worker 1): Unhandled exception 1 while handling message with ID "667c8cfd-5ce5-46a6-9394-32d1386ef7de"
System.Exception: Handle(string message)
   at Rebus.Tests.Bugs.VerifyThisParticularThingAboutSecondLevelRetries.Handler.<Handle>d__4.MoveNext() in C:\ReBus\Rebus.Tests\Bugs\VerifyThisParticularThingAboutSecondLevelRetries.cs:line 81
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.HandlerInvoker`1.<Invoke>d__14.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\HandlerInvoker.cs:line 154
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.DispatchIncomingMessageStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\DispatchIncomingMessageStep.cs:line 66
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Sagas.LoadSagaDataStep.<Process>d__6.MoveNext() in C:\ReBus\Rebus\Sagas\LoadSagaDataStep.cs:line 66
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.ActivateHandlersStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\ActivateHandlersStep.cs:line 47
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.HandleRoutingSlipsStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\HandleRoutingSlipsStep.cs:line 40
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Retry.Simple.FailedMessageWrapperStep.<Process>d__2.MoveNext() in C:\ReBus\Rebus\Retry\Simple\FailedMessageWrapperStep.cs:line 42
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.DeserializeIncomingMessageStep.<Process>d__2.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\DeserializeIncomingMessageStep.cs:line 34
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.DataBus.ClaimCheck.HydrateIncomingMessageStep.<Process>d__2.MoveNext() in C:\ReBus\Rebus\DataBus\ClaimCheck\HydrateIncomingMessageStep.cs:line 51
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.HandleDeferredMessagesStep.<Process>d__12.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\HandleDeferredMessagesStep.cs:line 121
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Retry.FailFast.FailFastStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Retry\FailFast\FailFastStep.cs:line 51
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Retry.Simple.SimpleRetryStrategyStep.<DispatchWithTrackerIdentifier>d__10.MoveNext() in C:\ReBus\Rebus\Retry\Simple\SimpleRetryStrategyStep.cs:line 118
Handle(string message): HEJ MED DIG
[WRN] Rebus.Retry.ErrorTracking.InMemErrorTracker (Rebus 1 worker 1): Unhandled exception 2 while handling message with ID "667c8cfd-5ce5-46a6-9394-32d1386ef7de"
System.Exception: Handle(string message)
   at Rebus.Tests.Bugs.VerifyThisParticularThingAboutSecondLevelRetries.Handler.<Handle>d__4.MoveNext() in C:\ReBus\Rebus.Tests\Bugs\VerifyThisParticularThingAboutSecondLevelRetries.cs:line 81
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.HandlerInvoker`1.<Invoke>d__14.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\HandlerInvoker.cs:line 154
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.DispatchIncomingMessageStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\DispatchIncomingMessageStep.cs:line 66
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Sagas.LoadSagaDataStep.<Process>d__6.MoveNext() in C:\ReBus\Rebus\Sagas\LoadSagaDataStep.cs:line 66
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.ActivateHandlersStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\ActivateHandlersStep.cs:line 47
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.HandleRoutingSlipsStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\HandleRoutingSlipsStep.cs:line 40
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Retry.Simple.FailedMessageWrapperStep.<Process>d__2.MoveNext() in C:\ReBus\Rebus\Retry\Simple\FailedMessageWrapperStep.cs:line 42
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.DeserializeIncomingMessageStep.<Process>d__2.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\DeserializeIncomingMessageStep.cs:line 34
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.DataBus.ClaimCheck.HydrateIncomingMessageStep.<Process>d__2.MoveNext() in C:\ReBus\Rebus\DataBus\ClaimCheck\HydrateIncomingMessageStep.cs:line 51
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Pipeline.Receive.HandleDeferredMessagesStep.<Process>d__12.MoveNext() in C:\ReBus\Rebus\Pipeline\Receive\HandleDeferredMessagesStep.cs:line 121
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Retry.FailFast.FailFastStep.<Process>d__3.MoveNext() in C:\ReBus\Rebus\Retry\FailFast\FailFastStep.cs:line 51
--- End of stack trace from previous location where exception was thrown ---
   at System.Runtime.ExceptionServices.ExceptionDispatchInfo.Throw()
   at System.Runtime.CompilerServices.TaskAwaiter.HandleNonSuccessAndDebuggerNotification(Task task)
   at System.Runtime.CompilerServices.TaskAwaiter.GetResult()
   at Rebus.Retry.Simple.SimpleRetryStrategyStep.<DispatchWithTrackerIdentifier>d__10.MoveNext() in C:\ReBus\Rebus\Retry\Simple\SimpleRetryStrategyStep.cs:line 118
Handle(IFailed<Object> message): FAILED: HEJ MED DIG
[DBG] Rebus.Pipeline.Receive.DispatchIncomingMessageStep (Rebus 1 worker 1): Dispatching "System.String, mscorlib" "667c8cfd-5ce5-46a6-9394-32d1386ef7de" to 1 handlers took 4 ms
Disposing Rebus.Activation.BuiltinHandlerActivator
[DBG] Rebus.Pipeline.Receive.HandleDeferredMessagesStep (Rebus 1 worker 1): Deferring message "String/667c8cfd-5ce5-46a6-9394-32d1386ef7de" until 2019-06-04T10:36:51.6554132+01:00
[INF] Rebus.Bus.RebusBus (Worker#3): Bus "Rebus 1" setting number of workers to 0
[DBG] Rebus.Workers.ThreadPoolBased.ThreadPoolWorker (Rebus 1 worker 1): Worker "Rebus 1 worker 1" stopped
[DBG] Rebus.Bus.RebusBus (Worker#3): Removing worker "Rebus 1 worker 1"
[INF] Rebus.Threading.TaskParallelLibrary.TplAsyncTask (Worker#3): Stopping periodic task "DueMessagesSender"
[INF] Rebus.Threading.TaskParallelLibrary.TplAsyncTask (Worker#3): Stopping periodic task "CleanupTrackedErrors"
[INF] Rebus.Bus.RebusBus (Worker#3): Bus "Rebus 1" stopped
Disposing System.Threading.ManualResetEvent
1

There are 1 answers

13
mookid8000 On

What do the logs say?

To help you get on your way, I just created this little test case with a verification that it does on fact work as expected: VerifyThisParticularThingAboutSecondLevelRetries.cs

If you run the test, it should log a bunch of stuff (namely a couple of stack traces from the delivery attempts), and then the message should be dispatched as an Failed<string>, which is compatible with the handler for IFailed<object>.