Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Ensuring we produce a valid JSON in case of empty string and -nan #273

Merged
merged 5 commits into from
Nov 18, 2024
Merged

Ensuring we produce a valid JSON in case of empty string and -nan #273

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
ae36f2b
Ensuring we produce a valid JSON in case of empty string and -nan
filipecosta90 Nov 7, 2024
21ede2f
Ensuring latency tracing is capped both on smallest and largest laten…
filipecosta90 Nov 7, 2024
5ce4f41
Added the latency test (command taking longer than 1 second) to CI
filipecosta90 Nov 7, 2024
de5019a
Cleaned up test_valid_json_using_debug_command
filipecosta90 Nov 7, 2024
bfe511c
Ensuring that the per second metrics are numeric non negative
filipecosta90 Nov 7, 2024
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
36 changes: 34 additions & 2 deletions JSON_handler.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -22,7 +22,7 @@

#include <stdlib.h>
#include <string.h>

#include <cmath> // For std::isnan
#include "JSON_handler.h"


Expand Down Expand Up @@ -71,7 +71,39 @@
fprintf(m_json_file, "\"%s\": ", objectname);
va_list argptr;
va_start(argptr, format);
vfprintf(m_json_file, format, argptr);
// Check if format includes "%s", indicating a string is expected
if (strstr(format, "%s") != nullptr) {
// Use a temporary va_list to check the string argument without advancing the original
va_list tmp_argptr;
va_copy(tmp_argptr, argptr);
const char *str_arg = va_arg(tmp_argptr, const char*);
va_end(tmp_argptr);

if (str_arg == nullptr) {
// Handle NULL strings by writing "null" to the JSON file
fprintf(m_json_file, "null");
} else {
// Print the valid string argument
vfprintf(m_json_file, format, argptr);
}
}
// Check if the format expects a floating-point number
else if (strstr(format, "f") != nullptr || strstr(format, "e") != nullptr || strstr(format, "g") != nullptr) {
va_list tmp_argptr;
va_copy(tmp_argptr, argptr);
double value = va_arg(tmp_argptr, double);
va_end(tmp_argptr);

if (std::isnan(value)) {
fprintf(m_json_file, "null");

Check warning on line 98 in JSON_handler.cpp

View check run for this annotation

Codecov / codecov/patch

JSON_handler.cpp#L98 

Added line #L98 was not covered by tests
} else {
vfprintf(m_json_file, format, argptr);
}
}
else {
// For other format specifiers, proceed as usual
vfprintf(m_json_file, format, argptr);
}
va_end(argptr);
beutify();
fprintf(m_json_file, ",");
Expand Down
6 changes: 6 additions & 0 deletions deps/hdr_histogram/hdr_histogram.c
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -448,6 +448,12 @@ size_t hdr_get_memory_size(struct hdr_histogram *h)
/* ## ## ## ## ## ## ## ## ## ## ## */
/* ####### ## ######## ## ## ## ######## ###### */

bool hdr_record_value_capped(struct hdr_histogram* h, int64_t value)
{
int64_t capped_value = (value > h->highest_trackable_value) ? h->highest_trackable_value : value;
capped_value = (capped_value < h->lowest_trackable_value) ? h->lowest_trackable_value : capped_value;
return hdr_record_value(h, capped_value);
}

