log: escape terminal control characters (#1114)

* log: escape terminal control characters
* log: make filtered output bounds explicit
* rework: honour the active locale when filtering output
* testsuite: contain unsupported locale fixture errors

configure.ac

@@ -13,7 +13,7 @@ AC_CHECK_HEADERS(poll.h sys/fcntl.h sys/select.h fcntl.h sys/time.h sys/unistd.h
     sys/acl.h acl/libacl.h attr/xattr.h sys/xattr.h sys/extattr.h dl.h \
     popt.h popt/popt.h linux/falloc.h netinet/in_systm.h netgroup.h \
     zlib.h xxhash.h openssl/md4.h openssl/md5.h zstd.h lz4.h sys/file.h \
-    sys/resource.h bsd/string.h idn2.h)
+    sys/resource.h bsd/string.h idn2.h wchar.h)
 AC_CHECK_HEADERS([netinet/ip.h], [], [], [[#include <netinet/in.h>]])
 AC_HEADER_MAJOR_FIXED
 
@@ -978,7 +978,7 @@ AC_CHECK_FUNCS(waitpid wait4 getcwd chown chmod lchmod mknod mkfifo fdopendir \
     seteuid strerror putenv iconv_open locale_charset nl_langinfo getxattr \
     extattr_get_link sigaction sigprocmask setattrlist getgrouplist \
     initgroups utimensat futimens posix_fallocate attropen setvbuf nanosleep usleep \
-    setenv unsetenv)
+    setenv unsetenv mbrtowc)
 
 dnl dirfd() is a macro or static inline on several systems (the BSDs), so the
 dnl default AC_CHECK_FUNCS link probe -- which declares `char dirfd(void);` and

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

@@ -24,6 +24,13 @@
 #include "inums.h"
 #include "rounding.h"	/* EXTRA_ROUNDING, so log_delete() aligns its file_struct */
 
+#if defined HAVE_WCHAR_H && defined HAVE_MBRTOWC
+#include <wchar.h>
+typedef mbstate_t filter_mbstate;
+#else
+typedef int filter_mbstate;
+#endif
+
 extern int dry_run;
 extern int am_daemon;
 extern int am_server;
@@ -120,7 +127,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)
 {
@@ -131,9 +138,9 @@ static void logit(int priority, const char *buf)
 		 * filename can't inject terminal escapes into the log an admin later
 		 * cat's (CWE-117); keep the trailing newline raw via end_char. */
 		int len = strlen(buf);
-		char trailing = len && (buf[len-1] == '\n' || buf[len-1] == '\r') ? buf[--len] : '\0';
+		char trailing = len && buf[len-1] == '\n' ? 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 +246,100 @@ 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 character using the active locale. Invalid or incomplete input
+ * returns 0 so its bytes are filtered individually. */
+static size_t locale_char_len(const char *buf, size_t len, filter_mbstate *state,
+			      int *is_control)
 {
-	char outbuf[1024], *ob = outbuf;
-	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)
-				exit_cleanup(RERR_MESSAGEIO);
-			ob = outbuf;
-		}
-		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 defined HAVE_WCHAR_H && defined HAVE_MBRTOWC
+	wchar_t wc;
+	size_t char_len = mbrtowc(&wc, buf, len, state);
+
+	if (char_len == (size_t)-1 || char_len == (size_t)-2) {
+		memset(state, 0, sizeof *state);
+		return 0;
 	}
-	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 (char_len == 0)
+		char_len = 1;
+	*is_control = wc != L'\t'
+		&& (wc < L' ' || (wc >= 0x7f && wc <= 0x9f));
+	return char_len;
+#else
+	(void)buf;
+	(void)len;
+	(void)state;
+	(void)is_control;
+	return 0;
+#endif
+}
+
+static size_t filtered_char_len(const char *buf, size_t len, int use_isprint,
+				filter_mbstate *state, int *escape)
+{
+	uchar byte = *(const uchar *)buf;
+	int is_control = 0;
+	size_t char_len = !use_isprint && byte >= 0x80
+		? locale_char_len(buf, len, state, &is_control) : 0;
+
+	if (char_len) {
+		*escape = is_control;
+		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];
+	filter_mbstate state;
+	size_t out_len = 0;
+	const char *end = in_buf + in_len;
+	memset(&state, 0, sizeof state);
+
+	while (in_buf < end) {
+		int escape;
+		size_t i, char_len = filtered_char_len(
+			in_buf, (size_t)(end - in_buf), use_isprint, &state, &escape);
+		size_t expansion = escape ? 5 : 1;
+		size_t out_size;
+
+		if (out_len > sizeof outbuf || char_len > sizeof outbuf / expansion)
+			exit_cleanup(RERR_MESSAGEIO);
+		out_size = char_len * expansion;
+		if (sizeof outbuf - out_len < out_size) {
+			if (out_len && fwrite(outbuf, 1, out_len, f) != out_len)
+				exit_cleanup(RERR_MESSAGEIO);
+			out_len = 0;
+		}
+		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 && 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,125 @@
+#!/usr/bin/env python3
+import os
+import subprocess
+
+from rsyncfns import SCRATCHDIR, rmtree, rsync_argv, test_fail
+
+
+def available_locales():
+    proc = subprocess.run(['locale', '-a'], stdout=subprocess.PIPE,
+                          stderr=subprocess.DEVNULL)
+    if proc.returncode != 0:
+        return {}
+    return {name.lower(): name for name in proc.stdout.decode('ascii', 'ignore').splitlines()}
+
+
+LOCALES = available_locales()
+
+
+def find_locale(locale_names):
+    return next((LOCALES[candidate.lower()] for candidate in locale_names
+                 if candidate.lower() in LOCALES), None)
+
+
+def check_locale_case(label, locale_names, name, expected, rejected):
+    locale_name = find_locale(locale_names)
+    if locale_name is None:
+        return False
+
+    case = base / label
+    case_src = case / 'src'
+    case_dst = case / 'dst'
+    case_src.mkdir(parents=True)
+    case_dst.mkdir()
+    env = os.environ.copy()
+    env['LC_ALL'] = locale_name
+
+    try:
+        create = subprocess.run(
+            [b'touch', os.fsencode(case_src) + b'/' + name], env=env,
+            stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+        if create.returncode != 0:
+            return False
+        proc = subprocess.run(
+            rsync_argv('-av', '--8-bit-output', str(case_src) + '/',
+                       str(case_dst) + '/'),
+            stdout=subprocess.PIPE, stderr=subprocess.PIPE, env=env)
+        if proc.returncode != 0:
+            test_fail(f"rsync failed under {locale_name}: {proc.stderr!r}")
+        output = proc.stdout + proc.stderr
+        if expected not in output or rejected in output:
+            test_fail(f"incorrect filtering under {locale_name}: {output!r}")
+    finally:
+        cleanup = subprocess.run(
+            [b'rm', b'-rf', b'--', os.fsencode(case)], env=env,
+            stdout=subprocess.PIPE, stderr=subprocess.PIPE)
+        if cleanup.returncode != 0:
+            test_fail(f"cleanup failed under {locale_name}: {cleanup.stderr!r}")
+    return True
+
+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
+
+utf8_locale = find_locale(('C.UTF-8', 'C.utf8', 'en_US.UTF-8', 'en_US.utf8'))
+env = os.environ.copy()
+if utf8_locale is not None:
+    env['LC_ALL'] = utf8_locale
+proc = subprocess.run(
+    rsync_argv('-av', '--8-bit-output', str(src) + '/', str(dst) + '/'),
+    stdout=subprocess.PIPE, stderr=subprocess.PIPE, env=env)
+if proc.returncode != 0:
+    test_fail(f"rsync failed with status {proc.returncode}: {proc.stderr!r}")
+
+output = proc.stdout + proc.stderr
+if utf8_locale is not None and 'utf8_csi' in created:
+    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 (utf8_locale is not None and '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")
+
+locale_cases = 0
+locale_cases += check_locale_case(
+    'iso-8859-1', ('en_US.ISO-8859-1', 'no_NO.ISO-8859-1'),
+    b'iso_\xd8\x9b_name', b'iso_\xd8\\#233_name', b'iso_\xd8\x9b_name')
+locale_cases += check_locale_case(
+    'euc-jp', ('ja_JP.eucJP', 'ja_JP.ujis', 'japanese.euc'),
+    b'euc_\x8e\xb1_name', b'euc_\x8e\xb1_name', b'euc_\\#216\\#261_name')
+
+print("output-control-chars: terminal controls escaped and valid multibyte text "
+      f"preserved ({locale_cases} optional locale cases)")

testsuite/output-options_test.py

@@ -98,6 +98,13 @@ p = out('-a', '--progress', f'{src}/', f'{TODIR}/')
 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.