I'm using JPA on Google app-engine datastore and some of the 'merge' operations are extremely slow. One of them usually takes more that 16 seconds. What can cause this?
--Update:A major part of the problem was caused by a concurrency issue. Now it's 3-5 seconds. (Just for the last 5 lines of code) The code is something like this:
Parent p= manager.find(Parent.class, key);
Child c = new Child();
...
//Setting child properties
...
p.getList().add(c);
EntityTransaction trans = manager.getTransaction();
trans.begin();
manager.merge(p);
trans.commit();
And even more details: In the following code, DB.merge/DB.persist means creating a transaction, merging/persisting, and committing the transaction (similar to the last lines of the previous code). Code:
List<Story> stories = DB.getAll(Story.class);
logger.warning("retrieve all");
Map<Key, Story> map = new HashMap<Key, Story>();
for(Story s:stories){
s.setUsed(0);
map.put(s.getKey(), s);
}
logger.warning("Settings:Done");
for(Story s:stories){
if(s==null)
continue;
s.getRelations().clear();
for(Key k:s.getSubStories()){
Story ss = map.get(k);
if(ss==null)
continue;
Story relationStory = new Story();
relationStory.setCreationDate(new Date());
relationStory.setTitle("Is sub-story of ");
logger.warning("getting relations");
user.getPieces().add(relationStory);
ss.getRelations().size();
s.getRelations().size();
logger.warning("merging user");
DB.merge(user);
logger.warning("merge: done");
Relation relation = new Relation();
relation.setFromStory(ss.getKey());
relation.setRelationStory(relationStory.getKey());
relation.setToStory(s.getKey());
logger.warning("persisting relation");
DB.persist(relation);
logger.warning("persist: done");
ss.getRelations().add(relation.getKey());
s.getRelations().add(relation.getKey());
ss.setUsed(ss.getUsed()+1);
}
}
logger.warning("First loop DONE!");
for(Story s:stories)
DB.merge(s);
logger.warning("Second loop DONE!");
Log:
W 05-29 06:30PM 49.228 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: retrieve all stories
W 05-29 06:30PM 49.607 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: Settings:Done
W 05-29 06:30PM 49.611 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: getting relations
W 05-29 06:30PM 50.068 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: merging user
W 05-29 06:30PM 55.273 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: merge: done-->5 seconds
W 05-29 06:30PM 55.273 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: persisting relation
W 05-29 06:30PM 55.516 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: persist: done
W 05-29 06:30PM 55.517 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: getting relations
W 05-29 06:30PM 55.517 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: merging user
W 05-29 06:31PM 11.926 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: merge: done-->16 seconds
W 05-29 06:31PM 11.926 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: persisting relation
W 05-29 06:31PM 11.997 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: persist: done
W 05-29 06:31PM 11.998 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: getting relations
W 05-29 06:31PM 11.998 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: merging user
E 05-29 06:31PM 17.123 com.nobarany.syavash.analyticstream.view.ViewInterface cleanSubstories: com.google.apphosting.api.DeadlineExceededException: