Merge pull request #43 from hudl/Plat-MakeSenseOfTimeoutCause

Find out the true cause of a CommandFailedException

Hudl.Mjolnir.Tests/Command/Attribute/NewCommandAttributeAndProxyTests.cs

@@ -80,7 +80,7 @@ public void MethodShouldTimeout_WhenTimeoutsAreNotIgnored()
         {
             var classToProxy = new CancellableWithOverrunnningMethod();
             var proxy = CommandInterceptor.CreateProxy<ICancellableTimeoutPreserved>(classToProxy);
-            Assert.Throws<CommandFailedException>(() => proxy.CancellableMethod(CancellationToken.None));
+            Assert.Throws<CommandTimeoutException>(() => proxy.CancellableMethod(CancellationToken.None));
         }
     }
 }

Hudl.Mjolnir.Tests/Stats/CommandStatsTests.cs

@@ -90,8 +90,8 @@ public async Task InvokeAsync_OperationCanceledException()
             catch (CommandFailedException e)
             {
                 Assert.True(e.GetBaseException() is OperationCanceledException);
-                mockStats.Verify(m => m.Elapsed("mjolnir command test.TimingOutWithoutFallback total", "Canceled", It.IsAny<TimeSpan>()), Times.Once);
-                mockStats.Verify(m => m.Elapsed("mjolnir command test.TimingOutWithoutFallback execute", "Canceled", It.IsAny<TimeSpan>()), Times.Once);
+                mockStats.Verify(m => m.Elapsed("mjolnir command test.TimingOutWithoutFallback total", "TimedOut", It.IsAny<TimeSpan>()), Times.Once);
+                mockStats.Verify(m => m.Elapsed("mjolnir command test.TimingOutWithoutFallback execute", "TimedOut", It.IsAny<TimeSpan>()), Times.Once);
                 return; // Expected.
             }
 

Hudl.Mjolnir/Command/Command.cs

@@ -301,22 +301,21 @@ public async Task<TResult> InvokeAsync()
             var invokeStopwatch = Stopwatch.StartNew();
             var executeStopwatch = Stopwatch.StartNew();
             var status = CommandCompletionStatus.RanToCompletion;
+            var cancellationTokenSource = new CancellationTokenSource(Timeout);
             try
             {
                 _log.InfoFormat("InvokeAsync Command={0} Breaker={1} Pool={2} Timeout={3}", Name, BreakerKey, PoolKey, Timeout.TotalMilliseconds);
 
-                var cancellationTokenSource = new CancellationTokenSource(Timeout);
                 // Note: this actually awaits the *enqueueing* of the task, not the task execution itself.
                 var result = await ExecuteInIsolation(cancellationTokenSource.Token).ConfigureAwait(false);
                 executeStopwatch.Stop();
                 return result;
             }
             catch (Exception e)
             {
+                var tokenSourceCancelled = cancellationTokenSource.IsCancellationRequested;
                 executeStopwatch.Stop();
-                status = StatusFromException(e);
-
-                var instigator = new CommandFailedException(e, status).WithData(new
+                var instigator = GetCommandFailedException(e,tokenSourceCancelled, out status).WithData(new
                 {
                     Command = Name,
                     Timeout = Timeout.TotalMilliseconds,
@@ -419,20 +418,30 @@ private async Task<TResult> ExecuteWithBreaker(CancellationToken cancellationTok
             return result;
         }
 
-
-        private static CommandCompletionStatus StatusFromException(Exception e)
+        private static CommandFailedException GetCommandFailedException(Exception e, bool timeoutTokenTriggered, out CommandCompletionStatus status)
         {
+            status = CommandCompletionStatus.Faulted;
             if (IsCancellationException(e))
             {
-                return CommandCompletionStatus.Canceled;
+                // If the timeout cancellationTokenSource was cancelled and we got an TaskCancelledException here then this means the call actually timed out.
+                // Otherwise an TaskCancelledException would have been raised if a user CancellationToken was passed through to the method call, and was explicitly
+                // cancelled from the client side.
+                if (timeoutTokenTriggered)
+                {
+                    status = CommandCompletionStatus.TimedOut;
+                    return new CommandTimeoutException(e);
+                }
+                status = CommandCompletionStatus.Canceled;
+                return new CommandCancelledException(e);
             }
 
             if (e is CircuitBreakerRejectedException || e is IsolationThreadPoolRejectedException)
             {
-                return CommandCompletionStatus.Rejected;
+                status = CommandCompletionStatus.Rejected;
+                return new CommandRejectedException(e);
             }
 
-            return CommandCompletionStatus.Faulted;
+            return new CommandFailedException(e);
         }
 
         private static bool IsCancellationException(Exception e)

Hudl.Mjolnir/Command/CommandCancelledException.cs

@@ -0,0 +1,12 @@
+using System;
+
+namespace Hudl.Mjolnir.Command
+{
+    public sealed class CommandCancelledException : CommandFailedException
+    {
+        internal CommandCancelledException(Exception cause)
+            : base("Command canceled", cause, CommandCompletionStatus.Canceled)
+        {
+        }
+    }
+}

Hudl.Mjolnir/Command/CommandCompletionStatus.cs

@@ -13,13 +13,18 @@ public enum CommandCompletionStatus
         Faulted,
 
         /// <summary>
-        /// Canceled (timed out).
+        /// Canceled.
         /// </summary>
         Canceled,
 
         /// <summary>
         /// Rejected by the circuit breaker.
         /// </summary>
         Rejected,
+
+        /// <summary>
+        /// Timed out
+        /// </summary>
+        TimedOut,
     }
 }

Hudl.Mjolnir/Command/CommandFailedException.cs

@@ -8,24 +8,12 @@ public class CommandFailedException : Exception
         public CommandCompletionStatus Status { get; internal set; }
         public FallbackStatus FallbackStatus { get; internal set; }
 
-        internal CommandFailedException(Exception cause, CommandCompletionStatus status) : base(GetMessage(status), cause)
+        internal CommandFailedException(Exception cause) : this("Command failed", cause, CommandCompletionStatus.Faulted) { }
+
+        protected CommandFailedException(string message, Exception cause, CommandCompletionStatus status) : base(message, cause)
         {
             IsFallbackImplemented = true; // Assume the best! Actually, we'll just set it to false later if we don't have an implementation.
             Status = status;
         }
-
-        private static string GetMessage(CommandCompletionStatus status)
-        {
-            switch (status)
-            {
-                case CommandCompletionStatus.Canceled:
-                    return "Command canceled";
-
-                case CommandCompletionStatus.Rejected:
-                    return "Command rejected";
-            }
-
-            return "Command failed";
-        }
     }
 }

