Add JSON output for stress-tester

antietcd
Vitaliy Filippov 2023-10-25 14:20:18 +03:00
parent 08f586bcec
commit 19426aa4c5
1 changed files with 56 additions and 25 deletions

View File

@ -59,6 +59,7 @@ public:
uint64_t min_value_len = 50; uint64_t min_value_len = 50;
uint64_t max_value_len = 300; uint64_t max_value_len = 300;
uint64_t print_stats_interval = 1; uint64_t print_stats_interval = 1;
bool json_output = false;
bool trace = true; bool trace = true;
bool stop_on_error = false; bool stop_on_error = false;
// FIXME: Multiple clients // FIXME: Multiple clients
@ -147,6 +148,8 @@ json11::Json::object kv_test_t::parse_args(int narg, const char *args[])
" Maximum value size in bytes\n" " Maximum value size in bytes\n"
" --print_stats 1\n" " --print_stats 1\n"
" Print operation statistics every this number of seconds\n" " Print operation statistics every this number of seconds\n"
" --json\n"
" JSON output\n"
" --trace 1\n" " --trace 1\n"
" Print all executed operations\n" " Print all executed operations\n"
" --stop_on_error 0\n" " --stop_on_error 0\n"
@ -207,6 +210,8 @@ void kv_test_t::parse_config(json11::Json cfg)
max_value_len = cfg["max_value_len"].uint64_value(); max_value_len = cfg["max_value_len"].uint64_value();
if (!cfg["print_stats"].is_null()) if (!cfg["print_stats"].is_null())
print_stats_interval = cfg["print_stats"].uint64_value(); print_stats_interval = cfg["print_stats"].uint64_value();
if (!cfg["json"].is_null())
json_output = true;
if (!cfg["trace"].is_null()) if (!cfg["trace"].is_null())
trace = cfg["trace"].bool_value(); trace = cfg["trace"].bool_value();
if (!cfg["stop_on_error"].is_null()) if (!cfg["stop_on_error"].is_null())
@ -253,10 +258,11 @@ void kv_test_t::run(json11::Json cfg)
reopening = false; reopening = false;
if (res < 0) if (res < 0)
{ {
printf("ERROR: Open index: %d (%s)\n", res, strerror(-res)); fprintf(stderr, "ERROR: Open index: %d (%s)\n", res, strerror(-res));
exit(1); exit(1);
} }
printf("Index opened\n"); if (trace)
printf("Index opened\n");
ringloop->wakeup(); ringloop->wakeup();
}); });
consumer.loop = [this]() { loop(); }; consumer.loop = [this]() { loop(); };
@ -319,17 +325,19 @@ void kv_test_t::loop()
reopening = true; reopening = true;
db->close([this]() db->close([this]()
{ {
printf("Index closed\n"); if (trace)
printf("Index closed\n");
db->open(inode_id, kv_cfg, [this](int res) db->open(inode_id, kv_cfg, [this](int res)
{ {
reopening = false; reopening = false;
if (res < 0) if (res < 0)
{ {
printf("ERROR: Reopen index: %d (%s)\n", res, strerror(-res)); fprintf(stderr, "ERROR: Reopen index: %d (%s)\n", res, strerror(-res));
finished = true; finished = true;
return; return;
} }
printf("Index reopened\n"); if (trace)
printf("Index reopened\n");
ringloop->wakeup(); ringloop->wakeup();
}); });
}); });
@ -359,13 +367,13 @@ void kv_test_t::loop()
auto it = values.find(key); auto it = values.find(key);
if (res != (it == values.end() ? -ENOENT : 0)) if (res != (it == values.end() ? -ENOENT : 0))
{ {
printf("ERROR: get %s: %d (%s)\n", key.c_str(), res, strerror(-res)); fprintf(stderr, "ERROR: get %s: %d (%s)\n", key.c_str(), res, strerror(-res));
if (stop_on_error) if (stop_on_error)
exit(1); exit(1);
} }
else if (it != values.end() && value != it->second) else if (it != values.end() && value != it->second)
{ {
printf("ERROR: get %s: mismatch: %s vs %s\n", key.c_str(), value.c_str(), it->second.c_str()); fprintf(stderr, "ERROR: get %s: mismatch: %s vs %s\n", key.c_str(), value.c_str(), it->second.c_str());
if (stop_on_error) if (stop_on_error)
exit(1); exit(1);
} }
@ -411,7 +419,7 @@ void kv_test_t::loop()
in_progress--; in_progress--;
if (res != 0) if (res != 0)
{ {
printf("ERROR: set %s = %s: %d (%s)\n", key.c_str(), value.c_str(), res, strerror(-res)); fprintf(stderr, "ERROR: set %s = %s: %d (%s)\n", key.c_str(), value.c_str(), res, strerror(-res));
if (stop_on_error) if (stop_on_error)
exit(1); exit(1);
} }
@ -447,7 +455,7 @@ void kv_test_t::loop()
in_progress--; in_progress--;
if (res != 0) if (res != 0)
{ {
printf("ERROR: del %s: %d (%s)\n", key.c_str(), res, strerror(-res)); fprintf(stderr, "ERROR: del %s: %d (%s)\n", key.c_str(), res, strerror(-res));
if (stop_on_error) if (stop_on_error)
exit(1); exit(1);
} }
@ -480,7 +488,7 @@ void kv_test_t::loop()
add_stat(stat.list, lst->tv_begin); add_stat(stat.list, lst->tv_begin);
if (res != -ENOENT) if (res != -ENOENT)
{ {
printf("ERROR: list: %d (%s)\n", res, strerror(-res)); fprintf(stderr, "ERROR: list: %d (%s)\n", res, strerror(-res));
lst->error = true; lst->error = true;
} }
else else
@ -492,7 +500,7 @@ void kv_test_t::loop()
k_it++; k_it++;
if (k_it != values.end()) if (k_it != values.end())
{ {
printf("ERROR: list: missing key %s\n", (k_it++)->first.c_str()); fprintf(stderr, "ERROR: list: missing key %s\n", (k_it++)->first.c_str());
lst->error = true; lst->error = true;
} }
} }
@ -522,13 +530,13 @@ void kv_test_t::loop()
} }
if (k_it == values.end() || k_it->first > key) if (k_it == values.end() || k_it->first > key)
{ {
printf("ERROR: list: extra key %s\n", key.c_str()); fprintf(stderr, "ERROR: list: extra key %s\n", key.c_str());
lst->error = true; lst->error = true;
break; break;
} }
else if (k_it->first < key) else if (k_it->first < key)
{ {
printf("ERROR: list: missing key %s\n", k_it->first.c_str()); fprintf(stderr, "ERROR: list: missing key %s\n", k_it->first.c_str());
lst->error = true; lst->error = true;
lst->next_after = k_it->first; lst->next_after = k_it->first;
k_it++; k_it++;
@ -537,7 +545,7 @@ void kv_test_t::loop()
{ {
if (k_it->second != value) if (k_it->second != value)
{ {
printf("ERROR: list: mismatch: %s = %s but should be %s\n", fprintf(stderr, "ERROR: list: mismatch: %s = %s but should be %s\n",
key.c_str(), value.c_str(), k_it->second.c_str()); key.c_str(), value.c_str(), k_it->second.c_str());
lst->error = true; lst->error = true;
} }
@ -576,18 +584,40 @@ void kv_test_t::print_stats(kv_test_stat_t & prev_stat, timespec & prev_stat_tim
{ {
kv_test_lat_t *lats[] = { &stat.get, &stat.add, &stat.update, &stat.del, &stat.list }; kv_test_lat_t *lats[] = { &stat.get, &stat.add, &stat.update, &stat.del, &stat.list };
kv_test_lat_t *prev[] = { &prev_stat.get, &prev_stat.add, &prev_stat.update, &prev_stat.del, &prev_stat.list }; kv_test_lat_t *prev[] = { &prev_stat.get, &prev_stat.add, &prev_stat.update, &prev_stat.del, &prev_stat.list };
char buf[128] = { 0 }; if (!json_output)
for (int i = 0; i < sizeof(lats)/sizeof(lats[0]); i++)
{ {
snprintf(buf, sizeof(buf)-1, "%.1f %s/s (%lu us)", (lats[i]->count-prev[i]->count)*1000000.0/usec, char buf[128] = { 0 };
lats[i]->name, (lats[i]->usec-prev[i]->usec)/(lats[i]->count-prev[i]->count > 0 ? lats[i]->count-prev[i]->count : 1)); for (int i = 0; i < sizeof(lats)/sizeof(lats[0]); i++)
int k; {
for (k = strlen(buf); k < strlen(lats[i]->name)+21; k++) snprintf(buf, sizeof(buf)-1, "%.1f %s/s (%lu us)", (lats[i]->count-prev[i]->count)*1000000.0/usec,
buf[k] = ' '; lats[i]->name, (lats[i]->usec-prev[i]->usec)/(lats[i]->count-prev[i]->count > 0 ? lats[i]->count-prev[i]->count : 1));
buf[k] = 0; int k;
printf("%s", buf); for (k = strlen(buf); k < strlen(lats[i]->name)+21; k++)
buf[k] = ' ';
buf[k] = 0;
printf("%s", buf);
}
printf("\n");
}
else
{
int64_t runtime = (cur_stat_time.tv_sec - start_stat_time.tv_sec)*1000000 +
(cur_stat_time.tv_nsec - start_stat_time.tv_nsec)/1000;
printf("{\"runtime\":%.1f", (double)runtime/1000000.0);
for (int i = 0; i < sizeof(lats)/sizeof(lats[0]); i++)
{
if (lats[i]->count > prev[i]->count)
{
printf(
",\"%s\":{\"avg\":{\"iops\":%.1f,\"usec\":%lu},\"total\":{\"count\":%lu,\"usec\":%lu}}",
lats[i]->name, (lats[i]->count-prev[i]->count)*1000000.0/usec,
(lats[i]->usec-prev[i]->usec)/(lats[i]->count-prev[i]->count),
lats[i]->count, lats[i]->usec
);
}
}
printf("}\n");
} }
printf("\n");
} }
prev_stat = stat; prev_stat = stat;
prev_stat_time = cur_stat_time; prev_stat_time = cur_stat_time;
@ -595,7 +625,8 @@ void kv_test_t::print_stats(kv_test_stat_t & prev_stat, timespec & prev_stat_tim
void kv_test_t::print_total_stats() void kv_test_t::print_total_stats()
{ {
printf("Total:\n"); if (!json_output)
printf("Total:\n");
kv_test_stat_t start_stats; kv_test_stat_t start_stats;
timespec start_stat_time = this->start_stat_time; timespec start_stat_time = this->start_stat_time;
print_stats(start_stats, start_stat_time); print_stats(start_stats, start_stat_time);