File APIs for Java Developers
Manipulate DOC, XLS, PPT, PDF and many others from your application.
The moose likes Threads and Synchronization and the fly likes values change unexpectedly due to threading issue? Big Moose Saloon
  Search | Java FAQ | Recent Topics | Flagged Topics | Hot Topics | Zero Replies
Register / Login

Win a copy of Java Interview Guide this week in the Jobs Discussion forum!
JavaRanch » Java Forums » Java » Threads and Synchronization
Bookmark "values change unexpectedly due to threading issue?" Watch "values change unexpectedly due to threading issue?" New topic

values change unexpectedly due to threading issue?

Marilyn de Queiroz

Joined: Jul 22, 2000
Posts: 9059
I'm coming across an odd issue with timestamp value are changing unexpectedly on me. It doesn't happen all the time, maybe 1 out of 1000 tickets, so it seems like it would be a threading issue but I can't find any evidence of that. The modules that this code is in only run one instance each.

Here's the pertinent code:

And here's the pertinent logs:
2009-09-08 19:23:42:INFO: Ticket #eESMr1-2613683 qualified for these metrics:
523 (2009-09-01 00:00:00.0 -> 2009-09-30 23:59:59.999) - Before offset
523 (2009-09-01 00:00:00.0 -> 2007-09-30 23:59:59.999) - After offset

or another odd example:
2009-09-08 19:27:28:INFO: Ticket #eESMr1-IBM-63434743 qualified for these metrics:
421 (2009-09-01 00:00:00.0 -> 2009-09-30 23:59:59.999) - Before offset
421 (2009-09-01 00:00:00.0 -> 2009-09-30 23:00:59.999) - After offset

and yet another:
2009-09-08 19:29:17:INFO: Ticket #eESMr1-IBM-63278713 qualified for these metrics:
421 (2009-08-01 00:00:00.0 -> 2009-08-31 23:59:59.999) - Before offset
421 (2009-09-01 00:00:00.0 -> 2009-08-31 23:59:59.999) - After offset

I've also been seeing odd Timestamp issues between when dates are stored in the qualified metric in the runBusinessClock method and when they're pulled out by something like the DeliverMetricsModule:

Pertinent code:

Pertinent logs:
MsleChange.log:2009-09-08 19:24:00:INFO: Converted reporting period time: 2009-08-01 00:00:00.0 -> 2009-08-31 23:59:59.999 for ticket #eESMr1-2601119
MsleChange.log:2009-09-08 19:25:17:INFO: - before work: 2009-09-01 00:00:00.0 -> 2009-08-31 23:59:59.999 for ticket #eESMr1-2601119 for metric #523
MsleChange.log:2009-09-08 19:25:17:INFO: - before work: 2009-08-01 00:00:00.0 -> 2009-08-31 23:59:59.999 for ticket #eESMr1-2601119 for metric #523

If anyone has any ideas what might be causing this, I could definitely use some help.


"Yesterday is history, tomorrow is a mystery, and today is a gift; that's why they call it the present." Eleanor Roosevelt
Steve Luke

Joined: Jan 28, 2003
Posts: 4181

I can't really tell what you are doing, there seems to be a lot going on and any one of the skipped steps might be the cause of the problem, but I think the error may come from the QualifiedMetric object, and/or the qualifiedMetrics collection.

The code you show for use of the TimeStamps are thread safe - they are stored as method-local variables and are passed as method parameters. So my next question would be - how does QualifiedMetric generate, store, and return those time stamps? If they are stored inside the QualifiedMetric object, rather than generated in the getDBField(...) method, and that single QualifiedMetrics object could be shared by multiple Threads, then you need to protect the values. One way to do that is to defensively copy the TimeStamp on its way out of the getDBField(...) method. Example:

So once a the timestamp was retrieved they are sure to have a local copy which other threads have no access to.

This only partially fixes the problem, though. I assume that the start time and the end time must be sure to come from the same action. If QualifiedMetrics is not thread safe then you can get into a situation where Thread1 gets the start time, Thread2 modifies the start and end time, and then Thread1 gets the end time. Thread1 now has start from before Thread2's action, and the end time from after Thread2's action which could be a problem if you need consistency in those values. So the solution is either:
(a) make sure the instance of QualifiedMetrics is Thread Safe itself taking into account data consistency between fields. This usually means a bit of synchronization and methods that can be used to get dependent fields together.
(b) or make it immutable so once the object is created it can't be changed. Any changes would require a new instance of QualifiedMetric which means any time a method has a reference to a QualifiedMetric it does not have to worry about another thread modifying its properties.
(c) Customize the collection you are using to store the QualifiedMetrics in. When a new QualifiedMetric is added make a copy and put it into a backing collection. When a QualifiedMetric is retrieved make a copy of it and send the copy out. That way the central repository is Thread Safe, a Thread has copies of the QualifiedMetric, and so doesn't have to worry about other Threads modifying it mid-use.

I agree. Here's the link:
subject: values change unexpectedly due to threading issue?
It's not a secret anymore!