git.sur5r.net Git - i3/i3/blob - src/log.c

   1 /*
   2  * vim:ts=4:sw=4:expandtab
   3  *
   4  * i3 - an improved dynamic tiling window manager
   5  * © 2009-2011 Michael Stapelberg and contributors (see also: LICENSE)
   6  *
   7  * log.c: Setting of loglevels, logging functions.
   8  *
   9  */
  10 #include <stdarg.h>
  11 #include <stdio.h>
  12 #include <string.h>
  13 #include <stdbool.h>
  14 #include <stdlib.h>
  15 #include <sys/time.h>
  16 #include <unistd.h>
  17 #include <fcntl.h>
  18 #include <sys/mman.h>
  19 #include <sys/stat.h>
  20 #include <errno.h>
  21
  22 #include "util.h"
  23 #include "log.h"
  24 #include "i3.h"
  25 #include "libi3.h"
  26 #include "shmlog.h"
  27
  28 /* loglevels.h is autogenerated at make time */
  29 #include "loglevels.h"
  30
  31 static uint64_t loglevel = 0;
  32 static bool verbose = false;
  33 static FILE *errorfile;
  34 char *errorfilename;
  35
  36 /* SHM logging variables */
  37
  38 /* The name for the SHM (/i3-log-%pid). Will end up on /dev/shm on most
  39  * systems. Global so that we can clean up at exit. */
  40 char *shmlogname = "";
  41 /* Size limit for the SHM log, by default 25 MiB. Can be overwritten using the
  42  * flag --shmlog-size. */
  43 int shmlog_size = 0;
  44 /* If enabled, logbuffer will point to a memory mapping of the i3 SHM log. */
  45 static char *logbuffer;
  46 /* A pointer (within logbuffer) where data will be written to next. */
  47 static char *logwalk;
  48 /* A pointer to the byte where we last wrapped. Necessary to not print the
  49  * left-overs at the end of the ringbuffer. */
  50 static char *loglastwrap;
  51 /* Size (in bytes) of the i3 SHM log. */
  52 static int logbuffer_size;
  53 /* File descriptor for shm_open. */
  54 static int logbuffer_shm;
  55
  56 /*
  57  * Writes the offsets for the next write and for the last wrap to the
  58  * shmlog_header.
  59  * Necessary to print the i3 SHM log in the correct order.
  60  *
  61  */
  62 static void store_log_markers(void) {
  63     i3_shmlog_header *header = (i3_shmlog_header*)logbuffer;
  64
  65     header->offset_next_write = (logwalk - logbuffer);
  66     header->offset_last_wrap = (loglastwrap - logbuffer);
  67     header->size = logbuffer_size;
  68 }
  69
  70 /*
  71  * Initializes logging by creating an error logfile in /tmp (or
  72  * XDG_RUNTIME_DIR, see get_process_filename()).
  73  *
  74  * Will be called twice if --shmlog-size is specified.
  75  *
  76  */
  77 void init_logging(void) {
  78     if (!errorfilename) {
  79         if (!(errorfilename = get_process_filename("errorlog")))
  80             ELOG("Could not initialize errorlog\n");
  81         else {
  82             errorfile = fopen(errorfilename, "w");
  83             if (fcntl(fileno(errorfile), F_SETFD, FD_CLOEXEC)) {
  84                 ELOG("Could not set close-on-exec flag\n");
  85             }
  86         }
  87     }
  88
  89     /* If this is a debug build (not a release version), we will enable SHM
  90      * logging by default, unless the user turned it off explicitly. */
  91     if (logbuffer == NULL && shmlog_size > 0) {
  92         /* Reserve 1% of the RAM for the logfile, but at max 25 MiB.
  93          * For 512 MiB of RAM this will lead to a 5 MiB log buffer.
  94          * At the moment (2011-12-10), no testcase leads to an i3 log
  95          * of more than ~ 600 KiB. */
  96         long long physical_mem_bytes = (long long)sysconf(_SC_PHYS_PAGES) *
  97                                                   sysconf(_SC_PAGESIZE);
  98         logbuffer_size = min(physical_mem_bytes * 0.01, shmlog_size);
  99         sasprintf(&shmlogname, "/i3-log-%d", getpid());
 100         logbuffer_shm = shm_open(shmlogname, O_RDWR | O_CREAT | O_TRUNC, S_IREAD | S_IWRITE);
 101         if (logbuffer_shm == -1) {
 102             ELOG("Could not shm_open SHM segment for the i3 log: %s\n", strerror(errno));
 103             return;
 104         }
 105
 106         if (ftruncate(logbuffer_shm, logbuffer_size) == -1) {
 107             close(logbuffer_shm);
 108             shm_unlink("/i3-log-");
 109             ELOG("Could not ftruncate SHM segment for the i3 log: %s\n", strerror(errno));
 110             return;
 111         }
 112
 113         logbuffer = mmap(NULL, logbuffer_size, PROT_READ | PROT_WRITE, MAP_SHARED, logbuffer_shm, 0);
 114         if (logbuffer == MAP_FAILED) {
 115             close(logbuffer_shm);
 116             shm_unlink("/i3-log-");
 117             ELOG("Could not mmap SHM segment for the i3 log: %s\n", strerror(errno));
 118             logbuffer = NULL;
 119             return;
 120         }
 121         logwalk = logbuffer + sizeof(i3_shmlog_header);
 122         loglastwrap = logbuffer + logbuffer_size;
 123         store_log_markers();
 124     }
 125 }
 126
 127 /*
 128  * Set verbosity of i3. If verbose is set to true, informative messages will
 129  * be printed to stdout. If verbose is set to false, only errors will be
 130  * printed.
 131  *
 132  */
 133 void set_verbosity(bool _verbose) {
 134     verbose = _verbose;
 135 }
 136
 137 /*
 138  * Enables the given loglevel.
 139  *
 140  */
 141 void add_loglevel(const char *level) {
 142     /* Handle the special loglevel "all" */
 143     if (strcasecmp(level, "all") == 0) {
 144         loglevel = UINT64_MAX;
 145         return;
 146     }
 147
 148     for (int i = 0; i < sizeof(loglevels) / sizeof(char*); i++) {
 149         if (strcasecmp(loglevels[i], level) != 0)
 150             continue;
 151
 152         /* The position in the array (plus one) is the amount of times
 153          * which we need to shift 1 to the left to get our bitmask for
 154          * the specific loglevel. */
 155         loglevel |= (1 << (i+1));
 156         break;
 157     }
 158 }
 159
 160 /*
 161  * Logs the given message to stdout (if print is true) while prefixing the
 162  * current time to it. Additionally, the message will be saved in the i3 SHM
 163  * log if enabled.
 164  * This is to be called by *LOG() which includes filename/linenumber/function.
 165  *
 166  */
 167 static void vlog(const bool print, const char *fmt, va_list args) {
 168     /* Precisely one page to not consume too much memory but to hold enough
 169      * data to be useful. */
 170     static char message[4096];
 171     static struct tm result;
 172     static time_t t;
 173     static struct tm *tmp;
 174     static size_t len;
 175
 176     /* Get current time */
 177     t = time(NULL);
 178     /* Convert time to local time (determined by the locale) */
 179     tmp = localtime_r(&t, &result);
 180     /* Generate time prefix */
 181     len = strftime(message, sizeof(message), "%x %X - ", tmp);
 182
 183     /*
 184      * logbuffer  print
 185      * ----------------
 186      *  true      true   format message, save, print
 187      *  true      false  format message, save
 188      *  false     true   print message only
 189      *  false     false  INVALID, never called
 190      */
 191     if (!logbuffer) {
 192 #ifdef DEBUG_TIMING
 193         struct timeval tv;
 194         gettimeofday(&tv, NULL);
 195         printf("%s%d.%d - ", message, tv.tv_sec, tv.tv_usec);
 196 #else
 197         printf("%s", message);
 198 #endif
 199         vprintf(fmt, args);
 200     } else {
 201         len += vsnprintf(message + len, sizeof(message) - len, fmt, args);
 202         if (len < 0 ) {
 203             fprintf(stderr, "BUG: something is overflowing here. Dropping the log entry\n");
 204             return;
 205         }
 206
 207         if (len >= sizeof(message)) {
 208             fprintf(stderr, "BUG: single log message > 4k\n");
 209         }
 210
 211         /* If there is no space for the current message (plus trailing
 212          * nullbyte) in the ringbuffer, we need to wrap and write to the
 213          * beginning again. */
 214         if ((len+1) >= (logbuffer_size - (logwalk - logbuffer))) {
 215             loglastwrap = logwalk;
 216             logwalk = logbuffer + sizeof(i3_shmlog_header);
 217         }
 218
 219         /* Copy the buffer, terminate it, move the write pointer to the byte after
 220          * our current message. */
 221         strncpy(logwalk, message, len);
 222         logwalk[len] = '\0';
 223         logwalk += len + 1;
 224
 225         store_log_markers();
 226
 227         if (print)
 228             fwrite(message, len, 1, stdout);
 229     }
 230 }
 231
 232 /*
 233  * Logs the given message to stdout while prefixing the current time to it,
 234  * but only if verbose mode is activated.
 235  *
 236  */
 237 void verboselog(char *fmt, ...) {
 238     va_list args;
 239
 240     if (!logbuffer && !verbose)
 241         return;
 242
 243     va_start(args, fmt);
 244     vlog(verbose, fmt, args);
 245     va_end(args);
 246 }
 247
 248 /*
 249  * Logs the given message to stdout while prefixing the current time to it.
 250  *
 251  */
 252 void errorlog(char *fmt, ...) {
 253     va_list args;
 254
 255     va_start(args, fmt);
 256     vlog(true, fmt, args);
 257     va_end(args);
 258
 259     /* also log to the error logfile, if opened */
 260     va_start(args, fmt);
 261     vfprintf(errorfile, fmt, args);
 262     fflush(errorfile);
 263     va_end(args);
 264 }
 265
 266 /*
 267  * Logs the given message to stdout while prefixing the current time to it,
 268  * but only if the corresponding debug loglevel was activated.
 269  * This is to be called by DLOG() which includes filename/linenumber
 270  *
 271  */
 272 void debuglog(uint64_t lev, char *fmt, ...) {
 273     va_list args;
 274
 275     if (!logbuffer && !(loglevel & lev))
 276         return;
 277
 278     va_start(args, fmt);
 279     vlog((loglevel & lev), fmt, args);
 280     va_end(args);
 281 }