castor
  1. castor
  2. CASTOR-1642

Exception during marshalling not unreported

    Details

    • Type: Bug Bug
    • Status: Closed Closed
    • Priority: Critical Critical
    • Resolution: Fixed
    • Affects Version/s: 1.0.3, 1.0.4
    • Fix Version/s: 1.0.5
    • Component/s: XML
    • Labels:
      None
    • Testcase included:
      yes
    • Number of attachments :
      4

      Description

      If an Exception occurs in the getValue of a field during marshalling, it is hidden in a catch with no logging and exception. For example, if an exception if thrown with the value for field "name" is gotten with "getValue", it is wrapped in an InvocationTargetException (from the invocation using reflection) and then in a CastorInvalidStateException (see FieldHandlerImpl.java:454 and 458).

      When the CastorInvalidStateException gets back to the Marshaller, it is squashed completely on line 1716:

      try

      { obj = elemDescriptor.getHandler().getValue(object); }

      catch(IllegalStateException ise)

      { continue; }

      In one case, my getXXX method did a DB query, which failed but there was nothing reported. In another case, there was a class loading problem, and again, nothing was reported.

      I think at least a error log of some sort is required. I would prefer to see a MarshallingException thrown, wrapping the original Exception.

      1. CastorExceptionTest.java
        1 kB
        Paul Philion
      2. CastorExceptionTest.xml
        0.4 kB
        Paul Philion
      3. marshal-exception-patch.txt
        1 kB
        Paul Philion
      4. marshaller-logging-patch.txt
        8 kB
        Paul Philion

        Issue Links

          Activity

          Hide
          Paul Philion added a comment -

          Adding a patch.

          I'm not sure if anyone relies on the "Skip if error" behavior for marshaling: To me is seems "bad" is it could result in invalid XML. Thus I would prefer to see an exception. If I had to set a flag to get that behavior, that would be fine.

          Show
          Paul Philion added a comment - Adding a patch. I'm not sure if anyone relies on the "Skip if error" behavior for marshaling: To me is seems "bad" is it could result in invalid XML. Thus I would prefer to see an exception. If I had to set a flag to get that behavior, that would be fine.
          Hide
          Werner Guttmann added a comment -

          Moving this to 1.0.5, as I won't be accepting any new issues for 1.0.4 anymore ..

          Show
          Werner Guttmann added a comment - Moving this to 1.0.5, as I won't be accepting any new issues for 1.0.4 anymore ..
          Hide
          Werner Guttmann added a comment -

          Paul, can you please attach all relevant classes that I need to be able to fully replay your problem ?

          Show
          Werner Guttmann added a comment - Paul, can you please attach all relevant classes that I need to be able to fully replay your problem ?
          Hide
          Paul Philion added a comment -

          Werner: That's a little tricky. The original problem spawned from having the wrong version of a JAR in the classpath. The object being marshaled depended on an object that was not in the deployed JAR: When the object was marshaled, the getXXX failed because the dependent class could not be loaded (ClassNotFoundError). The only difference we saw was that the object was no longer marshaled, but no errors occurred in the logs.

          Show
          Paul Philion added a comment - Werner: That's a little tricky. The original problem spawned from having the wrong version of a JAR in the classpath. The object being marshaled depended on an object that was not in the deployed JAR: When the object was marshaled, the getXXX failed because the dependent class could not be loaded (ClassNotFoundError). The only difference we saw was that the object was no longer marshaled, but no errors occurred in the logs.
          Hide
          Werner Guttmann added a comment -

          Any chances of coming up with a 'fake' setup ?

          Show
          Werner Guttmann added a comment - Any chances of coming up with a 'fake' setup ?
          Hide
          Paul Philion added a comment -

          That's what I tried to do with the test case. The only other alternative is to create two extra jars: One that contains the special marshaling class, that depends on a class in the second JAR. Then, deploy the first JAR without the second.

          I could try Class.forName("xyz.doesnot.Exist"); but that's about the same just throwing the exception. Does that make a difference?

          Show
          Paul Philion added a comment - That's what I tried to do with the test case. The only other alternative is to create two extra jars: One that contains the special marshaling class, that depends on a class in the second JAR. Then, deploy the first JAR without the second. I could try Class.forName("xyz.doesnot.Exist"); but that's about the same just throwing the exception. Does that make a difference?
          Hide
          Niall Smart added a comment -

          I posted on this problem on castor-user a few days ago:

          http://archive.castor.codehaus.org/user/5cacbc920610200401i5ea7b147o7e02e0339fca34f5%40mail.gmail.com

          You can see the problem by just serializing a class that throws an exception, e.g.:

          public class SomeObject {
          public String getName()

          { throw new UnsupportedOperationException("TODO"); }

          }

          The exception is silently ignored - FieldHandlerImpl wraps the InvocationTargetException in an
          IllegalStateException which is simply ignored by Marshaller.marshall() i.e.
          try { } catch

          { continue; }
          Show
          Niall Smart added a comment - I posted on this problem on castor-user a few days ago: http://archive.castor.codehaus.org/user/5cacbc920610200401i5ea7b147o7e02e0339fca34f5%40mail.gmail.com You can see the problem by just serializing a class that throws an exception, e.g.: public class SomeObject { public String getName() { throw new UnsupportedOperationException("TODO"); } } The exception is silently ignored - FieldHandlerImpl wraps the InvocationTargetException in an IllegalStateException which is simply ignored by Marshaller.marshall() i.e. try { } catch { continue; }
          Hide
          Werner Guttmann added a comment -

          Thanks, Niall.

          Show
          Werner Guttmann added a comment - Thanks, Niall.
          Hide
          Werner Guttmann added a comment -

          I agree that the exception thrown should not be caught and silently disposed. What we have to find out is as to why things have been coded like this ? I just cannot believe that this is an oversight. It it was coded like this on intention, I'd at least try to understand the motives behind this decision.

          Show
          Werner Guttmann added a comment - I agree that the exception thrown should not be caught and silently disposed. What we have to find out is as to why things have been coded like this ? I just cannot believe that this is an oversight. It it was coded like this on intention , I'd at least try to understand the motives behind this decision.
          Hide
          Stephen Bash added a comment -

          I can't comment on the history of the code, but I do want to tie this back to other issues we've seen over the last year. While not exactly the same, this issue is analogous to the validation exception handling during unmarshalling. My feeling right now is there is no one policy that will make everyone happy (in either case), so this might be a good excuse to introduce an ErrorHandlingStrategy object/interface to the Castor framework (based on the Strategy pattern if it wasn't obvious).

          Show
          Stephen Bash added a comment - I can't comment on the history of the code, but I do want to tie this back to other issues we've seen over the last year. While not exactly the same, this issue is analogous to the validation exception handling during unmarshalling. My feeling right now is there is no one policy that will make everyone happy (in either case), so this might be a good excuse to introduce an ErrorHandlingStrategy object/interface to the Castor framework (based on the Strategy pattern if it wasn't obvious).
          Hide
          Paul Philion added a comment -

          It looks like that code has been there since the initial version (rev #3636, 3/2/03). Looking closer at the marshal() method, it looks like there are other cases where exceptions are silently disposed, and have been there from the beginning.

          I suspect the problem has always been there, but that as most usage of the Marshaller (of Castor in general) has been very simple "bean getting": Simple get methods backed by simple fields. In that case, exceptions are rare. In my use case, I am using deferred initialization to populate fields from remote data stores: I don't want to populate unless the data is actually requested (and the bean itself is acting as a cache or deferred DAO). Thus, being silent about exceptions during the marshal is destructive.

          I suggest adding some logging at first. However, Castor doesn't really use logging right now, so I'm not sure what to suggest other then System.err.

          If Castor is planning to move to a logging framework (I don't can which one), then please use that to add ERROR logs. If not, then use System.err to write the except condition for any suppressed exception in marshal.

          I would still prefer to see the actual exception (wrapped in a MarshalException, of course), but I really need to see error logs.

          Show
          Paul Philion added a comment - It looks like that code has been there since the initial version (rev #3636, 3/2/03). Looking closer at the marshal() method, it looks like there are other cases where exceptions are silently disposed, and have been there from the beginning. I suspect the problem has always been there, but that as most usage of the Marshaller (of Castor in general) has been very simple "bean getting": Simple get methods backed by simple fields. In that case, exceptions are rare. In my use case, I am using deferred initialization to populate fields from remote data stores: I don't want to populate unless the data is actually requested (and the bean itself is acting as a cache or deferred DAO). Thus, being silent about exceptions during the marshal is destructive. I suggest adding some logging at first. However, Castor doesn't really use logging right now, so I'm not sure what to suggest other then System.err. If Castor is planning to move to a logging framework (I don't can which one), then please use that to add ERROR logs. If not, then use System.err to write the except condition for any suppressed exception in marshal. I would still prefer to see the actual exception (wrapped in a MarshalException, of course), but I really need to see error logs.
          Hide
          Werner Guttmann added a comment -

          Paul, unfortunately, the 'initial' version you've been looking at is the initial version after a server crash at Intalio. There's a second SVN repo that holds all the code pre-crash. Anyhow, I do agree that you'll be getting log entries at least. It is somewhat true that Castor does not properly use a logging framework, but that can (and should) be changed easily. Having said that, Castor JDO already uses commons-logging (with log4j in the back), so why not start using it consistently with Castor XML as well.

          Re: exception handling (and propagation), I think that Stephen's suggestion above points in the right direction. This is a strategy we'll be using to introduce the same mechanism (selective error handling) to the Castor XML code generator. Me thinks we should be doing the same for the (un-)marshalling part of Castor.

          Having said that, Stephen, how would you feel if I asked you to come up with an initial design of such an approach. Nothing in detail, just an initial contract ?

          Show
          Werner Guttmann added a comment - Paul, unfortunately, the 'initial' version you've been looking at is the initial version after a server crash at Intalio. There's a second SVN repo that holds all the code pre-crash. Anyhow, I do agree that you'll be getting log entries at least. It is somewhat true that Castor does not properly use a logging framework, but that can (and should) be changed easily. Having said that, Castor JDO already uses commons-logging (with log4j in the back), so why not start using it consistently with Castor XML as well. Re: exception handling (and propagation), I think that Stephen's suggestion above points in the right direction. This is a strategy we'll be using to introduce the same mechanism (selective error handling) to the Castor XML code generator. Me thinks we should be doing the same for the (un-)marshalling part of Castor. Having said that, Stephen, how would you feel if I asked you to come up with an initial design of such an approach. Nothing in detail, just an initial contract ?
          Hide
          Paul Philion added a comment -

          Werner: Sounds like a good approach. Let me know if there is any way I can assist. For example, I would be happy to add the logger to Marshaller and the log statements where ever I see a "silenced exception".

          I also assume that the existing debug stuff will be going away: I would be happy to submit a patch for that as well.

          Show
          Paul Philion added a comment - Werner: Sounds like a good approach. Let me know if there is any way I can assist. For example, I would be happy to add the logger to Marshaller and the log statements where ever I see a "silenced exception". I also assume that the existing debug stuff will be going away: I would be happy to submit a patch for that as well.
          Hide
          Werner Guttmann added a comment -

          Now, if you removed the current logging vehicle form all classes and replaced it with commons-logging, that would be absolutely brilliant. Please bear in mind that I do not have any idea about the size of this task .. ;-(

          Show
          Werner Guttmann added a comment - Now, if you removed the current logging vehicle form all classes and replaced it with commons-logging, that would be absolutely brilliant. Please bear in mind that I do not have any idea about the size of this task .. ;-(
          Hide
          Paul Philion added a comment -

          Yes, that would be brilliant... There are 236 references to System.out in 54 files in src/main/java, and 9 reverences to System.err in 8 files.

          I could do it (I'm happy to), but it would be a really big patch file.

          Show
          Paul Philion added a comment - Yes, that would be brilliant... There are 236 references to System.out in 54 files in src/main/java, and 9 reverences to System.err in 8 files. I could do it (I'm happy to), but it would be a really big patch file.
          Hide
          Werner Guttmann added a comment -

          Given that it always has been damn hard to integrate big patches, I think we should split this up by e.g. package. One could create sub-tasks for individual packages, and address them one by one.

          Show
          Werner Guttmann added a comment - Given that it always has been damn hard to integrate big patches, I think we should split this up by e.g. package. One could create sub-tasks for individual packages, and address them one by one.
          Hide
          Paul Philion added a comment -

          I will do the logging for the Marshaller class and add that patch to this ticket. I will base it on the logging setup in the JDO code. I will:
          1) Replace System.out with LOG.debug, wrapping in if (LOG.isDebugEnabled()) {} as necessary.
          2) Add LOG.warn to silenced exceptions, unless the code indicated that an exception is "ok", in which case I will add a LOG.debug.
          3) Remove references to enableDebug and _debug.

          I will move on to add the logging to other classes, on a package by package basis, as I have time. I will open another ticket for those patches.

          Show
          Paul Philion added a comment - I will do the logging for the Marshaller class and add that patch to this ticket. I will base it on the logging setup in the JDO code. I will: 1) Replace System.out with LOG.debug, wrapping in if (LOG.isDebugEnabled()) {} as necessary. 2) Add LOG.warn to silenced exceptions, unless the code indicated that an exception is "ok", in which case I will add a LOG.debug. 3) Remove references to enableDebug and _debug. I will move on to add the logging to other classes, on a package by package basis, as I have time. I will open another ticket for those patches.
          Hide
          Werner Guttmann added a comment -

          Sounds good to me ....

          Show
          Werner Guttmann added a comment - Sounds good to me ....
          Hide
          Paul Philion added a comment -

          Uploaded patch to add Commons logging to Marshaller.java.

          Show
          Paul Philion added a comment - Uploaded patch to add Commons logging to Marshaller.java.
          Hide
          Werner Guttmann added a comment -

          Committed patch as is, adding a new category for 'org.exolab.castor.xml' to src/bugs/log4j.xml as well.

          Show
          Werner Guttmann added a comment - Committed patch as is, adding a new category for 'org.exolab.castor.xml' to src/bugs/log4j.xml as well.
          Hide
          Werner Guttmann added a comment -

          Paul, all future patches that switch logging to commons-logging should be attached to a new sub-task created off this issue. In addition, I think you should create a new issue with regards to the discussion about an error handling strategy as well, so that this issue can remain closed. Thanks in advance ...

          Show
          Werner Guttmann added a comment - Paul, all future patches that switch logging to commons-logging should be attached to a new sub-task created off this issue. In addition, I think you should create a new issue with regards to the discussion about an error handling strategy as well, so that this issue can remain closed. Thanks in advance ...
          Hide
          Werner Guttmann added a comment -

          Btw, in case I have not mentioned this, your work is really appreciated .. .

          Show
          Werner Guttmann added a comment - Btw, in case I have not mentioned this, your work is really appreciated .. .
          Hide
          Werner Guttmann added a comment -

          Bulk-closing all issues assigned to 1.0.5. Please feel free to re-open any of those when required.

          Show
          Werner Guttmann added a comment - Bulk-closing all issues assigned to 1.0.5. Please feel free to re-open any of those when required.
          Hide
          Niall Smart added a comment -

          Werner

          While it is great that exceptions during marshalling will be logged instead of silently ignored I would really like the ability to have them propagated through Marshaller.marshall(). Could we keep this bug open to track that requirement?

          I accept that this is not the current behaviour, and will not necessarily suit everyone. Implementation complexity could range from a simple flag to indicate "log or propagate", through to introducing a new Marshal(Exception)Listener interface.

          In the meantime we might use a custom Log4J appender that will throw a RuntimeException for any Castor ERROR logs...crude but effective!

          Niall

          Show
          Niall Smart added a comment - Werner While it is great that exceptions during marshalling will be logged instead of silently ignored I would really like the ability to have them propagated through Marshaller.marshall(). Could we keep this bug open to track that requirement? I accept that this is not the current behaviour, and will not necessarily suit everyone. Implementation complexity could range from a simple flag to indicate "log or propagate", through to introducing a new Marshal(Exception)Listener interface. In the meantime we might use a custom Log4J appender that will throw a RuntimeException for any Castor ERROR logs...crude but effective! Niall
          Hide
          Edward Kuns added a comment -

          Better than a custom log4j appender would just be a new option to either log or log-and-throw exceptions encountered during marshaling.

          As a first step in that direction, we could add getter/setter for something like "swallowExceptions" (some better name for the same trait) which by default would be true (for backwards compatiblity). And with this first step, someone instantiating a marshaler/unmarshaler could then use the setter to make the un/marshalers log-and-throw exceptions.

          As a second step in that direction, we could add a parameter to castor.properties (perhaps) and/or castorbuilder.properties and/or some other method of doing this globally so that this setting wouldn't have to be made programmatically on each marshaler and unmarshaler.

          Best would probably be to make subtasks of this task for these steps. Thoughts?

          Show
          Edward Kuns added a comment - Better than a custom log4j appender would just be a new option to either log or log-and-throw exceptions encountered during marshaling. As a first step in that direction, we could add getter/setter for something like "swallowExceptions" (some better name for the same trait) which by default would be true (for backwards compatiblity). And with this first step, someone instantiating a marshaler/unmarshaler could then use the setter to make the un/marshalers log-and-throw exceptions. As a second step in that direction, we could add a parameter to castor.properties (perhaps) and/or castorbuilder.properties and/or some other method of doing this globally so that this setting wouldn't have to be made programmatically on each marshaler and unmarshaler. Best would probably be to make subtasks of this task for these steps. Thoughts?
          Hide
          Niall Smart added a comment -

          The custom log4j appender suggestion is a temporary hack until a better bug fix is in place (in any case it assumes commons-logging is using log4j).

          In the longer term I would prefer to see the listener pattern used instead of just a simple flag: it allows the caller more flexibility (e.g., to decide on a case by case basis whether to propagate the exception), it also allows trivial backwards compatibility by registering a default "log and do nothing" listener.

          Show
          Niall Smart added a comment - The custom log4j appender suggestion is a temporary hack until a better bug fix is in place (in any case it assumes commons-logging is using log4j). In the longer term I would prefer to see the listener pattern used instead of just a simple flag: it allows the caller more flexibility (e.g., to decide on a case by case basis whether to propagate the exception), it also allows trivial backwards compatibility by registering a default "log and do nothing" listener.
          Hide
          Werner Guttmann added a comment -

          Niall, rest assured that you requested feature will make it into Castor (possibly maybe even with 1.0.6). I like the idea of creating a separate follow-up issue where we would discuss an approach to be taken, and subsequently sub-tasks for the implementation pieces.

          Show
          Werner Guttmann added a comment - Niall, rest assured that you requested feature will make it into Castor (possibly maybe even with 1.0.6). I like the idea of creating a separate follow-up issue where we would discuss an approach to be taken, and subsequently sub-tasks for the implementation pieces.
          Hide
          Edward Kuns added a comment -

          I just created CASTOR-1691 as suggested in http://jira.codehaus.org/browse/CASTOR-1642#action_80028 – it is linked to this issue.

          Show
          Edward Kuns added a comment - I just created CASTOR-1691 as suggested in http://jira.codehaus.org/browse/CASTOR-1642#action_80028 – it is linked to this issue.
          Hide
          Werner Guttmann added a comment -

          Thanks, Edward. Exactly what we need ....

          Show
          Werner Guttmann added a comment - Thanks, Edward. Exactly what we need ... .

            People

            • Assignee:
              Werner Guttmann
              Reporter:
              Paul Philion
            • Votes:
              1 Vote for this issue
              Watchers:
              2 Start watching this issue

              Dates

              • Created:
                Updated:
                Resolved:

                Time Tracking

                Estimated:
                Original Estimate - 1 hour, 15 minutes
                1h 15m
                Remaining:
                Remaining Estimate - 1 hour, 15 minutes
                1h 15m
                Logged:
                Time Spent - Not Specified
                Not Specified