You are viewing a plain text version of this content. The canonical link for it is here.
Posted to dev@jackrabbit.apache.org by Christoph Kiehl <ck...@sulu3000.de> on 2007/08/09 01:05:00 UTC

Logging of exceptions

Hi,

while preparing the testcase for JCR-1039 I found a construct like this:

protected synchronized NodePropBundle loadBundle(NodeId id)
         throws ItemStateException {
     [...]
     } catch (Exception e) {
         String msg = "failed to read bundle: " + id + ": " + e;
         log.error(msg);
         throw new ItemStateException(msg, e);
     } finally {
     [...]
}

In the calling method the exception is handled like this:

private boolean hasNonVirtualItemState(ItemId id) {
     [...]
     } catch (ItemStateException ise) {
         return false;
     }
     [...]
}

The result is that you will never find the root cause "e" in the log. 
This makes it hard to diagnose bugs without using a debugger or 
modifying the source code.
I would suggest to use log.error(msg, e) instead of log.error(msg). I 
would even consider log.error(msg) to be harmful since there is almost 
always an exception which should be logged if you use log.error().
WDYT?

Cheers,
Christoph


Re: Logging of exceptions

Posted by Christoph Kiehl <ch...@sulu3000.de>.
Felix Meschberger wrote:

> Makes absolute sense, except for throwing the RuntimeException as you
> noted in your own follow-up.
> 
> And yes, I agree, this would require a big code review. On the other
> hand taking the pragmatic approach of fixing those places one after the
> other as the issues are encountered is probably the more feasible
> approach ...

Well, if the logging is removed from loadBundle() we would have to change all 
callers. Otherwise we might end up with exception not be logged at all.

But I like Thomas approach better anyway ;)

Cheers,
Christoph


Re: Logging of exceptions

Posted by Felix Meschberger <fm...@gmail.com>.
Hi,

Makes absolute sense, except for throwing the RuntimeException as you
noted in your own follow-up.

And yes, I agree, this would require a big code review. On the other
hand taking the pragmatic approach of fixing those places one after the
other as the issues are encountered is probably the more feasible
approach ...

Regards
Felix

Am Donnerstag, den 09.08.2007, 09:20 +0200 schrieb Christoph Kiehl:
> Felix Meschberger wrote:
> 
> > I agree, that the cause must not be lost. But rather than logging the
> > cause inside loadBundle (in this case), I suggest the
> > hasNonVirtualItemState method should not ignore the exception and log
> > it.
> > 
> > IMHO, if an exception is thrown, the same message should not be logged
> > by the thrower, because the thrower already informs about the situation.
> > Rather the catcher of the exception should handle it by logging or
> > rethrowing.
> > 
> > The problem on the other hand is, that ItemStateException does not
> > always relate a problem: Sometime it is thrown IIRC if an item state is
> > just not availabel and sometimes - as here - it is thrown as a
> > consequence of a possibly real problem.... This distinction can probably
> > not be made by the catcher of the exception ....
> 
> You are absolutely right. I was a bit puzzled because of reasons you 
> mentioned in your last paragraph and thought only the thrower knows 
> whether logging is needed or not.
> 
> But giving it another look I think if the item state is not available a 
> NoSuchItemStateException should be thrown (which is the case in the 
> places I looked at) which is a subclass of ItemStateException. So it 
> would be possible for SharedItemStateManager to distinguish between "not 
> found" and "problem".
> 
> Maybe the following:
> 
> private boolean hasNonVirtualItemState(ItemId id) {
>       [...]
>       } catch (ItemStateException ise) {
>           return false;
>       }
>       [...]
> }
> 
> should be rewritten to:
> 
> private boolean hasNonVirtualItemState(ItemId id) {
>       [...]
>       } catch (NoSuchItemStateException ise) {
>           return false;
>       } catch (ItemStateException ise) {
>           log.error(ise.getMessage(), ise);
>           throw new RuntimeException(ise);
>       }
>       [...]
> }
> 
> And then of course the logging could be removed from this snippet:
> 
> protected synchronized NodePropBundle loadBundle(NodeId id)
>           throws ItemStateException {
>       [...]
>       } catch (Exception e) {
>           String msg = "failed to read bundle: " + id + ": " + e;
>           log.error(msg);
>           throw new ItemStateException(msg, e);
>       } finally {
>       [...]
> }
> 
> to
> 
> protected synchronized NodePropBundle loadBundle(NodeId id)
>           throws ItemStateException {
>       [...]
>       } catch (Exception e) {
>           String msg = "failed to read bundle: " + id + ": ";
>           throw new ItemStateException(msg, e);
>       } finally {
>       [...]
> }
> 
> But I'm afraid that this might become a big change and a lot of code 
> needs to reviewed and checked.
> 
> Cheers,
> Christoph
> 


