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