Commit 58c7e7ff authored by Rob Latham's avatar Rob Latham
Browse files

additional statistics

also measure bulk transfers
parent b4dcf87b
......@@ -5,7 +5,10 @@ class io_stats {
server_write_calls(0), bytes_written(0), read_rpc_calls(0),
server_read_calls(0), server_read_time(0.0), bytes_read(0),
mutex_time(0.0), client_write_calls(0), client_read_calls(0),
client_read_time(0.0) {};
client_read_time(0.0), write_bulk_xfers(0), write_bulk_time(0.0),
read_bulk_xfers(0), read_bulk_time(0.0),
getfd(0), write_expose(0.0), read_expose(0.0),
write_response(0.0), read_response(0.0) {};
template<typename A> void serialize(A &ar) {
ar & write_rpc_calls;
......@@ -19,42 +22,77 @@ class io_stats {
ar & server_read_time;
ar & bytes_read;
ar & mutex_time;
ar & write_bulk_xfers;
ar & write_bulk_time;
ar & read_bulk_xfers;
ar & read_bulk_time;
ar & getfd;
ar & write_expose;
ar & read_expose;
ar & write_response;
ar & read_response;
}
// i know it's bad form but it's a pain to write setter functions for these
// so they are public
/* server things */
/* - server things - */
/* -- overall rpc stats -- */
int write_rpc_calls; // how many times the "write" rpc was called
double write_rpc_time; // how much time server spent in write rpc overall
int server_write_calls; // how many write calls server made to process rpc
double server_write_time; // time spent in write calls
int64_t bytes_written; // bytes written to storage
int read_rpc_calls; // how many times "read" rpc was called
double read_rpc_time; // total time spent in read rpc
/* -- file system stats -- */
double getfd; // time spent opening file or pulling fd out of data structure
int64_t server_write_calls; // how many write calls server made to process rpc
double server_write_time; // time spent in write calls
int64_t bytes_written; // bytes written to storage
int server_read_calls; // how many read calls server made to process rpc
double server_read_time; // time spent in read calls
int64_t bytes_read; // bytes read from storage
/* -- networking stats -- */
double write_bulk_time; // time spent in bulk xfer
int64_t write_bulk_xfers; // count of bulk xfers
double read_bulk_time; // time spent in bulk xfer
int64_t read_bulk_xfers; // count of bulk xfers
double write_expose; // time to register memory (get)
double read_expose; // time to register memory (put)
double write_response; // time responding to client
double read_response; // time responding to client
/* -- other stats -- */
double mutex_time; // time spent acquiring mutexes
/* client things */
/* - client things - */
int client_write_calls; // number of times "bv_write" called
double client_write_time; // time client spent in "bv_write",
int client_read_calls; // number of tiems "bv_read" called
double client_read_time; // time client spent in "bv_read
double client_init_time; // how long does it take to set everything up
io_stats & operator = (const io_stats &rhs);
void print_server() {
std::cout << "write_rpc_calls " << write_rpc_calls
<< " write_rpc_time " << write_rpc_time
<< " server_write_calls " << server_write_calls
<< " server_write_time " << server_write_time
<< " bytes_written " << bytes_written
<< " write_expose " << write_expose
<< " write_bulk_time " << write_bulk_time
<< " write_bulk_xfers " << write_bulk_xfers
<< " write_response " << write_response
<< " read_rpc_calls " << read_rpc_calls
<< " read_rpc_time " << read_rpc_time
<< " server_read_calls " << server_read_calls
<< " server_read_time " << server_read_time
<< " bytes_read " << bytes_read
<< " read_bulk_time " << read_bulk_time
<< " read_bulk_xfers " << read_bulk_xfers
<< " read_expose " << read_expose
<< " read_response " << read_response
<< " getfd " << getfd
<< " mutex_time " << mutex_time << std::endl;
}
void print_client() {
......@@ -70,50 +108,3 @@ class io_stats {
print_client();
}
};
io_stats & io_stats::operator = (const io_stats &rhs)
{
// overwriting basic types so no need to worry about self-assignment
/* server things */
write_rpc_calls = rhs.write_rpc_calls;
write_rpc_time = rhs.write_rpc_time;
server_write_calls = rhs.server_write_calls;
server_write_time = rhs.server_write_time;
bytes_written = rhs.bytes_written;
read_rpc_calls = rhs.read_rpc_calls;
read_rpc_time = rhs.read_rpc_time;
server_read_calls = rhs.server_read_calls;
server_read_time = rhs.server_read_time;
bytes_read = rhs.bytes_read;
mutex_time = rhs.mutex_time;
/* client things */
client_write_calls = rhs.client_write_calls;
client_write_time = rhs.client_write_time;
client_read_calls = rhs.client_read_calls;
client_read_time = rhs.client_read_time;
return *this;
}
io_stats operator + (const io_stats & lhs, const io_stats &rhs)
{
io_stats sum;
sum.write_rpc_calls = lhs.write_rpc_calls + rhs.write_rpc_calls;
sum.write_rpc_time = lhs.write_rpc_time + rhs.write_rpc_time;
sum.server_write_calls = lhs.server_write_calls + rhs.server_write_calls;
sum.server_write_time = lhs.server_write_time + rhs.server_write_time;
sum.bytes_written = lhs.bytes_written + rhs.bytes_written;
sum.read_rpc_calls = lhs.read_rpc_calls + rhs.read_rpc_calls;
sum.read_rpc_time = lhs.read_rpc_time + rhs.read_rpc_time;
sum.server_read_calls = lhs.server_read_calls + rhs.server_read_calls;
sum.server_read_time = lhs.server_read_time + rhs.server_read_time;
sum.bytes_read = lhs.bytes_read + rhs.bytes_read;
sum.mutex_time = lhs.mutex_time + rhs.mutex_time;
/* client things */
sum.client_write_calls = lhs.client_write_calls + rhs.client_write_calls;
sum.client_write_time = lhs.client_write_time + rhs.client_write_time;
sum.client_read_calls = lhs.client_read_calls + rhs.client_read_calls;
sum.client_read_time = lhs.client_read_time + rhs.client_read_time;
return sum;
}
......@@ -84,7 +84,10 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
- might want to data-sieve the I/O requests
- might later read file */
int flags = O_CREAT|O_RDWR;
double getfd_time = ABT_get_wtime();
int fd = getfd(file, flags);
getfd_time = ABT_get_wtime() - getfd_time;
stats.getfd += getfd_time;
// we have a scratch buffer we can work with, which might be smaller
// than whatever the client has sent our way. We will repeatedly bulk
......@@ -98,8 +101,11 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
segments[0].first = (void *)(&(buffer[0]));
segments[0].second = bufsize;
double expose_time = ABT_get_wtime();
tl::endpoint ep = req.get_endpoint();
tl::bulk local = engine->expose(segments, tl::bulk_mode::read_write);
expose_time = ABT_get_wtime() - expose_time;
stats.write_expose += expose_time;
// when are we done?
// - what if the client has a really long file descripton but for some reason only a small amount of memory?
......@@ -117,6 +123,7 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
// the '>>' operator moves bytes from one bulk descriptor to the
// other, moving the smaller of the two
file_xfer = 0;
double bulk_time = ABT_get_wtime();
try {
client_xfer = client_bulk(client_cursor, client_bulk.size()-client_cursor).on(ep) >> local;
} catch (std::exception err) {
......@@ -124,6 +131,10 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
<< client_cursor << " size: "
<< client_bulk.size()-client_cursor << std::endl;
}
bulk_time = ABT_get_wtime() - bulk_time;
stats.write_bulk_xfers++;
stats.write_bulk_time += bulk_time;
// operator overloading might make this a little hard to parse at first.
// - >> and << do a bulk transfer between bulk endpoints, transfering
// the smallest of the two
......@@ -131,8 +142,8 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
// if one wants a subset
// - select a subset on the client-side bulk descriptor before
// associating it with a connection.
double pwrite_time = ABT_get_wtime();
while (file_idx < file_starts.size() && file_xfer < client_xfer) {
double pwrite_time = ABT_get_wtime();
// we might be able to only write a partial block
nbytes = MIN(file_sizes[file_idx]-fileblk_cursor, client_xfer-buf_cursor);
......@@ -140,7 +151,6 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
{
std::lock_guard<tl::mutex> guard(stats_mutex);
stats.server_write_calls++;
stats.server_write_time = ABT_get_wtime() - pwrite_time;
stats.bytes_written += nbytes;
}
......@@ -159,8 +169,15 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
xfered += nbytes;
}
client_cursor += client_xfer;
pwrite_time = ABT_get_wtime() - pwrite_time;
stats.server_write_time += pwrite_time;
}
double response_time = ABT_get_wtime();
req.respond(xfered);
response_time = ABT_get_wtime() - response_time;
stats.write_response += response_time;
{
std::lock_guard<tl::mutex> guard(stats_mutex);
stats.write_rpc_calls++;
......@@ -197,7 +214,10 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
* first for read then written to */
int flags = O_RDWR;
double getfd_time = ABT_get_wtime();
int fd = getfd(file, flags);
getfd_time = ABT_get_wtime() - getfd_time;
stats.getfd += getfd_time;
tl::endpoint ep = req.get_endpoint();
/* Simliar algorithm as write, but data movement goes in the opposite direction */
......@@ -216,7 +236,6 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
{
std::lock_guard<tl::mutex> guard(stats_mutex);
stats.server_read_calls++;
stats.server_read_time = ABT_get_wtime() - pread_time;
stats.bytes_read += nbytes;
}
......@@ -234,15 +253,29 @@ struct bv_svc_provider : public tl::provider<bv_svc_provider>
xfered += nbytes;
}
pread_time = ABT_get_wtime() - pread_time;
stats.server_read_time += pread_time;
double expose_time = ABT_get_wtime();
std::vector<std::pair<void *, std::size_t>>segments(1);
segments[0].first = (void*)(&(buffer[0]));
segments[0].second = file_xfer;
tl::bulk local = engine->expose(segments, tl::bulk_mode::read_write);
expose_time = ABT_get_wtime() - expose_time;
stats.read_expose += expose_time;
double bulk_time = ABT_get_wtime();
client_xfer = client_bulk(client_cursor, client_bulk.size()-client_cursor).on(ep) << local;
client_cursor += client_xfer;
bulk_time = ABT_get_wtime() - bulk_time;
stats.read_bulk_xfers++;
stats.read_bulk_time += bulk_time;
}
double response_time = ABT_get_wtime();
req.respond(xfered);
response_time = ABT_get_wtime() - response_time;
stats.read_response += response_time;
{
std::lock_guard<tl::mutex> guard(stats_mutex);
stats.read_rpc_calls++;
......
Markdown is supported
0% or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment