From b8be8048b51c613f47e8874cd2fa4d246e94dff8 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ond=C5=99ej=20Sur=C3=BD?= Date: Tue, 15 Feb 2022 14:44:29 +0100 Subject: [PATCH 1/3] Add UV_RUNTIME_CHECK() macro to print uv_strerror() When libuv functions fail, they return correct return value that could be useful for more detailed debugging. Currently, we usually just check whether the return value is 0 and invoke assertion error if it doesn't throwing away the details why the call has failed. Unfortunately, this often happen on more exotic platforms. Add a UV_RUNTIME_CHECK() macro that can be used to print more detailed error message (via uv_strerror() before ending the execution of the program abruptly with the assertion. (cherry picked from commit 62e15bb06db5e7d209e8c20d7bdb1501df7dfba8) --- lib/isc/netmgr/netmgr-int.h | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/lib/isc/netmgr/netmgr-int.h b/lib/isc/netmgr/netmgr-int.h index b8a49feef2..2ce53402b2 100644 --- a/lib/isc/netmgr/netmgr-int.h +++ b/lib/isc/netmgr/netmgr-int.h @@ -2078,3 +2078,9 @@ void isc__nm_accept_connection_log(isc_result_t result, bool can_log_quota); #define STREAM_CLIENTS_PER_CONN 23 + +#define UV_RUNTIME_CHECK(func, ret) \ + if (ret != 0) { \ + isc_error_fatal(__FILE__, __LINE__, "%s failed: %s\n", #func, \ + uv_strerror(ret)); \ + } From f64150702283e29ca41ab2d740aea48cca37cfa9 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ond=C5=99ej=20Sur=C3=BD?= Date: Tue, 15 Feb 2022 14:51:02 +0100 Subject: [PATCH 2/3] Use UV_RUNTIME_CHECK() as appropriate Replace the RUNTIME_CHECK() calls for libuv API calls with UV_RUNTIME_CHECK() to get more detailed error message when something fails and should not. (cherry picked from commit 8715be1e4b51a4f74e5d4fedbb78995b5bbccb84) --- lib/isc/netmgr/netmgr.c | 39 +++++++++++++++++++++++--------------- lib/isc/netmgr/tcp.c | 12 ++++++------ lib/isc/netmgr/tcpdns.c | 21 +++++++++------------ lib/isc/netmgr/tlsdns.c | 42 ++++++++++++++++++++++------------------- lib/isc/netmgr/udp.c | 12 ++++++------ 5 files changed, 68 insertions(+), 58 deletions(-) diff --git a/lib/isc/netmgr/netmgr.c b/lib/isc/netmgr/netmgr.c index 481cc61586..ecdb26340d 100644 --- a/lib/isc/netmgr/netmgr.c +++ b/lib/isc/netmgr/netmgr.c @@ -295,20 +295,21 @@ isc__netmgr_create(isc_mem_t *mctx, uint32_t workers, isc_nm_t **netmgrp) { mgr->workers = isc_mem_get(mctx, workers * sizeof(isc__networker_t)); for (size_t i = 0; i < workers; i++) { - int r; isc__networker_t *worker = &mgr->workers[i]; + int r; + *worker = (isc__networker_t){ .mgr = mgr, .id = i, }; r = uv_loop_init(&worker->loop); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_loop_init, r); worker->loop.data = &mgr->workers[i]; r = uv_async_init(&worker->loop, &worker->async, async_cb); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_async_init, r); isc_mutex_init(&worker->lock); isc_condition_init(&worker->cond_prio); @@ -384,7 +385,7 @@ nm_destroy(isc_nm_t **mgr0) { isc_mutex_destroy(&worker->lock); r = uv_loop_close(&worker->loop); - INSIST(r == 0); + UV_RUNTIME_CHECK(uv_loop_close, r); for (size_t type = 0; type < NETIEVENT_MAX; type++) { isc_queue_destroy(worker->ievents[type]); @@ -2098,11 +2099,11 @@ isc__nmsocket_readtimeout_cb(uv_timer_t *timer) { void isc__nmsocket_timer_restart(isc_nmsocket_t *sock) { - int r = 0; - REQUIRE(VALID_NMSOCK(sock)); if (atomic_load(&sock->connecting)) { + int r; + if (sock->connect_timeout == 0) { return; } @@ -2110,17 +2111,19 @@ isc__nmsocket_timer_restart(isc_nmsocket_t *sock) { r = uv_timer_start(&sock->timer, isc__nmsocket_connecttimeout_cb, sock->connect_timeout + 10, 0); + UV_RUNTIME_CHECK(uv_timer_start, r); } else { + int r; + if (sock->read_timeout == 0) { return; } r = uv_timer_start(&sock->timer, isc__nmsocket_readtimeout_cb, sock->read_timeout, 0); + UV_RUNTIME_CHECK(uv_timer_start, r); } - - RUNTIME_CHECK(r == 0); } bool @@ -2143,12 +2146,14 @@ isc__nmsocket_timer_start(isc_nmsocket_t *sock) { void isc__nmsocket_timer_stop(isc_nmsocket_t *sock) { + int r; + REQUIRE(VALID_NMSOCK(sock)); /* uv_timer_stop() is idempotent, no need to check if running */ - int r = uv_timer_stop(&sock->timer); - RUNTIME_CHECK(r == 0); + r = uv_timer_stop(&sock->timer); + UV_RUNTIME_CHECK(uv_timer_stop, r); } isc__nm_uvreq_t * @@ -2232,24 +2237,27 @@ isc__nm_start_reading(isc_nmsocket_t *sock) { case isc_nm_udpsocket: r = uv_udp_recv_start(&sock->uv_handle.udp, isc__nm_alloc_cb, isc__nm_udp_read_cb); + UV_RUNTIME_CHECK(uv_udp_recv_start, r); break; case isc_nm_tcpsocket: r = uv_read_start(&sock->uv_handle.stream, isc__nm_alloc_cb, isc__nm_tcp_read_cb); + UV_RUNTIME_CHECK(uv_read_start, r); break; case isc_nm_tcpdnssocket: r = uv_read_start(&sock->uv_handle.stream, isc__nm_alloc_cb, isc__nm_tcpdns_read_cb); + UV_RUNTIME_CHECK(uv_read_start, r); break; case isc_nm_tlsdnssocket: r = uv_read_start(&sock->uv_handle.stream, isc__nm_alloc_cb, isc__nm_tlsdns_read_cb); + UV_RUNTIME_CHECK(uv_read_start, r); break; default: INSIST(0); ISC_UNREACHABLE(); } - RUNTIME_CHECK(r == 0); atomic_store(&sock->reading, true); } @@ -2264,17 +2272,18 @@ isc__nm_stop_reading(isc_nmsocket_t *sock) { switch (sock->type) { case isc_nm_udpsocket: r = uv_udp_recv_stop(&sock->uv_handle.udp); + UV_RUNTIME_CHECK(uv_udp_recv_stop, r); break; case isc_nm_tcpsocket: case isc_nm_tcpdnssocket: case isc_nm_tlsdnssocket: r = uv_read_stop(&sock->uv_handle.stream); + UV_RUNTIME_CHECK(uv_read_stop, r); break; default: INSIST(0); ISC_UNREACHABLE(); } - RUNTIME_CHECK(r == 0); atomic_store(&sock->reading, false); } @@ -3322,12 +3331,12 @@ isc__nm_set_network_buffers(isc_nm_t *nm, uv_handle_t *handle) { if (recv_buffer_size > 0) { int r = uv_recv_buffer_size(handle, &recv_buffer_size); - INSIST(r == 0); + UV_RUNTIME_CHECK(uv_recv_buffer_size, r); } if (send_buffer_size > 0) { int r = uv_send_buffer_size(handle, &send_buffer_size); - INSIST(r == 0); + UV_RUNTIME_CHECK(uv_send_buffer_size, r); } } @@ -3395,7 +3404,7 @@ isc_nm_work_offload(isc_nm_t *netmgr, isc_nm_workcb_t work_cb, r = uv_queue_work(&worker->loop, &work->req, isc__nm_work_cb, isc__nm_after_work_cb); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_queue_work, r); } void diff --git a/lib/isc/netmgr/tcp.c b/lib/isc/netmgr/tcp.c index b0034b9cbf..45339244c7 100644 --- a/lib/isc/netmgr/tcp.c +++ b/lib/isc/netmgr/tcp.c @@ -137,11 +137,11 @@ tcp_connect_direct(isc_nmsocket_t *sock, isc__nm_uvreq_t *req) { RUNTIME_CHECK(result == ISC_R_SUCCESS); r = uv_tcp_init(&worker->loop, &sock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); r = uv_tcp_open(&sock->uv_handle.tcp, sock->fd); if (r != 0) { @@ -521,14 +521,14 @@ isc__nm_async_tcplisten(isc__networker_t *worker, isc__netievent_t *ev0) { /* TODO: set min mss */ r = uv_tcp_init(&worker->loop, &sock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); /* This keeps the socket alive after everything else is gone */ isc__nmsocket_attach(sock, &(isc_nmsocket_t *){ NULL }); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); @@ -971,11 +971,11 @@ accept_connection(isc_nmsocket_t *ssock, isc_quota_t *quota) { worker = &csock->mgr->workers[isc_nm_tid()]; r = uv_tcp_init(&worker->loop, &csock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&csock->uv_handle.handle, csock); r = uv_timer_init(&worker->loop, &csock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&csock->timer, csock); r = uv_accept(&ssock->uv_handle.stream, &csock->uv_handle.stream); diff --git a/lib/isc/netmgr/tcpdns.c b/lib/isc/netmgr/tcpdns.c index 21d1ab5bc6..ce31e30c86 100644 --- a/lib/isc/netmgr/tcpdns.c +++ b/lib/isc/netmgr/tcpdns.c @@ -102,11 +102,11 @@ tcpdns_connect_direct(isc_nmsocket_t *sock, isc__nm_uvreq_t *req) { atomic_store(&sock->connecting, true); r = uv_tcp_init(&worker->loop, &sock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); if (isc__nm_closing(sock)) { result = ISC_R_SHUTTINGDOWN; @@ -492,13 +492,13 @@ isc__nm_async_tcpdnslisten(isc__networker_t *worker, isc__netievent_t *ev0) { /* TODO: set min mss */ r = uv_tcp_init(&worker->loop, &sock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); /* This keeps the socket alive after everything else is gone */ isc__nmsocket_attach(sock, &(isc_nmsocket_t *){ NULL }); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); LOCK(&sock->parent->lock); @@ -963,11 +963,11 @@ accept_connection(isc_nmsocket_t *ssock, isc_quota_t *quota) { worker = &csock->mgr->workers[csock->tid]; r = uv_tcp_init(&worker->loop, &csock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&csock->uv_handle.handle, csock); r = uv_timer_init(&worker->loop, &csock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&csock->timer, csock); r = uv_accept(&ssock->uv_handle.stream, &csock->uv_handle.stream); @@ -1162,7 +1162,7 @@ isc__nm_async_tcpdnssend(isc__networker_t *worker, isc__netievent_t *ev0) { bufs[0].base = uvreq->uvbuf.base + (r - 2); bufs[0].len = uvreq->uvbuf.len - (r - 2); } else if (r == UV_ENOSYS || r == UV_EAGAIN) { - /* uv_try_write not support, send asynchronously */ + /* uv_try_write not supported, send asynchronously */ } else { /* error sending data */ result = isc__nm_uverr2result(r); @@ -1177,12 +1177,9 @@ isc__nm_async_tcpdnssend(isc__networker_t *worker, isc__netievent_t *ev0) { } return; - fail: - if (result != ISC_R_SUCCESS) { - isc__nm_incstats(sock, STATID_SENDFAIL); - isc__nm_failed_send_cb(sock, uvreq, result); - } + isc__nm_incstats(sock, STATID_SENDFAIL); + isc__nm_failed_send_cb(sock, uvreq, result); } static void diff --git a/lib/isc/netmgr/tlsdns.c b/lib/isc/netmgr/tlsdns.c index d56c82857a..bd564bac25 100644 --- a/lib/isc/netmgr/tlsdns.c +++ b/lib/isc/netmgr/tlsdns.c @@ -118,11 +118,11 @@ tlsdns_connect_direct(isc_nmsocket_t *sock, isc__nm_uvreq_t *req) { RUNTIME_CHECK(result == ISC_R_SUCCESS); r = uv_tcp_init(&worker->loop, &sock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); if (isc__nm_closing(sock)) { @@ -564,13 +564,13 @@ isc__nm_async_tlsdnslisten(isc__networker_t *worker, isc__netievent_t *ev0) { /* TODO: set min mss */ r = uv_tcp_init(&worker->loop, &sock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); /* This keeps the socket alive after everything else is gone */ isc__nmsocket_attach(sock, &(isc_nmsocket_t *){ NULL }); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); LOCK(&sock->parent->lock); @@ -1188,7 +1188,7 @@ tls_cycle_output(isc_nmsocket_t *sock) { isc__nm_uvreq_t *req = NULL; size_t bytes; int rv; - int err; + int r; if (sock->tls.senddata.base != NULL || sock->tls.senddata.length > 0) { @@ -1212,34 +1212,38 @@ tls_cycle_output(isc_nmsocket_t *sock) { RUNTIME_CHECK(rv == 1); INSIST((size_t)pending == bytes); - err = uv_try_write(&sock->uv_handle.stream, &req->uvbuf, 1); + r = uv_try_write(&sock->uv_handle.stream, &req->uvbuf, 1); - if (err == pending) { + if (r == pending) { /* Wrote everything, restart */ isc__nm_uvreq_put(&req, sock); free_senddata(sock); continue; } - if (err > 0) { + if (r > 0) { /* Partial write, send rest asynchronously */ - memmove(req->uvbuf.base, req->uvbuf.base + err, - req->uvbuf.len - err); - req->uvbuf.len = req->uvbuf.len - err; - } else if (err == UV_ENOSYS || err == UV_EAGAIN) { + memmove(req->uvbuf.base, req->uvbuf.base + r, + req->uvbuf.len - r); + req->uvbuf.len = req->uvbuf.len - r; + } else if (r == UV_ENOSYS || r == UV_EAGAIN) { /* uv_try_write is not supported, send * asynchronously */ } else { - result = isc__nm_uverr2result(err); + result = isc__nm_uverr2result(r); isc__nm_uvreq_put(&req, sock); free_senddata(sock); break; } - err = uv_write(&req->uv_req.write, &sock->uv_handle.stream, - &req->uvbuf, 1, tls_write_cb); - - INSIST(err == 0); + r = uv_write(&req->uv_req.write, &sock->uv_handle.stream, + &req->uvbuf, 1, tls_write_cb); + if (r < 0) { + result = isc__nm_uverr2result(r); + isc__nm_uvreq_put(&req, sock); + free_senddata(sock); + break; + } break; } @@ -1469,11 +1473,11 @@ accept_connection(isc_nmsocket_t *ssock, isc_quota_t *quota) { worker = &csock->mgr->workers[csock->tid]; r = uv_tcp_init(&worker->loop, &csock->uv_handle.tcp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_tcp_init, r); uv_handle_set_data(&csock->uv_handle.handle, csock); r = uv_timer_init(&worker->loop, &csock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&csock->timer, csock); r = uv_accept(&ssock->uv_handle.stream, &csock->uv_handle.stream); diff --git a/lib/isc/netmgr/udp.c b/lib/isc/netmgr/udp.c index 0b7f01037f..3573836785 100644 --- a/lib/isc/netmgr/udp.c +++ b/lib/isc/netmgr/udp.c @@ -262,11 +262,11 @@ route_connect_direct(isc_nmsocket_t *sock) { atomic_store(&sock->connecting, true); r = uv_udp_init(&worker->loop, &sock->uv_handle.udp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_udp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); if (isc__nm_closing(sock)) { @@ -436,13 +436,13 @@ isc__nm_async_udplisten(isc__networker_t *worker, isc__netievent_t *ev0) { uv_init_flags |= UV_UDP_RECVMMSG; #endif r = uv_udp_init_ex(&worker->loop, &sock->uv_handle.udp, uv_init_flags); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_udp_init_ex, r); uv_handle_set_data(&sock->uv_handle.handle, sock); /* This keeps the socket alive after everything else is gone */ isc__nmsocket_attach(sock, &(isc_nmsocket_t *){ NULL }); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); LOCK(&sock->parent->lock); @@ -854,11 +854,11 @@ udp_connect_direct(isc_nmsocket_t *sock, isc__nm_uvreq_t *req) { atomic_store(&sock->connecting, true); r = uv_udp_init(&worker->loop, &sock->uv_handle.udp); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_udp_init, r); uv_handle_set_data(&sock->uv_handle.handle, sock); r = uv_timer_init(&worker->loop, &sock->timer); - RUNTIME_CHECK(r == 0); + UV_RUNTIME_CHECK(uv_timer_init, r); uv_handle_set_data((uv_handle_t *)&sock->timer, sock); if (isc__nm_closing(sock)) { From c30735707c71ba544e2fc14d2b2e31fa4640462f Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Ond=C5=99ej=20Sur=C3=BD?= Date: Tue, 15 Feb 2022 19:54:54 +0100 Subject: [PATCH 3/3] Add semantic patch to keep UV_RUNTIME_CHECK in sync The UV_RUNTIME_CHECK() macro requires to keep the function name in sync like this: r = func(...); UV_RUNTIME_CHECK(func, r); Add semantic patch to keep the function name and return variable in sync with the previous line. (cherry picked from commit 62bd5cb08c56e710ec1f4cd5da7454da6b01c5c1) --- cocci/UV_RUNTIME_CHECK.spatch | 8 ++++++++ 1 file changed, 8 insertions(+) create mode 100644 cocci/UV_RUNTIME_CHECK.spatch diff --git a/cocci/UV_RUNTIME_CHECK.spatch b/cocci/UV_RUNTIME_CHECK.spatch new file mode 100644 index 0000000000..6a50195b89 --- /dev/null +++ b/cocci/UV_RUNTIME_CHECK.spatch @@ -0,0 +1,8 @@ +@@ +expression E; +int R; +@@ + + R = E(...); +- UV_RUNTIME_CHECK(...); ++ UV_RUNTIME_CHECK(E, R);