Re: Logging of exceptions

Posted by Christoph Kiehl <ch...@sulu3000.de>.
Thomas Mueller wrote:

> Exceptions should never be used for orinary control flow (see also
> "Effective Java" page 170). My suggestion would be:
> 
> SharedItemStateManager.java,
>     private boolean hasNonVirtualItemState(ItemId id) throws
> ItemStateException {
> ...
>         if (id.denotesNode()) {
>             return persistMgr.exists((NodeId) id);
>         } else {
>             return persistMgr.exists((PropertyId) id);
>         }
>     }
> 
> This would be even a bigger change, but I think it would be the most
> logical solution.

Looks like the best solution so far, but I'm not sure which consequences this 
has. I'll try to change the method as proposed and report. But this might take a 
day or two because I'm quite busy at work right now. If someone else wants to 
give it a shot ...

Cheers,
Christoph


Re: Logging of exceptions

Posted by Thomas Mueller <th...@gmail.com>.
Hi,

Exceptions should never be used for orinary control flow (see also
"Effective Java" page 170). My suggestion would be:

SharedItemStateManager.java,
    private boolean hasNonVirtualItemState(ItemId id) throws
ItemStateException {
...
        if (id.denotesNode()) {
            return persistMgr.exists((NodeId) id);
        } else {
            return persistMgr.exists((PropertyId) id);
        }
    }

This would be even a bigger change, but I think it would be the most
logical solution.

Thomas


On 8/9/07, Christoph Kiehl <ck...@sulu3000.de> wrote:
> Christoph Kiehl wrote:
>
> > Maybe the following:
> >
> > private boolean hasNonVirtualItemState(ItemId id) {
> >      [...]
> >      } catch (ItemStateException ise) {
> >          return false;
> >      }
> >      [...]
> > }
> >
> > should be rewritten to:
> >
> > private boolean hasNonVirtualItemState(ItemId id) {
> >      [...]
> >      } catch (NoSuchItemStateException ise) {
> >          return false;
> >      } catch (ItemStateException ise) {
> >          log.error(ise.getMessage(), ise);
> >          throw new RuntimeException(ise);
> >      }
> >      [...]
> > }
>
> Well, maybe throwing a RepositoryException instead of a RuntimeException
> would be more appropriate ;)
>
> Cheers,
> Christoph
>
>

Re: Logging of exceptions

Posted by Christoph Kiehl <ck...@sulu3000.de>.
Christoph Kiehl wrote:

> Maybe the following:
> 
> private boolean hasNonVirtualItemState(ItemId id) {
>      [...]
>      } catch (ItemStateException ise) {
>          return false;
>      }
>      [...]
> }
> 
> should be rewritten to:
> 
> private boolean hasNonVirtualItemState(ItemId id) {
>      [...]
>      } catch (NoSuchItemStateException ise) {
>          return false;
>      } catch (ItemStateException ise) {
>          log.error(ise.getMessage(), ise);
>          throw new RuntimeException(ise);
>      }
>      [...]
> }

Well, maybe throwing a RepositoryException instead of a RuntimeException 
would be more appropriate ;)

Cheers,
Christoph


Re: Logging of exceptions

Posted by Christoph Kiehl <ck...@sulu3000.de>.
Felix Meschberger wrote:

> I agree, that the cause must not be lost. But rather than logging the
> cause inside loadBundle (in this case), I suggest the
> hasNonVirtualItemState method should not ignore the exception and log
> it.
> 
> IMHO, if an exception is thrown, the same message should not be logged
> by the thrower, because the thrower already informs about the situation.
> Rather the catcher of the exception should handle it by logging or
> rethrowing.
> 
> The problem on the other hand is, that ItemStateException does not
> always relate a problem: Sometime it is thrown IIRC if an item state is
> just not availabel and sometimes - as here - it is thrown as a
> consequence of a possibly real problem.... This distinction can probably
> not be made by the catcher of the exception ....

You are absolutely right. I was a bit puzzled because of reasons you 
mentioned in your last paragraph and thought only the thrower knows 
whether logging is needed or not.

But giving it another look I think if the item state is not available a 
NoSuchItemStateException should be thrown (which is the case in the 
places I looked at) which is a subclass of ItemStateException. So it 
would be possible for SharedItemStateManager to distinguish between "not 
found" and "problem".

Maybe the following:

private boolean hasNonVirtualItemState(ItemId id) {
      [...]
      } catch (ItemStateException ise) {
          return false;
      }
      [...]
}

should be rewritten to:

private boolean hasNonVirtualItemState(ItemId id) {
      [...]
      } catch (NoSuchItemStateException ise) {
          return false;
      } catch (ItemStateException ise) {
          log.error(ise.getMessage(), ise);
          throw new RuntimeException(ise);
      }
      [...]
}

And then of course the logging could be removed from this snippet:

protected synchronized NodePropBundle loadBundle(NodeId id)
          throws ItemStateException {
      [...]
      } catch (Exception e) {
          String msg = "failed to read bundle: " + id + ": " + e;
          log.error(msg);
          throw new ItemStateException(msg, e);
      } finally {
      [...]
}

to

protected synchronized NodePropBundle loadBundle(NodeId id)
          throws ItemStateException {
      [...]
      } catch (Exception e) {
          String msg = "failed to read bundle: " + id + ": ";
          throw new ItemStateException(msg, e);
      } finally {
      [...]
}

But I'm afraid that this might become a big change and a lot of code 
needs to reviewed and checked.

Cheers,
Christoph


Re: Logging of exceptions

Posted by Felix Meschberger <fm...@gmail.com>.
Hi,

I agree, that the cause must not be lost. But rather than logging the
cause inside loadBundle (in this case), I suggest the
hasNonVirtualItemState method should not ignore the exception and log
it.

IMHO, if an exception is thrown, the same message should not be logged
by the thrower, because the thrower already informs about the situation.
Rather the catcher of the exception should handle it by logging or
rethrowing.

The problem on the other hand is, that ItemStateException does not
always relate a problem: Sometime it is thrown IIRC if an item state is
just not availabel and sometimes - as here - it is thrown as a
consequence of a possibly real problem.... This distinction can probably
not be made by the catcher of the exception ....

Regards
Felix

Am Donnerstag, den 09.08.2007, 01:05 +0200 schrieb Christoph Kiehl:
> Hi,
> 
> while preparing the testcase for JCR-1039 I found a construct like this:
> 
> protected synchronized NodePropBundle loadBundle(NodeId id)
>          throws ItemStateException {
>      [...]
>      } catch (Exception e) {
>          String msg = "failed to read bundle: " + id + ": " + e;
>          log.error(msg);
>          throw new ItemStateException(msg, e);
>      } finally {
>      [...]
> }
> 
> In the calling method the exception is handled like this:
> 
> private boolean hasNonVirtualItemState(ItemId id) {
>      [...]
>      } catch (ItemStateException ise) {
>          return false;
>      }
>      [...]
> }
> 
> The result is that you will never find the root cause "e" in the log. 
> This makes it hard to diagnose bugs without using a debugger or 
> modifying the source code.
> I would suggest to use log.error(msg, e) instead of log.error(msg). I 
> would even consider log.error(msg) to be harmful since there is almost 
> always an exception which should be logged if you use log.error().
> WDYT?
> 
> Cheers,
> Christoph
>