Open Radar

 
Area:
Performance (slow, hung)

Summary:
Originally filed under 32934061, which was incorrectly marked as a duplicate of 32928868 and closed. I still experience this problem on 10.13db4 17A315i and was instructed to open a new bug report.

When comparing APFS’ performance to HFS+’s for common operations done during software development, I found that in no case does APFS perform better than HFS+. In some cases, it performs worse.

Development of a large project like Chrome often involves tools scanning many files to determine whether they’ve changed, either by examining their data or metadata such as timestamps. Chrome’s main git repository contains over 250,000 files, all repositories together contain over 400,000 files, and a build produces over 40,000 files. This can present quite a workout to a filesystem.

I found that with a cold buffer cache (following system boot), “git status” takes twice as long on APFS as it does on HFS+. A null build, in which everything’s already up-to-date and nothing new needs to be compiled, also takes longer on APFS than it does on HFS+. This tests each filesystem’s speed of reading file metadata, notably, modification timestamps.

On the other hand, most of the differences disappear with a warm buffer cache.

Summarizing various results, here are the wall clock times for various operations.

                                                   APFS   HFS+
git status, with core.untrackedcache false, cold  7.654  4.311
                                          , warm  1.428  1.174
git status, with core.untrackedcache true, cold   7.797  3.810
                                         , warm   0.726  0.684
null build, cold                                  8.193  6.014
          , warm                                  2.018  2.031

Both APFS and HFS+ volumes were on the same physical media, and neither was encrypted. For all tests, the system was installed on the APFS volume. Each “cold” test was performed immediately following a reboot, and each “warm” test was performed immediately thereafter. APFS and HFS+ were never tested during the same boot, to ensure that all parts of the system were equally cold and warm for purposes of comparison testing.

Tests were performed on a MacBook Pro (15-inch, 2016) (MacBookPro13,3) with a 512GB SSD (APPLE SSD SM0512L). Chrome was synced to c2c8d078d585958a92e62c96de953ed3ab8e8cfe (https://crrev.com/c2c8d078d585958a92e62c96de953ed3ab8e8cfe).

APFS is not performing on par with developer expectations coming from HFS+.

Steps to Reproduce:
Preconditions: Be sure that Xcode is installed. Be sure that it’s been launched, that you’ve accepted its license, and that it’s had the opportunity to install any components necessary. Be sure that xcode-select points to it.

Check out and build Chromium, once on an APFS volume, and once again on an HFS+ volume. (A more complete guide to building Chromium is at https://chromium.googlesource.com/chromium/src/+/master/docs/mac_build_instructions.md.)

% git clone https://chromium.googlesource.com/chromium/tools/depot_tools.git
% PATH="${PATH}:$(pwd)/depot_tools"
% mkdir chromium
% cd chromium
% mount | grep -F $(df . | tail +2 | cut -d' ' -f1)
/dev/disk1s1 on / (apfs, local, journaled)
% fetch chromium
[…wait…]
% cd src
% gn gen out/debug
Done. Made 6756 targets from 1296 files in 6251ms
% ninja -C out/debug chrome
ninja: Entering directory `out/debug'
[…wait…]
[29471/29471] STAMP obj/chrome/chrome.stamp
% mkdir /Volumes/HFSPlus/chromium
% cd /Volumes/HFSPlus/chromium
% mount | grep -F $(df . | tail +2 | cut -d' ' -f1)
/dev/disk0s4 on /Volumes/HFSPlus (hfs, local, journaled)
% fetch chromium
[…wait…]
% cd src
% gn gen out/debug
Done. Made 6756 targets from 1296 files in 6332ms
% ninja -C out/debug chrome
ninja: Entering directory `out/debug'
[…wait…]
[29471/29471] STAMP obj/chrome/chrome.stamp

Then, on each volume, test “git status” and the “ninja -C out/debug chrome” null build, both cold (immediately following boot) and warm (immediately thereafter).

Note that actually achieving a null build on an APFS+ volume is tricky due to radar 32928868. In order to reach a state where the timestamps stopped moving, I had to do several null builds and then reboot to attempt a re-test.

Expected Results:
HFS+ results

(git config --global core.untrackedcache false; git update-index; reboot)
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  1.48s user 8.51s system 231% cpu 4.311 total
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  0.68s user 2.62s system 281% cpu 1.174 total

(git config --global core.untrackedcache true; git update-index; reboot)
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  1.19s user 8.13s system 244% cpu 3.810 total
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  0.39s user 2.27s system 389% cpu 0.684 total

(reboot)
% time ninja -C out/debug chrome
ninja: Entering directory `out/debug'
ninja: no work to do.
ninja -C out/debug chrome  1.86s user 1.62s system 57% cpu 6.014 total
% time ninja -C out/debug chrome
ninja: Entering directory `out/debug'
ninja: no work to do.
ninja -C out/debug chrome  1.59s user 0.43s system 99% cpu 2.031 total

Observed Results:
APFS results

(git config --global core.untrackedcache false; git update-index; reboot)
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  1.57s user 30.67s system 421% cpu 7.654 total
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  0.69s user 2.84s system 247% cpu 1.428 total

(git config --global core.untrackedcache true; git update-index; reboot)
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  1.64s user 31.23s system 421% cpu 7.797 total
% time git status
On branch master
Your branch is up-to-date with 'origin/master'.
nothing to commit, working tree clean
git status  0.41s user 2.43s system 391% cpu 0.726 total

(reboot)
litterbox@litterbox zsh% time ninja -C out/debug chrome
ninja: Entering directory `out/debug'
ninja: no work to do.
ninja -C out/debug chrome  1.96s user 2.61s system 55% cpu 8.193 total
litterbox@litterbox zsh% time ninja -C out/debug chrome
ninja: Entering directory `out/debug'
ninja: no work to do.
ninja -C out/debug chrome  1.57s user 0.42s system 98% cpu 2.018 total

Version:
10.13db4 17A315i with Xcode 9b4 9M189t.
I have experienced this on every 10.13 beta back to the original 10.13db1 17A264c with Xcode 9b1 9M136h.