Tiptoeing into Transactions -- Stubbing my toe

[Ken Bowen]

Hello,

I'm using objectify 2.2.1, and attempting utilize transactions, but running into a problem I don't understand.
I have a registered kind Account [ ObjectifyService.register(com.formrunner.db.Account.class); ]:

@Entity @Unindexed @SuppressWarnings({ "serial" })
public class Account implements Serializable
{
@Id
private Long id;
Double accountBalance;
.... lots else ...
}

I've attempted to model an update to the balance of this as closely as possible to the discussion in http://code.google.com/p/objectify-appengine/wiki/IntroductionToObjectify#Transactions:

public static String stripeTransactionTest()
{
Long aid = 124L;
double payamount = 101.13;
Objectify ofy = ObjectifyService.beginTransaction();
try {
Account account0 = ofy.get(Account.class, aid);
double curBalDue = account0.getAccountBalance();
double newBalDue = curBalDue + payamount;
account0.setAccountBalance(newBalDue);
ofy.put(account0);

ofy.getTxn().commit();
} finally {
if (ofy.getTxn().isActive())
ofy.getTxn().rollback();
}
return "done";
}

124L is the ID of an Account in my local dev system (Eclipse with GAE plugin). I've hooked this to a simple test framework: A web page button which invokes this routine via DWR (direct web remoting), with nothing else going on. Unfortunately, it raises the following exception (full trace at end):

java.util.ConcurrentModificationException: too much contention on these datastore entities. please try again.

I've plugged in a few printfs to verify that the ofy.put(account0); succeeds, but the ofy.getTxn().commit(); fails, and then the rollback runs. Just for sanity's sake, I created a non-transactional version of this which runs fine:

public static String stripeTransactionTest()
{
Long aid = 124L;
double payamount = 101.13;
Objectify ofy = ObjectifyService.begin();
try {
Account account0 = ofy.get(Account.class, aid);
double curBalDue = account0.getAccountBalance();
double newBalDue = curBalDue + payamount;
account0.setAccountBalance(newBalDue);
ofy.put(account0);

Account account1 = ofy.get(Account.class, aid);
double endamt = account1.getAccountBalance();
System.out.println("endamt="+endamt);
} catch (Exception e){
e.printStackTrace(System.out);
}
return "done";
}

I hope someone can point out the mistake I'm making here.
Many thanks in advance,
Ken Bowen

Feb 19, 2012 3:43:48 PM com.google.apphosting.utils.jetty.AppEngineAuthentication$AppEngineUserRealm isUserInRole
INFO: Checking if principal te...@example.com is in role admin
10:43:48,470 [1960895647@qtp-301042878-14] INFO DefaultRemoter - Exec: AdminIntf.runStripeTests()
10:43:48,504 [1960895647@qtp-301042878-14] WARN DefaultRemoter - Method execution failed:
java.util.ConcurrentModificationException: too much contention on these datastore entities. please try again.
at com.google.appengine.api.datastore.DatastoreApiHelper.translateError(DatastoreApiHelper.java:39)
at com.google.appengine.api.datastore.DatastoreApiHelper$1.convertException(DatastoreApiHelper.java:98)
at com.google.appengine.api.utils.FutureWrapper.get(FutureWrapper.java:106)
at com.google.appengine.api.utils.FutureWrapper.get(FutureWrapper.java:90)
at com.google.appengine.api.utils.FutureWrapper.get(FutureWrapper.java:90)
at com.google.appengine.api.datastore.FutureHelper.getInternal(FutureHelper.java:72)
at com.google.appengine.api.datastore.FutureHelper.quietGet(FutureHelper.java:33)
at com.google.appengine.api.datastore.TransactionImpl.commit(TransactionImpl.java:105)
at com.formrunner.accounting.StripeProcess.stripeTransactionTest(StripeProcess.java:828)
at com.formrunner.admin.AdminIntf.runStripeTests(AdminIntf.java:633)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java.lang.reflect.Method.invoke(Method.java:597)
at com.google.appengine.tools.development.agent.runtime.Runtime.invoke(Runtime.java:100)
at org.directwebremoting.impl.ExecuteAjaxFilter.doFilter(ExecuteAjaxFilter.java:34)
at org.directwebremoting.impl.DefaultRemoter$1.doFilter(DefaultRemoter.java:428)
at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:431)
at org.directwebremoting.impl.DefaultRemoter.execute(DefaultRemoter.java:283)
at org.directwebremoting.servlet.PlainCallHandler.handle(PlainCallHandler.java:52)
at org.directwebremoting.servlet.UrlProcessor.handle(UrlProcessor.java:101)
at org.directwebremoting.servlet.DwrServlet.doPost(DwrServlet.java:146)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:637)
at javax.servlet.http.HttpServlet.service(HttpServlet.java:717)
at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:511)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1166)
at com.google.appengine.tools.development.HeaderVerificationFilter.doFilter(HeaderVerificationFilter.java:35)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.appengine.api.blobstore.dev.ServeBlobFilter.doFilter(ServeBlobFilter.java:60)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.TransactionCleanupFilter.doFilter(TransactionCleanupFilter.java:43)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.appengine.tools.development.StaticFileFilter.doFilter(StaticFileFilter.java:122)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.appengine.tools.development.BackendServersFilter.doFilter(BackendServersFilter.java:97)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:388)
at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:182)
at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:418)
at com.google.appengine.tools.development.DevAppEngineWebAppContext.handle(DevAppEngineWebAppContext.java:78)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at com.google.appengine.tools.development.JettyContainerService$ApiProxyHandler.handle(JettyContainerService.java:362)
at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
at org.mortbay.jetty.Server.handle(Server.java:326)
at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:542)
at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:938)
at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:755)
at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:582)
10:43:48,505 [1960895647@qtp-301042878-14] WARN BaseCallMarshaller - --Erroring: batchId[1] message[java.util.ConcurrentModificationException: too much contention on these datastore entities. please try again.]

