From: Wayne Davison <wayne@opencoder.net>
Date: Thu, 23 Jul 2020 17:36:49 +0000 (-0700)
Subject: Improve error output for local & remote-shell xfers
X-Git-Tag: v3.2.3pre1~43
X-Git-Url: http://git.samba.org/?p=rsync.git;a=commitdiff_plain;h=592059c8fd88fbb08f69554bf3176626c7ee7554

Improve error output for local & remote-shell xfers
---

diff --git a/NEWS.md b/NEWS.md
index 36d79af9..a0ec31e0 100644
--- a/NEWS.md
+++ b/NEWS.md
@@ -49,6 +49,14 @@
  - Output file+line info on out-of-memory & overflow errors while also avoiding
    the output of alternate build-dir path info that is not useful to the user.
 
+ - Improve the error handling for local and remote-shell transfers by sending
+   error messages directly to stderr, even on the remote side (instead of
+   having an error wind its way through the pipelined backlog).  This also
+   allows rsync to exit quickly when a receiver failure occurs, since rsync
+   doesn't need to try to keep the connection alive long enough for the fatal
+   error to go from the receiver to the generator to the sender.  To disable
+   this new default you can use the `--no-msgs2stderr` option.
+
  - Improved the testsuite on FreeBSD & Cygwin.
 
  - Added some compatibility code for HPE NonStop platforms.
