h2load: Write log file with write(2)

This commit is contained in:
Tatsuhiro Tsujikawa 2018-11-23 12:46:11 +09:00
parent de4fe72861
commit 089a03be42
2 changed files with 37 additions and 26 deletions

View File

@ -91,6 +91,7 @@ Config::Config()
header_table_size(4_k), header_table_size(4_k),
encoder_header_table_size(4_k), encoder_header_table_size(4_k),
data_fd(-1), data_fd(-1),
log_fd(-1),
port(0), port(0),
default_port(0), default_port(0),
verbose(false), verbose(false),
@ -824,19 +825,29 @@ void Client::on_stream_close(int32_t stream_id, bool success, bool final) {
++worker->stats.req_done; ++worker->stats.req_done;
++req_done; ++req_done;
if (worker->log) { if (worker->config->log_fd != -1) {
auto start = std::chrono::duration_cast<std::chrono::microseconds>( auto start = std::chrono::duration_cast<std::chrono::microseconds>(
req_stat->request_wall_time.time_since_epoch()); req_stat->request_wall_time.time_since_epoch());
auto delta = std::chrono::duration_cast<std::chrono::microseconds>( auto delta = std::chrono::duration_cast<std::chrono::microseconds>(
req_stat->stream_close_time - req_stat->request_time); req_stat->stream_close_time - req_stat->request_time);
*worker->log << start.count() << '\t' << (success ? req_stat->status : -1)
<< '\t' << delta.count() << '\n'; std::array<uint8_t, 256> buf;
// Flushing manually is important to ensure atomicity of lines, but auto p = std::begin(buf);
// doing it after each line (e.g. with std::endl) is noticeably slow. p = util::utos(p, start.count());
if (++worker->log_pending == 16) { *p++ = '\t';
worker->log->flush(); if (success) {
worker->log_pending = 0; p = util::utos(p, req_stat->status);
} else {
*p++ = '-';
*p++ = '1';
} }
*p++ = '\t';
p = util::utos(p, delta.count());
*p++ = '\n';
auto nwrite = std::distance(std::begin(buf), p);
assert(nwrite <= buf.size());
write(worker->config->log_fd, buf.data(), nwrite);
} }
} }
@ -1264,8 +1275,7 @@ Worker::Worker(uint32_t id, SSL_CTX *ssl_ctx, size_t req_todo, size_t nclients,
nreqs_rem(req_todo % nclients), nreqs_rem(req_todo % nclients),
rate(rate), rate(rate),
max_samples(max_samples), max_samples(max_samples),
next_client_id(0), next_client_id(0) {
log_pending(0) {
if (!config->is_rate_mode() && !config->is_timing_based_mode()) { if (!config->is_rate_mode() && !config->is_timing_based_mode()) {
progress_interval = std::max(static_cast<size_t>(1), req_todo / 10); progress_interval = std::max(static_cast<size_t>(1), req_todo / 10);
} else { } else {
@ -1300,11 +1310,6 @@ Worker::Worker(uint32_t id, SSL_CTX *ssl_ctx, size_t req_todo, size_t nclients,
} else { } else {
current_phase = Phase::MAIN_DURATION; current_phase = Phase::MAIN_DURATION;
} }
if (!config->log_file.empty()) {
log = std::make_unique<std::ofstream>(
config->log_file, std::ios_base::out | std::ios_base::app);
}
} }
Worker::~Worker() { Worker::~Worker() {
@ -1998,6 +2003,7 @@ int main(int argc, char **argv) {
#endif // NOTHREADS #endif // NOTHREADS
std::string datafile; std::string datafile;
std::string logfile;
bool nreqs_set_manually = false; bool nreqs_set_manually = false;
while (1) { while (1) {
static int flag = 0; static int flag = 0;
@ -2254,12 +2260,7 @@ int main(int argc, char **argv) {
break; break;
case 10: case 10:
// --log-file // --log-file
std::ofstream out(optarg, std::ios_base::out | std::ios_base::app); logfile = optarg;
if (!out.is_open()) {
std::cerr << "--log-file: cannot write to " << optarg << std::endl;
exit(EXIT_FAILURE);
}
config.log_file = optarg;
break; break;
} }
break; break;
@ -2423,6 +2424,15 @@ int main(int argc, char **argv) {
config.data_length = data_stat.st_size; config.data_length = data_stat.st_size;
} }
if (!logfile.empty()) {
config.log_fd = open(logfile.c_str(), O_WRONLY | O_CREAT | O_APPEND,
S_IRUSR | S_IWUSR | S_IRGRP);
if (config.log_fd == -1) {
std::cerr << "--log-file: Could not open file " << logfile << std::endl;
exit(EXIT_FAILURE);
}
}
struct sigaction act {}; struct sigaction act {};
act.sa_handler = SIG_IGN; act.sa_handler = SIG_IGN;
sigaction(SIGPIPE, &act, nullptr); sigaction(SIGPIPE, &act, nullptr);
@ -2773,6 +2783,10 @@ time for request: )"
SSL_CTX_free(ssl_ctx); SSL_CTX_free(ssl_ctx);
if (config.log_fd != -1) {
close(config.log_fd);
}
return 0; return 0;
} }

View File

@ -71,7 +71,6 @@ struct Config {
std::string host; std::string host;
std::string ifile; std::string ifile;
std::string ciphers; std::string ciphers;
std::string log_file;
// length of upload data // length of upload data
int64_t data_length; int64_t data_length;
addrinfo *addrs; addrinfo *addrs;
@ -98,6 +97,8 @@ struct Config {
uint32_t encoder_header_table_size; uint32_t encoder_header_table_size;
// file descriptor for upload data // file descriptor for upload data
int data_fd; int data_fd;
// file descriptor to write per-request stats to.
int log_fd;
uint16_t port; uint16_t port;
uint16_t default_port; uint16_t default_port;
bool verbose; bool verbose;
@ -271,10 +272,6 @@ struct Worker {
// specified // specified
ev_timer duration_watcher; ev_timer duration_watcher;
ev_timer warmup_watcher; ev_timer warmup_watcher;
// Stream to write per-request stats to.
std::unique_ptr<std::ostream> log;
// Number of unflushed lines in the log.
uint32_t log_pending;
Worker(uint32_t id, SSL_CTX *ssl_ctx, size_t nreq_todo, size_t nclients, Worker(uint32_t id, SSL_CTX *ssl_ctx, size_t nreq_todo, size_t nclients,
size_t rate, size_t max_samples, Config *config); size_t rate, size_t max_samples, Config *config);