Problem

A race condition can occur on AbstractSingleFieldType, which can result in SLA storing an older value.

2017-07-20 16:21:20,921 PsmmqAsyncExecutors-job:thread-1949 WARN admin 981x817687x1 jodn9g 10.253.50.10,10.34.1.141 /secure/CommentAssignIssue.jspa [c.a.j.i.customfields.impl.AbstractSingleFieldType] More than one value stored for custom field id 'customfield_10421' for issue 'TEST-429'. Keeping '


{"timeline":{"events":[{"date":1500584561284,"types":["START"]}]},"ongoingSLAData":{"goalId":253,"startTime":1500584561284,"paused":false,"thresholdData":{"calculatedAt":1500585461302,"remainingTime":1199982,"thresholdsConfigChangeDate":1493848724690,"thresholdsConfigChangeMsEpoch":1493848724690}},"completeSLAData":[],"metricId":27,"definitionChangeDate":1500577619927,"definitionChangeMsEpoch":1500577619926,"goalsChangeDate":1500577726747,"goalsChangeMsEpoch":1500577726746,"goalTimeUpdatedDate":1498854856593,"goalTimeUpdatedMsEpoch":1498854856594,"metricCreatedDate":1493848724690}' 


and deleting other values. Original values:[


{"timeline":{"events":[{"date":1500584561284,"types":["START"]}]},"ongoingSLAData":{"goalId":253,"startTime":1500584561284,"paused":false,"thresholdData":{"calculatedAt":1500585461302,"remainingTime":1199982,"thresholdsConfigChangeDate":1493848724690,"thresholdsConfigChangeMsEpoch":1493848724690}},"completeSLAData":[],"metricId":27,"definitionChangeDate":1500577619927,"definitionChangeMsEpoch":1500577619926,"goalsChangeDate":1500577726747,"goalsChangeMsEpoch":1500577726746,"goalTimeUpdatedDate":1498854856593,"goalTimeUpdatedMsEpoch":1498854856594,"metricCreatedDate":1493848724690},

{"timeline":{"events":[{"date":1500584561284,"types":["START"]},{"date":1500585680300,"types":["STOP"]}]},"ongoingSLAData":null,"completeSLAData":[{"succeeded":true,"goalTime":2100000,"elapsedTime":1119016,"remainingTime":980984,"remainingTimeInDaysAndMillis":null,"calendarName":"24/7 Calendar (Default)","startTime":1500584561284,"stopTime":1500585680300}],"metricId":27,"definitionChangeDate":1500577619927,"definitionChangeMsEpoch":1500577619926,"goalsChangeDate":null,"goalsChangeMsEpoch":null,"goalTimeUpdatedDate":null,"goalTimeUpdatedMsEpoch":null,"metricCreatedDate":1493848724690}]

Note that I've broken the message up for ease of reading. We can see that JIRA has chosen to retain the original SLA statement rather than the one which contains both the Start and the Stop events.

If there is a race condition between customFieldValuePersister where:

• A thread is updating the value, what it does is retrieve all existing values, then adds the new row and finally it will delete the old rows
• But if between the add and delete, another thread calls get, then it will have retrieved 2 rows, and the AbstractSingleFieldType only handles 1 value.

The way it handles this currently is

// The data is corrupt - presumably because of concurrent update bug in customFieldValuePersister
// Best we can do is pick one value as the winner
databaseValue = values.get(0);
log.warn("More than one value stored for custom field id '" + field.getId() + "' for issue '" + issueKey + "'. Keeping '" + databaseValue + "' and deleting other values. Original values:" + values);
customFieldValuePersister.updateValues(field, issueId, getDatabaseType(), Arrays.asList(databaseValue));

• Basically, it selects the first value returned to keep. But problem seems that the SELECT does not include any ORDER BY clause, and on most dbs this will mean that these records get returned in ASCENDING order of the ID column.
• This means that the older value is kept (the one due for deletion) and will delete the newer value.
• What this does to solve the issue is call another update, which adds the old value back and deletes the newer value.