views:

94

answers:

0

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: