1/* Copyright (c) 2012-2013 Apple Inc. All rights reserved. 2 * 3 * @APPLE_LICENSE_HEADER_START@ 4 * 5 * This file contains Original Code and/or Modifications of Original Code 6 * as defined in and that are subject to the Apple Public Source License 7 * Version 2.0 (the 'License'). You may not use this file except in 8 * compliance with the License. Please obtain a copy of the License at 9 * http://www.opensource.apple.com/apsl/ and read it before using this 10 * file. 11 * 12 * The Original Code and all software distributed under the License are 13 * distributed on an 'AS IS' basis, WITHOUT WARRANTY OF ANY KIND, EITHER 14 * EXPRESS OR IMPLIED, AND APPLE HEREBY DISCLAIMS ALL SUCH WARRANTIES, 15 * INCLUDING WITHOUT LIMITATION, ANY WARRANTIES OF MERCHANTABILITY, 16 * FITNESS FOR A PARTICULAR PURPOSE, QUIET ENJOYMENT OR NON-INFRINGEMENT. 17 * Please see the License for the specific language governing rights and 18 * limitations under the License. 19 * 20 * @APPLE_LICENSE_HEADER_END@ 21 */ 22 23#include <dlfcn.h> 24#include <errno.h> 25#include <fcntl.h> 26#include <limits.h> 27#include <mach/mach_time.h> 28#include <os/alloc_once_private.h> 29#include <os/assumes.h> 30#include <os/debug_private.h> 31#include <_simple.h> 32#include <stdarg.h> 33#include <stdbool.h> 34#include <stdio.h> 35#include <stdlib.h> 36#include <string.h> 37#include <syslog.h> 38#include <sys/time.h> 39#include <unistd.h> 40 41struct os_debug_log_globals_s { 42 uint64_t start; 43 os_redirect_t redirect; 44 int logfd; 45 bool prepend_timestamp : 1; 46 bool errors_only : 1; 47}; 48 49// If user picked a filename, use it and only it. 50// Otherwise, first try /var/tmp, then $TMPDIR, then give up. 51static inline 52int 53_os_debug_log_open_file(const char *suggestion) 54{ 55 if (suggestion) { 56 return open(suggestion, O_WRONLY | O_APPEND | O_CREAT | O_NOFOLLOW | 57 O_EXCL | O_CLOEXEC, 0644); 58 } 59 60 int fd; 61 char filename[PATH_MAX]; 62 char path[PATH_MAX]; 63 64 snprintf(filename, sizeof(filename), "os_debug_log.%s.%d.log", getprogname(), 65 getpid()); 66 67 strlcpy(path, "/var/tmp/", sizeof(path)); 68 if (access(path, W_OK) == 0) { 69 strlcat(path, filename, sizeof(path)); 70 fd = open(path, O_WRONLY | O_APPEND | O_CREAT | O_NOFOLLOW | O_EXCL | 71 O_CLOEXEC, 0644); 72 if (fd >= 0) { 73 return fd; 74 } 75 } 76 77 const char *tmpdir = getenv("TMPDIR"); 78 if (tmpdir) { 79 strlcpy(path, tmpdir, sizeof(path)); 80 if (access(path, W_OK) == 0) { 81 strlcat(path, filename, sizeof(path)); 82 fd = open(path, O_WRONLY | O_APPEND | O_CREAT | O_NOFOLLOW | 83 O_EXCL | O_CLOEXEC, 0644); 84 if (fd >= 0) { 85 return fd; 86 } 87 } 88 } 89 90 return -1; 91} 92 93static 94void 95_os_debug_log_init(void *globals) 96{ 97 struct os_debug_log_globals_s *g = globals; 98 99 g->errors_only = false; 100 101 g->redirect = dlsym(RTLD_MAIN_ONLY, "_os_debug_log_redirect_func"); 102 103 // This is a bit of a hack. LIBDISPATCH_LOG is part of dispatch's API. 104 // But now all dispatch logging goes through os_debug_log. So we have to 105 // recognize this env var here in Libc. 106 // rdar://problem/11685359 tracks deprecating LIBDISPATCH_LOG from dispatch. 107 char *e = getenv("LIBDISPATCH_LOG"); 108 if (!e) { 109 e = getenv("OS_DEBUG_LOG"); 110 } 111 112 // Default log destination 113 if (!e || strcmp(e, "YES") == 0) { 114#if DEBUG 115 e = "file"; 116#else 117 e = "syslog"; 118#endif 119 } 120 121 if (strcmp(e, "NO") == 0) { 122 g->logfd = -1; 123 g->errors_only = true; 124 } else if (strcmp(e, "syslog") == 0) { 125 g->logfd = -1; 126 } else if (strcmp(e, "stderr") == 0) { 127 g->logfd = STDERR_FILENO; 128 } else if (strcmp(e, "stdout") == 0) { 129 g->logfd = STDOUT_FILENO; 130 } else if (strcmp(e, "file") == 0) { 131 g->logfd = _os_debug_log_open_file(NULL); 132 if (g->logfd == -1) { 133 g->errors_only = true; 134 } 135 } else { 136 g->logfd = _os_debug_log_open_file(e); 137 if (g->logfd == -1) { 138 g->errors_only = true; 139 } 140 } 141 142 // From now on, g->logfd == -1 means syslog; anything >= 0 is the 143 // fd to use. Remember that file descriptor 0 is a perfectly valid 144 // value for open() to return if you closed (or never had) stdin. 145 146 // Timestamp every log message if logging directly to file and no 147 // redirector is set up. 148 if (g->logfd >= 0 && !g->redirect) { 149 g->prepend_timestamp = true; 150 151 struct timeval tv; 152 gettimeofday(&tv, NULL); 153 154 g->start = mach_absolute_time(); 155 156 dprintf(g->logfd, 157 "=== os_debug_log log file opened for %s[%u] at %ld.%06u", 158 getprogname(), getpid(), 159 tv.tv_sec, tv.tv_usec); 160 if (g->prepend_timestamp) { 161 mach_timebase_info_data_t tbi; 162 if (mach_timebase_info(&tbi) == 0) { 163 dprintf(g->logfd, " [ns=ticks*%u/%u]", 164 tbi.numer, tbi.denom); 165 } 166 } 167 dprintf(g->logfd, " ===\n"); 168 } 169} 170 171#ifndef OS_ALLOC_ONCE_KEY_OS_DEBUG_LOG 172#define OS_ALLOC_ONCE_KEY_OS_DEBUG_LOG OS_ALLOC_ONCE_KEY_OS_TRACE 173#endif 174 175static inline OS_CONST 176struct os_debug_log_globals_s * 177os_debug_log_globals(void) 178{ 179 return (struct os_debug_log_globals_s *) 180 os_alloc_once(OS_ALLOC_ONCE_KEY_OS_DEBUG_LOG, 181 sizeof(struct os_debug_log_globals_s), 182 _os_debug_log_init); 183} 184 185static __attribute__((always_inline)) 186uint64_t 187_os_debug_log_ticks_since_start(void) 188{ 189 return mach_absolute_time() - os_debug_log_globals()->start; 190} 191 192// False on error writing to file 193static inline 194bool 195_os_debug_log_write_fd(int level __attribute__((__unused__)), 196 char *str, int fd) 197{ 198 size_t len = strlen(str); 199 200 str[len++] = '\n'; // overwrite null - don't use str*() anymore 201 202 ssize_t rc, wlen = 0; 203 do { 204 rc = write(fd, &str[wlen], len - wlen); 205 if (os_slowpath(rc == -1)) { 206 if(errno == EINTR) { 207 rc = 0; 208 } else { 209 return false; 210 } 211 } 212 wlen += rc; 213 } while (wlen < len); 214 215 return true; 216} 217 218static __attribute__((__noinline__)) 219void 220_os_debug_log_write_error(void) 221{ 222 char err_str[256]; 223 const char *pfx = "os_debug_log() :"; 224 size_t pfxlen = strlen(pfx); 225 226 strlcpy(err_str, pfx, sizeof(err_str)); 227 strerror_r(errno, err_str+pfxlen, sizeof(err_str)-pfxlen); 228 _simple_asl_log(LOG_ERR, "com.apple.os_debug_log", err_str); 229} 230 231static inline 232void 233_os_debug_log_write(int level, char *str) 234{ 235 int fd = os_debug_log_globals()->logfd; 236 os_redirect_t rdr = os_debug_log_globals()->redirect; 237 // true = redirect has fully handled, don't log 238 if (os_slowpath(rdr) && os_fastpath(rdr(str))) { 239 return; 240 } 241 if (os_slowpath(fd >= 0)) { 242 if (os_fastpath(_os_debug_log_write_fd(level, str, fd))) { 243 return; 244 } else { 245 _os_debug_log_write_error(); 246 os_debug_log_globals()->logfd = -1; 247 // Don't return, fall out to syslog(). 248 } 249 } 250 _simple_asl_log(level, "com.apple.os_debug_log", str); 251} 252 253static __attribute__((always_inline)) 254void 255_os_debug_logv(int level, const char *msg, va_list ap) 256{ 257 if (os_slowpath(os_debug_log_globals()->errors_only) && level > LOG_ERR) { 258 // more important = lower integer 259 return; 260 } 261 char *buf, *freebuf; 262 size_t len; 263 264 len = vasprintf(&buf, msg, ap); 265 if (!buf) { 266 return; 267 } 268 freebuf = buf; 269 270 // The os_debug_log macros prepend many spaces to the format string. 271 // Overwrite them with a timestamp, *or* skip them. 272 const size_t pfxlen = strlen(_OS_DEBUG_LOG_PREFIX); 273 const size_t timelen = 16; 274 __OS_COMPILETIME_ASSERT__(pfxlen >= timelen); 275 276 if (os_fastpath(len > pfxlen)) { 277 if (os_slowpath(os_debug_log_globals()->prepend_timestamp)) { 278 char tmp = buf[timelen]; 279 snprintf(buf, timelen + 1, "%16llu", _os_debug_log_ticks_since_start()); 280 buf[timelen] = tmp; // snprintf's null 281 } else { 282 buf += pfxlen; 283 } 284 } 285 286 _os_debug_log_write(level, buf); 287 free(freebuf); 288} 289 290void 291_os_debug_log_error_str(char *msg) 292{ 293 _os_debug_log_write(LOG_ERR, msg); 294} 295 296OS_FORMAT_PRINTF(1, 2) 297void 298_os_debug_log(const char *msg, ...) 299{ 300 va_list ap; 301 va_start(ap, msg); 302 _os_debug_logv(LOG_DEBUG, msg, ap); 303 va_end(ap); 304} 305