bool hdr_record_value(struct hdr_histogram* h, int64_t value)
{
Expand Down
12 changes: 12 additions & 0 deletions deps/hdr_histogram/hdr_histogram.h
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -110,6 +110,18 @@ size_t hdr_get_memory_size(struct hdr_histogram* h);
*/
bool hdr_record_value(struct hdr_histogram* h, int64_t value);
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this still being used anywhere? Can it be removed?

If not, and you're keeping it for compat purposes, should the method docs be updated to indicate it's deprecated or something?

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this still being used anywhere?

@DrEsteban it's coming from the original repo: https://github.com/HdrHistogram/HdrHistogram_c
I believe it's best to create an issue there and document this further on the function signature.

Copy link
Contributor

@DrEsteban DrEsteban Nov 11, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Went ahead and did that: HdrHistogram/HdrHistogram_c#126

Please add details or clarifications as necessary.


/**
* Records a value in the histogram, rounding the value to the specified precision
* (based on the significant figure set during histogram creation). This function
* will cap the recorded value at the histogram's highest_trackable_value if the input
* exceeds this threshold, and at the lowest_trackable_value if it falls below.
*
* @param h Pointer to the histogram structure
* @param value Value to add to the histogram
* @return false if the value cannot be recorded due to an error, true otherwise
*/
bool hdr_record_value_capped(struct hdr_histogram* h, int64_t value);

/**
* Records a value in the histogram, will round this value of to a precision at or better
* than the significant_figure specified at construction time.
Expand Down
106 changes: 62 additions & 44 deletions run_stats.cpp
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -185,10 +185,10 @@
m_cur_stats.m_get_cmd.update_op(bytes_rx, bytes_tx, latency, hits, misses);
m_cur_stats.m_total_cmd.update_op(bytes_rx, bytes_tx, latency, hits, misses);
m_totals.update_op(bytes_rx, bytes_tx, latency);
hdr_record_value(m_get_latency_histogram,latency);
hdr_record_value(inst_m_get_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_get_latency_histogram,latency);
hdr_record_value_capped(inst_m_get_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);
}

void run_stats::update_set_op(struct timeval* ts, unsigned int bytes_rx, unsigned int bytes_tx, unsigned int latency)
Expand All @@ -198,10 +198,10 @@
m_cur_stats.m_set_cmd.update_op(bytes_rx, bytes_tx, latency);
m_cur_stats.m_total_cmd.update_op(bytes_rx, bytes_tx, latency);
m_totals.update_op(bytes_rx, bytes_tx, latency);
hdr_record_value(m_set_latency_histogram,latency);
hdr_record_value(inst_m_set_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_set_latency_histogram,latency);
hdr_record_value_capped(inst_m_set_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);
}

void run_stats::update_moved_get_op(struct timeval* ts, unsigned int bytes_rx, unsigned int bytes_tx, unsigned int latency)
Expand All @@ -211,10 +211,10 @@
m_cur_stats.m_get_cmd.update_moved_op(bytes_rx, bytes_tx, latency);
m_cur_stats.m_total_cmd.update_op(bytes_rx, bytes_tx, latency);
m_totals.update_op(bytes_rx, bytes_tx, latency);
hdr_record_value(m_get_latency_histogram,latency);
hdr_record_value(inst_m_get_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_get_latency_histogram,latency);
hdr_record_value_capped(inst_m_get_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 217 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L214-L217 

Added lines #L214 - L217 were not covered by tests
}

void run_stats::update_moved_set_op(struct timeval* ts, unsigned int bytes_rx, unsigned int bytes_tx, unsigned int latency)
Expand All @@ -224,10 +224,10 @@
m_cur_stats.m_set_cmd.update_moved_op(bytes_rx, bytes_tx, latency);
m_cur_stats.m_total_cmd.update_moved_op(bytes_rx, bytes_tx, latency);
m_totals.update_op(bytes_rx, bytes_tx, latency);
hdr_record_value(m_set_latency_histogram,latency);
hdr_record_value(inst_m_set_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_set_latency_histogram,latency);
hdr_record_value_capped(inst_m_set_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 230 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L227-L230 

Added lines #L227 - L230 were not covered by tests
}

void run_stats::update_moved_arbitrary_op(struct timeval *ts, unsigned int bytes_rx, unsigned int bytes_tx,
Expand All @@ -239,9 +239,9 @@
m_totals.update_op(bytes_rx, bytes_tx, latency);

struct hdr_histogram* hist = m_ar_commands_latency_histograms.at(request_index);
hdr_record_value(hist,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(hist,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 244 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L242-L244 

Added lines #L242 - L244 were not covered by tests
}

void run_stats::update_ask_get_op(struct timeval* ts, unsigned int bytes_rx, unsigned int bytes_tx, unsigned int latency)
Expand All @@ -251,10 +251,10 @@
m_cur_stats.m_get_cmd.update_ask_op(bytes_rx, bytes_tx, latency);
m_cur_stats.m_total_cmd.update_ask_op(bytes_rx, bytes_tx, latency);
m_totals.update_op(bytes_rx, bytes_tx, latency);
hdr_record_value(m_get_latency_histogram,latency);
hdr_record_value(inst_m_get_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_get_latency_histogram,latency);
hdr_record_value_capped(inst_m_get_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 257 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L254-L257 

Added lines #L254 - L257 were not covered by tests
}

void run_stats::update_ask_set_op(struct timeval* ts, unsigned int bytes_rx, unsigned int bytes_tx, unsigned int latency)
Expand All @@ -264,10 +264,10 @@
m_cur_stats.m_set_cmd.update_ask_op(bytes_rx, bytes_tx, latency);
m_cur_stats.m_total_cmd.update_ask_op(bytes_rx, bytes_tx, latency);
m_totals.update_op(bytes_rx, bytes_tx, latency);
hdr_record_value(m_set_latency_histogram,latency);
hdr_record_value(inst_m_set_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_set_latency_histogram,latency);
hdr_record_value_capped(inst_m_set_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 270 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L267-L270 

Added lines #L267 - L270 were not covered by tests
}

void run_stats::update_ask_arbitrary_op(struct timeval *ts, unsigned int bytes_rx, unsigned int bytes_tx,
Expand All @@ -279,9 +279,9 @@
m_totals.update_op(bytes_rx, bytes_tx, latency);

struct hdr_histogram* hist = m_ar_commands_latency_histograms.at(request_index);
hdr_record_value(hist,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(hist,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 284 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L282-L284 

Added lines #L282 - L284 were not covered by tests
}

void run_stats::update_wait_op(struct timeval *ts, unsigned int latency)
Expand All @@ -291,10 +291,10 @@
m_cur_stats.m_wait_cmd.update_op(0,0, latency);
m_cur_stats.m_total_cmd.update_op(0,0, latency);
m_totals.update_op(0,0, latency);
hdr_record_value(m_wait_latency_histogram,latency);
hdr_record_value(inst_m_wait_latency_histogram,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(m_wait_latency_histogram,latency);
hdr_record_value_capped(inst_m_wait_latency_histogram,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);

Check warning on line 297 in run_stats.cpp

View check run for this annotation

Codecov / codecov/patch

run_stats.cpp#L294-L297 

Added lines #L294 - L297 were not covered by tests
}

void run_stats::update_arbitrary_op(struct timeval *ts, unsigned int bytes_rx, unsigned int bytes_tx,
Expand All @@ -307,10 +307,10 @@

struct hdr_histogram* hist = m_ar_commands_latency_histograms.at(request_index);
struct hdr_histogram* inst_hist = inst_m_ar_commands_latency_histograms.at(request_index);
hdr_record_value(hist,latency);
hdr_record_value(inst_hist,latency);
hdr_record_value(m_totals_latency_histogram,latency);
hdr_record_value(inst_m_totals_latency_histogram,latency);
hdr_record_value_capped(hist,latency);
hdr_record_value_capped(inst_hist,latency);
hdr_record_value_capped(m_totals_latency_histogram,latency);
hdr_record_value_capped(inst_m_totals_latency_histogram,latency);
}

unsigned int run_stats::get_duration(void)
Expand Down Expand Up @@ -879,16 +879,17 @@
result.m_ask_sec = (double) (totals.m_set_cmd.m_ask + totals.m_get_cmd.m_ask) / test_duration_usec * 1000000;
}

void result_print_to_json(json_handler * jsonhandler, const char * type, double ops,
void result_print_to_json(json_handler * jsonhandler, const char * type, double ops_sec,
double hits, double miss, double moved, double ask, double kbs, double kbs_rx, double kbs_tx,
double latency, long m_total_latency, long ops,
std::vector<float> quantile_list, struct hdr_histogram* latency_histogram,
std::vector<unsigned int> timestamps,
std::vector<one_sec_cmd_stats> timeserie_stats )
{
if (jsonhandler != NULL){ // Added for double verification in case someone accidently send NULL.
jsonhandler->open_nesting(type);
jsonhandler->write_obj("Count","%lld", hdr_total_count(latency_histogram));
jsonhandler->write_obj("Ops/sec","%.2f", ops);
jsonhandler->write_obj("Count","%lld", ops);
jsonhandler->write_obj("Ops/sec","%.2f", ops_sec);
jsonhandler->write_obj("Hits/sec","%.2f", hits);
jsonhandler->write_obj("Misses/sec","%.2f", miss);

Expand All @@ -899,12 +900,13 @@
jsonhandler->write_obj("ASK/sec","%.2f", ask);

const bool has_samples = hdr_total_count(latency_histogram)>0;
const double avg_latency = has_samples ? hdr_mean(latency_histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
const double min_latency = has_samples ? hdr_min(latency_histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
const double max_latency = has_samples ? hdr_max(latency_histogram)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
const double avg_latency = latency;
const double min_latency = has_samples ? (hdr_min(latency_histogram) * 1.0)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
const double max_latency = has_samples ? (hdr_max(latency_histogram) * 1.0)/ (double) LATENCY_HDR_RESULTS_MULTIPLIER : 0.0;
// to be retrocompatible
jsonhandler->write_obj("Latency","%.3f", avg_latency);
jsonhandler->write_obj("Average Latency","%.3f", avg_latency);
jsonhandler->write_obj("Accumulated Latency","%lld", m_total_latency / LATENCY_HDR_RESULTS_MULTIPLIER);
Copy link
Contributor

@DrEsteban DrEsteban Nov 11, 2024 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Is this just a sum of all command latency experienced throughout the test? Is it more-or-less equivalent to Average Latency * Ops?

jsonhandler->write_obj("Min Latency","%.3f", min_latency);
jsonhandler->write_obj("Max Latency","%.3f", max_latency);
// preserve KB/sec for backwards compatibility
Expand All @@ -925,6 +927,7 @@
jsonhandler->write_obj("Count","%lld", cmd_stats.m_ops);
if (sec_has_samples){
jsonhandler->write_obj("Average Latency","%.3f", cmd_stats.m_avg_latency);
jsonhandler->write_obj("Accumulated Latency","%lld", cmd_stats.m_total_latency / LATENCY_HDR_RESULTS_MULTIPLIER);
jsonhandler->write_obj("Min Latency","%.3f", cmd_stats.m_min_latency);
jsonhandler->write_obj("Max Latency","%.3f", cmd_stats.m_max_latency);
for (std::size_t i = 0; i < quantile_list.size(); i++){
Expand Down Expand Up @@ -1240,6 +1243,9 @@
m_totals.m_ar_commands[i].m_bytes_sec,
m_totals.m_ar_commands[i].m_bytes_sec_rx,
m_totals.m_ar_commands[i].m_bytes_sec_tx,
m_totals.m_ar_commands[i].m_latency,
m_totals.m_ar_commands[i].m_total_latency,
m_totals.m_ar_commands[i].m_ops,
quantiles_list,
arbitrary_command_latency_histogram,
timestamps,
Expand All @@ -1258,6 +1264,9 @@
m_totals.m_set_cmd.m_bytes_sec,
m_totals.m_set_cmd.m_bytes_sec_rx,
m_totals.m_set_cmd.m_bytes_sec_tx,
m_totals.m_set_cmd.m_latency,
m_totals.m_set_cmd.m_total_latency,
m_totals.m_set_cmd.m_ops,
quantiles_list,
m_set_latency_histogram,
timestamps,
Expand All @@ -1271,6 +1280,9 @@
m_totals.m_get_cmd.m_bytes_sec,
m_totals.m_get_cmd.m_bytes_sec_rx,
m_totals.m_get_cmd.m_bytes_sec_tx,
m_totals.m_get_cmd.m_latency,
m_totals.m_get_cmd.m_total_latency,
m_totals.m_get_cmd.m_ops,
quantiles_list,
m_get_latency_histogram,
timestamps,
Expand All @@ -1284,6 +1296,9 @@
0.0,
0.0,
0.0,
0.0,
0.0,
m_totals.m_wait_cmd.m_ops,
quantiles_list,
m_wait_latency_histogram,
timestamps,
Expand All @@ -1299,6 +1314,9 @@
m_totals.m_bytes_sec,
m_totals.m_bytes_sec_rx,
m_totals.m_bytes_sec_tx,
m_totals.m_latency,
m_totals.m_total_latency,
m_totals.m_ops,
quantiles_list,
m_totals.latency_histogram,
timestamps,
Expand Down
Loading
Loading