[Git][NTPsec/ntpsec][master] 6 commits: Cleanup of NTS server logging

Hal Murray (@hal.murray) gitlab at mg.gitlab.com
Mon Aug 28 20:23:50 UTC 2023



Hal Murray pushed to branch master at NTPsec / ntpsec


Commits:
823dc9c1 by Hal Murray at 2023-08-23T23:09:20-07:00
Cleanup of NTS server logging

bug fix on good/bad counters
add OK/Failed to log message
cleanup CPU measurements in preperation for a log file

- - - - -
4a7a7b25 by Hal Murray at 2023-08-23T23:09:20-07:00
Move NTS counters to a struct

Actually split into 2 structs since it didn't fit in one.
Add slots to keep track of wall time and usr/sys CPU time

- - - - -
be1221b6 by Hal Murray at 2023-08-23T23:09:20-07:00
Finish dropping T_Timingstats

It was still used by the parser even though
it wasn't defined by keyword-gen

- - - - -
5900c46d by Hal Murray at 2023-08-24T19:08:59-07:00
Drop a few more unused symbols

INTERFACE_F_PRIVACY
INT_PPP
INT_MCASTIF
INT_PRIVACY
MDF_BCLNT
MDF_UCLNT

- - - - -
065516bd by Hal Murray at 2023-08-25T22:12:16-07:00
First cut at nssstats and ntskestats

- - - - -
1b7ed834 by Hal Murray at 2023-08-28T00:16:22-07:00
Fix bug in NTS-ke server logging wall clock time

- - - - -


17 changed files:

- include/isc_interfaceiter.h
- include/ntp.h
- include/nts.h
- ntpclients/ntpq.py
- ntpd/keyword-gen.c
- ntpd/ntp_control.c
- ntpd/ntp_io.c
- ntpd/ntp_parser.y
- ntpd/ntp_peer.c
- ntpd/ntp_proto.c
- ntpd/ntp_util.c
- ntpd/nts.c
- ntpd/nts_client.c
- ntpd/nts_cookie.c
- ntpd/nts_extens.c
- ntpd/nts_server.c
- tests/ntpd/nts_extens.c


Changes:

