Core Data fetch is extremely slow

Question

I'm running a very basic NSFetchRequest to fetch an entity MessageObject. I only have 2000 message objects, and I want to retreive them all. However, for some strange reason, the fetch request is taking over 10 seconds!

NSFetchRequest *fetchRequest = [[NSFetchRequest alloc] init];
NSEntityDescription *entity = [NSEntityDescription entityForName:@"MessageObject" inManagedObjectContext:appDelegate.managedObjectContext];
[fetchRequest setEntity:entity];
NSSortDescriptor *sort= [[NSSortDescriptor alloc] initWithKey:@"createDate" ascending:NO selector:@selector(compare:)];
[fetchRequest setSortDescriptors:[NSArray arrayWithObject:sort]];
[fetchRequest setFetchBatchSize:5];

And that's it, that's my fetch request. I'm not even using a predicate, and it takes over 10 seconds. I'm absolutely clueless as to what could be causing this. If anyone has any ideas or starting points, please share.

I've also tried enabling SQLite debugging logging (-com.apple.CoreData.SQLDebug 1), but I just get thousands of lines of output from this simple fetch. Is that normal?

 2012-06-22 19:39:59.171 myapp[81825:15e03] about to execute fetch
 2012-06-22 19:39:59.172 myapp[81825:15e03] CoreData: sql: SELECT 0, t0.Z_PK FROM ZMBNOTEOBJECT t0 ORDER BY t0.ZCREATEDATE DESC
 2012-06-22 19:39:59.178 myapp[81825:15e03] CoreData: annotation: sql connection fetch time: 0.0061s
 2012-06-22 19:39:59.179 myapp[81825:15e03] CoreData: annotation: total fetch execution time: 0.0067s for 2052 rows.
 2012-06-22 19:39:59.179 myapp[81825:15e03] CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZAUTHOREMAIL, t0.ZAUTHORNAME, t0.ZCREATEDATE, t0.ZISGLOBAL, t0.ZISLOCKED, t0.ZISNEW, t0.ZISPENDINGDELETE, t0.ZISPENDINGLIKE, t0.ZISPENDINGREAD, t0.ZISPENDINGSYNC, t0.ZLASTUPDATED, t0.ZLOCALLYMODIFIEDDATE, t0.ZMAINIDEA, t0.ZMETALASTUPDATED, t0.ZNOTEID, t0.ZNUMBEROFCHILDREN, t0.ZPARENTAUTHOREMAIL, t0.ZPARENTNOTEID, t0.ZROOTAUTHOREMAIL, t0.ZROOTNOTEID, t0.Z4PENDINGADDNOTES, t0.Z4PENDINGREMOVENOTES FROM ZMBNOTEOBJECT t0 WHERE  t0.Z_PK IN  (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)  ORDER BY t0.ZCREATEDATE DESC LIMIT 15
 2012-06-22 19:39:59.180 myapp[81825:15e03] CoreData: annotation: sql connection fetch time: 0.0008s
 2012-06-22 19:39:59.181 myapp[81825:15e03] CoreData: annotation: total fetch execution time: 0.0018s for 15 rows.
 2012-06-22 19:39:59.182 myapp[81825:15e03] CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZAUTHOREMAIL, t0.ZAUTHORNAME, t0.ZCREATEDATE, t0.ZISGLOBAL, t0.ZISLOCKED, t0.ZISNEW, t0.ZISPENDINGDELETE, t0.ZISPENDINGLIKE, t0.ZISPENDINGREAD, t0.ZISPENDINGSYNC, t0.ZLASTUPDATED, t0.ZLOCALLYMODIFIEDDATE, t0.ZMAINIDEA, t0.ZMETALASTUPDATED, t0.ZNOTEID, t0.ZNUMBEROFCHILDREN, t0.ZPARENTAUTHOREMAIL, t0.ZPARENTNOTEID, t0.ZROOTAUTHOREMAIL, t0.ZROOTNOTEID, t0.Z4PENDINGADDNOTES, t0.Z4PENDINGREMOVENOTES FROM ZMBNOTEOBJECT t0 WHERE  t0.Z_PK IN  (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)  ORDER BY t0.ZCREATEDATE DESC LIMIT 15
 2012-06-22 19:39:59.186 myapp[81825:15e03] CoreData: annotation: sql connection fetch time: 0.0042s
 2012-06-22 19:39:59.187 myapp[81825:15e03] CoreData: annotation: total fetch execution time: 0.0049s for 15 rows.
 2012-06-22 19:39:59.187 myapp[81825:15e03] CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZAUTHOREMAIL, t0.ZAUTHORNAME, t0.ZCREATEDATE, t0.ZISGLOBAL, t0.ZISLOCKED, t0.ZISNEW, t0.ZISPENDINGDELETE, t0.ZISPENDINGLIKE, t0.ZISPENDINGREAD, t0.ZISPENDINGSYNC, t0.ZLASTUPDATED, t0.ZLOCALLYMODIFIEDDATE, t0.ZMAINIDEA, t0.ZMETALASTUPDATED, t0.ZNOTEID, t0.ZNUMBEROFCHILDREN, t0.ZPARENTAUTHOREMAIL, t0.ZPARENTNOTEID, t0.ZROOTAUTHOREMAIL, t0.ZROOTNOTEID, t0.Z4PENDINGADDNOTES, t0.Z4PENDINGREMOVENOTES FROM ZMBNOTEOBJECT t0 WHERE  t0.Z_PK IN  (?,?,?,?,?,?,?,?,?,?,?,?,?,?,?)  ORDER BY t0.ZCREATEDATE DESC LIMIT 15
 2012-06-22 19:39:59.188 myapp[81825:15e03] CoreData: annotation: sql connection fetch time: 0.0008s
 2012-06-22 19:39:59.189 myapp[81825:15e03] CoreData: annotation: total fetch execution time: 0.0014s for 15 rows.
