Skip to content

Commit 09257e5

Browse files
committed
Fixed memory usage increasing over time due to per second histogram usage
1 parent 1d5ac99 commit 09257e5

File tree

4 files changed

+78
-29
lines changed

4 files changed

+78
-29
lines changed

run_stats.cpp

Lines changed: 42 additions & 22 deletions
Original file line numberDiff line numberDiff line change
@@ -117,6 +117,7 @@ run_stats::run_stats(benchmark_config *config) :
117117
{
118118
memset(&m_start_time, 0, sizeof(m_start_time));
119119
memset(&m_end_time, 0, sizeof(m_end_time));
120+
quantiles_list = config->print_percentiles.quantile_list;
120121

121122
if (config->arbitrary_commands->is_defined()) {
122123
setup_arbitrary_commands(config->arbitrary_commands->size());
@@ -155,6 +156,16 @@ void run_stats::roll_cur_stats(struct timeval* ts)
155156
{
156157
const unsigned int sec = ts_diff(m_start_time, *ts) / 1000000;
157158
if (sec > m_cur_stats.m_second) {
159+
m_cur_stats.m_get_cmd.summarize_quantiles(inst_m_get_latency_histogram,quantiles_list);
160+
m_cur_stats.m_set_cmd.summarize_quantiles(inst_m_set_latency_histogram,quantiles_list);
161+
m_cur_stats.m_wait_cmd.summarize_quantiles(inst_m_wait_latency_histogram,quantiles_list);
162+
for (unsigned int i=0; i<m_cur_stats.m_ar_commands.size(); i++) {
163+
m_cur_stats.m_ar_commands[i].summarize_quantiles(inst_m_ar_commands_latency_histograms[i],quantiles_list);
164+
hdr_reset(inst_m_ar_commands_latency_histograms[i]);
165+
}
166+
hdr_reset(inst_m_get_latency_histogram);
167+
hdr_reset(inst_m_set_latency_histogram);
168+
hdr_reset(inst_m_wait_latency_histogram);
158169
m_stats.push_back(m_cur_stats);
159170
m_cur_stats.reset(sec);
160171
}
@@ -166,7 +177,7 @@ void run_stats::update_get_op(struct timeval* ts, unsigned int bytes, unsigned i
166177
m_cur_stats.m_get_cmd.update_op(bytes, latency, hits, misses);
167178
m_totals.update_op(bytes, latency);
168179
hdr_record_value(m_get_latency_histogram,latency);
169-
180+
hdr_record_value(inst_m_get_latency_histogram,latency);
170181
}
171182

172183
void run_stats::update_set_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -176,6 +187,7 @@ void run_stats::update_set_op(struct timeval* ts, unsigned int bytes, unsigned i
176187
m_cur_stats.m_set_cmd.update_op(bytes, latency);
177188
m_totals.update_op(bytes, latency);
178189
hdr_record_value(m_set_latency_histogram,latency);
190+
hdr_record_value(inst_m_set_latency_histogram,latency);
179191
}
180192

181193
void run_stats::update_moved_get_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -185,6 +197,7 @@ void run_stats::update_moved_get_op(struct timeval* ts, unsigned int bytes, unsi
185197
m_cur_stats.m_get_cmd.update_moved_op(bytes, latency);
186198
m_totals.update_op(bytes, latency);
187199
hdr_record_value(m_get_latency_histogram,latency);
200+
hdr_record_value(inst_m_get_latency_histogram,latency);
188201
}
189202

190203
void run_stats::update_moved_set_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -194,6 +207,7 @@ void run_stats::update_moved_set_op(struct timeval* ts, unsigned int bytes, unsi
194207
m_cur_stats.m_set_cmd.update_moved_op(bytes, latency);
195208
m_totals.update_op(bytes, latency);
196209
hdr_record_value(m_set_latency_histogram,latency);
210+
hdr_record_value(inst_m_set_latency_histogram,latency);
197211
}
198212

199213
void run_stats::update_ask_get_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -203,6 +217,7 @@ void run_stats::update_ask_get_op(struct timeval* ts, unsigned int bytes, unsign
203217
m_cur_stats.m_get_cmd.update_ask_op(bytes, latency);
204218
m_totals.update_op(bytes, latency);
205219
hdr_record_value(m_get_latency_histogram,latency);
220+
hdr_record_value(inst_m_get_latency_histogram,latency);
206221
}
207222

208223
void run_stats::update_ask_set_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -212,6 +227,7 @@ void run_stats::update_ask_set_op(struct timeval* ts, unsigned int bytes, unsign
212227
m_cur_stats.m_set_cmd.update_ask_op(bytes, latency);
213228
m_totals.update_op(bytes, latency);
214229
hdr_record_value(m_set_latency_histogram,latency);
230+
hdr_record_value(inst_m_set_latency_histogram,latency);
215231
}
216232

217233
void run_stats::update_wait_op(struct timeval *ts, unsigned int latency)
@@ -221,6 +237,7 @@ void run_stats::update_wait_op(struct timeval *ts, unsigned int latency)
221237
m_cur_stats.m_wait_cmd.update_op(0, latency);
222238
m_totals.update_op(0, latency);
223239
hdr_record_value(m_wait_latency_histogram,latency);
240+
hdr_record_value(inst_m_wait_latency_histogram,latency);
224241
}
225242

226243
void run_stats::update_arbitrary_op(struct timeval *ts, unsigned int bytes,
@@ -231,7 +248,9 @@ void run_stats::update_arbitrary_op(struct timeval *ts, unsigned int bytes,
231248
m_totals.update_op(bytes, latency);
232249

233250
struct hdr_histogram* hist = m_ar_commands_latency_histograms.at(request_index);
251+
struct hdr_histogram* inst_hist = inst_m_ar_commands_latency_histograms.at(request_index);
234252
hdr_record_value(hist,latency);
253+
hdr_record_value(inst_hist,latency);
235254
}
236255

237256
unsigned int run_stats::get_duration(void)
@@ -828,22 +847,23 @@ void result_print_to_json(json_handler * jsonhandler, const char * type, double
828847
char timestamp_str[16];
829848
one_sec_cmd_stats cmd_stats = timeserie_stats[i];
830849
const unsigned int timestamp = timestamps[i];
831-
const bool sec_has_samples = hdr_total_count(cmd_stats.latency_histogram)>0;
832-
const double sec_avg_latency = sec_has_samples ? hdr_mean(cmd_stats.latency_histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
833-
const double sec_min_latency = has_samples ? hdr_min(cmd_stats.latency_histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
834-
const double sec_max_latency = has_samples ? hdr_max(cmd_stats.latency_histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
850+
const bool sec_has_samples = cmd_stats.m_ops > 0;
835851
snprintf(timestamp_str,sizeof(timestamp_str)-1,"%d", timestamp);
836852
jsonhandler->open_nesting(timestamp_str);
837-
jsonhandler->write_obj("Count","%lld", hdr_total_count(cmd_stats.latency_histogram));
838-
jsonhandler->write_obj("Average Latency","%.2f", sec_avg_latency);
839-
jsonhandler->write_obj("Min Latency","%.2f", sec_min_latency);
840-
jsonhandler->write_obj("Max Latency","%.2f", sec_max_latency);
841-
for (std::size_t i = 0; i < quantile_list.size(); i++){
842-
const float quantile = quantile_list[i];
843-
char quantile_header[8];
844-
snprintf(quantile_header,sizeof(quantile_header)-1,"p%.2f", quantile);
845-
const double value = hdr_value_at_percentile(cmd_stats.latency_histogram, quantile )/ (double) LATENCY_HDR_RESULTS_MULTIPLIER;
846-
jsonhandler->write_obj((char *)quantile_header,"%.2f", value);
853+
jsonhandler->write_obj("Count","%lld", cmd_stats.m_ops);
854+
if (sec_has_samples){
855+
jsonhandler->write_obj("Average Latency","%.3f", cmd_stats.m_avg_latency);
856+
jsonhandler->write_obj("Min Latency","%.3f", cmd_stats.m_min_latency);
857+
jsonhandler->write_obj("Max Latency","%.3f", cmd_stats.m_max_latency);
858+
for (std::size_t i = 0; i < quantile_list.size(); i++){
859+
if (i < cmd_stats.summarized_quantile_values.size()){
860+
const float quantile = quantile_list[i];
861+
char quantile_header[8];
862+
snprintf(quantile_header,sizeof(quantile_header)-1,"p%.2f", quantile);
863+
const double value = cmd_stats.summarized_quantile_values[i];
864+
jsonhandler->write_obj((char *)quantile_header,"%.3f", value);
865+
}
866+
}
847867
}
848868
jsonhandler->close_nesting();
849869
}
@@ -1103,7 +1123,7 @@ void run_stats::print_kb_sec_column(output_table &table) {
11031123
table.add_column(column);
11041124
}
11051125

1106-
void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& command_list, bool cluster_mode, std::vector<float> quantile_list) {
1126+
void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& command_list, bool cluster_mode) {
11071127
if (jsonhandler != NULL){ // Added for double verification in case someone accidently send NULL.
11081128
jsonhandler->open_nesting("Runtime");
11091129
const unsigned long long start_time_ms = (m_start_time.tv_sec * 1000000 + m_start_time.tv_usec)/1000;
@@ -1133,7 +1153,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11331153
cluster_mode ? m_totals.m_ar_commands[i].m_moved_sec : -1,
11341154
cluster_mode ? m_totals.m_ar_commands[i].m_ask_sec : -1,
11351155
m_totals.m_ar_commands[i].m_bytes_sec,
1136-
quantile_list,
1156+
quantiles_list,
11371157
arbitrary_command_latency_histogram,
11381158
timestamps,
11391159
arbitrary_command_stats
@@ -1149,7 +1169,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11491169
cluster_mode ? m_totals.m_set_cmd.m_moved_sec : -1,
11501170
cluster_mode ? m_totals.m_set_cmd.m_ask_sec : -1,
11511171
m_totals.m_set_cmd.m_bytes_sec,
1152-
quantile_list,
1172+
quantiles_list,
11531173
m_set_latency_histogram,
11541174
timestamps,
11551175
set_stats
@@ -1160,7 +1180,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11601180
cluster_mode ? m_totals.m_get_cmd.m_moved_sec : -1,
11611181
cluster_mode ? m_totals.m_get_cmd.m_ask_sec : -1,
11621182
m_totals.m_get_cmd.m_bytes_sec,
1163-
quantile_list,
1183+
quantiles_list,
11641184
m_get_latency_histogram,
11651185
timestamps,
11661186
get_stats
@@ -1171,7 +1191,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11711191
cluster_mode ? 0.0 : -1,
11721192
cluster_mode ? 0.0 : -1,
11731193
0.0,
1174-
quantile_list,
1194+
quantiles_list,
11751195
m_wait_latency_histogram,
11761196
timestamps,
11771197
wait_stats
@@ -1184,7 +1204,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11841204
cluster_mode ? m_totals.m_moved_sec : -1,
11851205
cluster_mode ? m_totals.m_ask_sec : -1,
11861206
m_totals.m_bytes_sec,
1187-
quantile_list,
1207+
quantiles_list,
11881208
m_totals.latency_histogram,
11891209
timestamps,
11901210
total_stats
@@ -1327,7 +1347,7 @@ void run_stats::print(FILE *out, benchmark_config *config,
13271347
jsonhandler->open_nesting("UNKNOWN STATS");
13281348
}
13291349

1330-
print_json(jsonhandler, *config->arbitrary_commands, config->cluster_mode, config->print_percentiles.quantile_list);
1350+
print_json(jsonhandler, *config->arbitrary_commands, config->cluster_mode);
13311351
}
13321352

13331353
if (!config->hide_histogram) {

run_stats.h

Lines changed: 8 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -97,6 +97,7 @@ class run_stats {
9797
totals m_totals;
9898

9999
std::list<one_second_stats> m_stats;
100+
std::vector<float> quantiles_list;
100101

101102
// current second stats ( appended to m_stats and reset every second )
102103
one_second_stats m_cur_stats;
@@ -106,6 +107,12 @@ class run_stats {
106107
safe_hdr_histogram m_wait_latency_histogram;
107108
std::vector<safe_hdr_histogram> m_ar_commands_latency_histograms;
108109

110+
// instantaneous command stats ( used in the per second latencies )
111+
safe_hdr_histogram inst_m_get_latency_histogram;
112+
safe_hdr_histogram inst_m_set_latency_histogram;
113+
safe_hdr_histogram inst_m_wait_latency_histogram;
114+
std::vector<safe_hdr_histogram> inst_m_ar_commands_latency_histograms;
115+
109116
void roll_cur_stats(struct timeval* ts);
110117

111118
public:
@@ -167,7 +174,7 @@ class run_stats {
167174
void print_avg_latency_column(output_table &table);
168175
void print_quantile_latency_column(output_table &table, double quantile, char* label);
169176
void print_kb_sec_column(output_table &table);
170-
void print_json(json_handler *jsonhandler, arbitrary_command_list& command_list, bool cluster_mode, std::vector<float> quantile_list);
177+
void print_json(json_handler *jsonhandler, arbitrary_command_list& command_list, bool cluster_mode);
171178
void print_histogram(FILE *out, json_handler* jsonhandler, arbitrary_command_list& command_list);
172179
void print(FILE *file, benchmark_config *config,
173180
const char* header = NULL, json_handler* jsonhandler = NULL);

run_stats_types.cpp

Lines changed: 23 additions & 5 deletions
Original file line numberDiff line numberDiff line change
@@ -33,7 +33,10 @@ one_sec_cmd_stats::one_sec_cmd_stats() :
3333
m_misses(0),
3434
m_moved(0),
3535
m_ask(0),
36-
m_total_latency(0) {
36+
m_total_latency(0),
37+
m_avg_latency(0.0),
38+
m_max_latency(0.0),
39+
m_min_latency(0.0) {
3740
}
3841

3942

@@ -45,7 +48,10 @@ void one_sec_cmd_stats::reset() {
4548
m_moved = 0;
4649
m_ask = 0;
4750
m_total_latency = 0;
48-
hdr_reset(latency_histogram);
51+
m_avg_latency = 0;
52+
m_max_latency = 0;
53+
m_min_latency = 0;
54+
summarized_quantile_values.clear();
4955
}
5056

5157
void one_sec_cmd_stats::merge(const one_sec_cmd_stats& other) {
@@ -56,14 +62,27 @@ void one_sec_cmd_stats::merge(const one_sec_cmd_stats& other) {
5662
m_moved += other.m_moved;
5763
m_ask += other.m_ask;
5864
m_total_latency += other.m_total_latency;
59-
hdr_add(latency_histogram,other.latency_histogram);
65+
m_avg_latency = (double) m_total_latency / (double) m_ops / (double) LATENCY_HDR_RESULTS_MULTIPLIER;
66+
m_max_latency = other.m_max_latency > m_max_latency ? other.m_max_latency : m_max_latency;
67+
m_min_latency = other.m_min_latency < m_min_latency ? other.m_min_latency : m_min_latency;
68+
}
69+
70+
void one_sec_cmd_stats::summarize_quantiles(safe_hdr_histogram histogram, std::vector<float> quantiles) {
71+
const bool has_samples = m_ops>0;
72+
for (std::size_t i = 0; i < quantiles.size(); i++){
73+
const float quantile = quantiles[i];
74+
const double value = hdr_value_at_percentile(histogram, quantile)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER;
75+
summarized_quantile_values.push_back(value);
76+
}
77+
m_avg_latency = has_samples ? hdr_mean(histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
78+
m_max_latency = has_samples ? hdr_max(histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
79+
m_min_latency = has_samples ? hdr_min(histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
6080
}
6181

6282
void one_sec_cmd_stats::update_op(unsigned int bytes, unsigned int latency) {
6383
m_bytes += bytes;
6484
m_ops++;
6585
m_total_latency += latency;
66-
hdr_record_value(latency_histogram,latency);
6786
}
6887

6988
void one_sec_cmd_stats::update_op(unsigned int bytes, unsigned int latency,
@@ -148,7 +167,6 @@ void one_second_stats::setup_arbitrary_commands(size_t n_arbitrary_commands) {
148167
m_ar_commands.setup(n_arbitrary_commands);
149168
}
150169

151-
152170
void one_second_stats::reset(unsigned int second) {
153171
m_second = second;
154172
m_get_cmd.reset();

run_stats_types.h

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -82,10 +82,14 @@ class one_sec_cmd_stats {
8282
unsigned int m_moved;
8383
unsigned int m_ask;
8484
unsigned long long int m_total_latency;
85-
safe_hdr_histogram latency_histogram;
85+
std::vector<double> summarized_quantile_values;
86+
double m_avg_latency;
87+
double m_min_latency;
88+
double m_max_latency;
8689
one_sec_cmd_stats();
8790
void reset();
8891
void merge(const one_sec_cmd_stats& other);
92+
void summarize_quantiles(safe_hdr_histogram histogram, std::vector<float> quantiles);
8993
void update_op(unsigned int bytes, unsigned int latency);
9094
void update_op(unsigned int bytes, unsigned int latency, unsigned int hits, unsigned int misses);
9195
void update_moved_op(unsigned int bytes, unsigned int latency);

0 commit comments

Comments
 (0)