From 89730c2ae84d730ad7da7051d2416ce075565e56 Mon Sep 17 00:00:00 2001 From: Sergey Krutsko Date: Wed, 17 Dec 2014 22:16:31 -0800 Subject: [PATCH 1/8] Hook execution sequence issue --- .../src/test/java/com/netflix/hystrix/HystrixCommandTest.java | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index 3d67997e9..6eecf4878 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -75,6 +75,10 @@ public void cleanup() { } } + private static void recordHookCall(StringBuilder sequenceRecorder, String methodName) { + sequenceRecorder.append(methodName).append(" - "); + } + /** * Test a successful command execution. */ From a21a253a8bf8585ee9b0e15d8572b0165e2f22c0 Mon Sep 17 00:00:00 2001 From: Sergey Krutsko Date: Wed, 17 Dec 2014 22:27:07 -0800 Subject: [PATCH 2/8] Unit tests to reproduce Hook execution sequence issue. --- .../netflix/hystrix/HystrixCommandTest.java | 72 +++++++++++++++++++ 1 file changed, 72 insertions(+) diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index 6eecf4878..57f00bc07 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -3396,6 +3396,9 @@ public void testExecutionHookSuccessfulCommand() { assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + /* test with queue() */ command = new SuccessfulTestCommand(); try { @@ -3428,6 +3431,10 @@ public void testExecutionHookSuccessfulCommand() { // thread execution assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + } /** @@ -3480,6 +3487,9 @@ public void testExecutionHookSuccessfulCommandViaFireAndForget() { // thread execution assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3526,6 +3536,10 @@ public void testExecutionHookSuccessfulCommandWithMultipleGetsOnFuture() { // thread execution assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + } /** @@ -3569,6 +3583,10 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + + /* test with queue() */ command = new UnknownFailureTestCommandWithoutFallback(); try { @@ -3605,6 +3623,8 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3641,6 +3661,10 @@ public void testExecutionHookRunFailureWithFallback() { assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + + /* test with queue() */ command = new KnownFailureTestCommandWithFallback(new TestCircuitBreaker()); try { @@ -3673,6 +3697,9 @@ public void testExecutionHookRunFailureWithFallback() { // thread execution assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3716,6 +3743,9 @@ public void testExecutionHookRunFailureWithFallbackFailure() { assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + /* test with queue() */ command = new KnownFailureTestCommandWithFallbackFailure(); try { @@ -3751,6 +3781,9 @@ public void testExecutionHookRunFailureWithFallbackFailure() { // thread execution assertEquals(1, command.builder.executionHook.threadStart.get()); assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3799,6 +3832,10 @@ public void testExecutionHookTimeoutWithoutFallback() { // ignore } assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackError - onError - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + } /** @@ -3844,6 +3881,9 @@ public void testExecutionHookTimeoutWithFallback() { // ignore } assertEquals(1, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackSuccess - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3896,6 +3936,10 @@ public void testExecutionHookRejectedWithFallback() { // thread execution assertEquals(0, command.builder.executionHook.threadStart.get()); assertEquals(0, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onFallbackStart - onFallbackSuccess - onComplete - ", command.builder.executionHook.executionSequence.toString()); + } /** @@ -3941,6 +3985,9 @@ public void testExecutionHookShortCircuitedWithFallbackViaQueue() { // thread execution assertEquals(0, command.builder.executionHook.threadStart.get()); assertEquals(0, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3986,6 +4033,9 @@ public void testExecutionHookShortCircuitedWithFallbackViaExecute() { // thread execution assertEquals(0, command.builder.executionHook.threadStart.get()); assertEquals(0, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -4024,6 +4074,9 @@ public void testExecutionHookSuccessfulCommandWithSemaphoreIsolation() { assertEquals(0, command.builder.executionHook.threadStart.get()); assertEquals(0, command.builder.executionHook.threadComplete.get()); + // expected hook execution sequence + assertEquals("onStart - onRunStart - onRunSuccess - onComplete - ", command.builder.executionHook.executionSequence.toString()); + /* test with queue() */ command = new TestSemaphoreCommand(new TestCircuitBreaker(), 1, 10); try { @@ -4058,6 +4111,9 @@ public void testExecutionHookSuccessfulCommandWithSemaphoreIsolation() { // thread execution assertEquals(0, command.builder.executionHook.threadStart.get()); assertEquals(0, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onRunStart - onRunSuccess - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -4106,6 +4162,10 @@ public void testExecutionHookFailureWithSemaphoreIsolation() { // thread execution assertEquals(0, command.builder.executionHook.threadStart.get()); assertEquals(0, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); + } /** @@ -5145,11 +5205,13 @@ public String getCollapserPropertiesCacheKey(HystrixCollapserKey collapserKey, c private static class TestExecutionHook extends HystrixCommandExecutionHook { + StringBuilder executionSequence = new StringBuilder(); AtomicInteger startExecute = new AtomicInteger(); @Override public void onStart(HystrixInvokable commandInstance) { super.onStart(commandInstance); + recordHookCall(executionSequence, "onStart"); startExecute.incrementAndGet(); } @@ -5158,6 +5220,7 @@ public void onStart(HystrixInvokable commandInstance) { @Override public T onComplete(HystrixInvokable commandInstance, T response) { endExecuteSuccessResponse = response; + recordHookCall(executionSequence, "onComplete"); return super.onComplete(commandInstance, response); } @@ -5168,6 +5231,7 @@ public T onComplete(HystrixInvokable commandInstance, T response) { public Exception onError(HystrixInvokable commandInstance, FailureType failureType, Exception e) { endExecuteFailureException = e; endExecuteFailureType = failureType; + recordHookCall(executionSequence, "onError"); return super.onError(commandInstance, failureType, e); } @@ -5176,6 +5240,7 @@ public Exception onError(HystrixInvokable commandInstance, FailureType fa @Override public void onRunStart(HystrixInvokable commandInstance) { super.onRunStart(commandInstance); + recordHookCall(executionSequence, "onRunStart"); startRun.incrementAndGet(); } @@ -5184,6 +5249,7 @@ public void onRunStart(HystrixInvokable commandInstance) { @Override public T onRunSuccess(HystrixInvokable commandInstance, T response) { runSuccessResponse = response; + recordHookCall(executionSequence, "onRunSuccess"); return super.onRunSuccess(commandInstance, response); } @@ -5192,6 +5258,7 @@ public T onRunSuccess(HystrixInvokable commandInstance, T response) { @Override public Exception onRunError(HystrixInvokable commandInstance, Exception e) { runFailureException = e; + recordHookCall(executionSequence, "onRunError"); return super.onRunError(commandInstance, e); } @@ -5200,6 +5267,7 @@ public Exception onRunError(HystrixInvokable commandInstance, Exception e @Override public void onFallbackStart(HystrixInvokable commandInstance) { super.onFallbackStart(commandInstance); + recordHookCall(executionSequence, "onFallbackStart"); startFallback.incrementAndGet(); } @@ -5208,6 +5276,7 @@ public void onFallbackStart(HystrixInvokable commandInstance) { @Override public T onFallbackSuccess(HystrixInvokable commandInstance, T response) { fallbackSuccessResponse = response; + recordHookCall(executionSequence, "onFallbackSuccess"); return super.onFallbackSuccess(commandInstance, response); } @@ -5216,6 +5285,7 @@ public T onFallbackSuccess(HystrixInvokable commandInstance, T response) @Override public Exception onFallbackError(HystrixInvokable commandInstance, Exception e) { fallbackFailureException = e; + recordHookCall(executionSequence, "onFallbackError"); return super.onFallbackError(commandInstance, e); } @@ -5224,6 +5294,7 @@ public Exception onFallbackError(HystrixInvokable commandInstance, Except @Override public void onThreadStart(HystrixInvokable commandInstance) { super.onThreadStart(commandInstance); + recordHookCall(executionSequence, "onThreadStart"); threadStart.incrementAndGet(); } @@ -5232,6 +5303,7 @@ public void onThreadStart(HystrixInvokable commandInstance) { @Override public void onThreadComplete(HystrixInvokable commandInstance) { super.onThreadComplete(commandInstance); + recordHookCall(executionSequence, "onThreadComplete"); threadComplete.incrementAndGet(); } From f95c6940f2195e877e39c0d45f41c3754510633c Mon Sep 17 00:00:00 2001 From: Sergey Krutsko Date: Wed, 17 Dec 2014 22:36:21 -0800 Subject: [PATCH 3/8] Unit tests to reproduce Hook execution sequence issue. testExecutionHookFailedOnHystrixBadRequestWithSemaphoreIsolation --- .../netflix/hystrix/HystrixCommandTest.java | 98 ++++++++++++++++++- 1 file changed, 97 insertions(+), 1 deletion(-) diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index 57f00bc07..f790e5c35 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -31,7 +31,6 @@ import rx.Scheduler; import rx.functions.Action1; import rx.observers.TestSubscriber; -import rx.schedulers.Schedulers; import com.netflix.config.ConfigurationManager; import com.netflix.hystrix.AbstractCommand.TryableSemaphore; @@ -4165,7 +4164,51 @@ public void testExecutionHookFailureWithSemaphoreIsolation() { // expected hook execution sequence assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); + } + + /** + * Execution hook on fail with HystrixBadRequest exception + */ + @Test + public void testExecutionHookFailedOnHystrixBadRequestWithSemaphoreIsolation() { + TestSemaphoreCommandFailWithHystrixBadRequestException command = new TestSemaphoreCommandFailWithHystrixBadRequestException(new TestCircuitBreaker(), 1, 10); + try { + command.execute(); + fail("we expect a failure"); + } catch (Exception e) { + // expected + } + + assertFalse(command.isExecutedInThread()); + + // the run() method should run as we're not short-circuited or rejected + assertEquals(1, command.builder.executionHook.startRun.get()); + // we expect a successful response from run() + assertNull(command.builder.executionHook.runSuccessResponse); + // we expect an exception + assertNotNull(command.builder.executionHook.runFailureException); + + // the fallback() method should not be run as we were successful + assertEquals(0, command.builder.executionHook.startFallback.get()); + // null since it didn't run + assertNull(command.builder.executionHook.fallbackSuccessResponse); + // null since it didn't run + assertNull(command.builder.executionHook.fallbackFailureException); + + // the execute() method was used + assertEquals(1, command.builder.executionHook.startExecute.get()); + // we should not have a response from execute() + assertNull(command.builder.executionHook.endExecuteSuccessResponse); + // we should not have an exception since run() succeeded + assertNull(command.builder.executionHook.endExecuteFailureException); + + // thread execution + assertEquals(0, command.builder.executionHook.threadStart.get()); + assertEquals(0, command.builder.executionHook.threadComplete.get()); + + // expected hook execution sequence + assertEquals("onStart - onRunStart - onRunError - onError - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -4485,6 +4528,29 @@ protected Boolean run() { } + private static class KnownHystrixBadRequestFailureTestCommandWithoutFallback extends TestHystrixCommand { + + public KnownHystrixBadRequestFailureTestCommandWithoutFallback(TestCircuitBreaker circuitBreaker) { + super(testPropsBuilder().setCircuitBreaker(circuitBreaker).setMetrics(circuitBreaker.metrics)); + } + + public KnownHystrixBadRequestFailureTestCommandWithoutFallback(TestCircuitBreaker circuitBreaker, boolean fallbackEnabled) { + super(testPropsBuilder().setCircuitBreaker(circuitBreaker).setMetrics(circuitBreaker.metrics) + .setCommandPropertiesDefaults(HystrixCommandPropertiesTest.getUnitTestPropertiesSetter().withFallbackEnabled(fallbackEnabled))); + } + + @Override + protected Boolean run() { + System.out.println("*** simulated failed with HystrixBadRequestException ***"); + throw new HystrixBadRequestException("we failed with a simulated issue"); + } + + @Override + protected Boolean getFallback() { + return false; + } + } + /** * Failed execution - fallback implementation successfully returns value. */ @@ -4910,6 +4976,36 @@ protected Boolean run() { } } + /** + * The run() will take time. No fallback implementation. + */ + private static class TestSemaphoreCommandFailWithHystrixBadRequestException extends TestHystrixCommand { + + private final long executionSleep; + + private TestSemaphoreCommandFailWithHystrixBadRequestException(TestCircuitBreaker circuitBreaker, int executionSemaphoreCount, long executionSleep) { + super(testPropsBuilder().setCircuitBreaker(circuitBreaker).setMetrics(circuitBreaker.metrics) + .setCommandPropertiesDefaults(HystrixCommandPropertiesTest.getUnitTestPropertiesSetter() + .withExecutionIsolationStrategy(ExecutionIsolationStrategy.SEMAPHORE) + .withExecutionIsolationSemaphoreMaxConcurrentRequests(executionSemaphoreCount))); + this.executionSleep = executionSleep; + } + + private TestSemaphoreCommandFailWithHystrixBadRequestException(TestCircuitBreaker circuitBreaker, TryableSemaphore semaphore, long executionSleep) { + super(testPropsBuilder().setCircuitBreaker(circuitBreaker).setMetrics(circuitBreaker.metrics) + .setCommandPropertiesDefaults(HystrixCommandPropertiesTest.getUnitTestPropertiesSetter() + .withExecutionIsolationStrategy(ExecutionIsolationStrategy.SEMAPHORE)) + .setExecutionSemaphore(semaphore)); + this.executionSleep = executionSleep; + } + + @Override + protected Boolean run() { + System.out.print("*** simulated failed execution ***"); + throw new HystrixBadRequestException("we failed with a simulated issue"); + } + } + /** * Semaphore based command that allows caller to use latches to know when it has started and signal when it * would like the command to finish From 912bb9e66384b581e836ee98510d58f897f229a5 Mon Sep 17 00:00:00 2001 From: Matt Jacobs Date: Wed, 17 Dec 2014 23:28:24 -0800 Subject: [PATCH 4/8] Changing expectations of hook order to match 1.3 --- .../netflix/hystrix/HystrixCommandTest.java | 30 +++++++++---------- 1 file changed, 15 insertions(+), 15 deletions(-) diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index f790e5c35..c6d66ad54 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -3396,7 +3396,7 @@ public void testExecutionHookSuccessfulCommand() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ command = new SuccessfulTestCommand(); @@ -3432,7 +3432,7 @@ public void testExecutionHookSuccessfulCommand() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } @@ -3488,7 +3488,7 @@ public void testExecutionHookSuccessfulCommandViaFireAndForget() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3537,7 +3537,7 @@ public void testExecutionHookSuccessfulCommandWithMultipleGetsOnFuture() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } @@ -3583,7 +3583,7 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ @@ -3623,7 +3623,7 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3661,7 +3661,7 @@ public void testExecutionHookRunFailureWithFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ @@ -3698,7 +3698,7 @@ public void testExecutionHookRunFailureWithFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3743,7 +3743,7 @@ public void testExecutionHookRunFailureWithFallbackFailure() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ command = new KnownFailureTestCommandWithFallbackFailure(); @@ -3782,7 +3782,7 @@ public void testExecutionHookRunFailureWithFallbackFailure() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3833,7 +3833,7 @@ public void testExecutionHookTimeoutWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackError - onError - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackError - onError - onRunSuccess - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } @@ -3882,7 +3882,7 @@ public void testExecutionHookTimeoutWithFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackSuccess - onRunSuccess - onThreadComplete - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackSuccess - onComplete - onRunSuccess - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3986,7 +3986,7 @@ public void testExecutionHookShortCircuitedWithFallbackViaQueue() { assertEquals(0, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -4034,7 +4034,7 @@ public void testExecutionHookShortCircuitedWithFallbackViaExecute() { assertEquals(0, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -4163,7 +4163,7 @@ public void testExecutionHookFailureWithSemaphoreIsolation() { assertEquals(0, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onFallbackStart - onFallbackError - onError - onComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); } /** From cd0e6c22d8a0c46e64d69a7ab55ab5e2a8f7b33d Mon Sep 17 00:00:00 2001 From: Matt Jacobs Date: Wed, 17 Dec 2014 23:36:38 -0800 Subject: [PATCH 5/8] Switching order on onRunStart, onThreadStart hook execution to match 1.3 --- .../src/main/java/com/netflix/hystrix/AbstractCommand.java | 2 +- .../src/test/java/com/netflix/hystrix/HystrixCommandTest.java | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java b/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java index eb54f5a0a..017983eb9 100644 --- a/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java +++ b/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java @@ -506,8 +506,8 @@ private Observable getRunObservableDecoratedForMetricsAndErrorHandling(final @Override public void call(Subscriber s) { - executionHook.onRunStart(_self); executionHook.onThreadStart(_self); + executionHook.onRunStart(_self); if (isCommandTimedOut.get() == TimedOutStatus.TIMED_OUT) { // the command timed out in the wrapping thread so we will return immediately // and not increment any of the counters below or other such logic diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index c6d66ad54..8f9668ecb 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -3583,7 +3583,7 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ From f18919b0aa4e08613b518743927a44977e131796 Mon Sep 17 00:00:00 2001 From: Matt Jacobs Date: Tue, 23 Dec 2014 22:48:32 -0500 Subject: [PATCH 6/8] Removed assertions that executionHook.onRunSuccess gets called in timeout case --- .../main/java/com/netflix/hystrix/AbstractCommand.java | 10 +--------- .../java/com/netflix/hystrix/HystrixCommandTest.java | 4 ++-- 2 files changed, 3 insertions(+), 11 deletions(-) diff --git a/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java b/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java index 017983eb9..f4a9830a3 100644 --- a/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java +++ b/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java @@ -750,15 +750,7 @@ private Observable getFallbackOrThrowException(final HystrixEventType eventTy executionResult = executionResult.addEvents(eventType); final AbstractCommand _cmd = this; - return getFallbackWithProtection().map(new Func1() { - - @Override - public R call(R t1) { - System.out.println(">>>>>>>>>>>> fallback on thread: " + Thread.currentThread()); - return executionHook.onComplete(_cmd, t1); - } - - }).doOnCompleted(new Action0() { + return getFallbackWithProtection().doOnCompleted(new Action0() { @Override public void call() { diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index 8f9668ecb..9ab580c54 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -3833,7 +3833,7 @@ public void testExecutionHookTimeoutWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackError - onError - onRunSuccess - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } @@ -3882,7 +3882,7 @@ public void testExecutionHookTimeoutWithFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackSuccess - onComplete - onRunSuccess - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onFallbackStart - onFallbackSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); } /** From 65ed5fb4667159daeedc70419bafce987711c60b Mon Sep 17 00:00:00 2001 From: Matt Jacobs Date: Sat, 27 Dec 2014 15:16:33 -0500 Subject: [PATCH 7/8] Switch assertion order of hooks, as onThreadComplete is firing earlier in 1.4 --- .../java/com/netflix/hystrix/HystrixCommandTest.java | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index 9ab580c54..30430edc8 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -3583,7 +3583,7 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onThreadComplete - onRunError - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ @@ -3623,7 +3623,7 @@ public void testExecutionHookRunFailureWithoutFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onThreadComplete - onRunError - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3661,7 +3661,7 @@ public void testExecutionHookRunFailureWithFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onThreadComplete - onRunError - onFallbackStart - onFallbackSuccess - onComplete - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ @@ -3698,7 +3698,7 @@ public void testExecutionHookRunFailureWithFallback() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackSuccess - onComplete - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onThreadComplete - onRunError - onFallbackStart - onFallbackSuccess - onComplete - ", command.builder.executionHook.executionSequence.toString()); } /** @@ -3743,7 +3743,7 @@ public void testExecutionHookRunFailureWithFallbackFailure() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onThreadComplete - onRunError - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); /* test with queue() */ command = new KnownFailureTestCommandWithFallbackFailure(); @@ -3782,7 +3782,7 @@ public void testExecutionHookRunFailureWithFallbackFailure() { assertEquals(1, command.builder.executionHook.threadComplete.get()); // expected hook execution sequence - assertEquals("onStart - onThreadStart - onRunStart - onRunError - onFallbackStart - onFallbackError - onError - onThreadComplete - ", command.builder.executionHook.executionSequence.toString()); + assertEquals("onStart - onThreadStart - onRunStart - onThreadComplete - onRunError - onFallbackStart - onFallbackError - onError - ", command.builder.executionHook.executionSequence.toString()); } /** From 7d740d8a459c176552fa01bce87577c9e9a8e569 Mon Sep 17 00:00:00 2001 From: Matt Jacobs Date: Sat, 27 Dec 2014 15:41:55 -0500 Subject: [PATCH 8/8] Added ExecutionHook.onError call to HystrixBadRequestException handling --- .../java/com/netflix/hystrix/AbstractCommand.java | 12 +++++++++++- .../hystrix/exception/HystrixRuntimeException.java | 2 +- .../java/com/netflix/hystrix/HystrixCommandTest.java | 8 ++++---- 3 files changed, 16 insertions(+), 6 deletions(-) diff --git a/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java b/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java index f4a9830a3..a64afdd8d 100644 --- a/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java +++ b/hystrix-core/src/main/java/com/netflix/hystrix/AbstractCommand.java @@ -561,7 +561,6 @@ public void call(Notification n) { @Override public R call(R t1) { - System.out.println("map " + t1); if (!once) { // report success executionResult = executionResult.addEvents(HystrixEventType.SUCCESS); @@ -617,6 +616,17 @@ public Observable call(Throwable t) { logger.warn("Error calling ExecutionHook.onRunError", hookException); } + try { + Exception decorated = executionHook.onError(_self, FailureType.BAD_REQUEST_EXCEPTION, (Exception) t); + + if (decorated instanceof HystrixBadRequestException) { + t = (HystrixBadRequestException) decorated; + } else { + logger.warn("ExecutionHook.onError returned an exception that was not an instance of HystrixBadRequestException so will be ignored.", decorated); + } + } catch (Exception hookException) { + logger.warn("Error calling ExecutionHook.onError", hookException); + } /* * HystrixBadRequestException is treated differently and allowed to propagate without any stats tracking or fallback logic */ diff --git a/hystrix-core/src/main/java/com/netflix/hystrix/exception/HystrixRuntimeException.java b/hystrix-core/src/main/java/com/netflix/hystrix/exception/HystrixRuntimeException.java index 6c1dd5052..b70a877f2 100644 --- a/hystrix-core/src/main/java/com/netflix/hystrix/exception/HystrixRuntimeException.java +++ b/hystrix-core/src/main/java/com/netflix/hystrix/exception/HystrixRuntimeException.java @@ -32,7 +32,7 @@ public class HystrixRuntimeException extends RuntimeException { private final FailureType failureCause; public static enum FailureType { - COMMAND_EXCEPTION, TIMEOUT, SHORTCIRCUIT, REJECTED_THREAD_EXECUTION, REJECTED_SEMAPHORE_EXECUTION, REJECTED_SEMAPHORE_FALLBACK + BAD_REQUEST_EXCEPTION, COMMAND_EXCEPTION, TIMEOUT, SHORTCIRCUIT, REJECTED_THREAD_EXECUTION, REJECTED_SEMAPHORE_EXECUTION, REJECTED_SEMAPHORE_FALLBACK } public HystrixRuntimeException(FailureType failureCause, Class commandClass, String message, Exception cause, Throwable fallbackException) { diff --git a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java index 30430edc8..5f2e1736b 100644 --- a/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java +++ b/hystrix-core/src/test/java/com/netflix/hystrix/HystrixCommandTest.java @@ -4184,12 +4184,12 @@ public void testExecutionHookFailedOnHystrixBadRequestWithSemaphoreIsolation() { // the run() method should run as we're not short-circuited or rejected assertEquals(1, command.builder.executionHook.startRun.get()); - // we expect a successful response from run() + // we expect no response from run() assertNull(command.builder.executionHook.runSuccessResponse); // we expect an exception assertNotNull(command.builder.executionHook.runFailureException); - // the fallback() method should not be run as we were successful + // the fallback() method should not be run as BadRequestException is handled by immediate propagation assertEquals(0, command.builder.executionHook.startFallback.get()); // null since it didn't run assertNull(command.builder.executionHook.fallbackSuccessResponse); @@ -4200,8 +4200,8 @@ public void testExecutionHookFailedOnHystrixBadRequestWithSemaphoreIsolation() { assertEquals(1, command.builder.executionHook.startExecute.get()); // we should not have a response from execute() assertNull(command.builder.executionHook.endExecuteSuccessResponse); - // we should not have an exception since run() succeeded - assertNull(command.builder.executionHook.endExecuteFailureException); + // we should have a HystrixBadRequest exception since run() succeeded + assertNotNull(command.builder.executionHook.endExecuteFailureException); // thread execution assertEquals(0, command.builder.executionHook.threadStart.get());