=====================================
include/isc_interfaceiter.h
=====================================
@@ -67,7 +67,7 @@ typedef struct isc_interface {
 #define INTERFACE_F_LOOPBACK		0x00000004U
 #define INTERFACE_F_BROADCAST		0x00000008U
 #define INTERFACE_F_MULTICAST		0x00000010U
-#define INTERFACE_F_PRIVACY		0x00000020U	/* RFC 4941 */
+// #define INTERFACE_F_PRIVACY		0x00000020U	/* RFC 4941 */
 /*@}*/
 
 /***


=====================================
include/ntp.h
=====================================
@@ -165,15 +165,15 @@ typedef struct netendpt {
  * in Mode 6 ifstats reports.
  */
 #define INT_UP		0x001	/* Interface is up */
-#define	INT_PPP		0x002	/* Point-to-point interface */
+/* #define	INT_PPP		0x002	** Point-to-point interface */
 #define	INT_LOOPBACK	0x004U	/* the loopback interface */
 #define	INT_BROADCAST	0x008	/* can broadcast out this interface */
 /* #define INT_MULTICAST	0x010	** can multicast out this interface */
 #define	INT_BCASTOPEN	0x020U	/* broadcast receive socket is open */
 /* #define INT_MCASTOPEN	0x040	** multicasting enabled */
 #define INT_WILDCARD	0x080	/* wildcard interface - usually skipped */
-#define INT_MCASTIF	0x100	/* bound directly to MCAST address */
-#define INT_PRIVACY	0x200	/* RFC 4941 IPv6 privacy address */
+/* #define INT_MCASTIF	0x100	** bound directly to MCAST address */
+/* #define INT_PRIVACY	0x200	** RFC 4941 IPv6 privacy address */
 /* #define INT_BCASTXMIT	0x400   ** socket setup to allow broadcasts */
 
 /*
@@ -636,8 +636,8 @@ struct mon_data {
 /* #define MDF_BCAST	0x04	** broadcast server (not used) */
 #define	MDF_POOL	0x08	/* pool client solicitor */
 /* #define MDF_ACAST	0x10	** manycast client solicitor (not used) */
-#define	MDF_BCLNT	0x20	/* eph. broadcast/multicast client */
-#define MDF_UCLNT	0x40	/* preemptible manycast or pool client */
+/* #define MDF_BCLNT	0x20	** eph. broadcast/multicast client */
+/* #define MDF_UCLNT	0x40	** preemptible manycast or pool client */
 /*
  * In the context of struct peer in ntpd, one cast_flags bit
  * represent configured associations which never receive packets, and


=====================================
include/nts.h
=====================================
@@ -188,6 +188,7 @@ enum nts_errors_type {
 	nts_bad_request = 1
 };
 
+
 enum aead_ciphers {
 #define NO_AEAD 0xffff
 	AEAD_AES_128_GCM = 1,
@@ -237,24 +238,38 @@ extern struct ntsconfig_t ntsconfig;
 
 
 /* NTS-related statistics visible via ntpq -c nts */
-extern uint64_t nts_client_send;
-extern uint64_t nts_client_recv_good;
-extern uint64_t nts_client_recv_bad;
-extern uint64_t nts_server_send;
-extern uint64_t nts_server_recv_good;
-extern uint64_t nts_server_recv_bad;
-extern uint64_t nts_cookie_make;
-extern uint64_t nts_cookie_not_server;   /* we are not a NTS server */
-extern uint64_t nts_cookie_decode_total; /* total attempts, includes too old */
-extern uint64_t nts_cookie_decode_current;
-extern uint64_t nts_cookie_decode_old;
-extern uint64_t nts_cookie_decode_old2;
-extern uint64_t nts_cookie_decode_older;
-extern uint64_t nts_cookie_decode_too_old; /* or garbage */
-extern uint64_t nts_cookie_decode_error;
-extern uint64_t nts_ke_serves_good;
-extern uint64_t nts_ke_serves_bad;
-extern uint64_t nts_ke_probes_good;
-extern uint64_t nts_ke_probes_bad;
+struct nts_counters {
+  uint64_t client_send;
+  uint64_t client_recv_good;
+  uint64_t client_recv_bad;
+  uint64_t server_send;
+  uint64_t server_recv_good;
+  uint64_t server_recv_bad;
+  uint64_t cookie_make;
+  uint64_t cookie_not_server;   /* we are not a NTS server */
+  uint64_t cookie_decode_total; /* total attempts, includes too old */
+  uint64_t cookie_decode_current;
+  uint64_t cookie_decode_old;
+  uint64_t cookie_decode_old2;
+  uint64_t cookie_decode_older;
+  uint64_t cookie_decode_too_old; /* or garbage */
+  uint64_t cookie_decode_error;
+};
+struct ntske_counters {
+  uint64_t serves_good;
+  double   serves_good_wall;
+  double   serves_good_usr;
+  double   serves_good_sys;
+  uint64_t serves_nossl;
+  uint64_t serves_bad;
+  double   serves_bad_wall;
+  double   serves_bad_usr;
+  double   serves_bad_sys;
+  uint64_t probes_good;
+  uint64_t probes_bad;
+};
+extern struct nts_counters nts_cnt, old_nts_cnt;
+extern struct ntske_counters ntske_cnt, old_ntske_cnt;
+
 
 #endif /* GUARD_NTS_H */


=====================================
ntpclients/ntpq.py
=====================================
@@ -1665,12 +1665,22 @@ usage: authinfo
    ("nts_cookie_decode_older",   " NTS decode cookies older:  ", NTP_UINT),
    ("nts_cookie_decode_too_old", " NTS decode cookies too old:", NTP_UINT),
    ("nts_cookie_decode_error",   "NTS decode cookies error:   ", NTP_UINT),
+  )
+        ntskeinfo = (
    ("nts_ke_probes_good",        "NTS KE client probes good:  ", NTP_UINT),
    ("nts_ke_probes_bad",         "NTS KE client probes bad:   ", NTP_UINT),
    ("nts_ke_serves_good",        "NTS KE serves good:         ", NTP_UINT),
+   ("nts_ke_serves_good_wall",   "NTS KE serves good wall:    ", NTP_FLOAT),
+   ("nts_ke_serves_good_usr",    "NTS KE serves good CPU/usr: ", NTP_FLOAT),
+   ("nts_ke_serves_good_sys",    "NTS KE serves good CPU/sys: ", NTP_FLOAT),
+   ("nts_ke_serves_nossl",       "NTS KE serves no SSL:       ", NTP_UINT),
    ("nts_ke_serves_bad",         "NTS KE serves bad:          ", NTP_UINT),
+   ("nts_ke_serves_bad_wall",    "NTS KE serves bad wall:     ", NTP_FLOAT),
+   ("nts_ke_serves_bad_usr",     "NTS KE serves bad CPU/usr:  ", NTP_FLOAT),
+   ("nts_ke_serves_bad_sys",     "NTS KE serves bad CPU/sys:  ", NTP_FLOAT),
   )
         self.collect_display(associd=0, variables=ntsinfo, decodestatus=False)