... (thousands of more lines similar to above)

I'm not very familiar with reading this, but it appears that it fetches 2052 rows in .0067 seconds. So why does it keep doing more stuff after that? Shouldn't the request finish if it finished fetching the rows? Is it faulting the data or something?

Also, I've removed setFetchBatchSize - that got rid of the thousands of lines, but the fetch request still takes really long. This is the output I get:

2012-06-22 20:07:25.316 myapp[8927:707] about to execute fetch
 2012-06-22 20:07:25.322 myapp[8927:707] CoreData: sql: SELECT 0, t0.Z_PK, t0.Z_OPT, t0.ZAUTHOREMAIL, t0.ZAUTHORNAME, t0.ZCREATEDATE,t0.ZISLOCKED, t0.ZISNEW, t0.ZISPENDINGDELETE, t0.ZISPENDINGSYNC, t0.ZLASTUPDATED, t0.ZLOCALLYMODIFIEDDATE, t0.ZMAINIDEA, t0.ZMETALASTUPDATED, t0.ZNOTEID, t0.ZNUMBEROFCHILDREN, t0.ZPARENTAUTHOREMAIL, t0.ZPARENTNOTEID, t0.ZROOTAUTHOREMAIL, t0.ZROOTNOTEID, t0.Z4PENDINGADDNOTES, t0.Z4PENDINGREMOVENOTES FROM ZMBNOTEOBJECT t0 ORDER BY t0.ZCREATEDATE DESC
 2012-06-22 20:07:26.758 myapp[8927:707] CoreData: annotation: sql connection fetch time: 1.0891s
 2012-06-22 20:07:26.763 myapp[8927:707] CoreData: annotation: total fetch execution time: 1.4407s for 4000 rows.
 2012-06-22 20:07:35.967 myapp[8927:707] finished fetching

What's weird is that at 20:07:26.763 it apparently says it took 1.4407 seconds for 4000 rows, but not for another 9 seconds do I get the output saying "finished fetching" (which is an NSLog statement that appears after [[self fetchedResultsController] performFetch:&error]) What's up with that?

Answer 1

Remove setFetchBatchSize.

If your intent is to load everything at once, just remove it.

Moreover, if you need to load all attributes, add :

fetchRequest.returnsObjectsAsFaults = NO;

It will load every entity and populate the attributes.

You may want to load only certain attributes, so use this to select what you need:

fetchRequest.propertiesToFetch = ...

And you're done.