Load cups into easysw/current.
[thirdparty/cups.git] / scheduler / log.c
1 /*
2  * "$Id: log.c 4860 2005-12-01 22:07:26Z mike $"
3  *
4  *   Log file routines for the Common UNIX Printing System (CUPS).
5  *
6  *   Copyright 1997-2005 by Easy Software Products, all rights reserved.
7  *
8  *   These coded instructions, statements, and computer programs are the
9  *   property of Easy Software Products and are protected by Federal
10  *   copyright law.  Distribution and use rights are outlined in the file
11  *   "LICENSE.txt" which should have been included with this file.  If this
12  *   file is missing or damaged please contact Easy Software Products
13  *   at:
14  *
15  *       Attn: CUPS Licensing Information
16  *       Easy Software Products
17  *       44141 Airport View Drive, Suite 204
18  *       Hollywood, Maryland 20636 USA
19  *
20  *       Voice: (301) 373-9600
21  *       EMail: cups-info@cups.org
22  *         WWW: http://www.cups.org
23  *
24  * Contents:
25  *
26  *   cupsdGetDateTime()    - Returns a pointer to a date/time string.
27  *   cupsdLogMessage()     - Log a message to the error log file.
28  *   cupsdLogPage()        - Log a page to the page log file.
29  *   cupsdLogRequest()     - Log an HTTP request in Common Log Format.
30  *   check_log_file() - Open/rotate a log file if it needs it.
31  */
32
33 /*
34  * Include necessary headers...
35  */
36
37 #include "cupsd.h"
38 #include <stdarg.h>
39
40 #ifdef HAVE_VSYSLOG
41 #  include <syslog.h>
42 #endif /* HAVE_VSYSLOG */
43
44
45 /*
46  * Local functions...
47  */
48
49 static int      check_log_file(cups_file_t **, const char *);
50
51
52 /*
53  * 'cupsdGetDateTime()' - Returns a pointer to a date/time string.
54  */
55
56 char *                                  /* O - Date/time string */
57 cupsdGetDateTime(time_t t)              /* I - Time value */
58 {
59   struct tm     *date;                  /* Date/time value */
60   static time_t last_time = -1;         /* Last time value */
61   static char   s[1024];                /* Date/time string */
62   static const char * const months[12] =/* Months */
63                 {
64                   "Jan",
65                   "Feb",
66                   "Mar",
67                   "Apr",
68                   "May",
69                   "Jun",
70                   "Jul",
71                   "Aug",
72                   "Sep",
73                   "Oct",
74                   "Nov",
75                   "Dec"
76                 };
77
78
79   if (t != last_time)
80   {
81     last_time = t;
82
83    /*
84     * Get the date and time from the UNIX time value, and then format it
85     * into a string.  Note that we *can't* use the strftime() function since
86     * it is localized and will seriously confuse automatic programs if the
87     * month names are in the wrong language!
88     *
89     * Also, we use the "timezone" variable that contains the current timezone
90     * offset from GMT in seconds so that we are reporting local time in the
91     * log files.  If you want GMT, set the TZ environment variable accordingly
92     * before starting the scheduler.
93     *
94     * (*BSD and Darwin store the timezone offset in the tm structure)
95     */
96
97     date = localtime(&t);
98
99     snprintf(s, sizeof(s), "[%02d/%s/%04d:%02d:%02d:%02d %+03ld%02ld]",
100              date->tm_mday, months[date->tm_mon], 1900 + date->tm_year,
101              date->tm_hour, date->tm_min, date->tm_sec,
102 #ifdef HAVE_TM_GMTOFF
103              date->tm_gmtoff / 3600, (date->tm_gmtoff / 60) % 60);
104 #else
105              timezone / 3600, (timezone / 60) % 60);
106 #endif /* HAVE_TM_GMTOFF */
107   }
108
109   return (s);
110 }
111
112
113 /*
114  * 'cupsdLogMessage()' - Log a message to the error log file.
115  */
116
117 int                                     /* O - 1 on success, 0 on error */
118 cupsdLogMessage(int        level,       /* I - Log level */
119                 const char *message,    /* I - printf-style message string */
120                 ...)                    /* I - Additional args as needed */
121 {
122   int                   len;            /* Length of message */
123   va_list               ap;             /* Argument pointer */
124   static const char     levels[] =      /* Log levels... */
125                 {
126                   ' ',
127                   'X',
128                   'A',
129                   'C',
130                   'E',
131                   'W',
132                   'N',
133                   'I',
134                   'D',
135                   'd'
136                 };
137 #ifdef HAVE_VSYSLOG
138   static const int syslevels[] =        /* SYSLOG levels... */
139                 {
140                   0,
141                   LOG_EMERG,
142                   LOG_ALERT,
143                   LOG_CRIT,
144                   LOG_ERR,
145                   LOG_WARNING,
146                   LOG_NOTICE,
147                   LOG_INFO,
148                   LOG_DEBUG,
149                   LOG_DEBUG
150                 };
151 #endif /* HAVE_VSYSLOG */
152   static int    linesize = 0;           /* Size of line for output file */
153   static char   *line = NULL;           /* Line for output file */
154
155
156  /*
157   * See if we want to log this message...
158   */
159
160   if (level > LogLevel || !ErrorLog)
161     return (1);
162
163 #ifdef HAVE_VSYSLOG
164  /*
165   * See if we are logging errors via syslog...
166   */
167
168   if (!strcmp(ErrorLog, "syslog"))
169   {
170     va_start(ap, message);
171     vsyslog(syslevels[level], message, ap);
172     va_end(ap);
173
174     return (1);
175   }
176 #endif /* HAVE_VSYSLOG */
177
178  /*
179   * Not using syslog; check the log file...
180   */
181
182   if (!check_log_file(&ErrorFile, ErrorLog))
183     return (0);
184
185  /*
186   * Print the log level and date/time...
187   */
188
189   cupsFilePrintf(ErrorFile, "%c %s ", levels[level], cupsdGetDateTime(time(NULL)));
190
191  /*
192   * Allocate the line buffer as needed...
193   */
194
195   if (!linesize)
196   {
197     linesize = 8192;
198     line     = malloc(linesize);
199
200     if (!line)
201     {
202       cupsFilePrintf(ErrorFile,
203                      "ERROR: Unable to allocate memory for line - %s\n",
204                      strerror(errno));
205       cupsFileFlush(ErrorFile);
206
207       return (0);
208     }
209   }
210
211  /*
212   * Format the log message...
213   */
214
215   va_start(ap, message);
216   len = vsnprintf(line, linesize, message, ap);
217   va_end(ap);
218
219  /*
220   * Resize the buffer as needed...
221   */
222
223   if (len >= linesize)
224   {
225     len ++;
226
227     if (len < 8192)
228       len = 8192;
229     else if (len > 65536)
230       len = 65536;
231
232     line = realloc(line, len);
233
234     if (line)
235       linesize = len;
236     else
237     {
238       cupsFilePrintf(ErrorFile,
239                      "ERROR: Unable to allocate memory for line - %s\n",
240                      strerror(errno));
241       cupsFileFlush(ErrorFile);
242
243       return (0);
244     }
245
246     va_start(ap, message);
247     len = vsnprintf(line, linesize, message, ap);
248     va_end(ap);
249   }
250
251   if (len >= linesize)
252     len = linesize - 1;
253
254  /*
255   * Then the log message...
256   */
257
258   cupsFilePuts(ErrorFile, line);
259
260  /*
261   * Then a newline...
262   */
263
264   if (len > 0 && line[len - 1] != '\n')
265     cupsFilePutChar(ErrorFile, '\n');
266
267  /*
268   * Flush the line to the file and return...
269   */
270
271   cupsFileFlush(ErrorFile);
272
273   return (1);
274 }
275
276
277 /*
278  * 'cupsdLogPage()' - Log a page to the page log file.
279  */
280
281 int                                     /* O - 1 on success, 0 on error */
282 cupsdLogPage(cupsd_job_t *job,          /* I - Job being printed */
283              const char  *page)         /* I - Page being printed */
284 {
285   ipp_attribute_t *billing,             /* job-billing attribute */
286                   *hostname;            /* job-originating-host-name attribute */
287
288
289   billing  = ippFindAttribute(job->attrs, "job-billing", IPP_TAG_ZERO);
290   hostname = ippFindAttribute(job->attrs, "job-originating-host-name",
291                               IPP_TAG_ZERO);
292
293 #ifdef HAVE_VSYSLOG
294  /*
295   * See if we are logging pages via syslog...
296   */
297
298   if (!strcmp(PageLog, "syslog"))
299   {
300     syslog(LOG_INFO, "PAGE %s %s %d %s %s %s", job->printer->name,
301            job->username ? job->username : "-",
302            job->id, page, billing ? billing->values[0].string.text : "-",
303            hostname->values[0].string.text);
304
305     return (1);
306   }
307 #endif /* HAVE_VSYSLOG */
308
309  /*
310   * Not using syslog; check the log file...
311   */
312
313   if (!check_log_file(&PageFile, PageLog))
314     return (0);
315
316  /*
317   * Print a page log entry of the form:
318   *
319   *    printer job-id user [DD/MON/YYYY:HH:MM:SS +TTTT] page num-copies \
320   *        billing hostname
321   */
322
323   cupsFilePrintf(PageFile, "%s %s %d %s %s %s %s\n", job->printer->name,
324                  job->username ? job->username : "-",
325                  job->id, cupsdGetDateTime(time(NULL)), page,
326                  billing ? billing->values[0].string.text : "-",
327                  hostname->values[0].string.text);
328   cupsFileFlush(PageFile);
329
330   return (1);
331 }
332
333
334 /*
335  * 'cupsdLogRequest()' - Log an HTTP request in Common Log Format.
336  */
337
338 int                                     /* O - 1 on success, 0 on error */
339 cupsdLogRequest(cupsd_client_t *con,    /* I - Request to log */
340                 http_status_t  code)    /* I - Response code */
341 {
342   static const char * const states[] =  /* HTTP client states... */
343                 {
344                   "WAITING",
345                   "OPTIONS",
346                   "GET",
347                   "GET",
348                   "HEAD",
349                   "POST",
350                   "POST",
351                   "POST",
352                   "PUT",
353                   "PUT",
354                   "DELETE",
355                   "TRACE",
356                   "CLOSE",
357                   "STATUS"
358                 };
359
360
361 #ifdef HAVE_VSYSLOG
362  /*
363   * See if we are logging accesses via syslog...
364   */
365
366   if (!strcmp(AccessLog, "syslog"))
367   {
368     syslog(LOG_INFO, "REQUEST %s - %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT "\n",
369            con->http.hostname, con->username[0] != '\0' ? con->username : "-",
370            states[con->operation], con->uri,
371            con->http.version / 100, con->http.version % 100,
372            code, CUPS_LLCAST con->bytes);
373
374     return (1);
375   }
376 #endif /* HAVE_VSYSLOG */
377
378  /*
379   * Not using syslog; check the log file...
380   */
381
382   if (!check_log_file(&AccessFile, AccessLog))
383     return (0);
384
385  /*
386   * Write a log of the request in "common log format"...
387   */
388
389   cupsFilePrintf(AccessFile,
390                  "%s - %s %s \"%s %s HTTP/%d.%d\" %d " CUPS_LLFMT " %s %s\n",
391                  con->http.hostname, con->username[0] != '\0' ? con->username : "-",
392                  cupsdGetDateTime(con->start), states[con->operation], con->uri,
393                  con->http.version / 100, con->http.version % 100,
394                  code, CUPS_LLCAST con->bytes,
395                  con->request ?
396                      ippOpString(con->request->request.op.operation_id) : "-",
397                  con->response ?
398                      ippErrorString(con->response->request.status.status_code) :
399                      "-");
400
401   cupsFileFlush(AccessFile);
402
403   return (1);
404 }
405
406
407 /*
408  * 'check_log_file()' - Open/rotate a log file if it needs it.
409  */
410
411 static int                              /* O  - 1 if log file open */
412 check_log_file(cups_file_t **lf,        /* IO - Log file */
413                const char  *logname)    /* I  - Log filename */
414 {
415   char  backname[1024],                 /* Backup log filename */
416         filename[1024],                 /* Formatted log filename */
417         *ptr;                           /* Pointer into filename */
418
419
420  /*
421   * See if we have a log file to check...
422   */
423
424   if (!lf || !logname || !logname[0])
425     return (1);
426
427  /*
428   * Format the filename as needed...
429   */
430
431   if (!*lf || (cupsFileTell(*lf) > MaxLogSize && MaxLogSize > 0))
432   {
433    /*
434     * Handle format strings...
435     */
436
437     filename[sizeof(filename) - 1] = '\0';
438
439     if (logname[0] != '/')
440     {
441       strlcpy(filename, ServerRoot, sizeof(filename));
442       strlcat(filename, "/", sizeof(filename));
443     }
444     else
445       filename[0] = '\0';
446
447     for (ptr = filename + strlen(filename);
448          *logname && ptr < (filename + sizeof(filename) - 1);
449          logname ++)
450       if (*logname == '%')
451       {
452        /*
453         * Format spec...
454         */
455
456         logname ++;
457         if (*logname == 's')
458         {
459          /*
460           * Insert the server name...
461           */
462
463           strlcpy(ptr, ServerName, sizeof(filename) - (ptr - filename));
464           ptr += strlen(ptr);
465         }
466         else
467         {
468          /*
469           * Otherwise just insert the character...
470           */
471
472           *ptr++ = *logname;
473         }
474       }
475       else
476         *ptr++ = *logname;
477
478     *ptr = '\0';
479   }
480
481  /*
482   * See if the log file is open...
483   */
484
485   if (!*lf)
486   {
487    /*
488     * Nope, open the log file...
489     */
490
491     if ((*lf = cupsFileOpen(filename, "a")) == NULL)
492     {
493       syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename,
494              strerror(errno));
495
496       return (0);
497     }
498
499     if (strncmp(filename, "/dev/", 5))
500     {
501      /*
502       * Change ownership and permissions of non-device logs...
503       */
504
505       fchown(cupsFileNumber(*lf), RunUser, Group);
506       fchmod(cupsFileNumber(*lf), LogFilePerm);
507     }
508   }
509
510  /*
511   * Do we need to rotate the log?
512   */
513
514   if (cupsFileTell(*lf) > MaxLogSize && MaxLogSize > 0)
515   {
516    /*
517     * Rotate log file...
518     */
519
520     cupsFileClose(*lf);
521
522     strcpy(backname, filename);
523     strlcat(backname, ".O", sizeof(backname));
524
525     unlink(backname);
526     rename(filename, backname);
527
528     if ((*lf = cupsFileOpen(filename, "a")) == NULL)
529     {
530       syslog(LOG_ERR, "Unable to open log file \"%s\" - %s", filename,
531              strerror(errno));
532
533       return (0);
534     }
535
536     if (strncmp(filename, "/dev/", 5))
537     {
538      /*
539       * Change ownership and permissions of non-device logs...
540       */
541
542       fchown(cupsFileNumber(*lf), RunUser, Group);
543       fchmod(cupsFileNumber(*lf), LogFilePerm);
544     }
545   }
546
547   return (1);
548 }
549
550
551 /*
552  * End of "$Id: log.c 4860 2005-12-01 22:07:26Z mike $".
553  */