Core Dataに久々にはまった

ユビレジを使っているお客さんから商品のダウンロードがえらい遅いという報告を受けました。さあ、いったい何が起きている？？

遅い原因は、二つありました。

インポートの際に手抜きをして、Find-or-Createをナイーブに実装していた
saveがめちゃくちゃ遅い

このうちの前者は、Core Data Programming Guideにあるとおり、ちょっと賢く実装しなおせば、かなり改善されます。まあ、リレーションがあると、そっちも事前に辞書にして渡すとかの工夫は必要ですが、大したことない。

これでダウンロードのスループットは改善されましたが、やっぱり偉いレスポンシブネスに問題があります。

これが後者の問題。なんかわからないけど、インポートしていくと、だんだんsaveにかかる時間が長くなります。最初は100件ずつsaveとかしていて、もっと少ない方が良いかなーと思って、10件ずつとか1件ずつとかにしても、saveに1秒とかかかるていたらく。遅すぎるだろこれ。

ちょっと簡単なモデルで試してみました。

NSManagedObjectContext* context = self.managedObjectContext;

NSUInteger total = 0;
NSUInteger batchSize = 10000;

Account* account = [self insertNewObject:[Account class] intoContext:context];
[context obtainPermanentIDsForObjects:@[account] error:nil];
[context save:nil];

NSManagedObjectID* accountID = [account objectID];

while (true) {
	[self benchmark:[NSString stringWithFormat:@"Inserting %d posts", batchSize] block:^{
		for (int i = 0; i < batchSize; i++) {
			Post* post = [self insertNewObject:[Post class] intoContext:context];
			post.account = account;
			post.title = [NSString stringWithFormat:@"Post %d", i + total];
		}
	}];
	
	NSTimeInterval timeToPush = [self benchmark:@"Save to root" block:^{
		NSArray* newObjects = [[context insertedObjects] sortedArrayUsingDescriptors:@[]];
		[context obtainPermanentIDsForObjects:newObjects error:nil];
		[context save:nil];
	}];
	
	NSUInteger nextBacthSize = batchSize / timeToPush;
	if (nextBacthSize == 0) {
		nextBacthSize = 1;
	}
	
	total += batchSize;
	NSLog(@"Total Posts = %d, nextBatchSize = %d", total, nextBacthSize);
	
	batchSize = nextBacthSize;
}

こんな感じで、1秒間に何個要素を追加してsaveできるのか、計算します。モデルは、AccountとPostというのが作ってあって、AccountはpostsというリレーションにたくさんPostを保持します。あと、benchmarkっていうのは、こんなメソッド。ブロックの実行にかかった時間を計測して、NSLogして、ついでにその時間を返します。

- (NSTimeInterval)benchmark:(NSString*)message block:(void(^)())block {
	NSDate* start = [NSDate date];
	block();
	NSDate* finish = [NSDate date];
	NSTimeInterval time = [finish timeIntervalSinceDate:start];
	
	if (message) {
		NSLog(@"%@: in %g secs", message, time);
	}
	
	return time;
}

しばらく動かすと、ばっちり遅くなっていく様子が観察できました。

2012-07-08 09:32:58.753 TransactionTest[2609:707] Inserting 10000 posts: in 1.48322 secs
2012-07-08 09:33:01.008 TransactionTest[2609:707] Save to root: in 2.25142 secs
2012-07-08 09:33:01.010 TransactionTest[2609:707] Total Posts = 10000, nextBatchSize = 4441
......
2012-07-08 09:34:22.501 TransactionTest[2609:707] Inserting 2353 posts: in 1.23398 secs
2012-07-08 09:34:23.509 TransactionTest[2609:707] Save to root: in 1.00631 secs
2012-07-08 09:34:23.510 TransactionTest[2609:707] Total Posts = 113627, nextBatchSize = 2338

しばらく動かすと、毎秒4000個あまりPostsをインサートしてsaveできていたのが、半分程度まで落ちます*1。ばっちり問題を再現できています（多分）。

ちなみに、

post.account = account;

としている行をコメントアウトすると、性能の劣化は発生しません。リレーションがあるとよくないみたい。

うーむ。こまった。「1万件のデータセットはfairly small sizeだ！」と豪語するCore Dataさんですが、10万件はそうでもないようです。

ちなみに、製品のコードではiOS 5で導入されたNested Managed Object Contextを使っています。子供をsaveしてから親をsaveして、とするわけですが、ここで「親をsaveするのをバックグラウンドで実行することができるのでUIはブロックしないよ！」とWWDC 2011のビデオで説明しているのが見られます。が、この問題は子供から親へsaveするときにも発生するのよね……

ちょっと本当に困っています。

Workaroundとしては、

Core Dataのリレーションを使うのを止めて、accountIDみたいな感じで、リレーションのためのプロパティを適当に書く。ORまっぱみたいのを自分で実装しなおす。

ことになるのかなぁ。これなら、insertのときには数字を入れるだけなので、この問題は発生しないはず……

*1:ちなみにこの後もどんどん性能が落ちていきます。