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 /* keep track of whether we've run openlog() */
  38 static int openlog_run = 0;
  39 #endif
  40
  41 static int can_update_log_fp = TRUE;
  42 static FILE *log_fp = NULL;
  43
  44 /*
  45  * Logging facility names
  46  */
  47 static const FR_NAME_NUMBER levels[] = {
  48         { ": Debug: ",          L_DBG   },
  49         { ": Auth: ",           L_AUTH  },
  50         { ": Proxy: ",          L_PROXY },
  51         { ": Info: ",           L_INFO  },
  52         { ": Acct: ",           L_ACCT  },
  53         { ": Error: ",          L_ERR   },
  54         { NULL, 0 }
  55 };
  56
  57 /*
  58  *      Log the message to the logfile. Include the severity and
  59  *      a time stamp.
  60  */
  61 int vradlog(int lvl, const char *fmt, va_list ap)
  62 {
  63         struct main_config_t *myconfig = &mainconfig;
  64         int fd = myconfig->radlog_fd;
  65         FILE *fp = NULL;
  66         unsigned char *p;
  67         char buffer[8192];
  68         int len, print_timestamp = 0;
  69
  70         /*
  71          *      NOT debugging, and trying to log debug messages.
  72          *
  73          *      Throw the message away.
  74          */
  75         if (!debug_flag && (lvl == L_DBG)) {
  76                 return 0;
  77         }
  78
  79         /*
  80          *      If we don't want any messages, then
  81          *      throw them away.
  82          */
  83         if (myconfig->radlog_dest == RADLOG_NULL) {
  84                 return 0;
  85         }
  86
  87         /*
  88          *      Don't print timestamps to syslog, it does that for us.
  89          *      Don't print timestamps for low levels of debugging.
  90          *
  91          *      Print timestamps for non-debugging, and for high levels
  92          *      of debugging.
  93          */
  94         if ((myconfig->radlog_dest != RADLOG_SYSLOG) &&
  95             (debug_flag != 1) && (debug_flag != 2)) {
  96                 print_timestamp = 1;
  97         }
  98
  99         if ((fd != -1) &&
 100             (myconfig->radlog_dest != RADLOG_STDOUT) &&
 101             (myconfig->radlog_dest != RADLOG_STDERR)) {
 102                 myconfig->radlog_fd = -1;
 103                 fd = -1;
 104         }
 105
 106         *buffer = '\0';
 107         len = 0;
 108         if (fd != -1) {
 109                 /*
 110                  *      Use it, rather than anything else.
 111                  */
 112
 113 #ifdef HAVE_SYSLOG_H
 114         } else if (myconfig->radlog_dest == RADLOG_SYSLOG) {
 115                 /*
 116                  *      Open run openlog() on the first log message
 117                  */
 118                 if(!openlog_run) {
 119                         openlog(progname, LOG_PID, myconfig->syslog_facility);
 120                         openlog_run = 1;
 121                 }
 122 #endif
 123
 124         } else if (myconfig->radlog_dest == RADLOG_FILES) {
 125                 if (!myconfig->log_file) {
 126                         /*
 127                          *      Errors go to stderr, in the hope that
 128                          *      they will be printed somewhere.
 129                          */
 130                         if (lvl & L_ERR) {
 131                                 fd = STDERR_FILENO;
 132                                 print_timestamp = 0;
 133                                 snprintf(buffer, sizeof(buffer), "%s: ", progname);
 134                                 len = strlen(buffer);
 135                         } else {
 136                                 /*
 137                                  *      No log file set.  Discard it.
 138                                  */
 139                                 return 0;
 140                         }
 141
 142                 } else if (log_fp) {
 143                         struct stat buf;
 144
 145                         if (stat(myconfig->log_file, &buf) < 0) {
 146                                 fclose(log_fp);
 147                                 log_fp = fr_log_fp = NULL;
 148                         }
 149                 }
 150
 151                 if (!log_fp && myconfig->log_file) {
 152                         fp = fopen(myconfig->log_file, "a");
 153                         if (!fp) {
 154                                 fprintf(stderr, "%s: Couldn't open %s for logging: %s\n",
 155                                         progname, myconfig->log_file, strerror(errno));
 156
 157                                 fprintf(stderr, "  (");
 158                                 vfprintf(stderr, fmt, ap);  /* the message that caused the log */
 159                                 fprintf(stderr, ")\n");
 160                                 return -1;
 161                         }
 162                         setlinebuf(fp);
 163                 }
 164
 165                 /*
 166                  *      We can only set the global variable log_fp IF
 167                  *      we have no child threads.  If we do have child
 168                  *      threads, each thread has to open it's own FP.
 169                  */
 170                 if (can_update_log_fp && fp) fr_log_fp = log_fp = fp;
 171         }
 172
 173         if (print_timestamp) {
 174                 const char *s;
 175                 time_t timeval;
 176
 177                 timeval = time(NULL);
 178                 CTIME_R(&timeval, buffer + len, sizeof(buffer) - len - 1);
 179
 180                 s = fr_int2str(levels, (lvl & ~L_CONS), ": ");
 181
 182                 strcat(buffer, s);
 183                 len = strlen(buffer);
 184         }
 185
 186         vsnprintf(buffer + len, sizeof(buffer) - len - 1, fmt, ap);
 187
 188         /*
 189          *      Filter out characters not in Latin-1.
 190          */
 191         for (p = (unsigned char *)buffer; *p != '\0'; p++) {
 192                 if (*p == '\r' || *p == '\n')
 193                         *p = ' ';
 194                 else if (*p == '\t') continue;
 195                 else if (*p < 32 || (*p >= 128 && *p <= 160))
 196                         *p = '?';
 197         }
 198         strcat(buffer, "\n");
 199
 200 #ifdef HAVE_SYSLOG_H
 201         if (myconfig->radlog_dest == RADLOG_SYSLOG) {
 202                 switch(lvl & ~L_CONS) {
 203                         case L_DBG:
 204                                 lvl = LOG_DEBUG;
 205                                 break;
 206                         case L_AUTH:
 207                                 lvl = LOG_NOTICE;
 208                                 break;
 209                         case L_PROXY:
 210                                 lvl = LOG_NOTICE;
 211                                 break;
 212                         case L_ACCT:
 213                                 lvl = LOG_NOTICE;
 214                                 break;
 215                         case L_INFO:
 216                                 lvl = LOG_INFO;
 217                                 break;
 218                         case L_ERR:
 219                                 lvl = LOG_ERR;
 220                                 break;
 221                 }
 222                 syslog(lvl, "%s", buffer);
 223         } else
 224 #endif
 225         if (log_fp != NULL) {
 226                 fputs(buffer, log_fp);
 227         } else if (fp != NULL) {
 228                 fputs(buffer, fp);
 229                 fclose(fp);
 230         } else if (fd >= 0) {
 231                 write(fd, buffer, strlen(buffer));
 232         }
 233
 234         return 0;
 235 }
 236
 237 int log_debug(const char *msg, ...)
 238 {
 239         va_list ap;
 240         int r;
 241
 242         va_start(ap, msg);
 243         r = vradlog(L_DBG, msg, ap);
 244         va_end(ap);
 245
 246         return r;
 247 }
 248
 249 int radlog(int lvl, const char *msg, ...)
 250 {
 251         va_list ap;
 252         int r;
 253
 254         va_start(ap, msg);
 255         r = vradlog(lvl, msg, ap);
 256         va_end(ap);
 257
 258         return r;
 259 }
 260
 261
 262 /*
 263  *      Dump a whole list of attributes to DEBUG2
 264  */
 265 void vp_listdebug(VALUE_PAIR *vp)
 266 {
 267         char tmpPair[70];
 268         for (; vp; vp = vp->next) {
 269                 vp_prints(tmpPair, sizeof(tmpPair), vp);
 270                 DEBUG2("     %s", tmpPair);
 271         }
 272 }
 273
 274 /*
 275  *      If the server is running with multiple threads, signal the log
 276  *      subsystem that we're about to START multiple threads.  Once
 277  *      that happens, we can no longer open/close the log_fp in a
 278  *      child thread, as writing to global variables causes a race
 279  *      condition.
 280  *
 281  *      We also close the fr_log_fp, as it can no longer write to the
 282  *      log file (if any).
 283  *
 284  *      All of this work is because we want to catch the case of the
 285  *      administrator deleting the log file.  If that happens, we want
 286  *      the logs to go to the *new* file, and not the *old* one.
 287  */
 288 void force_log_reopen(void)
 289 {
 290         can_update_log_fp = 0;
 291
 292         if (mainconfig.radlog_dest != RADLOG_FILES) return;
 293
 294         if (log_fp) fclose(log_fp);
 295         fr_log_fp = log_fp = NULL;
 296 }
 297
 298 extern char *request_log_file;
 299 char *debug_log_file = NULL;
 300
 301 void radlog_request(int lvl, int priority, REQUEST *request, const char *msg, ...)
 302 {
 303         size_t len = 0;
 304         const char *filename = request_log_file;
 305         FILE *fp = NULL;
 306         va_list ap;
 307         char buffer[1024];
 308
 309         va_start(ap, msg);
 310
 311         /*
 312          *      Debug messages get treated specially.
 313          */
 314         if (lvl == L_DBG) {
 315                 /*
 316                  *      There is log function, but the debug level
 317                  *      isn't high enough.  OR, we're in debug mode,
 318                  *      and the debug level isn't high enough.  Return.
 319                  */
 320                 if ((request && request->radlog &&
 321                      (priority > request->options)) ||
 322                     ((debug_flag != 0) && (priority > debug_flag))) {
 323                         va_end(ap);
 324                         return;
 325                 }
 326
 327                 /*
 328                  *      Use the debug output file, if specified,
 329                  *      otherwise leave it as "request_log_file".
 330                  */
 331                 filename = debug_log_file;
 332                 if (!filename) filename = request_log_file;
 333
 334                 /*
 335                  *      Debug messages get mashed to L_INFO for
 336                  *      radius.log.
 337                  */
 338                 if (!filename) lvl = L_INFO;
 339         }
 340
 341         if (request && filename) {
 342                 char *p;
 343                 radlog_func_t rl = request->radlog;
 344
 345                 request->radlog = NULL;
 346
 347                 /*
 348                  *      This is SLOW!  Doing it for every log message
 349                  *      in every request is NOT recommended!
 350                  */
 351
 352                 radius_xlat(buffer, sizeof(buffer), filename,
 353                             request, NULL); /* FIXME: escape chars! */
 354                 request->radlog = rl;
 355
 356                 p = strrchr(buffer, FR_DIR_SEP);
 357                 if (p) {
 358                         *p = '\0';
 359                         if (rad_mkdir(buffer, S_IRWXU) < 0) {
 360                                 radlog(L_ERR, "Failed creating %s: %s",
 361                                        buffer,strerror(errno));
 362                                 va_end(ap);
 363                                 return;
 364                         }
 365                         *p = FR_DIR_SEP;
 366                 }
 367
 368                 fp = fopen(buffer, "a");
 369         }
 370
 371         /*
 372          *      Print timestamps to the file.
 373          */
 374         if (fp) {
 375                 char *s;
 376                 time_t timeval;
 377                 timeval = time(NULL);
 378
 379                 CTIME_R(&timeval, buffer + len, sizeof(buffer) - len - 1);
 380
 381                 s = strrchr(buffer, '\n');
 382                 if (s) {
 383                         s[0] = ' ';
 384                         s[1] = '\0';
 385                 }
 386
 387                 s = fr_int2str(levels, (lvl & ~L_CONS), ": ");
 388
 389                 strcat(buffer, s);
 390                 len = strlen(buffer);
 391         }
 392
 393         if (request && request->module[0]) {
 394                 snprintf(buffer + len, sizeof(buffer) + len, "[%s] ", request->module);
 395                 len = strlen(buffer);
 396         }
 397         vsnprintf(buffer + len, sizeof(buffer) - len, msg, ap);
 398
 399         if (!fp) {
 400                 if (request) {
 401                         radlog(lvl, "(%u) %s", request->number, buffer);
 402                 } else {
 403                         radlog(lvl, "%s", buffer);
 404                 }
 405         } else {
 406                 if (request) fprintf(fp, "(%u) ", request->number);
 407                 fputs(buffer, fp);
 408                 fputc('\n', fp);
 409                 fclose(fp);
 410         }
 411
 412         va_end(ap);
 413 }