Merge "storaged: add task io to dump service"

This commit is contained in:
Jin Qian 2017-07-26 22:47:42 +00:00 committed by Android (Google) Code Review
commit 6abe26cdf4
7 changed files with 225 additions and 86 deletions

View File

@ -97,22 +97,6 @@ struct disk_perf {
uint32_t queue; // I/Os in queue
};
#define CMD_MAX_LEN ( 64 )
struct task_info {
uint32_t pid; // task id
uint64_t rchar; // characters read
uint64_t wchar; // characters written
uint64_t syscr; // read syscalls
uint64_t syscw; // write syscalls
uint64_t read_bytes; // bytes read (from storage layer)
uint64_t write_bytes; // bytes written (to storage layer)
uint64_t cancelled_write_bytes; // cancelled write byte by truncate
uint64_t starttime; // start time of task
char cmd[CMD_MAX_LEN]; // filename of the executable
};
class lock_t {
sem_t* mSem;
public:

View File

@ -41,7 +41,7 @@ enum io_type_t {
IO_TYPES = 2
};
struct uid_io_stats {
struct io_stats {
uint64_t rchar; // characters read
uint64_t wchar; // characters written
uint64_t read_bytes; // bytes read (from storage layer)
@ -49,14 +49,30 @@ struct uid_io_stats {
uint64_t fsync; // number of fsync syscalls
};
struct task_info {
std::string comm;
pid_t pid;
struct io_stats io[UID_STATS];
bool parse_task_io_stats(std::string&& s);
};
struct uid_info {
uint32_t uid; // user id
std::string name; // package name
struct uid_io_stats io[UID_STATS]; // [0]:foreground [1]:background
struct io_stats io[UID_STATS]; // [0]:foreground [1]:background
std::unordered_map<uint32_t, task_info> tasks; // mapped from pid
bool parse_uid_io_stats(std::string&& s);
};
struct io_usage {
uint64_t bytes[IO_TYPES][UID_STATS][CHARGER_STATS];
bool is_zero() const;
};
struct uid_io_usage {
uint64_t bytes[IO_TYPES][UID_STATS][CHARGER_STATS];
struct io_usage uid_ios;
// mapped from task comm to task io usage
std::map<std::string, struct io_usage> task_ios;
};
struct uid_record {

View File

@ -35,7 +35,7 @@ bool parse_emmc_ecsd(int ext_csd_fd, struct emmc_info* info);
void sort_running_uids_info(std::vector<struct uid_info> &uids);
// Logging
void log_console_running_uids_info(std::vector<struct uid_info> uids);
void log_console_running_uids_info(const std::vector<struct uid_info>& uids, bool flag_dump_task);
void log_debug_disk_perf(struct disk_perf* perf, const char* type);

View File

@ -63,13 +63,15 @@ void* storaged_main(void* /* unused */) {
static void help_message(void) {
printf("usage: storaged [OPTION]\n");
printf(" -u --uid Dump uid I/O usage to stdout\n");
printf(" -t --task Dump task I/O usage to stdout\n");
printf(" -s --start Start storaged (default)\n");
fflush(stdout);
}
int main(int argc, char** argv) {
int flag_main_service = 0;
int flag_dump_uid = 0;
bool flag_main_service = false;
bool flag_dump_uid = false;
bool flag_dump_task = false;
int opt;
for (;;) {
@ -78,19 +80,23 @@ int main(int argc, char** argv) {
{"start", no_argument, 0, 's'},
{"kill", no_argument, 0, 'k'},
{"uid", no_argument, 0, 'u'},
{"task", no_argument, 0, 't'},
{"help", no_argument, 0, 'h'}
};
opt = getopt_long(argc, argv, ":skdhu0", long_options, &opt_idx);
opt = getopt_long(argc, argv, ":skdhu0t", long_options, &opt_idx);
if (opt == -1) {
break;
}
switch (opt) {
case 's':
flag_main_service = 1;
flag_main_service = true;
break;
case 'u':
flag_dump_uid = 1;
flag_dump_uid = true;
break;
case 't':
flag_dump_task = true;
break;
case 'h':
help_message();
@ -104,10 +110,10 @@ int main(int argc, char** argv) {
}
if (argc == 1) {
flag_main_service = 1;
flag_main_service = true;
}
if (flag_main_service && flag_dump_uid) {
if (flag_main_service && (flag_dump_uid || flag_dump_task)) {
fprintf(stderr, "Invalid arguments. Option \"start\" and \"dump\" cannot be used together.\n");
help_message();
return -1;
@ -130,7 +136,7 @@ int main(int argc, char** argv) {
return 0;
}
if (flag_dump_uid) {
if (flag_dump_uid || flag_dump_task) {
sp<IStoraged> storaged_service = get_storaged_service();
if (storaged_service == NULL) {
fprintf(stderr, "Cannot find storaged service.\nMaybe run storaged --start first?\n");
@ -144,7 +150,7 @@ int main(int argc, char** argv) {
}
sort_running_uids_info(res);
log_console_running_uids_info(res);
log_console_running_uids_info(res, flag_dump_task);
return 0;
}

View File

@ -14,6 +14,7 @@
* limitations under the License.
*/
#include <inttypes.h>
#include <stdint.h>
#include <vector>
@ -47,6 +48,15 @@ std::vector<struct uid_info> BpStoraged::dump_uids(const char* /*option*/) {
uid.uid = reply.readInt32();
uid.name = reply.readCString();
reply.read(&uid.io, sizeof(uid.io));
uint32_t tasks_size = reply.readInt32();
for (uint32_t i = 0; i < tasks_size; i++) {
struct task_info task;
task.pid = reply.readInt32();
task.comm = reply.readCString();
reply.read(&task.io, sizeof(task.io));
uid.tasks[task.pid] = task;
}
}
return res;
}
@ -59,10 +69,17 @@ status_t BnStoraged::onTransact(uint32_t code, const Parcel& data, Parcel* reply
return BAD_TYPE;
std::vector<struct uid_info> res = dump_uids(NULL);
reply->writeInt32(res.size());
for (auto uid : res) {
for (const auto& uid : res) {
reply->writeInt32(uid.uid);
reply->writeCString(uid.name.c_str());
reply->write(&uid.io, sizeof(uid.io));
reply->writeInt32(uid.tasks.size());
for (const auto& task_it : uid.tasks) {
reply->writeInt32(task_it.first);
reply->writeCString(task_it.second.comm.c_str());
reply->write(&task_it.second.io, sizeof(task_it.second.io));
}
}
return NO_ERROR;
}
@ -96,6 +113,7 @@ status_t Storaged::dump(int fd, const Vector<String16>& args) {
int time_window = 0;
uint64_t threshold = 0;
bool force_report = false;
bool debug = false;
for (size_t i = 0; i < args.size(); i++) {
const auto& arg = args[i];
if (arg == String16("--hours")) {
@ -123,6 +141,10 @@ status_t Storaged::dump(int fd, const Vector<String16>& args) {
force_report = true;
continue;
}
if (arg == String16("--debug")) {
debug = true;
continue;
}
}
uint64_t last_ts = 0;
@ -130,22 +152,41 @@ status_t Storaged::dump(int fd, const Vector<String16>& args) {
storaged->get_uid_records(hours, threshold, force_report);
for (const auto& it : records) {
if (last_ts != it.second.start_ts) {
dprintf(fd, "%llu", (unsigned long long)it.second.start_ts);
dprintf(fd, "%" PRIu64, it.second.start_ts);
}
dprintf(fd, ",%llu\n", (unsigned long long)it.first);
dprintf(fd, ",%" PRIu64 "\n", it.first);
last_ts = it.first;
for (const auto& record : it.second.entries) {
dprintf(fd, "%s %ju %ju %ju %ju %ju %ju %ju %ju\n",
const struct io_usage& uid_usage = record.ios.uid_ios;
dprintf(fd, "%s %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64
" %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 "\n",
record.name.c_str(),
record.ios.bytes[READ][FOREGROUND][CHARGER_OFF],
record.ios.bytes[WRITE][FOREGROUND][CHARGER_OFF],
record.ios.bytes[READ][BACKGROUND][CHARGER_OFF],
record.ios.bytes[WRITE][BACKGROUND][CHARGER_OFF],
record.ios.bytes[READ][FOREGROUND][CHARGER_ON],
record.ios.bytes[WRITE][FOREGROUND][CHARGER_ON],
record.ios.bytes[READ][BACKGROUND][CHARGER_ON],
record.ios.bytes[WRITE][BACKGROUND][CHARGER_ON]);
uid_usage.bytes[READ][FOREGROUND][CHARGER_OFF],
uid_usage.bytes[WRITE][FOREGROUND][CHARGER_OFF],
uid_usage.bytes[READ][BACKGROUND][CHARGER_OFF],
uid_usage.bytes[WRITE][BACKGROUND][CHARGER_OFF],
uid_usage.bytes[READ][FOREGROUND][CHARGER_ON],
uid_usage.bytes[WRITE][FOREGROUND][CHARGER_ON],
uid_usage.bytes[READ][BACKGROUND][CHARGER_ON],
uid_usage.bytes[WRITE][BACKGROUND][CHARGER_ON]);
if (debug) {
for (const auto& task_it : record.ios.task_ios) {
const struct io_usage& task_usage = task_it.second;
const std::string& comm = task_it.first;
dprintf(fd, "-> %s %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64
" %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 "\n",
comm.c_str(),
task_usage.bytes[READ][FOREGROUND][CHARGER_OFF],
task_usage.bytes[WRITE][FOREGROUND][CHARGER_OFF],
task_usage.bytes[READ][BACKGROUND][CHARGER_OFF],
task_usage.bytes[WRITE][BACKGROUND][CHARGER_OFF],
task_usage.bytes[READ][FOREGROUND][CHARGER_ON],
task_usage.bytes[WRITE][FOREGROUND][CHARGER_ON],
task_usage.bytes[READ][BACKGROUND][CHARGER_ON],
task_usage.bytes[WRITE][BACKGROUND][CHARGER_ON]);
}
}
}
}

View File

@ -56,6 +56,66 @@ std::unordered_map<uint32_t, struct uid_info> uid_monitor::get_uid_io_stats()
return get_uid_io_stats_locked();
};
/* return true on parse success and false on failure */
bool uid_info::parse_uid_io_stats(std::string&& s)
{
std::vector<std::string> fields = Split(s, " ");
if (fields.size() < 11 ||
!ParseUint(fields[0], &uid) ||
!ParseUint(fields[1], &io[FOREGROUND].rchar) ||
!ParseUint(fields[2], &io[FOREGROUND].wchar) ||
!ParseUint(fields[3], &io[FOREGROUND].read_bytes) ||
!ParseUint(fields[4], &io[FOREGROUND].write_bytes) ||
!ParseUint(fields[5], &io[BACKGROUND].rchar) ||
!ParseUint(fields[6], &io[BACKGROUND].wchar) ||
!ParseUint(fields[7], &io[BACKGROUND].read_bytes) ||
!ParseUint(fields[8], &io[BACKGROUND].write_bytes) ||
!ParseUint(fields[9], &io[FOREGROUND].fsync) ||
!ParseUint(fields[10], &io[BACKGROUND].fsync)) {
LOG_TO(SYSTEM, WARNING) << "Invalid I/O stats: \""
<< s << "\"";
return false;
}
return true;
}
/* return true on parse success and false on failure */
bool task_info::parse_task_io_stats(std::string&& s)
{
std::vector<std::string> fields = Split(s, ",");
if (fields.size() < 13 ||
!ParseInt(fields[2], &pid) ||
!ParseUint(fields[3], &io[FOREGROUND].rchar) ||
!ParseUint(fields[4], &io[FOREGROUND].wchar) ||
!ParseUint(fields[5], &io[FOREGROUND].read_bytes) ||
!ParseUint(fields[6], &io[FOREGROUND].write_bytes) ||
!ParseUint(fields[7], &io[BACKGROUND].rchar) ||
!ParseUint(fields[8], &io[BACKGROUND].wchar) ||
!ParseUint(fields[9], &io[BACKGROUND].read_bytes) ||
!ParseUint(fields[10], &io[BACKGROUND].write_bytes) ||
!ParseUint(fields[11], &io[FOREGROUND].fsync) ||
!ParseUint(fields[12], &io[BACKGROUND].fsync)) {
LOG_TO(SYSTEM, WARNING) << "Invalid I/O stats: \""
<< s << "\"";
return false;
}
comm = fields[1];
return true;
}
bool io_usage::is_zero() const
{
for (int i = 0; i < IO_TYPES; i++) {
for (int j = 0; j < UID_STATS; j++) {
for (int k = 0; k < CHARGER_STATS; k++) {
if (bytes[i][j][k])
return false;
}
}
}
return true;
}
std::unordered_map<uint32_t, struct uid_info> uid_monitor::get_uid_io_stats_locked()
{
std::unordered_map<uint32_t, struct uid_info> uid_io_stats;
@ -65,7 +125,7 @@ std::unordered_map<uint32_t, struct uid_info> uid_monitor::get_uid_io_stats_lock
return uid_io_stats;
}
std::vector<std::string> io_stats = Split(buffer, "\n");
std::vector<std::string> io_stats = Split(std::move(buffer), "\n");
struct uid_info u;
bool refresh_uid = false;
@ -73,31 +133,22 @@ std::unordered_map<uint32_t, struct uid_info> uid_monitor::get_uid_io_stats_lock
if (io_stats[i].empty()) {
continue;
}
std::vector<std::string> fields = Split(io_stats[i], " ");
if (fields.size() < 11 ||
!ParseUint(fields[0], &u.uid) ||
!ParseUint(fields[1], &u.io[FOREGROUND].rchar) ||
!ParseUint(fields[2], &u.io[FOREGROUND].wchar) ||
!ParseUint(fields[3], &u.io[FOREGROUND].read_bytes) ||
!ParseUint(fields[4], &u.io[FOREGROUND].write_bytes) ||
!ParseUint(fields[5], &u.io[BACKGROUND].rchar) ||
!ParseUint(fields[6], &u.io[BACKGROUND].wchar) ||
!ParseUint(fields[7], &u.io[BACKGROUND].read_bytes) ||
!ParseUint(fields[8], &u.io[BACKGROUND].write_bytes) ||
!ParseUint(fields[9], &u.io[FOREGROUND].fsync) ||
!ParseUint(fields[10], &u.io[BACKGROUND].fsync)) {
LOG_TO(SYSTEM, WARNING) << "Invalid I/O stats: \""
<< io_stats[i] << "\"";
continue;
}
if (last_uid_io_stats.find(u.uid) == last_uid_io_stats.end()) {
refresh_uid = true;
u.name = std::to_string(u.uid);
if (io_stats[i].compare(0, 4, "task")) {
if (!u.parse_uid_io_stats(std::move(io_stats[i])))
continue;
if (last_uid_io_stats.find(u.uid) == last_uid_io_stats.end()) {
refresh_uid = true;
u.name = std::to_string(u.uid);
} else
u.name = last_uid_io_stats[u.uid].name;
uid_io_stats[u.uid] = u;
} else {
u.name = last_uid_io_stats[u.uid].name;
struct task_info t;
if (!t.parse_task_io_stats(std::move(io_stats[i])))
continue;
uid_io_stats[u.uid].tasks[t.pid] = t;
}
uid_io_stats[u.uid] = u;
}
if (refresh_uid) {
@ -119,8 +170,6 @@ static inline int records_size(
return count;
}
static struct uid_io_usage zero_io_usage;
void uid_monitor::add_records_locked(uint64_t curr_ts)
{
// remove records more than 5 days old
@ -133,8 +182,12 @@ void uid_monitor::add_records_locked(uint64_t curr_ts)
for (const auto& p : curr_io_stats) {
struct uid_record record = {};
record.name = p.first;
record.ios = p.second;
if (memcmp(&record.ios, &zero_io_usage, sizeof(struct uid_io_usage))) {
if (!p.second.uid_ios.is_zero()) {
record.ios.uid_ios = p.second.uid_ios;
for (const auto& p_task : p.second.task_ios) {
if (!p_task.second.is_zero())
record.ios.task_ios[p_task.first] = p_task.second;
}
new_records.entries.push_back(record);
}
}
@ -179,14 +232,15 @@ std::map<uint64_t, struct uid_records> uid_monitor::dump(
struct uid_records filtered;
for (const auto& rec : recs) {
if (rec.ios.bytes[READ][FOREGROUND][CHARGER_ON] +
rec.ios.bytes[READ][FOREGROUND][CHARGER_OFF] +
rec.ios.bytes[READ][BACKGROUND][CHARGER_ON] +
rec.ios.bytes[READ][BACKGROUND][CHARGER_OFF] +
rec.ios.bytes[WRITE][FOREGROUND][CHARGER_ON] +
rec.ios.bytes[WRITE][FOREGROUND][CHARGER_OFF] +
rec.ios.bytes[WRITE][BACKGROUND][CHARGER_ON] +
rec.ios.bytes[WRITE][BACKGROUND][CHARGER_OFF] > threshold) {
const io_usage& uid_usage = rec.ios.uid_ios;
if (uid_usage.bytes[READ][FOREGROUND][CHARGER_ON] +
uid_usage.bytes[READ][FOREGROUND][CHARGER_OFF] +
uid_usage.bytes[READ][BACKGROUND][CHARGER_ON] +
uid_usage.bytes[READ][BACKGROUND][CHARGER_OFF] +
uid_usage.bytes[WRITE][FOREGROUND][CHARGER_ON] +
uid_usage.bytes[WRITE][FOREGROUND][CHARGER_OFF] +
uid_usage.bytes[WRITE][BACKGROUND][CHARGER_ON] +
uid_usage.bytes[WRITE][BACKGROUND][CHARGER_OFF] > threshold) {
filtered.entries.push_back(rec);
}
}
@ -227,14 +281,38 @@ void uid_monitor::update_curr_io_stats_locked()
int64_t bg_wr_delta = uid.io[BACKGROUND].write_bytes -
last_uid_io_stats[uid.uid].io[BACKGROUND].write_bytes;
usage.bytes[READ][FOREGROUND][charger_stat] +=
(fg_rd_delta < 0) ? uid.io[FOREGROUND].read_bytes : fg_rd_delta;
usage.bytes[READ][BACKGROUND][charger_stat] +=
(bg_rd_delta < 0) ? uid.io[BACKGROUND].read_bytes : bg_rd_delta;
usage.bytes[WRITE][FOREGROUND][charger_stat] +=
(fg_wr_delta < 0) ? uid.io[FOREGROUND].write_bytes : fg_wr_delta;
usage.bytes[WRITE][BACKGROUND][charger_stat] +=
(bg_wr_delta < 0) ? uid.io[BACKGROUND].write_bytes : bg_wr_delta;
usage.uid_ios.bytes[READ][FOREGROUND][charger_stat] +=
(fg_rd_delta < 0) ? 0 : fg_rd_delta;
usage.uid_ios.bytes[READ][BACKGROUND][charger_stat] +=
(bg_rd_delta < 0) ? 0 : bg_rd_delta;
usage.uid_ios.bytes[WRITE][FOREGROUND][charger_stat] +=
(fg_wr_delta < 0) ? 0 : fg_wr_delta;
usage.uid_ios.bytes[WRITE][BACKGROUND][charger_stat] +=
(bg_wr_delta < 0) ? 0 : bg_wr_delta;
for (const auto& task_it : uid.tasks) {
const struct task_info& task = task_it.second;
const pid_t pid = task_it.first;
const std::string& comm = task_it.second.comm;
int64_t task_fg_rd_delta = task.io[FOREGROUND].read_bytes -
last_uid_io_stats[uid.uid].tasks[pid].io[FOREGROUND].read_bytes;
int64_t task_bg_rd_delta = task.io[BACKGROUND].read_bytes -
last_uid_io_stats[uid.uid].tasks[pid].io[BACKGROUND].read_bytes;
int64_t task_fg_wr_delta = task.io[FOREGROUND].write_bytes -
last_uid_io_stats[uid.uid].tasks[pid].io[FOREGROUND].write_bytes;
int64_t task_bg_wr_delta = task.io[BACKGROUND].write_bytes -
last_uid_io_stats[uid.uid].tasks[pid].io[BACKGROUND].write_bytes;
struct io_usage& task_usage = usage.task_ios[comm];
task_usage.bytes[READ][FOREGROUND][charger_stat] +=
(task_fg_rd_delta < 0) ? 0 : task_fg_rd_delta;
task_usage.bytes[READ][BACKGROUND][charger_stat] +=
(task_bg_rd_delta < 0) ? 0 : task_bg_rd_delta;
task_usage.bytes[WRITE][FOREGROUND][charger_stat] +=
(task_fg_wr_delta < 0) ? 0 : task_fg_wr_delta;
task_usage.bytes[WRITE][BACKGROUND][charger_stat] +=
(task_bg_wr_delta < 0) ? 0 : task_bg_wr_delta;
}
}
last_uid_io_stats = uid_io_stats;

View File

@ -18,6 +18,7 @@
#include <dirent.h>
#include <fcntl.h>
#include <inttypes.h>
#include <linux/time.h>
#include <stdint.h>
#include <stdio.h>
@ -182,15 +183,28 @@ void sort_running_uids_info(std::vector<struct uid_info> &uids) {
}
// Logging functions
void log_console_running_uids_info(std::vector<struct uid_info> uids) {
void log_console_running_uids_info(const std::vector<struct uid_info>& uids, bool flag_dump_task) {
printf("name/uid fg_rchar fg_wchar fg_rbytes fg_wbytes "
"bg_rchar bg_wchar bg_rbytes bg_wbytes fg_fsync bg_fsync\n");
for (const auto& uid : uids) {
printf("%s %ju %ju %ju %ju %ju %ju %ju %ju %ju %ju\n", uid.name.c_str(),
printf("%s %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64
" %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 "\n",
uid.name.c_str(),
uid.io[0].rchar, uid.io[0].wchar, uid.io[0].read_bytes, uid.io[0].write_bytes,
uid.io[1].rchar, uid.io[1].wchar, uid.io[1].read_bytes, uid.io[1].write_bytes,
uid.io[0].fsync, uid.io[1].fsync);
if (flag_dump_task) {
for (const auto& task_it : uid.tasks) {
const struct task_info& task = task_it.second;
printf("-> %s %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64
" %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 " %" PRIu64 "\n",
task.comm.c_str(),
task.io[0].rchar, task.io[0].wchar, task.io[0].read_bytes, task.io[0].write_bytes,
task.io[1].rchar, task.io[1].wchar, task.io[1].read_bytes, task.io[1].write_bytes,
task.io[0].fsync, task.io[1].fsync);
}
}
}
fflush(stdout);
}