src/main/log.c

   1 /*
   2  * log.c        Logging module.
   3  *
   4  * Version:     $Id$
   5  *
   6  *   This program is free software; you can redistribute it and/or modify
   7  *   it under the terms of the GNU General Public License as published by
   8  *   the Free Software Foundation; either version 2 of the License, or
   9  *   (at your option) any later version.
  10  *
  11  *   This program is distributed in the hope that it will be useful,
  12  *   but WITHOUT ANY WARRANTY; without even the implied warranty of
  13  *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  14  *   GNU General Public License for more details.
  15  *
  16  *   You should have received a copy of the GNU General Public License
  17  *   along with this program; if not, write to the Free Software
  18  *   Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301, USA
  19  *
  20  * Copyright 2001,2006  The FreeRADIUS server project
  21  * Copyright 2000  Miquel van Smoorenburg <miquels@cistron.nl>
  22  * Copyright 2000  Alan DeKok <aland@ox.org>
  23  * Copyright 2001  Chad Miller <cmiller@surfsouth.com>
  24  */
  25
  26 #include <freeradius-devel/ident.h>
  27 RCSID("$Id$")
  28
  29 #include <freeradius-devel/radiusd.h>
  30
  31 #ifdef HAVE_SYS_STAT_H
  32 #include <sys/stat.h>
  33 #endif
  34
  35 #ifdef HAVE_SYSLOG_H
  36 #       include <syslog.h>
  37 #endif
  38
  39 /*
  40  * Logging facility names
  41  */
  42 static const FR_NAME_NUMBER levels[] = {
  43         { ": Debug: ",          L_DBG   },
  44         { ": Auth: ",           L_AUTH  },
  45         { ": Proxy: ",          L_PROXY },
  46         { ": Info: ",           L_INFO  },
  47         { ": Acct: ",           L_ACCT  },
  48         { ": Error: ",          L_ERR   },
  49         { NULL, 0 }
  50 };
  51
  52 #define VTC_RED         "\x1b[31m"
  53 #define VTC_BOLD        "\x1b[1m"
  54 #define VTC_RESET       "\x1b[0m"
  55
  56 static const FR_NAME_NUMBER colours[] = {
  57         { "",                   L_DBG   },
  58         { VTC_BOLD,             L_AUTH  },
  59         { VTC_BOLD,             L_PROXY },
  60         { VTC_BOLD,             L_INFO  },
  61         { VTC_BOLD,             L_ACCT  },
  62         { VTC_RED,              L_ERR   },
  63         { NULL, 0 }
  64 };
  65
  66 int log_dates_utc = 0;
  67
  68
  69 /*
  70  *      Log the message to the logfile. Include the severity and
  71  *      a time stamp.
  72  */
  73 int vradlog(int lvl, const char *fmt, va_list ap)
  74 {
  75         struct main_config_t *myconfig = &mainconfig;
  76         unsigned char *p;
  77         char buffer[8192];
  78         char *unsan;
  79         size_t len;
  80
  81         /*
  82          *      NOT debugging, and trying to log debug messages.
  83          *
  84          *      Throw the message away.
  85          */
  86         if (!debug_flag && (lvl == L_DBG)) {
  87                 return 0;
  88         }
  89
  90         /*
  91          *      If we don't want any messages, then
  92          *      throw them away.
  93          */
  94         if (myconfig->radlog_dest == RADLOG_NULL) {
  95                 return 0;
  96         }
  97
  98         buffer[0] = '\0';
  99         len = 0;
 100
 101         if (myconfig->colourise &&
 102             ((myconfig->radlog_dest == RADLOG_STDOUT) ||
 103              (myconfig->radlog_dest == RADLOG_STDERR))) {
 104                 len += strlcpy(buffer + len, fr_int2str(colours, lvl, ""),
 105                                sizeof(buffer) - len) ;
 106         }
 107
 108         /*
 109          *      Mark the point where we treat the buffer as unsanitized.
 110          */
 111         unsan = buffer + len;
 112
 113         /*
 114          *      Don't print timestamps to syslog, it does that for us.
 115          *      Don't print timestamps for low levels of debugging.
 116          *
 117          *      Print timestamps for non-debugging, and for high levels
 118          *      of debugging.
 119          */
 120         if ((myconfig->radlog_dest != RADLOG_SYSLOG) &&
 121             (debug_flag != 1) && (debug_flag != 2)) {
 122                 time_t timeval;
 123
 124                 timeval = time(NULL);
 125                 CTIME_R(&timeval, buffer + len, sizeof(buffer) - len - 1);
 126
 127                 len = strlen(buffer);
 128
 129                 len += strlcpy(buffer + len,
 130                                fr_int2str(levels, (lvl & ~L_CONS), ": "),
 131                                sizeof(buffer) - len);
 132         }
 133
 134         if (len < sizeof(buffer)) {
 135                 len += vsnprintf(buffer + len,
 136                                  sizeof(buffer) - len - 1, fmt, ap);
 137         }
 138
 139         /*
 140          *      Filter out characters not in Latin-1.
 141          */
 142         for (p = (unsigned char *)unsan; *p != '\0'; p++) {
 143                 if (*p == '\r' || *p == '\n')
 144                         *p = ' ';
 145                 else if (*p == '\t') continue;
 146                 else if (*p < 32 || (*p >= 128 && *p <= 160))
 147                         *p = '?';
 148         }
 149
 150         if (myconfig->colourise && (len < sizeof(buffer)) &&
 151             ((myconfig->radlog_dest == RADLOG_STDOUT) ||
 152              (myconfig->radlog_dest == RADLOG_STDERR))) {
 153                 len += strlcpy(buffer + len, VTC_RESET, sizeof(buffer) - len);
 154         }
 155
 156         if (len < (sizeof(buffer) - 1)) {
 157                 buffer[len]     = '\n';
 158                 buffer[len + 1] = '\0';
 159         } else {
 160                 buffer[len - 1] = '\n';
 161                 buffer[len]     = '\0';
 162         }
 163
 164         switch (myconfig->radlog_dest) {
 165
 166 #ifdef HAVE_SYSLOG_H
 167         case RADLOG_SYSLOG:
 168                 switch(lvl & ~L_CONS) {
 169                         case L_DBG:
 170                                 lvl = LOG_DEBUG;
 171                                 break;
 172                         case L_AUTH:
 173                                 lvl = LOG_NOTICE;
 174                                 break;
 175                         case L_PROXY:
 176                                 lvl = LOG_NOTICE;
 177                                 break;
 178                         case L_ACCT:
 179                                 lvl = LOG_NOTICE;
 180                                 break;
 181                         case L_INFO:
 182                                 lvl = LOG_INFO;
 183                                 break;
 184                         case L_ERR:
 185                                 lvl = LOG_ERR;
 186                                 break;
 187                 }
 188                 syslog(lvl, "%s", buffer);
 189                 break;
 190 #endif
 191
 192         case RADLOG_FILES:
 193         case RADLOG_STDOUT:
 194         case RADLOG_STDERR:
 195                 write(myconfig->radlog_fd, buffer, strlen(buffer));
 196                 break;
 197
 198         default:
 199         case RADLOG_NULL:       /* should have been caught above */
 200                 break;
 201         }
 202
 203         return 0;
 204 }
 205
 206 int log_debug(const char *msg, ...)
 207 {
 208         va_list ap;
 209         int r;
 210
 211         va_start(ap, msg);
 212         r = vradlog(L_DBG, msg, ap);
 213         va_end(ap);
 214
 215         return r;
 216 }
 217
 218 int radlog(int lvl, const char *msg, ...)
 219 {
 220         va_list ap;
 221         int r;
 222
 223         va_start(ap, msg);
 224         r = vradlog(lvl, msg, ap);
 225         va_end(ap);
 226
 227         return r;
 228 }
 229
 230
 231 /*
 232  *      Dump a whole list of attributes to DEBUG2
 233  */
 234 void vp_listdebug(VALUE_PAIR *vp)
 235 {
 236         char tmpPair[70];
 237         for (; vp; vp = vp->next) {
 238                 vp_prints(tmpPair, sizeof(tmpPair), vp);
 239                 DEBUG2("     %s", tmpPair);
 240         }
 241 }
 242
 243 extern char *request_log_file;
 244 #ifdef WITH_COMMAND_SOCKET
 245 extern char *debug_log_file;
 246 #endif
 247
 248 void radlog_request(int lvl, int priority, REQUEST *request, const char *msg, ...)
 249 {
 250         size_t len = 0;
 251         const char *filename = request_log_file;
 252         FILE *fp = NULL;
 253         va_list ap;
 254         char buffer[8192];
 255         char *p;
 256
 257         va_start(ap, msg);
 258
 259         /*
 260          *      Debug messages get treated specially.
 261          */
 262         if (lvl == L_DBG) {
 263                 /*
 264                  *      There is log function, but the debug level
 265                  *      isn't high enough.  OR, we're in debug mode,
 266                  *      and the debug level isn't high enough.  Return.
 267                  */
 268                 if ((request && request->radlog &&
 269                      (priority > request->options)) ||
 270                     ((debug_flag != 0) && (priority > debug_flag))) {
 271                         va_end(ap);
 272                         return;
 273                 }
 274
 275                 /*
 276                  *      Use the debug output file, if specified,
 277                  *      otherwise leave it as "request_log_file".
 278                  */
 279 #ifdef WITH_COMMAND_SOCKET
 280                 filename = debug_log_file;
 281                 if (!filename)
 282 #endif
 283                   filename = request_log_file;
 284
 285                 filename = request_log_file;
 286         }
 287
 288         if (request && filename) {
 289                 radlog_func_t rl = request->radlog;
 290
 291                 request->radlog = NULL;
 292
 293                 /*
 294                  *      This is SLOW!  Doing it for every log message
 295                  *      in every request is NOT recommended!
 296                  */
 297
 298                 radius_xlat(buffer, sizeof(buffer), filename,
 299                             request, NULL, NULL); /* FIXME: escape chars! */
 300                 request->radlog = rl;
 301
 302                 p = strrchr(buffer, FR_DIR_SEP);
 303                 if (p) {
 304                         *p = '\0';
 305                         if (rad_mkdir(buffer, S_IRWXU) < 0) {
 306                                 radlog(L_ERR, "Failed creating %s: %s",
 307                                        buffer,strerror(errno));
 308                                 va_end(ap);
 309                                 return;
 310                         }
 311                         *p = FR_DIR_SEP;
 312                 }
 313
 314                 fp = fopen(buffer, "a");
 315         }
 316
 317         /*
 318          *      Print timestamps to the file.
 319          */
 320         if (fp) {
 321                 time_t timeval;
 322                 timeval = time(NULL);
 323
 324 #ifdef HAVE_GMTIME_R
 325                 if (log_dates_utc) {
 326                         struct tm utc;
 327                         gmtime_r(&timeval, &utc);
 328                         asctime_r(&utc, buffer);
 329                 } else
 330 #endif
 331                         CTIME_R(&timeval, buffer, sizeof(buffer) - 1);
 332
 333                 len = strlen(buffer);
 334                 p = strrchr(buffer, '\n');
 335                 if (p) {
 336                         p[0] = ' ';
 337                         p[1] = '\0';
 338                 }
 339
 340                 len += strlcpy(buffer + len,
 341                                fr_int2str(levels, (lvl & ~L_CONS), ": "),
 342                                sizeof(buffer) - len);
 343
 344                 if (len >= sizeof(buffer)) goto finish;
 345         }
 346
 347         if (request && request->module[0]) {
 348                 len = snprintf(buffer + len, sizeof(buffer) - len, "%s : ",
 349                                request->module);
 350
 351                 if (len >= sizeof(buffer)) goto finish;
 352         }
 353
 354         vsnprintf(buffer + len, sizeof(buffer) - len, msg, ap);
 355
 356         finish:
 357         if (!fp) {
 358                 if (request) {
 359                         radlog(lvl, "(%u) %s", request->number, buffer);
 360                 } else {
 361                         radlog(lvl, "%s", buffer);
 362                 }
 363         } else {
 364                 if (request) fprintf(fp, "(%u) ", request->number);
 365                 fputs(buffer, fp);
 366                 fputc('\n', fp);
 367                 fclose(fp);
 368         }
 369
 370         va_end(ap);
 371 }