1 /* sync_log.c -- Cyrus synchonization logging functions
2 *
3 * Copyright (c) 1994-2008 Carnegie Mellon University. All rights reserved.
4 *
5 * Redistribution and use in source and binary forms, with or without
6 * modification, are permitted provided that the following conditions
7 * are met:
8 *
9 * 1. Redistributions of source code must retain the above copyright
10 * notice, this list of conditions and the following disclaimer.
11 *
12 * 2. Redistributions in binary form must reproduce the above copyright
13 * notice, this list of conditions and the following disclaimer in
14 * the documentation and/or other materials provided with the
15 * distribution.
16 *
17 * 3. The name "Carnegie Mellon University" must not be used to
18 * endorse or promote products derived from this software without
19 * prior written permission. For permission or any legal
20 * details, please contact
21 * Carnegie Mellon University
22 * Center for Technology Transfer and Enterprise Creation
23 * 4615 Forbes Avenue
24 * Suite 302
25 * Pittsburgh, PA 15213
26 * (412) 268-7393, fax: (412) 268-7395
27 * innovation@andrew.cmu.edu
28 *
29 * 4. Redistributions of any form whatsoever must retain the following
30 * acknowledgment:
31 * "This product includes software developed by Computing Services
32 * at Carnegie Mellon University (http://www.cmu.edu/computing/)."
33 *
34 * CARNEGIE MELLON UNIVERSITY DISCLAIMS ALL WARRANTIES WITH REGARD TO
35 * THIS SOFTWARE, INCLUDING ALL IMPLIED WARRANTIES OF MERCHANTABILITY
36 * AND FITNESS, IN NO EVENT SHALL CARNEGIE MELLON UNIVERSITY BE LIABLE
37 * FOR ANY SPECIAL, INDIRECT OR CONSEQUENTIAL DAMAGES OR ANY DAMAGES
38 * WHATSOEVER RESULTING FROM LOSS OF USE, DATA OR PROFITS, WHETHER IN
39 * AN ACTION OF CONTRACT, NEGLIGENCE OR OTHER TORTIOUS ACTION, ARISING
40 * OUT OF OR IN CONNECTION WITH THE USE OR PERFORMANCE OF THIS SOFTWARE.
41 *
42 * Original version written by David Carter <dpc22@cam.ac.uk>
43 * Rewritten and integrated into Cyrus by Ken Murchison <ken@oceana.com>
44 */
45
46 /* YYY Need better quoting for obscure filenames: use literals? */
47
48 #include <config.h>
49
50 #ifdef HAVE_UNISTD_H
51 #include <unistd.h>
52 #endif
53 #include <stdarg.h>
54 #include <stdlib.h>
55 #include <stdio.h>
56 #include <string.h>
57 #include <syslog.h>
58 #include <errno.h>
59
60 #include "assert.h"
61 #include "exitcodes.h"
62 #include "sync_log.h"
63 #include "global.h"
64 #include "cyr_lock.h"
65 #include "mailbox.h"
66 #include "retry.h"
67 #include "util.h"
68 #include "xmalloc.h"
69 #include "xstrlcpy.h"
70
71 /* generated headers are not necessarily in current directory */
72 #include "imap/imap_err.h"
73
74 static int sync_log_suppressed = 0;
75 static strarray_t *channels = NULL;
76 static strarray_t *unsuppressable = NULL;
77
sync_log_init(void)78 EXPORTED void sync_log_init(void)
79 {
80 const char *conf;
81 int i;
82
83
84 /* sync_log_init() may be called more than once */
85 if (channels) strarray_free(channels);
86
87 conf = config_getstring(IMAPOPT_SYNC_LOG_CHANNELS);
88 if (!conf) conf = "\"\"";
89 channels = strarray_split(conf, " ", 0);
90 /*
91 * The sysadmin can specify "" in the value of sync_log_channels to
92 * mean the default channel name - this will be useful for sysadmins
93 * who want to start using a sync log channel for squatter but who
94 * have been using the default sync log channel for sync_client.
95 */
96 i = strarray_find(channels, "\"\"", 0);
97 if (i >= 0)
98 strarray_set(channels, i, NULL);
99
100 strarray_free(unsuppressable);
101 unsuppressable = NULL;
102 conf = config_getstring(IMAPOPT_SYNC_LOG_UNSUPPRESSABLE_CHANNELS);
103 if (conf)
104 unsuppressable = strarray_split(conf, " ", 0);
105 }
106
sync_log_suppress(void)107 EXPORTED void sync_log_suppress(void)
108 {
109 sync_log_suppressed = 1;
110 }
111
sync_log_done(void)112 EXPORTED void sync_log_done(void)
113 {
114 strarray_free(channels);
115 channels = NULL;
116
117 strarray_free(unsuppressable);
118 unsuppressable = NULL;
119 }
120
sync_log_fname(const char * channel)121 static char *sync_log_fname(const char *channel)
122 {
123 static char buf[MAX_MAILBOX_PATH];
124
125 if (channel)
126 snprintf(buf, MAX_MAILBOX_PATH,
127 "%s/sync/%s/log", config_dir, channel);
128 else
129 snprintf(buf, MAX_MAILBOX_PATH,
130 "%s/sync/log", config_dir);
131
132 return buf;
133 }
134
sync_log_enabled(const char * channel)135 static int sync_log_enabled(const char *channel)
136 {
137 if (!config_getswitch(IMAPOPT_SYNC_LOG))
138 return 0; /* entire mechanism is disabled */
139 if (!sync_log_suppressed)
140 return 1; /* _suppress() wasn't called */
141 if (unsuppressable && strarray_find(unsuppressable, channel, 0) >= 0)
142 return 1; /* channel is unsuppressable */
143 return 0; /* suppressed */
144 }
145
sync_log_base(const char * channel,const char * string)146 static void sync_log_base(const char *channel, const char *string)
147 {
148 int fd;
149 struct stat sbuffile, sbuffd;
150 int retries = 0;
151 const char *fname;
152
153 fname = sync_log_fname(channel);
154
155 while (retries++ < SYNC_LOG_RETRIES) {
156 fd = open(fname, O_WRONLY|O_APPEND|O_CREAT, 0640);
157 if (fd < 0 && errno == ENOENT) {
158 if (!cyrus_mkdir(fname, 0755)) {
159 fd = open(fname, O_WRONLY|O_APPEND|O_CREAT, 0640);
160 }
161 }
162 if (fd < 0) {
163 syslog(LOG_ERR, "sync_log(): Unable to write to log file %s: %s",
164 fname, strerror(errno));
165 return;
166 }
167
168 if (lock_blocking(fd, fname) == -1) {
169 syslog(LOG_ERR, "sync_log(): Failed to lock %s for %s: %m",
170 fname, string);
171 xclose(fd);
172 return;
173 }
174
175 /* Check that the file wasn't renamed after it was opened above */
176 if ((fstat(fd, &sbuffd) == 0) &&
177 (stat(fname, &sbuffile) == 0) &&
178 (sbuffd.st_ino == sbuffile.st_ino))
179 break;
180
181 lock_unlock(fd, fname);
182 xclose(fd);
183 }
184 if (retries >= SYNC_LOG_RETRIES) {
185 xclose(fd);
186 syslog(LOG_ERR,
187 "sync_log(): Failed to lock %s for %s after %d attempts",
188 fname, string, retries);
189 return;
190 }
191
192 if (retry_write(fd, string, strlen(string)) < 0)
193 syslog(LOG_ERR, "write() to %s failed: %s",
194 fname, strerror(errno));
195
196 (void)fsync(fd); /* paranoia */
197 lock_unlock(fd, fname);
198 xclose(fd);
199 }
200
sync_quote_name(const char * name)201 static const char *sync_quote_name(const char *name)
202 {
203 static char buf[MAX_MAILBOX_BUFFER+3]; /* "x2 plus \0 */
204 char c;
205 int src;
206 int dst = 0;
207 int need_quote = 0;
208
209 /* initial quote */
210 buf[dst++] = '"';
211
212 /* degenerate case - no name is the empty string, quote it */
213 if (!name || !*name) {
214 need_quote = 1;
215 goto end;
216 }
217
218 for (src = 0; name[src]; src++) {
219 c = name[src];
220 if ((c == '\r') || (c == '\n'))
221 fatal("Illegal line break in folder name", EC_IOERR);
222
223 /* quoteable characters */
224 if ((c == '\\') || (c == '\"') || (c == '{') || (c == '}')) {
225 need_quote = 1;
226 buf[dst++] = '\\';
227 }
228
229 /* non-atom characters */
230 else if ((c == ' ') || (c == '\t') || (c == '(') || (c == ')')) {
231 need_quote = 1;
232 }
233
234 buf[dst++] = c;
235
236 if (dst > MAX_MAILBOX_BUFFER)
237 fatal("word too long", EC_IOERR);
238 }
239
240 end:
241 if (need_quote) {
242 buf[dst++] = '\"';
243 buf[dst] = '\0';
244 return buf;
245 }
246 else {
247 buf[dst] = '\0';
248 return buf + 1; /* skip initial quote */
249 }
250 }
251
252 #define BUFSIZE 4096
253
va_format(const char * fmt,va_list ap)254 static char *va_format(const char *fmt, va_list ap)
255 {
256 static char buf[BUFSIZE+1];
257 size_t len;
258 int ival;
259 const char *sval;
260 const char *p;
261
262 for (len = 0, p = fmt; *p && len < BUFSIZE; p++) {
263 if (*p != '%') {
264 buf[len++] = *p;
265 continue;
266 }
267 switch (*++p) {
268 case 'd':
269 ival = va_arg(ap, int);
270 len += snprintf(buf+len, BUFSIZE-len, "%d", ival);
271 break;
272 case 's':
273 sval = va_arg(ap, const char *);
274 sval = sync_quote_name(sval);
275 strlcpy(buf+len, sval, BUFSIZE-len);
276 len += strlen(sval);
277 break;
278 default:
279 buf[len++] = *p;
280 break;
281 }
282 }
283
284 if (buf[len-1] != '\n') buf[len++] = '\n';
285 buf[len] = '\0';
286
287 return buf;
288 }
289
sync_log(const char * fmt,...)290 EXPORTED void sync_log(const char *fmt, ...)
291 {
292 va_list ap;
293 const char *val;
294 int i;
295
296 if (!channels) return;
297
298 va_start(ap, fmt);
299 val = va_format(fmt, ap);
300 va_end(ap);
301
302 for (i = 0 ; i < channels->count ; i++) {
303 const char *channel = channels->data[i];
304 if (sync_log_enabled(channel))
305 sync_log_base(channel, val);
306 }
307 }
308
sync_log_channel(const char * channel,const char * fmt,...)309 EXPORTED void sync_log_channel(const char *channel, const char *fmt, ...)
310 {
311 va_list ap;
312 const char *val;
313
314 va_start(ap, fmt);
315 val = va_format(fmt, ap);
316 va_end(ap);
317
318 sync_log_base(channel, val);
319 }
320
321 /*
322 * Read-side sync log code
323 */
324 struct sync_log_reader
325 {
326 /*
327 * This object works in three modes:
328 *
329 * - initialised with a sync log channel
330 * - standard mode used by sync_client
331 * - slr->log_file != NULL
332 * - slr->work_file is the name of a rename()d
333 * file that needs to be unlink()ed.
334 *
335 * - initialised with a saved file name
336 * - used by the sync_client -f option
337 * - slr->log_file = NULL
338 * - slr->work_file is the file given us by the user
339 * which it's important that we do not unlink()
340 *
341 * - initialised with a file descriptor
342 * - slr->log_file = NULL
343 * - slr->work_file = NULL
344 * - slr->fd is a file descriptor, probably stdin,
345 * and possibly a pipe
346 * - we cannot unlink() anything even if we wanted to.
347 */
348 char *log_file;
349 char *work_file;
350 int fd;
351 int fd_is_ours;
352 struct protstream *input;
353 struct buf type;
354 struct buf arg1;
355 struct buf arg2;
356 };
357
sync_log_reader_alloc(void)358 static sync_log_reader_t *sync_log_reader_alloc(void)
359 {
360 sync_log_reader_t *slr = xzmalloc(sizeof(sync_log_reader_t));
361 slr->fd = -1;
362 return slr;
363 }
364
365 /*
366 * Create a sync log reader object which will read from the given sync log
367 * channel 'channel'. The channel may be NULL for the default channel.
368 * Returns a new object which must be freed with sync_log_reader_free().
369 * Does not return NULL.
370 */
sync_log_reader_create_with_channel(const char * channel)371 EXPORTED sync_log_reader_t *sync_log_reader_create_with_channel(const char *channel)
372 {
373 sync_log_reader_t *slr = sync_log_reader_alloc();
374 struct buf buf = BUF_INITIALIZER;
375
376 slr->log_file = xstrdup(sync_log_fname(channel));
377
378 /* Create a work log filename. We will process this
379 * first if it exists */
380 buf_printf(&buf, "%s-run", slr->log_file);
381 slr->work_file = buf_release(&buf);
382
383 return slr;
384 }
385
386 /*
387 * Create a sync log reader object which will read from the given file
388 * 'filename'. Returns a new object which must be freed with
389 * sync_log_reader_free(). Does not return NULL.
390 */
sync_log_reader_create_with_filename(const char * filename)391 EXPORTED sync_log_reader_t *sync_log_reader_create_with_filename(const char *filename)
392 {
393 sync_log_reader_t *slr = sync_log_reader_alloc();
394 slr->work_file = xstrdup(filename);
395 /* slr->log_file remain NULL, which matters later */
396 return slr;
397 }
398
399 /*
400 * Create a sync log reader object which will read from the given file
401 * descriptor 'fd'. The file descriptor must be open for reading and
402 * is not closed. Returns a new object which must be freed with
403 * sync_log_reader_free(). Does not return NULL.
404 */
sync_log_reader_create_with_fd(int fd)405 EXPORTED sync_log_reader_t *sync_log_reader_create_with_fd(int fd)
406 {
407 sync_log_reader_t *slr = sync_log_reader_alloc();
408 slr->fd = fd;
409 slr->fd_is_ours = 0;
410 /* slr->log_file remain NULL, which matters later */
411 return slr;
412 }
413
414 /*
415 * Free a sync log reader object.
416 */
sync_log_reader_free(sync_log_reader_t * slr)417 EXPORTED void sync_log_reader_free(sync_log_reader_t *slr)
418 {
419 if (!slr) return;
420 if (slr->input) prot_free(slr->input);
421 if (slr->fd_is_ours && slr->fd >= 0) close(slr->fd);
422 free(slr->log_file);
423 free(slr->work_file);
424 buf_free(&slr->type);
425 buf_free(&slr->arg1);
426 buf_free(&slr->arg2);
427 free(slr);
428 }
429
430 /*
431 * Begin reading a sync log file. If the reader is reading from a
432 * channel, rename the current log file so it will not be appended to by
433 * the write side code, and open the file. Otherwise, just open the file
434 * (note this is still necessary even when the reader is reading from a
435 * file descriptor).
436 *
437 * When sync_log_reader_begin() returns success, you should loop calling
438 * sync_log_reader_getitem() and handling the items, until it returns
439 * EOF, and then call sync_log_reader_end().
440 *
441 * Returns zero on success, IMAP_AGAIN if reading from a channel and
442 * there is no current log file, or an IMAP error code on failure.
443 */
sync_log_reader_begin(sync_log_reader_t * slr)444 EXPORTED int sync_log_reader_begin(sync_log_reader_t *slr)
445 {
446 struct stat sbuf;
447 int r;
448
449 if (slr->input) {
450 r = sync_log_reader_end(slr);
451 if (r) return r;
452 }
453
454 if (stat(slr->work_file, &sbuf) == 0) {
455 /* Existing work log file - process this first */
456 syslog(LOG_NOTICE,
457 "Reprocessing sync log file %s", slr->work_file);
458 }
459 else if (!slr->log_file) {
460 syslog(LOG_ERR, "Failed to stat %s: %m",
461 slr->log_file);
462 return IMAP_IOERROR;
463 }
464 else {
465 /* Check for sync_log file */
466 if (stat(slr->log_file, &sbuf) < 0) {
467 if (errno == ENOENT)
468 return IMAP_AGAIN; /* no problem, try again later */
469 syslog(LOG_ERR, "Failed to stat %s: %m",
470 slr->log_file);
471 return IMAP_IOERROR;
472 }
473
474 /* Move sync_log to our work file */
475 if (rename(slr->log_file, slr->work_file) < 0) {
476 syslog(LOG_ERR, "Rename %s -> %s failed: %m",
477 slr->log_file, slr->work_file);
478 return IMAP_IOERROR;
479 }
480 }
481
482 if (slr->fd < 0) {
483 int fd = open(slr->work_file, O_RDWR, 0);
484 if (fd < 0) {
485 syslog(LOG_ERR, "Failed to open %s: %m", slr->work_file);
486 return IMAP_IOERROR;
487 }
488
489 if (lock_blocking(fd, slr->work_file) < 0) {
490 syslog(LOG_ERR, "Failed to lock %s: %m", slr->work_file);
491 close(fd);
492 return IMAP_IOERROR;
493 }
494
495 slr->fd = fd;
496 slr->fd_is_ours = 1;
497
498 /* we can unlock immediately, since we have serialised
499 * any process which held the lock over the rename. All
500 * future attempts to lock this inode will stat and notice
501 * the rename, so they won't write any more */
502 lock_unlock(slr->fd, slr->work_file);
503 }
504
505 slr->input = prot_new(slr->fd, /*write*/0);
506
507 return 0;
508 }
509
sync_log_reader_get_file_name(const sync_log_reader_t * slr)510 EXPORTED const char *sync_log_reader_get_file_name(const sync_log_reader_t *slr)
511 {
512 return slr->work_file;
513 }
514
515 /*
516 * Finish reading a sync log file. Closes the file (and, if the reader
517 * is reading from a channel, unlinks the work file and prepares for the
518 * next file). Returns 0 on success or an IMAP error code on failure.
519 */
sync_log_reader_end(sync_log_reader_t * slr)520 EXPORTED int sync_log_reader_end(sync_log_reader_t *slr)
521 {
522 if (!slr->input)
523 return 0;
524
525 if (slr->input) {
526 prot_free(slr->input);
527 slr->input = NULL;
528 }
529
530 if (slr->fd_is_ours && slr->fd >= 0) {
531 lock_unlock(slr->fd, slr->work_file);
532 close(slr->fd);
533 slr->fd = -1;
534 }
535
536 if (slr->log_file) {
537 /* We were initialised with a sync log channel, whose
538 * log file we rename()d to the work file. Now that
539 * we've done with the work file we can unlink it.
540 * Further checks at this point are just paranoia. */
541 if (slr->work_file && unlink(slr->work_file) < 0) {
542 syslog(LOG_ERR, "Unlink %s failed: %m", slr->work_file);
543 return IMAP_IOERROR;
544 }
545 }
546
547 return 0;
548 }
549
550 /*
551 * Read a single log item from a sync log file. The item will be
552 * returned as three constant strings. The first string is the type of
553 * the item (e.g. "MAILBOX") and is always capitalised. The second and
554 * third strings are arguments.
555 *
556 * Returns 0 on success, EOF when the end of the file is reached, or an
557 * IMAP error code on failure.
558 */
sync_log_reader_getitem(sync_log_reader_t * slr,const char * args[3])559 EXPORTED int sync_log_reader_getitem(sync_log_reader_t *slr,
560 const char *args[3])
561 {
562 int c;
563 const char *arg1s = NULL;
564 const char *arg2s = NULL;
565
566 if (!slr->input)
567 return EOF;
568
569 for (;;) {
570 if ((c = getword(slr->input, &slr->type)) == EOF)
571 return EOF;
572
573 /* Ignore blank lines */
574 if (c == '\r') c = prot_getc(slr->input);
575 if (c == '\n')
576 continue;
577
578 if (c != ' ') {
579 syslog(LOG_ERR, "Invalid input");
580 eatline(slr->input, c);
581 continue;
582 }
583
584 if ((c = getastring(slr->input, 0, &slr->arg1)) == EOF) return EOF;
585 arg1s = slr->arg1.s;
586
587 arg2s = NULL;
588 if (c == ' ') {
589 if ((c = getastring(slr->input, 0, &slr->arg2)) == EOF) return EOF;
590 arg2s = slr->arg2.s;
591 }
592
593 if (c == '\r') c = prot_getc(slr->input);
594 if (c != '\n') {
595 syslog(LOG_ERR, "Garbage at end of input line");
596 eatline(slr->input, c);
597 continue;
598 }
599
600 break;
601 }
602
603 ucase(slr->type.s);
604 args[0] = slr->type.s;
605 args[1] = arg1s;
606 args[2] = arg2s;
607 return 0;
608 }
609