libuv/test/test-metrics.c

239 lines
6.5 KiB
C
Raw Normal View History

/* Copyright libuv project contributors. All rights reserved.
*
* Permission is hereby granted, free of charge, to any person obtaining a copy
* of this software and associated documentation files (the "Software"), to
* deal in the Software without restriction, including without limitation the
* rights to use, copy, modify, merge, publish, distribute, sublicense, and/or
* sell copies of the Software, and to permit persons to whom the Software is
* furnished to do so, subject to the following conditions:
*
* The above copyright notice and this permission notice shall be included in
* all copies or substantial portions of the Software.
*
* THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
* IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
* FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
* AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
* LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING
* FROM, OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS
* IN THE SOFTWARE.
*/
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
#include "uv.h"
#include "task.h"
#include <string.h> /* memset */
#define UV_NS_TO_MS 1000000
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
typedef struct {
uv_fs_t open_req;
uv_fs_t write_req;
uv_fs_t close_req;
} fs_reqs_t;
static uint64_t last_events_count;
static char test_buf[] = "test-buffer\n";
static fs_reqs_t fs_reqs;
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
static void timer_spin_cb(uv_timer_t* handle) {
uint64_t t;
(*(int*) handle->data)++;
t = uv_hrtime();
/* Spin for 500 ms to spin loop time out of the delta check. */
while (uv_hrtime() - t < 600 * UV_NS_TO_MS) { }
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
}
TEST_IMPL(metrics_idle_time) {
const uint64_t timeout = 1000;
uv_timer_t timer;
uint64_t idle_time;
int cntr;
cntr = 0;
timer.data = &cntr;
ASSERT_EQ(0, uv_loop_configure(uv_default_loop(), UV_METRICS_IDLE_TIME));
ASSERT_EQ(0, uv_timer_init(uv_default_loop(), &timer));
ASSERT_EQ(0, uv_timer_start(&timer, timer_spin_cb, timeout, 0));
ASSERT_EQ(0, uv_run(uv_default_loop(), UV_RUN_DEFAULT));
ASSERT_GT(cntr, 0);
idle_time = uv_metrics_idle_time(uv_default_loop());
/* Permissive check that the idle time matches within the timeout ±500 ms. */
ASSERT((idle_time <= (timeout + 500) * UV_NS_TO_MS) &&
(idle_time >= (timeout - 500) * UV_NS_TO_MS));
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
MAKE_VALGRIND_HAPPY();
return 0;
}
static void metrics_routine_cb(void* arg) {
const uint64_t timeout = 1000;
uv_loop_t loop;
uv_timer_t timer;
uint64_t idle_time;
int cntr;
cntr = 0;
timer.data = &cntr;
ASSERT_EQ(0, uv_loop_init(&loop));
ASSERT_EQ(0, uv_loop_configure(&loop, UV_METRICS_IDLE_TIME));
ASSERT_EQ(0, uv_timer_init(&loop, &timer));
ASSERT_EQ(0, uv_timer_start(&timer, timer_spin_cb, timeout, 0));
ASSERT_EQ(0, uv_run(&loop, UV_RUN_DEFAULT));
ASSERT_GT(cntr, 0);
idle_time = uv_metrics_idle_time(&loop);
/* Only checking that idle time is greater than the lower bound since there
* may have been thread contention, causing the event loop to be delayed in
* the idle phase longer than expected.
*/
ASSERT_GE(idle_time, (timeout - 500) * UV_NS_TO_MS);
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
close_loop(&loop);
ASSERT_EQ(0, uv_loop_close(&loop));
}
TEST_IMPL(metrics_idle_time_thread) {
uv_thread_t threads[5];
int i;
for (i = 0; i < 5; i++) {
ASSERT_EQ(0, uv_thread_create(&threads[i], metrics_routine_cb, NULL));
}
for (i = 0; i < 5; i++) {
uv_thread_join(&threads[i]);
}
return 0;
}
static void timer_noop_cb(uv_timer_t* handle) {
(*(int*) handle->data)++;
}
TEST_IMPL(metrics_idle_time_zero) {
uv_metrics_t metrics;
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
uv_timer_t timer;
int cntr;
cntr = 0;
timer.data = &cntr;
ASSERT_EQ(0, uv_loop_configure(uv_default_loop(), UV_METRICS_IDLE_TIME));
ASSERT_EQ(0, uv_timer_init(uv_default_loop(), &timer));
ASSERT_EQ(0, uv_timer_start(&timer, timer_noop_cb, 0, 0));
ASSERT_EQ(0, uv_run(uv_default_loop(), UV_RUN_DEFAULT));
ASSERT_GT(cntr, 0);
ASSERT_EQ(0, uv_metrics_idle_time(uv_default_loop()));
ASSERT_EQ(0, uv_metrics_info(uv_default_loop(), &metrics));
ASSERT_UINT64_EQ(cntr, metrics.loop_count);
MAKE_VALGRIND_HAPPY();
return 0;
}
static void close_cb(uv_fs_t* req) {
uv_metrics_t metrics;
ASSERT_EQ(0, uv_metrics_info(uv_default_loop(), &metrics));
ASSERT_UINT64_EQ(3, metrics.loop_count);
ASSERT_UINT64_GT(metrics.events, last_events_count);
uv_fs_req_cleanup(req);
last_events_count = metrics.events;
}
static void write_cb(uv_fs_t* req) {
uv_metrics_t metrics;
ASSERT_EQ(0, uv_metrics_info(uv_default_loop(), &metrics));
ASSERT_UINT64_EQ(2, metrics.loop_count);
ASSERT_UINT64_GT(metrics.events, last_events_count);
ASSERT_EQ(req->result, sizeof(test_buf));
uv_fs_req_cleanup(req);
last_events_count = metrics.events;
ASSERT_EQ(0, uv_fs_close(uv_default_loop(),
&fs_reqs.close_req,
fs_reqs.open_req.result,
close_cb));
}
static void create_cb(uv_fs_t* req) {
uv_metrics_t metrics;
ASSERT_EQ(0, uv_metrics_info(uv_default_loop(), &metrics));
/* Event count here is still 0 so not going to check. */
ASSERT_UINT64_EQ(1, metrics.loop_count);
ASSERT_GE(req->result, 0);
uv_fs_req_cleanup(req);
last_events_count = metrics.events;
uv_buf_t iov = uv_buf_init(test_buf, sizeof(test_buf));
ASSERT_EQ(0, uv_fs_write(uv_default_loop(),
&fs_reqs.write_req,
req->result,
&iov,
1,
0,
write_cb));
}
static void prepare_cb(uv_prepare_t* handle) {
uv_metrics_t metrics;
uv_prepare_stop(handle);
ASSERT_EQ(0, uv_metrics_info(uv_default_loop(), &metrics));
ASSERT_UINT64_EQ(0, metrics.loop_count);
ASSERT_UINT64_EQ(0, metrics.events);
ASSERT_EQ(0, uv_fs_open(uv_default_loop(),
&fs_reqs.open_req,
"test_file",
O_WRONLY | O_CREAT, S_IRUSR | S_IWUSR,
create_cb));
}
TEST_IMPL(metrics_info_check) {
uv_fs_t unlink_req;
uv_prepare_t prepare;
uv_fs_unlink(NULL, &unlink_req, "test_file", NULL);
uv_fs_req_cleanup(&unlink_req);
ASSERT_EQ(0, uv_prepare_init(uv_default_loop(), &prepare));
ASSERT_EQ(0, uv_prepare_start(&prepare, prepare_cb));
ASSERT_EQ(0, uv_run(uv_default_loop(), UV_RUN_DEFAULT));
uv_fs_unlink(NULL, &unlink_req, "test_file", NULL);
uv_fs_req_cleanup(&unlink_req);
core: add API to measure event loop idle time The API addition `uv_metrics_idle_time()` is a thread safe call that allows the user to retrieve the amount of time the event loop has spent in the kernel's event provider (i.e. poll). It was done this way to allow retrieving this value without needing to interrupt the execution of the event loop. This option can be enabled by passing `UV_METRICS_IDLE_TIME` to `uv_loop_configure()`. One important aspect of this change is, when enabled, to always first call the event provider with a `timeout == 0`. This allows libuv to know whether any events were waiting in the event queue when the event provider was called. The importance of this is because libuv is tracking the amount of "idle time", not "poll time". Thus the provider entry time is not recorded when `timeout == 0` (the event provider never idles in this case). While this does add a small amount of overhead, when enabled, but the overhead decreases when the event loop has a heavier load. This is because poll events will be waiting when the event provider is called. Thus never actually recording the provider entry time. Checking if `uv_loop_t` is configured with `UV_METRICS_IDLE_TIME` always happens in `uv__metrics_set_provider_entry_time()` and `uv__metrics_update_idle_time()`. Making the conditional logic wrapping each call simpler and allows for instrumentation to always hook into those two function calls. Rather than placing the fields directly on `uv__loop_internal_fields_t` add the struct `uv__loop_metrics_t` as a location for future metrics API additions. Tests and additional documentation has been included. PR-URL: https://github.com/libuv/libuv/pull/2725 Reviewed-By: Fedor Indutny <fedor.indutny@gmail.com> Reviewed-By: Santiago Gimeno <santiago.gimeno@gmail.com> Reviewed-By: Jameson Nash <vtjnash@gmail.com>
2020-03-26 23:15:13 +00:00
MAKE_VALGRIND_HAPPY();
return 0;
}