Skip to content

Commit e6cd4ce

Browse files
Merge pull request #188 from RedisLabs/fix.mem_increase
Fixed memory usage increasing over time due to per second histogram usage
2 parents f1d4c18 + 833b433 commit e6cd4ce

File tree

4 files changed

+79
-29
lines changed

4 files changed

+79
-29
lines changed

run_stats.cpp

Lines changed: 43 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());
@@ -127,6 +128,7 @@ void run_stats::setup_arbitrary_commands(size_t n_arbitrary_commands) {
127128
m_totals.setup_arbitrary_commands(n_arbitrary_commands);
128129
m_cur_stats.setup_arbitrary_commands(n_arbitrary_commands);
129130
m_ar_commands_latency_histograms.resize(n_arbitrary_commands);
131+
inst_m_ar_commands_latency_histograms.resize(n_arbitrary_commands);
130132
}
131133

132134
void run_stats::set_start_time(struct timeval* start_time)
@@ -155,6 +157,16 @@ void run_stats::roll_cur_stats(struct timeval* ts)
155157
{
156158
const unsigned int sec = ts_diff(m_start_time, *ts) / 1000000;
157159
if (sec > m_cur_stats.m_second) {
160+
m_cur_stats.m_get_cmd.summarize_quantiles(inst_m_get_latency_histogram,quantiles_list);
161+
m_cur_stats.m_set_cmd.summarize_quantiles(inst_m_set_latency_histogram,quantiles_list);
162+
m_cur_stats.m_wait_cmd.summarize_quantiles(inst_m_wait_latency_histogram,quantiles_list);
163+
for (unsigned int i=0; i<m_cur_stats.m_ar_commands.size(); i++) {
164+
m_cur_stats.m_ar_commands[i].summarize_quantiles(inst_m_ar_commands_latency_histograms[i],quantiles_list);
165+
hdr_reset(inst_m_ar_commands_latency_histograms[i]);
166+
}
167+
hdr_reset(inst_m_get_latency_histogram);
168+
hdr_reset(inst_m_set_latency_histogram);
169+
hdr_reset(inst_m_wait_latency_histogram);
158170
m_stats.push_back(m_cur_stats);
159171
m_cur_stats.reset(sec);
160172
}
@@ -166,7 +178,7 @@ void run_stats::update_get_op(struct timeval* ts, unsigned int bytes, unsigned i
166178
m_cur_stats.m_get_cmd.update_op(bytes, latency, hits, misses);
167179
m_totals.update_op(bytes, latency);
168180
hdr_record_value(m_get_latency_histogram,latency);
169-
181+
hdr_record_value(inst_m_get_latency_histogram,latency);
170182
}
171183

172184
void run_stats::update_set_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -176,6 +188,7 @@ void run_stats::update_set_op(struct timeval* ts, unsigned int bytes, unsigned i
176188
m_cur_stats.m_set_cmd.update_op(bytes, latency);
177189
m_totals.update_op(bytes, latency);
178190
hdr_record_value(m_set_latency_histogram,latency);
191+
hdr_record_value(inst_m_set_latency_histogram,latency);
179192
}
180193

181194
void run_stats::update_moved_get_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -185,6 +198,7 @@ void run_stats::update_moved_get_op(struct timeval* ts, unsigned int bytes, unsi
185198
m_cur_stats.m_get_cmd.update_moved_op(bytes, latency);
186199
m_totals.update_op(bytes, latency);
187200
hdr_record_value(m_get_latency_histogram,latency);
201+
hdr_record_value(inst_m_get_latency_histogram,latency);
188202
}
189203

190204
void run_stats::update_moved_set_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -194,6 +208,7 @@ void run_stats::update_moved_set_op(struct timeval* ts, unsigned int bytes, unsi
194208
m_cur_stats.m_set_cmd.update_moved_op(bytes, latency);
195209
m_totals.update_op(bytes, latency);
196210
hdr_record_value(m_set_latency_histogram,latency);
211+
hdr_record_value(inst_m_set_latency_histogram,latency);
197212
}
198213

199214
void run_stats::update_ask_get_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -203,6 +218,7 @@ void run_stats::update_ask_get_op(struct timeval* ts, unsigned int bytes, unsign
203218
m_cur_stats.m_get_cmd.update_ask_op(bytes, latency);
204219
m_totals.update_op(bytes, latency);
205220
hdr_record_value(m_get_latency_histogram,latency);
221+
hdr_record_value(inst_m_get_latency_histogram,latency);
206222
}
207223

208224
void run_stats::update_ask_set_op(struct timeval* ts, unsigned int bytes, unsigned int latency)
@@ -212,6 +228,7 @@ void run_stats::update_ask_set_op(struct timeval* ts, unsigned int bytes, unsign
212228
m_cur_stats.m_set_cmd.update_ask_op(bytes, latency);
213229
m_totals.update_op(bytes, latency);
214230
hdr_record_value(m_set_latency_histogram,latency);
231+
hdr_record_value(inst_m_set_latency_histogram,latency);
215232
}
216233

217234
void run_stats::update_wait_op(struct timeval *ts, unsigned int latency)
@@ -221,6 +238,7 @@ void run_stats::update_wait_op(struct timeval *ts, unsigned int latency)
221238
m_cur_stats.m_wait_cmd.update_op(0, latency);
222239
m_totals.update_op(0, latency);
223240
hdr_record_value(m_wait_latency_histogram,latency);
241+
hdr_record_value(inst_m_wait_latency_histogram,latency);
224242
}
225243

226244
void run_stats::update_arbitrary_op(struct timeval *ts, unsigned int bytes,
@@ -231,7 +249,9 @@ void run_stats::update_arbitrary_op(struct timeval *ts, unsigned int bytes,
231249
m_totals.update_op(bytes, latency);
232250

233251
struct hdr_histogram* hist = m_ar_commands_latency_histograms.at(request_index);
252+
struct hdr_histogram* inst_hist = inst_m_ar_commands_latency_histograms.at(request_index);
234253
hdr_record_value(hist,latency);
254+
hdr_record_value(inst_hist,latency);
235255
}
236256

237257
unsigned int run_stats::get_duration(void)
@@ -828,22 +848,23 @@ void result_print_to_json(json_handler * jsonhandler, const char * type, double
828848
char timestamp_str[16];
829849
one_sec_cmd_stats cmd_stats = timeserie_stats[i];
830850
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;
851+
const bool sec_has_samples = cmd_stats.m_ops > 0;
835852
snprintf(timestamp_str,sizeof(timestamp_str)-1,"%d", timestamp);
836853
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);
854+
jsonhandler->write_obj("Count","%lld", cmd_stats.m_ops);
855+
if (sec_has_samples){
856+
jsonhandler->write_obj("Average Latency","%.3f", cmd_stats.m_avg_latency);
857+
jsonhandler->write_obj("Min Latency","%.3f", cmd_stats.m_min_latency);
858+
jsonhandler->write_obj("Max Latency","%.3f", cmd_stats.m_max_latency);
859+
for (std::size_t i = 0; i < quantile_list.size(); i++){
860+
if (i < cmd_stats.summarized_quantile_values.size()){
861+
const float quantile = quantile_list[i];
862+
char quantile_header[8];
863+
snprintf(quantile_header,sizeof(quantile_header)-1,"p%.2f", quantile);
864+
const double value = cmd_stats.summarized_quantile_values[i];
865+
jsonhandler->write_obj((char *)quantile_header,"%.3f", value);
866+
}
867+
}
847868
}
848869
jsonhandler->close_nesting();
849870
}
@@ -1103,7 +1124,7 @@ void run_stats::print_kb_sec_column(output_table &table) {
11031124
table.add_column(column);
11041125
}
11051126

1106-
void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& command_list, bool cluster_mode, std::vector<float> quantile_list) {
1127+
void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& command_list, bool cluster_mode) {
11071128
if (jsonhandler != NULL){ // Added for double verification in case someone accidently send NULL.
11081129
jsonhandler->open_nesting("Runtime");
11091130
const unsigned long long start_time_ms = (m_start_time.tv_sec * 1000000 + m_start_time.tv_usec)/1000;
@@ -1133,7 +1154,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11331154
cluster_mode ? m_totals.m_ar_commands[i].m_moved_sec : -1,
11341155
cluster_mode ? m_totals.m_ar_commands[i].m_ask_sec : -1,
11351156
m_totals.m_ar_commands[i].m_bytes_sec,
1136-
quantile_list,
1157+
quantiles_list,
11371158
arbitrary_command_latency_histogram,
11381159
timestamps,
11391160
arbitrary_command_stats
@@ -1149,7 +1170,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11491170
cluster_mode ? m_totals.m_set_cmd.m_moved_sec : -1,
11501171
cluster_mode ? m_totals.m_set_cmd.m_ask_sec : -1,
11511172
m_totals.m_set_cmd.m_bytes_sec,
1152-
quantile_list,
1173+
quantiles_list,
11531174
m_set_latency_histogram,
11541175
timestamps,
11551176
set_stats
@@ -1160,7 +1181,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11601181
cluster_mode ? m_totals.m_get_cmd.m_moved_sec : -1,
11611182
cluster_mode ? m_totals.m_get_cmd.m_ask_sec : -1,
11621183
m_totals.m_get_cmd.m_bytes_sec,
1163-
quantile_list,
1184+
quantiles_list,
11641185
m_get_latency_histogram,
11651186
timestamps,
11661187
get_stats
@@ -1171,7 +1192,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11711192
cluster_mode ? 0.0 : -1,
11721193
cluster_mode ? 0.0 : -1,
11731194
0.0,
1174-
quantile_list,
1195+
quantiles_list,
11751196
m_wait_latency_histogram,
11761197
timestamps,
11771198
wait_stats
@@ -1184,7 +1205,7 @@ void run_stats::print_json(json_handler *jsonhandler, arbitrary_command_list& co
11841205
cluster_mode ? m_totals.m_moved_sec : -1,
11851206
cluster_mode ? m_totals.m_ask_sec : -1,
11861207
m_totals.m_bytes_sec,
1187-
quantile_list,
1208+
quantiles_list,
11881209
m_totals.latency_histogram,
11891210
timestamps,
11901211
total_stats
@@ -1327,7 +1348,7 @@ void run_stats::print(FILE *out, benchmark_config *config,
13271348
jsonhandler->open_nesting("UNKNOWN STATS");
13281349
}
13291350

1330-
print_json(jsonhandler, *config->arbitrary_commands, config->cluster_mode, config->print_percentiles.quantile_list);
1351+
print_json(jsonhandler, *config->arbitrary_commands, config->cluster_mode);
13311352
}
13321353

13331354
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_min_latency(0.0),
39+
m_max_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)