Attachment 3395 Details for Bug 3055 – Better MaxStartups logging v2

[patch] Better MaxStartups logging v2

bz3055.diff (text/plain), 5.04 KB, created by Damien Miller on 2020-05-15 15:48:35 AEST

(hide)

Description:

Filename:

MIME Type:

Creator: Damien Miller

Created: 2020-05-15 15:48:35 AEST

Size: 5.04 KB

patch

obsolete

>Index: misc.c
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/misc.c,v
>retrieving revision 1.147
>diff -u -p -r1.147 misc.c
>--- misc.c	25 Apr 2020 06:59:36 -0000	1.147
>+++ misc.c	15 May 2020 05:47:08 -0000
>@@ -517,6 +517,35 @@ convtime(const char *s)
> }
> 
> /*
>+ * format a time interval (in seconds) for human readability, e.g.
>+ * 600 => "10m", 87300 => "1d15m".
>+ * Returns NULL on error. Caller must free result.
>+ */
>+char *
>+fmt_interval(u_int seconds)
>+{
>+	char *ret = NULL;
>+
>+	if (seconds == 0)
>+		return strdup("0s");
>+
>+#define FMT_UNIT(unit, letter) \
>+	do { \
>+		if (seconds >= unit) { \
>+			xextendf(&ret, "", "%u%c", seconds / unit, letter); \
>+			seconds %= unit; \
>+		} \
>+	} while(0)
>+	FMT_UNIT(WEEKS, 'w');
>+	FMT_UNIT(DAYS, 'd');
>+	FMT_UNIT(HOURS, 'h');
>+	FMT_UNIT(MINUTES, 'm');
>+	FMT_UNIT(1, 's');
>+#undef FMT_UNIT
>+	return ret;
>+}
>+
>+/*
>  * Returns a standardized host+port identifier string.
>  * Caller must free returned string.
>  */
>Index: misc.h
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/misc.h,v
>retrieving revision 1.84
>diff -u -p -r1.84 misc.h
>--- misc.h	24 Jan 2020 23:54:40 -0000	1.84
>+++ misc.h	15 May 2020 05:47:09 -0000
>@@ -66,6 +66,7 @@ int	 parse_user_host_path(const char *, 
> int	 parse_user_host_port(const char *, char **, char **, int *);
> int	 parse_uri(const char *, const char *, char **, char **, int *, char **);
> long	 convtime(const char *);
>+char	*fmt_interval(u_int);
> char	*tilde_expand_filename(const char *, uid_t);
> char	*percent_expand(const char *, ...) __attribute__((__sentinel__));
> char	*tohex(const void *, size_t);
>Index: sshd.c
>===================================================================
>RCS file: /cvs/src/usr.bin/ssh/sshd.c,v
>retrieving revision 1.553
>diff -u -p -r1.553 sshd.c
>--- sshd.c	8 May 2020 05:13:14 -0000	1.553
>+++ sshd.c	15 May 2020 05:47:09 -0000
>@@ -788,7 +788,7 @@ notify_hostkeys(struct ssh *ssh)
>  * all connections are dropped for startups > max_startups
>  */
> static int
>-drop_connection(int startups)
>+should_drop_connection(int startups)
> {
> 	int p, r;
> 
>@@ -805,10 +805,68 @@ drop_connection(int startups)
> 	p += options.max_startups_rate;
> 	r = arc4random_uniform(100);
> 
>-	debug("drop_connection: p %d, r %d", p, r);
>+	debug("%s: p %d, r %d", __func__, p, r);
> 	return (r < p) ? 1 : 0;
> }
> 
>+/*
>+ * Check whether connection should be accepted by MaxStartups.
>+ * Returns 0 if the connection is accepted. If the connection is refused,
>+ * returns 1 and attempts to send notification to client.
>+ * Logs when the MaxStartups condition is entered or exited, and periodically
>+ * while in that state.
>+ */
>+static int
>+drop_connection(int sock, int startups)
>+{
>+	char *laddr, *raddr;
>+	const char msg[] = "Exceeded MaxStartups\r\n";
>+	static time_t last_drop, first_drop;
>+	static u_int ndropped;
>+	LogLevel drop_level = SYSLOG_LEVEL_VERBOSE;
>+	time_t now;
>+
>+	now = monotime();
>+	if (!should_drop_connection(startups)) {
>+		if (last_drop != 0 &&
>+		    startups < options.max_startups_begin - 1) {
>+			/* XXX maybe need better hysteresis here */
>+			logit("exited MaxStartups throttling after %s, "
>+			    "%u connections dropped",
>+			    fmt_interval((u_int)(now - first_drop)), ndropped);
>+			last_drop = 0;
>+		}
>+		return 0;
>+	}
>+
>+#define SSHD_MAXSTARTUPS_LOG_INTERVAL	(5 * 60)
>+	if (last_drop == 0) {
>+		error("beginning MaxStartups throttling");
>+		drop_level = SYSLOG_LEVEL_INFO;
>+		first_drop = now;
>+		ndropped = 0;
>+	} else if (last_drop + SSHD_MAXSTARTUPS_LOG_INTERVAL < now) {
>+		/* Periodic logs */
>+		error("in MaxStartups throttling for %s, "
>+		    "%u connections dropped",
>+		    fmt_interval((u_int)(now - first_drop)), ndropped + 1);
>+		drop_level = SYSLOG_LEVEL_INFO;
>+	}
>+	last_drop = now;
>+	ndropped++;
>+
>+	laddr = get_local_ipaddr(sock);
>+	raddr = get_peer_ipaddr(sock);
>+	do_log2(drop_level, "drop connection #%d from [%s]:%d on [%s]:%d "
>+	    "past MaxStartups", startups, raddr, get_peer_port(sock),
>+	    laddr, get_local_port(sock));
>+	free(laddr);
>+	free(raddr);
>+	/* best-effort notification to client */
>+	(void)write(sock, msg, sizeof(msg) - 1);
>+	return 1;
>+}
>+
> static void
> usage(void)
> {
>@@ -1152,27 +1210,9 @@ server_accept_loop(int *sock_in, int *so
> 					usleep(100 * 1000);
> 				continue;
> 			}
>-			if (unset_nonblock(*newsock) == -1) {
>-				close(*newsock);
>-				continue;
>-			}
>-			if (drop_connection(startups) == 1) {
>-				char *laddr = get_local_ipaddr(*newsock);
>-				char *raddr = get_peer_ipaddr(*newsock);
>-				char msg[] = "Exceeded MaxStartups\r\n";
>-
>-				verbose("drop connection #%d from [%s]:%d "
>-				    "on [%s]:%d past MaxStartups", startups,
>-				    raddr, get_peer_port(*newsock),
>-				    laddr, get_local_port(*newsock));
>-				free(laddr);
>-				free(raddr);
>-				/* best-effort notification to client */
>-				(void)write(*newsock, msg, strlen(msg));
>-				close(*newsock);
>-				continue;
>-			}
>-			if (pipe(startup_p) == -1) {
>+			if (unset_nonblock(*newsock) == -1 ||
>+			    drop_connection(*newsock, startups) ||
>+			    pipe(startup_p) == -1) {
> 				close(*newsock);
> 				continue;
> 			}

Actions: View | Diff

Attachments on bug 3055: 3394 | 3395