1/* 2 * "$Id: log.c 11433 2013-11-20 18:57:44Z msweet $" 3 * 4 * Log file routines for the CUPS scheduler. 5 * 6 * Copyright 2007-2012 by Apple Inc. 7 * Copyright 1997-2007 by Easy Software Products, all rights reserved. 8 * 9 * These coded instructions, statements, and computer programs are the 10 * property of Apple Inc. and are protected by Federal copyright 11 * law. Distribution and use rights are outlined in the file "LICENSE.txt" 12 * which should have been included with this file. If this file is 13 * file is missing or damaged, see the license at "http://www.cups.org/". 14 * 15 * Contents: 16 * 17 * cupsdCheckLogFile() - Open/rotate a log file if it needs it. 18 * cupsdGetDateTime() - Returns a pointer to a date/time string. 19 * cupsdLogGSSMessage() - Log a GSSAPI error... 20 * cupsdLogJob() - Log a job message. 21 * cupsdLogMessage() - Log a message to the error log file. 22 * cupsdLogPage() - Log a page to the page log file. 23 * cupsdLogRequest() - Log an HTTP request in Common Log Format. 24 * cupsdWriteErrorLog() - Write a line to the ErrorLog. 25 * format_log_line() - Format a line for a log file. 26 */ 27 28/* 29 * Include necessary headers... 30 */ 31 32#include "cupsd.h" 33#include <stdarg.h> 34#include <syslog.h> 35 36 37/* 38 * Local globals... 39 */ 40 41static int log_linesize = 0; /* Size of line for output file */ 42static char *log_line = NULL; /* Line for output file */ 43 44#ifdef HAVE_VSYSLOG 45static const int syslevels[] = /* SYSLOG levels... */ 46 { 47 0, 48 LOG_EMERG, 49 LOG_ALERT, 50 LOG_CRIT, 51 LOG_ERR, 52 LOG_WARNING, 53 LOG_NOTICE, 54 LOG_INFO, 55 LOG_DEBUG, 56 LOG_DEBUG 57 }; 58#endif /* HAVE_VSYSLOG */ 59 60 61/* 62 * Local functions... 63 */ 64 65static int format_log_line(const char *message, va_list ap); 66 67 68/* 69 * 'cupsdCheckLogFile()' - Open/rotate a log file if it needs it. 70 */ 71 72int /* O - 1 if log file open */ 73cupsdCheckLogFile(cups_file_t **lf, /* IO - Log file */ 74 const char *logname) /* I - Log filename */ 75{ 76 char backname[1024], /* Backup log filename */ 77 filename[1024], /* Formatted log filename */ 78 *ptr; /* Pointer into filename */ 79 const char *logptr; /* Pointer into log filename */ 80 81 82 /* 83 * See if we have a log file to check... 84 */ 85 86 if (!lf || !logname || !logname[0]) 87 return (1); 88 89 /* 90 * Format the filename as needed... 91 */ 92 93 if (!*lf || 94 (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && 95 MaxLogSize > 0)) 96 { 97 /* 98 * Handle format strings... 99 */ 100 101 filename[sizeof(filename) - 1] = '\0'; 102 103 if (logname[0] != '/') 104 { 105 strlcpy(filename, ServerRoot, sizeof(filename)); 106 strlcat(filename, "/", sizeof(filename)); 107 } 108 else 109 filename[0] = '\0'; 110 111 for (logptr = logname, ptr = filename + strlen(filename); 112 *logptr && ptr < (filename + sizeof(filename) - 1); 113 logptr ++) 114 if (*logptr == '%') 115 { 116 /* 117 * Format spec... 118 */ 119 120 logptr ++; 121 if (*logptr == 's') 122 { 123 /* 124 * Insert the server name... 125 */ 126 127 strlcpy(ptr, ServerName, sizeof(filename) - (ptr - filename)); 128 ptr += strlen(ptr); 129 } 130 else 131 { 132 /* 133 * Otherwise just insert the character... 134 */ 135 136 *ptr++ = *logptr; 137 } 138 } 139 else 140 *ptr++ = *logptr; 141 142 *ptr = '\0'; 143 } 144 145 /* 146 * See if the log file is open... 147 */ 148 149 if (!*lf) 150 { 151 /* 152 * Nope, open the log file... 153 */ 154 155 if ((*lf = cupsFileOpen(filename, "a")) == NULL) 156 { 157 /* 158 * If the file is in CUPS_LOGDIR then try to create a missing directory... 159 */ 160 161 if (!strncmp(filename, CUPS_LOGDIR, strlen(CUPS_LOGDIR))) 162 { 163 /* 164 * Try updating the permissions of the containing log directory, using 165 * the log file permissions as a basis... 166 */ 167 168 int log_dir_perm = 0300 | LogFilePerm; 169 /* LogFilePerm + owner write/search */ 170 if (log_dir_perm & 0040) 171 log_dir_perm |= 0010; /* Add group search */ 172 if (log_dir_perm & 0004) 173 log_dir_perm |= 0001; /* Add other search */ 174 175 cupsdCheckPermissions(CUPS_LOGDIR, NULL, log_dir_perm, RunUser, Group, 176 1, -1); 177 178 *lf = cupsFileOpen(filename, "a"); 179 } 180 181 if (*lf == NULL) 182 { 183 syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, 184 strerror(errno)); 185 186 if (FatalErrors & CUPSD_FATAL_LOG) 187 cupsdEndProcess(getpid(), 0); 188 189 return (0); 190 } 191 } 192 193 if (strncmp(filename, "/dev/", 5)) 194 { 195 /* 196 * Change ownership and permissions of non-device logs... 197 */ 198 199 fchown(cupsFileNumber(*lf), RunUser, Group); 200 fchmod(cupsFileNumber(*lf), LogFilePerm); 201 } 202 } 203 204 /* 205 * Do we need to rotate the log? 206 */ 207 208 if (strncmp(logname, "/dev/", 5) && cupsFileTell(*lf) > MaxLogSize && 209 MaxLogSize > 0) 210 { 211 /* 212 * Rotate log file... 213 */ 214 215 cupsFileClose(*lf); 216 217 strlcpy(backname, filename, sizeof(backname)); 218 strlcat(backname, ".O", sizeof(backname)); 219 220 unlink(backname); 221 rename(filename, backname); 222 223 if ((*lf = cupsFileOpen(filename, "a")) == NULL) 224 { 225 syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename, 226 strerror(errno)); 227 228 if (FatalErrors & CUPSD_FATAL_LOG) 229 cupsdEndProcess(getpid(), 0); 230 231 return (0); 232 } 233 234 /* 235 * Change ownership and permissions of non-device logs... 236 */ 237 238 fchown(cupsFileNumber(*lf), RunUser, Group); 239 fchmod(cupsFileNumber(*lf), LogFilePerm); 240 } 241 242 return (1); 243} 244 245 246/* 247 * 'cupsdGetDateTime()' - Returns a pointer to a date/time string. 248 */ 249 250char * /* O - Date/time string */ 251cupsdGetDateTime(struct timeval *t, /* I - Time value or NULL for current */ 252 cupsd_time_t format) /* I - Format to use */ 253{ 254 struct timeval curtime; /* Current time value */ 255 struct tm *date; /* Date/time value */ 256 static struct timeval last_time = { 0, 0 }; 257 /* Last time we formatted */ 258 static char s[1024]; /* Date/time string */ 259 static const char * const months[12] =/* Months */ 260 { 261 "Jan", 262 "Feb", 263 "Mar", 264 "Apr", 265 "May", 266 "Jun", 267 "Jul", 268 "Aug", 269 "Sep", 270 "Oct", 271 "Nov", 272 "Dec" 273 }; 274 275 276 /* 277 * Make sure we have a valid time... 278 */ 279 280 if (!t) 281 { 282 gettimeofday(&curtime, NULL); 283 t = &curtime; 284 } 285 286 if (t->tv_sec != last_time.tv_sec || 287 (LogTimeFormat == CUPSD_TIME_USECS && t->tv_usec != last_time.tv_usec)) 288 { 289 last_time = *t; 290 291 /* 292 * Get the date and time from the UNIX time value, and then format it 293 * into a string. Note that we *can't* use the strftime() function since 294 * it is localized and will seriously confuse automatic programs if the 295 * month names are in the wrong language! 296 * 297 * Also, we use the "timezone" variable that contains the current timezone 298 * offset from GMT in seconds so that we are reporting local time in the 299 * log files. If you want GMT, set the TZ environment variable accordingly 300 * before starting the scheduler. 301 * 302 * (*BSD and Darwin store the timezone offset in the tm structure) 303 */ 304 305 date = localtime(&(t->tv_sec)); 306 307 if (format == CUPSD_TIME_STANDARD) 308 snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]", 309 date->tm_mday, months[date->tm_mon], 1900 + date->tm_year, 310 date->tm_hour, date->tm_min, date->tm_sec, 311#ifdef HAVE_TM_GMTOFF 312 date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60); 313#else 314 timezone / 3600, (timezone / 60) % 60); 315#endif /* HAVE_TM_GMTOFF */ 316 else 317 snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d.%06d %+03ld%02ld]", 318 date->tm_mday, months[date->tm_mon], 1900 + date->tm_year, 319 date->tm_hour, date->tm_min, date->tm_sec, (int)t->tv_usec, 320#ifdef HAVE_TM_GMTOFF 321 date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60); 322#else 323 timezone / 3600, (timezone / 60) % 60); 324#endif /* HAVE_TM_GMTOFF */ 325 } 326 327 return (s); 328} 329 330 331/* 332 * 'cupsdLogFCMessage()' - Log a file checking message. 333 */ 334 335void 336cupsdLogFCMessage( 337 void *context, /* I - Printer (if any) */ 338 _cups_fc_result_t result, /* I - Check result */ 339 const char *message) /* I - Message to log */ 340{ 341 cupsd_printer_t *p = (cupsd_printer_t *)context; 342 /* Printer */ 343 cupsd_loglevel_t level; /* Log level */ 344 345 346 if (result == _CUPS_FILE_CHECK_OK) 347 level = CUPSD_LOG_DEBUG2; 348 else 349 level = CUPSD_LOG_ERROR; 350 351 if (p) 352 { 353 cupsdLogMessage(level, "%s: %s", p->name, message); 354 355 if (result == _CUPS_FILE_CHECK_MISSING || 356 result == _CUPS_FILE_CHECK_WRONG_TYPE) 357 { 358 strlcpy(p->state_message, message, sizeof(p->state_message)); 359 360 if (cupsdSetPrinterReasons(p, "+cups-missing-filter-warning")) 361 cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message); 362 } 363 else if (result == _CUPS_FILE_CHECK_PERMISSIONS || 364 result == _CUPS_FILE_CHECK_RELATIVE_PATH) 365 { 366 strlcpy(p->state_message, message, sizeof(p->state_message)); 367 368 if (cupsdSetPrinterReasons(p, "+cups-insecure-filter-warning")) 369 cupsdAddEvent(CUPSD_EVENT_PRINTER_STATE, p, NULL, "%s", message); 370 } 371 } 372 else 373 cupsdLogMessage(level, "%s", message); 374} 375 376 377#ifdef HAVE_GSSAPI 378/* 379 * 'cupsdLogGSSMessage()' - Log a GSSAPI error... 380 */ 381 382int /* O - 1 on success, 0 on error */ 383cupsdLogGSSMessage( 384 int level, /* I - Log level */ 385 int major_status, /* I - Major GSSAPI status */ 386 int minor_status, /* I - Minor GSSAPI status */ 387 const char *message, /* I - printf-style message string */ 388 ...) /* I - Additional args as needed */ 389{ 390 OM_uint32 err_major_status, /* Major status code for display */ 391 err_minor_status; /* Minor status code for display */ 392 OM_uint32 msg_ctx; /* Message context */ 393 gss_buffer_desc major_status_string = GSS_C_EMPTY_BUFFER, 394 /* Major status message */ 395 minor_status_string = GSS_C_EMPTY_BUFFER; 396 /* Minor status message */ 397 int ret; /* Return value */ 398 char buffer[8192]; /* Buffer for vsnprintf */ 399 400 401 if (strchr(message, '%')) 402 { 403 /* 404 * Format the message string... 405 */ 406 407 va_list ap; /* Pointer to arguments */ 408 409 va_start(ap, message); 410 vsnprintf(buffer, sizeof(buffer), message, ap); 411 va_end(ap); 412 413 message = buffer; 414 } 415 416 msg_ctx = 0; 417 err_major_status = gss_display_status(&err_minor_status, 418 major_status, 419 GSS_C_GSS_CODE, 420 GSS_C_NO_OID, 421 &msg_ctx, 422 &major_status_string); 423 424 if (!GSS_ERROR(err_major_status)) 425 gss_display_status(&err_minor_status, minor_status, GSS_C_MECH_CODE, 426 GSS_C_NULL_OID, &msg_ctx, &minor_status_string); 427 428 ret = cupsdLogMessage(level, "%s: %s, %s", message, 429 (char *)major_status_string.value, 430 (char *)minor_status_string.value); 431 gss_release_buffer(&err_minor_status, &major_status_string); 432 gss_release_buffer(&err_minor_status, &minor_status_string); 433 434 return (ret); 435} 436#endif /* HAVE_GSSAPI */ 437 438 439/* 440 * 'cupsdLogJob()' - Log a job message. 441 */ 442 443int /* O - 1 on success, 0 on error */ 444cupsdLogJob(cupsd_job_t *job, /* I - Job */ 445 int level, /* I - Log level */ 446 const char *message, /* I - Printf-style message string */ 447 ...) /* I - Additional arguments as needed */ 448{ 449 va_list ap, ap2; /* Argument pointers */ 450 char jobmsg[1024]; /* Format string for job message */ 451 int status; /* Formatting status */ 452 453 454 /* 455 * See if we want to log this message... 456 */ 457 458 if (TestConfigFile || !ErrorLog) 459 return (1); 460 461 if ((level > LogLevel || 462 (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) && 463 LogDebugHistory <= 0) 464 return (1); 465 466 /* 467 * Format and write the log message... 468 */ 469 470 if (job) 471 snprintf(jobmsg, sizeof(jobmsg), "[Job %d] %s", job->id, message); 472 else 473 strlcpy(jobmsg, message, sizeof(jobmsg)); 474 475 va_start(ap, message); 476 477 do 478 { 479 va_copy(ap2, ap); 480 status = format_log_line(jobmsg, ap2); 481 va_end(ap2); 482 } 483 while (status == 0); 484 485 va_end(ap); 486 487 if (status > 0) 488 { 489 if (job && 490 (level > LogLevel || 491 (level == CUPSD_LOG_INFO && LogLevel < CUPSD_LOG_DEBUG)) && 492 LogDebugHistory > 0) 493 { 494 /* 495 * Add message to the job history... 496 */ 497 498 cupsd_joblog_t *temp; /* Copy of log message */ 499 size_t log_len = strlen(log_line); 500 /* Length of log message */ 501 502 if ((temp = malloc(sizeof(cupsd_joblog_t) + log_len)) != NULL) 503 { 504 temp->time = time(NULL); 505 memcpy(temp->message, log_line, log_len + 1); 506 } 507 508 if (!job->history) 509 job->history = cupsArrayNew(NULL, NULL); 510 511 if (job->history && temp) 512 { 513 cupsArrayAdd(job->history, temp); 514 515 if (cupsArrayCount(job->history) > LogDebugHistory) 516 { 517 /* 518 * Remove excess messages... 519 */ 520 521 temp = cupsArrayFirst(job->history); 522 cupsArrayRemove(job->history, temp); 523 free(temp); 524 } 525 } 526 else if (temp) 527 free(temp); 528 529 return (1); 530 } 531 else if (level <= LogLevel && 532 (level != CUPSD_LOG_INFO || LogLevel >= CUPSD_LOG_DEBUG)) 533 return (cupsdWriteErrorLog(level, log_line)); 534 else 535 return (1); 536 } 537 else 538 return (cupsdWriteErrorLog(CUPSD_LOG_ERROR, 539 "Unable to allocate memory for log line!")); 540} 541 542 543/* 544 * 'cupsdLogMessage()' - Log a message to the error log file. 545 */ 546 547int /* O - 1 on success, 0 on error */ 548cupsdLogMessage(int level, /* I - Log level */ 549 const char *message, /* I - printf-style message string */ 550 ...) /* I - Additional args as needed */ 551{ 552 va_list ap, ap2; /* Argument pointers */ 553 int status; /* Formatting status */ 554 555 556 /* 557 * See if we want to log this message... 558 */ 559 560 if ((TestConfigFile || !ErrorLog) && level <= CUPSD_LOG_WARN) 561 { 562 va_start(ap, message); 563#ifdef HAVE_VSYSLOG 564 vsyslog(LOG_LPR | syslevels[level], message, ap); 565#else 566 vfprintf(stderr, message, ap); 567 putc('\n', stderr); 568#endif /* HAVE_VSYSLOG */ 569 va_end(ap); 570 571 return (1); 572 } 573 574 if (level > LogLevel || !ErrorLog) 575 return (1); 576 577 /* 578 * Format and write the log message... 579 */ 580 581 va_start(ap, message); 582 583 do 584 { 585 va_copy(ap2, ap); 586 status = format_log_line(message, ap2); 587 va_end(ap2); 588 } 589 while (status == 0); 590 591 va_end(ap); 592 593 if (status > 0) 594 return (cupsdWriteErrorLog(level, log_line)); 595 else 596 return (cupsdWriteErrorLog(CUPSD_LOG_ERROR, 597 "Unable to allocate memory for log line!")); 598} 599 600 601/* 602 * 'cupsdLogPage()' - Log a page to the page log file. 603 */ 604 605int /* O - 1 on success, 0 on error */ 606cupsdLogPage(cupsd_job_t *job, /* I - Job being printed */ 607 const char *page) /* I - Page being printed */ 608{ 609 int i; /* Looping var */ 610 char buffer[2048], /* Buffer for page log */ 611 *bufptr, /* Pointer into buffer */ 612 name[256]; /* Attribute name */ 613 const char *format, /* Pointer into PageLogFormat */ 614 *nameend; /* End of attribute name */ 615 ipp_attribute_t *attr; /* Current attribute */ 616 char number[256]; /* Page number */ 617 int copies; /* Number of copies */ 618 619 620 /* 621 * Format the line going into the page log... 622 */ 623 624 if (!PageLogFormat) 625 return (1); 626 627 strlcpy(number, "1", sizeof(number)); 628 copies = 1; 629 sscanf(page, "%255s%d", number, &copies); 630 631 for (format = PageLogFormat, bufptr = buffer; *format; format ++) 632 { 633 if (*format == '%') 634 { 635 format ++; 636 637 switch (*format) 638 { 639 case '%' : /* Literal % */ 640 if (bufptr < (buffer + sizeof(buffer) - 1)) 641 *bufptr++ = '%'; 642 break; 643 644 case 'p' : /* Printer name */ 645 strlcpy(bufptr, job->printer->name, 646 sizeof(buffer) - (bufptr - buffer)); 647 bufptr += strlen(bufptr); 648 break; 649 650 case 'j' : /* Job ID */ 651 snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", job->id); 652 bufptr += strlen(bufptr); 653 break; 654 655 case 'u' : /* Username */ 656 strlcpy(bufptr, job->username ? job->username : "-", 657 sizeof(buffer) - (bufptr - buffer)); 658 bufptr += strlen(bufptr); 659 break; 660 661 case 'T' : /* Date and time */ 662 strlcpy(bufptr, cupsdGetDateTime(NULL, LogTimeFormat), 663 sizeof(buffer) - (bufptr - buffer)); 664 bufptr += strlen(bufptr); 665 break; 666 667 case 'P' : /* Page number */ 668 strlcpy(bufptr, number, sizeof(buffer) - (bufptr - buffer)); 669 bufptr += strlen(bufptr); 670 break; 671 672 case 'C' : /* Number of copies */ 673 snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), "%d", copies); 674 bufptr += strlen(bufptr); 675 break; 676 677 case '{' : /* {attribute} */ 678 if ((nameend = strchr(format, '}')) != NULL && 679 (nameend - format - 2) < (sizeof(name) - 1)) 680 { 681 /* 682 * Pull the name from inside the brackets... 683 */ 684 685 memcpy(name, format + 1, nameend - format - 1); 686 name[nameend - format - 1] = '\0'; 687 688 format = nameend; 689 690 if ((attr = ippFindAttribute(job->attrs, name, 691 IPP_TAG_ZERO)) != NULL) 692 { 693 /* 694 * Add the attribute value... 695 */ 696 697 for (i = 0; 698 i < attr->num_values && 699 bufptr < (buffer + sizeof(buffer) - 1); 700 i ++) 701 { 702 if (i) 703 *bufptr++ = ','; 704 705 switch (attr->value_tag) 706 { 707 case IPP_TAG_INTEGER : 708 case IPP_TAG_ENUM : 709 snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), 710 "%d", attr->values[i].integer); 711 bufptr += strlen(bufptr); 712 break; 713 714 case IPP_TAG_BOOLEAN : 715 snprintf(bufptr, sizeof(buffer) - (bufptr - buffer), 716 "%d", attr->values[i].boolean); 717 bufptr += strlen(bufptr); 718 break; 719 720 case IPP_TAG_TEXTLANG : 721 case IPP_TAG_NAMELANG : 722 case IPP_TAG_TEXT : 723 case IPP_TAG_NAME : 724 case IPP_TAG_KEYWORD : 725 case IPP_TAG_URI : 726 case IPP_TAG_URISCHEME : 727 case IPP_TAG_CHARSET : 728 case IPP_TAG_LANGUAGE : 729 case IPP_TAG_MIMETYPE : 730 strlcpy(bufptr, attr->values[i].string.text, 731 sizeof(buffer) - (bufptr - buffer)); 732 bufptr += strlen(bufptr); 733 break; 734 735 default : 736 strlcpy(bufptr, "???", 737 sizeof(buffer) - (bufptr - buffer)); 738 bufptr += strlen(bufptr); 739 break; 740 } 741 } 742 } 743 else if (bufptr < (buffer + sizeof(buffer) - 1)) 744 *bufptr++ = '-'; 745 break; 746 } 747 748 default : 749 if (bufptr < (buffer + sizeof(buffer) - 2)) 750 { 751 *bufptr++ = '%'; 752 *bufptr++ = *format; 753 } 754 break; 755 } 756 } 757 else if (bufptr < (buffer + sizeof(buffer) - 1)) 758 *bufptr++ = *format; 759 } 760 761 *bufptr = '\0'; 762 763#ifdef HAVE_VSYSLOG 764 /* 765 * See if we are logging pages via syslog... 766 */ 767 768 if (!strcmp(PageLog, "syslog")) 769 { 770 syslog(LOG_INFO, "%s", buffer); 771 772 return (1); 773 } 774#endif /* HAVE_VSYSLOG */ 775 776 /* 777 * Not using syslog; check the log file... 778 */ 779 780 if (!cupsdCheckLogFile(&PageFile, PageLog)) 781 return (0); 782 783 /* 784 * Print a page log entry of the form: 785 * 786 * printer user job-id [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \ 787 * billing hostname 788 */ 789 790 cupsFilePrintf(PageFile, "%s\n", buffer); 791 cupsFileFlush(PageFile); 792 793 return (1); 794} 795 796 797/* 798 * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format. 799 */ 800 801int /* O - 1 on success, 0 on error */ 802cupsdLogRequest(cupsd_client_t *con, /* I - Request to log */ 803 http_status_t code) /* I - Response code */ 804{ 805 char temp[2048]; /* Temporary string for URI */ 806 static const char * const states[] = /* HTTP client states... */ 807 { 808 "WAITING", 809 "OPTIONS", 810 "GET", 811 "GET", 812 "HEAD", 813 "POST", 814 "POST", 815 "POST", 816 "PUT", 817 "PUT", 818 "DELETE", 819 "TRACE", 820 "CLOSE", 821 "STATUS" 822 }; 823 824 825 /* 826 * Filter requests as needed... 827 */ 828 829 if (AccessLogLevel < CUPSD_ACCESSLOG_ALL) 830 { 831 /* 832 * Eliminate simple GET, POST, and PUT requests... 833 */ 834 835 if ((con->operation == HTTP_GET && 836 strncmp(con->uri, "/admin/conf", 11) && 837 strncmp(con->uri, "/admin/log", 10)) || 838 (con->operation == HTTP_POST && !con->request && 839 strncmp(con->uri, "/admin", 6)) || 840 (con->operation != HTTP_GET && con->operation != HTTP_POST && 841 con->operation != HTTP_PUT)) 842 return (1); 843 844 if (con->request && con->response && 845 (con->response->request.status.status_code < IPP_REDIRECTION_OTHER_SITE || 846 con->response->request.status.status_code == IPP_NOT_FOUND)) 847 { 848 /* 849 * Check successful requests... 850 */ 851 852 ipp_op_t op = con->request->request.op.operation_id; 853 static cupsd_accesslog_t standard_ops[] = 854 { 855 CUPSD_ACCESSLOG_ALL, /* reserved */ 856 CUPSD_ACCESSLOG_ALL, /* reserved */ 857 CUPSD_ACCESSLOG_ACTIONS,/* Print-Job */ 858 CUPSD_ACCESSLOG_ACTIONS,/* Print-URI */ 859 CUPSD_ACCESSLOG_ACTIONS,/* Validate-Job */ 860 CUPSD_ACCESSLOG_ACTIONS,/* Create-Job */ 861 CUPSD_ACCESSLOG_ACTIONS,/* Send-Document */ 862 CUPSD_ACCESSLOG_ACTIONS,/* Send-URI */ 863 CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Job */ 864 CUPSD_ACCESSLOG_ALL, /* Get-Job-Attributes */ 865 CUPSD_ACCESSLOG_ALL, /* Get-Jobs */ 866 CUPSD_ACCESSLOG_ALL, /* Get-Printer-Attributes */ 867 CUPSD_ACCESSLOG_ACTIONS,/* Hold-Job */ 868 CUPSD_ACCESSLOG_ACTIONS,/* Release-Job */ 869 CUPSD_ACCESSLOG_ACTIONS,/* Restart-Job */ 870 CUPSD_ACCESSLOG_ALL, /* reserved */ 871 CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer */ 872 CUPSD_ACCESSLOG_CONFIG, /* Resume-Printer */ 873 CUPSD_ACCESSLOG_CONFIG, /* Purge-Jobs */ 874 CUPSD_ACCESSLOG_CONFIG, /* Set-Printer-Attributes */ 875 CUPSD_ACCESSLOG_ACTIONS,/* Set-Job-Attributes */ 876 CUPSD_ACCESSLOG_CONFIG, /* Get-Printer-Supported-Values */ 877 CUPSD_ACCESSLOG_ACTIONS,/* Create-Printer-Subscription */ 878 CUPSD_ACCESSLOG_ACTIONS,/* Create-Job-Subscription */ 879 CUPSD_ACCESSLOG_ALL, /* Get-Subscription-Attributes */ 880 CUPSD_ACCESSLOG_ALL, /* Get-Subscriptions */ 881 CUPSD_ACCESSLOG_ACTIONS,/* Renew-Subscription */ 882 CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Subscription */ 883 CUPSD_ACCESSLOG_ALL, /* Get-Notifications */ 884 CUPSD_ACCESSLOG_ACTIONS,/* Send-Notifications */ 885 CUPSD_ACCESSLOG_ALL, /* reserved */ 886 CUPSD_ACCESSLOG_ALL, /* reserved */ 887 CUPSD_ACCESSLOG_ALL, /* reserved */ 888 CUPSD_ACCESSLOG_ALL, /* Get-Print-Support-Files */ 889 CUPSD_ACCESSLOG_CONFIG, /* Enable-Printer */ 890 CUPSD_ACCESSLOG_CONFIG, /* Disable-Printer */ 891 CUPSD_ACCESSLOG_CONFIG, /* Pause-Printer-After-Current-Job */ 892 CUPSD_ACCESSLOG_ACTIONS,/* Hold-New-Jobs */ 893 CUPSD_ACCESSLOG_ACTIONS,/* Release-Held-New-Jobs */ 894 CUPSD_ACCESSLOG_CONFIG, /* Deactivate-Printer */ 895 CUPSD_ACCESSLOG_CONFIG, /* Activate-Printer */ 896 CUPSD_ACCESSLOG_CONFIG, /* Restart-Printer */ 897 CUPSD_ACCESSLOG_CONFIG, /* Shutdown-Printer */ 898 CUPSD_ACCESSLOG_CONFIG, /* Startup-Printer */ 899 CUPSD_ACCESSLOG_ACTIONS,/* Reprocess-Job */ 900 CUPSD_ACCESSLOG_ACTIONS,/* Cancel-Current-Job */ 901 CUPSD_ACCESSLOG_ACTIONS,/* Suspend-Current-Job */ 902 CUPSD_ACCESSLOG_ACTIONS,/* Resume-Job */ 903 CUPSD_ACCESSLOG_ACTIONS,/* Promote-Job */ 904 CUPSD_ACCESSLOG_ACTIONS /* Schedule-Job-After */ 905 }; 906 static cupsd_accesslog_t cups_ops[] = 907 { 908 CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Default */ 909 CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Printers */ 910 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Printer */ 911 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Printer */ 912 CUPSD_ACCESSLOG_ALL, /* CUPS-Get-Classes */ 913 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Add-Modify-Class */ 914 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Delete-Class */ 915 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Accept-Jobs */ 916 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Reject-Jobs */ 917 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Set-Default */ 918 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-Devices */ 919 CUPSD_ACCESSLOG_CONFIG, /* CUPS-Get-PPDs */ 920 CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Move-Job */ 921 CUPSD_ACCESSLOG_ACTIONS,/* CUPS-Authenticate-Job */ 922 CUPSD_ACCESSLOG_ALL /* CUPS-Get-PPD */ 923 }; 924 925 926 if ((op <= IPP_SCHEDULE_JOB_AFTER && standard_ops[op] > AccessLogLevel) || 927 (op >= CUPS_GET_DEFAULT && op <= CUPS_GET_PPD && 928 cups_ops[op - CUPS_GET_DEFAULT] > AccessLogLevel)) 929 return (1); 930 } 931 } 932 933#ifdef HAVE_VSYSLOG 934 /* 935 * See if we are logging accesses via syslog... 936 */ 937 938 if (!strcmp(AccessLog, "syslog")) 939 { 940 syslog(LOG_INFO, 941 "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", 942 con->http.hostname, con->username[0] != '\0' ? con->username : "-", 943 states[con->operation], _httpEncodeURI(temp, con->uri, sizeof(temp)), 944 con->http.version / 100, con->http.version % 100, 945 code, CUPS_LLCAST con->bytes, 946 con->request ? 947 ippOpString(con->request->request.op.operation_id) : "-", 948 con->response ? 949 ippErrorString(con->response->request.status.status_code) : "-"); 950 951 return (1); 952 } 953#endif /* HAVE_VSYSLOG */ 954 955 /* 956 * Not using syslog; check the log file... 957 */ 958 959 if (!cupsdCheckLogFile(&AccessFile, AccessLog)) 960 return (0); 961 962 /* 963 * Write a log of the request in "common log format"... 964 */ 965 966 cupsFilePrintf(AccessFile, 967 "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n", 968 con->http.hostname, 969 con->username[0] != '\0' ? con->username : "-", 970 cupsdGetDateTime(&(con->start), LogTimeFormat), 971 states[con->operation], 972 _httpEncodeURI(temp, con->uri, sizeof(temp)), 973 con->http.version / 100, con->http.version % 100, 974 code, CUPS_LLCAST con->bytes, 975 con->request ? 976 ippOpString(con->request->request.op.operation_id) : "-", 977 con->response ? 978 ippErrorString(con->response->request.status.status_code) : 979 "-"); 980 981 cupsFileFlush(AccessFile); 982 983 return (1); 984} 985 986 987/* 988 * 'cupsdWriteErrorLog()' - Write a line to the ErrorLog. 989 */ 990 991int /* O - 1 on success, 0 on failure */ 992cupsdWriteErrorLog(int level, /* I - Log level */ 993 const char *message) /* I - Message string */ 994{ 995 static const char levels[] = /* Log levels... */ 996 { 997 ' ', 998 'X', 999 'A', 1000 'C', 1001 'E', 1002 'W', 1003 'N', 1004 'I', 1005 'D', 1006 'd' 1007 }; 1008 1009 1010#ifdef HAVE_VSYSLOG 1011 /* 1012 * See if we are logging errors via syslog... 1013 */ 1014 1015 if (!strcmp(ErrorLog, "syslog")) 1016 { 1017 syslog(syslevels[level], "%s", message); 1018 return (1); 1019 } 1020#endif /* HAVE_VSYSLOG */ 1021 1022 /* 1023 * Not using syslog; check the log file... 1024 */ 1025 1026 if (!cupsdCheckLogFile(&ErrorFile, ErrorLog)) 1027 return (0); 1028 1029 /* 1030 * Write the log message... 1031 */ 1032 1033 cupsFilePrintf(ErrorFile, "%c %s %s\n", levels[level], 1034 cupsdGetDateTime(NULL, LogTimeFormat), message); 1035 cupsFileFlush(ErrorFile); 1036 1037 return (1); 1038} 1039 1040 1041/* 1042 * 'format_log_line()' - Format a line for a log file. 1043 * 1044 * This function resizes a global string buffer as needed. Each call returns 1045 * a pointer to this buffer, so the contents are only good until the next call 1046 * to format_log_line()... 1047 */ 1048 1049static int /* O - -1 for fatal, 0 for retry, 1 for success */ 1050format_log_line(const char *message, /* I - Printf-style format string */ 1051 va_list ap) /* I - Argument list */ 1052{ 1053 int len; /* Length of formatted line */ 1054 1055 1056 /* 1057 * Allocate the line buffer as needed... 1058 */ 1059 1060 if (!log_linesize) 1061 { 1062 log_linesize = 8192; 1063 log_line = malloc(log_linesize); 1064 1065 if (!log_line) 1066 return (-1); 1067 } 1068 1069 /* 1070 * Format the log message... 1071 */ 1072 1073 len = vsnprintf(log_line, log_linesize, message, ap); 1074 1075 /* 1076 * Resize the buffer as needed... 1077 */ 1078 1079 if (len >= log_linesize && log_linesize < 65536) 1080 { 1081 char *temp; /* Temporary string pointer */ 1082 1083 1084 len ++; 1085 1086 if (len < 8192) 1087 len = 8192; 1088 else if (len > 65536) 1089 len = 65536; 1090 1091 temp = realloc(log_line, len); 1092 1093 if (temp) 1094 { 1095 log_line = temp; 1096 log_linesize = len; 1097 1098 return (0); 1099 } 1100 } 1101 1102 return (1); 1103} 1104 1105 1106/* 1107 * End of "$Id: log.c 11433 2013-11-20 18:57:44Z msweet $". 1108 */ 1109