[Jeff Schnitzer]

ConcurrentModificationException is what happens when the data has changed while your transaction was in progress. There must be some other write to that data going on at the same time, possibly DWR is making the async call twice?

There are bigger problems with your code, however.

In optimistic concurrency architectures like GAE, pretty much all transactions need to be repeated until success.  Which means all transactions must be idempotent.  The code you posted is not idempotent, so you need to find a way to make it so, otherwise one of the repeats could end up doubling your anticipated balance change.

Making these kinds of transactions idempotent usually involves leaning on modification of another entity, some sort of entity that identifies the transaction.  One way to do it, in pseudocode:

create txn object

repeat in transaction until success {

   do your work

   delete the txn object

}

Sometimes you'll end up with abandoned txn objects but you can delete them later.  In GAE this is a little tricky because of entity group rules, so you'll want your txn object to be parented by one of the entities that you modify in the transaction.

Jeff

[Ken Bowen]

Thanks much, Jeff...I'll be digging in.
--Ken

[Ken Bowen]

[Update/FYI]
My colleague Chuck Houpt pointed out to me that my Account entity actually contained some PostLoad code which was badly behaved: it called ofy() instead of snaring the ofy from the surrounding context, and then the code called ofy.put(...) -- hence the contention. Chuck adapted "Use Pythonic Transactions" from "Best Practices" to our DAO, and now utilizing repeatInTransaction is working just fine for us in our code. (BTW, DWR turned out to be blameless.)

Many thanks to Jeff for a fantastic system.
--Ken Bowen

On Feb 19, 2012, at 5:52 PM, Jeff Schnitzer wrote:

[David Fuelling]

Hey Jeff,

Is there any reason to make the "Idempotency Lock" entity (you call it a "txn object" above) parented by the Entity being updated in the Transaction?  For example, would the following code work to ensure idempotence?

==================

Pseudocode Model

==================

@Entity

class IdempotencyLock{

@Id String Id

}

==================

PseudoCode Version 1

==================

String idempotencyId = … //UUID?

int numRetries = 5;

+ while(numRetries > 0)

{

  

  // Start a new TX

  ofyTx = ofy().factory().beginTransaction()

  try

  {

    Key<IdempotencyLock> lockKey = … //Create Key with idempotencyId

    IdempotencyLock lockFromDatastore = ofyTx.get(lockKey);

    if (lockFromDatastore != null)

    {

      //The Account update already succeeded, so abort

      break;

    }

  }

  catch (final NotFoundException nfe)

  {

    // Do nothing - this is ok.

  }

  // If the thread gets here, then as of the start of the above TX, no IdempotencyLock existed for this while-loop

  try

  {

    IdempotencyLock idempotencyLock = new IdempotencyLock(accountId + "");

    ofyTx.put(idempotencyLock);

    increaseAccountBalance(ofyTx, account, amount);

    ofyTx.getTxn().commit();

  }

  catch(ConcurrentModificationException e)

  {

    // Something else trying to update the Account, so retry

    ofyTx.getTxn().rollback();

  }

  numRetries--;

}

this.cleanupTransactionLock(idempotencyId)

============

One thing to consider in the above code is choice of "id" for the transaction entity IdempotencyLock.  In my example, I'm suggesting a UUID, but it's possible that using an AccountId might work -- still thinking about that one.  Probably depends on what's happening in the "account update" biz logic.

Finally, if the above code (or some improvement on it) could work using a UUID (i.e., general locking key), then it seems like it could be generalized and included in Objectify (or some utility library for Objectify).  This type of code is somewhat complex and error-prone, so it would be nice to have a canonical example somewhere.  Any suggestions?  I don't mind writing a first-shot, possibly integrating with your DAOT class?  

Thanks!

david 

[Jeff Schnitzer]

The reason to parent the "Idempotency Lock" with one of the entities in the transaction is because otherwise you add a new entity group to a transaction.  Normal transactions become XG transactions; XG transactions become one EG larger; the cap on 5 EGs in a XG transaction becomes 4 EGs.

If you are concerned with throughput (especially on a contended EG) this becomes an issue.

I've found a few different ways of doing this so I'd like to start by just documenting it, and if we find convergence, maybe including support for it directly in Objectify.

Jeff

[David Fuelling]

Great point on the extra transaction.  I'm not philosophically opposed to the Transaction object being in the same entity group, and the more I think about it, there doesn't seem to be a strong reason *not* to do it that way, especially if it avoids taking one of the 5 EG's in an XG's.

I'm eager to codify this into some kind of best-practice, so feel free to post some alternative ways of doing this (if any) and maybe we can get a good start on the documentation just by hashing it out in the forum.

(Of course, if you prefer doing it another way, I'm open to that as well).

Thanks!

david