log: escape terminal control characters

flist.c

@@ -187,7 +187,8 @@ static void emit_filelist_progress(int count)
 		return;
 	if (output_needs_newline == 2) /* avoid a newline in the middle of this filelist-progress output */
 		output_needs_newline = 0;
-	rprintf(FCLIENT, " %d files...\r", count);
+	rprintf(FCLIENT, " %d files...", count);
+	rput_progress();
 	output_needs_newline = 2;
 }
 

generator.c

@@ -395,8 +395,10 @@ static void do_delete_pass(void)
 	}
 	delete_in_dir(NULL, NULL, dev_zero);
 
-	if (INFO_GTE(FLIST, 2) && !am_server)
-		rprintf(FINFO, "                    \r");
+	if (INFO_GTE(FLIST, 2) && !am_server) {
+		rprintf(FINFO, "                    ");
+		rput_progress();
+	}
 }
 
 static inline int mtime_differs(STRUCT_STAT *stp, struct file_struct *file)

log.c

@@ -120,7 +120,7 @@ static char const *rerr_name(int code)
 	return NULL;
 }
 
-static void filtered_fwrite(FILE *f, const char *in_buf, int in_len, int use_isprint, int escape_c1, char end_char);
+static void filtered_fwrite(FILE *f, const char *in_buf, int in_len, int use_isprint, char end_char);
 
 static void logit(int priority, const char *buf)
 {
@@ -133,7 +133,7 @@ static void logit(int priority, const char *buf)
 		int len = strlen(buf);
 		char trailing = len && (buf[len-1] == '\n' || buf[len-1] == '\r') ? buf[--len] : '\0';
 		fprintf(logfile_fp, "%s [%d] ", timestring(time(NULL)), (int)getpid());
-		filtered_fwrite(logfile_fp, buf, len, 0, 1, trailing);
+		filtered_fwrite(logfile_fp, buf, len, 0, trailing);
 		fflush(logfile_fp);
 	} else {
 		syslog(priority, "%s", buf);
@@ -239,27 +239,107 @@ void logfile_reopen(void)
 	}
 }
 
