Help me solve a concurrency mystery (platform bug? Expected behavior? Or am I missing something?)

Question

To set up the problem, add a new currency data type custom field called Test_Counter__c to the Opportunity Object. Then create a test opportunity named TestOp.

Then create the following class:

public class OpCounter
{

// Add custom currency field Test_Counter__c to Opportunity
// Create a test opportunity named TestOp

@future
public static void IncrementTestCounter1()
{
    List<Opportunity> ops;

    ops = [Select ID, Amount, Test_Counter__c from Opportunity where Name ='TestOp' For Update];

    Decimal currentvalue = ops[0].Test_Counter__c;    // Read the current value
    //Decimal currentvalue = ops[0].Amount;    // Read the current value

    if(currentvalue==null) currentvalue = 0;

    currentvalue+=1;

    // This increments the field by one but adds a long delay
    for(Integer x=0; x<100000; x++)
    {
        ops[0].Test_Counter__c = currentvalue;
        //ops[0].Amount = currentvalue;
    }

    update ops;
    // The value on this update will be the original value + 1 for custom field
    // It will be the # of successes for standard field
}



@future
public static void IncrementTestCounter2()
{
    List<Opportunity> ops;

    ops = [Select ID, Amount, Test_Counter__c from Opportunity where Name ='TestOp' For Update];
    ops = [Select ID, Amount, Test_Counter__c from Opportunity where Name ='TestOp' For Update];

    Decimal currentvalue = ops[0].Test_Counter__c;    // Read the current value
    //Decimal currentvalue = ops[0].Amount;    // Read the current value

    if(currentvalue==null) currentvalue = 0;

    currentvalue+=1;

    // This increments the field by one but adds a long delay
    for(Integer x=0; x<100000; x++)
    {
        ops[0].Test_Counter__c = currentvalue;
        //ops[0].Amount = currentvalue;
    }

    update ops;
    // The value on this update will be # of successes for custom field
    // or standard field
}    
}

These routines are quite simple - they select the record using "For Update", increment the value, wait a while (the loop is just to create a delay), then update the record.

In an anonymous Apex window (dev console), enter the following (10 lines):

OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();
OpCounter.IncrementTestCounter1();

What this should do is launch 10 simultaneous jobs. Because the query specifies "For Update" and there is a delay, some of the jobs will block - and in fact, some will likely fail - This is expected, and is not the issue at hand.

What I expected to see is the counter would increment by the number of jobs that succeeded.

What I do see is that it only increments by one or sometimes two when using a custom field. When I change it to use the standard amount field (see commented lines), it does increment by the number of jobs that succeeded as expected.

Now try calling the IncrementTestCounter2 method instead. This one differs from the first in that it does a second query for the value. This code ALWAYS increments either field by the number of jobs that succeeded.

If I am interpreting the results correctly, it seems that the For Update query returns the value of the field at the time the query was made for custom fields, not the value at the time the lock is released.

As I see it, there are three possibilities here:

1. There is a pretty scary concurrency bug related to use of custom fields in For Update queries.
2. SFDC is doing a "write lock" instead of a "read lock" on custom fields, which is weird, but could be an expected behavior.
3. I'm missing something obvious.

Any help in confirming what I am seeing and offering either an alternate explanation would be greatly appreciated. My understanding is that one of the Apex Devs did look at the problem and was unable to reproduce the issue. This strikes me as odd, as I'm been able to reliably reproduce this on every org that I've tried it on. I'm seeing the same behavior on Summer 13 and Winter 14.

Answer 1

I believe SELECT ... FOR UPDATE does indeed do a write lock, as implied by the docs:

Apex allows you to lock sObject records while they’re being updated in order to prevent race conditions and other thread safety problems. While an sObject record is locked, no other client or user is allowed to make updates either through code or the Salesforce user interface. The client locking the records can perform logic on the records and make updates with the guarantee that the locked records won’t be changed by another client during the lock period. The lock gets released when the transaction completes.

In any case, I'm not sure that explains the discrepancies between standard and custom fields. I'll run this question by the Apex dev team and see what they say...

UPDATE (9/24/13) - Apex team are actively investigating. I'll post more as information becomes available.

UPDATE (5/20/14) - this should be fixed in the Summer '14 release. I'll confirm once I get a chance to test it.

UPDATE (5/1/15) - for the record, this was fixed in the Summer '14 release.