Best practices for error logging when a HystrixCommand overrides getFallback()

[Jim Griswold]

Hi all,

I am experimenting with Hystrix and I was wondering what the best practices are around error logging in cases where a fallback value is provided.

For example, suppose that service A calls service B inside a HystrixCommand and I have overridden getFallback() for this command so that a reasonable default value is used in the failure case.

If service B goes down, I'd like to implement the following so that I can better understand the application's behavior when looking at the logs:

- If the circuit is currently closed, write an error log line in service A's logs which identifies the Exception that caused the failure (e.g. a ConnectException) and its stack trace.

- If the circuit is currently open, write an error log line in service A's logs when the command is invoked, ideally including the command name and stack trace.

- Write these log lines in the proper sequence, as opposed to writing all hystrix-related log data in a request context filter or similar at the end of a request.

- Share this behavior across the multiple HystrixCommand subclasses I create without duplicating the basic logging code.

The only solution I have so far is to create an abstract class descending from HystrixCommand which adds this functionality and returns a value provided by a new overrideable method, then make all my HystrixCommand classes descend from that new one.

From what I've seen in the docs and on github, this does not appear to be a common usage pattern. Given that error logging is such a common concern, I have the sense that I'm working against the grain here. I would love your thoughts on the cleanest approach or an alternative way of thinking about this.

Thanks in advance for your help and for this great project!

Jim 

[Matt Jacobs]

Jim - 

This is a good question.  At the moment, there's no logging on a fallback success.  There is a metrics exposed that counts the number of fallback successes, so you can see behavior at scale.  If you want to add logging to your fallback firing successfully, I can think of 2 options:

1) Implement a HystrixCommandExecutionHook and override the onFallbackSuccess method to do logging.  This would apply to all HystrixCommands on your JVM, so could do all logging here once you wire in the hook to your application.

2) For each getFallback() method that you implement, have the last statement before the return be a logging message.  If you did this, you could have very fine-grained control over the logging within each command.

Hope that helps,

Matt

[Jim Griswold]

Thanks, Matt! I hadn't come across the execution hooks, so I'll give that a whirl. Appreciate the help.

Jim

[Jim Griswold]

Hi Matt,

Your idea to use a HystrixCommandExecutionHook has been very helpful. I found that adding overriding onExecutionError method and adding some logging mapped very well to my needs.

Thanks again for the help!

Jim

On Tuesday, June 2, 2015 at 4:11:18 PM UTC-4, Matt Jacobs wrote:

[Matt Jacobs]

Glad to hear it!

--
You received this message because you are subscribed to the Google Groups "HystrixOSS" group.
To unsubscribe from this group and stop receiving emails from it, send an email to hystrixoss+...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

[jaikrishnan v]

Hello Matt,

I need to have some bit of clarity on what level of logging we have to use inside hystrix fallback method?

Regards,

Jay

[Matt Jacobs]

debug