Merge branch '1206-tcp-high-water-stats' into 'master'

Added tcp-high-water statistics variable.

Closes #1206

See merge request isc-projects/bind9!2425

CHANGES

@@ -1,3 +1,7 @@
+5314.	[func]		Added a new statistics variable "tcp-highwater"
+			that reports the maximum number of simultaneous TCP
+			clients BIND has handled while running. [GL #1206]
+
 5313.	[bug]		The default GeoIP2 database location did not match
 			the ARM.  'named -V' now reports the default
 			location. [GL #1301]

bin/named/server.c

@@ -11447,6 +11447,11 @@ named_server_status(named_server_t *server, isc_buffer_t **text) {
 		     isc_quota_getmax(&server->sctx->tcpquota));
 	CHECK(putstr(text, line));
 
+	snprintf(line, sizeof(line), "TCP high-water: %u\n",
+		     (unsigned)ns_stats_get_counter(server->sctx->nsstats,
+					  ns_statscounter_tcphighwater));
+	CHECK(putstr(text, line));
+
 	if (server->reload_status != NAMED_RELOAD_DONE) {
 		snprintf(line, sizeof(line), "reload/reconfig %s\n",
 			 server->reload_status == NAMED_RELOAD_FAILED

bin/named/statschannel.c

@@ -241,6 +241,8 @@ init_desc(void) {
 	SET_NSSTATDESC(invalidsig, "requests with invalid signature",
 		       "ReqBadSIG");
 	SET_NSSTATDESC(requesttcp, "TCP requests received", "ReqTCP");
+	SET_NSSTATDESC(tcphighwater, "TCP connection high-water",
+		       "TCPConnHighWater");
 	SET_NSSTATDESC(authrej, "auth queries rejected", "AuthQryRej");
 	SET_NSSTATDESC(recurserej, "recursive queries rejected", "RecQryRej");
 	SET_NSSTATDESC(xfrrej, "transfer requests rejected", "XfrRej");
@@ -322,6 +324,7 @@ init_desc(void) {
 		       "QryUsedStale");
 	SET_NSSTATDESC(prefetch, "queries triggered prefetch", "Prefetch");
 	SET_NSSTATDESC(keytagopt, "Keytag option received", "KeyTagOpt");
+
 	INSIST(i == ns_statscounter_max);
 
 	/* Initialize resolver statistics */

bin/tests/system/tcp/ans6/ans.py

@@ -0,0 +1,153 @@
+############################################################################
+# Copyright (C) Internet Systems Consortium, Inc. ("ISC")
+#
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# See the COPYRIGHT file distributed with this work for additional
+# information regarding copyright ownership.
+############################################################################
+
+############################################################################
+#
+# This tool allows an arbitrary number of TCP connections to be made to the
+# specified service and to keep them open until told otherwise.  It is
+# controlled by writing text commands to a TCP socket (default port: 5309).
+#
+# Currently supported commands:
+#
+#   - open <COUNT> <HOST> <PORT>
+#
+#     Opens <COUNT> TCP connections to <HOST>:<PORT> and keeps them open.
+#     <HOST> must be an IP address (IPv4 or IPv6).
+#
+#   - close <COUNT>
+#
+#     Close the oldest <COUNT> previously established connections.
+#
+############################################################################
+
+from __future__ import print_function
+
+import datetime
+import errno
+import os
+import select
+import signal
+import socket
+import sys
+import time
+
+
+# Timeout for establishing all connections requested by a single 'open' command.
+OPEN_TIMEOUT = 2
+
+
+def log(msg):
+    print(datetime.datetime.now().strftime('%d-%b-%Y %H:%M:%S.%f ') + msg)
+
+
+def open_connections(active_conns, count, host, port):
+    queued = []
+    errors = []
+
+    try:
+        socket.inet_aton(host)
+        family = socket.AF_INET
+    except socket.error:
+        family = socket.AF_INET6
+
+    log('Opening %d connections...' % count)
+
+    for _ in range(count):
+        sock = socket.socket(family, socket.SOCK_STREAM)
+        sock.setblocking(0)
+        err = sock.connect_ex((host, port))
+        if err not in (0, errno.EINPROGRESS):
+            log('%s on connect for socket %s' % (errno.errorcode[err], sock))
+            errors.append(sock)
+        else:
+            queued.append(sock)
+
+    start = time.time()
+    while queued:
+        now = time.time()
+        time_left = OPEN_TIMEOUT - (now - start)
+        if time_left <= 0:
+            break
+        _, wsocks, _ = select.select([], queued, [], time_left)
+        for sock in wsocks:
+            queued.remove(sock)
+            err = sock.getsockopt(socket.SOL_SOCKET, socket.SO_ERROR)
+            if err:
+                log('%s for socket %s' % (errno.errorcode[err], sock))
+                errors.append(sock)
+            else:
+                active_conns.append(sock)
+
+    if errors:
+        log('result=FAIL: %d connection(s) failed' % len(errors))
+    elif queued:
+        log('result=FAIL: Timed out, aborting %d pending connections' % len(queued))
+        for sock in queued:
+            sock.close()
+    else:
+        log('result=OK: Successfully opened %d connections' % count)
+
+
+def close_connections(active_conns, count):
+    log('Closing %d connections...' % count)
+    for _ in range(count):
+        sock = active_conns.pop(0)
+        sock.close()
+    log('result=OK: Successfully closed %d connections' % count)
+
+
+def sigterm(*_):
+    log('SIGTERM received, shutting down')
+    os.remove('ans.pid')
+    sys.exit(0)
+
+
+def main():
+    active_conns = []
+
+    signal.signal(signal.SIGTERM, sigterm)
+
+    with open('ans.pid', 'w') as pidfile:
+        print(os.getpid(), file=pidfile)
+
+    listenip = '10.53.0.6'
+    try:
+        port = int(os.environ['CONTROLPORT'])
+    except KeyError:
+        port = 5309
+
+    log('Listening on %s:%d' % (listenip, port))
+
+    ctlsock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
+    ctlsock.setsockopt(socket.SOL_SOCKET, socket.SO_REUSEADDR, 1)
+    ctlsock.bind((listenip, port))
+    ctlsock.listen(1)
+
+    while True:
+        (clientsock, _) = ctlsock.accept()
+        log('Accepted control connection from %s' % clientsock)
+        cmdline = clientsock.recv(512).decode('ascii').strip()
+        if cmdline:
+            log('Received command: %s' % cmdline)
+            cmd = cmdline.split()
+            if cmd[0] == 'open':
+                count, host, port = cmd[1:]
+                open_connections(active_conns, int(count), host, int(port))
+            elif cmd[0] == 'close':
+                (count, ) = cmd[1:]
+                close_connections(active_conns, int(count))
+            else:
+                log('result=FAIL: Unknown command')
+        clientsock.close()
+
+
+if __name__ == '__main__':
+    main()

bin/tests/system/tcp/clean.sh

@@ -13,6 +13,8 @@ rm -f */named.memstats
 rm -f */named.run
 rm -f */named.conf
 rm -f */named.stats
+rm -f ans6/ans.run*
 rm -f dig.out*
+rm -f rndc.out*
 rm -f ns*/named.lock
 rm -f ns*/managed-keys.bind*

bin/tests/system/tcp/ns5/named.conf.in

@@ -0,0 +1,43 @@
+/*
+ * Copyright (C) Internet Systems Consortium, Inc. ("ISC")
+ *
+ * This Source Code Form is subject to the terms of the Mozilla Public
+ * License, v. 2.0. If a copy of the MPL was not distributed with this
+ * file, You can obtain one at http://mozilla.org/MPL/2.0/.
+ *
+ * See the COPYRIGHT file distributed with this work for additional
+ * information regarding copyright ownership.
+ */
+
+// NS5
+
+key rndc_key {
+	secret "1234abcd8765";
+	algorithm hmac-sha256;
+};
+
+controls {
+	inet 10.53.0.5 port @CONTROLPORT@ allow { any; } keys { rndc_key; };
+};
+
+
+options {
+	query-source address 10.53.0.5;
+	notify-source 10.53.0.5;
+	transfer-source 10.53.0.5;
+	port @PORT@;
+	directory ".";
+	pid-file "named.pid";
+	listen-on { 10.53.0.5; };
+	listen-on-v6 { none; };
+        tcp-listen-queue 32;
+	recursion yes;
+	notify yes;
+        tcp-clients 17;
+	dnssec-validation no;
+};
+
+zone "." {
+	type hint;
+	file "../../common/root.hint";
+};

bin/tests/system/tcp/prereq.sh

@@ -0,0 +1,19 @@
+#!/bin/sh
+#
+# Copyright (C) Internet Systems Consortium, Inc. ("ISC")
+#
+# This Source Code Form is subject to the terms of the Mozilla Public
+# License, v. 2.0. If a copy of the MPL was not distributed with this
+# file, You can obtain one at http://mozilla.org/MPL/2.0/.
+#
+# See the COPYRIGHT file distributed with this work for additional
+# information regarding copyright ownership.
+
+SYSTEMTESTTOP=..
+. $SYSTEMTESTTOP/conf.sh
+
+if ! test -n "$PYTHON"; then
+	echo_i "This test requires Python."
+	exit 1
+fi
+

bin/tests/system/tcp/setup.sh

@@ -18,3 +18,4 @@ copy_setports ns1/named.conf.in ns1/named.conf
 copy_setports ns2/named.conf.in ns2/named.conf
 copy_setports ns3/named.conf.in ns3/named.conf
 copy_setports ns4/named.conf.in ns4/named.conf
+copy_setports ns5/named.conf.in ns5/named.conf

bin/tests/system/tcp/tests.sh

@@ -14,6 +14,7 @@ SYSTEMTESTTOP=..
 
 DIGOPTS="-p ${PORT}"
 RNDCCMD="$RNDC -p ${CONTROLPORT} -c ../common/rndc.conf"
+SEND="$PERL $SYSTEMTESTTOP/send.pl 10.53.0.6 ${CONTROLPORT}"
 
 status=0
 
@@ -55,5 +56,94 @@ if [ "$ntcp21" -ge "$ntcp22" ];then ret=1; fi
 if [ $ret != 0 ]; then echo_i "failed"; fi
 status=`expr $status + $ret`
 
+# -------- TCP high-water tests ----------
+n=0
+
+refresh_tcp_stats() {
+	$RNDCCMD -s 10.53.0.5 status > rndc.out.$n || ret=1
+	TCP_CUR="$(sed -n "s/^tcp clients: \([0-9][0-9]*\).*/\1/p" rndc.out.$n)"
+	TCP_LIMIT="$(sed -n "s/^tcp clients: .*\/\([0-9][0-9]*\)/\1/p" rndc.out.$n)"
+	TCP_HIGH="$(sed -n "s/^TCP high-water: \([0-9][0-9]*\)/\1/p" rndc.out.$n)"
+}
+
+wait_for_log() {
+	msg=$1
+	file=$2
+	for i in 1 2 3 4 5 6 7 8 9 10; do
+		nextpart "$file" | grep "$msg" > /dev/null && return
+		sleep 1
+	done
+	echo_i "exceeded time limit waiting for '$msg' in $file"
+	ret=1
+}
+
+# Send a command to the tool script listening on 10.53.0.6.
+send_command() {
+	nextpart ans6/ans.run > /dev/null
+	echo "$*" | $SEND
+	wait_for_log "result=OK" ans6/ans.run
+}
+
+# Instructs ans6 to open $1 TCP connections to 10.53.0.5.
+open_connections() {
+	send_command "open" "${1}" 10.53.0.5 "${PORT}"
+}
+
+# Instructs ans6 to close $1 TCP connections to 10.53.0.5.
+close_connections() {
+	send_command "close" "${1}"
+}
+
+# Check TCP statistics after server startup before using them as a baseline for
+# subsequent checks.
+n=$((n + 1))
+echo_i "TCP high-water: check initial statistics ($n)"
+ret=0
+refresh_tcp_stats
+assert_int_equal "${TCP_CUR}" 1 "current TCP clients count"
+if [ $ret != 0 ]; then echo_i "failed"; fi
+status=`expr $status + $ret`
+
+# Ensure the TCP high-water statistic gets updated after some TCP connections
+# are established.
+n=$((n + 1))
+echo_i "TCP high-water: check value after some TCP connections are established ($n)"
+ret=0
+OLD_TCP_CUR="${TCP_CUR}"
+TCP_ADDED=9
+open_connections "${TCP_ADDED}"
+refresh_tcp_stats
+assert_int_equal "${TCP_CUR}" $((OLD_TCP_CUR + TCP_ADDED)) "current TCP clients count"
+assert_int_equal "${TCP_HIGH}" $((OLD_TCP_CUR + TCP_ADDED)) "TCP high-water value"
+if [ $ret != 0 ]; then echo_i "failed"; fi
+status=`expr $status + $ret`
+
+# Ensure the TCP high-water statistic remains unchanged after some TCP
+# connections are closed.
+n=$((n + 1))
+echo_i "TCP high-water: check value after some TCP connections are closed ($n)"
+ret=0
+OLD_TCP_CUR="${TCP_CUR}"
+OLD_TCP_HIGH="${TCP_HIGH}"
+TCP_REMOVED=5
+close_connections "${TCP_REMOVED}"
+refresh_tcp_stats
+assert_int_equal "${TCP_CUR}" $((OLD_TCP_CUR - TCP_REMOVED)) "current TCP clients count"
+assert_int_equal "${TCP_HIGH}" "${OLD_TCP_HIGH}" "TCP high-water value"
+if [ $ret != 0 ]; then echo_i "failed"; fi
+status=`expr $status + $ret`
+
+# Ensure the TCP high-water statistic never exceeds the configured TCP clients
+# limit.
+n=$((n + 1))
+echo_i "TCP high-water: ensure tcp-clients is an upper bound ($n)"
+ret=0
+open_connections $((TCP_LIMIT + 1))
+refresh_tcp_stats
+assert_int_equal "${TCP_CUR}" "${TCP_LIMIT}" "current TCP clients count"
+assert_int_equal "${TCP_HIGH}" "${TCP_LIMIT}" "TCP high-water value"
+if [ $ret != 0 ]; then echo_i "failed"; fi
+status=`expr $status + $ret`
+
 echo_i "exit status: $status"
 [ $status -eq 0 ] || exit 1

doc/arm/notes-new-features.xml

@@ -11,6 +11,13 @@
 
 <section xml:id="relnotes_features"><info><title>New Features</title></info>
   <itemizedlist>
+    <listitem>
+      <para>
+        Added a new statistics variable <command>tcp-highwater</command>
+        that reports the maximum number of simultaneous TCP clients BIND
+        has handled while running.
+      </para>
+    </listitem>
     <listitem>
       <para>
         Added a new command line option to <command>dig</command>:

lib/isc/include/isc/stats.h

@@ -132,6 +132,31 @@ isc_stats_set(isc_stats_t *stats, uint64_t val,
  *\li	'stats' is a valid isc_stats_t.
  */
 
+void isc_stats_update_if_greater(isc_stats_t *stats,
+				 isc_statscounter_t counter,
+				 isc_statscounter_t value);
+/*%<
+* Atomically assigns 'value' to 'counter' if value > counter.
+*
+* Requires:
+*\li	'stats' is a valid isc_stats_t.
+*
+*\li	counter is less than the maximum available ID for the stats specified
+*	on creation.
+*/
+
+isc_statscounter_t
+isc_stats_get_counter(isc_stats_t *stats, isc_statscounter_t counter);
+/*%<
+ * Returns value currently stored in counter.
+ *
+ * Requires:
+ *\li	'stats' is a valid isc_stats_t.
+ *
+ *\li	counter is less than the maximum available ID for the stats specified
+ *	on creation.
+ */
+
 ISC_LANG_ENDDECLS
 
 #endif /* ISC_STATS_H */

lib/isc/include/isc/types.h

@@ -72,7 +72,11 @@ typedef struct isc_socket		isc_socket_t;		/*%< Socket */
 typedef struct isc_socketevent		isc_socketevent_t;	/*%< Socket Event */
 typedef struct isc_socketmgr		isc_socketmgr_t;	/*%< Socket Manager */
 typedef struct isc_stats		isc_stats_t;		/*%< Statistics */
-typedef int				isc_statscounter_t;	/*%< Statistics Counter */
+#if defined(_WIN32) && !defined(_WIN64)
+	typedef int_fast32_t 		isc_statscounter_t;	/*%< Statistics Counter */
+#else
+	typedef int_fast64_t 		isc_statscounter_t;
+#endif
 typedef struct isc_symtab		isc_symtab_t;		/*%< Symbol Table */
 typedef struct isc_task			isc_task_t;		/*%< Task */
 typedef ISC_LIST(isc_task_t)		isc_tasklist_t;		/*%< Task List */

lib/isc/stats.c

@@ -29,29 +29,31 @@
 #define ISC_STATS_VALID(x)		ISC_MAGIC_VALID(x, ISC_STATS_MAGIC)
 
 #if defined(_WIN32) && !defined(_WIN64)
-typedef atomic_int_fast32_t isc_stat_t;
+	typedef atomic_int_fast32_t isc__atomic_statcounter_t;
 #else
-typedef atomic_int_fast64_t isc_stat_t;
+	typedef atomic_int_fast64_t isc__atomic_statcounter_t;
 #endif
 
 struct isc_stats {
-	unsigned int		magic;
-	isc_mem_t		*mctx;
-	isc_refcount_t		references;
-	int			ncounters;
-	isc_stat_t		*counters;
+	unsigned int			magic;
+	isc_mem_t			*mctx;
+	isc_refcount_t			references;
+	int				ncounters;
+	isc__atomic_statcounter_t	*counters;
 };
 
 static isc_result_t
 create_stats(isc_mem_t *mctx, int ncounters, isc_stats_t **statsp) {
 	isc_stats_t *stats;
+	size_t counters_alloc_size;
 
 	REQUIRE(statsp != NULL && *statsp == NULL);
 
 	stats = isc_mem_get(mctx, sizeof(*stats));
-	stats->counters = isc_mem_get(mctx, sizeof(isc_stat_t) * ncounters);
+	counters_alloc_size = sizeof(isc__atomic_statcounter_t) * ncounters;
+	stats->counters = isc_mem_get(mctx, counters_alloc_size);
 	isc_refcount_init(&stats->references, 1);
-	memset(stats->counters, 0, sizeof(isc_stat_t) * ncounters);
+	memset(stats->counters, 0, counters_alloc_size);
 	stats->mctx = NULL;
 	isc_mem_attach(mctx, &stats->mctx);
 	stats->ncounters = ncounters;
@@ -81,7 +83,8 @@ isc_stats_detach(isc_stats_t **statsp) {
 
 	if (isc_refcount_decrement(&stats->references) == 1) {
 		isc_mem_put(stats->mctx, stats->counters,
-			    sizeof(isc_stat_t) * stats->ncounters);
+			    sizeof(isc__atomic_statcounter_t) *
+				stats->ncounters);
 		isc_mem_putanddetach(&stats->mctx, stats, sizeof(*stats));
 	}
 }
@@ -146,3 +149,34 @@ isc_stats_set(isc_stats_t *stats, uint64_t val,
 	atomic_store_explicit(&stats->counters[counter], val,
 			      memory_order_relaxed);
 }
+
+void isc_stats_update_if_greater(isc_stats_t *stats,
+				 isc_statscounter_t counter,
+				 isc_statscounter_t value)
+{
+	REQUIRE(ISC_STATS_VALID(stats));
+	REQUIRE(counter < stats->ncounters);
+
+	isc_statscounter_t curr_value;
+
+	do {
+		curr_value = atomic_load_explicit(&stats->counters[counter],
+						  memory_order_relaxed);
+		if (curr_value >= value) {
+			break;
+		}
+
+	} while (!atomic_compare_exchange_strong(&stats->counters[counter],
+						 &curr_value,
+						 value));
+}
+
+isc_statscounter_t
+isc_stats_get_counter(isc_stats_t *stats, isc_statscounter_t counter)
+{
+	REQUIRE(ISC_STATS_VALID(stats));
+	REQUIRE(counter < stats->ncounters);
+
+	return (atomic_load_explicit(&stats->counters[counter],
+				    memory_order_relaxed));
+}

lib/isc/win32/libisc.def.in

@@ -532,9 +532,11 @@ isc_stats_create
 isc_stats_decrement
 isc_stats_detach
 isc_stats_dump
+isc_stats_get_counter
 isc_stats_increment
 isc_stats_ncounters
 isc_stats_set
+isc_stats_update_if_greater
 isc_stdio_close
 isc_stdio_flush
 isc_stdio_open

lib/ns/client.c

@@ -3400,7 +3400,6 @@ client_accept(ns_client_t *client) {
 	isc_result_t result;
 
 	CTRACE("accept");
-
 	/*
 	 * Set up a new TCP connection. This means try to attach to the
 	 * TCP client quota (tcp-clients), but fail if we're over quota.
@@ -3451,6 +3450,12 @@ client_accept(ns_client_t *client) {
 		RUNTIME_CHECK(result == ISC_R_SUCCESS);
 	}
 
+	/* TCP high-water stats update. */
+	unsigned int curr_tcpquota = isc_quota_getused(&client->sctx->tcpquota);
+	ns_stats_update_if_greater(client->sctx->nsstats,
+				   ns_statscounter_tcphighwater,
+				   curr_tcpquota);
+
 	/*
 	 * If this client was set up using get_client() or get_worker(),
 	 * then TCP is already marked active. However, if it was restarted

lib/ns/include/ns/stats.h

@@ -102,7 +102,9 @@ enum {
 	ns_statscounter_prefetch = 63,
 	ns_statscounter_keytagopt = 64,
 
-	ns_statscounter_max = 65
+	ns_statscounter_tcphighwater = 65,
+
+	ns_statscounter_max = 66,
 };
 
 void
@@ -123,4 +125,11 @@ ns_stats_decrement(ns_stats_t *stats, isc_statscounter_t counter);
 isc_stats_t *
 ns_stats_get(ns_stats_t *stats);
 
+void ns_stats_update_if_greater(ns_stats_t *stats,
+				isc_statscounter_t counter,
+				isc_statscounter_t value);
+
+isc_statscounter_t
+ns_stats_get_counter(ns_stats_t *stats, isc_statscounter_t counter);
+
 #endif /* NS_STATS_H */

lib/ns/stats.c

@@ -109,3 +109,20 @@ ns_stats_get(ns_stats_t *stats) {
 
 	return (stats->counters);
 }
+
+void ns_stats_update_if_greater(ns_stats_t *stats,
+			     isc_statscounter_t counter,
+			     isc_statscounter_t value)
+{
+	REQUIRE(NS_STATS_VALID(stats));
+
+	isc_stats_update_if_greater(stats->counters, counter, value);
+}
+
+isc_statscounter_t
+ns_stats_get_counter(ns_stats_t *stats, isc_statscounter_t counter)
+{
+	REQUIRE(NS_STATS_VALID(stats));
+
+	return (isc_stats_get_counter(stats->counters, counter));
+}

lib/ns/win32/libns.def

@@ -102,6 +102,8 @@ ns_stats_create
 ns_stats_decrement
 ns_stats_detach
 ns_stats_get
+ns_stats_get_counter
 ns_stats_increment
+ns_stats_update_if_greater
 ns_update_start
 ns_xfr_start

util/copyrights

@@ -1077,7 +1077,9 @@
 ./bin/tests/system/synthfromdnssec/setup.sh	SH	2017,2018,2019
 ./bin/tests/system/synthfromdnssec/tests.sh	SH	2017,2018,2019
 ./bin/tests/system/system-test-driver.sh	X	2019
+./bin/tests/system/tcp/ans6/ans.py		PYTHON	2019
 ./bin/tests/system/tcp/clean.sh			SH	2014,2016,2018,2019
+./bin/tests/system/tcp/prereq.sh		SH	2019
 ./bin/tests/system/tcp/setup.sh			SH	2018,2019
 ./bin/tests/system/tcp/tests.sh			SH	2014,2016,2018,2019
 ./bin/tests/system/testcrypto.sh		SH	2014,2016,2017,2018,2019