Changed human_num() to big_num() with an extra arg so that it can
[rsync.git] / log.c
1 /*
2  * Logging and utility functions.
3  *
4  * Copyright (C) 1998-2001 Andrew Tridgell <tridge@samba.org>
5  * Copyright (C) 2000-2001 Martin Pool <mbp@samba.org>
6  * Copyright (C) 2003-2008 Wayne Davison
7  *
8  * This program is free software; you can redistribute it and/or modify
9  * it under the terms of the GNU General Public License as published by
10  * the Free Software Foundation; either version 3 of the License, or
11  * (at your option) any later version.
12  *
13  * This program is distributed in the hope that it will be useful,
14  * but WITHOUT ANY WARRANTY; without even the implied warranty of
15  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
16  * GNU General Public License for more details.
17  *
18  * You should have received a copy of the GNU General Public License along
19  * with this program; if not, visit the http://fsf.org website.
20  */
21
22 #include "rsync.h"
23 #include "ifuncs.h"
24
25 extern int dry_run;
26 extern int am_daemon;
27 extern int am_server;
28 extern int am_sender;
29 extern int am_generator;
30 extern int local_server;
31 extern int quiet;
32 extern int module_id;
33 extern int msg_fd_out;
34 extern int allow_8bit_chars;
35 extern int protocol_version;
36 extern int preserve_times;
37 extern int uid_ndx;
38 extern int gid_ndx;
39 extern int stdout_format_has_i;
40 extern int stdout_format_has_o_or_i;
41 extern int logfile_format_has_i;
42 extern int logfile_format_has_o_or_i;
43 extern int receiver_symlink_times;
44 extern mode_t orig_umask;
45 extern char *auth_user;
46 extern char *stdout_format;
47 extern char *logfile_format;
48 extern char *logfile_name;
49 #ifdef ICONV_CONST
50 extern iconv_t ic_chck;
51 #endif
52 #ifdef ICONV_OPTION
53 extern iconv_t ic_send, ic_recv;
54 #endif
55 extern char curr_dir[];
56 extern char *module_dir;
57 extern unsigned int module_dirlen;
58
59 static int log_initialised;
60 static int logfile_was_closed;
61 static FILE *logfile_fp;
62 struct stats stats;
63
64 int got_xfer_error = 0;
65 int output_needs_newline = 0;
66
67 struct {
68         int code;
69         char const *name;
70 } const rerr_names[] = {
71         { RERR_SYNTAX     , "syntax or usage error" },
72         { RERR_PROTOCOL   , "protocol incompatibility" },
73         { RERR_FILESELECT , "errors selecting input/output files, dirs" },
74         { RERR_UNSUPPORTED, "requested action not supported" },
75         { RERR_STARTCLIENT, "error starting client-server protocol" },
76         { RERR_SOCKETIO   , "error in socket IO" },
77         { RERR_FILEIO     , "error in file IO" },
78         { RERR_STREAMIO   , "error in rsync protocol data stream" },
79         { RERR_MESSAGEIO  , "errors with program diagnostics" },
80         { RERR_IPC        , "error in IPC code" },
81         { RERR_CRASHED    , "sibling process crashed" },
82         { RERR_TERMINATED , "sibling process terminated abnormally" },
83         { RERR_SIGNAL1    , "received SIGUSR1" },
84         { RERR_SIGNAL     , "received SIGINT, SIGTERM, or SIGHUP" },
85         { RERR_WAITCHILD  , "waitpid() failed" },
86         { RERR_MALLOC     , "error allocating core memory buffers" },
87         { RERR_PARTIAL    , "some files could not be transferred" },
88         { RERR_VANISHED   , "some files vanished before they could be transferred" },
89         { RERR_TIMEOUT    , "timeout in data send/receive" },
90         { RERR_CONTIMEOUT , "timeout waiting for daemon connection" },
91         { RERR_CMD_FAILED , "remote shell failed" },
92         { RERR_CMD_KILLED , "remote shell killed" },
93         { RERR_CMD_RUN    , "remote command could not be run" },
94         { RERR_CMD_NOTFOUND,"remote command not found" },
95         { RERR_DEL_LIMIT  , "the --max-delete limit stopped deletions" },
96         { 0, NULL }
97 };
98
99 /*
100  * Map from rsync error code to name, or return NULL.
101  */
102 static char const *rerr_name(int code)
103 {
104         int i;
105         for (i = 0; rerr_names[i].name; i++) {
106                 if (rerr_names[i].code == code)
107                         return rerr_names[i].name;
108         }
109         return NULL;
110 }
111
112 static void logit(int priority, const char *buf)
113 {
114         if (logfile_was_closed)
115                 logfile_reopen();
116         if (logfile_fp) {
117                 fprintf(logfile_fp, "%s [%d] %s",
118                         timestring(time(NULL)), (int)getpid(), buf);
119                 fflush(logfile_fp);
120         } else {
121                 syslog(priority, "%s", buf);
122         }
123 }
124
125 static void syslog_init()
126 {
127         static int been_here = 0;
128         int options = LOG_PID;
129
130         if (been_here)
131                 return;
132         been_here = 1;
133
134 #ifdef LOG_NDELAY
135         options |= LOG_NDELAY;
136 #endif
137
138 #ifdef LOG_DAEMON
139         openlog("rsyncd", options, lp_syslog_facility(module_id));
140 #else
141         openlog("rsyncd", options);
142 #endif
143
144 #ifndef LOG_NDELAY
145         logit(LOG_INFO, "rsyncd started\n");
146 #endif
147 }
148
149 static void logfile_open(void)
150 {
151         mode_t old_umask = umask(022 | orig_umask);
152         logfile_fp = fopen(logfile_name, "a");
153         umask(old_umask);
154         if (!logfile_fp) {
155                 int fopen_errno = errno;
156                 /* Rsync falls back to using syslog on failure. */
157                 syslog_init();
158                 rsyserr(FERROR, fopen_errno,
159                         "failed to open log-file %s", logfile_name);
160                 rprintf(FINFO, "Ignoring \"log file\" setting.\n");
161         }
162 }
163
164 void log_init(int restart)
165 {
166         if (log_initialised) {
167                 if (!restart)
168                         return;
169                 if (strcmp(logfile_name, lp_log_file(module_id)) != 0) {
170                         if (logfile_fp) {
171                                 fclose(logfile_fp);
172                                 logfile_fp = NULL;
173                         } else
174                                 closelog();
175                         logfile_name = NULL;
176                 } else if (*logfile_name)
177                         return; /* unchanged, non-empty "log file" names */
178                 else if (lp_syslog_facility(-1) != lp_syslog_facility(module_id))
179                         closelog();
180                 else
181                         return; /* unchanged syslog settings */
182         } else
183                 log_initialised = 1;
184
185         /* This looks pointless, but it is needed in order for the
186          * C library on some systems to fetch the timezone info
187          * before the chroot. */
188         timestring(time(NULL));
189
190         /* Optionally use a log file instead of syslog.  (Non-daemon
191          * rsyncs will have already set logfile_name, as needed.) */
192         if (am_daemon && !logfile_name)
193                 logfile_name = lp_log_file(module_id);
194         if (logfile_name && *logfile_name)
195                 logfile_open();
196         else
197                 syslog_init();
198 }
199
200 void logfile_close(void)
201 {
202         if (logfile_fp) {
203                 logfile_was_closed = 1;
204                 fclose(logfile_fp);
205                 logfile_fp = NULL;
206         }
207 }
208
209 void logfile_reopen(void)
210 {
211         if (logfile_was_closed) {
212                 logfile_was_closed = 0;
213                 logfile_open();
214         }
215 }
216
217 static void filtered_fwrite(FILE *f, const char *buf, int len, int use_isprint)
218 {
219         const char *s, *end = buf + len;
220         for (s = buf; s < end; s++) {
221                 if ((s < end - 4
222                   && *s == '\\' && s[1] == '#'
223                   && isDigit(s + 2)
224                   && isDigit(s + 3)
225                   && isDigit(s + 4))
226                  || (*s != '\t'
227                   && ((use_isprint && !isPrint(s))
228                    || *(uchar*)s < ' '))) {
229                         if (s != buf && fwrite(buf, s - buf, 1, f) != 1)
230                                 exit_cleanup(RERR_MESSAGEIO);
231                         fprintf(f, "\\#%03o", *(uchar*)s);
232                         buf = s + 1;
233                 }
234         }
235         if (buf != end && fwrite(buf, end - buf, 1, f) != 1)
236                 exit_cleanup(RERR_MESSAGEIO);
237 }
238
239 /* this is the underlying (unformatted) rsync debugging function. Call
240  * it with FINFO, FERROR_*, FWARNING, FLOG, or FCLIENT.  Note: recursion
241  * can happen with certain fatal conditions. */
242 void rwrite(enum logcode code, const char *buf, int len, int is_utf8)
243 {
244         int trailing_CR_or_NL;
245         FILE *f = NULL;
246 #ifdef ICONV_OPTION
247         iconv_t ic = is_utf8 && ic_recv != (iconv_t)-1 ? ic_recv : ic_chck;
248 #else
249 #ifdef ICONV_CONST
250         iconv_t ic = ic_chck;
251 #endif
252 #endif
253
254         if (len < 0)
255                 exit_cleanup(RERR_MESSAGEIO);
256
257         if (am_server && msg_fd_out >= 0) {
258                 assert(!is_utf8);
259                 /* Pass the message to our sibling. */
260                 send_msg((enum msgcode)code, buf, len, 0);
261                 return;
262         }
263
264         if (code == FERROR_SOCKET) /* This gets simplified for a non-sibling. */
265                 code = FERROR;
266
267         if (code == FCLIENT)
268                 code = FINFO;
269         else if (am_daemon || logfile_name) {
270                 static int in_block;
271                 char msg[2048];
272                 int priority = code == FINFO || code == FLOG ? LOG_INFO :  LOG_WARNING;
273
274                 if (in_block)
275                         return;
276                 in_block = 1;
277                 if (!log_initialised)
278                         log_init(0);
279                 strlcpy(msg, buf, MIN((int)sizeof msg, len + 1));
280                 logit(priority, msg);
281                 in_block = 0;
282
283                 if (code == FLOG || (am_daemon && !am_server))
284                         return;
285         } else if (code == FLOG)
286                 return;
287
288         if (quiet && code == FINFO)
289                 return;
290
291         if (am_server) {
292                 enum msgcode msg = (enum msgcode)code;
293                 if (protocol_version < 30) {
294                         if (msg == MSG_ERROR)
295                                 msg = MSG_ERROR_XFER;
296                         else if (msg == MSG_WARNING)
297                                 msg = MSG_INFO;
298                 }
299                 /* Pass the message to the non-server side. */
300                 if (send_msg(msg, buf, len, !is_utf8))
301                         return;
302                 if (am_daemon) {
303                         /* TODO: can we send the error to the user somehow? */
304                         return;
305                 }
306         }
307
308         switch (code) {
309         case FERROR_XFER:
310                 got_xfer_error = 1;
311                 /* FALL THROUGH */
312         case FERROR:
313         case FWARNING:
314                 f = stderr;
315                 break;
316         case FINFO:
317                 f = am_server ? stderr : stdout;
318                 break;
319         default:
320                 exit_cleanup(RERR_MESSAGEIO);
321         }
322
323         if (output_needs_newline) {
324                 fputc('\n', f);
325                 output_needs_newline = 0;
326         }
327
328         trailing_CR_or_NL = len && (buf[len-1] == '\n' || buf[len-1] == '\r')
329                           ? buf[--len] : 0;
330
331         if (len && buf[0] == '\r') {
332                 fputc('\r', f);
333                 buf++;
334                 len--;
335         }
336
337 #ifdef ICONV_CONST
338         if (ic != (iconv_t)-1) {
339                 xbuf outbuf, inbuf;
340                 char convbuf[1024];
341                 int ierrno;
342
343                 INIT_CONST_XBUF(outbuf, convbuf);
344                 INIT_XBUF(inbuf, (char*)buf, len, -1);
345
346                 while (inbuf.len) {
347                         iconvbufs(ic, &inbuf, &outbuf, 0);
348                         ierrno = errno;
349                         if (outbuf.len) {
350                                 filtered_fwrite(f, convbuf, outbuf.len, 0);
351                                 outbuf.len = 0;
352                         }
353                         if (!ierrno || ierrno == E2BIG)
354                                 continue;
355                         fprintf(f, "\\#%03o", CVAL(inbuf.buf, inbuf.pos++));
356                         inbuf.len--;
357                 }
358         } else
359 #endif
360                 filtered_fwrite(f, buf, len, !allow_8bit_chars);
361
362         if (trailing_CR_or_NL) {
363                 fputc(trailing_CR_or_NL, f);
364                 fflush(f);
365         }
366 }
367
368 /* This is the rsync debugging function. Call it with FINFO, FERROR_*,
369  * FWARNING, FLOG, or FCLIENT. */
370 void rprintf(enum logcode code, const char *format, ...)
371 {
372         va_list ap;
373         char buf[BIGPATHBUFLEN];
374         size_t len;
375
376         va_start(ap, format);
377         len = vsnprintf(buf, sizeof buf, format, ap);
378         va_end(ap);
379
380         /* Deal with buffer overruns.  Instead of panicking, just
381          * truncate the resulting string.  (Note that configure ensures
382          * that we have a vsnprintf() that doesn't ever return -1.) */
383         if (len > sizeof buf - 1) {
384                 static const char ellipsis[] = "[...]";
385
386                 /* Reset length, and zero-terminate the end of our buffer */
387                 len = sizeof buf - 1;
388                 buf[len] = '\0';
389
390                 /* Copy the ellipsis to the end of the string, but give
391                  * us one extra character:
392                  *
393                  *                  v--- null byte at buf[sizeof buf - 1]
394                  *        abcdefghij0
395                  *     -> abcd[...]00  <-- now two null bytes at end
396                  *
397                  * If the input format string has a trailing newline,
398                  * we copy it into that extra null; if it doesn't, well,
399                  * all we lose is one byte.  */
400                 memcpy(buf+len-sizeof ellipsis, ellipsis, sizeof ellipsis);
401                 if (format[strlen(format)-1] == '\n') {
402                         buf[len-1] = '\n';
403                 }
404         }
405
406         rwrite(code, buf, len, 0);
407 }
408
409 /* This is like rprintf, but it also tries to print some
410  * representation of the error code.  Normally errcode = errno.
411  *
412  * Unlike rprintf, this always adds a newline and there should not be
413  * one in the format string.
414  *
415  * Note that since strerror might involve dynamically loading a
416  * message catalog we need to call it once before chroot-ing. */
417 void rsyserr(enum logcode code, int errcode, const char *format, ...)
418 {
419         va_list ap;
420         char buf[BIGPATHBUFLEN];
421         size_t len;
422
423         strlcpy(buf, RSYNC_NAME ": ", sizeof buf);
424         len = (sizeof RSYNC_NAME ": ") - 1;
425
426         va_start(ap, format);
427         len += vsnprintf(buf + len, sizeof buf - len, format, ap);
428         va_end(ap);
429
430         if (len < sizeof buf) {
431                 len += snprintf(buf + len, sizeof buf - len,
432                                 ": %s (%d)\n", strerror(errcode), errcode);
433         }
434         if (len >= sizeof buf)
435                 exit_cleanup(RERR_MESSAGEIO);
436
437         rwrite(code, buf, len, 0);
438 }
439
440 void rflush(enum logcode code)
441 {
442         FILE *f = NULL;
443
444         if (am_daemon || code == FLOG)
445                 return;
446
447         if (!am_server && (code == FINFO || code == FCLIENT))
448                 f = stdout;
449         else
450                 f = stderr;
451
452         fflush(f);
453 }
454
455 /* A generic logging routine for send/recv, with parameter substitiution. */
456 static void log_formatted(enum logcode code, const char *format, const char *op,
457                           struct file_struct *file, const char *fname,
458                           struct stats *initial_stats, int iflags,
459                           const char *hlink)
460 {
461         char buf[MAXPATHLEN+1024], buf2[MAXPATHLEN], fmt[32];
462         char *p, *s, *c;
463         const char *n;
464         size_t len, total;
465         int64 b;
466
467         *fmt = '%';
468
469         /* We expand % codes one by one in place in buf.  We don't
470          * copy in the terminating null of the inserted strings, but
471          * rather keep going until we reach the null of the format. */
472         total = strlcpy(buf, format, sizeof buf);
473         if (total > MAXPATHLEN) {
474                 rprintf(FERROR, "log-format string is WAY too long!\n");
475                 exit_cleanup(RERR_MESSAGEIO);
476         }
477         buf[total++] = '\n';
478         buf[total] = '\0';
479
480         for (p = buf; (p = strchr(p, '%')) != NULL; ) {
481                 s = p++;
482                 c = fmt + 1;
483                 if (*p == '-')
484                         *c++ = *p++;
485                 while (isDigit(p) && c - fmt < (int)(sizeof fmt) - 8)
486                         *c++ = *p++;
487                 if (!*p)
488                         break;
489                 *c = '\0';
490                 n = NULL;
491
492                 switch (*p) {
493                 case 'h':
494                         if (am_daemon)
495                                 n = client_name(0);
496                         break;
497                 case 'a':
498                         if (am_daemon)
499                                 n = client_addr(0);
500                         break;
501                 case 'l':
502                         strlcat(fmt, ".0f", sizeof fmt);
503                         snprintf(buf2, sizeof buf2, fmt,
504                                  (double)F_LENGTH(file));
505                         n = buf2;
506                         break;
507                 case 'U':
508                         strlcat(fmt, "u", sizeof fmt);
509                         snprintf(buf2, sizeof buf2, fmt,
510                                  uid_ndx ? F_OWNER(file) : 0);
511                         n = buf2;
512                         break;
513                 case 'G':
514                         if (!gid_ndx || file->flags & FLAG_SKIP_GROUP)
515                                 n = "DEFAULT";
516                         else {
517                                 strlcat(fmt, "u", sizeof fmt);
518                                 snprintf(buf2, sizeof buf2, fmt,
519                                          F_GROUP(file));
520                                 n = buf2;
521                         }
522                         break;
523                 case 'p':
524                         strlcat(fmt, "ld", sizeof fmt);
525                         snprintf(buf2, sizeof buf2, fmt,
526                                  (long)getpid());
527                         n = buf2;
528                         break;
529                 case 'M':
530                         n = c = timestring(file->modtime);
531                         while ((c = strchr(c, ' ')) != NULL)
532                                 *c = '-';
533                         break;
534                 case 'B':
535                         c = buf2 + MAXPATHLEN - PERMSTRING_SIZE - 1;
536                         permstring(c, file->mode);
537                         n = c + 1; /* skip the type char */
538                         break;
539                 case 'o':
540                         n = op;
541                         break;
542                 case 'f':
543                         if (fname) {
544                                 c = f_name_buf();
545                                 strlcpy(c, fname, MAXPATHLEN);
546                         } else
547                                 c = f_name(file, NULL);
548                         if (am_sender && F_PATHNAME(file)) {
549                                 pathjoin(buf2, sizeof buf2,
550                                          F_PATHNAME(file), c);
551                                 clean_fname(buf2, 0);
552                                 if (fmt[1]) {
553                                         strlcpy(c, buf2, MAXPATHLEN);
554                                         n = c;
555                                 } else
556                                         n = buf2;
557                         } else if (am_daemon && *c != '/') {
558                                 pathjoin(buf2, sizeof buf2,
559                                          curr_dir + module_dirlen, c);
560                                 clean_fname(buf2, 0);
561                                 if (fmt[1]) {
562                                         strlcpy(c, buf2, MAXPATHLEN);
563                                         n = c;
564                                 } else
565                                         n = buf2;
566                         } else {
567                                 clean_fname(c, 0);
568                                 n = c;
569                         }
570                         if (*n == '/')
571                                 n++;
572                         break;
573                 case 'n':
574                         if (fname) {
575                                 c = f_name_buf();
576                                 strlcpy(c, fname, MAXPATHLEN);
577                         } else
578                                 c = f_name(file, NULL);
579                         if (S_ISDIR(file->mode))
580                                 strlcat(c, "/", MAXPATHLEN);
581                         n = c;
582                         break;
583                 case 'L':
584                         if (hlink && *hlink) {
585                                 n = hlink;
586                                 strlcpy(buf2, " => ", sizeof buf2);
587                         } else if (S_ISLNK(file->mode) && !fname) {
588                                 n = F_SYMLINK(file);
589                                 strlcpy(buf2, " -> ", sizeof buf2);
590                         } else {
591                                 n = "";
592                                 if (!fmt[1])
593                                         break;
594                                 strlcpy(buf2, "    ", sizeof buf2);
595                         }
596                         strlcat(fmt, "s", sizeof fmt);
597                         snprintf(buf2 + 4, sizeof buf2 - 4, fmt, n);
598                         n = buf2;
599                         break;
600                 case 'm':
601                         n = lp_name(module_id);
602                         break;
603                 case 't':
604                         n = timestring(time(NULL));
605                         break;
606                 case 'P':
607                         n = module_dir;
608                         break;
609                 case 'u':
610                         n = auth_user;
611                         break;
612                 case 'b':
613                         if (am_sender) {
614                                 b = stats.total_written -
615                                         initial_stats->total_written;
616                         } else {
617                                 b = stats.total_read -
618                                         initial_stats->total_read;
619                         }
620                         strlcat(fmt, ".0f", sizeof fmt);
621                         snprintf(buf2, sizeof buf2, fmt, (double)b);
622                         n = buf2;
623                         break;
624                 case 'c':
625                         if (!am_sender) {
626                                 b = stats.total_written -
627                                         initial_stats->total_written;
628                         } else {
629                                 b = stats.total_read -
630                                         initial_stats->total_read;
631                         }
632                         strlcat(fmt, ".0f", sizeof fmt);
633                         snprintf(buf2, sizeof buf2, fmt, (double)b);
634                         n = buf2;
635                         break;
636                 case 'i':
637                         if (iflags & ITEM_DELETED) {
638                                 n = "*deleting  ";
639                                 break;
640                         }
641                         n  = c = buf2 + MAXPATHLEN - 32;
642                         c[0] = iflags & ITEM_LOCAL_CHANGE
643                               ? iflags & ITEM_XNAME_FOLLOWS ? 'h' : 'c'
644                              : !(iflags & ITEM_TRANSFER) ? '.'
645                              : !local_server && *op == 's' ? '<' : '>';
646                         if (S_ISLNK(file->mode)) {
647                                 c[1] = 'L';
648                                 c[3] = '.';
649                                 c[4] = !(iflags & ITEM_REPORT_TIME) ? '.'
650                                      : !preserve_times || !receiver_symlink_times
651                                     || (iflags & ITEM_REPORT_TIMEFAIL) ? 'T' : 't';
652                         } else {
653                                 c[1] = S_ISDIR(file->mode) ? 'd'
654                                      : IS_SPECIAL(file->mode) ? 'S'
655                                      : IS_DEVICE(file->mode) ? 'D' : 'f';
656                                 c[3] = !(iflags & ITEM_REPORT_SIZE) ? '.' : 's';
657                                 c[4] = !(iflags & ITEM_REPORT_TIME) ? '.'
658                                      : !preserve_times ? 'T' : 't';
659                         }
660                         c[2] = !(iflags & ITEM_REPORT_CHANGE) ? '.' : 'c';
661                         c[5] = !(iflags & ITEM_REPORT_PERMS) ? '.' : 'p';
662                         c[6] = !(iflags & ITEM_REPORT_OWNER) ? '.' : 'o';
663                         c[7] = !(iflags & ITEM_REPORT_GROUP) ? '.' : 'g';
664                         c[8] = !(iflags & ITEM_REPORT_ATIME) ? '.' : 'u';
665                         c[9] = !(iflags & ITEM_REPORT_ACL) ? '.' : 'a';
666                         c[10] = !(iflags & ITEM_REPORT_XATTR) ? '.' : 'x';
667                         c[11] = '\0';
668
669                         if (iflags & (ITEM_IS_NEW|ITEM_MISSING_DATA)) {
670                                 char ch = iflags & ITEM_IS_NEW ? '+' : '?';
671                                 int i;
672                                 for (i = 2; c[i]; i++)
673                                         c[i] = ch;
674                         } else if (c[0] == '.' || c[0] == 'h' || c[0] == 'c') {
675                                 int i;
676                                 for (i = 2; c[i]; i++) {
677                                         if (c[i] != '.')
678                                                 break;
679                                 }
680                                 if (!c[i]) {
681                                         for (i = 2; c[i]; i++)
682                                                 c[i] = ' ';
683                                 }
684                         }
685                         break;
686                 }
687
688                 /* "n" is the string to be inserted in place of this % code. */
689                 if (!n)
690                         continue;
691                 if (n != buf2 && fmt[1]) {
692                         strlcat(fmt, "s", sizeof fmt);
693                         snprintf(buf2, sizeof buf2, fmt, n);
694                         n = buf2;
695                 }
696                 len = strlen(n);
697
698                 /* Subtract the length of the escape from the string's size. */
699                 total -= p - s + 1;
700
701                 if (len + total >= (size_t)sizeof buf) {
702                         rprintf(FERROR,
703                                 "buffer overflow expanding %%%c -- exiting\n",
704                                 p[0]);
705                         exit_cleanup(RERR_MESSAGEIO);
706                 }
707
708                 /* Shuffle the rest of the string along to make space for n */
709                 if (len != (size_t)(p - s + 1))
710                         memmove(s + len, p + 1, total - (s - buf) + 1);
711                 total += len;
712
713                 /* Insert the contents of string "n", but NOT its null. */
714                 if (len)
715                         memcpy(s, n, len);
716
717                 /* Skip over inserted string; continue looking */
718                 p = s + len;
719         }
720
721         rwrite(code, buf, total, 0);
722 }
723
724 /* Return 1 if the format escape is in the log-format string (e.g. look for
725  * the 'b' in the "%9b" format escape). */
726 int log_format_has(const char *format, char esc)
727 {
728         const char *p;
729
730         if (!format)
731                 return 0;
732
733         for (p = format; (p = strchr(p, '%')) != NULL; ) {
734                 if (*++p == '-')
735                         p++;
736                 while (isDigit(p))
737                         p++;
738                 if (!*p)
739                         break;
740                 if (*p == esc)
741                         return 1;
742         }
743         return 0;
744 }
745
746 /* Log the transfer of a file.  If the code is FCLIENT, the output just goes
747  * to stdout.  If it is FLOG, it just goes to the log file.  Otherwise we
748  * output to both. */
749 void log_item(enum logcode code, struct file_struct *file,
750               struct stats *initial_stats, int iflags, const char *hlink)
751 {
752         const char *s_or_r = am_sender ? "send" : "recv";
753
754         if (code != FLOG && stdout_format && !am_server) {
755                 log_formatted(FCLIENT, stdout_format, s_or_r,
756                               file, NULL, initial_stats, iflags, hlink);
757         }
758         if (code != FCLIENT && logfile_format && *logfile_format) {
759                 log_formatted(FLOG, logfile_format, s_or_r,
760                               file, NULL, initial_stats, iflags, hlink);
761         }
762 }
763
764 void maybe_log_item(struct file_struct *file, int iflags, int itemizing,
765                     const char *buf)
766 {
767         int significant_flags = iflags & SIGNIFICANT_ITEM_FLAGS;
768         int see_item = itemizing && (significant_flags || *buf
769                 || stdout_format_has_i > 1 || (INFO_GTE(NAME, 2) && stdout_format_has_i));
770         int local_change = iflags & ITEM_LOCAL_CHANGE && significant_flags;
771         if (am_server) {
772                 if (logfile_name && !dry_run && see_item
773                  && (significant_flags || logfile_format_has_i))
774                         log_item(FLOG, file, &stats, iflags, buf);
775         } else if (see_item || local_change || *buf
776             || (S_ISDIR(file->mode) && significant_flags)) {
777                 enum logcode code = significant_flags || logfile_format_has_i ? FINFO : FCLIENT;
778                 log_item(code, file, &stats, iflags, buf);
779         }
780 }
781
782 void log_delete(const char *fname, int mode)
783 {
784         static struct {
785                 union file_extras ex[4]; /* just in case... */
786                 struct file_struct file;
787         } x;
788         int len = strlen(fname);
789         const char *fmt;
790
791         x.file.mode = mode;
792
793         if (!INFO_GTE(DEL, 1) && !stdout_format)
794                 ;
795         else if (am_server && protocol_version >= 29 && len < MAXPATHLEN) {
796                 if (S_ISDIR(mode))
797                         len++; /* directories include trailing null */
798                 send_msg(MSG_DELETED, fname, len, am_generator);
799         } else {
800                 fmt = stdout_format_has_o_or_i ? stdout_format : "deleting %n";
801                 log_formatted(FCLIENT, fmt, "del.", &x.file, fname, &stats,
802                               ITEM_DELETED, NULL);
803         }
804
805         if (!logfile_name || dry_run || !logfile_format)
806                 return;
807
808         fmt = logfile_format_has_o_or_i ? logfile_format : "deleting %n";
809         log_formatted(FLOG, fmt, "del.", &x.file, fname, &stats, ITEM_DELETED, NULL);
810 }
811
812 /*
813  * Called when the transfer is interrupted for some reason.
814  *
815  * Code is one of the RERR_* codes from errcode.h, or terminating
816  * successfully.
817  */
818 void log_exit(int code, const char *file, int line)
819 {
820         if (code == 0) {
821                 rprintf(FLOG,"sent %s bytes  received %s bytes  total size %s\n",
822                         big_num(stats.total_written, 0),
823                         big_num(stats.total_read, 0),
824                         big_num(stats.total_size, 0));
825         } else if (am_server != 2) {
826                 const char *name;
827
828                 name = rerr_name(code);
829                 if (!name)
830                         name = "unexplained error";
831
832                 /* VANISHED is not an error, only a warning */
833                 if (code == RERR_VANISHED) {
834                         rprintf(FWARNING, "rsync warning: %s (code %d) at %s(%d) [%s=%s]\n",
835                                 name, code, file, line, who_am_i(), RSYNC_VERSION);
836                 } else {
837                         rprintf(FERROR, "rsync error: %s (code %d) at %s(%d) [%s=%s]\n",
838                                 name, code, file, line, who_am_i(), RSYNC_VERSION);
839                 }
840         }
841 }