aka When does a final field change?
Background
jSuneido limits how long a database update transaction can be active. This is because active update transactions consume resources.
Read-only transactions consume little resources and are not limited. (This is a benefit of the append-only database structure.)
There are two parts to the limiting. If an update transaction commits and it was active more than a certain amount of time (currently 5 seconds) then a warning is logged but otherwise the transaction completes normally.
A separate process runs periodically (currently once per second) and any update transactions that have been active for too long (default 10 seconds) are aborted. A PriorityQueue is used for this so that only the longest running update transaction needs to be looked at.
Problem
Recently I noticed that some of our customers were getting the warning, but the duration given was well over the abort limit. That should have been impossible - the transactions should have been aborted before they reached that point. My first thought was that I had "broken" it with some recent change. But going back through the logs it looked like this had been happening for quite a while.
Searching the logs, I found that there were some transactions getting aborted due to duration, so that part of the code was working at least some of the time.
I added some debugging and found that the problem was that PriorityQueue peek was not returning the oldest transaction. That seemed impossible since by definition PriorityQueue peek returns the smallest element.
I checked my comparator but it was simple and seemed correct. I wrote some equivalent test code and it worked fine.
I started searching on the internet to see if anyone else had run into similar problems. Sure enough they had, but the reason was that they had been modifying the elements after inserting them. (Similar to problems if you modify elements after inserting into hash tables.)
But the field I was ordering by was final so it couldn't be modified.
Or could it? A final field still has to get set at some point. Sure enough, I was inserting the transactions into the queue in the super constructor, which ran before the field was initialized. So the queue insertion was always seeing a value of zero and the order was undefined. Argh!
(Java normally prevents this kind of problem, but I was casting to a derived class in code called by a base class constructor. Moral of the story - avoid tricky code!)
In case you're wondering, I had tested. But it worked when testing since I would only have a single active transaction, and the order was irrelevant.
It was an easy fix to reorganize the code slightly to ensure the queue insertion was done after the field was initialized. (Although that splits what used to be a single synchronized method into two, which makes me nervous about concurrency problems. I think it's ok, hopefully it won't be the subject of a future blog post!)
Background
jSuneido limits how long a database update transaction can be active. This is because active update transactions consume resources.
Read-only transactions consume little resources and are not limited. (This is a benefit of the append-only database structure.)
There are two parts to the limiting. If an update transaction commits and it was active more than a certain amount of time (currently 5 seconds) then a warning is logged but otherwise the transaction completes normally.
A separate process runs periodically (currently once per second) and any update transactions that have been active for too long (default 10 seconds) are aborted. A PriorityQueue is used for this so that only the longest running update transaction needs to be looked at.
Problem
Recently I noticed that some of our customers were getting the warning, but the duration given was well over the abort limit. That should have been impossible - the transactions should have been aborted before they reached that point. My first thought was that I had "broken" it with some recent change. But going back through the logs it looked like this had been happening for quite a while.
Searching the logs, I found that there were some transactions getting aborted due to duration, so that part of the code was working at least some of the time.
I added some debugging and found that the problem was that PriorityQueue peek was not returning the oldest transaction. That seemed impossible since by definition PriorityQueue peek returns the smallest element.
I checked my comparator but it was simple and seemed correct. I wrote some equivalent test code and it worked fine.
I started searching on the internet to see if anyone else had run into similar problems. Sure enough they had, but the reason was that they had been modifying the elements after inserting them. (Similar to problems if you modify elements after inserting into hash tables.)
But the field I was ordering by was final so it couldn't be modified.
Or could it? A final field still has to get set at some point. Sure enough, I was inserting the transactions into the queue in the super constructor, which ran before the field was initialized. So the queue insertion was always seeing a value of zero and the order was undefined. Argh!
(Java normally prevents this kind of problem, but I was casting to a derived class in code called by a base class constructor. Moral of the story - avoid tricky code!)
In case you're wondering, I had tested. But it worked when testing since I would only have a single active transaction, and the order was irrelevant.
It was an easy fix to reorganize the code slightly to ensure the queue insertion was done after the field was initialized. (Although that splits what used to be a single synchronized method into two, which makes me nervous about concurrency problems. I think it's ok, hopefully it won't be the subject of a future blog post!)
No comments:
Post a Comment