Win a copy of The Little Book of Impediments (e-book only) this week in the Agile and Other Processes forum!
  • Post Reply
  • Bookmark Topic Watch Topic
  • New Topic

Weird rollback behaviour

 
Santiago Conde
Greenhorn
Posts: 16
  • Mark post as helpful
  • send pies
  • Quote
  • Report post to moderator
Hello all

I'm suffering a strange behaviour using transactions. The enviroment is:
  • Java 1.3.1 (not under my control)
  • JDBC driver: IBM provided for connecting to DB2 in a AS/400
  • Using struts with autocommit = false.

  • Problem:
    The database state is inconsistent with the fact that a rollback was made. The code structure is more or less this... (not real code, just the skeleton)



    The points before every "point" include some information.
    The case is that the log string -written after the finally block- shows the following flow:

    ...point 1 - General Error - beginning rollback - ...point 2 - ...point 3 - SQLError in finally

    and just one second later

    ...point 1 - General Error - beginning rollback - ...point 2 - ...point 3 - SQLError in finally - begging commit - finishing commit

    And I wonder what's happening here? The program flow goes inside the catch clause, begin the rollback, GO BACK inside the try clause, never reach the line with the text " finishing rollback " - I figure out just because the second exception arise - and then, ONE SECOND LATER, do the very same trip with the addition that it makes the commit !?

    I have two different occurences of this.

    Final note: if you're wondering about the logging mechanism I only can say that it wasn't my fault. The boss just ask me to explain it, no more.

    Perhaps this doesn't have anything to do with JDBC transactions or stuff like that, and more with a poorly java implementation. Right now I'm confused. If anybody has any idea about where could the problem be, I will be very grateful.

    Thanks for your time
    Santi
     
    David Harkness
    Ranch Hand
    Posts: 1646
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    Since the message doesn't contain "Beginning rollback," I assume it's not issuing the rollback. Instead, I think that everythingOk is being set true in the try block, but one of the SQL statements before commit is failing (otherwise "beginning commit" would be in message).

    Since everythingOk is still set, the rollback is bypassed, and the close() call seems to be causing the exception. However, since you aren't printing the stack traces, you're throwing away your best clues.

    I suspect there are deeper logic issues at work here combined with a failing SQL statement. I don't know what (short of communication error) would make close() fail, though.
     
    Jeanne Boyarsky
    author & internet detective
    Marshal
    Posts: 35279
    384
    Eclipse IDE Java VI Editor
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    Santiago,
    I agree with David that you need the stack traces.

    The whole everythingOk boolean is a bit odd though. Why don't you just do the rollback in the catch block?
     
    Santiago Conde
    Greenhorn
    Posts: 16
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    David, Jeanne

    First of all, thanks for sharing your reflections. About the stack trace, like I said before, this is a problem "inside an envelope", that is, I have the code and the message log, but no way to change the code nor the deployment configuration. My "mission" is just giving a explanation to my boss. Kinda of a riddle.

    Said this, back to the question; the message does contain the "beggining rollback" string. In fact, this is the origin of my puzzlement. It's IN THE MIDDLE of the log string. If I understood the flow implicit in the log correctly, this implies that the program jumped to the catch block, went to the finally block, began the rollback, RETURNED to the try block, executed the rest of the instructions and then went inside the catch block of the second try...

    This goes against all my knowledge about the logic flow in Java... and I was wondering if it would have to do with some exotic behaviour of IBM drivers doing rollbacks, or with astral conjuntions or... who knows!

    The principle about the simpler explanation is the most probable one says to me that the problem is consecuence of a bad design and a bad code implementation. Patch over patch, etc etc.

    So, if there's no obvious reason which explain this behaviour, the recomendation to my boss will be almost what you have said: "see the stack trace and the answer will be there (more or less)". Apart from that, I can't say much more.

    Thanks again, and take care
    Santi
     
    David Harkness
    Ranch Hand
    Posts: 1646
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    I love a good puzzle, but it's no fun if you don't know if you have the right pieces. Is that the exact output from those txt variables? I ask because the code doesn't have any " - " seperators, yet they appear in the log.

    Also, is each full run output in the log atomically? Might we see interleaved log messages? I doubt that's the case since it's building a String and I asume printing it as a single String so it shouldn't be broken apart.

    Interesting nonetheless.
     
    Santiago Conde
    Greenhorn
    Posts: 16
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    David

    I completely agree with you about having the right pieces, and that's the reason why I feel a bit dissapointed with this task. Anyway, I also thought, like you did, about the string being 'concatenated' through several runs, but it is initialized at the very beginning of the method so I can't imagine how it could be happenning.

    About the exact text in the log string, the answer is no, this is not the real output; I have made a schema for depict the problem. The real code is far more complex (1600 lines of code). That's why I say that the root of the problem will likely be hidden behind all those lines... (and you can't figure the bad code/design style they have). But you are right when you think that the string is being constructed in several steps and showed at the end of the method.

    Well, I have no hope of giving a rational explanation to this without more information. My advices to the next programmer who had to fight with this will be: put the rollback inside every catch block and look closely to the stack trace (changing the way the errors are logged right now).

    Thanks a lot for your time and your opinions. I didn't know if I was missing something here, but now I'm more confident in my diagnose.

    Santi
     
    David Harkness
    Ranch Hand
    Posts: 1646
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    Well, sometimes validation is all the help we need.

    I can't help but thinking that the txt variable is actually an instance variable (not local to the method doing this big query), and multiple threads are using the same instance. If this were the case, the log messages would be interleaved.

    The random indentation style (sometimes 2 spaces, sometimes 4) is enough to convnce me you're right that it's a poor coding issue. Heck, what bug isn't?
     
    Adeel Ansari
    Ranch Hand
    Posts: 2874
    • Mark post as helpful
    • send pies
    • Quote
    • Report post to moderator
    Originally posted by David Harkness:
    I love a good puzzle, but it's no fun if you don't know if you have the right pieces.


    Very well said.
     
    • Post Reply
    • Bookmark Topic Watch Topic
    • New Topic