Merge branch '2700-improve-failed-tcp-accept-logging' into 'main'

Improve the logging on failed TCP accept

Closes #2700

See merge request isc-projects/bind9!5611
This commit is contained in:
Ondřej Surý 2021-12-02 13:18:10 +00:00
commit 240b8a3afc
7 changed files with 51 additions and 58 deletions

View file

@ -1,3 +1,9 @@
5773. [func] Change the message when accepting TCP connection has
failed to say "Accepting TCP connection failed" and
change the log level for ISC_R_NOTCONNECTED, ISC_R_QUOTA
and ISC_R_SOFTQUOTA results codes from ERROR to INFO.
[GL #2700]
5772. [bug] The resolver could hang on shutdown due to dispatch
resources not being cleaned up when a TCP connection
was reset. [GL #3026]

View file

@ -49,6 +49,15 @@ Feature Changes
or wildcard (``*``) characters. This reverts change :gl:`!5738` from the
previous release. :gl:`#1610`
- Previously, when an incoming TCP connection could not be accepted because the client
closed the connection early, an error message of ``TCP connection
failed: socket is not connected`` was logged. This message has been changed
to ``Accepting TCP connection failed: socket is not connected``. The
severity level at which this type of message is logged has also
been changed from ``error`` to ``info`` for the following triggering
events: ``socket is not connected``, ``quota reached``, and ``soft
quota reached``. :gl:`#2700`
Bug Fixes
~~~~~~~~~

View file

@ -2034,4 +2034,7 @@ isc__nm_failed_read_cb(isc_nmsocket_t *sock, isc_result_t result, bool async);
void
isc__nmsocket_connecttimeout_cb(uv_timer_t *timer);
void
isc__nm_accept_connection_log(isc_result_t result, bool can_log_quota);
#define STREAM_CLIENTS_PER_CONN 23

View file

@ -2048,6 +2048,33 @@ isc__nmsocket_connecttimeout_cb(uv_timer_t *timer) {
}
}
void
isc__nm_accept_connection_log(isc_result_t result, bool can_log_quota) {
int level;
switch (result) {
case ISC_R_SUCCESS:
case ISC_R_NOCONN:
return;
case ISC_R_QUOTA:
case ISC_R_SOFTQUOTA:
if (!can_log_quota) {
return;
}
level = ISC_LOG_INFO;
break;
case ISC_R_NOTCONNECTED:
level = ISC_LOG_INFO;
break;
default:
level = ISC_LOG_ERROR;
}
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL, ISC_LOGMODULE_NETMGR,
level, "Accepting TCP connection failed: %s",
isc_result_totext(result));
}
static void
isc__nmsocket_readtimeout_cb(uv_timer_t *timer) {
isc_nmsocket_t *sock = uv_handle_get_data((uv_handle_t *)timer);

View file

@ -631,15 +631,7 @@ tcp_connection_cb(uv_stream_t *server, int status) {
result = accept_connection(ssock, quota);
done:
if (result != ISC_R_SUCCESS && result != ISC_R_NOCONN) {
if ((result != ISC_R_QUOTA && result != ISC_R_SOFTQUOTA) ||
can_log_tcp_quota()) {
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL,
ISC_LOGMODULE_NETMGR, ISC_LOG_ERROR,
"TCP connection failed: %s",
isc_result_totext(result));
}
}
isc__nm_accept_connection_log(result, can_log_tcp_quota());
}
void
@ -931,15 +923,7 @@ isc__nm_async_tcpaccept(isc__networker_t *worker, isc__netievent_t *ev0) {
REQUIRE(sock->tid == isc_nm_tid());
result = accept_connection(sock, ievent->quota);
if (result != ISC_R_SUCCESS && result != ISC_R_NOCONN) {
if ((result != ISC_R_QUOTA && result != ISC_R_SOFTQUOTA) ||
can_log_tcp_quota()) {
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL,
ISC_LOGMODULE_NETMGR, ISC_LOG_ERROR,
"TCP connection failed: %s",
isc_result_totext(result));
}
}
isc__nm_accept_connection_log(result, can_log_tcp_quota());
}
static isc_result_t

View file

@ -600,16 +600,7 @@ tcpdns_connection_cb(uv_stream_t *server, int status) {
result = accept_connection(ssock, quota);
done:
if (result != ISC_R_SUCCESS && result != ISC_R_NOCONN) {
if ((result != ISC_R_QUOTA && result != ISC_R_SOFTQUOTA) ||
can_log_tcpdns_quota())
{
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL,
ISC_LOGMODULE_NETMGR, ISC_LOG_ERROR,
"TCP connection failed: %s",
isc_result_totext(result));
}
}
isc__nm_accept_connection_log(result, can_log_tcpdns_quota());
}
void
@ -920,16 +911,7 @@ isc__nm_async_tcpdnsaccept(isc__networker_t *worker, isc__netievent_t *ev0) {
REQUIRE(ievent->sock->tid == isc_nm_tid());
result = accept_connection(ievent->sock, ievent->quota);
if (result != ISC_R_SUCCESS && result != ISC_R_NOCONN) {
if ((result != ISC_R_QUOTA && result != ISC_R_SOFTQUOTA) ||
can_log_tcpdns_quota())
{
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL,
ISC_LOGMODULE_NETMGR, ISC_LOG_ERROR,
"TCP connection failed: %s",
isc_result_totext(result));
}
}
isc__nm_accept_connection_log(result, can_log_tcpdns_quota());
}
static isc_result_t

View file

@ -675,16 +675,7 @@ tlsdns_connection_cb(uv_stream_t *server, int status) {
result = accept_connection(ssock, quota);
done:
if (result != ISC_R_SUCCESS && result != ISC_R_NOCONN) {
if ((result != ISC_R_QUOTA && result != ISC_R_SOFTQUOTA) ||
can_log_tlsdns_quota())
{
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL,
ISC_LOGMODULE_NETMGR, ISC_LOG_ERROR,
"TCP connection failed: %s",
isc_result_totext(result));
}
}
isc__nm_accept_connection_log(result, can_log_tlsdns_quota());
}
void
@ -1425,16 +1416,7 @@ isc__nm_async_tlsdnsaccept(isc__networker_t *worker, isc__netievent_t *ev0) {
REQUIRE(ievent->sock->tid == isc_nm_tid());
result = accept_connection(ievent->sock, ievent->quota);
if (result != ISC_R_SUCCESS && result != ISC_R_NOCONN) {
if ((result != ISC_R_QUOTA && result != ISC_R_SOFTQUOTA) ||
can_log_tlsdns_quota())
{
isc_log_write(isc_lctx, ISC_LOGCATEGORY_GENERAL,
ISC_LOGMODULE_NETMGR, ISC_LOG_ERROR,
"TCP connection failed: %s",
isc_result_totext(result));
}
}
isc__nm_accept_connection_log(result, can_log_tlsdns_quota());
}
static isc_result_t