Commit ea75c71d authored by Matthias Vallentin's avatar Matthias Vallentin

Report absolute instead of cumulative measurements

This has the advantage that it makes each sample independent and one can
now easily "slice" profiler log files. For example, if the first half of
the execution time is quite different from the second (due to caching or
different user input), then one can now use the first half of the log
file and the second half independently, which was not possible before
because log entries were cumulative.
parent 875208e7
...@@ -127,7 +127,7 @@ class profiled_coordinator : public coordinator<Policy> { ...@@ -127,7 +127,7 @@ class profiled_coordinator : public coordinator<Policy> {
out << setw(15) << m.time.count() out << setw(15) << m.time.count()
<< setw(15) << m.usr.count() << setw(15) << m.usr.count()
<< setw(15) << m.sys.count() << setw(15) << m.sys.count()
<< setw(15) << m.mem; << m.mem;
return out; return out;
} }
...@@ -170,7 +170,7 @@ class profiled_coordinator : public coordinator<Policy> { ...@@ -170,7 +170,7 @@ class profiled_coordinator : public coordinator<Policy> {
<< setw(15) << "time" // duration of this sample (cumulative) << setw(15) << "time" // duration of this sample (cumulative)
<< setw(15) << "usr" // time spent in user mode (cumulative) << setw(15) << "usr" // time spent in user mode (cumulative)
<< setw(15) << "sys" // time spent in kernel model (cumulative) << setw(15) << "sys" // time spent in kernel model (cumulative)
<< setw(15) << "mem" // used memory (cumulative) << "mem" // used memory (cumulative)
<< std::endl; << std::endl;
} }
...@@ -210,6 +210,7 @@ class profiled_coordinator : public coordinator<Policy> { ...@@ -210,6 +210,7 @@ class profiled_coordinator : public coordinator<Policy> {
auto wallclock = m_system_start + (m.time - m_clock_start); auto wallclock = m_system_start + (m.time - m_clock_start);
std::lock_guard<std::mutex> file_guard{m_file_mtx}; std::lock_guard<std::mutex> file_guard{m_file_mtx};
record(wallclock, "worker", worker, w.worker); record(wallclock, "worker", worker, w.worker);
w.worker = {};
} }
} }
...@@ -247,6 +248,7 @@ class profiled_coordinator : public coordinator<Policy> { ...@@ -247,6 +248,7 @@ class profiled_coordinator : public coordinator<Policy> {
std::lock_guard<std::mutex> file_guard{m_file_mtx}; std::lock_guard<std::mutex> file_guard{m_file_mtx};
for (auto& j : m_jobs) { for (auto& j : m_jobs) {
record(wallclock, "actor", j.first, j.second); record(wallclock, "actor", j.first, j.second);
j.second = {};
} }
} }
} }
......
...@@ -312,12 +312,10 @@ record <- function(name, fun, ...) { ...@@ -312,12 +312,10 @@ record <- function(name, fun, ...) {
make_zero <- function(x) mapvalues(x, NaN, 0, warn_missing=FALSE) make_zero <- function(x) mapvalues(x, NaN, 0, warn_missing=FALSE)
make_profile <- function(filename) { make_profile <- function(filename) {
d1 <- function(x) c(x[1], diff(x))
read.table(filename, header=T) %>% read.table(filename, header=T) %>%
filter(time > 0) %>%
group_by(id, type) %>% group_by(id, type) %>%
arrange(time) %>% arrange(time) %>%
transmute(clock=clock, time=d1(time), usr=d1(usr), sys=d1(sys)) %>%
filter(time > 0) %>%
mutate(cpu=usr+sys, util=cpu/time, dom=make_zero((usr-sys)/cpu)) mutate(cpu=usr+sys, util=cpu/time, dom=make_zero((usr-sys)/cpu))
} }
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment