log.c

Rsync 3.0.5 source code

	strlcpy(buf, RSYNC_NAME ": ", sizeof buf);
	len = (sizeof RSYNC_NAME ": ") - 1;

	va_start(ap, format);
	len += vsnprintf(buf + len, sizeof buf - len, format, ap);
	va_end(ap);

	if (len < sizeof buf) {
		len += snprintf(buf + len, sizeof buf - len,
				": %s (%d)\n", strerror(errcode), errcode);
	}
	if (len >= sizeof buf)
		exit_cleanup(RERR_MESSAGEIO);

	rwrite(code, buf, len, 0);
}

void rflush(enum logcode code)
{
	FILE *f = NULL;

	if (am_daemon || code == FLOG)
		return;

	if (code == FINFO && !am_server)
		f = stdout;
	else
		f = stderr;

	fflush(f);
}

/* A generic logging routine for send/recv, with parameter substitiution. */
static void log_formatted(enum logcode code, const char *format, const char *op,
			  struct file_struct *file, const char *fname,
			  struct stats *initial_stats, int iflags,
			  const char *hlink)
{
	char buf[MAXPATHLEN+1024], buf2[MAXPATHLEN], fmt[32];
	char *p, *s, *c;
	const char *n;
	size_t len, total;
	int64 b;

	*fmt = '%';

	/* We expand % codes one by one in place in buf.  We don't
	 * copy in the terminating null of the inserted strings, but
	 * rather keep going until we reach the null of the format. */
	total = strlcpy(buf, format, sizeof buf);
	if (total > MAXPATHLEN) {
		rprintf(FERROR, "log-format string is WAY too long!\n");
		exit_cleanup(RERR_MESSAGEIO);
	}
	buf[total++] = '\n';
	buf[total] = '\0';

	for (p = buf; (p = strchr(p, '%')) != NULL; ) {
		s = p++;
		c = fmt + 1;
		if (*p == '-')
			*c++ = *p++;
		while (isDigit(p) && c - fmt < (int)(sizeof fmt) - 8)
			*c++ = *p++;
		if (!*p)
			break;
		*c = '\0';
		n = NULL;

		switch (*p) {
		case 'h':
			if (am_daemon)
				n = client_name(0);
			break;
		case 'a':
			if (am_daemon)
				n = client_addr(0);
			break;
		case 'l':
			strlcat(fmt, ".0f", sizeof fmt);
			snprintf(buf2, sizeof buf2, fmt,
				 (double)F_LENGTH(file));
			n = buf2;
			break;
		case 'U':
			strlcat(fmt, "u", sizeof fmt);
			snprintf(buf2, sizeof buf2, fmt,
				 uid_ndx ? F_OWNER(file) : 0);
			n = buf2;
			break;
		case 'G':
			if (!gid_ndx || file->flags & FLAG_SKIP_GROUP)
				n = "DEFAULT";
			else {
				strlcat(fmt, "u", sizeof fmt);
				snprintf(buf2, sizeof buf2, fmt,
					 F_GROUP(file));
				n = buf2;
			}
			break;
		case 'p':
			strlcat(fmt, "ld", sizeof fmt);
			snprintf(buf2, sizeof buf2, fmt,
				 (long)getpid());
			n = buf2;
			break;
		case 'M':
			n = c = timestring(file->modtime);
			while ((c = strchr(c, ' ')) != NULL)
				*c = '-';
			break;
		case 'B':
			c = buf2 + MAXPATHLEN - PERMSTRING_SIZE - 1;
			permstring(c, file->mode);
			n = c + 1; /* skip the type char */
			break;
		case 'o':
			n = op;
			break;
		case 'f':
			if (fname) {
				c = f_name_buf();
				strlcpy(c, fname, MAXPATHLEN);
			} else
				c = f_name(file, NULL);
			if (am_sender && F_PATHNAME(file)) {
				pathjoin(buf2, sizeof buf2,
					 F_PATHNAME(file), c);
				clean_fname(buf2, 0);
				if (fmt[1]) {
					strlcpy(c, buf2, MAXPATHLEN);
					n = c;
				} else
					n = buf2;
			} else if (am_daemon && *c != '/') {
				pathjoin(buf2, sizeof buf2,
					 curr_dir + module_dirlen, c);
				clean_fname(buf2, 0);
				if (fmt[1]) {
					strlcpy(c, buf2, MAXPATHLEN);
					n = c;
				} else
					n = buf2;
			} else {
				clean_fname(c, 0);
				n = c;
			}
			if (*n == '/')
				n++;
			break;
		case 'n':
			if (fname) {
				c = f_name_buf();
				strlcpy(c, fname, MAXPATHLEN);
			} else
				c = f_name(file, NULL);
			if (S_ISDIR(file->mode))
				strlcat(c, "/", MAXPATHLEN);
			n = c;
			break;
		case 'L':
			if (hlink && *hlink) {
				n = hlink;
				strlcpy(buf2, " => ", sizeof buf2);
			} else if (S_ISLNK(file->mode) && !fname) {
				n = F_SYMLINK(file);
				strlcpy(buf2, " -> ", sizeof buf2);
			} else {
				n = "";
				if (!fmt[1])
					break;
				strlcpy(buf2, "    ", sizeof buf2);
			}
			strlcat(fmt, "s", sizeof fmt);
			snprintf(buf2 + 4, sizeof buf2 - 4, fmt, n);
			n = buf2;
			break;
		case 'm':
			n = lp_name(module_id);
			break;
		case 't':
			n = timestring(time(NULL));
			break;
		case 'P':
			n = full_module_path;
			break;
		case 'u':
			n = auth_user;
			break;
		case 'b':
			if (am_sender) {
				b = stats.total_written -
					initial_stats->total_written;
			} else {
				b = stats.total_read -
					initial_stats->total_read;
			}
			strlcat(fmt, ".0f", sizeof fmt);
			snprintf(buf2, sizeof buf2, fmt, (double)b);
			n = buf2;
			break;
		case 'c':
			if (!am_sender) {
				b = stats.total_written -
					initial_stats->total_written;
			} else {
				b = stats.total_read -
					initial_stats->total_read;
			}
			strlcat(fmt, ".0f", sizeof fmt);
			snprintf(buf2, sizeof buf2, fmt, (double)b);
			n = buf2;
			break;
		case 'i':
			if (iflags & ITEM_DELETED) {
				n = "*deleting  ";
				break;
			}
			n  = c = buf2 + MAXPATHLEN - 32;
			c[0] = iflags & ITEM_LOCAL_CHANGE
			      ? iflags & ITEM_XNAME_FOLLOWS ? 'h' : 'c'
			     : !(iflags & ITEM_TRANSFER) ? '.'
			     : !local_server && *op == 's' ? '<' : '>';
			if (S_ISLNK(file->mode)) {
				c[1] = 'L';
				c[3] = '.';
				c[4] = !(iflags & ITEM_REPORT_TIME) ? '.'
				     : !preserve_times || !receiver_symlink_times
				    || (iflags & ITEM_REPORT_TIMEFAIL) ? 'T' : 't';
			} else {
				c[1] = S_ISDIR(file->mode) ? 'd'
				     : IS_SPECIAL(file->mode) ? 'S'
				     : IS_DEVICE(file->mode) ? 'D' : 'f';
				c[3] = !(iflags & ITEM_REPORT_SIZE) ? '.' : 's';
				c[4] = !(iflags & ITEM_REPORT_TIME) ? '.'
				     : !preserve_times ? 'T' : 't';
			}
			c[2] = !(iflags & ITEM_REPORT_CHANGE) ? '.' : 'c';
			c[5] = !(iflags & ITEM_REPORT_PERMS) ? '.' : 'p';
			c[6] = !(iflags & ITEM_REPORT_OWNER) ? '.' : 'o';
			c[7] = !(iflags & ITEM_REPORT_GROUP) ? '.' : 'g';
			c[8] = !(iflags & ITEM_REPORT_ATIME) ? '.' : 'u';
			c[9] = !(iflags & ITEM_REPORT_ACL) ? '.' : 'a';
			c[10] = !(iflags & ITEM_REPORT_XATTR) ? '.' : 'x';
			c[11] = '\0';

			if (iflags & (ITEM_IS_NEW|ITEM_MISSING_DATA)) {
				char ch = iflags & ITEM_IS_NEW ? '+' : '?';
				int i;
				for (i = 2; c[i]; i++)
					c[i] = ch;
			} else if (c[0] == '.' || c[0] == 'h' || c[0] == 'c') {
				int i;
				for (i = 2; c[i]; i++) {
					if (c[i] != '.')
						break;
				}
				if (!c[i]) {
					for (i = 2; c[i]; i++)
						c[i] = ' ';
				}
			}
			break;
		}

		/* "n" is the string to be inserted in place of this % code. */
		if (!n)
			continue;
		if (n != buf2 && fmt[1]) {
			strlcat(fmt, "s", sizeof fmt);
			snprintf(buf2, sizeof buf2, fmt, n);
			n = buf2;
		}
		len = strlen(n);

		/* Subtract the length of the escape from the string's size. */
		total -= p - s + 1;

		if (len + total >= (size_t)sizeof buf) {
			rprintf(FERROR,
				"buffer overflow expanding %%%c -- exiting\n",
				p[0]);
			exit_cleanup(RERR_MESSAGEIO);
		}

		/* Shuffle the rest of the string along to make space for n */
		if (len != (size_t)(p - s + 1))
			memmove(s + len, p + 1, total - (s - buf) + 1);
		total += len;

		/* Insert the contents of string "n", but NOT its null. */
		if (len)
			memcpy(s, n, len);

		/* Skip over inserted string; continue looking */
		p = s + len;
	}

	rwrite(code, buf, total, 0);
}

/* Return 1 if the format escape is in the log-format string (e.g. look for
 * the 'b' in the "%9b" format escape). */
int log_format_has(const char *format, char esc)
{
	const char *p;

	if (!format)
		return 0;

	for (p = format; (p = strchr(p, '%')) != NULL; ) {
		if (*++p == '-')
			p++;
		while (isDigit(p))
			p++;
		if (!*p)
			break;
		if (*p == esc)
			return 1;
	}
	return 0;
}

/* Log the transfer of a file.  If the code is FCLIENT, the output just goes
 * to stdout.  If it is FLOG, it just goes to the log file.  Otherwise we
 * output to both. */
void log_item(enum logcode code, struct file_struct *file,
	      struct stats *initial_stats, int iflags, const char *hlink)
{
	const char *s_or_r = am_sender ? "send" : "recv";

	if (code != FLOG && stdout_format && !am_server) {
		log_formatted(FCLIENT, stdout_format, s_or_r,
			      file, NULL, initial_stats, iflags, hlink);
	}
	if (code != FCLIENT && logfile_format && *logfile_format) {
		log_formatted(FLOG, logfile_format, s_or_r,
			      file, NULL, initial_stats, iflags, hlink);
	}
}

void maybe_log_item(struct file_struct *file, int iflags, int itemizing,
		    const char *buf)
{
	int significant_flags = iflags & SIGNIFICANT_ITEM_FLAGS;
	int see_item = itemizing && (significant_flags || *buf
		|| stdout_format_has_i > 1 || (verbose > 1 && stdout_format_has_i));
	int local_change = iflags & ITEM_LOCAL_CHANGE && significant_flags;
	if (am_server) {
		if (logfile_name && !dry_run && see_item
		 && (significant_flags || logfile_format_has_i))
			log_item(FLOG, file, &stats, iflags, buf);
	} else if (see_item || local_change || *buf
	    || (S_ISDIR(file->mode) && significant_flags)) {
		enum logcode code = significant_flags || logfile_format_has_i ? FINFO : FCLIENT;
		log_item(code, file, &stats, iflags, buf);
	}
}

void log_delete(const char *fname, int mode)
{
	static struct {
		union file_extras ex[4]; /* just in case... */
		struct file_struct file;
	} x;
	int len = strlen(fname);
	const char *fmt;

	x.file.mode = mode;

	if (!verbose && !stdout_format)
		;
	else if (am_server && protocol_version >= 29 && len < MAXPATHLEN) {
		if (S_ISDIR(mode))
			len++; /* directories include trailing null */
		send_msg(MSG_DELETED, fname, len, am_generator);
	} else {
		fmt = stdout_format_has_o_or_i ? stdout_format : "deleting %n";
		log_formatted(FCLIENT, fmt, "del.", &x.file, fname, &stats,
			      ITEM_DELETED, NULL);
	}

	if (!logfile_name || dry_run || !logfile_format)
		return;

	fmt = logfile_format_has_o_or_i ? logfile_format : "deleting %n";
	log_formatted(FLOG, fmt, "del.", &x.file, fname, &stats, ITEM_DELETED, NULL);
}

/*
 * Called when the transfer is interrupted for some reason.
 *
 * Code is one of the RERR_* codes from errcode.h, or terminating
 * successfully.
 */
void log_exit(int code, const char *file, int line)
{
	if (code == 0) {
		rprintf(FLOG,"sent %.0f bytes  received %.0f bytes  total size %.0f\n",
			(double)stats.total_written,
			(double)stats.total_read,
			(double)stats.total_size);
	} else if (am_server != 2) {
		const char *name;

		name = rerr_name(code);
		if (!name)
			name = "unexplained error";

		/* VANISHED is not an error, only a warning */
		if (code == RERR_VANISHED) {
			rprintf(FWARNING, "rsync warning: %s (code %d) at %s(%d) [%s=%s]\n",
				name, code, file, line, who_am_i(), RSYNC_VERSION);
		} else {
			rprintf(FERROR, "rsync error: %s (code %d) at %s(%d) [%s=%s]\n",
				name, code, file, line, who_am_i(), RSYNC_VERSION);
		}
	}
}