0

パフォーマンスの問題、つまり長いトランザクション時間に苦しむ iOS アプリがあります。関連するトランザクションの一部は大規模で、数百回の更新が行われますが、問題が発生すると、特定のトランザクションの期間が 20 倍程度増加します (したがって、3 秒から 60 秒になる可能性があります)。また、トランザクション時間 (短い時間と長い時間の両方) を観察すると、特定の種類のトランザクションの時間はゆっくりと着実に成長し、ある時点で突然上昇することがわかります。これはすべて、データベースのサイズまたはこれまでに使用されたトランザクションの数に関連しているようです。(アプリの再起動後も問題は解決しません。)

時限呼び出しを行うことsqlite3_statusで、パフォーマンスが悪化するにつれて「PAGECACHE_OVERFLOW」の数値が大きくなるように見えることがわかりました。「リープ」までは、2,351,392 付近で「固定」されているように見え、その数値の上下でおそらく 10,000 変化します。

(おそらく 50,000 行のうちどれを含めればよいかわからないため、ここにコードを含めてもあまり意味がありませんが、誰かが望む場合は、さらにデータを含めることができます。)

問題を説明するための基本的な時間データを次に示します。

Line 6003: 2013-01-17 17:05:57.296 [640f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7bd7490> (operation count 50) for TestCase 31 was 0.007225
Line 6006: 2013-01-17 17:05:57.699 [640f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7bdcc50> (operation count 100) for TestCase 31 was 0.012519
Line 6008: 2013-01-17 17:05:58.130 [640f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7be3ce0> (operation count 150) for TestCase 31 was 0.012854
Line 6011: 2013-01-17 17:05:58.614 [640f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7bead70> (operation count 200) for TestCase 31 was 0.012298
Line 6013: 2013-01-17 17:05:59.117 [640f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7bf1dd0> (operation count 250) for TestCase 31 was 0.008589
Line 10158: 2013-01-17 17:10:59.635 [6e6b] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b6a370> (operation count 50) for TestCase 20 was 0.019303
Line 10161: 2013-01-17 17:11:00.526 [6e6b] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b704a0> (operation count 100) for TestCase 20 was 0.090055
Line 10164: 2013-01-17 17:11:01.354 [6e6b] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7ea94b0> (operation count 150) for TestCase 20 was 0.014182
Line 13712: 2013-01-17 17:11:08.467 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e77090> (operation count 50) for TestCase 21 was 0.014494
Line 13714: 2013-01-17 17:11:09.368 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e7dae0> (operation count 100) for TestCase 21 was 0.016176
Line 16852: 2013-01-17 17:11:15.417 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e5da90> (operation count 50) for TestCase 22 was 0.016824
Line 16854: 2013-01-17 17:11:16.469 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e81e50> (operation count 100) for TestCase 22 was 0.018769
Line 18: 2013-01-17 17:11:24.845 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b14fa0> (operation count 50) for TestCase 13 was 0.025399
Line 21: 2013-01-17 17:11:26.447 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7bd4cb0> (operation count 100) for TestCase 13 was 0.025167
Line 23: 2013-01-17 17:11:27.886 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e3acf0> (operation count 150) for TestCase 13 was 0.026859
Line 27: 2013-01-17 17:11:29.353 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7ee8920> (operation count 200) for TestCase 13 was 0.019391
Line 29: 2013-01-17 17:11:30.601 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7eef680> (operation count 250) for TestCase 13 was 0.019822
Line 5742: 2013-01-17 17:11:41.681 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x5730970> (operation count 50) for TestCase 23 was 0.081646
Line 5745: 2013-01-17 17:11:43.421 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b263f0> (operation count 100) for TestCase 23 was 0.021661
Line 5747: 2013-01-17 17:11:44.821 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7f86ff0> (operation count 150) for TestCase 23 was 0.028541
Line 5750: 2013-01-17 17:11:46.233 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b7fda0> (operation count 200) for TestCase 23 was 0.023087
Line 5752: 2013-01-17 17:11:47.696 [1b97] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e64400> (operation count 250) for TestCase 23 was 0.030041
Line 10685: 2013-01-17 17:12:04.873 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x84a0ec0> (operation count 50) for TestCase 24 was 0.030812
Line 10687: 2013-01-17 17:12:06.479 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x5728a80> (operation count 100) for TestCase 24 was 0.026640
Line 10690: 2013-01-17 17:12:08.147 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e5f130> (operation count 150) for TestCase 24 was 0.029734
Line 10692: 2013-01-17 17:12:09.807 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b0d280> (operation count 200) for TestCase 24 was 0.039982
Line 15692: 2013-01-17 17:12:20.456 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x83edb60> (operation count 50) for TestCase 25 was 0.044163
Line 15695: 2013-01-17 17:12:22.265 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b8d1c0> (operation count 100) for TestCase 25 was 0.036278
Line 15697: 2013-01-17 17:12:24.092 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e4fa90> (operation count 150) for TestCase 25 was 0.039441
Line 15700: 2013-01-17 17:12:25.957 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7f63ef0> (operation count 200) for TestCase 25 was 0.044993
Line 15702: 2013-01-17 17:12:27.844 [6473] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x84e9d00> (operation count 250) for TestCase 25 was 0.039544
Line 20761: 2013-01-17 17:12:36.498 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e7f600> (operation count 50) for TestCase 26 was 0.036249
Line 20763: 2013-01-17 17:12:39.247 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b30960> (operation count 100) for TestCase 26 was 0.058809
Line 20767: 2013-01-17 17:12:41.772 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7ea9a70> (operation count 150) for TestCase 26 was 0.048724
Line 20769: 2013-01-17 17:12:43.768 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b287b0> (operation count 200) for TestCase 26 was 0.040958
Line 20772: 2013-01-17 17:12:45.788 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7b64eb0> (operation count 250) for TestCase 26 was 0.040524
Line 17: 2013-01-17 17:12:58.002 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7f78130> (operation count 50) for TestCase 27 was 0.049245
Line 20: 2013-01-17 17:13:00.157 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7eacf20> (operation count 100) for TestCase 27 was 0.042884
Line 22: 2013-01-17 17:13:02.323 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x83e0de0> (operation count 150) for TestCase 27 was 0.043717
Line 25: 2013-01-17 17:13:04.483 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e2f690> (operation count 200) for TestCase 27 was 0.044739
Line 27: 2013-01-17 17:13:06.686 [9327] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7f6c7f0> (operation count 250) for TestCase 27 was 0.044045
Line 5109: 2013-01-17 17:13:33.149 [9613] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x8444de0> (operation count 50) for TestCase 28 was 0.054260
Line 5112: 2013-01-17 17:13:35.969 [9613] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7f6fd50> (operation count 100) for TestCase 28 was 0.065153
Line 5114: 2013-01-17 17:13:38.885 [9613] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7ee9b10> (operation count 150) for TestCase 28 was 0.046428
Line 5117: 2013-01-17 17:13:41.801 [9613] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7bc66a0> (operation count 200) for TestCase 28 was 0.057400
Line 5119: 2013-01-17 17:13:44.749 [9613] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7efadb0> (operation count 250) for TestCase 28 was 0.050737
Line 6553: 2013-01-17 17:13:52.572 [9613] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x85b71d0> (operation count 50) for TestCase 29 was 0.068941
Line 12883: 2013-01-17 17:51:57.413 [ff5f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x7e5d260> (operation count 50) for TestCase 6 was 0.217507
Line 12886: 2013-01-17 17:52:08.760 [ff5f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x84a4c60> (operation count 100) for TestCase 6 was 0.224743
Line 12888: 2013-01-17 17:52:20.051 [ff5f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x84f7110> (operation count 150) for TestCase 6 was 0.220262
Line 12891: 2013-01-17 17:52:31.397 [ff5f] [TestCase insertDependentRows:](1224) <PHI> Time to insert/update MyAppMarker <MyAppMarker: 0x8540ec0> (operation count 200) for TestCase 6 was 0.222045

質問は次のとおりだと思います。これの考えられる原因、またはそれをさらに診断する方法を知っている人はいますか?

更新:プロファイラーの [割り当て] オプションを使用していくつかのテストを行いました。多くの DB 挿入/更新が B ツリー (PAGECACHE にある) に (ヒープ) スペースを割り当てており、決して解放していないようです。これは理にかなっていると思いますが、ストレージの量が多いようです。

4

1 に答える 1

2

最後にこれを理解しました。The Case of the Missing Indexesでした。テストを十分に長く実行し、間隔を空けて DB ファイル サイズをダンプしたところ、操作時間が DB サイズにほぼ比例して増加していることが明らかになりました。

DB を掘り下げて (私は設定しませんでした)、WHERE対応するインデックスを持たない大きなテーブルで頻繁に使用されるいくつかの句を見つけました。約 6 つのインデックスが追加され、パフォーマンスは O(1) に近づきました。

PAGECACHE 統計がどの程度変化したか、また SQLite ヒープ リークがなくなったかどうかを確認する時間はまだありません。「良い」と呼ぶ前に、それらの髪の毛を見てみましょう。

追加: ちょっとした注意事項 -- 私が追加したインデックスの 1 つが、既にそこにあるはずだったことが判明しました。だけがコード化されました

CREATE INDEX IF NOT EXISTS FileIdIndex ON FileMetaData (FileId)

以前にあった場合（「モジュール性」のために別のモジュールで）

CREATE INDEX IF NOT EXISTS FileIdIndex ON Master (FileId)

したがって、インデックス名を作成するときは、テーブル名を「FileIdToFileMetaDataIndex」のようにインデックス名の一部にして、名前の衝突を避けるのが最善です。

于 2013-01-23T00:38:33.840 に答える