2021-05-28 16:30:09 +03:00
|
|
|
// Copyright (c) 2021-present The Torchy Authors.
|
|
|
|
// Distributed under the MIT license that can be found in the LICENSE file.
|
|
|
|
|
2021-05-31 15:08:50 +03:00
|
|
|
#include "config.h"
|
2021-05-28 16:30:09 +03:00
|
|
|
|
|
|
|
#ifdef TORCHY_ENABLE_STATS
|
2021-06-01 14:20:04 +03:00
|
|
|
#include "stopwatch.h"
|
|
|
|
#include "trace.h"
|
2021-05-31 15:08:50 +03:00
|
|
|
#include <algorithm>
|
2021-05-31 20:13:43 +03:00
|
|
|
#include <array>
|
2021-06-02 18:33:21 +03:00
|
|
|
#include <cstdlib>
|
2021-05-31 15:08:50 +03:00
|
|
|
#include <cstring>
|
2021-06-02 18:33:21 +03:00
|
|
|
#include <fstream>
|
2021-05-28 16:30:09 +03:00
|
|
|
#include <iostream>
|
2021-05-31 20:13:43 +03:00
|
|
|
#include <sstream>
|
|
|
|
#include <string>
|
|
|
|
#include <unordered_map>
|
|
|
|
#include <vector>
|
2021-05-28 16:30:09 +03:00
|
|
|
|
|
|
|
using namespace std;
|
|
|
|
|
|
|
|
#define NUM_ELEMS(a) (sizeof(a) / sizeof(*a))
|
|
|
|
|
|
|
|
namespace {
|
|
|
|
|
|
|
|
const char* flush_reasons[] = {
|
2021-05-31 15:08:50 +03:00
|
|
|
"debug",
|
2021-05-28 16:30:09 +03:00
|
|
|
"dim",
|
|
|
|
"has_storage",
|
2021-05-31 15:08:50 +03:00
|
|
|
"inplace shared",
|
2021-05-28 16:30:09 +03:00
|
|
|
"is_contiguous",
|
|
|
|
"numel",
|
2021-05-31 15:08:50 +03:00
|
|
|
"overflow shared list",
|
2021-05-28 16:30:09 +03:00
|
|
|
"set_size",
|
|
|
|
"set_storage_offset",
|
|
|
|
"set_stride",
|
2021-10-19 17:14:38 +03:00
|
|
|
"shallow_copy_from",
|
2021-05-28 16:30:09 +03:00
|
|
|
"size",
|
|
|
|
"sizes",
|
|
|
|
"storage",
|
|
|
|
"storage_offset",
|
|
|
|
"stride",
|
|
|
|
"strides",
|
|
|
|
"trace max length",
|
|
|
|
};
|
|
|
|
|
2021-05-31 15:08:50 +03:00
|
|
|
static_assert(NUM_ELEMS(flush_reasons) == (unsigned)FlushReason::NUM_REASONS);
|
2021-05-28 16:30:09 +03:00
|
|
|
|
2021-06-01 14:20:04 +03:00
|
|
|
float median(vector<float> &v) {
|
|
|
|
sort(v.begin(), v.end());
|
|
|
|
auto sz = v.size();
|
|
|
|
if (sz % 2 == 0)
|
|
|
|
return (v[sz/2 - 1] + v[sz/2]) / 2.0;
|
|
|
|
return v[sz / 2];
|
|
|
|
}
|
|
|
|
|
|
|
|
void inc(vector<unsigned> &v, size_t idx, unsigned amount = 1) {
|
|
|
|
if (idx >= v.size())
|
|
|
|
v.resize(idx+1);
|
|
|
|
v[idx] += amount;
|
|
|
|
}
|
|
|
|
|
2021-06-02 18:33:21 +03:00
|
|
|
string shrink_trace(const string &t) {
|
|
|
|
istringstream ss(t);
|
|
|
|
string out;
|
|
|
|
unsigned lines = 0;
|
|
|
|
|
|
|
|
for (string line; getline(ss, line); ) {
|
|
|
|
if (line.find("[dead]") != string::npos)
|
|
|
|
continue;
|
|
|
|
|
2021-06-08 19:30:24 +03:00
|
|
|
if (++lines == 20) {
|
|
|
|
out += "...\\l";
|
|
|
|
break;
|
|
|
|
}
|
|
|
|
|
2021-06-02 18:33:21 +03:00
|
|
|
auto pos = line.find(" #refs=");
|
|
|
|
if (pos != string::npos)
|
|
|
|
line.resize(pos);
|
|
|
|
|
|
|
|
pos = line.find(" #output");
|
|
|
|
if (pos != string::npos)
|
|
|
|
line.resize(pos);
|
|
|
|
|
|
|
|
out += line.substr(0, 50);
|
|
|
|
out += "\\l";
|
|
|
|
}
|
|
|
|
return out;
|
|
|
|
}
|
|
|
|
|
2021-05-31 20:13:43 +03:00
|
|
|
array<unsigned, (unsigned)FlushReason::NUM_REASONS> flush_reasons_count;
|
|
|
|
array<unsigned, MAX_TRACE_LENGTH+1> trace_size;
|
|
|
|
array<unsigned, MAX_TRACE_LENGTH+1> num_trace_outputs;
|
|
|
|
array<unsigned, MAX_TRACE_LENGTH+1> num_trace_deads;
|
2021-09-24 20:02:01 +03:00
|
|
|
vector<pair<float, string>> trace_compile_time;
|
2021-06-01 14:20:04 +03:00
|
|
|
unordered_map<string, vector<float>> trace_run_time;
|
2021-05-31 20:13:43 +03:00
|
|
|
unordered_map<string, unordered_map<string, unsigned>> trace_successors;
|
2021-06-02 18:33:21 +03:00
|
|
|
string first_trace, current_trace, last_trace;
|
2021-09-16 19:24:08 +03:00
|
|
|
unsigned unsupported_wrappers = 0;
|
2021-09-07 13:58:06 +03:00
|
|
|
unsigned torchscript_failures = 0;
|
2021-05-28 16:30:09 +03:00
|
|
|
|
|
|
|
struct PrintStats {
|
|
|
|
~PrintStats() {
|
2021-05-31 20:13:43 +03:00
|
|
|
cerr << "\n\n------------ STATISTICS ------------\n\n";
|
|
|
|
print_table("Trace Flush Reason", flush_reasons_count.data(), flush_reasons,
|
|
|
|
flush_reasons_count.size());
|
|
|
|
print_table("Trace Size", trace_size.data(), trace_size.size());
|
|
|
|
print_table("Number of Outputs per Trace", num_trace_outputs.data(),
|
|
|
|
num_trace_outputs.size());
|
|
|
|
print_table("Number of Dead Ops per Trace", num_trace_deads.data(),
|
|
|
|
num_trace_deads.size());
|
|
|
|
|
|
|
|
vector<unsigned> successor_frequency;
|
|
|
|
for (const auto &p : trace_successors) {
|
|
|
|
inc(successor_frequency, p.second.size());
|
|
|
|
}
|
|
|
|
print_table("Number of Successors per Trace", successor_frequency.data(),
|
|
|
|
successor_frequency.size());
|
|
|
|
|
|
|
|
vector<unsigned> trace_freq_stats;
|
|
|
|
unsigned total = 0;
|
2021-06-01 14:20:04 +03:00
|
|
|
for (const auto &p : trace_run_time) {
|
|
|
|
inc(trace_freq_stats, p.second.size());
|
|
|
|
total += p.second.size();
|
2021-05-31 20:13:43 +03:00
|
|
|
}
|
|
|
|
print_table("Frequency per Trace", trace_freq_stats.data(),
|
|
|
|
trace_freq_stats.size());
|
|
|
|
|
2021-06-01 14:20:04 +03:00
|
|
|
vector<unsigned> trace_times;
|
|
|
|
for (auto &p : trace_run_time) {
|
|
|
|
inc(trace_times, unsigned(median(p.second) * 1000000.0), p.second.size());
|
|
|
|
}
|
|
|
|
print_table("Run-times per Trace (microseconds)", trace_times.data(),
|
|
|
|
trace_times.size());
|
|
|
|
|
2021-05-31 20:13:43 +03:00
|
|
|
print_header("Most Frequent Traces");
|
2021-09-28 12:28:44 +03:00
|
|
|
{
|
|
|
|
vector<pair<unsigned,string>> traces;
|
|
|
|
for (auto &p : trace_run_time) {
|
|
|
|
traces.emplace_back(p.second.size(), p.first);
|
|
|
|
}
|
|
|
|
sort(traces.begin(), traces.end());
|
|
|
|
|
|
|
|
auto I = traces.rbegin(), E = traces.rend();
|
|
|
|
for (unsigned i = 0; i < 20 && I != E; ++i, ++I) {
|
|
|
|
auto med = median(trace_run_time.at(I->second));
|
|
|
|
cerr << "Trace executed " << I->first << " times ("
|
|
|
|
<< unsigned(med * 1000000.0) << " us)\n"
|
|
|
|
<< I->second << "\n\n";
|
|
|
|
}
|
2021-05-31 20:13:43 +03:00
|
|
|
}
|
|
|
|
|
2021-09-24 20:02:01 +03:00
|
|
|
print_header("Slowest Trace Compilation");
|
|
|
|
sort(trace_compile_time.begin(), trace_compile_time.end());
|
|
|
|
{
|
|
|
|
auto I = trace_compile_time.rbegin(), E = trace_compile_time.rend();
|
2021-09-28 12:28:44 +03:00
|
|
|
for (unsigned i = 0; i < 20 && I != E; ++i, ++I) {
|
2021-09-24 20:02:01 +03:00
|
|
|
cerr << "Trace compiled in "
|
|
|
|
<< unsigned(I->first * 1000000.0) << " us\n"
|
|
|
|
<< I->second << "\n\n";
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
2021-09-07 13:58:06 +03:00
|
|
|
cerr << "Number of Torchscript failures:\t" << torchscript_failures
|
2021-09-16 19:24:08 +03:00
|
|
|
<< "\nNumber of unsupported ops:\t" << unsupported_wrappers
|
2021-09-07 13:58:06 +03:00
|
|
|
<< "\nNumber of traces:\t" << total
|
2021-09-28 12:28:44 +03:00
|
|
|
<< "\nDistinct traces:\t" << trace_compile_time.size() << '\n';
|
2021-05-31 20:13:43 +03:00
|
|
|
|
2021-05-28 16:30:09 +03:00
|
|
|
cerr << endl;
|
2021-06-02 18:33:21 +03:00
|
|
|
|
|
|
|
if (auto p = getenv("TORCHY_PRINT_DOT"))
|
|
|
|
if (*p)
|
|
|
|
print_dot();
|
2021-05-28 16:30:09 +03:00
|
|
|
}
|
|
|
|
|
2021-05-31 20:13:43 +03:00
|
|
|
private:
|
2021-06-02 18:33:21 +03:00
|
|
|
void print_dot() {
|
|
|
|
{
|
|
|
|
ofstream f("trace.dot");
|
|
|
|
print_dot(f, false);
|
|
|
|
}
|
|
|
|
{
|
|
|
|
ofstream f("trace_detailed.dot");
|
|
|
|
print_dot(f, true);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
void print_dot(ofstream &os, bool label_trace) {
|
|
|
|
unordered_map<string, unsigned> trace_map;
|
|
|
|
trace_map[first_trace] = 0;
|
|
|
|
|
|
|
|
auto get_id = [&](const string &t) -> unsigned {
|
|
|
|
auto sz = trace_map.size();
|
|
|
|
return trace_map.emplace(t, sz).first->second;
|
|
|
|
};
|
|
|
|
|
|
|
|
os << "digraph {\n"
|
|
|
|
"n0 [label=Start]\n"
|
|
|
|
"n0 -> T0\n";
|
|
|
|
|
|
|
|
for (const auto &p : trace_successors) {
|
|
|
|
unsigned src = get_id(p.first);
|
|
|
|
|
|
|
|
if (label_trace)
|
|
|
|
os << 'T' << src << " [label=\"" << shrink_trace(p.first)
|
|
|
|
<< "\", shape=box]\n";
|
|
|
|
|
|
|
|
for (const auto &p : p.second) {
|
|
|
|
os << 'T' << src << " -> T" << get_id(p.first) << '\n';
|
|
|
|
}
|
|
|
|
}
|
|
|
|
os << "}\n";
|
|
|
|
}
|
|
|
|
|
2021-05-28 16:30:09 +03:00
|
|
|
void print_table(const char *header, unsigned *data, const char **labels,
|
2021-05-31 20:13:43 +03:00
|
|
|
size_t size) {
|
|
|
|
print_header(header);
|
2021-05-28 16:30:09 +03:00
|
|
|
|
2021-05-31 20:13:43 +03:00
|
|
|
size_t max_label = 0;
|
2021-05-28 16:30:09 +03:00
|
|
|
for (unsigned i = 0; i < size; ++i) {
|
2021-05-31 15:08:50 +03:00
|
|
|
if (data[i] != 0)
|
2021-05-31 20:13:43 +03:00
|
|
|
max_label = max(max_label, strlen(labels[i]));
|
2021-05-28 16:30:09 +03:00
|
|
|
}
|
|
|
|
|
|
|
|
for (unsigned i = 0; i < size; ++i) {
|
2021-05-31 15:08:50 +03:00
|
|
|
if (data[i] == 0)
|
|
|
|
continue;
|
|
|
|
cerr << labels[i] << ": ";
|
|
|
|
pad(labels[i], max_label);
|
2021-05-28 16:30:09 +03:00
|
|
|
cerr << data[i] << '\n';
|
|
|
|
}
|
|
|
|
cerr << '\n';
|
|
|
|
}
|
|
|
|
|
2021-05-31 20:13:43 +03:00
|
|
|
void print_table(const char *header, unsigned *data, size_t size) {
|
|
|
|
print_header(header);
|
|
|
|
|
|
|
|
size_t max_label = to_string(size-1).size();
|
|
|
|
|
|
|
|
for (unsigned i = 0; i < size; ++i) {
|
|
|
|
if (data[i] == 0)
|
|
|
|
continue;
|
|
|
|
string label = to_string(i);
|
|
|
|
cerr << label << ": ";
|
|
|
|
pad(label.c_str(), max_label);
|
|
|
|
cerr << data[i] << '\n';
|
|
|
|
}
|
|
|
|
cerr << '\n';
|
|
|
|
}
|
|
|
|
|
|
|
|
void print_header(const char *header) {
|
|
|
|
cerr << header << '\n';
|
|
|
|
repeat('=', strlen(header));
|
|
|
|
cerr << '\n';
|
|
|
|
}
|
|
|
|
|
|
|
|
void pad(const char *str, size_t length) {
|
|
|
|
repeat(' ', length - strlen(str));
|
|
|
|
}
|
|
|
|
|
|
|
|
void repeat(char ch, size_t length) {
|
|
|
|
for (size_t i = 0; i < length; ++i) {
|
|
|
|
cerr << ch;
|
2021-05-28 16:30:09 +03:00
|
|
|
}
|
|
|
|
}
|
|
|
|
};
|
|
|
|
|
|
|
|
PrintStats printer;
|
|
|
|
|
|
|
|
}
|
|
|
|
|
2021-06-01 20:27:46 +03:00
|
|
|
void stats_register_trace(const Trace &t, FlushReason reason) {
|
2021-05-31 15:08:50 +03:00
|
|
|
++flush_reasons_count[(unsigned)reason];
|
2021-05-31 20:13:43 +03:00
|
|
|
|
|
|
|
unsigned num_ops = t.numOps();
|
|
|
|
++trace_size[num_ops];
|
|
|
|
|
|
|
|
unsigned num_outputs = 0;
|
|
|
|
unsigned num_deads = 0;
|
|
|
|
|
|
|
|
auto *ops = t.getOps();
|
|
|
|
for (unsigned i = 0; i < num_ops; ++i) {
|
|
|
|
auto &op = ops[i];
|
|
|
|
num_outputs += op.observable;
|
2021-09-24 20:02:01 +03:00
|
|
|
num_deads += op.dead;
|
2021-05-31 20:13:43 +03:00
|
|
|
}
|
|
|
|
++num_trace_outputs[num_outputs];
|
|
|
|
++num_trace_deads[num_deads];
|
|
|
|
|
2021-06-01 20:27:46 +03:00
|
|
|
// We need to get the trace's string representation before it is executed.
|
|
|
|
// Tensor's trace_idx gets overwritten during materialization.
|
2021-05-31 20:13:43 +03:00
|
|
|
stringstream trace_ss;
|
|
|
|
trace_ss << t;
|
2021-06-01 20:27:46 +03:00
|
|
|
current_trace = move(trace_ss).str();
|
2021-06-02 18:33:21 +03:00
|
|
|
|
|
|
|
if (first_trace.empty())
|
|
|
|
first_trace = current_trace;
|
2021-06-01 20:27:46 +03:00
|
|
|
}
|
2021-05-31 20:13:43 +03:00
|
|
|
|
2021-09-24 20:02:01 +03:00
|
|
|
void stats_register_compile_time(const StopWatch &run_time) {
|
|
|
|
trace_compile_time.emplace_back(run_time.seconds(), current_trace);
|
|
|
|
}
|
|
|
|
|
2021-06-01 20:27:46 +03:00
|
|
|
void stats_register_trace_time(const StopWatch &run_time) {
|
2021-06-02 18:33:21 +03:00
|
|
|
trace_run_time[current_trace].emplace_back(run_time.seconds());
|
2021-06-01 14:20:04 +03:00
|
|
|
|
2021-05-31 20:13:43 +03:00
|
|
|
if (!last_trace.empty())
|
2021-06-02 18:33:21 +03:00
|
|
|
++trace_successors[last_trace][current_trace];
|
2021-06-01 20:27:46 +03:00
|
|
|
last_trace = move(current_trace);
|
2021-05-28 16:30:09 +03:00
|
|
|
}
|
|
|
|
|
2021-09-16 19:24:08 +03:00
|
|
|
void stats_inc_unsupported_wrapper() {
|
|
|
|
++unsupported_wrappers;
|
|
|
|
}
|
|
|
|
|
2021-09-07 13:58:06 +03:00
|
|
|
void stats_inc_torchscript_fail() {
|
|
|
|
++torchscript_failures;
|
|
|
|
}
|
|
|
|
|
2021-05-28 16:30:09 +03:00
|
|
|
#endif
|