src/shl_log.c

   1 /*
   2  * Log/Debug Interface
   3  * Copyright (c) 2011-2012 David Herrmann <dh.herrmann@googlemail.com>
   4  * Dedicated to the Public Domain
   5  */
   6
   7 /*
   8  * Log/Debug API Implementation
   9  * We provide thread-safety so we need a global lock. Function which
  10  * are prefixed with log__* need the lock to be held. All other functions must
  11  * be called without the lock held.
  12  */
  13
  14 #include <errno.h>
  15 #include <pthread.h>
  16 #include <stdarg.h>
  17 #include <stdbool.h>
  18 #include <stdio.h>
  19 #include <stdlib.h>
  20 #include <string.h>
  21 #include <sys/time.h>
  22 #include "shl_githead.h"
  23 #include "shl_log.h"
  24 #include "shl_misc.h"
  25
  26 /*
  27  * Locking
  28  * We need a global locking mechanism. Use pthread here.
  29  */
  30
  31 static pthread_mutex_t log__mutex = PTHREAD_MUTEX_INITIALIZER;
  32
  33 static inline void log_lock()
  34 {
  35         pthread_mutex_lock(&log__mutex);
  36 }
  37
  38 static inline void log_unlock()
  39 {
  40         pthread_mutex_unlock(&log__mutex);
  41 }
  42
  43 /*
  44  * Time Management
  45  * We print seconds and microseconds since application start for each
  46  * log-message.
  47  */
  48
  49 static struct timeval log__ftime;
  50
  51 static void log__time(long long *sec, long long *usec)
  52 {
  53         struct timeval t;
  54
  55         if (log__ftime.tv_sec == 0 && log__ftime.tv_usec == 0) {
  56                 gettimeofday(&log__ftime, NULL);
  57                 *sec = 0;
  58                 *usec = 0;
  59         } else {
  60                 gettimeofday(&t, NULL);
  61                 *sec = t.tv_sec - log__ftime.tv_sec;
  62                 *usec = (long long)t.tv_usec - (long long)log__ftime.tv_usec;
  63                 if (*usec < 0) {
  64                         *sec -= 1;
  65                         *usec = 1000000 + *usec;
  66                 }
  67         }
  68 }
  69
  70 /*
  71  * Default Values
  72  * Several logging-parameters may be omitted by applications. To provide sane
  73  * default values we provide constants here.
  74  *
  75  * LOG_SUBSYSTEM: By default no subsystem is specified
  76  */
  77
  78 SHL_EXPORT
  79 const struct log_config LOG_CONFIG = {
  80         .sev = {
  81                 [LOG_DEBUG] = 2,
  82                 [LOG_INFO] = 2,
  83                 [LOG_NOTICE] = 2,
  84                 [LOG_WARNING] = 2,
  85                 [LOG_ERROR] = 2,
  86                 [LOG_CRITICAL] = 2,
  87                 [LOG_ALERT] = 2,
  88                 [LOG_FATAL] = 2,
  89         }
  90 };
  91
  92 const char *LOG_SUBSYSTEM = NULL;
  93
  94 /*
  95  * Filters
  96  * By default DEBUG and INFO messages are disabled. If LOG_ENABLE_DEBUG is not
  97  * defined, then all log_debug() statements compile to zero-code and they cannot
  98  * be enabled on runtime.
  99  * To enable DEBUG or INFO messages at runtime, you can either specify that they
 100  * should be enabled globally, per file or specify a custom filter. Other
 101  * messages than DEBUG and INFO cannot be configured. However, additional
 102  * configuration options may be added later.
 103  *
 104  * Use log_set_config() to enable debug/info messages globally. If you
 105  * enable a global message type, then all other filters are skipped. If you
 106  * disable a global message type then fine-grained filters can take effect.
 107  *
 108  * To enable DEBUG/INFO messages for a specific source-file, you can add
 109  * this line to the top of the source file:
 110  *   #define LOG_CONFIG LOG_STATIC_CONFIG(true, true)
 111  * So info and debug messages are enabled for this file on compile-time. First
 112  * parameter of LOG_STATIC_CONFIG is for debug, second one for info.
 113  *
 114  * Or you can add new configurations on runtime. Runtime configurations take a
 115  * filter parameter and a config parameter. The filter specifies what messages
 116  * are affected and the config parameter specifies what action is performed.
 117  */
 118
 119 static struct log_config log__gconfig = {
 120         .sev = {
 121                 [LOG_DEBUG] = 0,
 122                 [LOG_INFO] = 0,
 123                 [LOG_NOTICE] = 1,
 124                 [LOG_WARNING] = 1,
 125                 [LOG_ERROR] = 1,
 126                 [LOG_CRITICAL] = 1,
 127                 [LOG_ALERT] = 1,
 128                 [LOG_FATAL] = 1,
 129         }
 130 };
 131
 132 struct log_dynconf {
 133         struct log_dynconf *next;
 134         int handle;
 135         struct log_filter filter;
 136         struct log_config config;
 137 };
 138
 139 static struct log_dynconf *log__dconfig = NULL;
 140
 141 void log_set_config(const struct log_config *config)
 142 {
 143         if (!config)
 144                 return;
 145
 146         log_lock();
 147         log__gconfig = *config;
 148         log_unlock();
 149 }
 150
 151 int log_add_filter(const struct log_filter *filter,
 152                         const struct log_config *config)
 153 {
 154         struct log_dynconf *dconf;
 155         int ret;
 156
 157         if (!filter || !config)
 158                 return -EINVAL;
 159
 160         dconf = malloc(sizeof(*dconf));
 161         if (!dconf)
 162                 return -ENOMEM;
 163
 164         memset(dconf, 0, sizeof(*dconf));
 165         memcpy(&dconf->filter, filter, sizeof(*filter));
 166         memcpy(&dconf->config, config, sizeof(*config));
 167
 168         log_lock();
 169         if (log__dconfig)
 170                 dconf->handle = log__dconfig->handle + 1;
 171         dconf->next = log__dconfig;
 172         log__dconfig = dconf;
 173         ret = dconf->handle;
 174         log_unlock();
 175
 176         return ret;
 177 }
 178
 179 void log_rm_filter(int handle)
 180 {
 181         struct log_dynconf *dconf, *i;
 182
 183         dconf = NULL;
 184
 185         log_lock();
 186         if (log__dconfig) {
 187                 if (log__dconfig->handle == handle) {
 188                         dconf = log__dconfig;
 189                         log__dconfig = dconf->next;
 190                 } else for (i = log__dconfig; i->next; i = i->next) {
 191                         dconf = i->next;
 192                         if (dconf->handle == handle) {
 193                                 i->next = dconf->next;
 194                                 break;
 195                         }
 196                 }
 197         }
 198         log_unlock();
 199
 200         free(dconf);
 201 }
 202
 203 void log_clean_filters()
 204 {
 205         struct log_dynconf *dconf;
 206
 207         log_lock();
 208         while ((dconf = log__dconfig)) {
 209                 log__dconfig = dconf->next;
 210                 free(dconf);
 211         }
 212         log_unlock();
 213 }
 214
 215 static bool log__matches(const struct log_filter *filter,
 216                                 const char *file,
 217                                 int line,
 218                                 const char *func,
 219                                 const char *subs)
 220 {
 221         if (*filter->file) {
 222                 if (!file || strncmp(filter->file, file, LOG_STRMAX))
 223                         return false;
 224         }
 225         if (filter->line >= 0 && filter->line != line)
 226                 return false;
 227         if (*filter->func) {
 228                 if (!func || strncmp(filter->func, func, LOG_STRMAX))
 229                         return false;
 230         }
 231         if (*filter->subs) {
 232                 if (!subs || strncmp(filter->subs, subs, LOG_STRMAX))
 233                         return false;
 234         }
 235         return true;
 236 }
 237
 238 static bool log__omit(const char *file,
 239                         int line,
 240                         const char *func,
 241                         const struct log_config *config,
 242                         const char *subs,
 243                         enum log_severity sev)
 244 {
 245         int val;
 246         struct log_dynconf *dconf;
 247
 248         if (sev >= LOG_SEV_NUM)
 249                 return false;
 250
 251         if (config) {
 252                 val = config->sev[sev];
 253                 if (val == 0)
 254                         return true;
 255                 if (val == 1)
 256                         return false;
 257         }
 258
 259         for (dconf = log__dconfig; dconf; dconf = dconf->next) {
 260                 if (log__matches(&dconf->filter, file, line, func, subs)) {
 261                         val = dconf->config.sev[sev];
 262                         if (val == 0)
 263                                 return true;
 264                         if (val == 1)
 265                                 return false;
 266                 }
 267         }
 268
 269         val = log__gconfig.sev[sev];
 270         if (val == 0)
 271                 return true;
 272         if (val == 1)
 273                 return false;
 274
 275         return false;
 276 }
 277
 278 /*
 279  * Forward declaration so we can use the locked-versions in other functions
 280  * here. Be careful to avoid deadlocks, though.
 281  * Also set default log-subsystem to "log" for all logging inside this API.
 282  */
 283
 284 static void log__submit(const char *file,
 285                         int line,
 286                         const char *func,
 287                         const struct log_config *config,
 288                         const char *subs,
 289                         unsigned int sev,
 290                         const char *format,
 291                         va_list args);
 292
 293 static void log__format(const char *file,
 294                         int line,
 295                         const char *func,
 296                         const struct log_config *config,
 297                         const char *subs,
 298                         unsigned int sev,
 299                         const char *format,
 300                         ...);
 301
 302 #define LOG_SUBSYSTEM "log"
 303
 304 /*
 305  * Log-File
 306  * By default logging is done to stderr. However, you can set a file which is
 307  * used instead of stderr for logging. We do not provide complex log-rotation or
 308  * management functions, you can add them yourself or use a proper init-system
 309  * like systemd which does this for you.
 310  * We cannot set this to "stderr" as stderr might not be a compile-time
 311  * constant. Therefore, NULL means stderr.
 312  */
 313
 314 static FILE *log__file = NULL;
 315
 316 int log_set_file(const char *file)
 317 {
 318         FILE *f, *old;
 319
 320         if (file) {
 321                 f = fopen(file, "a");
 322                 if (!f) {
 323                         log_err("cannot change log-file to %s (%d): %m",
 324                                 file, errno);
 325                         return -EFAULT;
 326                 }
 327         } else {
 328                 f = NULL;
 329                 file = "<default>";
 330         }
 331
 332         old = NULL;
 333
 334         log_lock();
 335         if (log__file != f) {
 336                 log__format(LOG_DEFAULT, LOG_NOTICE,
 337                                 "set log-file to %s", file);
 338                 old = log__file;
 339                 log__file = f;
 340                 f = NULL;
 341         }
 342         log_unlock();
 343
 344         if (f)
 345                 fclose(f);
 346         if (old)
 347                 fclose(old);
 348
 349         return 0;
 350 }
 351
 352 /*
 353  * Basic logger
 354  * The log__submit function writes the message into the current log-target. It
 355  * must be called with log__mutex locked.
 356  * log__format does the same but first converts the argument list into a
 357  * va_list.
 358  * By default the current time elapsed since the first message was logged is
 359  * prepended to the message. file, line and func information are appended to the
 360  * message if sev == LOG_DEBUG.
 361  * The subsystem, if not NULL, is prepended as "SUBS: " to the message and a
 362  * newline is always appended by default. Multiline-messages are not allowed and
 363  * do not make sense here.
 364  */
 365
 366 static const char *log__sev2str[] = {
 367         [LOG_DEBUG] = "DEBUG",
 368         [LOG_INFO] = "INFO",
 369         [LOG_NOTICE] = "NOTICE",
 370         [LOG_WARNING] = "WARNING",
 371         [LOG_ERROR] = "ERROR",
 372         [LOG_CRITICAL] = "CRITICAL",
 373         [LOG_ALERT] = "ALERT",
 374         [LOG_FATAL] = "FATAL",
 375 };
 376
 377 static void log__submit(const char *file,
 378                         int line,
 379                         const char *func,
 380                         const struct log_config *config,
 381                         const char *subs,
 382                         unsigned int sev,
 383                         const char *format,
 384                         va_list args)
 385 {
 386         const char *prefix = NULL;
 387         FILE *out;
 388         long long sec, usec;
 389
 390         if (log__omit(file, line, func, config, subs, sev))
 391                 return;
 392
 393         if (log__file)
 394                 out = log__file;
 395         else
 396                 out = stderr;
 397
 398         log__time(&sec, &usec);
 399
 400         if (sev < LOG_SEV_NUM)
 401                 prefix = log__sev2str[sev];
 402
 403         if (prefix) {
 404                 if (subs)
 405                         fprintf(out, "[%.4lld.%.6lld] %s: %s: ",
 406                                 sec, usec, prefix, subs);
 407                 else
 408                         fprintf(out, "[%.4lld.%.6lld] %s: ",
 409                                 sec, usec, prefix);
 410         } else {
 411                 if (subs)
 412                         fprintf(out, "[%.4lld.%.6lld] %s: ", sec, usec, subs);
 413                 else
 414                         fprintf(out, "[%.4lld.%.6lld] ", sec, usec);
 415         }
 416
 417         vfprintf(out, format, args);
 418
 419         if (sev == LOG_DEBUG) {
 420                 if (!func)
 421                         func = "<unknown>";
 422                 if (!file)
 423                         file = "<unknown>";
 424                 if (line < 0)
 425                         line = 0;
 426                 fprintf(out, " (%s() in %s:%d)\n", func, file, line);
 427         } else {
 428                 fprintf(out, "\n");
 429         }
 430 }
 431
 432 static void log__format(const char *file,
 433                         int line,
 434                         const char *func,
 435                         const struct log_config *config,
 436                         const char *subs,
 437                         unsigned int sev,
 438                         const char *format,
 439                         ...)
 440 {
 441         va_list list;
 442
 443         va_start(list, format);
 444         log__submit(file, line, func, config, subs, sev, format, list);
 445         va_end(list);
 446 }
 447
 448 SHL_EXPORT
 449 void log_submit(const char *file,
 450                 int line,
 451                 const char *func,
 452                 const struct log_config *config,
 453                 const char *subs,
 454                 unsigned int sev,
 455                 const char *format,
 456                 va_list args)
 457 {
 458         int saved_errno = errno;
 459
 460         log_lock();
 461         log__submit(file, line, func, config, subs, sev, format, args);
 462         log_unlock();
 463
 464         errno = saved_errno;
 465 }
 466
 467 SHL_EXPORT
 468 void log_format(const char *file,
 469                 int line,
 470                 const char *func,
 471                 const struct log_config *config,
 472                 const char *subs,
 473                 unsigned int sev,
 474                 const char *format,
 475                 ...)
 476 {
 477         va_list list;
 478         int saved_errno = errno;
 479
 480         va_start(list, format);
 481         log_lock();
 482         log__submit(file, line, func, config, subs, sev, format, list);
 483         log_unlock();
 484         va_end(list);
 485
 486         errno = saved_errno;
 487 }
 488
 489 SHL_EXPORT
 490 void log_llog(void *data,
 491               const char *file,
 492               int line,
 493               const char *func,
 494               const char *subs,
 495               unsigned int sev,
 496               const char *format,
 497               va_list args)
 498 {
 499         log_submit(file, line, func, NULL, subs, sev, format, args);
 500 }
 501
 502 void log_print_init(const char *appname)
 503 {
 504         if (!appname)
 505                 appname = "<unknown>";
 506         log_format(LOG_DEFAULT_CONF, NULL, LOG_NOTICE,
 507                    "%s Revision %s %s %s", appname,
 508                    shl_git_head, __DATE__, __TIME__);
 509 }