InstructorCourseInstructorAddAction vulnerable to eventual consistency

[damithc]

From dam...@gmail.com on March 03, 2014 19:00:02

It contains a create followed by update immediately after.
Here's the exception

java.lang.AssertionError: Non-null value expected for an institute name
at teammates.common.util.Assumption.fail(Assumption.java:56)
at teammates.common.util.Assumption.assertTrue(Assumption.java:25)
at teammates.common.util.FieldValidator.getValidityInfoForAllowedName(FieldValidator.java:495)
at teammates.common.util.FieldValidator.getInvalidityInfo(FieldValidator.java:368)
at teammates.common.util.FieldValidator.getInvalidityInfo(FieldValidator.java:345)
at teammates.common.datatransfer.AccountAttributes.getInvalidityInfo(AccountAttributes.java:65)
at teammates.common.datatransfer.EntityAttributes.isValid(EntityAttributes.java:15)
at teammates.storage.api.AccountsDb.updateAccount(AccountsDb.java:90)
at teammates.logic.core.AccountsLogic.makeAccountInstructor(AccountsLogic.java:178)
at teammates.logic.core.AccountsLogic.createInstructorAccount(AccountsLogic.java:65)
at teammates.logic.api.Logic.createInstructorAccount(Logic.java:214)
at teammates.ui.controller.InstructorCourseInstructorAddAction.execute(InstructorCourseInstructorAddAction.java:30)
at teammates.ui.controller.Action.executeAndPostProcess(Action.java:125)
at teammates.ui.controller.ControllerServlet.doPost(ControllerServlet.java:48)
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 teammates.ui.controller.LoginFilter.doFilter(LoginFilter.java:46)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at teammates.storage.datastore.DatastoreFilter.doFilter(DatastoreFilter.java:28)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.appengine.tools.appstats.AppstatsFilter.doFilter(AppstatsFilter.java:141)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.ParseBlobUploadFilter.doFilter(ParseBlobUploadFilter.java:125)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.apphosting.runtime.jetty.SaveSessionFilter.doFilter(SaveSessionFilter.java:35)
at org.mortbay.jetty.servlet.ServletHandler$CachedChain.doFilter(ServletHandler.java:1157)
at com.google.apphosting.utils.servlet.JdbcMySqlConnectionCleanupFilter.doFilter(JdbcMySqlConnectionCleanupFilter.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 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.apphosting.runtime.jetty.AppVersionHandlerMap.handle(AppVersionHandlerMap.java:266)
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.headerComplete(HttpConnection.java:923)
at com.google.apphosting.runtime.jetty.RpcRequestParser.parseAvailable(RpcRequestParser.java:76)
at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
at com.google.apphosting.runtime.jetty.JettyServletEngineAdapter.serviceRequest(JettyServletEngineAdapter.java:146)
at com.google.apphosting.runtime.JavaRuntime$RequestRunnable.run(JavaRuntime.java:446)
at com.google.tracing.TraceContext$TraceContextRunnable.runInContext(TraceContext.java:437)
at com.google.tracing.TraceContext$TraceContextRunnable$1.run(TraceContext.java:444)
at com.google.tracing.CurrentContext.runInContext(CurrentContext.java:188)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContextNoUnref(TraceContext.java:308)
at com.google.tracing.TraceContext$AbstractTraceContextCallback.runInInheritedContext(TraceContext.java:300)
at com.google.tracing.TraceContext$TraceContextRunnable.run(TraceContext.java:441)
at com.google.apphosting.runtime.ThreadGroupPool$PoolEntry.run(ThreadGroupPool.java:251)
at java.lang.Thread.run(Thread.java:724)

Original issue: http://code.google.com/p/teammatespes/issues/detail?id=1669

[damithc]

From leeshaw...@gmail.com on March 04, 2014 00:30:49

I have been tracing through the code and there are several checks before this assumption that checks for the existence of the account. If the account is affected by eventual consistency, it would have been flagged as an error earlier in the code.

Also, the assumption checks for the other 3 fields of the account (name, googleId and email) all passes. Only the institute assumption fails.

In this case, would it be plausible to assume that some part of the data (particularly the institute field) is lost or corrupted? If so, one possible solution is to have the incoming instructor account take after the institute of the instructor that added the new instructor. Is this a good idea?

Status: Started

[damithc]

From dam...@gmail.com on March 04, 2014 00:44:59

If those multiple checks are done using multiple queries, they might not hit the same datastore instance even if it is within the same http request.

[damithc]

From leeshaw...@gmail.com on March 04, 2014 00:52:57

In this case, should I use a task queue to handle the part of "makeAccountInstructor" or should I rollback the whole transaction by deleting the instructor and showing a "please retry" message?

[damithc]

From dam...@gmail.com on March 04, 2014 01:16:41

See if you can avoid writing-reading-updating the same object back-to-back. May be you can do everything by just one write?. e.g. instead of creating an account and updating it, just create it with the correct values in the first place.

[damithc]

From leeshaw...@gmail.com on March 06, 2014 06:12:21

Made the upgrading of an account to instructor perform only 1 write as opposed to a previous 1 read and 1 write. Also added a new test to check for the upgrading of accounts to instructor.

Code ready for review at: https://codereview.appspot.com/72060044

Status: ReadyForReview

[damithc]

From dam...@gmail.com on March 06, 2014 06:40:18

It seems this error was caused by legacy data. It happened when I tried to add an instructor who already had a legacy account that did not have an institute name (because that account was created before we started using institute names).
The current patch doesn't seem to improve anything. does it? if not, we can abandon this issue.

Status: ChangesRequested

[damithc]

From leeshaw...@gmail.com on March 06, 2014 06:51:52

Yes the current patch only reduces the process by 1 read, which is very minor considering the fact that instructors are not added on a very high frequency. So I suppose we can abandon this issue?

Status: WontFix

[damithc]

[Change Log]
status: null ~> status.closed