Initial pass at storage benchmarks.

Now that we're offering to store private app data on adopted storage
devices, the performance of those devices is much more important to
overall user experience.

To help set user expectations, this change offers to execute a
real-world benchmark on a storage device, returning a metric that can
be used to compare internal and external storage.  The benchmark is
generated from the strace-instrumented storage access patterns of
typical apps.

A typical device completes the benchmark in under two seconds on
internal storage, a UHS-3 SD card is even faster (!), but a very slow
Class 4 SD card takes about 30 seconds to complete, giving us a clear
signal.

The measured benchmark numbers are logged along with information
about the storage device, such as manufacturer, model, etc.  Card
serial numbers are scrubbed from output.

Bug: 21172095
Change-Id: I9b2713dafdfdfcf5d97bf1bc21841f39409a7e54

Android.mk

@@ -23,6 +23,7 @@ common_src_files := \
 	EmulatedVolume.cpp \
 	Utils.cpp \
 	MoveTask.cpp \
+	Benchmark.cpp \
 
 common_c_includes := \
 	system/extras/ext4_utils \

Benchmark.cpp

@@ -0,0 +1,138 @@
+/*
+ * Copyright (C) 2015 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#include "Benchmark.h"
+#include "BenchmarkGen.h"
+#include "VolumeManager.h"
+#include "ResponseCode.h"
+
+#include <base/file.h>
+#include <base/logging.h>
+#include <cutils/iosched_policy.h>
+
+#include <sys/time.h>
+#include <sys/resource.h>
+
+using android::base::ReadFileToString;
+using android::base::WriteStringToFile;
+
+namespace android {
+namespace vold {
+
+static std::string simpleRead(const std::string& path) {
+    std::string tmp;
+    ReadFileToString(path, &tmp);
+    tmp.erase(tmp.find_last_not_of(" \n\r") + 1);
+    return tmp;
+}
+
+nsecs_t Benchmark(const std::string& path, const std::string& sysPath) {
+    errno = 0;
+    int orig_prio = getpriority(PRIO_PROCESS, 0);
+    if (errno != 0) {
+        PLOG(ERROR) << "Failed to getpriority";
+        return -1;
+    }
+    if (setpriority(PRIO_PROCESS, 0, -10) != 0) {
+        PLOG(ERROR) << "Failed to setpriority";
+        return -1;
+    }
+
+    IoSchedClass orig_clazz = IoSchedClass_NONE;
+    int orig_ioprio = 0;
+    if (android_get_ioprio(0, &orig_clazz, &orig_ioprio)) {
+        PLOG(ERROR) << "Failed to android_get_ioprio";
+        return -1;
+    }
+    if (android_set_ioprio(0, IoSchedClass_RT, 0)) {
+        PLOG(ERROR) << "Failed to android_set_ioprio";
+        return -1;
+    }
+
+    char orig_cwd[PATH_MAX];
+    if (getcwd(orig_cwd, PATH_MAX) == NULL) {
+        PLOG(ERROR) << "Failed getcwd";
+        return -1;
+    }
+    if (chdir(path.c_str()) != 0) {
+        PLOG(ERROR) << "Failed chdir";
+        return -1;
+    }
+
+    LOG(INFO) << "Benchmarking " << path;
+    nsecs_t start = systemTime(SYSTEM_TIME_BOOTTIME);
+
+    BenchmarkCreate();
+    nsecs_t create = systemTime(SYSTEM_TIME_BOOTTIME);
+
+    if (!WriteStringToFile("3", "/proc/sys/vm/drop_caches")) {
+        PLOG(ERROR) << "Failed to drop_caches";
+    }
+    nsecs_t drop = systemTime(SYSTEM_TIME_BOOTTIME);
+
+    BenchmarkRun();
+    nsecs_t run = systemTime(SYSTEM_TIME_BOOTTIME);
+
+    BenchmarkDestroy();
+    nsecs_t destroy = systemTime(SYSTEM_TIME_BOOTTIME);
+
+    nsecs_t create_d = create - start;
+    nsecs_t drop_d = drop - create;
+    nsecs_t run_d = run - drop;
+    nsecs_t destroy_d = destroy - run;
+
+    LOG(INFO) << "create took " << nanoseconds_to_milliseconds(create_d) << "ms";
+    LOG(INFO) << "drop took " << nanoseconds_to_milliseconds(drop_d) << "ms";
+    LOG(INFO) << "run took " << nanoseconds_to_milliseconds(run_d) << "ms";
+    LOG(INFO) << "destroy took " << nanoseconds_to_milliseconds(destroy_d) << "ms";
+
+    std::string detail;
+    detail += "id=" + BenchmarkIdent()
+            + ",cr=" + std::to_string(create_d)
+            + ",dr=" + std::to_string(drop_d)
+            + ",ru=" + std::to_string(run_d)
+            + ",de=" + std::to_string(destroy_d)
+            + ",si=" + simpleRead(sysPath + "/size")
+            + ",ve=" + simpleRead(sysPath + "/device/vendor")
+            + ",mo=" + simpleRead(sysPath + "/device/model")
+            + ",csd=" + simpleRead(sysPath + "/device/csd")
+            + ",scr=" + simpleRead(sysPath + "/device/scr");
+
+    // Scrub CRC and serial number out of CID
+    std::string cid = simpleRead(sysPath + "/device/cid");
+    if (cid.length() == 32) {
+        cid.erase(32, 1);
+        cid.erase(18, 8);
+        detail += ",cid=" + cid;
+    }
+
+    VolumeManager::Instance()->getBroadcaster()->sendBroadcast(
+            ResponseCode::BenchmarkResult, detail.c_str(), false);
+
+    if (chdir(orig_cwd) != 0) {
+        PLOG(ERROR) << "Failed to chdir";
+    }
+    if (android_set_ioprio(0, orig_clazz, orig_ioprio)) {
+        PLOG(ERROR) << "Failed to android_set_ioprio";
+    }
+    if (setpriority(PRIO_PROCESS, 0, orig_prio) != 0) {
+        PLOG(ERROR) << "Failed to setpriority";
+    }
+    return run_d;
+}
+
+}  // namespace vold
+}  // namespace android

Benchmark.h

@@ -0,0 +1,33 @@
+/*
+ * Copyright (C) 2015 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+#ifndef ANDROID_VOLD_BENCHMARK_H
+#define ANDROID_VOLD_BENCHMARK_H
+
+#include <utils/Errors.h>
+#include <utils/Timers.h>
+
+#include <string>
+
+namespace android {
+namespace vold {
+
+nsecs_t Benchmark(const std::string& path, const std::string& sysPath);
+
+}  // namespace vold
+}  // namespace android
+
+#endif

CommandListener.cpp

@@ -25,8 +25,13 @@
 #include <fs_mgr.h>
 #include <stdio.h>
 #include <string.h>
+#include <stdint.h>
+#include <inttypes.h>
 
 #define LOG_TAG "VoldCmdListener"
+
+#include <base/stringprintf.h>
+#include <cutils/fs.h>
 #include <cutils/log.h>
 
 #include <sysutils/SocketClient.h>
@@ -238,6 +243,13 @@ int CommandListener::VolumeCmd::runCommand(SocketClient *cli,
 
         (new android::vold::MoveTask(fromVol, toVol))->start();
         return sendGenericOkFail(cli, 0);
+
+    } else if (cmd == "benchmark" && argc > 2) {
+        // benchmark [volId]
+        std::string id(argv[2]);
+        nsecs_t res = vm->benchmarkVolume(id);
+        return cli->sendMsg(ResponseCode::CommandOkay,
+                android::base::StringPrintf("%" PRId64, res).c_str(), false);
     }
 
     return cli->sendMsg(ResponseCode::CommandSyntaxError, nullptr, false);

Disk.h

@@ -49,6 +49,8 @@ public:
         kSd = 1 << 2,
         /* Flag that disk is USB disk */
         kUsb = 1 << 3,
+        /* Flag that disk is EMMC internal */
+        kEmmc = 1 << 4,
     };
 
     const std::string& getId() { return mId; }

ResponseCode.h

@@ -82,6 +82,7 @@ public:
     static const int VolumeDestroyed = 659;
 
     static const int MoveStatus = 660;
+    static const int BenchmarkResult = 661;
 
     static int convertFromErrno();
 };

VolumeManager.cpp

@@ -45,6 +45,7 @@
 
 #include <private/android_filesystem_config.h>
 
+#include "Benchmark.h"
 #include "EmulatedVolume.h"
 #include "VolumeManager.h"
 #include "NetlinkManager.h"
@@ -367,6 +368,43 @@ std::shared_ptr<android::vold::VolumeBase> VolumeManager::findVolume(const std::
     return nullptr;
 }
 
+nsecs_t VolumeManager::benchmarkVolume(const std::string& id) {
+    std::string path;
+    std::string sysPath;
+    auto vol = findVolume(id);
+    if (vol != nullptr) {
+        if (vol->getState() == android::vold::VolumeBase::State::kMounted) {
+            path = vol->getPath();
+            auto disk = findDisk(vol->getDiskId());
+            if (disk != nullptr) {
+                sysPath = disk->getSysPath();
+            }
+        }
+    } else {
+        path = "/data";
+    }
+
+    if (path.empty()) {
+        LOG(WARNING) << "Failed to find volume for " << id;
+        return -1;
+    }
+
+    path += "/misc";
+    if (android::vold::PrepareDir(path, 01771, AID_SYSTEM, AID_MISC)) {
+        return -1;
+    }
+    path += "/vold";
+    if (android::vold::PrepareDir(path, 0700, AID_ROOT, AID_ROOT)) {
+        return -1;
+    }
+    path += "/bench";
+    if (android::vold::PrepareDir(path, 0700, AID_ROOT, AID_ROOT)) {
+        return -1;
+    }
+
+    return android::vold::Benchmark(path, sysPath);
+}
+
 int VolumeManager::linkPrimary(userid_t userId) {
     std::string source(mPrimary->getPath());
     if (mPrimary->getType() == android::vold::VolumeBase::Type::kEmulated) {

VolumeManager.h

@@ -29,6 +29,7 @@
 
 #include <cutils/multiuser.h>
 #include <utils/List.h>
+#include <utils/Timers.h>
 #include <sysutils/SocketListener.h>
 #include <sysutils/NetlinkEvent.h>
 
@@ -115,6 +116,8 @@ public:
     std::shared_ptr<android::vold::Disk> findDisk(const std::string& id);
     std::shared_ptr<android::vold::VolumeBase> findVolume(const std::string& id);
 
+    nsecs_t benchmarkVolume(const std::string& id);
+
     int startUser(userid_t userId);
     int cleanupUser(userid_t userId);
 

bench/benchgen.py

@@ -0,0 +1,338 @@
+#!/usr/bin/env python
+
+# Copyright (C) 2015 The Android Open Source Project
+#
+# Licensed under the Apache License, Version 2.0 (the 'License');
+# you may not use this file except in compliance with the License.
+# You may obtain a copy of the License at
+#
+#      http://www.apache.org/licenses/LICENSE-2.0
+#
+# Unless required by applicable law or agreed to in writing, software
+# distributed under the License is distributed on an 'AS IS' BASIS,
+# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+# See the License for the specific language governing permissions and
+# limitations under the License.
+
+"""
+Generates storage benchmark from captured strace output.
+
+Currently assumes that all mmap'ed regions are resource accesses, and emulates as pread().
+
+Usage:
+$ adb shell strace -p `pid zygote` -o /data/local/tmp/trace -f -ff -y -ttt -e trace=file,desc,munmap
+$ adb pull /data/local/tmp/trace*
+$ python benchgen.py trace.*
+
+"""
+
+import re, sys, collections, traceback, argparse
+
+from operator import itemgetter
+from collections import defaultdict
+
+class Event:
+    def __init__(self, thread, time, call, args, ret):
+        self.thread = thread
+        self.time = time
+        self.call = call
+        self.args = args
+        self.ret = ret
+
+    def __repr__(self):
+        return "%s(%s)=%s" % (self.call, repr(self.args), self.ret)
+
+
+class File:
+    def __init__(self, name, ident):
+        self.name = name
+        self.ident = ident
+        self.size = 0
+
+    def __repr__(self):
+        return self.name
+
+
+events = []
+files = {}
+
+def find_file(name):
+    name = name.strip('<>"')
+    if name not in files:
+        files[name] = File(name, len(files))
+    return files[name]
+
+def extract_file(e, arg):
+    if "<" in arg:
+        fd, path = arg.split("<")
+        path = path.strip(">")
+        handle = "t%sf%s" % (e.thread, fd)
+        return (fd, find_file(path), handle)
+    else:
+        return (None, None, None)
+
+def parse_args(s):
+    args = []
+    arg = ""
+    esc = False
+    quot = False
+    for c in s:
+        if esc:
+            esc = False
+            arg += c
+            continue
+
+        if c == '"':
+            if quot:
+                quot = False
+                continue
+            else:
+                quot = True
+                continue
+
+        if c == '\\':
+            esc = True
+            continue
+
+        if c == ',' and not quot:
+            args.append(arg.strip())
+            arg = ""
+        else:
+            arg += c
+
+    args.append(arg.strip())
+    return args
+
+
+bufsize = 1048576
+interesting = ["mmap2","read","write","pread64","pwrite64","fsync","fdatasync","openat","close","lseek","_llseek"]
+
+re_event = re.compile(r"^([\d\.]+) (.+?)\((.+?)\) = (.+?)$")
+re_arg = re.compile(r'''((?:[^,"']|"[^"]*"|'[^']*')+)''')
+for fn in sys.argv[1:]:
+    with open(fn) as f:
+        thread = int(fn.split(".")[-1])
+        for line in f:
+            line = re_event.match(line)
+            if not line: continue
+
+            time, call, args, ret = line.groups()
+            if call not in interesting: continue
+            if "/data/" not in args: continue
+
+            time = float(time)
+            args = parse_args(args)
+            events.append(Event(thread, time, call, args, ret))
+
+
+with open("BenchmarkGen.h", 'w') as bench:
+    print >>bench, """/*
+ * Copyright (C) 2015 The Android Open Source Project
+ *
+ * Licensed under the Apache License, Version 2.0 (the "License");
+ * you may not use this file except in compliance with the License.
+ * You may obtain a copy of the License at
+ *
+ *      http://www.apache.org/licenses/LICENSE-2.0
+ *
+ * Unless required by applicable law or agreed to in writing, software
+ * distributed under the License is distributed on an "AS IS" BASIS,
+ * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+ * See the License for the specific language governing permissions and
+ * limitations under the License.
+ */
+
+
+/******************************************************************
+ * THIS CODE WAS GENERATED BY benchgen.py, DO NOT MODIFY DIRECTLY *
+ ******************************************************************/
+
+
+#include <base/logging.h>
+
+#include <stdlib.h>
+#include <sys/types.h>
+#include <sys/stat.h>
+#include <sys/sendfile.h>
+#include <fcntl.h>
+
+#include <algorithm>
+#include <string>
+
+namespace android {
+namespace vold {
+
+static status_t BenchmarkRun() {
+"""
+
+    print >>bench, "char* buf = (char*) malloc(%d);" % (bufsize)
+
+    nread = 0
+    nwrite = 0
+    nsync = 0
+    events = sorted(events, key=lambda e: e.time)
+    active = set()
+    defined = set()
+    for e in events:
+        if e.call == "openat":
+            fd, f, handle = extract_file(e, e.ret)
+            if f:
+                active.add(handle)
+                if handle not in defined:
+                    print >>bench, "int ",
+                    defined.add(handle)
+                print >>bench, '%s = TEMP_FAILURE_RETRY(open("file%s", %s));' % (handle, f.ident, e.args[2])
+
+        elif e.call == "close":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                active.remove(handle)
+                print >>bench, 'TEMP_FAILURE_RETRY(close(%s));' % (handle)
+
+        elif e.call == "lseek":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                print >>bench, 'TEMP_FAILURE_RETRY(lseek(%s, %s, %s));' % (handle, e.args[1], e.args[2])
+
+        elif e.call == "_llseek":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                print >>bench, 'TEMP_FAILURE_RETRY(lseek(%s, %s, %s));' % (handle, e.args[1], e.args[3])
+
+        elif e.call == "read":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                # TODO: track actual file size instead of guessing
+                count = min(int(e.args[2]), bufsize)
+                f.size += count
+                print >>bench, 'TEMP_FAILURE_RETRY(read(%s, buf, %d));' % (handle, count)
+                nread += 1
+
+        elif e.call == "write":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                # TODO: track actual file size instead of guessing
+                count = min(int(e.args[2]), bufsize)
+                f.size += count
+                print >>bench, 'TEMP_FAILURE_RETRY(read(%s, buf, %d));' % (handle, count)
+                nwrite += 1
+
+        elif e.call == "pread64":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                f.size = max(f.size, int(e.args[2]) + int(e.args[3]))
+                count = min(int(e.args[2]), bufsize)
+                print >>bench, 'TEMP_FAILURE_RETRY(pread(%s, buf, %d, %s));' % (handle, count, e.args[3])
+                nread += 1
+
+        elif e.call == "pwrite64":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                f.size = max(f.size, int(e.args[2]) + int(e.args[3]))
+                count = min(int(e.args[2]), bufsize)
+                print >>bench, 'TEMP_FAILURE_RETRY(pwrite(%s, buf, %d, %s));' % (handle, count, e.args[3])
+                nwrite += 1
+
+        elif e.call == "fsync":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                print >>bench, 'TEMP_FAILURE_RETRY(fsync(%s));' % (handle)
+                nsync += 1
+
+        elif e.call == "fdatasync":
+            fd, f, handle = extract_file(e, e.args[0])
+            if handle in active:
+                print >>bench, 'TEMP_FAILURE_RETRY(fdatasync(%s));' % (handle)
+                nsync += 1
+
+        elif e.call == "mmap2":
+            fd, f, handle = extract_file(e, e.args[4])
+            if handle in active:
+                count = min(int(e.args[1]), bufsize)
+                offset = int(e.args[5], 0)
+                f.size = max(f.size, count + offset)
+                print >>bench, 'TEMP_FAILURE_RETRY(pread(%s, buf, %s, %s)); // mmap2' % (handle, count, offset)
+                nread += 1
+
+    for handle in active:
+        print >>bench, 'TEMP_FAILURE_RETRY(close(%s));' % (handle)
+
+    print >>bench, """
+free(buf);
+return 0;
+}
+
+static status_t CreateFile(const char* name, size_t len) {
+    status_t res = -1;
+    int in = -1;
+    int out = -1;
+
+    if ((in = TEMP_FAILURE_RETRY(open("/dev/zero", O_RDONLY))) < 0) {
+        PLOG(ERROR) << "Failed to open";
+        goto done;
+    }
+    if ((out = TEMP_FAILURE_RETRY(open(name, O_WRONLY|O_CREAT|O_TRUNC))) < 0) {
+        PLOG(ERROR) << "Failed to open " << name;
+        goto done;
+    }
+
+    char buf[65536];
+    while (len > 0) {
+        int n = read(in, buf, std::min(len, sizeof(buf)));
+        if (write(out, buf, n) != n) {
+            PLOG(ERROR) << "Failed to write";
+            goto done;
+        }
+        len -= n;
+    }
+
+    res = 0;
+done:
+    close(in);
+    close(out);
+    return res;
+}
+
+static status_t BenchmarkCreate() {
+status_t res = 0;
+res |= CreateFile("stub", 0);
+"""
+    for f in files.values():
+        print >>bench, 'res |= CreateFile("file%s", %d);' % (f.ident, f.size)
+
+    print >>bench, """
+return res;
+}
+
+static status_t BenchmarkDestroy() {
+status_t res = 0;
+res |= unlink("stub");
+"""
+    for f in files.values():
+        print >>bench, 'res |= unlink("file%s");' % (f.ident)
+
+    print >>bench, """
+return res;
+}
+
+static std::string BenchmarkIdent() {"""
+    print >>bench, """return "r%d:w%d:s%d";""" % (nread, nwrite, nsync)
+    print >>bench, """}
+
+}  // namespace vold
+}  // namespace android
+"""
+
+
+size = sum([ f.size for f in files.values() ])
+print "Found", len(files), "data files accessed, total size", (size/1024), "kB"
+
+types = defaultdict(int)
+for e in events:
+    types[e.call] += 1
+
+print "Found syscalls:"
+for t, n in types.iteritems():
+    print str(n).rjust(8), t
+
+print