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