---------- Forwarded message ---------
From: David Mollitor <dam6...@gmail.com>
Date: Fri, Dec 6, 2019 at 12:52 PM
Subject: Re: Error Handling and Logging
To: <d...@hbase.apache.org>
Hell Team,
I'm not sure how to automate this, but as I scan through the log
statements, another thing I am observing is the following:
1// Lots of punctuation. There is no need to yell (!!!) or to try to be
proper (.). Please be concise and most log messages do not end with a
period
2// Contractions. Please do not use contractions (can't, won't we're)
these are harder words for our international friends
3// Use strong words. Avoid phases like "couldn't complete the action" and
instead consider using something like "failed to complete action". The
word "fail" is trained into me much more than the word "couldn't"
Thanks so much for all the positive feedback I've received from the HBase
team here and in private conversations.
On Thu, Dec 5, 2019 at 1:10 PM Nick Dimiduk <ndimi...@apache.org> wrote:
> I think these are good points all around. Can any of these anti-patterns be
> flagged by a checkstyle rule? Static analysis would make the infractions
> easier to track down.
>
> One more point of my own: I’m of the opinion that we log too much in
> general. Info level should not describe the details of operations as
> normal. I’m also not a fan of logging data structure “status”messages, as
> we do, for example, from the block cache. It’s enough to expose these as
> metrics.
>
> Thanks for speaking up! If you’re feeling ambitious, please ping me on any
> PRs and we’ll get things cleaned up.
>
> Thanks,
> Nick
>
> On Tue, Dec 3, 2019 at 21:02 Stack <st...@duboce.net> wrote:
>
> > Thanks for the helpful note David. Appreciated.
> > S
> >
> > On Tue, Nov 26, 2019 at 1:44 PM David Mollitor <dam6...@gmail.com>
> wrote:
> >
> > > Hello Team,
> > >
> > > I am one of many people responsible for supporting the Hadoop products
> > out
> > > in the field. Error handling and logging are crucial to my success.
> > I've
> > > been reading over the code and I see many of the same mistakes again
> and
> > > again. I just wanted to bring some of these things to your attention
> so
> > > that moving forward, we can make these products better.
> > >
> > > The general best-practice is:
> > >
> > > public class TestExceptionLogging
> > > {
> > > private static final Logger LOG =
> > > LoggerFactory.getLogger(TestExceptionLogging.class);
> > >
> > > public static void main(String[] args) {
> > > try {
> > > processData();
> > > } catch (Exception e) {
> > > LOG.error("Application failed", e);
> > > }
> > > }
> > >
> > > public static void processData() throws Exception {
> > > try {
> > > readData();
> > > } catch (Exception e) {
> > > throw new Exception("Failed to process data", e);
> > > }
> > > }
> > >
> > > public static byte[] readData() throws Exception {
> > > throw new IOException("Failed to read device");
> > > }
> > > }
> > >
> > > Produces:
> > >
> > > [main] ERROR TestExceptionLogging - Application failed
> > > java.lang.Exception: Failed to process data
> > > at TestExceptionLogging.processData(TestExceptionLogging.java:22)
> > > at TestExceptionLogging.main(TestExceptionLogging.java:12)
> > > Caused by: java.io.IOException: Failed to read device
> > > at TestExceptionLogging.readData(TestExceptionLogging.java:27)
> > > at TestExceptionLogging.processData(TestExceptionLogging.java:20)
> > > ... 1 more
> > >
> > >
> > >
> > > Please notice that when an exception is thrown, and caught, it is
> wrapped
> > > at each level and each level adds some more context to describe what
> was
> > > happening when the error occurred. It also produces a complete stack
> > trace
> > > that pinpoints the issue. For Hive folks, it is rarely the case that a
> > > method consuming a HMS API call should itself throw a MetaException.
> The
> > > MetaException has no way of wrapping an underlying Exception and
> helpful
> > > data is often loss. A method may chooses to wrap a MetaException, but
> it
> > > should not be throwing them around as the default behavior.
> > >
> > > Also important to note is that there is exactly one place that is doing
> > the
> > > logging. There does not need to be any logging at the lower levels. A
> > > catch block should throw or log, not both. This is an anti-pattern and
> > > annoying as the end user: having to deal with multiple stack traces at
> > > different log levels for the same error condition. The log message
> > should
> > > be at the highest level only.
> > >
> > > https://community.oracle.com/docs/DOC-983543#logAndThrow
> > >
> > > Both projects use SLF4J as the logging framework (facade anyway).
> Please
> > > familiarize yourself with how to correctly log an Exception. There is
> no
> > > need to log a thread name, a time stamp, a class name, or a stack
> trace.
> > > The logging framework will do that all for you.
> > >
> > > http://www.slf4j.org/faq.html#paramException
> > >
> > > Again, there is no need to 'stringify' an exception. For example, do
> not
> > > use this:
> > >
> > >
> > >
> >
> https://github.com/apache/hadoop/blob/trunk/hadoop-common-project/hadoop-common/src/main/java/org/apache/hadoop/util/StringUtils.java#L86
> > >
> > >
> > > If you do however want to dump a stack trace for debugging (or trace)
> > > purposes, consider performing the following:
> > >
> > > if (LOG.isDebugEnabled()) {
> > > LOG.debug("Dump Thread Stack", new Exception("Thread Stack Trace (Not
> > an
> > > Error)"));
> > > }
> > >
> > > Finally, I've seen it a couple of times in Apache project that enabling
> > > debug-level logging causes the application to emit logs at other
> levels,
> > > for example:
> > >
> > > LOG.warn("Some error occurred: {}", e.getMessage());
> > > if (LOG.isDebugEnabled()) {
> > > LOG. warn("Dump Warning Thread Stack", e);
> > > }
> > >
> > > Please refrain from doing this. The inner log statement should be at
> > DEBUG
> > > level to match the check. Otherwise, when I enable DEBUG logging in
> the
> > > application, the expectation that I have is that I will have the exact
> > > logging as the INFO level, but I will also have additional DEBUG
> details
> > as
> > > well. I am going to be using 'grep' to find DEBUG and I will miss this
> > > additional logging. I will then be peeved when I say "ah ha! It's a
> WARN
> > > log message, I don't need DEBUG enabled to get this logging when the
> > issue
> > > happens again!"... but then I restart the application and discover I do
> > in
> > > fact need DEBUG logging enabled.
> > >
> > > Finally, finally, do not pass server-generated stack traces to a client
> > > application. When a client dumps a stack trace, it is not always
> trivial
> > > to decide if the stack trace is in regards to the client or the server.
> > > This can also be a security issue as it may hint to the client which
> > > libraries and (based on line numbers) which versions of the libraries
> are
> > > being used. If the server is going to generate an error in response
> to a
> > > client API call, the server should log the exception (right before
> > > returning the response to the client) and it should only pass a helpful
> > > error message to the client. The operator/administrator can look in the
> > > server logs for the details.
> > >
> > > Thanks!
> > >
> >
>
