Codebase list i3-gaps / 6a17515 src / log.c
6a17515

Tree @6a17515 (Download .tar.gz)

log.c @6a17515raw · history · blame

  1
  2
  3
  4
  5
  6
  7
  8
  9
 10
 11
 12
 13
 14
 15
 16
 17
 18
 19
 20
 21
 22
 23
 24
 25
 26
 27
 28
 29
 30
 31
 32
 33
 34
 35
 36
 37
 38
 39
 40
 41
 42
 43
 44
 45
 46
 47
 48
 49
 50
 51
 52
 53
 54
 55
 56
 57
 58
 59
 60
 61
 62
 63
 64
 65
 66
 67
 68
 69
 70
 71
 72
 73
 74
 75
 76
 77
 78
 79
 80
 81
 82
 83
 84
 85
 86
 87
 88
 89
 90
 91
 92
 93
 94
 95
 96
 97
 98
 99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
363
364
365
366
367
368
369
370
371
372
373
374
375
376
377
378
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416
417
418
419
420
421
422
423
424
425
426
/*
 * vim:ts=4:sw=4:expandtab
 *
 * i3 - an improved dynamic tiling window manager
 * © 2009 Michael Stapelberg and contributors (see also: LICENSE)
 *
 * log.c: Logging functions.
 *
 */
#include <config.h>

#include "all.h"
#include "shmlog.h"

#include <ev.h>
#include <libgen.h>
#include <sys/socket.h>
#include <sys/un.h>
#include <errno.h>
#include <fcntl.h>
#include <stdarg.h>
#include <stdbool.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/mman.h>
#include <sys/stat.h>
#include <sys/time.h>
#include <unistd.h>

#if defined(__APPLE__)
#include <sys/sysctl.h>
#endif

static bool debug_logging = false;
static bool verbose = false;
static FILE *errorfile;
char *errorfilename;

/* SHM logging variables */

/* The name for the SHM (/i3-log-%pid). Will end up on /dev/shm on most
 * systems. Global so that we can clean up at exit. */
char *shmlogname = "";
/* Size limit for the SHM log, by default 25 MiB. Can be overwritten using the
 * flag --shmlog-size. */
int shmlog_size = 0;
/* If enabled, logbuffer will point to a memory mapping of the i3 SHM log. */
static char *logbuffer;
/* A pointer (within logbuffer) where data will be written to next. */
static char *logwalk;
/* A pointer to the shmlog header */
static i3_shmlog_header *header;
/* A pointer to the byte where we last wrapped. Necessary to not print the
 * left-overs at the end of the ringbuffer. */
static char *loglastwrap;
/* Size (in bytes) of the i3 SHM log. */
static int logbuffer_size;
/* File descriptor for shm_open. */
static int logbuffer_shm;
/* Size (in bytes) of physical memory */
static long long physical_mem_bytes;

typedef struct log_client {
    int fd;

    TAILQ_ENTRY(log_client)
    clients;
} log_client;

TAILQ_HEAD(log_client_head, log_client)
log_clients = TAILQ_HEAD_INITIALIZER(log_clients);

void log_broadcast_to_clients(const char *message, size_t len);

/*
 * Writes the offsets for the next write and for the last wrap to the
 * shmlog_header.
 * Necessary to print the i3 SHM log in the correct order.
 *
 */
static void store_log_markers(void) {
    header->offset_next_write = (logwalk - logbuffer);
    header->offset_last_wrap = (loglastwrap - logbuffer);
    header->size = logbuffer_size;
}

/*
 * Initializes logging by creating an error logfile in /tmp (or
 * XDG_RUNTIME_DIR, see get_process_filename()).
 *
 * Will be called twice if --shmlog-size is specified.
 *
 */
void init_logging(void) {
    if (!errorfilename) {
        if (!(errorfilename = get_process_filename("errorlog")))
            fprintf(stderr, "Could not initialize errorlog\n");
        else {
            errorfile = fopen(errorfilename, "w");
            if (!errorfile) {
                fprintf(stderr, "Could not initialize errorlog on %s: %s\n",
                        errorfilename, strerror(errno));
            } else {
                if (fcntl(fileno(errorfile), F_SETFD, FD_CLOEXEC)) {
                    fprintf(stderr, "Could not set close-on-exec flag\n");
                }
            }
        }
    }
    if (physical_mem_bytes == 0) {
#if defined(__APPLE__)
        int mib[2] = {CTL_HW, HW_MEMSIZE};
        size_t length = sizeof(long long);
        sysctl(mib, 2, &physical_mem_bytes, &length, NULL, 0);
#else
        physical_mem_bytes = (long long)sysconf(_SC_PHYS_PAGES) *
                             sysconf(_SC_PAGESIZE);
#endif
    }
    /* Start SHM logging if shmlog_size is > 0. shmlog_size is SHMLOG_SIZE by
     * default on development versions, and 0 on release versions. If it is
     * not > 0, the user has turned it off, so let's close the logbuffer. */
    if (shmlog_size > 0 && logbuffer == NULL)
        open_logbuffer();
    else if (shmlog_size <= 0 && logbuffer)
        close_logbuffer();
    atexit(purge_zerobyte_logfile);
}