-static void filtered_fwrite(FILE *f, const char *in_buf, int in_len, int use_isprint, int escape_c1, char end_char)
+/* Decode one RFC 3629 UTF-8 character.  Invalid, overlong, surrogate and
+ * out-of-range sequences return 0 so their bytes are filtered individually. */
+static size_t strict_utf8_char_len(const char *buf, size_t len, uint32 *codepoint)
 {
-	char outbuf[1024], *ob = outbuf;
+	const uchar *s = (const uchar *)buf;
+
+	if (!len)
+		return 0;
+	if (s[0] < 0x80) {
+		*codepoint = s[0];
+		return 1;
+	}
+	if (s[0] >= 0xc2 && s[0] <= 0xdf && len >= 2
+	 && s[1] >= 0x80 && s[1] <= 0xbf) {
+		*codepoint = (uint32)(s[0] & 0x1f) << 6 | (s[1] & 0x3f);
+		return 2;
+	}
+	if (s[0] >= 0xe0 && s[0] <= 0xef && len >= 3
+	 && s[1] >= (s[0] == 0xe0 ? 0xa0 : 0x80)
+	 && s[1] <= (s[0] == 0xed ? 0x9f : 0xbf)
+	 && s[2] >= 0x80 && s[2] <= 0xbf) {
+		*codepoint = (uint32)(s[0] & 0x0f) << 12
+			   | (uint32)(s[1] & 0x3f) << 6 | (s[2] & 0x3f);
+		return 3;
+	}
+	if (s[0] >= 0xf0 && s[0] <= 0xf4 && len >= 4
+	 && s[1] >= (s[0] == 0xf0 ? 0x90 : 0x80)
+	 && s[1] <= (s[0] == 0xf4 ? 0x8f : 0xbf)
+	 && s[2] >= 0x80 && s[2] <= 0xbf
+	 && s[3] >= 0x80 && s[3] <= 0xbf) {
+		*codepoint = (uint32)(s[0] & 0x07) << 18
+			   | (uint32)(s[1] & 0x3f) << 12
+			   | (uint32)(s[2] & 0x3f) << 6 | (s[3] & 0x3f);
+		return 4;
+	}
+	return 0;
+}
+
+static size_t filtered_char_len(const char *buf, size_t len, int use_isprint,
+				int *escape)
+{
+	uchar byte = *(const uchar *)buf;
+	uint32 codepoint;
+	size_t char_len = !use_isprint && byte >= 0x80
+		? strict_utf8_char_len(buf, len, &codepoint) : 0;
+
+	if (char_len) {
+		*escape = codepoint >= 0x80 && codepoint <= 0x9f;
+		return char_len;
+	}
+	*escape = (len > 4 && *buf == '\\' && buf[1] == '#'
+		   && isDigit(buf + 2) && isDigit(buf + 3) && isDigit(buf + 4))
+	       || (*buf != '\t' && ((use_isprint && !isPrint(buf)) || byte < ' '
+		   || byte == 0x7f || (byte >= 0x80 && byte <= 0x9f)));
+	return 1;
+}
+
+static void filtered_fwrite(FILE *f, const char *in_buf, int in_len, int use_isprint, char end_char)
+{
+	char outbuf[1024];
+	size_t out_len = 0;
 	const char *end = in_buf + in_len;
+
 	while (in_buf < end) {
-		if (ob - outbuf >= (int)sizeof outbuf - 10) {
-			if (fwrite(outbuf, ob - outbuf, 1, f) != 1)
+		int escape;
+		size_t i, char_len = filtered_char_len(
+			in_buf, (size_t)(end - in_buf), use_isprint, &escape);
+		size_t out_size = escape ? char_len * 5 : char_len;
+
+		if (sizeof outbuf - out_len < out_size) {
+			if (out_len > sizeof outbuf)
+				exit_cleanup(RERR_MESSAGEIO);
+			if (out_len && fwrite(outbuf, 1, out_len, f) != out_len)
 				exit_cleanup(RERR_MESSAGEIO);
-			ob = outbuf;
+			out_len = 0;
 		}
-		if ((in_buf < end - 4 && *in_buf == '\\' && in_buf[1] == '#'
-		  && isDigit(in_buf + 2) && isDigit(in_buf + 3) && isDigit(in_buf + 4))
-		 || (*in_buf != '\t' && ((use_isprint && !isPrint(in_buf)) || *(uchar*)in_buf < ' '
-		  || (escape_c1 && *(uchar*)in_buf >= 0x80 && *(uchar*)in_buf <= 0x9f))))
-			ob += snprintf(ob, 6, "\\#%03o", *(uchar*)in_buf++);
-		else
-			*ob++ = *in_buf++;
+		if (escape) {
+			for (i = 0; i < char_len; i++) {
+				uchar byte = (uchar)in_buf[i];
+				outbuf[out_len++] = '\\';
+				outbuf[out_len++] = '#';
+				outbuf[out_len++] = (char)('0' + ((byte >> 6) & 7));
+				outbuf[out_len++] = (char)('0' + ((byte >> 3) & 7));
+				outbuf[out_len++] = (char)('0' + (byte & 7));
+			}
+		} else {
+			memcpy(outbuf + out_len, in_buf, char_len);
+			out_len += char_len;
+		}
+		in_buf += char_len;
 	}
-	if (end_char) /* The "- 10" above means that there is always room for one more char here. */
-		*ob++ = end_char;
-	if (ob != outbuf && fwrite(outbuf, ob - outbuf, 1, f) != 1)
+	if (end_char && out_len == sizeof outbuf) {
+		if (fwrite(outbuf, 1, out_len, f) != out_len)
+			exit_cleanup(RERR_MESSAGEIO);
+		out_len = 0;
+	}
+	if (end_char)
+		outbuf[out_len++] = end_char;
+	if (out_len > sizeof outbuf)
+		exit_cleanup(RERR_MESSAGEIO);
+	if (out_len && fwrite(outbuf, 1, out_len, f) != out_len)
 		exit_cleanup(RERR_MESSAGEIO);
 }
 
@@ -268,7 +348,7 @@ static void filtered_fwrite(FILE *f, const char *in_buf, int in_len, int use_isp
  * can happen with certain fatal conditions. */
 void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 {
-	char trailing_CR_or_NL;
+	char trailing_NL;
 	FILE *f = msgs2stderr == 1 ? stderr : stdout;
 #ifdef ICONV_OPTION
 	iconv_t ic = is_utf8 && ic_recv != (iconv_t)-1 ? ic_recv : ic_chck;
@@ -377,13 +457,7 @@ void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 		output_needs_newline = 0;
 	}
 
-	trailing_CR_or_NL = len && (buf[len-1] == '\n' || buf[len-1] == '\r') ? buf[--len] : '\0';
-
-	if (len && buf[0] == '\r') {
-		fputc('\r', f);
-		buf++;
-		len--;
-	}
+	trailing_NL = len && buf[len-1] == '\n' ? buf[--len] : '\0';
 
 #ifdef ICONV_CONST
 	if (ic != (iconv_t)-1) {
@@ -398,10 +472,10 @@ void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 			iconvbufs(ic, &inbuf, &outbuf, inbuf.pos ? 0 : ICB_INIT);
 			ierrno = errno;
 			if (outbuf.len) {
-				char trailing = inbuf.len ? '\0' : trailing_CR_or_NL;
-				filtered_fwrite(f, convbuf, outbuf.len, 0, 0, trailing);
+				char trailing = inbuf.len ? '\0' : trailing_NL;
+				filtered_fwrite(f, convbuf, outbuf.len, 0, trailing);
 				if (trailing) {
-					trailing_CR_or_NL = '\0';
+					trailing_NL = '\0';
 					fflush(f);
 				}
 				outbuf.len = 0;
@@ -415,19 +489,30 @@ void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
 			}
 		}
 
-		if (trailing_CR_or_NL) {
-			fputc(trailing_CR_or_NL, f);
+		if (trailing_NL) {
+			fputc(trailing_NL, f);
 			fflush(f);
 		}
 	} else
 #endif
 	{
-		filtered_fwrite(f, buf, len, !allow_8bit_chars, 0, trailing_CR_or_NL);
-		if (trailing_CR_or_NL)
+		filtered_fwrite(f, buf, len, !allow_8bit_chars, trailing_NL);
+		if (trailing_NL)
 			fflush(f);
 	}
 }
 
+/* Emit the carriage return owned by rsync's progress displays. */
+void rput_progress(void)
+{
+	FILE *f = msgs2stderr == 1 ? stderr : stdout;
+
+	if (quiet)
+		return;
+	if (fputc('\r', f) == EOF || fflush(f) == EOF)
+		exit_cleanup(RERR_MESSAGEIO);
+}
+
 /* This is the rsync debugging function. Call it with FINFO, FERROR_*,
  * FWARNING, FLOG, or FCLIENT. */
 void rprintf(enum logcode code, const char *format, ...)

progress.c

@@ -126,7 +126,8 @@ static void rprint_progress(OFF_T ofs, OFF_T size, struct timeval *now, int is_l
 
 	output_needs_newline = 0;
 	pct = ofs == size ? 100 : (int) (100.0 * ofs / size);
-	rprintf(FCLIENT, "\r%15s %3d%% %7.2f%s %s%s",
+	rput_progress();
+	rprintf(FCLIENT, "%15s %3d%% %7.2f%s %s%s",
 		human_num(ofs), pct, rate, units, rembuf, eol);
 	if (!is_last && !quiet) {
 		output_needs_newline = 1;

testsuite/output-control-chars_test.py

@@ -0,0 +1,60 @@
+#!/usr/bin/env python3
+import os
+import subprocess
+
+from rsyncfns import SCRATCHDIR, rmtree, rsync_argv, test_fail, test_skipped
+
+base = SCRATCHDIR / 'output-control-chars'
+src = base / 'src'
+dst = base / 'dst'
+rmtree(base)
+src.mkdir(parents=True)
+dst.mkdir()
+
+src_b = os.fsencode(src)
+names = {
+    'raw_csi': b'raw_\x9b_name',
+    'utf8_csi': b'utf8_\xc2\x9b_name',
+    'valid_utf8': b'valid_\xd8\x9b_name',
+    'leading_cr': b'\rleading_cr_name',
+    'delete': b'delete_\x7f_name',
+}
+created = {}
+for label, name in names.items():
+    try:
+        with open(src_b + b'/' + name, 'wb') as fh:
+            fh.write(b'x')
+        created[label] = name
+    except OSError:
+        pass
+
+if 'utf8_csi' not in created:
+    test_skipped("filesystem rejects a UTF-8-encoded C1 filename")
+
+proc = subprocess.run(
+    rsync_argv('-av', '--8-bit-output', str(src) + '/', str(dst) + '/'),
+    stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+if proc.returncode != 0:
+    test_fail(f"rsync failed with status {proc.returncode}: {proc.stderr!r}")
+
+output = proc.stdout + proc.stderr
+if b'\xc2\x9b' in output:
+    test_fail("UTF-8-encoded CSI reached terminal output")
+if b'\\#302\\#233' not in output:
+    test_fail("UTF-8-encoded CSI was not escaped byte-for-byte")
+if 'raw_csi' in created and names['raw_csi'] in output:
+    test_fail("raw CSI reached terminal output")
+if 'raw_csi' in created and b'\\#233' not in output:
+    test_fail("raw CSI was not escaped")
+if 'valid_utf8' in created and names['valid_utf8'] not in output:
+    test_fail("valid UTF-8 containing a C1-range continuation byte was changed")
+if 'leading_cr' in created and names['leading_cr'] in output:
+    test_fail("leading carriage return reached terminal output")
+if 'leading_cr' in created and b'\\#015leading_cr_name' not in output:
+    test_fail("leading carriage return was not escaped")
+if 'delete' in created and names['delete'] in output:
+    test_fail("DEL reached terminal output")
+if 'delete' in created and b'delete_\\#177_name' not in output:
+    test_fail("DEL was not escaped")
+
+print("output-control-chars: terminal controls escaped and valid UTF-8 preserved")

testsuite/output-options_test.py

@@ -98,6 +98,13 @@ def out(*args, want_rc=0, env=None, text=True):
 if '100%' not in p.stdout:
     test_fail(f"--progress did not show a percentage:\n{p.stdout}")
 
+# --quiet must suppress the progress carriage return as well as its text.
+rmtree(TODIR)
+p = out('-a', '-q', '--progress', f'{src}/', f'{TODIR}/')
+if p.stdout != '':
+    test_fail(f"--quiet --progress produced stdout: {p.stdout!r}")
+verify_dirs(src, TODIR, label='--quiet --progress still transferred')
+
 # --- -h / --human-readable formats byte counts with a unit suffix -----------
 # Without -h, --stats prints grouped digits ("50,000 bytes"); with -h it uses a
 # K/M/G suffix ("50.00K"). Use a file big enough that the two forms differ.