Skip to content

Commit

Permalink
Improve error output for local & remote-shell xfers
Browse files Browse the repository at this point in the history
  • Loading branch information
WayneD committed Jul 23, 2020
1 parent 37f4a23 commit 592059c
Show file tree
Hide file tree
Showing 6 changed files with 54 additions and 35 deletions.
8 changes: 8 additions & 0 deletions NEWS.md
Original file line number Diff line number Diff line change
Expand Up @@ -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.
Expand Down
38 changes: 19 additions & 19 deletions io.c
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -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;
Expand Down Expand Up @@ -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&" : "");
}
Expand All @@ -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
Expand All @@ -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
Expand All @@ -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;

Expand Down Expand Up @@ -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);
}
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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);
}
Expand Down Expand Up @@ -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;
Expand Down Expand Up @@ -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) {
Expand All @@ -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) {
Expand All @@ -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");
}
Expand All @@ -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");
}
Expand Down Expand Up @@ -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) {
Expand Down Expand Up @@ -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)
Expand All @@ -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 */
Expand All @@ -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;
Expand All @@ -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)
Expand Down
6 changes: 3 additions & 3 deletions log.c
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand Down Expand Up @@ -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)
Expand Down
2 changes: 1 addition & 1 deletion main.c
Original file line number Diff line number Diff line change
Expand Up @@ -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();
Expand Down
13 changes: 10 additions & 3 deletions options.c
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand Down Expand Up @@ -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 },
Expand Down Expand Up @@ -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);
Expand Down Expand Up @@ -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;
Expand Down
22 changes: 13 additions & 9 deletions rsync.1.md
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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
Expand Down

0 comments on commit 592059c

Please sign in to comment.