+        self.collect_display(associd=0, variables=ntskeinfo, decodestatus=False)
 
     def help_ntsinfo(self):
         self.say("""\


=====================================
ntpd/keyword-gen.c
=====================================
@@ -99,6 +99,8 @@ struct key_tok ntp_keywords[] = {
 { "rawstats",		T_Rawstats,		FOLLBY_TOKEN },
 { "sysstats", 		T_Sysstats,		FOLLBY_TOKEN },
 { "usestats",		T_Usestats,		FOLLBY_TOKEN },
+{ "ntsstats",		T_Ntsstats,		FOLLBY_TOKEN },
+{ "ntskestats",		T_Ntskestats,		FOLLBY_TOKEN },
 /* filegen_option */
 { "file",		T_File,			FOLLBY_STRING },
 { "link",		T_Link,			FOLLBY_TOKEN },


=====================================
ntpd/ntp_control.c
=====================================
@@ -408,28 +408,35 @@ static const struct var sys_var[] = {
 
 #ifndef DISABLE_NTS
 /* ntsinfo: NTS statistics */
-  Var_u64("nts_client_send", RO, nts_client_send),
-  Var_u64("nts_client_recv_good", RO, nts_client_recv_good),
-  Var_u64("nts_client_recv_bad", RO, nts_client_recv_bad),
-  Var_u64("nts_server_send", RO, nts_server_send),
-  Var_u64("nts_server_recv_good", RO, nts_server_recv_good),
-  Var_u64("nts_server_recv_bad", RO, nts_server_recv_bad),
-  Var_u64("nts_cookie_make", RO, nts_cookie_make),
-  Var_u64("nts_cookie_not_server", RO, nts_cookie_not_server),
-  Var_u64("nts_cookie_decode_total", RO, nts_cookie_decode_total),
-  Var_u64("nts_cookie_decode_current", RO, nts_cookie_decode_current),
+  Var_u64("nts_client_send", RO, nts_cnt.client_send),
+  Var_u64("nts_client_recv_good", RO, nts_cnt.client_recv_good),
+  Var_u64("nts_client_recv_bad", RO, nts_cnt.client_recv_bad),
+  Var_u64("nts_server_send", RO, nts_cnt.server_send),
+  Var_u64("nts_server_recv_good", RO, nts_cnt.server_recv_good),
+  Var_u64("nts_server_recv_bad", RO, nts_cnt.server_recv_bad),
+  Var_u64("nts_cookie_make", RO, nts_cnt.cookie_make),
+  Var_u64("nts_cookie_not_server", RO, nts_cnt.cookie_not_server),
+  Var_u64("nts_cookie_decode_total", RO, nts_cnt.cookie_decode_total),
+  Var_u64("nts_cookie_decode_current", RO, nts_cnt.cookie_decode_current),
   /* Following line is a hack for old versions of ntpq
    * nts_cookie_decode is old name for nts_cookie_decode_current */
-  Var_u64("nts_cookie_decode", RO, nts_cookie_decode_current),
-  Var_u64("nts_cookie_decode_old", RO, nts_cookie_decode_old),
-  Var_u64("nts_cookie_decode_old2", RO, nts_cookie_decode_old2),
-  Var_u64("nts_cookie_decode_older", RO, nts_cookie_decode_older),
-  Var_u64("nts_cookie_decode_too_old", RO, nts_cookie_decode_too_old),
-  Var_u64("nts_cookie_decode_error", RO, nts_cookie_decode_error),
-  Var_u64("nts_ke_serves_good", RO, nts_ke_serves_good),
-  Var_u64("nts_ke_serves_bad", RO, nts_ke_serves_bad),
-  Var_u64("nts_ke_probes_good", RO, nts_ke_probes_good),
-  Var_u64("nts_ke_probes_bad", RO, nts_ke_probes_bad),
+  Var_u64("nts_cookie_decode", RO, nts_cnt.cookie_decode_current),
+  Var_u64("nts_cookie_decode_old", RO, nts_cnt.cookie_decode_old),
+  Var_u64("nts_cookie_decode_old2", RO, nts_cnt.cookie_decode_old2),
+  Var_u64("nts_cookie_decode_older", RO, nts_cnt.cookie_decode_older),
+  Var_u64("nts_cookie_decode_too_old", RO, nts_cnt.cookie_decode_too_old),
+  Var_u64("nts_cookie_decode_error", RO, nts_cnt.cookie_decode_error),
+  Var_u64("nts_ke_serves_good", RO, ntske_cnt.serves_good),
+  Var_dbl("nts_ke_serves_good_wall", RO, ntske_cnt.serves_good_wall),
+  Var_dbl("nts_ke_serves_good_usr", RO, ntske_cnt.serves_good_usr),
+  Var_dbl("nts_ke_serves_good_sys", RO, ntske_cnt.serves_good_sys),
+  Var_u64("nts_ke_serves_nossl", RO, ntske_cnt.serves_nossl),
+  Var_u64("nts_ke_serves_bad", RO, ntske_cnt.serves_bad),
+  Var_dbl("nts_ke_serves_bad_wall", RO, ntske_cnt.serves_bad_wall),
+  Var_dbl("nts_ke_serves_bad_usr", RO, ntske_cnt.serves_bad_usr),
+  Var_dbl("nts_ke_serves_bad_sys", RO, ntske_cnt.serves_bad_sys),
+  Var_u64("nts_ke_probes_good", RO, ntske_cnt.probes_good),
+  Var_u64("nts_ke_probes_bad", RO, ntske_cnt.probes_bad),
 #endif
 
   { .flags=EOV }                  // end marker for scans


=====================================
ntpd/ntp_io.c
=====================================
@@ -1190,10 +1190,6 @@ convert_isc_if(
 			? INT_UP : 0)
 		| ((INTERFACE_F_LOOPBACK & isc_if->flags)
 			? INT_LOOPBACK : 0)
-		| ((INTERFACE_F_POINTTOPOINT & isc_if->flags)
-			? INT_PPP : 0)
-		| ((INTERFACE_F_PRIVACY & isc_if->flags)
-			? INT_PRIVACY : 0)
 		;
 
 	/*


=====================================
ntpd/ntp_parser.y
=====================================
@@ -166,6 +166,8 @@
 %token	<Integer>	T_Ntpport
 %token	<Integer>	T_NtpSignDsocket
 %token	<Integer>	T_Nts
+%token	<Integer>	T_Ntsstats
+%token	<Integer>	T_Ntskestats
 %token	<Integer>	T_Orphan
 %token	<Integer>	T_Orphanwait
 %token	<Integer>	T_Panic
@@ -208,7 +210,6 @@
 %token	<Integer>	T_Time1
 %token	<Integer>	T_Time2
 %token	<Integer>	T_Timer
-%token	<Integer>	T_Timingstats
 %token	<Integer>	T_Tinker
 %token	<Integer>	T_Tlsciphers
 %token	<Integer>	T_Tlsciphersuites
@@ -655,8 +656,9 @@ stat
 	|	T_Rawstats
 	|	T_Sysstats
 	|	T_Protostats
-	|	T_Timingstats
 	|	T_Usestats
+	|	T_Ntsstats
+	|	T_Ntskestats
 	;
 
 filegen_option_list


=====================================
ntpd/ntp_peer.c
=====================================
@@ -571,9 +571,7 @@ newpeer(
 	if (dstadr != NULL) {
 		peer = findexistingpeer(srcadr, hostname, NULL, hmode);
 		while (peer != NULL) {
-			if (peer->dstadr == dstadr ||
-			    ((MDF_BCLNT & cast_flags) &&
-			     (MDF_BCLNT & peer->cast_flags)))
+			if (peer->dstadr == dstadr)
 				break;
 
 			if (dstadr == ANY_INTERFACE_CHOOSE(srcadr) &&


=====================================
ntpd/ntp_proto.c
=====================================
@@ -2490,7 +2490,7 @@ dns_take_pool(
 	pctl.mode = 0;
 	pctl.peerkey = 0;
 	peer = newpeer(rmtadr, NULL, lcladr,
-		       MODE_CLIENT, &pctl, MDF_UCAST | MDF_UCLNT, false);
+		       MODE_CLIENT, &pctl, MDF_UCAST, false);
 	peer_xmit(peer);
 	if (peer->cfg.flags & FLAG_IBURST)
 	  peer->retry = NTP_RETRY;
@@ -2611,7 +2611,9 @@ local_refid(
 {
 	endpt *	unicast_ep;
 
-	if (p->dstadr != NULL && !(INT_MCASTIF & p->dstadr->flags))
+// FIXME: Is this ever NULL?  MCAST leftover??
+// (actually, just check)
+	if (p->dstadr != NULL)
 		unicast_ep = p->dstadr;
 	else
 		unicast_ep = findinterface(&p->srcadr);


=====================================
ntpd/ntp_util.c
=====================================
@@ -13,6 +13,7 @@
 #include "ntp_auth.h"
 #include "ntpd.h"
 #include "timespecops.h"
+#include "nts.h"
 
 #include <stdio.h>
 #include <libgen.h>
@@ -63,6 +64,8 @@ static FILEGEN rawstats;
 static FILEGEN refstats;
 static FILEGEN sysstats;
 static FILEGEN usestats;
+static FILEGEN ntsstats;
+static FILEGEN ntskestats;
 
 /*
  * This controls whether stats are written to the fileset. Provided
@@ -80,6 +83,8 @@ static double prev_drift_comp;		/* last frequency update */
  */
 static	void	record_sys_stats(void);
 static	void	record_use_stats(void);
+static	void	record_nts_stats(void);
+static	void	record_ntske_stats(void);
 	void	ntpd_time_stepped(void);
 static  void	check_leap_expiration(bool, time_t);
 
@@ -113,6 +118,8 @@ uninit_util(void)
 	filegen_unregister("peerstats");
 	filegen_unregister("protostats");
 	filegen_unregister("usestats");
+	filegen_unregister("ntsstats");
+	filegen_unregister("ntpkestats");
 }
 #endif /* DEBUG */
 
@@ -131,6 +138,8 @@ init_util(void)
 	filegen_register(statsdir, "peerstats",	  &peerstats);
 	filegen_register(statsdir, "protostats",  &protostats);
 	filegen_register(statsdir, "usestats",	  &usestats);
+	filegen_register(statsdir, "ntsstats",	  &ntsstats);
+	filegen_register(statsdir, "ntskestats",  &ntskestats);
 
 	/*
 	 * register with libntp ntp_set_tod() to call us back
@@ -198,6 +207,8 @@ void
 write_stats(void) {
 	record_sys_stats();
 	record_use_stats();
+	record_nts_stats();
+	record_ntske_stats();
 	if (stats_drift_file != 0) {
 
 		/*
@@ -724,6 +735,76 @@ void record_use_stats(void)
 	}
 }
 
+#define nts_since(CNT) ((unsigned long long)(nts_cnt.CNT - old_nts_cnt.CNT))
+uptime_t nts_stattime;
+void record_nts_stats(void) {
+#ifndef DISABLE_NTS
+	struct timespec	now;
+
+	if (!stats_control)
+		return;
+
+	clock_gettime(CLOCK_REALTIME, &now);
+	filegen_setup(&ntsstats, now.tv_sec);
+	if (ntsstats.fp != NULL) {
+		fprintf(ntsstats.fp,
+		    "%s %u %llu %llu %llu %llu %llu %llu %llu %llu %llu %llu %llu %llu %llu %llu %llu\n",
+		    timespec_to_MJDtime(&now), current_time-nts_stattime,
+		    nts_since(client_send),
+		    nts_since(client_recv_good),
+		    nts_since(client_recv_bad),
+		    nts_since(server_send),
+		    nts_since(server_recv_good),
+		    nts_since(server_recv_bad),
+		    nts_since(cookie_make),
+		    nts_since(cookie_not_server),
+		    nts_since(cookie_decode_total),
+		    nts_since(cookie_decode_current),
+		    nts_since(cookie_decode_old),
+		    nts_since(cookie_decode_old2),
+		    nts_since(cookie_decode_older),
+		    nts_since(cookie_decode_too_old),
+		    nts_since(cookie_decode_error) );
+		fflush(ntsstats.fp);
+	}
+	old_nts_cnt = nts_cnt;
+	nts_stattime = current_time;
+#endif
+}
+
+#define ntske_since(CNT) ((unsigned long long)(ntske_cnt.CNT - old_ntske_cnt.CNT))
+#define ntske_since_f(CNT) (ntske_cnt.CNT - old_ntske_cnt.CNT)
+uptime_t ntske_stattime;
+void record_ntske_stats(void) {
+#ifndef DISABLE_NTS
+	struct timespec	now;
+
+	if (!stats_control)
+		return;
+
+	clock_gettime(CLOCK_REALTIME, &now);
+	filegen_setup(&ntskestats, now.tv_sec);
+	if (ntsstats.fp != NULL) {
+		fprintf(ntskestats.fp,
+		    "%s %u %llu %.3f %.3f %.3f %llu %llu %.3f %.3f %.3f %llu %llu\n",
+		    timespec_to_MJDtime(&now), current_time-ntske_stattime,
+		    ntske_since(serves_good),
+		    ntske_since_f(serves_good_wall),
+		    ntske_since_f(serves_good_usr),
+		    ntske_since_f(serves_good_sys),
+		    ntske_since(serves_nossl),
+		    ntske_since(serves_bad),
+		    ntske_since_f(serves_bad_wall),
+		    ntske_since_f(serves_bad_usr),
+		    ntske_since_f(serves_bad_sys),
+		    ntske_since(probes_good),
+		    ntske_since(probes_bad) );
+		fflush(ntskestats.fp);
+	}
+	old_ntske_cnt = ntske_cnt;
+	ntske_stattime = current_time;
+#endif
+}
 
 /*
  * record_proto_stats - write system statistics to file


=====================================
ntpd/nts.c
=====================================
@@ -29,6 +29,9 @@
 #include "nts.h"
 #include "nts2.h"
 
+struct nts_counters nts_cnt, old_nts_cnt;
+struct ntske_counters ntske_cnt, old_ntske_cnt;
+
 struct ntsconfig_t ntsconfig = {
 	.ntsenable = false,
 	.mintls = NULL,


=====================================
ntpd/nts_client.c
=====================================
@@ -98,7 +98,7 @@ bool nts_probe(struct peer * peer) {
 
 	server = open_TCP_socket(peer, hostname);
 	if (-1 == server) {
-		nts_ke_probes_bad++;
+		ntske_cnt.probes_bad++;
 		return false;
 	}
 
@@ -107,7 +107,7 @@ bool nts_probe(struct peer * peer) {
 		ntp_strerror_r(errno, errbuf, sizeof(errbuf));
 		msyslog(LOG_ERR, "NTSc: can't setsockopt: %s", errbuf);
 		close(server);
-		nts_ke_probes_bad++;
+		ntske_cnt.probes_bad++;
 		return false;
 	}
 
@@ -168,11 +168,11 @@ bool nts_probe(struct peer * peer) {
 		goto bail;
 
 	addrOK = true;
-	nts_ke_probes_good++;
+	ntske_cnt.probes_good++;
 
   bail:
 	if (!addrOK) {
-		nts_ke_probes_bad++;
+		ntske_cnt.probes_bad++;
 		peer->nts_state.count = -1;
 	}
 	SSL_shutdown(ssl);


=====================================
ntpd/nts_cookie.c
=====================================
@@ -101,17 +101,6 @@ int nts_nKeys = 0;
 pthread_mutex_t cookie_lock = PTHREAD_MUTEX_INITIALIZER;
 AES_SIV_CTX* cookie_ctx;
 
-/* Statistics for ntpq */
-uint64_t nts_cookie_make = 0;
-uint64_t nts_cookie_not_server = 0;
-uint64_t nts_cookie_decode_total = 0;
-uint64_t nts_cookie_decode_current = 0; /* less than one day old, current key*/
-uint64_t nts_cookie_decode_old = 0;	/* zero to one day old */
-uint64_t nts_cookie_decode_old2 = 0;	/* one to two days old */
-uint64_t nts_cookie_decode_older = 0;	/* more than 2 days old */
-uint64_t nts_cookie_decode_too_old = 0;
-uint64_t nts_cookie_decode_error = 0;
-
 void nts_lock_cookielock(void);
 void nts_unlock_cookielock(void);
 
@@ -309,7 +298,7 @@ int nts_make_cookie(uint8_t *cookie,
 	if (NULL == cookie_ctx)
 		return 0;		/* We aren't initialized yet. */
 
-	nts_cookie_make++;
+	nts_cnt.cookie_make++;
 
 	INSIST(keylen <= NTS_MAX_KEYLEN);
 
@@ -385,7 +374,7 @@ bool nts_unpack_cookie(uint8_t *cookie, int cookielen,
 		return false;	/* We aren't initialized yet. */
 
 	if (0 == nts_nKeys) {
-		nts_cookie_not_server++;
+		nts_cnt.cookie_not_server++;
 		return false;  /* We are not a NTS enabled server. */
 	}
 
@@ -401,19 +390,19 @@ bool nts_unpack_cookie(uint8_t *cookie, int cookielen,
 		break;
 	  }
 	}
-	nts_cookie_decode_total++;  /* total attempts, includes too old */
+	nts_cnt.cookie_decode_total++;  /* total attempts, includes too old */
 	if (nts_nKeys == i) {
-		nts_cookie_decode_too_old++;
+		nts_cnt.cookie_decode_too_old++;
 		return false;
         }
 	if (0 == i) {
-		nts_cookie_decode_current++;
+		nts_cnt.cookie_decode_current++;
 	} else if (1 == i) {
-		nts_cookie_decode_old++;
+		nts_cnt.cookie_decode_old++;
 	} else if (2 == i) {
-		nts_cookie_decode_old2++;
+		nts_cnt.cookie_decode_old2++;
 	} else {
-		nts_cookie_decode_older++;
+		nts_cnt.cookie_decode_older++;
 	}
 #if 0
 	if (1<i) {
@@ -444,7 +433,7 @@ bool nts_unpack_cookie(uint8_t *cookie, int cookielen,
 	nts_unlock_cookielock();
 
 	if (!ok) {
-		nts_cookie_decode_error++;
+		nts_cnt.cookie_decode_error++;
 		return false;
 	}
 


=====================================
ntpd/nts_extens.c
=====================================
@@ -32,14 +32,6 @@
 #define NTP_EX_HDR_LNG 4
 #define NTP_EX_U16_LNG 2
 
-/* Statistics for ntpq */
-uint64_t nts_client_send = 0;
-uint64_t nts_client_recv_good = 0;
-uint64_t nts_client_recv_bad = 0;
-uint64_t nts_server_send = 0;
-uint64_t nts_server_recv_good = 0;
-uint64_t nts_server_recv_bad = 0;
-
 enum NtpExtFieldType {
 	Unique_Identifier = 0x104,
 	NTS_Cookie = 0x204,
@@ -121,7 +113,7 @@ int extens_client_send(struct peer *peer, struct pkt *xpkt) {
 	buf.left -= left;
 
 	used = buf.next-xpkt->exten;
-	nts_client_send++;
+	nts_cnt.client_send++;
 	return used;
 }
 
@@ -132,7 +124,7 @@ bool extens_server_recv(struct ntspacket_t *ntspacket, uint8_t *pkt, int lng) {
 	bool sawcookie, sawAEEF;
 	int cookielen;			/* cookie and placeholder(s) */
 
-	nts_server_recv_bad++;		/* assume bad, undo if OK */
+	nts_cnt.server_recv_bad++;		/* assume bad, undo if OK */
 
 	buf.next = pkt+LEN_PKT_NOMAC;
 	buf.left = lng-LEN_PKT_NOMAC;
@@ -265,8 +257,8 @@ bool extens_server_recv(struct ntspacket_t *ntspacket, uint8_t *pkt, int lng) {
 	//  printf("ESRx: %d, %d, %d\n",
 	//      lng-LEN_PKT_NOMAC, ntspacket->needed, ntspacket->keylen);
 	ntspacket->valid = true;
-	nts_server_recv_good++;
-	nts_server_recv_bad--;
+	nts_cnt.server_recv_good++;
+	nts_cnt.server_recv_bad--;
 	return true;
 }
 
@@ -350,7 +342,7 @@ int extens_server_send(struct ntspacket_t *ntspacket, struct pkt *xpkt) {
 
 	// printf("ESSx: %lu, %d\n", (long unsigned)left, used);
 
-	nts_server_send++;
+	nts_cnt.server_send++;
 	return used;
 }
 
@@ -359,7 +351,7 @@ bool extens_client_recv(struct peer *peer, uint8_t *pkt, int lng) {
 	int idx;
 	bool sawAEEF = false;
 
-	nts_client_recv_bad++;		/* assume bad, undo if OK */
+	nts_cnt.client_recv_bad++;	/* assume bad, undo if OK */
 
 	buf.next = pkt+LEN_PKT_NOMAC;
 	buf.left = lng-LEN_PKT_NOMAC;
@@ -447,8 +439,8 @@ bool extens_client_recv(struct peer *peer, uint8_t *pkt, int lng) {
 	}
 	if (buf.left > 0)
 		return false;
-	nts_client_recv_good++;
-	nts_client_recv_bad--;
+	nts_cnt.client_recv_good++;
+	nts_cnt.client_recv_bad--;
 	return true;
 }
 /* end */


=====================================
ntpd/nts_server.c
=====================================
@@ -50,12 +50,6 @@ static int listener6_sock = -1;
  * This seems like overkill, but it doesn't happen often. */
 pthread_mutex_t certificate_lock = PTHREAD_MUTEX_INITIALIZER;
 
-/* Statistics for ntpq */
-uint64_t nts_ke_serves_good = 0;
-uint64_t nts_ke_serves_bad = 0;
-uint64_t nts_ke_probes_good = 0;
-uint64_t nts_ke_probes_bad = 0;
-
 static int alpn_select_cb(SSL *ssl,
 			  const unsigned char **out,
 			  unsigned char *outlen,
@@ -198,9 +192,13 @@ void* nts_ke_listener(void* arg) {
 	char addrbuf[100];
 	char usingbuf[100];
 	struct timespec start, finish;		/* wall clock */
+	double wall;
+	bool worked;
+	const char *good;
 #ifdef RUSAGE_THREAD
 	struct timespec start_u, finish_u;	/* CPU user */
 	struct timespec start_s, finish_s;	/* CPU system */
+	double usr, sys;			/* seconds */
 	struct rusage usage;
 #endif
 
@@ -259,7 +257,7 @@ void* nts_ke_listener(void* arg) {
 			ntp_strerror_r(errno, errbuf, sizeof(errbuf));
 			msyslog(LOG_ERR, "NTSs: can't setsockopt: %s", errbuf);
 			close(client);
-			nts_ke_serves_bad++;
+			ntske_cnt.serves_bad++;
 			continue;
 		}
 
@@ -271,11 +269,12 @@ void* nts_ke_listener(void* arg) {
 
 		if (SSL_accept(ssl) <= 0) {
 			clock_gettime(CLOCK_REALTIME, &finish);
-			finish = sub_tspec(finish, start);
-			nts_ke_accept_fail(addrbuf, tspec_to_d(finish));
+			wall = tspec_to_d(sub_tspec(finish, start));
+			nts_ke_accept_fail(addrbuf, wall);
 			SSL_free(ssl);
 			close(client);
-			nts_ke_serves_bad++;
+			ntske_cnt.serves_nossl++;
+// FIXME: update start_u and start_s
 			continue;
 		}
 
@@ -285,32 +284,48 @@ void* nts_ke_listener(void* arg) {
 			SSL_get_cipher_name(ssl),
 			SSL_get_cipher_bits(ssl, NULL));
 
-		if (!nts_ke_request(ssl))
-			nts_ke_serves_bad++;
+		if (nts_ke_request(ssl)) {
+			worked = true;
+			good = "OK";
+		} else {
+			worked = false;
+			good = "Failed";
+		}
 
 		SSL_shutdown(ssl);
 		SSL_free(ssl);
 		close(client);
 
 		clock_gettime(CLOCK_REALTIME, &finish);
-		finish = sub_tspec(finish, start);
+		wall = tspec_to_d(sub_tspec(finish, start));
+		if (worked) {
+			ntske_cnt.serves_good++;
+			ntske_cnt.serves_good_wall += wall;
+		} else {
+			ntske_cnt.serves_bad++;
+			ntske_cnt.serves_bad_wall += wall;
+		}
 #ifdef RUSAGE_THREAD
 		getrusage(RUSAGE_THREAD, &usage);
 		finish_u = tval_to_tspec(usage.ru_utime);
 		finish_s = tval_to_tspec(usage.ru_stime);
-		start_u = sub_tspec(finish_u, start_u);
-		start_s = sub_tspec(finish_s, start_s);
-#endif
-		nts_ke_serves_good++;
-#ifdef RUSAGE_THREAD
-		msyslog(LOG_INFO, "NTSs: NTS-KE from %s, Using %s, took %.3f sec, CPU: %.3f+%.3f ms",
-			addrbuf, usingbuf, tspec_to_d(finish),
-			tspec_to_d(start_u)*1000, tspec_to_d(start_s)*1000);
+		usr = tspec_to_d(sub_tspec(finish_u, start_u));
+		sys = tspec_to_d(sub_tspec(finish_s, start_s));
 		start_u = finish_u;
 		start_s = finish_s;
+		if (worked) {
+			ntske_cnt.serves_good_usr += usr;
+			ntske_cnt.serves_good_sys += sys;
+		} else {
+			ntske_cnt.serves_bad_usr += usr;
+			ntske_cnt.serves_bad_sys += sys;
+		}
+		msyslog(LOG_INFO, "NTSs: NTS-KE from %s, %s, Using %s, took %.3f sec, CPU: %.3f+%.3f ms",
+			addrbuf, good, usingbuf, wall,
+			usr*1000, sys*1000);
 #else
-		msyslog(LOG_INFO, "NTSs: NTS-KE from %s, Using %s, took %.3f sec",
-			addrbuf, usingbuf, tspec_to_d(finish));
+		msyslog(LOG_INFO, "NTSs: NTS-KE from %s, %s, Using %s, took %.3f sec",
+			addrbuf, good, usingbuf, wall);
 #endif
 	}
 	return NULL;


=====================================
tests/ntpd/nts_extens.c
=====================================
@@ -54,7 +54,7 @@ TEST(nts_extens, extens_client_send) {
 	used = extens_client_send(&peer, &xpkt);
 	TEST_ASSERT_EQUAL(1056, used);
 	TEST_ASSERT_EQUAL(1, peer.nts_state.readIdx);
-	TEST_ASSERT_EQUAL(1, nts_client_send);
+	TEST_ASSERT_EQUAL(1, nts_cnt.client_send);
 	TEST_ASSERT_EQUAL(3, peer.nts_state.count);
 }
 



View it on GitLab: https://gitlab.com/NTPsec/ntpsec/-/compare/d4eeb4b6aa28b295353d196c7cfe58e8e73baf86...1b7ed8346c661dbbf923b56f82218ae3e3047fef

-- 
View it on GitLab: https://gitlab.com/NTPsec/ntpsec/-/compare/d4eeb4b6aa28b295353d196c7cfe58e8e73baf86...1b7ed8346c661dbbf923b56f82218ae3e3047fef
You're receiving this email because of your account on gitlab.com.


-------------- next part --------------
An HTML attachment was scrubbed...
URL: <https://lists.ntpsec.org/pipermail/vc/attachments/20230828/1c5c89a8/attachment-0001.htm>


More information about the vc mailing list