1 /*-
2 * Copyright (c) 2003 Andrey Simonenko
3 * 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 * 1. Redistributions of source code must retain the above copyright
9 * notice, this list of conditions and the following disclaimer.
10 * 2. Redistributions in binary form must reproduce the above copyright
11 * notice, this list of conditions and the following disclaimer in the
12 * documentation and/or other materials provided with the distribution.
13 *
14 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
15 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
16 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
17 * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
18 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
19 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
20 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
21 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
22 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
23 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
24 * SUCH DAMAGE.
25 */
26
27 #include "config.h"
28
29 #ifndef lint
30 static const char rcsid[] ATTR_UNUSED =
31 "@(#)$Id: ipa_log.c,v 1.3.2.1 2011/11/15 18:12:29 simon Exp $";
32 #endif /* !lint */
33
34 #include <sys/types.h>
35 #include <sys/stat.h>
36 #include <sys/uio.h>
37
38 #include <errno.h>
39 #include <fcntl.h>
40 #include <stdarg.h>
41 #include <stdio.h>
42 #include <stdlib.h>
43 #include <string.h>
44 #include <syslog.h>
45 #include <unistd.h>
46
47 #include "ipa_mod.h"
48
49 #include "queue.h"
50
51 #include "dlapi.h"
52 #include "confcommon.h"
53 #include "memfunc.h"
54
55 #include "ipa_ac.h"
56 #include "ipa_db.h"
57 #include "ipa_ctl.h"
58 #include "ipa_cmd.h"
59 #include "ipa_time.h"
60
61 #include "ipa_conf.h"
62 #include "ipa_log.h"
63 #include "ipa_main.h"
64 #include "ipa_rules.h"
65 #include "ipa_autorules.h"
66
67 /*
68 * To prevent possible recursion from mem_*() functions,
69 * libc memory allocation function is used in this file.
70 */
71
72 /*
73 * open_log(), logmsg() and mod_logmsg() save errno on enter
74 * and restore errno on exit, to allow external function to check
75 * value of errno, changed by some function which caused error.
76 */
77
78 #define LOG_STREAM_BUF_SIZE 1024
79
80 /*
81 * Do not call read() syscall for caught standard output and
82 * error stream more than LOG_STREAM_READ_CALLS, to get other code
83 * a chance to be executed.
84 */
85 #define LOG_STREAM_READ_CALLS 10
86
87 /* vlogmsgx() or something like this. */
88 void (*xvlogmsgx)(int, const char *, va_list);
89
90 const char *log_ident = IPA_LOG_IDENT; /* -i log_ident */
91 const char *log_file = NULL; /* -o log_file */
92
93 static int syslog_logopt; /* Syslog log options. */
94
95 static long mypid; /* PID of current process. */
96 static int log_fd = -1; /* Log file descriptor. */
97
98 static int bt_indent = 0; /* Indent for logbt(). */
99
100 #ifndef LOG_FILE_PERM
101 # define LOG_FILE_PERM (S_IRUSR|S_IWUSR|S_IRGRP) /* 0640 */
102 #endif
103
104 /* IPA_LOG_xxx -> Message */
105 static const char *const priomsg[] = {
106 "", /* 0 */
107 "W: ", /* 1 */
108 "E: " /* 2 */
109 };
110
111 /* IPA_LOG_xxx -> LOG_xxx */
112 static const int log_priority[] = {
113 LOG_INFO, /* 0 */
114 LOG_WARNING, /* 1 */
115 LOG_ERR /* 2 */
116 };
117
118 #ifdef WITH_PTHREAD
119 # define STRERRBUF_SIZE 128 /* Size of buffer for strerror_r(). */
120 #endif
121
122 /*
123 * Initialize settings for syslog only.
124 */
125 void
init_log(void)126 init_log(void)
127 {
128 if (log_file == NULL)
129 syslog_logopt = LOG_PID |
130 #ifdef LOG_ODELAY
131 LOG_ODELAY |
132 #endif
133 #ifdef LOG_NOWAIT
134 LOG_NOWAIT |
135 #endif
136 (debug ?
137 #ifdef LOG_PERROR
138 LOG_PERROR
139 #else
140 0
141 #endif
142 : LOG_CONS);
143 }
144
145 /*
146 * This function is called by modules to output their log messages.
147 */
148 void
mod_logmsg(const char * mod_name,int priority,int code,const char * format,va_list ap)149 mod_logmsg(const char *mod_name, int priority, int code, const char *format,
150 va_list ap)
151 {
152 char buf[LOG_BUF_SIZE];
153 char *msg;
154 int rv, errno_save, msg_alloced;
155
156 errno_save = errno;
157
158 msg_alloced = 0;
159 rv = vsnprintf(buf, sizeof(buf), format, ap);
160 if (rv < 0)
161 msg = "(mod_logmsg: vsnprintf failed)";
162 else if (rv < sizeof(buf))
163 msg = buf;
164 else if (rv >= sizeof(buf)) {
165 msg = malloc(++rv);
166 if (msg == NULL)
167 msg = "(mod_logmsg: malloc failed)";
168 else if (vsnprintf(msg, rv, format, ap) < 0) {
169 free(msg);
170 msg = "(mod_logmsg: vsnprintf failed)";
171 } else
172 msg_alloced = 1;
173 }
174
175 if (code != 0) {
176 errno = code;
177 logmsg(priority, "MOD %s: %s", mod_name, msg);
178 } else
179 logmsgx(priority, "MOD %s: %s", mod_name, msg);
180
181 if (msg_alloced)
182 free(msg);
183 errno = errno_save;
184 }
185
186 /*
187 * Write a message with a timestamp to the log file and to
188 * standard error if needed. If stat(2) for the opened
189 * log file failed, then try to open/create it again.
190 * If log_file is NULL, then output message only to stderr.
191 */
192 static void
log_message(const char * message)193 log_message(const char *message)
194 {
195 struct iovec iov[3];
196 struct stat statbuf;
197 time_t t;
198 int fd;
199 #ifdef WITH_PTHREAD
200 char strtimebuf[26];
201 char strerrbuf[STRERRBUF_SIZE];
202 #endif
203
204 iov[2].iov_base = "\n";
205 iov[2].iov_len = 1;
206
207 while (log_file != NULL) {
208 if (log_fd >= 0) {
209 /* Log file is opened, check if it still exist. */
210 if (stat(log_file, &statbuf) == 0)
211 break;
212 /* File does not exist. */
213 (void)close(log_fd);
214 }
215 /* Create/open log file. */
216 log_fd = open(log_file, O_WRONLY|O_APPEND|O_CREAT,
217 LOG_FILE_PERM);
218 if (log_fd >= 0)
219 break;
220 if (!debug) {
221 /*
222 * Cannot open/create log file and
223 * cannot log to stderr.
224 */
225 return;
226 }
227 iov[0].iov_base = "log_message: cannot open log file: ";
228 iov[0].iov_len = 35;
229 #ifdef WITH_PTHREAD
230 iov[1].iov_base =
231 strerror_r(errno, strerrbuf, sizeof(strerrbuf)) == 0 ?
232 strerrbuf : "(strerror_r failed)";
233 #else
234 iov[1].iov_base = strerror(errno);
235 #endif
236 iov[1].iov_len = strlen(iov[1].iov_base);
237 (void)writev(STDERR_FILENO, iov, 3);
238 break;
239 }
240
241 fd = debug ? STDERR_FILENO : log_fd;
242
243 if (time(&t) == (time_t)-1) {
244 iov[0].iov_base = "log_message: time failed: ";
245 iov[0].iov_len = 26;
246 #ifdef WITH_PTHREAD
247 iov[1].iov_base =
248 (strerror_r(errno, strerrbuf, sizeof(strerrbuf)) == 0) ?
249 strerrbuf : "(strerror_r failed)";
250 #else
251 iov[1].iov_base = strerror(errno);
252 #endif
253 iov[1].iov_len = strlen(iov[1].iov_base);
254 } else {
255 /* From SUSv3: "DDD MMM dd hh:mm:ss YYYY\n\0" */
256 #ifdef WITH_PTHREAD
257 iov[0].iov_base = ctime_r(&t, strtimebuf) + 4;
258 #else
259 iov[0].iov_base = ctime(&t) + 4;
260 #endif
261 iov[0].iov_len = strlen(iov[0].iov_base) - 1;
262 iov[1].iov_base = (char *)message;
263 iov[1].iov_len = strlen(message);
264 }
265
266 for (;;) {
267 if (writev(fd, iov, 3) < 0)
268 if (debug && fd != STDERR_FILENO) {
269 (void)close(log_fd);
270 log_fd = -1;
271 break;
272 }
273 if (debug && fd == STDERR_FILENO) {
274 fd = log_fd;
275 if (fd < 0)
276 break;
277 } else
278 break;
279 }
280 }
281
282 /*
283 * Call openlog() for syslog (real open for log descriptor is delayed).
284 */
285 void
open_log(void)286 open_log(void)
287 {
288 if (log_file == NULL) {
289 int errno_save;
290
291 errno_save = errno;
292 openlog(log_ident, syslog_logopt, LOG_USER);
293 errno = errno_save;
294 } else {
295 mypid = (long)getpid();
296 log_fd = -1;
297 }
298 }
299
300 /*
301 * Close log descriptor.
302 */
303 void
close_log(void)304 close_log(void)
305 {
306 if (log_file == NULL)
307 closelog();
308 else if (log_fd >= 0) {
309 (void)close(log_fd);
310 log_fd = -1;
311 }
312 }
313
314 /*
315 * Wrapper for log function from memfunc.c.
316 */
317 void
mvlogmsgx_wrapper(const char * format,va_list ap)318 mvlogmsgx_wrapper(const char *format, va_list ap)
319 {
320 /*
321 * Since mxxx() functions log messages when errors
322 * occurred, we simply use fixed log priority here.
323 */
324 vlogmsgx(IPA_LOG_ERR, format, ap);
325 }
326
327 /*
328 * vprintf-like function, do not output message for errno.
329 */
330 void
vlogmsgx(int priority,const char * format,va_list ap)331 vlogmsgx(int priority, const char *format, va_list ap)
332 {
333 bt_indent = 0;
334 if (log_file == NULL) {
335 #ifdef HAVE_VSYSLOG
336 vsyslog(log_priority[priority], format, ap);
337 #else
338 char buf[LOG_BUF_SIZE];
339
340 if (vsnprintf(buf, sizeof(buf), format, ap) >= 0)
341 syslog(log_priority[priority], buf);
342 #endif
343 #ifdef LOG_PERROR
344 return;
345 #endif
346 }
347
348 {
349 char buf1[LOG_BUF_SIZE];
350 char buf2[LOG_BUF_SIZE + 128];
351 char *msg1, *msg2;
352 int rv;
353 char msg1_alloced, msg2_alloced;
354
355 msg1_alloced = msg2_alloced = 0;
356 rv = vsnprintf(buf1, sizeof(buf1), format, ap);
357 if (rv < 0)
358 msg1 = "(vlogmsgx: vsnprintf failed for msg1)";
359 else if (rv < sizeof(buf1))
360 msg1 = buf1;
361 else if (rv >= sizeof(buf1)) {
362 msg1 = malloc(++rv);
363 if (msg1 == NULL)
364 msg1 = "(vlogmsgx: malloc failed for msg1)";
365 else if (vsnprintf(msg1, rv, format, ap) < 0) {
366 free(msg1);
367 msg1 = "(vlogmsgx: vsnprintf failed for msg1)";
368 } else
369 msg1_alloced = 1;
370 }
371 rv = snprintf(buf2, sizeof(buf2), " %s[%ld]: %s%s", log_ident,
372 mypid, priomsg[priority], msg1);
373 if (rv < 0)
374 msg2 = "(vlogmsgx: vsnprintf failed for msg2)";
375 else if (rv < sizeof(buf2))
376 msg2 = buf2;
377 else if (rv >= sizeof(buf2)) {
378 msg2 = malloc(++rv);
379 if (msg2 == NULL)
380 msg2 = "(vlogmsgx: malloc failed for msg2)";
381 else if (vsnprintf(msg2, rv, format, ap) < 0) {
382 free(msg2);
383 msg2 = "(vlogmsgx: vsnprintf failed for msg2)";
384 } else
385 msg2_alloced = 1;
386 }
387
388 log_message(msg2);
389
390 if (msg1_alloced)
391 free(msg1);
392 if (msg2_alloced)
393 free(msg2);
394 }
395 }
396
397 /*
398 * The same as vlogmsgx(), but output everything on stderr and
399 * output is not atomic, since this is not required.
400 */
401 void
vlogmsgx_stderr(int priority,const char * format,va_list ap)402 vlogmsgx_stderr(int priority, const char *format, va_list ap)
403 {
404 (void)fflush(stdout);
405 switch (priority) {
406 case IPA_LOG_INFO:
407 fprintf(stderr, "Info: ");
408 break;
409 case IPA_LOG_WARNING:
410 fprintf(stderr, "Warning: ");
411 break;
412 case IPA_LOG_ERR:
413 fprintf(stderr, "Error: ");
414 break;
415 }
416 vfprintf(stderr, format, ap);
417 fprintf(stderr, "\n");
418 }
419
420 /*
421 * printf-like function, do not output message for errno.
422 */
423 void
logmsgx(int priority,const char * format,...)424 logmsgx(int priority, const char *format, ...)
425 {
426 va_list ap;
427
428 va_start(ap, format);
429 vlogmsgx(priority, format, ap);
430 va_end(ap);
431 }
432
433 /*
434 * printf-like function, also output message for errno.
435 */
436 void
logmsg(int priority,const char * format,...)437 logmsg(int priority, const char *format, ...)
438 {
439 va_list ap;
440
441 if (errno == 0) {
442 va_start(ap, format);
443 vlogmsgx(priority, format, ap);
444 va_end(ap);
445 return;
446 }
447
448 {
449 char buf[LOG_BUF_SIZE];
450 char *msg;
451 int rv, errno_save, msg_alloced;
452 #ifdef WITH_PTHREAD
453 char strerrbuf[STRERRBUF_SIZE];
454 #endif
455
456 errno_save = errno;
457 msg_alloced = 0;
458 va_start(ap, format);
459 rv = vsnprintf(buf, sizeof(buf), format, ap);
460 if (rv < 0)
461 msg = "(logmsg: vsnprintf failed)";
462 else if (rv < sizeof(buf))
463 msg = buf;
464 else if (rv >= sizeof(buf)) {
465 msg = malloc(++rv);
466 if (msg == NULL)
467 msg = "(logmsg: malloc failed)";
468 else if (vsnprintf(msg, rv, format, ap) < 0) {
469 free(msg);
470 msg = "(logmsg: vsnprintf failed)";
471 } else
472 msg_alloced = 1;
473 }
474
475 va_end(ap);
476 #ifdef WITH_PTHREAD
477 if (strerror_r(errno_save, strerrbuf, sizeof(strerrbuf)) == 0)
478 logmsgx(priority, "%s: %s", msg, strerrbuf);
479 else
480 logmsgx(priority, "%s: error code %d", msg, errno_save);
481 #else
482 logmsgx(priority, "%s: %s", msg, strerror(errno_save));
483 #endif
484 if (msg_alloced)
485 free(msg);
486 errno = errno_save;
487 }
488 }
489
490 /*
491 * printf-like function for debug messages.
492 */
493 void
logdbg(const char * format,...)494 logdbg(const char *format, ...)
495 {
496 char buf[LOG_BUF_SIZE];
497 va_list ap;
498 int rv;
499
500 va_start(ap, format);
501 rv = vsnprintf(buf, sizeof(buf), format, ap);
502 va_end(ap);
503 if (rv < 0)
504 logmsg(IPA_LOG_ERR, "logdbg: vsnprintf failed");
505 else
506 logmsgx(IPA_LOG_INFO, "DEBUG: %s", buf);
507 }
508
509 /*
510 * Call xvlomsgx() which is a pointer to some vlogmsgx-like function.
511 */
512 void
xlogmsgx(int priority,const char * format,...)513 xlogmsgx(int priority, const char *format, ...)
514 {
515 va_list ap;
516
517 va_start(ap, format);
518 xvlogmsgx(priority, format, ap);
519 va_end(ap);
520 }
521
522 /*
523 * Log backtrace information.
524 */
525 void
logbt(const char * msg)526 logbt(const char *msg)
527 {
528 int indent;
529
530 indent = bt_indent;
531 logmsgx(log_file == NULL ? IPA_LOG_INFO : IPA_LOG_ERR, " %*s`- %s",
532 indent, "", msg);
533 bt_indent = indent + 2;
534 }
535
536 /*
537 * Read data from non-blocking fd and log them prepending with
538 * stream name string, interpret '\0' and '\n' as new lines, call
539 * read() syscall for fd no more than LOG_STREAM_READ_CALLS times.
540 * This function is used only by log_stdout() and log_stderr().
541 */
542 void
log_stream(int fd,const char * stream_name)543 log_stream(int fd, const char *stream_name)
544 {
545 char *ptr1, *ptr2;
546 ssize_t nread; /* Number of read bytes from last read(). */
547 size_t ngot; /* Number of valid bytes in string. */
548 size_t nleft; /* Number of not used bytes in string. */
549 unsigned int ncalls; /* Number of read() invocations. */
550 int i;
551 char string[LOG_STREAM_BUF_SIZE];
552
553 ncalls = 0;
554 ptr1 = string;
555 nleft = sizeof(string) - 1;
556 ngot = 0;
557 (void)fflush(stdout);
558 for (;;) {
559 nread = read(fd, ptr1, nleft);
560 if (nread < 0) {
561 if (errno == EAGAIN
562 #if EAGAIN != EWOULDBLOCK
563 || errno == EWOULDBLOCK
564 #endif
565 ) {
566 if (ptr1 != string)
567 logmsgx(IPA_LOG_WARNING, "*%s: %s",
568 stream_name, string);
569 } else
570 logmsg(IPA_LOG_ERR, "log_stream(%s): read",
571 stream_name);
572 break;
573 }
574 ngot += nread;
575 for (i = 0, ptr1 = ptr2 = string; i < ngot; ++ptr2, ++i)
576 switch (*ptr2) {
577 case '\n':
578 *ptr2 = '\0';
579 /* FALLTHROUGH */
580 case '\0':
581 logmsgx(IPA_LOG_WARNING, "*%s: %s",
582 stream_name, ptr1);
583 ptr1 = ptr2 + 1;
584 }
585 if (ptr1 == string) {
586 ptr1[ngot] = '\0';
587 ngot = 0;
588 nleft = sizeof(string) - 1;
589 logmsgx(IPA_LOG_WARNING, "*%s: %s", stream_name, ptr1);
590 } else if (ptr1 != ptr2) {
591 ngot = ptr2 - ptr1;
592 memcpy(string, ptr1, ngot);
593 ptr1 = string + ngot;
594 *ptr1 = '\0';
595 nleft = sizeof(string) - ngot - 1;
596 } else {
597 ptr1 = string;
598 ngot = 0;
599 nleft = sizeof(string) - 1;
600 }
601 if (++ncalls == LOG_STREAM_READ_CALLS) {
602 if (ngot != 0) /* and has '\0' in string. */
603 logmsgx(IPA_LOG_WARNING, "*%s: %s",
604 stream_name, string);
605 break;
606 }
607 }
608 }
609