/*
 * Opens the logbuffer.
 *
 */
void open_logbuffer(void) {
    /* Reserve 1% of the RAM for the logfile, but at max 25 MiB.
     * For 512 MiB of RAM this will lead to a 5 MiB log buffer.
     * At the moment (2011-12-10), no testcase leads to an i3 log
     * of more than ~ 600 KiB. */
    logbuffer_size = shmlog_size;
    if (physical_mem_bytes * 0.01 < (long long)shmlog_size) {
        logbuffer_size = physical_mem_bytes * 0.01;
    }

#if defined(__FreeBSD__)
    sasprintf(&shmlogname, "/tmp/i3-log-%d", getpid());
#else
    sasprintf(&shmlogname, "/i3-log-%d", getpid());
#endif
    logbuffer_shm = shm_open(shmlogname, O_RDWR | O_CREAT, S_IREAD | S_IWRITE);
    if (logbuffer_shm == -1) {
        fprintf(stderr, "Could not shm_open SHM segment for the i3 log: %s\n", strerror(errno));
        return;
    }

#if defined(__OpenBSD__) || defined(__APPLE__)
    if (ftruncate(logbuffer_shm, logbuffer_size) == -1) {
        fprintf(stderr, "Could not ftruncate SHM segment for the i3 log: %s\n", strerror(errno));
#else
    int ret;
    if ((ret = posix_fallocate(logbuffer_shm, 0, logbuffer_size)) != 0) {
        fprintf(stderr, "Could not ftruncate SHM segment for the i3 log: %s\n", strerror(ret));
#endif
        close(logbuffer_shm);
        shm_unlink(shmlogname);
        return;
    }

    logbuffer = mmap(NULL, logbuffer_size, PROT_READ | PROT_WRITE, MAP_SHARED, logbuffer_shm, 0);
    if (logbuffer == MAP_FAILED) {
        close_logbuffer();
        fprintf(stderr, "Could not mmap SHM segment for the i3 log: %s\n", strerror(errno));
        return;
    }

    /* Initialize with 0-bytes, just to be sure… */
    memset(logbuffer, '\0', logbuffer_size);

    header = (i3_shmlog_header *)logbuffer;

    logwalk = logbuffer + sizeof(i3_shmlog_header);
    loglastwrap = logbuffer + logbuffer_size;
    store_log_markers();
}

/*
 * Closes the logbuffer.
 *
 */
void close_logbuffer(void) {
    close(logbuffer_shm);
    shm_unlink(shmlogname);
    free(shmlogname);
    logbuffer = NULL;
    shmlogname = "";
}

/*
 * Set verbosity of i3. If verbose is set to true, informative messages will
 * be printed to stdout. If verbose is set to false, only errors will be
 * printed.
 *
 */
void set_verbosity(bool _verbose) {
    verbose = _verbose;
}

/*
 * Get debug logging.
 *
 */
bool get_debug_logging(void) {
    return debug_logging;
}

/*
 * Set debug logging.
 *
 */
void set_debug_logging(const bool _debug_logging) {
    debug_logging = _debug_logging;
}

/*
 * Logs the given message to stdout (if print is true) while prefixing the
 * current time to it. Additionally, the message will be saved in the i3 SHM
 * log if enabled.
 * This is to be called by *LOG() which includes filename/linenumber/function.
 *
 */
static void vlog(const bool print, const char *fmt, va_list args) {
    /* Precisely one page to not consume too much memory but to hold enough
     * data to be useful. */
    static char message[4096];
    static struct tm result;
    static time_t t;
    static struct tm *tmp;
    static size_t len;

    /* Get current time */
    t = time(NULL);
    /* Convert time to local time (determined by the locale) */
    tmp = localtime_r(&t, &result);
    /* Generate time prefix */
    len = strftime(message, sizeof(message), "%x %X - ", tmp);

    /*
     * logbuffer  print
     * ----------------
     *  true      true   format message, save, print
     *  true      false  format message, save
     *  false     true   print message only
     *  false     false  INVALID, never called
     */
    if (!logbuffer) {
#ifdef DEBUG_TIMING
        struct timeval tv;
        gettimeofday(&tv, NULL);
        printf("%s%d.%d - ", message, tv.tv_sec, tv.tv_usec);
#else
        printf("%s", message);
#endif
        vprintf(fmt, args);
    } else {
        len += vsnprintf(message + len, sizeof(message) - len, fmt, args);
        if (len >= sizeof(message)) {
            fprintf(stderr, "BUG: single log message > 4k\n");

            /* vsnprintf returns the number of bytes that *would have been written*,
             * not the actual amount written. Thus, limit len to sizeof(message) to avoid
             * memory corruption and outputting garbage later.  */
            len = sizeof(message);

            /* Punch in a newline so the next log message is not dangling at
             * the end of the truncated message. */
            message[len - 2] = '\n';
        }

        /* If there is no space for the current message in the ringbuffer, we
         * need to wrap and write to the beginning again. */
        if (len >= (size_t)(logbuffer_size - (logwalk - logbuffer))) {
            loglastwrap = logwalk;
            logwalk = logbuffer + sizeof(i3_shmlog_header);
            store_log_markers();
            header->wrap_count++;
        }

        /* Copy the buffer, move the write pointer to the byte after our
         * current message. */
        strncpy(logwalk, message, len);
        logwalk += len;

        store_log_markers();

        if (print)
            fwrite(message, len, 1, stdout);

        log_broadcast_to_clients(message, len);
    }
}

/*
 * Logs the given message to stdout while prefixing the current time to it,
 * but only if verbose mode is activated.
 *
 */
void verboselog(char *fmt, ...) {
    va_list args;

    if (!logbuffer && !verbose)
        return;

    va_start(args, fmt);
    vlog(verbose, fmt, args);
    va_end(args);
}

/*
 * Logs the given message to stdout while prefixing the current time to it.
 *
 */
void errorlog(char *fmt, ...) {
    va_list args;

    va_start(args, fmt);
    vlog(true, fmt, args);
    va_end(args);

    /* also log to the error logfile, if opened */
    va_start(args, fmt);
    vfprintf(errorfile, fmt, args);
    fflush(errorfile);
    va_end(args);
}

/*
 * Logs the given message to stdout while prefixing the current time to it,
 * but only if debug logging was activated.
 * This is to be called by DLOG() which includes filename/linenumber
 *
 */
void debuglog(char *fmt, ...) {
    va_list args;

    if (!logbuffer && !(debug_logging))
        return;

    va_start(args, fmt);
    vlog(debug_logging, fmt, args);
    va_end(args);
}

/*
 * Deletes the unused log files. Useful if i3 exits immediately, eg.
 * because --get-socketpath was called. We don't care for syscall
 * failures. This function is invoked automatically when exiting.
 */
void purge_zerobyte_logfile(void) {
    struct stat st;
    char *slash;

    if (!errorfilename)
        return;

    /* don't delete the log file if it contains something */
    if ((stat(errorfilename, &st)) == -1 || st.st_size > 0)
        return;

    if (unlink(errorfilename) == -1)
        return;

    if ((slash = strrchr(errorfilename, '/')) != NULL) {
        *slash = '\0';
        /* possibly fails with ENOTEMPTY if there are files (or
         * sockets) left. */
        rmdir(errorfilename);
    }
}

char *current_log_stream_socket_path = NULL;

/*
 * Handler for activity on the listening socket, meaning that a new client
 * has just connected and we should accept() them. Sets up the event handler
 * for activity on the new connection and inserts the file descriptor into
 * the list of log clients.
 *
 */
void log_new_client(EV_P_ struct ev_io *w, int revents) {
    struct sockaddr_un peer;
    socklen_t len = sizeof(struct sockaddr_un);
    int fd;
    if ((fd = accept(w->fd, (struct sockaddr *)&peer, &len)) < 0) {
        if (errno != EINTR) {
            perror("accept()");
        }
        return;
    }

    /* Close this file descriptor on exec() */
    (void)fcntl(fd, F_SETFD, FD_CLOEXEC);

    set_nonblock(fd);

    log_client *client = scalloc(1, sizeof(log_client));
    client->fd = fd;
    TAILQ_INSERT_TAIL(&log_clients, client, clients);

    DLOG("log: new client connected on fd %d\n", fd);
}

void log_broadcast_to_clients(const char *message, size_t len) {
    log_client *current = TAILQ_FIRST(&log_clients);
    while (current != TAILQ_END(&log_clients)) {
        /* XXX: In case slow connections turn out to be a problem here
         * (unlikely as long as i3-dump-log is the only consumer), introduce
         * buffering, similar to the IPC interface. */
        ssize_t n = writeall(current->fd, message, len);
        log_client *previous = current;
        current = TAILQ_NEXT(current, clients);
        if (n < 0) {
            TAILQ_REMOVE(&log_clients, previous, clients);
            free(previous);
        }
    }
}