1 /*
2 * aprsc
3 *
4 * (c) Heikki Hannikainen, OH7LZB <hessu@hes.iki.fi>
5 *
6 * This program is licensed under the BSD license, which can be found
7 * in the file LICENSE.
8 *
9 */
10
11 /*
12 * log.c
13 *
14 * logging facility with configurable log levels and
15 * logging destinations
16 */
17
18 #include <stdio.h>
19 #include <stdarg.h>
20 #include <syslog.h>
21 #include <unistd.h>
22 #include <time.h>
23 #include <sys/time.h>
24 #include <string.h>
25 #include <pthread.h>
26 #include <sys/types.h>
27 #include <sys/stat.h>
28 #include <sys/file.h>
29 #include <fcntl.h>
30 #include <errno.h>
31
32 #include "hlog.h"
33 #include "hmalloc.h"
34 #include "rwlock.h"
35
36 int log_dest = L_DEFDEST; /* Logging destination */
37 int log_level = LOG_INFO; /* Logging level */
38 int log_facility = LOG_DAEMON; /* Logging facility */
39 char *log_name = NULL; /* Logging name */
40
41 char *log_basename = NULL; /* Derived from log_name */
42 char *log_dir = NULL; /* Access log directory */
43 char *log_fname = NULL; /* Access log file name */
44 int log_file = -1; /* If logging to a file, the file name */
45 rwlock_t log_file_lock = RWL_INITIALIZER;
46
47 char accesslog_basename[] = "aprsc.access.log";
48 char *accesslog_dir = NULL; /* Access log directory */
49 char *accesslog_fname = NULL; /* Access log file name */
50 int accesslog_file = -1; /* Access log fd */
51 rwlock_t accesslog_lock = RWL_INITIALIZER;
52
53 int log_rotate_size = 0; /* Rotate log when it reaches a given size */
54 int log_rotate_num = 5; /* How many logs to keep around */
55
56 char *log_levelnames[] = {
57 "EMERG",
58 "ALERT",
59 "CRIT",
60 "ERROR",
61 "WARNING",
62 "NOTICE",
63 "INFO",
64 "DEBUG",
65 NULL
66 };
67
68 char *log_destnames[] = {
69 "none",
70 "stderr",
71 "syslog",
72 "file",
73 NULL
74 };
75
76 /*
77 * Quote a string, C-style. dst will be null-terminated, always.
78 */
79
str_quote(char * dst,int dst_len,const char * src,int src_len)80 static int str_quote(char *dst, int dst_len, const char *src, int src_len)
81 {
82 int si;
83 int di = 0;
84 int dst_use_len = dst_len - 2; /* leave space for terminating NUL and escaping an escape */
85 unsigned char c;
86
87 for (si = 0; si < src_len; si++) {
88 if (di >= dst_use_len)
89 break;
90
91 c = (unsigned char) src[si];
92
93 /* printable ASCII */
94 if (c >= 0x20 && c < 0x7f) {
95 /* escape the escape (space reserved already) */
96 if (c == '\\')
97 dst[di++] = '\\';
98
99 dst[di++] = c;
100 continue;
101 }
102
103 /* hex escape, is going to take more space */
104 if (di >= dst_use_len - 4)
105 break;
106
107 dst[di++] = '\\';
108 dst[di++] = 'x';
109 di += snprintf(dst + di, 3, "%.2X", c);
110 }
111
112 dst[di++] = 0;
113
114 return di;
115 }
116
117 /*
118 * Append a formatted string to a dynamically allocated string
119 */
120
str_append(char * s,const char * fmt,...)121 char *str_append(char *s, const char *fmt, ...)
122 {
123 va_list args;
124 char buf[LOG_LEN];
125 int len;
126 char *ret;
127
128 va_start(args, fmt);
129 vsnprintf(buf, LOG_LEN, fmt, args);
130 va_end(args);
131 buf[LOG_LEN-1] = 0;
132
133 len = strlen(s);
134 ret = hrealloc(s, len + strlen(buf) + 1);
135 strcpy(ret + len, buf);
136
137 return ret;
138 }
139
140 /*
141 * Pick a log level
142 */
143
pick_loglevel(char * s,char ** names)144 int pick_loglevel(char *s, char **names)
145 {
146 int i;
147
148 for (i = 0; (names[i]); i++)
149 if (!strcasecmp(s, names[i]))
150 return i;
151
152 return -1;
153 }
154
155 /*
156 * Open log
157 */
158
open_log(char * name,int reopen)159 int open_log(char *name, int reopen)
160 {
161 if (!reopen)
162 rwl_wrlock(&log_file_lock);
163
164 if (log_name)
165 hfree(log_name);
166
167 if (!(log_name = hstrdup(name))) {
168 fprintf(stderr, "aprsc logger: out of memory!\n");
169 exit(1);
170 }
171
172 if (log_basename)
173 hfree(log_basename);
174
175 log_basename = hmalloc(strlen(log_name) + 5);
176 sprintf(log_basename, "%s.log", log_name);
177
178 if (log_dest == L_SYSLOG)
179 openlog(name, LOG_NDELAY|LOG_PID, log_facility);
180
181 if (log_dest == L_FILE) {
182 if (log_fname)
183 hfree(log_fname);
184
185 log_fname = hmalloc(strlen(log_dir) + strlen(log_basename) + 2);
186 sprintf(log_fname, "%s/%s", log_dir, log_basename);
187
188 log_file = open(log_fname, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);
189 if (log_file < 0) {
190 fprintf(stderr, "aprsc logger: Could not open %s: %s\n", log_fname, strerror(errno));
191 exit(1);
192 }
193 }
194
195 rwl_wrunlock(&log_file_lock);
196
197 if (log_dest == L_FILE)
198 hlog(LOG_DEBUG, "Log file %s %sopened on fd %d", log_fname, (reopen) ? "re" : "", log_file);
199
200 return 0;
201 }
202
203 /*
204 * Close log
205 */
206
close_log(int reopen)207 int close_log(int reopen)
208 {
209 hlog(LOG_DEBUG, "close_log");
210
211 char *s = NULL;
212 if (log_name)
213 s = hstrdup(log_name);
214
215 rwl_wrlock(&log_file_lock);
216
217 if (log_name) {
218 hfree(log_name);
219 log_name = NULL;
220 }
221
222 if (log_dest == L_SYSLOG) {
223 closelog();
224 } else if (log_dest == L_FILE) {
225 if (log_file >= 0) {
226 if (close(log_file))
227 fprintf(stderr, "aprsc logger: Could not close log file %s: %s\n", log_fname, strerror(errno));
228 log_file = -1;
229 }
230 if (log_fname) {
231 hfree(log_fname);
232 log_fname = NULL;
233 }
234 }
235
236 if (reopen && s)
237 open_log(s, 1);
238
239 if (!reopen)
240 rwl_wrunlock(&log_file_lock);
241
242 if (s)
243 hfree(s);
244
245 return 0;
246 }
247
248 /*
249 * Rotate the log file
250 */
251
rotate_log(void)252 int rotate_log(void)
253 {
254 char *tmp;
255 int i;
256 char *r1, *r2;
257
258 if (rwl_trywrlock(&log_file_lock)) {
259 fprintf(stderr, "failed to wrlock log_file_lock for rotation\n");
260 return 0;
261 }
262
263 // check if still oversize and not rotated by another thread
264 off_t l = lseek(log_file, 0, SEEK_CUR);
265 if (l < log_rotate_size) {
266 rwl_wrunlock(&log_file_lock);
267 return 0;
268 }
269
270 // rename
271 tmp = hmalloc(strlen(log_fname) + 6);
272 sprintf(tmp, "%s.tmp", log_fname);
273 if (rename(log_fname, tmp) != 0) {
274 fprintf(stderr, "aprsc logger: Failed to rename %s to %s: %s\n", log_fname, tmp, strerror(errno));
275 // continue anyway, try to reopen
276 }
277
278 // reopen
279 if (close(log_file))
280 fprintf(stderr, "aprsc logger: Could not close log file %s: %s\n", log_fname, strerror(errno));
281
282 log_file = open(log_fname, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);
283 if (log_file < 0) {
284 fprintf(stderr, "aprsc logger: Could not open %s: %s\n", log_fname, strerror(errno));
285 log_file = -1;
286 }
287
288 rwl_wrunlock(&log_file_lock);
289
290 // do the rest of the rotation
291 r1 = hmalloc(strlen(log_fname) + 16);
292 r2 = hmalloc(strlen(log_fname) + 16);
293
294 for (i = log_rotate_num-1; i > 0; i--) {
295 sprintf(r1, "%s.%d", log_fname, i-1);
296 sprintf(r2, "%s.%d", log_fname, i);
297 if (rename(r1, r2) != 0 && errno != ENOENT) {
298 fprintf(stderr, "rename %s => %s failed:%s\n", r1, r2, strerror(errno));
299 }
300 }
301
302 if (rename(tmp, r1) != 0) {
303 fprintf(stderr, "aprsc logger: Failed to rename %s to %s: %s\n", tmp, r1, strerror(errno));
304 }
305
306 hfree(tmp);
307 hfree(r1);
308 hfree(r2);
309
310 return 0;
311 }
312
hlog_write(int priority,const char * s)313 static int hlog_write(int priority, const char *s)
314 {
315 struct tm lt;
316 struct timeval tv;
317 char wb[LOG_LEN];
318 int len, w;
319
320 gettimeofday(&tv, NULL);
321 gmtime_r(&tv.tv_sec, <);
322
323 if (log_dest & L_STDERR) {
324 rwl_rdlock(&log_file_lock);
325 fprintf(stderr, "%4d/%02d/%02d %02d:%02d:%02d.%06d %s[%d:%lx] %s: %s\n",
326 lt.tm_year + 1900, lt.tm_mon + 1, lt.tm_mday, lt.tm_hour, lt.tm_min, lt.tm_sec, (int)tv.tv_usec,
327 (log_name) ? log_name : "aprsc", (int)getpid(), (unsigned long int)pthread_self(), log_levelnames[priority], s);
328 rwl_rdunlock(&log_file_lock);
329
330 }
331
332 if ((log_dest & L_FILE) && (log_file >= 0)) {
333 len = snprintf(wb, LOG_LEN, "%4d/%02d/%02d %02d:%02d:%02d.%06d %s[%d:%lx] %s: %s\n",
334 lt.tm_year + 1900, lt.tm_mon + 1, lt.tm_mday, lt.tm_hour, lt.tm_min, lt.tm_sec, (int)tv.tv_usec,
335 (log_name) ? log_name : "aprsc", (int)getpid(), (unsigned long int)pthread_self(), log_levelnames[priority], s);
336 if (len >= LOG_LEN) {
337 len = LOG_LEN-1; // Truncated! Do not write out the NUL byte in the end.
338 wb[LOG_LEN-2] = '\n'; // Do write out a newline which was truncated.
339 }
340
341 wb[LOG_LEN-1] = 0;
342 rwl_rdlock(&log_file_lock);
343 if ((w = write(log_file, wb, len)) != len)
344 fprintf(stderr, "aprsc logger: Could not write to %s (fd %d): %s\n", log_fname, log_file, strerror(errno));
345 rwl_rdunlock(&log_file_lock);
346
347 if (log_rotate_size) {
348 off_t l = lseek(log_file, 0, SEEK_CUR);
349 if (l >= log_rotate_size) {
350 rotate_log();
351 }
352 }
353
354 }
355
356 if (log_dest & L_SYSLOG) {
357 rwl_rdlock(&log_file_lock);
358 syslog(priority, "%s: %s", log_levelnames[priority], s);
359 rwl_rdunlock(&log_file_lock);
360 }
361
362 return 1;
363 }
364
365 /*
366 * Log a message with a packet (will be quoted)
367 */
368
hlog(int priority,const char * fmt,...)369 int hlog(int priority, const char *fmt, ...)
370 {
371 va_list args;
372 char s[LOG_LEN];
373
374 if (priority > 7)
375 priority = 7;
376 else if (priority < 0)
377 priority = 0;
378
379 if (priority > log_level)
380 return 0;
381
382 va_start(args, fmt);
383 vsnprintf(s, LOG_LEN, fmt, args);
384 va_end(args);
385
386 return hlog_write(priority, s);
387 }
388
389
390 /*
391 * Log a message, with a packet in the end.
392 * Packet will be quoted.
393 */
394
hlog_packet(int priority,const char * packet,int packetlen,const char * fmt,...)395 int hlog_packet(int priority, const char *packet, int packetlen, const char *fmt, ...)
396 {
397 va_list args;
398 char s[LOG_LEN];
399 int l;
400
401 if (priority > 7)
402 priority = 7;
403 else if (priority < 0)
404 priority = 0;
405
406 if (priority > log_level)
407 return 0;
408
409 va_start(args, fmt);
410 l = vsnprintf(s, LOG_LEN, fmt, args);
411 va_end(args);
412
413 str_quote(s + l, LOG_LEN - l, packet, packetlen);
414
415 return hlog_write(priority, s);
416 }
417
418 /*
419 * Open access log
420 */
421
accesslog_open(char * logd,int reopen)422 int accesslog_open(char *logd, int reopen)
423 {
424 if (!reopen)
425 rwl_wrlock(&accesslog_lock);
426
427 if (accesslog_fname)
428 hfree(accesslog_fname);
429
430 if (accesslog_dir)
431 hfree(accesslog_dir);
432
433 accesslog_dir = hstrdup(logd);
434 accesslog_fname = hmalloc(strlen(accesslog_dir) + strlen(accesslog_basename) + 2);
435 sprintf(accesslog_fname, "%s/%s", accesslog_dir, accesslog_basename);
436
437 accesslog_file = open(accesslog_fname, O_WRONLY|O_CREAT|O_APPEND, S_IRUSR|S_IWUSR|S_IRGRP);
438 if (accesslog_file < 0)
439 hlog(LOG_CRIT, "Could not open %s: %s", accesslog_fname, strerror(errno));
440
441 rwl_wrunlock(&accesslog_lock);
442
443 return accesslog_file;
444 }
445
446 /*
447 * Close access log
448 */
449
accesslog_close(char * reopenpath)450 int accesslog_close(char *reopenpath)
451 {
452 hlog(LOG_DEBUG, "Closing access log...");
453 rwl_wrlock(&accesslog_lock);
454 hlog(LOG_DEBUG, "Closing access log, got lock");
455
456 if (close(accesslog_file))
457 hlog(LOG_CRIT, "Could not close %s: %s", accesslog_fname, strerror(errno));
458 hfree(accesslog_fname);
459 hfree(accesslog_dir);
460 accesslog_fname = accesslog_dir = NULL;
461 accesslog_file = -1;
462
463 if (reopenpath) {
464 return accesslog_open(reopenpath, 1);
465 } else {
466 rwl_wrunlock(&accesslog_lock);
467 return 0;
468 }
469 }
470
471 /*
472 * Log an access log message
473 */
474
accesslog(const char * fmt,...)475 int accesslog(const char *fmt, ...)
476 {
477 va_list args;
478 char s[LOG_LEN], wb[LOG_LEN];
479 time_t t;
480 struct tm lt;
481 int len;
482 ssize_t w;
483
484 va_start(args, fmt);
485 vsnprintf(s, LOG_LEN, fmt, args);
486 va_end(args);
487 s[LOG_LEN-1] = 0;
488
489 time(&t);
490 gmtime_r(&t, <);
491
492 len = snprintf(wb, LOG_LEN, "[%4.4d/%2.2d/%2.2d %2.2d:%2.2d:%2.2d] %s\n",
493 lt.tm_year + 1900, lt.tm_mon + 1, lt.tm_mday, lt.tm_hour, lt.tm_min, lt.tm_sec, s);
494 wb[LOG_LEN-1] = 0;
495
496 rwl_rdlock(&accesslog_lock);
497 if (accesslog_file >= 0) {
498 if ((w = write(accesslog_file, wb, len)) != len)
499 hlog(LOG_CRIT, "Could not write to %s (fd %d): %s", accesslog_fname, accesslog_file, strerror(errno));
500 } else {
501 if (accesslog_file != -666) {
502 hlog(LOG_ERR, "Access log not open, log lines are lost!");
503 accesslog_file = -666;
504 }
505 }
506 rwl_rdunlock(&accesslog_lock);
507
508 return 1;
509 }
510
511 /*
512 * Write my PID to file, after locking the pid file.
513 * Leaves the file descriptor open so that the lock will be held
514 * as long as the process is running.
515 */
516
517 int pidfile_fd = -1;
518
writepid(char * name)519 int writepid(char *name)
520 {
521 int f;
522 char s[32];
523 int l;
524
525 f = open(name, O_WRONLY|O_CREAT, S_IRUSR|S_IWUSR|S_IRGRP|S_IROTH);
526 if (f < 0) {
527 hlog(LOG_CRIT, "Could not open %s for writing: %s",
528 name, strerror(errno));
529 return 0;
530 }
531
532 pidfile_fd = f;
533
534 if (flock(f, LOCK_EX|LOCK_NB) < 0) {
535 if (errno == EWOULDBLOCK) {
536 hlog(LOG_CRIT, "Could not lock pid file file %s, another process has a lock on it. Another process running - bailing out.", name);
537 } else {
538 hlog(LOG_CRIT, "Failed to lock pid file %s: %s", name, strerror(errno));
539 }
540 return 0;
541 }
542
543 l = snprintf(s, 32, "%ld\n", (long)getpid());
544
545 if (ftruncate(f, 0) < 0) {
546 hlog(LOG_CRIT, "Could not truncate pid file %s: %s",
547 name, strerror(errno));
548 return 0;
549 }
550
551 if (write(f, s, l) != l) {
552 hlog(LOG_CRIT, "Could not write pid to %s: %s",
553 name, strerror(errno));
554 return 0;
555 }
556
557 return 1;
558 }
559
closepid(void)560 int closepid(void)
561 {
562 if (pidfile_fd >= 0) {
563 if (close(pidfile_fd) != 0) {
564 hlog(LOG_CRIT, "Could not close pid file: %s", strerror(errno));
565 return -1;
566 }
567 pidfile_fd = -1;
568 }
569
570 return 0;
571 }
572