1#ifdef HAVE_CONFIG_H 2#include "config.h" 3#endif 4 5/* ========================================================================= 6 7logger.c was written by Simon Bazley (sibaz@sibaz.com) 8 9I believe libatalk is released under the L/GPL licence. 10Just incase, it is, thats the licence I'm applying to this file. 11Netatalk 2001 (c) 12 13========================================================================= */ 14 15#include <stdio.h> 16#include <limits.h> 17#include <stdarg.h> 18#include <string.h> 19#include <stdlib.h> 20#include <syslog.h> 21#include <sys/types.h> 22#include <sys/stat.h> 23#include <fcntl.h> 24#include <sys/uio.h> 25#include <unistd.h> 26#include <sys/time.h> 27#include <time.h> 28#include <ctype.h> 29#include <errno.h> 30#include <stdbool.h> 31 32#include <atalk/util.h> 33#include <atalk/logger.h> 34 35#define OPEN_LOGS_AS_UID 0 36 37#define COUNT_ARRAY(array) (sizeof((array))/sizeof((array)[0])) 38 39#define MAXLOGSIZE 512 40 41#define LOGLEVEL_STRING_IDENTIFIERS { \ 42 "LOG_NOTHING", \ 43 "LOG_SEVERE", \ 44 "LOG_ERROR", \ 45 "LOG_WARN", \ 46 "LOG_NOTE", \ 47 "LOG_INFO", \ 48 "LOG_DEBUG", \ 49 "LOG_DEBUG6", \ 50 "LOG_DEBUG7", \ 51 "LOG_DEBUG8", \ 52 "LOG_DEBUG9", \ 53 "LOG_MAXDEBUG"} 54 55/* these are the string identifiers corresponding to each logtype */ 56#define LOGTYPE_STRING_IDENTIFIERS { \ 57 "Default", \ 58 "Logger", \ 59 "CNID", \ 60 "AFPDaemon", \ 61 "DSI", \ 62 "ATalkDaemon", \ 63 "PAPDaemon", \ 64 "UAMS", \ 65 "end_of_list_marker"} \ 66 67/* ========================================================================= 68 Config 69 ========================================================================= */ 70 71/* Main log config container */ 72log_config_t log_config = { 0 }; 73 74/* Default log config: log nothing to files. 75 0: set ? 76 0: syslog ? 77 -1: logfiles fd 78 log_none: no logging by default 79 0: Display options */ 80#define DEFAULT_LOG_CONFIG {0, 0, -1, log_none, 0} 81 82UAM_MODULE_EXPORT logtype_conf_t type_configs[logtype_end_of_list_marker] = { 83 DEFAULT_LOG_CONFIG, /* logtype_default */ 84 DEFAULT_LOG_CONFIG, /* logtype_logger */ 85 DEFAULT_LOG_CONFIG, /* logtype_cnid */ 86 DEFAULT_LOG_CONFIG, /* logtype_afpd */ 87 DEFAULT_LOG_CONFIG, /* logtype_dsi */ 88 DEFAULT_LOG_CONFIG, /* logtype_atalkd */ 89 DEFAULT_LOG_CONFIG, /* logtype_papd */ 90 DEFAULT_LOG_CONFIG /* logtype_uams */ 91}; 92 93/* We use this in order to track the last n log messages in order to prevent flooding */ 94#define LOG_FLOODING_MINCOUNT 5 /* this controls after how many consecutive messages must be detected 95 before we start to hide them */ 96#define LOG_FLOODING_MAXCOUNT 1000 /* this controls after how many consecutive messages we force a 97 "repeated x times" message */ 98#define LOG_FLOODING_ARRAY_SIZE 3 /* this contols how many messages in flow we track */ 99struct log_flood_entry { 100 int count; 101 unsigned int hash; 102}; 103static struct log_flood_entry log_flood_array[LOG_FLOODING_ARRAY_SIZE]; 104static int log_flood_entries; 105 106/* These are used by the LOG macro to store __FILE__ and __LINE__ */ 107static const char *log_src_filename; 108static int log_src_linenumber; 109 110/* Array to store text to list given a log type */ 111static const char *arr_logtype_strings[] = LOGTYPE_STRING_IDENTIFIERS; 112static const unsigned int num_logtype_strings = COUNT_ARRAY(arr_logtype_strings); 113 114/* Array for charachters representing log severity in the log file */ 115static const char arr_loglevel_chars[] = {'-','S', 'E', 'W', 'N', 'I', 'D'}; 116static const unsigned int num_loglevel_chars = COUNT_ARRAY(arr_loglevel_chars); 117 118static const char *arr_loglevel_strings[] = LOGLEVEL_STRING_IDENTIFIERS; 119static const unsigned int num_loglevel_strings = COUNT_ARRAY(arr_loglevel_strings); 120 121/* ========================================================================= 122 Internal function definitions 123 ========================================================================= */ 124 125/* Hash a log message */ 126static unsigned int hash_message(const char *message) 127{ 128 const char *p = message; 129 unsigned int hash = 0, i = 7; 130 131 while (*p) { 132 hash += *p * i; 133 i++; 134 p++; 135 } 136 return hash; 137} 138 139/* 140 * If filename == NULL its for syslog logging, otherwise its for file-logging. 141 * "unsetuplog" calls with loglevel == NULL. 142 * loglevel == NULL means: 143 * if logtype == default 144 * disable logging 145 * else 146 * set to default logging 147 */ 148static void setuplog_internal(const char *loglevel, const char *logtype, const char *filename) 149{ 150 unsigned int typenum, levelnum; 151 152 /* Parse logtype */ 153 for( typenum=0; typenum < num_logtype_strings; typenum++) { 154 if (strcasecmp(logtype, arr_logtype_strings[typenum]) == 0) 155 break; 156 } 157 if (typenum >= num_logtype_strings) { 158 return; 159 } 160 161 /* Parse loglevel */ 162 if (loglevel == NULL) { 163 levelnum = 0; 164 } else { 165 for(levelnum=1; levelnum < num_loglevel_strings; levelnum++) { 166 if (strcasecmp(loglevel, arr_loglevel_strings[levelnum]) == 0) 167 break; 168 } 169 if (levelnum >= num_loglevel_strings) { 170 return; 171 } 172 } 173 174 /* is this a syslog setup or a filelog setup ? */ 175 if (filename == NULL) { 176 /* must be syslog */ 177 syslog_setup(levelnum, 178 typenum, 179 logoption_ndelay | logoption_pid, 180 logfacility_daemon); 181 } else { 182 /* this must be a filelog */ 183 log_setup(filename, levelnum, typenum); 184 } 185 186 return; 187} 188 189static void generate_message_details(char *message_details_buffer, 190 int message_details_buffer_length, 191 int display_options, 192 enum loglevels loglevel, enum logtypes logtype) 193{ 194 char *ptr = message_details_buffer; 195 int templen; 196 int len = message_details_buffer_length; 197 struct timeval tv; 198 pid_t pid; 199 200 *ptr = 0; 201 202 /* Print time */ 203 gettimeofday(&tv, NULL); 204 strftime(ptr, len, "%b %d %H:%M:%S.", localtime(&tv.tv_sec)); 205 templen = strlen(ptr); 206 len -= templen; 207 ptr += templen; 208 209 templen = snprintf(ptr, len, "%06u ", (int)tv.tv_usec); 210 if (templen == -1 || templen >= len) 211 return; 212 213 len -= templen; 214 ptr += templen; 215 216 /* Process name && PID */ 217 pid = getpid(); 218 templen = snprintf(ptr, len, "%s[%d]", log_config.processname, pid); 219 if (templen == -1 || templen >= len) 220 return; 221 len -= templen; 222 ptr += templen; 223 224 /* Source info ? */ 225 if ( ! (display_options & logoption_nsrcinfo)) { 226 char *basename = strrchr(log_src_filename, '/'); 227 if (basename) 228 templen = snprintf(ptr, len, " {%s:%d}", basename + 1, log_src_linenumber); 229 else 230 templen = snprintf(ptr, len, " {%s:%d}", log_src_filename, log_src_linenumber); 231 if (templen == -1 || templen >= len) 232 return; 233 len -= templen; 234 ptr += templen; 235 } 236 237 /* Errorlevel */ 238 if (loglevel >= (num_loglevel_chars - 1)) 239 templen = snprintf(ptr, len, " (D%d:", loglevel - 1); 240 else 241 templen = snprintf(ptr, len, " (%c:", arr_loglevel_chars[loglevel]); 242 243 if (templen == -1 || templen >= len) 244 return; 245 len -= templen; 246 ptr += templen; 247 248 /* Errortype */ 249 if (logtype<num_logtype_strings) { 250 templen = snprintf(ptr, len, "%s", arr_logtype_strings[logtype]); 251 if (templen == -1 || templen >= len) 252 return; 253 len -= templen; 254 ptr += templen; 255 } 256 257 strncat(ptr, "): ", len); 258 ptr[len -1] = 0; 259} 260 261static int get_syslog_equivalent(enum loglevels loglevel) 262{ 263 switch (loglevel) 264 { 265 /* The question is we know how bad it is for us, 266 but how should that translate in the syslogs? */ 267 case 1: /* severe */ 268 return LOG_ERR; 269 case 2: /* error */ 270 return LOG_ERR; 271 case 3: /* warning */ 272 return LOG_WARNING; 273 case 4: /* note */ 274 return LOG_NOTICE; 275 case 5: /* information */ 276 return LOG_INFO; 277 default: /* debug */ 278 return LOG_DEBUG; 279 } 280} 281 282/* ========================================================================= 283 Global function definitions 284 ========================================================================= */ 285 286void log_init(void) 287{ 288 syslog_setup(log_info, 289 logtype_default, 290 logoption_ndelay | logoption_pid, 291 logfacility_daemon); 292} 293 294void log_setup(const char *filename, enum loglevels loglevel, enum logtypes logtype) 295{ 296 uid_t process_uid; 297 298 if (loglevel == 0) { 299 /* Disable */ 300 if (type_configs[logtype].set) { 301 if (type_configs[logtype].fd != -1) 302 close(type_configs[logtype].fd); 303 type_configs[logtype].fd = -1; 304 type_configs[logtype].level = -1; 305 type_configs[logtype].set = false; 306 307 /* if disabling default also set all "default using" levels to 0 */ 308 if (logtype == logtype_default) { 309 while (logtype != logtype_end_of_list_marker) { 310 if ( ! (type_configs[logtype].set)) 311 type_configs[logtype].level = -1; 312 logtype++; 313 } 314 } 315 } 316 return; 317 } 318 319 /* Safety check */ 320 if (NULL == filename) 321 return; 322 323 /* Resetting existing config ? */ 324 if (type_configs[logtype].set) { 325 if (type_configs[logtype].fd != -1) 326 close(type_configs[logtype].fd); 327 type_configs[logtype].fd = -1; 328 type_configs[logtype].level = -1; 329 type_configs[logtype].set = false; 330 type_configs[logtype].syslog = false; 331 332 /* Reset configs using default */ 333 if (logtype == logtype_default) { 334 int typeiter = 0; 335 while (typeiter != logtype_end_of_list_marker) { 336 if (type_configs[typeiter].set == false) { 337 type_configs[typeiter].level = -1; 338 type_configs[typeiter].syslog = false; 339 } 340 typeiter++; 341 } 342 } 343 } 344 345 /* Set new values */ 346 type_configs[logtype].level = loglevel; 347 348 /* Open log file as OPEN_LOGS_AS_UID*/ 349 350 /* Is it /dev/tty ? */ 351 if (strcmp(filename, "/dev/tty") == 0) { 352 type_configs[logtype].fd = 1; /* stdout */ 353 354 /* Does it end in "XXXXXX" ? debug reguest via SIGINT */ 355 } else if (strcmp(filename + strlen(filename) - 6, "XXXXXX") == 0) { 356 char *tmp = strdup(filename); 357 type_configs[logtype].fd = mkstemp(tmp); 358 free(tmp); 359 360 } else { 361 process_uid = geteuid(); 362 if (process_uid) { 363 if (seteuid(OPEN_LOGS_AS_UID) == -1) { 364 process_uid = 0; 365 } 366 } 367 type_configs[logtype].fd = open(filename, 368 O_CREAT | O_WRONLY | O_APPEND, 369 S_IRUSR | S_IWUSR | S_IRGRP | S_IROTH); 370 if (process_uid) { 371 if (seteuid(process_uid) == -1) { 372 LOG(log_error, logtype_logger, "can't seteuid back %s", strerror(errno)); 373 exit(EXITERR_SYS); 374 } 375 } 376 } 377 378 /* Check for error opening/creating logfile */ 379 if (type_configs[logtype].fd == -1) { 380 type_configs[logtype].level = -1; 381 type_configs[logtype].set = false; 382 return; 383 } 384 385 fcntl(type_configs[logtype].fd, F_SETFD, FD_CLOEXEC); 386 type_configs[logtype].set = true; 387 log_config.inited = true; 388 389 /* Here's how we make it possible to LOG to a logtype like "logtype_afpd" */ 390 /* which then uses the default logtype setup if it isn't setup itself: */ 391 /* we just copy the loglevel from default to all logtypes that are not setup. */ 392 /* In "make_log_entry" we then check for the logtypes if they arent setup */ 393 /* and use default then. We must provide accessible values for all logtypes */ 394 /* in order to make it easy and fast to check the loglevels in the LOG macro! */ 395 396 if (logtype == logtype_default) { 397 int typeiter = 0; 398 while (typeiter != logtype_end_of_list_marker) { 399 if ( ! (type_configs[typeiter].set)) 400 type_configs[typeiter].level = loglevel; 401 typeiter++; 402 } 403 } 404 405 LOG(log_debug, logtype_logger, "Setup file logging: type: %s, level: %s, file: %s", 406 arr_logtype_strings[logtype], arr_loglevel_strings[loglevel], filename); 407} 408 409/* Setup syslog logging */ 410void syslog_setup(int loglevel, enum logtypes logtype, int display_options, int facility) 411{ 412 /* 413 * FIXME: 414 * this currently doesn't care if logtype is already logging to a file. 415 * Fortunately currently there's no way a user could trigger this as afpd.conf 416 * is not re-read on SIGHUP. 417 */ 418 419 type_configs[logtype].level = loglevel; 420 type_configs[logtype].set = true; 421 type_configs[logtype].syslog = true; 422 log_config.syslog_display_options = display_options; 423 log_config.syslog_facility = facility; 424 425 /* Setting default logging? Then set all logtype not set individually */ 426 if (logtype == logtype_default) { 427 int typeiter = 0; 428 while (typeiter != logtype_end_of_list_marker) { 429 if ( ! (type_configs[typeiter].set)) { 430 type_configs[typeiter].level = loglevel; 431 type_configs[typeiter].syslog = true; 432 } 433 typeiter++; 434 } 435 } 436 437 log_config.inited = 1; 438 439 LOG(log_info, logtype_logger, "Set syslog logging to level: %s", 440 arr_loglevel_strings[loglevel]); 441} 442 443void log_close(void) 444{ 445} 446 447/* This function sets up the processname */ 448void set_processname(const char *processname) 449{ 450 strncpy(log_config.processname, processname, 15); 451 log_config.processname[15] = 0; 452} 453 454/* Called by the LOG macro for syslog messages */ 455static void make_syslog_entry(enum loglevels loglevel, enum logtypes logtype _U_, char *message) 456{ 457 if ( !log_config.syslog_opened ) { 458 openlog(log_config.processname, 459 log_config.syslog_display_options, 460 log_config.syslog_facility); 461 log_config.syslog_opened = true; 462 } 463 464 syslog(get_syslog_equivalent(loglevel), "%s", message); 465} 466 467/* ------------------------------------------------------------------------- 468 make_log_entry has 1 main flaws: 469 The message in its entirity, must fit into the tempbuffer. 470 So it must be shorter than MAXLOGSIZE 471 ------------------------------------------------------------------------- */ 472void make_log_entry(enum loglevels loglevel, enum logtypes logtype, 473 const char *file, int line, char *message, ...) 474{ 475 /* fn is not reentrant but is used in signal handler 476 * with LOGGER it's a little late source name and line number 477 * are already changed. */ 478 static int inlog = 0; 479 int fd, len; 480 char temp_buffer[MAXLOGSIZE]; 481 char log_details_buffer[MAXLOGSIZE]; 482 va_list args; 483 struct iovec iov[2]; 484 int i,j; 485 if (inlog) 486 return; 487 488 inlog = 1; 489 490 if (!log_config.inited) { 491 log_init(); 492 } 493 494 if (type_configs[logtype].syslog) { 495 if (type_configs[logtype].level >= loglevel) { 496 /* Initialise the Messages and send it to syslog */ 497 va_start(args, message); 498 vsnprintf(temp_buffer, MAXLOGSIZE -1, message, args); 499 va_end(args); 500 temp_buffer[MAXLOGSIZE -1] = 0; 501 make_syslog_entry(loglevel, logtype, temp_buffer); 502 } 503 inlog = 0; 504 return; 505 } 506 507 /* logging to a file */ 508 509 log_src_filename = file; 510 log_src_linenumber = line; 511 512 /* Check if requested logtype is setup */ 513 if (type_configs[logtype].set) 514 /* Yes */ 515 fd = type_configs[logtype].fd; 516 else 517 /* No: use default */ 518 fd = type_configs[logtype_default].fd; 519 520 if (fd < 0) { 521 /* no where to send the output, give up */ 522 goto exit; 523 } 524 525 /* Initialise the Messages */ 526 va_start(args, message); 527 len = vsnprintf(temp_buffer, MAXLOGSIZE -1, message, args); 528 va_end(args); 529 530 /* Append \n */ 531 if (len ==-1 || len >= MAXLOGSIZE -1) { 532 /* vsnprintf hit the buffer size*/ 533 temp_buffer[MAXLOGSIZE-2] = '\n'; 534 temp_buffer[MAXLOGSIZE-1] = 0; 535 } 536 else { 537 temp_buffer[len] = '\n'; 538 temp_buffer[len+1] = 0; 539 } 540 541 if (type_configs[logtype].level >= log_debug) 542 goto log; /* bypass flooding checks */ 543 544 /* Prevent flooding: hash the message and check if we got the same one recently */ 545 int hash = hash_message(temp_buffer) + log_src_linenumber; 546 547 /* Search for the same message by hash */ 548 for (i = log_flood_entries - 1; i >= 0; i--) { 549 if (log_flood_array[i].hash == hash) { 550 551 /* found same message */ 552 log_flood_array[i].count++; 553 554 /* Check if that message has reached LOG_FLOODING_MAXCOUNT */ 555 if (log_flood_array[i].count >= LOG_FLOODING_MAXCOUNT) { 556 /* yes, log it and remove from array */ 557 558 /* reusing log_details_buffer */ 559 sprintf(log_details_buffer, "message repeated %i times\n", 560 LOG_FLOODING_MAXCOUNT - 1); 561 write(fd, log_details_buffer, strlen(log_details_buffer)); 562 563 if ((i + 1) == LOG_FLOODING_ARRAY_SIZE) { 564 /* last array element, just decrement count */ 565 log_flood_entries--; 566 goto exit; 567 } 568 /* move array elements down */ 569 for (j = i + 1; j != LOG_FLOODING_ARRAY_SIZE ; j++) 570 log_flood_array[j-1] = log_flood_array[j]; 571 log_flood_entries--; 572 } 573 574 if (log_flood_array[i].count < LOG_FLOODING_MINCOUNT) 575 /* log it */ 576 goto log; 577 /* discard it */ 578 goto exit; 579 } /* if */ 580 } /* for */ 581 582 /* No matching message found, add this message to array*/ 583 if (log_flood_entries == LOG_FLOODING_ARRAY_SIZE) { 584 /* array is full, discard oldest entry printing "message repeated..." if count > 1 */ 585 if (log_flood_array[0].count >= LOG_FLOODING_MINCOUNT) { 586 /* reusing log_details_buffer */ 587 sprintf(log_details_buffer, "message repeated %i times\n", 588 log_flood_array[0].count - LOG_FLOODING_MINCOUNT + 1); 589 write(fd, log_details_buffer, strlen(log_details_buffer)); 590 } 591 for (int i = 1; i < LOG_FLOODING_ARRAY_SIZE; i++) { 592 log_flood_array[i-1] = log_flood_array[i]; 593 } 594 log_flood_entries--; 595 } 596 log_flood_array[log_flood_entries].count = 1; 597 log_flood_array[log_flood_entries].hash = hash; 598 log_flood_entries++; 599 600log: 601 if ( ! log_config.console) { 602 generate_message_details(log_details_buffer, sizeof(log_details_buffer), 603 type_configs[logtype].set ? 604 type_configs[logtype].display_options : 605 type_configs[logtype_default].display_options, 606 loglevel, logtype); 607 608 /* If default wasnt setup its fd is -1 */ 609 iov[0].iov_base = log_details_buffer; 610 iov[0].iov_len = strlen(log_details_buffer); 611 iov[1].iov_base = temp_buffer; 612 iov[1].iov_len = strlen(temp_buffer); 613 writev( fd, iov, 2); 614 } else { 615 write(fd, temp_buffer, strlen(temp_buffer)); 616 } 617 618exit: 619 inlog = 0; 620} 621 622 623void setuplog(const char *logstr) 624{ 625 char *ptr, *ptrbak, *logtype, *loglevel = NULL, *filename = NULL; 626 ptr = strdup(logstr); 627 ptrbak = ptr; 628 629 /* logtype */ 630 logtype = ptr; 631 632 /* get loglevel */ 633 ptr = strpbrk(ptr, " \t"); 634 if (ptr) { 635 *ptr++ = 0; 636 while (*ptr && isspace(*ptr)) 637 ptr++; 638 loglevel = ptr; 639 640 /* get filename */ 641 ptr = strpbrk(ptr, " \t"); 642 if (ptr) { 643 *ptr++ = 0; 644 while (*ptr && isspace(*ptr)) 645 ptr++; 646 } 647 filename = ptr; 648 if (filename && *filename == 0) 649 filename = NULL; 650 } 651 652 /* finally call setuplog, filename can be NULL */ 653 setuplog_internal(loglevel, logtype, filename); 654 655 free(ptrbak); 656} 657 658void unsetuplog(const char *logstr) 659{ 660 char *str, *logtype, *filename; 661 662 str = strdup(logstr); 663 664 /* logtype */ 665 logtype = str; 666 667 /* get filename, can be NULL */ 668 strtok(str, " \t"); 669 filename = strtok(NULL, " \t"); 670 671 /* finally call setuplog, filename can be NULL */ 672 setuplog_internal(NULL, str, filename); 673 674 free(str); 675} 676