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