Hudl.Mjolnir/Command/CommandRejectedException.cs

@@ -0,0 +1,12 @@
+using System;
+
+namespace Hudl.Mjolnir.Command
+{
+    public sealed class CommandRejectedException : CommandFailedException
+    {
+        internal CommandRejectedException(Exception cause)
+            : base("Command rejected", cause, CommandCompletionStatus.Rejected)
+        {
+        }
+    }
+}

Hudl.Mjolnir/Command/CommandTimeoutException.cs

@@ -0,0 +1,12 @@
+using System;
+
+namespace Hudl.Mjolnir.Command
+{
+    public sealed class CommandTimeoutException : CommandFailedException
+    {
+        internal CommandTimeoutException(Exception cause)
+            : base("Command timed out", cause, CommandCompletionStatus.TimedOut)
+        {
+        }
+    }
+}

Hudl.Mjolnir/Hudl.Mjolnir.csproj

@@ -74,8 +74,11 @@
     <Compile Include="Command\Attribute\FireAndForgetAttribute.cs" />
     <Compile Include="Command\Attribute\InvocationCommand.cs" />
     <Compile Include="Command\Command.cs" />
+    <Compile Include="Command\CommandCancelledException.cs" />
     <Compile Include="Command\CommandContext.cs" />
     <Compile Include="Command\CommandFailedException.cs" />
+    <Compile Include="Command\CommandRejectedException.cs" />
+    <Compile Include="Command\CommandTimeoutException.cs" />
     <Compile Include="Command\VoidResult.cs" />
     <Compile Include="External\IgnoringStats.cs" />
     <Compile Include="External\IStats.cs" />

Hudl.Mjolnir/Properties/AssemblyInfo.cs

@@ -27,10 +27,10 @@
 [assembly: Guid("97b23684-6c4a-4749-b307-5867cbce2dff")]
 
 // Used for NuGet packaging, uses semantic versioning: major.minor.patch-prerelease.
-[assembly: AssemblyInformationalVersion("2.4.0")]
+[assembly: AssemblyInformationalVersion("2.5.0")]
 
 // Keep this the same as AssemblyInformationalVersion.
-[assembly: AssemblyFileVersion("2.4.0")]
+[assembly: AssemblyFileVersion("2.5.0")]
 
 // ONLY change this when the major version changes; never with minor/patch/build versions.
 // It'll almost always be the major version followed by three zeroes (e.g. 1.0.0.0).