Improve performance of eCryptfs -> ext4 crypto migrator |
|||||||
Issue descriptionOn kevin, dd if=foo of=bar bs=32M conv=fsync says the disk can perform at speed of 50 MB/s. OTOH, our migrator takes about a minute to migrate a user directory whose total size is about 250 MB (i.e. ~5 MB/s). We can do something (e.g. multi-threading) to make this better.
,
Apr 21 2017
My rough guesstimate from other thread about kevin performance is migration_time_seconds = 0.035 * nfiles + 47 * data_GB. 35ms per file on synchronization, 47 seconds / GB (approx 20MB/s)
,
Apr 21 2017
I've been tracking some of my performance tests in this sheet https://docs.google.com/a/google.com/spreadsheets/d/15AVRNLlNm0yPMoa6svOYX0uWli_XMY_O-cXD2TOaJ0M/edit?usp=sharing
,
Apr 21 2017
Did some measurement by adding some logging (code uploaded at https://chromium-review.googlesource.com/c/484163/) #1 Log in & Log out to test account (1) 2017-04-21T17:24:29.700437+09:00 ERR cryptohomed[1540]: Total bytes: 1005235379 2017-04-21T17:24:29.700554+09:00 ERR cryptohomed[1540]: Sendfile bytes: 992849030 2017-04-21T17:24:29.700634+09:00 ERR cryptohomed[1540]: # of files: 10290 2017-04-21T17:24:29.700709+09:00 ERR cryptohomed[1540]: # of symlinks: 1 2017-04-21T17:24:29.700781+09:00 ERR cryptohomed[1540]: # of directories: 2882 2017-04-21T17:24:29.700853+09:00 ERR cryptohomed[1540]: # of fsync()&fdatasync(): 26266 2017-04-21T17:24:29.702860+09:00 ERR cryptohomed[1540]: # of sync(): 1 2017-04-21T17:24:29.702937+09:00 ERR cryptohomed[1540]: Elapsed: 159256 ms 2017-04-21T17:24:29.702979+09:00 ERR cryptohomed[1540]: Elapsed (calculate total): 983 ms 2017-04-21T17:24:29.703017+09:00 ERR cryptohomed[1540]: Elapsed (prepare): 985 ms 2017-04-21T17:24:29.703054+09:00 ERR cryptohomed[1540]: Elapsed (sendfile): 8401 ms 2017-04-21T17:24:29.703092+09:00 ERR cryptohomed[1540]: Elapsed (fsync&fdatasync): 35352 ms 2017-04-21T17:24:29.703236+09:00 ERR cryptohomed[1540]: Elapsed (sync): 2478 ms 2017-04-21T17:24:29.703337+09:00 ERR cryptohomed[1540]: Elapsed (report): 127 ms 2017-04-21T17:24:29.703432+09:00 ERR cryptohomed[1540]: Elapsed (for links): 2479 ms 2017-04-21T17:24:29.703530+09:00 ERR cryptohomed[1540]: Elapsed (for files): 120313 ms 2017-04-21T17:24:29.703721+09:00 ERR cryptohomed[1540]: Elapsed (for files, before data transfer): 20988 ms 2017-04-21T17:24:29.703822+09:00 ERR cryptohomed[1540]: Elapsed (for files, for data transfer): 78306 ms 2017-04-21T17:24:29.703861+09:00 ERR cryptohomed[1540]: Elapsed (for files, after data transfer): 20898 ms 2017-04-21T17:24:29.703900+09:00 ERR cryptohomed[1540]: Elapsed (for dirs, before loop): 17239 ms 2017-04-21T17:24:29.703936+09:00 ERR cryptohomed[1540]: Elapsed (for dirs, after loop): 6159 ms 2017-04-21T17:24:29.703973+09:00 ERR cryptohomed[1540]: Elapsed (for delete): 9546 ms 2017-04-21T17:24:29.704024+09:00 ERR cryptohomed[1540]: 6.31207MB/s #2 Log in & Log out to test account (2) 2017-04-21T17:44:16.417328+09:00 ERR cryptohomed[1537]: Total bytes: 197823921 2017-04-21T17:44:16.418169+09:00 ERR cryptohomed[1537]: Sendfile bytes: 188878212 2017-04-21T17:44:16.418381+09:00 ERR cryptohomed[1537]: # of files: 6512 2017-04-21T17:44:16.418492+09:00 ERR cryptohomed[1537]: # of symlinks: 1 2017-04-21T17:44:16.418596+09:00 ERR cryptohomed[1537]: # of directories: 2090 2017-04-21T17:44:16.418697+09:00 ERR cryptohomed[1537]: # of fsync()&fdatasync(): 17154 2017-04-21T17:44:16.418791+09:00 ERR cryptohomed[1537]: # of sync(): 1 2017-04-21T17:44:16.418926+09:00 ERR cryptohomed[1537]: Elapsed: 84383 ms 2017-04-21T17:44:16.419027+09:00 ERR cryptohomed[1537]: Elapsed (calculate total): 649 ms 2017-04-21T17:44:16.419125+09:00 ERR cryptohomed[1537]: Elapsed (prepare): 651 ms 2017-04-21T17:44:16.419237+09:00 ERR cryptohomed[1537]: Elapsed (sendfile): 2583 ms 2017-04-21T17:44:16.419336+09:00 ERR cryptohomed[1537]: Elapsed (fsync&fdatasync): 22429 ms 2017-04-21T17:44:16.419431+09:00 ERR cryptohomed[1537]: Elapsed (sync): 248 ms 2017-04-21T17:44:16.419525+09:00 ERR cryptohomed[1537]: Elapsed (report): 65 ms 2017-04-21T17:44:16.419624+09:00 ERR cryptohomed[1537]: Elapsed (for links): 249 ms 2017-04-21T17:44:16.419722+09:00 ERR cryptohomed[1537]: Elapsed (for files): 60656 ms 2017-04-21T17:44:16.419822+09:00 ERR cryptohomed[1537]: Elapsed (for files, before data transfer): 12707 ms 2017-04-21T17:44:16.419979+09:00 ERR cryptohomed[1537]: Elapsed (for files, for data transfer): 35255 ms 2017-04-21T17:44:16.420085+09:00 ERR cryptohomed[1537]: Elapsed (for files, after data transfer): 12619 ms 2017-04-21T17:44:16.420180+09:00 ERR cryptohomed[1537]: Elapsed (for dirs, before loop): 11479 ms 2017-04-21T17:44:16.420274+09:00 ERR cryptohomed[1537]: Elapsed (for dirs, after loop): 4242 ms 2017-04-21T17:44:16.420371+09:00 ERR cryptohomed[1537]: Elapsed (for delete): 5471 ms 2017-04-21T17:44:16.420481+09:00 ERR cryptohomed[1537]: 2.34435MB/s #3 Launched Play Store 2017-04-21T18:18:59.656795+09:00 ERR cryptohomed[1548]: Total bytes: 604277085 2017-04-21T18:18:59.656920+09:00 ERR cryptohomed[1548]: Sendfile bytes: 590243749 2017-04-21T18:18:59.657001+09:00 ERR cryptohomed[1548]: # of files: 11235 2017-04-21T18:18:59.657074+09:00 ERR cryptohomed[1548]: # of symlinks: 13 2017-04-21T18:18:59.657146+09:00 ERR cryptohomed[1548]: # of directories: 3260 2017-04-21T18:18:59.657218+09:00 ERR cryptohomed[1548]: # of fsync()&fdatasync(): 28891 2017-04-21T18:18:59.657287+09:00 ERR cryptohomed[1548]: # of sync(): 13 2017-04-21T18:18:59.657370+09:00 ERR cryptohomed[1548]: Elapsed: 166102 ms 2017-04-21T18:18:59.657506+09:00 ERR cryptohomed[1548]: Elapsed (calculate total): 6366 ms 2017-04-21T18:18:59.657585+09:00 ERR cryptohomed[1548]: Elapsed (prepare): 6368 ms 2017-04-21T18:18:59.657659+09:00 ERR cryptohomed[1548]: Elapsed (sendfile): 10031 ms 2017-04-21T18:18:59.657734+09:00 ERR cryptohomed[1548]: Elapsed (fsync&fdatasync): 39125 ms 2017-04-21T18:18:59.657805+09:00 ERR cryptohomed[1548]: Elapsed (sync): 1264 ms 2017-04-21T18:18:59.657878+09:00 ERR cryptohomed[1548]: Elapsed (report): 139 ms 2017-04-21T18:18:59.657958+09:00 ERR cryptohomed[1548]: Elapsed (for links): 1274 ms 2017-04-21T18:18:59.658036+09:00 ERR cryptohomed[1548]: Elapsed (for files): 119647 ms 2017-04-21T18:18:59.658568+09:00 ERR cryptohomed[1548]: Elapsed (for files, before data transfer): 22282 ms 2017-04-21T18:18:59.658660+09:00 ERR cryptohomed[1548]: Elapsed (for files, for data transfer): 74643 ms 2017-04-21T18:18:59.658713+09:00 ERR cryptohomed[1548]: Elapsed (for files, after data transfer): 22596 ms 2017-04-21T18:18:59.658765+09:00 ERR cryptohomed[1548]: Elapsed (for dirs, before loop): 19277 ms 2017-04-21T18:18:59.658842+09:00 ERR cryptohomed[1548]: Elapsed (for dirs, after loop): 6991 ms 2017-04-21T18:18:59.658895+09:00 ERR cryptohomed[1548]: Elapsed (for delete): 9840 ms 2017-04-21T18:18:59.658963+09:00 ERR cryptohomed[1548]: 3.63798MB/s #4 Installed a few Android apps 2017-04-21T17:56:14.175922+09:00 ERR cryptohomed[1537]: Total bytes: 1329490772 2017-04-21T17:56:14.176102+09:00 ERR cryptohomed[1537]: Sendfile bytes: 1315154229 2017-04-21T17:56:14.176260+09:00 ERR cryptohomed[1537]: # of files: 11529 2017-04-21T17:56:14.176396+09:00 ERR cryptohomed[1537]: # of symlinks: 15 2017-04-21T17:56:14.176528+09:00 ERR cryptohomed[1537]: # of directories: 3327 2017-04-21T17:56:14.176665+09:00 ERR cryptohomed[1537]: # of fsync()&fdatasync(): 29589 2017-04-21T17:56:14.176798+09:00 ERR cryptohomed[1537]: # of sync(): 15 2017-04-21T17:56:14.176968+09:00 ERR cryptohomed[1537]: Elapsed: 183678 ms 2017-04-21T17:56:14.177107+09:00 ERR cryptohomed[1537]: Elapsed (calculate total): 1265 ms 2017-04-21T17:56:14.177237+09:00 ERR cryptohomed[1537]: Elapsed (prepare): 1267 ms 2017-04-21T17:56:14.177367+09:00 ERR cryptohomed[1537]: Elapsed (sendfile): 21329 ms 2017-04-21T17:56:14.177499+09:00 ERR cryptohomed[1537]: Elapsed (fsync&fdatasync): 39184 ms 2017-04-21T17:56:14.177634+09:00 ERR cryptohomed[1537]: Elapsed (sync): 2189 ms 2017-04-21T17:56:14.177836+09:00 ERR cryptohomed[1537]: Elapsed (report): 132 ms 2017-04-21T17:56:14.178014+09:00 ERR cryptohomed[1537]: Elapsed (for links): 2203 ms 2017-04-21T17:56:14.178144+09:00 ERR cryptohomed[1537]: Elapsed (for files): 142035 ms 2017-04-21T17:56:14.178276+09:00 ERR cryptohomed[1537]: Elapsed (for files, before data transfer): 22656 ms 2017-04-21T17:56:14.178355+09:00 ERR cryptohomed[1537]: Elapsed (for files, for data transfer): 96666 ms 2017-04-21T17:56:14.178407+09:00 ERR cryptohomed[1537]: Elapsed (for files, after data transfer): 22582 ms 2017-04-21T17:56:14.178485+09:00 ERR cryptohomed[1537]: Elapsed (for dirs, before loop): 19377 ms 2017-04-21T17:56:14.178535+09:00 ERR cryptohomed[1537]: Elapsed (for dirs, after loop): 6742 ms 2017-04-21T17:56:14.178585+09:00 ERR cryptohomed[1537]: Elapsed (for delete): 9331 ms 2017-04-21T17:56:14.178659+09:00 ERR cryptohomed[1537]: 7.23814MB/s
,
Apr 21 2017
The rate varies from 2.3MB/s to 7.2MB, but in each case, file migration contributes to about 70% for the total amount of time elapsed. #1 120313/159256 = 76% #2 60656/84383 = 72% #3 119647/166102 = 72% #4 142035/183678 = 77%
,
Apr 21 2017
Other than time spent for files, the major contributor is directory operations (i.e. "Elapsed (for dirs, before loop)", "Elapsed (for dirs, after loop)", and "Elapsed (for delete)"). File transfer and directory oprations contribute to more than 90% of the total elapsed time.
,
Apr 24 2017
Can we ship with the original version for M-60 or do would we need any speed improvement?
,
Apr 24 2017
I've look at my mix of data on my machine with two accounts and Android running with photos and termux and music and other misc apps: 62061 (from statfs() f_files - f_ffree output inside termux) /home/.shadow/../vault 25641188 11216820 13098800 47% /home/chronos/user (from disk_usage from chrome://system ) So, at current rate; 11GB and 62k files would result in about 40 minutes?
,
Apr 24 2017
The transfer rate may vary from 2 MB/s to 7 MB/s depending on file size distribution and IO scheduler's behavior. With the current implementation, it's expected that migrating 11 GB takes 1500-5500 seconds.
,
Apr 24 2017
Good timing, just trying to collect some stats. Could you grab the following: find /home/.shadow/../mount/user/Cache -type f | wc -l find /home/.shadow/../mount/root/android-data/data/data/*/cache -type f | wc -l du -hcs /home/.shadow/../mount/user/Cache du -hcs /home/.shadow/../mount/root/android-data/data/data/*/cache
,
Apr 24 2017
Note that my device is not rooted so I can't run arbitrary commands on it.
,
Apr 27 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform2/+/52cae269ccc7da91e6ff73d04db9d82b27f19c51 commit 52cae269ccc7da91e6ff73d04db9d82b27f19c51 Author: Ryo Hashimoto <hashimoto@google.com> Date: Thu Apr 27 05:13:12 2017 cryptohome: Stop performing redundant IO in MigrateFile - Stop calling GetLength(). - Stop calling Flush() and SetLength() for the last chunk. With this change, migration completes about 10% faster. BUG= chromium:713988 TEST=cros_workon_make cryptohome --test Change-Id: I8fc8211fbb5d34552d506b7c33c5df63925653b5 Reviewed-on: https://chromium-review.googlesource.com/487842 Commit-Ready: Ryo Hashimoto <hashimoto@chromium.org> Tested-by: Ryo Hashimoto <hashimoto@chromium.org> Reviewed-by: Dan Spaid <dspaid@chromium.org> [modify] https://crrev.com/52cae269ccc7da91e6ff73d04db9d82b27f19c51/cryptohome/dircrypto_data_migrator/migration_helper.cc
,
May 16 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform2/+/31f931f8ea47d1111db56321ecf0e59dca80e93e commit 31f931f8ea47d1111db56321ecf0e59dca80e93e Author: Ryo Hashimoto <hashimoto@google.com> Date: Tue May 16 04:59:37 2017 cryptohome: Stop performing redundant IO in MigrateFile - Stop calling GetLength(). - Stop calling Flush() and SetLength() for the last chunk. With this change, migration completes about 10% faster. BUG= chromium:713988 TEST=cros_workon_make cryptohome --test Change-Id: I8fc8211fbb5d34552d506b7c33c5df63925653b5 Reviewed-on: https://chromium-review.googlesource.com/487842 Commit-Ready: Ryo Hashimoto <hashimoto@chromium.org> Tested-by: Ryo Hashimoto <hashimoto@chromium.org> Reviewed-by: Dan Spaid <dspaid@chromium.org> (cherry picked from commit 52cae269ccc7da91e6ff73d04db9d82b27f19c51) Reviewed-on: https://chromium-review.googlesource.com/505973 Reviewed-by: Ryo Hashimoto <hashimoto@chromium.org> Commit-Queue: Ryo Hashimoto <hashimoto@chromium.org> [modify] https://crrev.com/31f931f8ea47d1111db56321ecf0e59dca80e93e/cryptohome/dircrypto_data_migrator/migration_helper.cc
,
May 17 2017
,
May 23 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform2/+/c3a3698c08a366235a5ed260fb57450de3692733 commit c3a3698c08a366235a5ed260fb57450de3692733 Author: Hidehiko Abe <hidehiko@chromium.org> Date: Tue May 23 17:24:05 2017 login: Fix WriteFile error handling. PurgeStateAccounts test checks WriteFile return code with ASSERT_TRUE. This is wrong, because it returns -1 on error, and the size of write bytes on success. BUG= chromium:713988 TEST=cros_workon_make chromeos-login --test Change-Id: Ifefed8873d86b3531d29f9c8ca66c5bb2a894395 Reviewed-on: https://chromium-review.googlesource.com/512443 Commit-Ready: Hidehiko Abe <hidehiko@chromium.org> Tested-by: Hidehiko Abe <hidehiko@chromium.org> Reviewed-by: Mattias Nissler <mnissler@chromium.org> [modify] https://crrev.com/c3a3698c08a366235a5ed260fb57450de3692733/login_manager/device_local_account_policy_service_unittest.cc
,
May 24 2017
,
May 26 2017
The following revision refers to this bug: https://chromium.googlesource.com/chromiumos/platform2/+/cce3487ae90204234402dfae890d9a7fe7683420 commit cce3487ae90204234402dfae890d9a7fe7683420 Author: Ryo Hashimoto <hashimoto@google.com> Date: Fri May 26 09:46:06 2017 cryptohome: Multi-threaded data migration Files and links are migrated on job threads, while the main thread traverses the directory tree and feed jobs. Chunk size calculation is changed to limit disk space usage. BUG= chromium:713988 TEST=cros_workon_make cryptohome --test Change-Id: I6c797d01dfbaa47e349f4749728c45e0a39c2caf Reviewed-on: https://chromium-review.googlesource.com/492867 Commit-Ready: Ryo Hashimoto <hashimoto@chromium.org> Tested-by: Ryo Hashimoto <hashimoto@chromium.org> Reviewed-by: Hidehiko Abe <hidehiko@chromium.org> [modify] https://crrev.com/cce3487ae90204234402dfae890d9a7fe7683420/cryptohome/dircrypto_data_migrator/migration_helper_unittest.cc [modify] https://crrev.com/cce3487ae90204234402dfae890d9a7fe7683420/cryptohome/dircrypto_data_migrator/migration_helper.cc [modify] https://crrev.com/cce3487ae90204234402dfae890d9a7fe7683420/cryptohome/dircrypto_data_migrator/migration_helper.h [modify] https://crrev.com/cce3487ae90204234402dfae890d9a7fe7683420/cryptohome/mock_platform.h [modify] https://crrev.com/cce3487ae90204234402dfae890d9a7fe7683420/cryptohome/platform.cc [modify] https://crrev.com/cce3487ae90204234402dfae890d9a7fe7683420/cryptohome/platform.h
,
May 29 2017
Now it should be about 2.5x faster than before. A few more small improvements are still possible, but let me close this issue for now. All changes are included in M-60 branch.
,
Jan 22 2018
|
|||||||
►
Sign in to add a comment |
|||||||
Comment 1 by dspaid@chromium.org
, Apr 21 2017