Make sure that whenever log_init() gets called, that a daemon rsync

[rsync/rsync-patches.git] / log-file.diff

This patch allows a non-daemon server and a client rsync to log what they
are doing, similar to how a daemon logs its actions.

--- old/cleanup.c
+++ new/cleanup.c
@@ -21,6 +21,7 @@
 
 #include "rsync.h"
 
+extern int am_server;
 extern int io_error;
 extern int keep_partial;
 extern int log_got_error;
@@ -149,7 +150,7 @@ void _exit_cleanup(int code, const char 
 			code = RERR_PARTIAL;
 	}
 
-	if (code)
+	if (code || am_server)
 		log_exit(code, file, line);
 
 	if (verbose > 2) {
--- old/clientserver.c
+++ new/clientserver.c
@@ -44,10 +44,14 @@ extern int protocol_version;
 extern int io_timeout;
 extern int no_detach;
 extern int default_af_hint;
+extern int logfile_format_has_i;
+extern int logfile_format_has_o_or_i;
 extern mode_t orig_umask;
 extern char *bind_address;
 extern char *sockopts;
 extern char *config_file;
+extern char *logfile_format;
+extern char *logfile_name;
 extern char *files_from;
 extern char *tmpdir;
 extern struct chmod_mode_struct *chmod_modes;
@@ -55,8 +59,6 @@ extern struct filter_list_struct server_
 
 char *auth_user;
 int read_only = 0;
-int daemon_log_format_has_i = 0;
-int daemon_log_format_has_o_or_i = 0;
 int module_id = -1;
 struct chmod_mode_struct *daemon_chmod_modes;
 
@@ -329,11 +331,12 @@ static int rsync_module(int f_in, int f_
 		read_only = 1;
 
 	if (lp_transfer_logging(i)) {
-		if (log_format_has(lp_log_format(i), 'i'))
-			daemon_log_format_has_i = 1;
-		if (daemon_log_format_has_i
-		    || log_format_has(lp_log_format(i), 'o'))
-			daemon_log_format_has_o_or_i = 1;
+		logfile_format = lp_log_format(i);
+		if (log_format_has(logfile_format, 'i'))
+			logfile_format_has_i = 1;
+		if (logfile_format_has_i
+		    || log_format_has(logfile_format, 'o'))
+			logfile_format_has_o_or_i = 1;
 	}
 
 	am_root = (MY_UID() == 0);
--- old/flist.c
+++ new/flist.c
@@ -95,15 +95,15 @@ static int show_filelist_p(void)
 
 static void start_filelist_progress(char *kind)
 {
-	rprintf(FINFO, "%s ... ", kind);
+	rprintf(FCLIENT, "%s ... ", kind);
 	if (verbose > 1 || do_progress)
-		rprintf(FINFO, "\n");
+		rprintf(FCLIENT, "\n");
 	rflush(FINFO);
 }
 
 static void emit_filelist_progress(int count)
 {
-	rprintf(FINFO, " %d files...\r", count);
+	rprintf(FCLIENT, " %d files...\r", count);
 }
 
 static void maybe_emit_filelist_progress(int count)
@@ -295,7 +295,7 @@ void flist_expand(struct file_list *flis
 				flist->malloced);
 
 	if (verbose >= 2 && flist->malloced != FLIST_START) {
-		rprintf(FINFO, "[%s] expand file_list to %.0f bytes, did%s move\n",
+		rprintf(FCLIENT, "[%s] expand file_list to %.0f bytes, did%s move\n",
 		    who_am_i(),
 		    (double)sizeof flist->files[0] * flist->malloced,
 		    (new_ptr == flist->files) ? " not" : "");
@@ -1077,6 +1077,7 @@ struct file_list *send_file_list(int f, 
 	int64 start_write;
 	int use_ff_fd = 0;
 
+	rprintf(FLOG, "building file list\n");
 	if (show_filelist_p())
 		start_filelist_progress("building file list");
 
@@ -1343,6 +1344,7 @@ struct file_list *recv_file_list(int f)
 	unsigned short flags;
 	int64 start_read;
 
+	rprintf(FLOG, "receiving file list\n");
 	if (show_filelist_p())
 		start_filelist_progress("receiving file list");
 
--- old/generator.c
+++ new/generator.c
@@ -27,7 +27,7 @@ extern int verbose;
 extern int dry_run;
 extern int do_xfers;
 extern int log_format_has_i;
-extern int daemon_log_format_has_i;
+extern int logfile_format_has_i;
 extern int am_root;
 extern int am_server;
 extern int am_daemon;
@@ -663,7 +663,7 @@ static int try_dests_reg(struct file_str
 		} else if (itemizing)
 			itemize(file, ndx, 0, stp, 0, 0, NULL);
 		if (verbose > 1 && maybe_ATTRS_REPORT) {
-			code = daemon_log_format_has_i || dry_run
+			code = logfile_format_has_i || dry_run
 			     ? FCLIENT : FINFO;
 			rprintf(code, "%s is uptodate\n", fname);
 		}
@@ -686,7 +686,7 @@ static int try_dests_reg(struct file_str
 		if (maybe_ATTRS_REPORT
 		 && ((!itemizing && verbose && match_level == 2)
 		  || (verbose > 1 && match_level == 3))) {
-			code = daemon_log_format_has_i || dry_run
+			code = logfile_format_has_i || dry_run
 			     ? FCLIENT : FINFO;
 			rprintf(code, "%s%s\n", fname,
 				match_level == 3 ? " is uptodate" : "");
@@ -742,7 +742,7 @@ static int try_dests_non(struct file_str
 			itemize(file, ndx, 0, &st, changes, 0, lp);
 		}
 		if (verbose > 1 && maybe_ATTRS_REPORT) {
-			code = daemon_log_format_has_i || dry_run
+			code = logfile_format_has_i || dry_run
 			     ? FCLIENT : FINFO;
 			rprintf(code, "%s is uptodate\n", fname);
 		}
@@ -1304,9 +1304,9 @@ void generate_files(int f_out, struct fi
 	if (protocol_version >= 29) {
 		itemizing = 1;
 		maybe_ATTRS_REPORT = log_format_has_i ? 0 : ATTRS_REPORT;
-		code = daemon_log_format_has_i ? 0 : FLOG;
+		code = logfile_format_has_i ? 0 : FLOG;
 	} else if (am_daemon) {
-		itemizing = daemon_log_format_has_i && do_xfers;
+		itemizing = logfile_format_has_i && do_xfers;
 		maybe_ATTRS_REPORT = ATTRS_REPORT;
 		code = itemizing || !do_xfers ? FCLIENT : FINFO;
 	} else if (!am_server) {
--- old/log.c
+++ new/log.c
@@ -44,18 +44,19 @@ extern int protocol_version;
 extern int preserve_times;
 extern int log_format_has_i;
 extern int log_format_has_o_or_i;
-extern int daemon_log_format_has_o_or_i;
+extern int logfile_format_has_o_or_i;
 extern mode_t orig_umask;
 extern char *auth_user;
 extern char *log_format;
+extern char *logfile_format;
+extern char *logfile_name;
 #if defined HAVE_ICONV_OPEN && defined HAVE_ICONV_H
 extern iconv_t ic_chck;
 #endif
 
 static int log_initialised;
 static int logfile_was_closed;
-static char *logfname;
-static FILE *logfile;
+static FILE *logfile_fp;
 struct stats stats;
 
 int log_got_error = 0;
@@ -109,10 +110,10 @@ static void logit(int priority, char *bu
 {
 	if (logfile_was_closed)
 		logfile_reopen();
-	if (logfile) {
-		fprintf(logfile,"%s [%d] %s",
+	if (logfile_fp) {
+		fprintf(logfile_fp, "%s [%d] %s",
 			timestring(time(NULL)), (int)getpid(), buf);
-		fflush(logfile);
+		fflush(logfile_fp);
 	} else {
 		syslog(priority, "%s", buf);
 	}
@@ -145,14 +146,14 @@ static void syslog_init()
 static void logfile_open(void)
 {
 	mode_t old_umask = umask(022 | orig_umask);
-	logfile = fopen(logfname, "a");
+	logfile_fp = fopen(logfile_name, "a");
 	umask(old_umask);
-	if (!logfile) {
+	if (!logfile_fp) {
 		int fopen_errno = errno;
 		/* Rsync falls back to using syslog on failure. */
 		syslog_init();
 		rsyserr(FERROR, fopen_errno,
-			"failed to open log-file %s", logfname);
+			"failed to open log-file %s", logfile_name);
 		rprintf(FINFO, "Ignoring \"log file\" setting.\n");
 	}
 }
@@ -171,9 +172,11 @@ void log_init(void)
 	t = time(NULL);
 	localtime(&t);
 
-	/* optionally use a log file instead of syslog */
-	logfname = lp_log_file();
-	if (logfname && *logfname)
+	/* Optionally use a log file instead of syslog.  (Non-daemon
+	 * rsyncs will have already set logfile_name, as needed.) */
+	if (am_daemon)
+		logfile_name = lp_log_file();
+	if (logfile_name && *logfile_name)
 		logfile_open();
 	else
 		syslog_init();
@@ -181,10 +184,10 @@ void log_init(void)
 
 void logfile_close(void)
 {
-	if (logfile) {
+	if (logfile_fp) {
 		logfile_was_closed = 1;
-		fclose(logfile);
-		logfile = NULL;
+		fclose(logfile_fp);
+		logfile_fp = NULL;
 	}
 }
 
@@ -243,9 +246,9 @@ void rwrite(enum logcode code, char *buf
 
 	if (code == FCLIENT)
 		code = FINFO;
-	else if (am_daemon) {
+	else if (am_daemon || logfile_name) {
 		static int in_block;
-		char msg[2048];
+		char msg[2048], *s;
 		int priority = code == FERROR ? LOG_WARNING : LOG_INFO;
 
 		if (in_block)
@@ -254,10 +257,11 @@ void rwrite(enum logcode code, char *buf
 		if (!log_initialised)
 			log_init();
 		strlcpy(msg, buf, MIN((int)sizeof msg, len + 1));
-		logit(priority, msg);
+		for (s = msg; *s == '\n' && s[1]; s++) {}
+		logit(priority, s);
 		in_block = 0;
 
-		if (code == FLOG || !am_server)
+		if (code == FLOG || (am_daemon && !am_server))
 			return;
 	} else if (code == FLOG)
 		return;
@@ -403,26 +407,14 @@ void rflush(enum logcode code)
 {
 	FILE *f = NULL;
 
-	if (am_daemon) {
+	if (am_daemon || code == FLOG)
 		return;
-	}
 
-	if (code == FLOG) {
-		return;
-	}
-
-	if (code == FERROR) {
+	if (code == FERROR || am_server)
 		f = stderr;
-	}
-
-	if (code == FINFO) {
-		if (am_server)
-			f = stderr;
-		else
-			f = stdout;
-	}
+	else
+		f = stdout;
 
-	if (!f) exit_cleanup(RERR_MESSAGEIO);
 	fflush(f);
 }
 
@@ -695,12 +687,12 @@ void log_item(struct file_struct *file, 
 {
 	char *s_or_r = am_sender ? "send" : "recv";
 
-	if (lp_transfer_logging(module_id)) {
-		log_formatted(FLOG, lp_log_format(module_id), s_or_r,
-			      file, initial_stats, iflags, hlink);
-	} else if (log_format && !am_server) {
+	if (log_format && !am_server) {
 		log_formatted(FNAME, log_format, s_or_r,
 			      file, initial_stats, iflags, hlink);
+	} else if (logfile_format) {
+		log_formatted(FLOG, logfile_format, s_or_r,
+			      file, initial_stats, iflags, hlink);
 	}
 }
 
@@ -712,7 +704,7 @@ void maybe_log_item(struct file_struct *
 		|| log_format_has_i > 1 || (verbose > 1 && log_format_has_i));
 	int local_change = iflags & ITEM_LOCAL_CHANGE && significant_flags;
 	if (am_server) {
-		if (am_daemon && !dry_run && see_item)
+		if (logfile_name && !dry_run && see_item)
 			log_item(file, &stats, iflags, buf);
 	} else if (see_item || local_change || *buf
 	    || (S_ISDIR(file->mode) && significant_flags))
@@ -740,10 +732,10 @@ void log_delete(char *fname, int mode)
 			      ITEM_DELETED, NULL);
 	}
 
-	if (!am_daemon || dry_run || !lp_transfer_logging(module_id))
+	if (!logfile_name || dry_run || !logfile_format)
 		return;
 
-	fmt = daemon_log_format_has_o_or_i ? lp_log_format(module_id) : "deleting %n";
+	fmt = logfile_format_has_o_or_i ? logfile_format : "deleting %n";
 	log_formatted(FLOG, fmt, "del.", &file, &stats, ITEM_DELETED, NULL);
 }
 
--- old/main.c
+++ new/main.c
@@ -168,7 +168,6 @@ static void handle_stats(int f)
 		return;
 
 	if (am_daemon) {
-		log_exit(0, __FILE__, __LINE__);
 		if (f == -1 || !am_sender)
 			return;
 	}
--- old/options.c
+++ new/options.c
@@ -146,6 +146,8 @@ char *basis_dir[MAX_BASIS_DIRS+1];
 char *config_file = NULL;
 char *shell_cmd = NULL;
 char *log_format = NULL;
+char *logfile_name = NULL;
+char *logfile_format = NULL;
 char *password_file = NULL;
 char *rsync_path = RSYNC_PATH;
 char *backup_dir = NULL;
@@ -162,7 +164,9 @@ int verbose = 0;
 int quiet = 0;
 int log_before_transfer = 0;
 int log_format_has_i = 0;
+int logfile_format_has_i = 0;
 int log_format_has_o_or_i = 0;
+int logfile_format_has_o_or_i = 0;
 int always_checksum = 0;
 int list_only = 0;
 
@@ -359,6 +363,7 @@ void usage(enum logcode F)
   rprintf(F,"     --progress              show progress during transfer\n");
   rprintf(F," -P                          same as --partial --progress\n");
   rprintf(F," -i, --itemize-changes       output a change-summary for all updates\n");
+  rprintf(F,"     --log-file=FILE         output what we're doing to a log file\n");
   rprintf(F,"     --log-format=FORMAT     output filenames using the specified format\n");
   rprintf(F,"     --password-file=FILE    read password from FILE\n");
   rprintf(F,"     --list-only             list the files instead of copying them\n");
@@ -492,6 +497,7 @@ static struct poptOption long_options[] 
   {"partial-dir",      0,  POPT_ARG_STRING, &partial_dir, 0, 0, 0 },
   {"delay-updates",    0,  POPT_ARG_NONE,   &delay_updates, 0, 0, 0 },
   {"prune-empty-dirs",'m', POPT_ARG_NONE,   &prune_empty_dirs, 0, 0, 0 },
+  {"log-file",         0,  POPT_ARG_STRING, &logfile_name, 0, 0, 0 },
   {"log-format",       0,  POPT_ARG_STRING, &log_format, 0, 0, 0 },
   {"itemize-changes", 'i', POPT_ARG_NONE,   0, 'i', 0, 0 },
   {"bwlimit",          0,  POPT_ARG_INT,    &bwlimit, 0, 0, 0 },
@@ -1311,6 +1317,21 @@ int parse_arguments(int *argc, const cha
 	if (log_format_has_i || log_format_has(log_format, 'o'))
 		log_format_has_o_or_i = 1;
 
+	if (am_daemon)
+		logfile_name = NULL;
+	else if (logfile_name) {
+		if (am_server) {
+			logfile_format = "%i %n%L";
+			logfile_format_has_i = logfile_format_has_o_or_i = 1;
+		} else if (log_format) {
+			logfile_format = log_format;
+			logfile_format_has_i = log_format_has_i;
+			logfile_format_has_o_or_i = log_format_has_o_or_i;
+		}
+		log_before_transfer = !am_server;
+		log_init();
+	}
+
 	if (daemon_bwlimit && (!bwlimit || bwlimit > daemon_bwlimit))
 		bwlimit = daemon_bwlimit;
 	if (bwlimit) {
--- old/progress.c
+++ new/progress.c
@@ -103,7 +103,7 @@ static void rprint_progress(OFF_T ofs, O
 			stats.num_files);
 	} else
 		strcpy(eol, "\r");
-	rprintf(FINFO, "%12s %3d%% %7.2f%s %4d:%02d:%02d%s",
+	rprintf(FCLIENT, "%12s %3d%% %7.2f%s %4d:%02d:%02d%s",
 		human_num(ofs), pct, rate, units,
 		remain_h, remain_m, remain_s, eol);
 }
--- old/receiver.c
+++ new/receiver.c
@@ -27,7 +27,7 @@ extern int am_server;
 extern int do_progress;
 extern int log_before_transfer;
 extern int log_format_has_i;
-extern int daemon_log_format_has_i;
+extern int logfile_format_has_i;
 extern int csum_length;
 extern int read_batch;
 extern int write_batch;
@@ -341,8 +341,7 @@ int recv_files(int f_in, struct file_lis
 	struct file_struct *file;
 	struct stats initial_stats;
 	int save_make_backups = make_backups;
-	int itemizing = am_daemon ? daemon_log_format_has_i
-		      : !am_server && log_format_has_i;
+	int itemizing = am_server ? logfile_format_has_i : log_format_has_i;
 	int max_phase = protocol_version >= 29 ? 2 : 1;
 	int i, recv_ok;
 
--- old/rsync.c
+++ new/rsync.c
@@ -32,7 +32,7 @@
 
 extern int verbose;
 extern int dry_run;
-extern int daemon_log_format_has_i;
+extern int logfile_format_has_i;
 extern int preserve_perms;
 extern int preserve_executability;
 extern int preserve_times;
@@ -218,7 +218,7 @@ int set_file_attrs(char *fname, struct f
 #endif
 
 	if (verbose > 1 && flags & ATTRS_REPORT) {
-		enum logcode code = daemon_log_format_has_i || dry_run
+		enum logcode code = logfile_format_has_i || dry_run
 				  ? FCLIENT : FINFO;
 		if (updated)
 			rprintf(code, "%s\n", fname);
--- old/rsync.h
+++ new/rsync.h
@@ -158,8 +158,8 @@
 
 
 /* Log-message categories.  Only FERROR and FINFO get sent over the socket.
- * FLOG and FCLIENT are only used on the daemon side for custom logging,
- * while FNAME is only used on the client side. */
+ * FLOG only goes to the log file, not to the client; FCLIENT is the opposite.
+ * FNAME is a client-side message when outputting a filename on its own. */
 enum logcode { FERROR=1, FINFO=2, FLOG=3, FCLIENT=4, FNAME=5, FSOCKERR=6 };
 
 /* Messages types that are sent over the message channel.  The logcode
--- old/rsync.yo
+++ new/rsync.yo
@@ -387,6 +387,7 @@ to the detailed description below for a 
      --progress              show progress during transfer
  -P                          same as --partial --progress
  -i, --itemize-changes       output a change-summary for all updates
+     --log-file=FILE         output what we're doing to a log file
      --log-format=FORMAT     output filenames using the specified format
      --password-file=FILE    read password from FILE
      --list-only             list the files instead of copying them
@@ -1423,6 +1424,23 @@ the string "*deleting" for each item tha
 you are talking to a recent enough rsync that it logs deletions instead of
 outputting them as a verbose message).
 
+dit(bf(--log-file=FILE)) This option causes rsync to log what it is doing
+to a file.  This is similar to the logging that a daemon does, but can be
+requested for the client side and/or the server side of a non-daemon
+transfer.  If specified as a client option, transfer logging will in effect
+if the bf(--log-format) option was either specified or implied (e.g.
+bf(--verbose) implies a basic log format).  If explicitly sent to a server
+via the bf(--rsync-path) option, transfer logging will always occur using
+the default bf(--itemize-changes) format.
+
+Here's a example command that requests the remote side to log what is
+happening:
+
+verb(  rsync -av --rsync-path="path --log-file=/tmp/rlog" src/ dest/)
+
+This is very useful if you need to debug why a connection is closing
+unexpectedly.
+
 dit(bf(--log-format=FORMAT)) This allows you to specify exactly what the
 rsync client outputs to the user on a per-file basis.  The format is a text
 string containing embedded single-character escape sequences prefixed with
--- old/sender.c
+++ new/sender.c
@@ -25,7 +25,7 @@ extern int am_server;
 extern int am_daemon;
 extern int log_before_transfer;
 extern int log_format_has_i;
-extern int daemon_log_format_has_i;
+extern int logfile_format_has_i;
 extern int csum_length;
 extern int append_mode;
 extern int io_error;
@@ -215,8 +215,7 @@ void send_files(struct file_list *flist,
 	int phase = 0, max_phase = protocol_version >= 29 ? 2 : 1;
 	struct stats initial_stats;
 	int save_make_backups = make_backups;
-	int itemizing = am_daemon ? daemon_log_format_has_i
-		      : !am_server && log_format_has_i;
+	int itemizing = am_server ? logfile_format_has_i : log_format_has_i;
 	int f_xfer = write_batch < 0 ? batch_fd : f_out;
 	int i, j;