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