diff --git a/io.c b/io.c
index 1785f832..fe4a8778 100644
--- a/io.c
+++ b/io.c
@@ -464,7 +464,7 @@ void reduce_iobuf_size(xbuf *out, size_t new_size)
 {
 	if (new_size < out->size) {
 		/* Avoid weird buffer interactions by only outputting this to stderr. */
-		if (msgs2stderr && DEBUG_GTE(IO, 4)) {
+		if (msgs2stderr == 1 && DEBUG_GTE(IO, 4)) {
 			const char *name = out == &iobuf.out ? "iobuf.out"
 					 : out == &iobuf.msg ? "iobuf.msg"
 					 : NULL;
@@ -482,7 +482,7 @@ void restore_iobuf_size(xbuf *out)
 	if (IOBUF_WAS_REDUCED(out->size)) {
 		size_t new_size = IOBUF_RESTORE_SIZE(out->size);
 		/* Avoid weird buffer interactions by only outputting this to stderr. */
-		if (msgs2stderr && DEBUG_GTE(IO, 4)) {
+		if (msgs2stderr == 1 && DEBUG_GTE(IO, 4)) {
 			const char *name = out == &iobuf.out ? "iobuf.out"
 					 : out == &iobuf.msg ? "iobuf.msg"
 					 : NULL;
@@ -566,7 +566,7 @@ static char *perform_io(size_t needed, int flags)
 			exit_cleanup(RERR_PROTOCOL);
 		}
 
-		if (msgs2stderr && DEBUG_GTE(IO, 3)) {
+		if (msgs2stderr == 1 && DEBUG_GTE(IO, 3)) {
 			rprintf(FINFO, "[%s] perform_io(%ld, %sinput)\n",
 				who_am_i(), (long)needed, flags & PIO_CONSUME_INPUT ? "consume&" : "");
 		}
@@ -580,7 +580,7 @@ static char *perform_io(size_t needed, int flags)
 			exit_cleanup(RERR_PROTOCOL);
 		}
 
-		if (msgs2stderr && DEBUG_GTE(IO, 3)) {
+		if (msgs2stderr == 1 && DEBUG_GTE(IO, 3)) {
 			rprintf(FINFO, "[%s] perform_io(%ld, outroom) needs to flush %ld\n",
 				who_am_i(), (long)needed,
 				iobuf.out.len + needed > iobuf.out.size
@@ -596,7 +596,7 @@ static char *perform_io(size_t needed, int flags)
 			exit_cleanup(RERR_PROTOCOL);
 		}
 
-		if (msgs2stderr && DEBUG_GTE(IO, 3)) {
+		if (msgs2stderr == 1 && DEBUG_GTE(IO, 3)) {
 			rprintf(FINFO, "[%s] perform_io(%ld, msgroom) needs to flush %ld\n",
 				who_am_i(), (long)needed,
 				iobuf.msg.len + needed > iobuf.msg.size
@@ -605,7 +605,7 @@ static char *perform_io(size_t needed, int flags)
 		break;
 
 	case 0:
-		if (msgs2stderr && DEBUG_GTE(IO, 3))
+		if (msgs2stderr == 1 && DEBUG_GTE(IO, 3))
 			rprintf(FINFO, "[%s] perform_io(%ld, %d)\n", who_am_i(), (long)needed, flags);
 		break;
 
@@ -663,7 +663,7 @@ static char *perform_io(size_t needed, int flags)
 					SIVAL(iobuf.out.buf + iobuf.raw_data_header_pos, 0,
 					      ((MPLEX_BASE + (int)MSG_DATA)<<24) + iobuf.out.len - 4);
 
-					if (msgs2stderr && DEBUG_GTE(IO, 1)) {
+					if (msgs2stderr == 1 && DEBUG_GTE(IO, 1)) {
 						rprintf(FINFO, "[%s] send_msg(%d, %ld)\n",
 							who_am_i(), (int)MSG_DATA, (long)iobuf.out.len - 4);
 					}
@@ -783,7 +783,7 @@ static char *perform_io(size_t needed, int flags)
 					exit_cleanup(RERR_SOCKETIO);
 				}
 			}
-			if (msgs2stderr && DEBUG_GTE(IO, 2))
+			if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 				rprintf(FINFO, "[%s] recv=%ld\n", who_am_i(), (long)n);
 
 			if (io_timeout || stop_at_utime) {
@@ -822,7 +822,7 @@ static char *perform_io(size_t needed, int flags)
 					exit_cleanup(RERR_SOCKETIO);
 				}
 			}
-			if (msgs2stderr && DEBUG_GTE(IO, 2)) {
+			if (msgs2stderr == 1 && DEBUG_GTE(IO, 2)) {
 				rprintf(FINFO, "[%s] %s sent=%ld\n",
 					who_am_i(), out == &iobuf.out ? "out" : "msg", (long)n);
 			}
@@ -935,7 +935,7 @@ int send_msg(enum msgcode code, const char *buf, size_t len, int convert)
 {
 	char *hdr;
 	size_t needed, pos;
-	BOOL want_debug = DEBUG_GTE(IO, 1) && convert >= 0 && (msgs2stderr || code != MSG_INFO);
+	BOOL want_debug = DEBUG_GTE(IO, 1) && convert >= 0 && (msgs2stderr == 1 || code != MSG_INFO);
 
 	if (!OUT_MULTIPLEXED)
 		return 0;
@@ -1290,7 +1290,7 @@ void read_args(int f_in, char *mod_name, char *buf, size_t bufsiz, int rl_nulls,
 
 BOOL io_start_buffering_out(int f_out)
 {
-	if (msgs2stderr && DEBUG_GTE(IO, 2))
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 		rprintf(FINFO, "[%s] io_start_buffering_out(%d)\n", who_am_i(), f_out);
 
 	if (iobuf.out.buf) {
@@ -1309,7 +1309,7 @@ BOOL io_start_buffering_out(int f_out)
 
 BOOL io_start_buffering_in(int f_in)
 {
-	if (msgs2stderr && DEBUG_GTE(IO, 2))
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 		rprintf(FINFO, "[%s] io_start_buffering_in(%d)\n", who_am_i(), f_in);
 
 	if (iobuf.in.buf) {
@@ -1328,7 +1328,7 @@ BOOL io_start_buffering_in(int f_in)
 
 void io_end_buffering_in(BOOL free_buffers)
 {
-	if (msgs2stderr && DEBUG_GTE(IO, 2)) {
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2)) {
 		rprintf(FINFO, "[%s] io_end_buffering_in(IOBUF_%s_BUFS)\n",
 			who_am_i(), free_buffers ? "FREE" : "KEEP");
 	}
@@ -1343,7 +1343,7 @@ void io_end_buffering_in(BOOL free_buffers)
 
 void io_end_buffering_out(BOOL free_buffers)
 {
-	if (msgs2stderr && DEBUG_GTE(IO, 2)) {
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2)) {
 		rprintf(FINFO, "[%s] io_end_buffering_out(IOBUF_%s_BUFS)\n",
 			who_am_i(), free_buffers ? "FREE" : "KEEP");
 	}
@@ -1431,7 +1431,7 @@ static void read_a_msg(void)
 	msg_bytes = tag & 0xFFFFFF;
 	tag = (tag >> 24) - MPLEX_BASE;
 
-	if (DEBUG_GTE(IO, 1) && msgs2stderr)
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 1))
 		rprintf(FINFO, "[%s] got msg=%d, len=%ld\n", who_am_i(), (int)tag, (long)msg_bytes);
 
 	switch (tag) {
@@ -2303,7 +2303,7 @@ void io_start_multiplex_out(int fd)
 {
 	io_flush(FULL_FLUSH);
 
-	if (msgs2stderr && DEBUG_GTE(IO, 2))
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 		rprintf(FINFO, "[%s] io_start_multiplex_out(%d)\n", who_am_i(), fd);
 
 	if (!iobuf.msg.buf)
@@ -2320,7 +2320,7 @@ void io_start_multiplex_out(int fd)
 /* Setup for multiplexing a MSG_* stream with the data stream. */
 void io_start_multiplex_in(int fd)
 {
-	if (msgs2stderr && DEBUG_GTE(IO, 2))
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 		rprintf(FINFO, "[%s] io_start_multiplex_in(%d)\n", who_am_i(), fd);
 
 	iobuf.in_multiplexed = 1; /* See also IN_MULTIPLEXED */
@@ -2331,7 +2331,7 @@ int io_end_multiplex_in(int mode)
 {
 	int ret = iobuf.in_multiplexed ? iobuf.in_fd : -1;
 
-	if (msgs2stderr && DEBUG_GTE(IO, 2))
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 		rprintf(FINFO, "[%s] io_end_multiplex_in(mode=%d)\n", who_am_i(), mode);
 
 	iobuf.in_multiplexed = 0;
@@ -2349,7 +2349,7 @@ int io_end_multiplex_out(int mode)
 {
 	int ret = iobuf.out_empty_len ? iobuf.out_fd : -1;
 
-	if (msgs2stderr && DEBUG_GTE(IO, 2))
+	if (msgs2stderr == 1 && DEBUG_GTE(IO, 2))
 		rprintf(FINFO, "[%s] io_end_multiplex_out(mode=%d)\n", who_am_i(), mode);
 
 	if (mode != MPLX_TO_BUFFERED)
diff --git a/log.c b/log.c
index 0dc26331..e641198c 100644
--- a/log.c
+++ b/log.c
@@ -251,7 +251,7 @@ static void filtered_fwrite(FILE *f, const char *in_buf, int in_len, int use_isp
 void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 {
 	char trailing_CR_or_NL;
-	FILE *f = msgs2stderr ? stderr : stdout;
+	FILE *f = msgs2stderr == 1 ? stderr : stdout;
 #ifdef ICONV_OPTION
 	iconv_t ic = is_utf8 && ic_recv != (iconv_t)-1 ? ic_recv : ic_chck;
 #else
@@ -263,7 +263,7 @@ void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 	if (len < 0)
 		exit_cleanup(RERR_MESSAGEIO);
 
-	if (msgs2stderr) {
+	if (msgs2stderr == 1) {
 		/* A normal daemon can get msgs2stderr set if the socket is busted, so we
 		 * change the message destination into an FLOG message in order to try to
 		 * get some info about an abnormal-exit into the log file. An rsh daemon
@@ -327,7 +327,7 @@ void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 		exit_cleanup(RERR_MESSAGEIO);
 	}
 
-	if (am_server && !msgs2stderr) {
+	if (am_server && msgs2stderr != 1 && (msgs2stderr != 2 || f != stderr)) {
 		enum msgcode msg = (enum msgcode)code;
 		if (protocol_version < 30) {
 			if (msg == MSG_ERROR)
diff --git a/main.c b/main.c
index 61f62118..fcc0e65e 100644
--- a/main.c
+++ b/main.c
@@ -1086,7 +1086,7 @@ static void do_server_recv(int f_in, int f_out, int argc, char *argv[])
 	char *local_name = NULL;
 	int negated_levels;
 
-	if (filesfrom_fd >= 0 && !msgs2stderr && protocol_version < 31) {
+	if (filesfrom_fd >= 0 && msgs2stderr != 1 && protocol_version < 31) {
 		/* We can't mix messages with files-from data on the socket,
 		 * so temporarily turn off info/debug messages. */
 		negate_output_levels();
diff --git a/options.c b/options.c
index 59335269..ecd1a1f7 100644
--- a/options.c
+++ b/options.c
@@ -91,7 +91,7 @@ int relative_paths = -1;
 int implied_dirs = 1;
 int missing_args = 0; /* 0 = FERROR_XFER, 1 = ignore, 2 = delete */
 int numeric_ids = 0;
-int msgs2stderr = 0;
+int msgs2stderr = -1;
 int allow_8bit_chars = 0;
 int force_delete = 0;
 int io_timeout = 0;
@@ -803,7 +803,7 @@ static struct poptOption long_options[] = {
   {"no-v",             0,  POPT_ARG_VAL,    &verbose, 0, 0, 0 },
   {"info",             0,  POPT_ARG_STRING, 0, OPT_INFO, 0, 0 },
   {"debug",            0,  POPT_ARG_STRING, 0, OPT_DEBUG, 0, 0 },
-  {"msgs2stderr",      0,  POPT_ARG_NONE,   &msgs2stderr, 0, 0, 0 },
+  {"msgs2stderr",      0,  POPT_ARG_VAL,    &msgs2stderr, 1, 0, 0 },
   {"no-msgs2stderr",   0,  POPT_ARG_VAL,    &msgs2stderr, 0, 0, 0 },
   {"quiet",           'q', POPT_ARG_NONE,   0, 'q', 0, 0 },
   {"motd",             0,  POPT_ARG_VAL,    &output_motd, 1, 0, 0 },
@@ -2187,7 +2187,9 @@ int parse_arguments(int *argc_p, const char ***argv_p)
 		setvbuf(stdout, (char *)NULL, mode, 0);
 	}
 
-	if (msgs2stderr) {
+	if (msgs2stderr < 0)
+		msgs2stderr = am_daemon > 0 ? 0 : 2;
+	if (msgs2stderr == 1) {
 		/* Make stderr line buffered for better sharing of the stream. */
 		fflush(stderr); /* Just in case... */
 		setvbuf(stderr, (char *)NULL, _IOLBF, 0);
@@ -2887,6 +2889,11 @@ void server_options(char **args, int *argc_p)
 			args[ac++] = "--log-format=X";
 	}
 
+	if (msgs2stderr == 1)
+		args[ac++] = "--msgs2stderr";
+	else if (msgs2stderr == 0)
+		args[ac++] = "--no-msgs2stderr";
+
 	if (block_size) {
 		if (asprintf(&arg, "-B%u", (int)block_size) < 0)
 			goto oom;
diff --git a/rsync.1.md b/rsync.1.md
index 5e6e3788..4a2b5aeb 100644
--- a/rsync.1.md
+++ b/rsync.1.md
@@ -334,7 +334,7 @@ detailed description below for a complete description.
 --verbose, -v            increase verbosity
 --info=FLAGS             fine-grained informational verbosity
 --debug=FLAGS            fine-grained debug verbosity
---msgs2stderr            output messages directly to stderr
+--msgs2stderr            output all messages directly to stderr
 --quiet, -q              suppress non-error messages
 --no-motd                suppress daemon-mode MOTD
 --checksum, -c           skip based on checksum, not mod-time & size
@@ -595,18 +595,14 @@ your home directory (remove the '=' for that).
 
 0.  `--msgs2stderr`
 
-    This option changes rsync to send all its output directly to stderr rather
+    This option tells rsync to send all the messages directly to stderr rather
     than to send messages to the client side via the protocol.  The protocol
     allows rsync to output normal messages via stdout and errors via stderr,
     but it can delay messages behind a slew of data.
 
-    One case where this is helpful is when sending really large files, since
-    errors that happen on a remote receiver tend to get delayed until after the
-    file's data is fully sent.  It is also helpful for debugging, since it
-    helps to avoid overpopulating the protocol data with extra message data.
-
-    The option does not affect the remote side of a transfer without using
-    `--remote-option`, e.g. `-M--msgs2stderr` or `{-M,}--msgs2stderr`.
+    This option helps to avoid putting a lot of data into the pipe if you are
+    outputting debugging information via several `-v` options or the `--debug`
+    options.
 
     Also keep in mind that connecting to a normal (non-remote-shell) daemon
     does not have a stderr channel to send messages back to the client side, so
@@ -616,6 +612,14 @@ your home directory (remove the '=' for that).
     so that the merging of the output of 3 programs happens in a more readable
     manner.
 
+    Starting with rsync 3.2.3 rsync will send **errors** directly to stderr for
+    a non-daemon transfer, so you no longer need to specify this option just to
+    try to improve rsync's behavior when a remote receiver encounters an error.
+    You can override this new default by specifying `--no-msgs2stderr`.
+
+    Also starting with rsync 3.2.3 rsync will forward the `--msgs2stderr` or
+    `--no-msgs2stderr` option to the remote rsync.
+
 0.  `--quiet`, `-q`
 
     This option decreases the amount of information you are given during the