#include <dlfcn.h>
#include <errno.h>
#include <fcntl.h>
#include <limits.h>
#include <mach/mach_time.h>
#include <os/alloc_once_private.h>
#include <os/trace.h>
#include <_simple.h>
#include <stdarg.h>
#include <stdbool.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <syslog.h>
#include <sys/time.h>
#include <unistd.h>
typedef bool (*os_redirect_t)(const char *);
struct os_trace_globals_s {
uint64_t start;
os_redirect_t redirect;
int logfd;
bool prepend_timestamp : 1;
bool errors_only : 1;
};
static inline
int
_os_trace_open_file(const char *suggestion)
{
if (suggestion) {
return open(suggestion, O_WRONLY | O_APPEND | O_CREAT | O_NOFOLLOW |
O_EXCL | O_CLOEXEC, 0644);
}
int fd;
char filename[PATH_MAX];
char path[PATH_MAX];
snprintf(filename, sizeof(filename), "os_trace.%s.%d.log", getprogname(),
getpid());
strlcpy(path, "/var/tmp/", sizeof(path));
if (access(path, W_OK) == 0) {
strlcat(path, filename, sizeof(path));
fd = open(path, O_WRONLY | O_APPEND | O_CREAT | O_NOFOLLOW | O_EXCL |
O_CLOEXEC, 0644);
if (fd >= 0) {
return fd;
}
}
const char *tmpdir = getenv("TMPDIR");
if (tmpdir) {
strlcpy(path, tmpdir, sizeof(path));
if (access(path, W_OK) == 0) {
strlcat(path, filename, sizeof(path));
fd = open(path, O_WRONLY | O_APPEND | O_CREAT | O_NOFOLLOW |
O_EXCL | O_CLOEXEC, 0644);
if (fd >= 0) {
return fd;
}
}
}
return -1;
}
static
void
_os_trace_init(void *globals)
{
struct os_trace_globals_s *g = globals;
g->errors_only = false;
g->redirect = dlsym(RTLD_MAIN_ONLY, "_os_trace_redirect_func");
char *e = getenv("LIBDISPATCH_LOG");
if (!e) {
e = getenv("OS_TRACE");
}
if (!e || strcmp(e, "YES") == 0) {
#if DEBUG
e = "file";
#else
e = "syslog";
#endif
}
if (strcmp(e, "NO") == 0) {
g->logfd = -1;
g->errors_only = true;
} else if (strcmp(e, "syslog") == 0) {
g->logfd = -1;
} else if (strcmp(e, "stderr") == 0) {
g->logfd = STDERR_FILENO;
} else if (strcmp(e, "stdout") == 0) {
g->logfd = STDOUT_FILENO;
} else if (strcmp(e, "file") == 0) {
g->logfd = _os_trace_open_file(NULL);
if (g->logfd == -1) {
g->errors_only = true;
}
} else {
g->logfd = _os_trace_open_file(e);
if (g->logfd == -1) {
g->errors_only = true;
}
}
if (g->logfd >= 0 && !g->redirect) {
g->prepend_timestamp = true;
struct timeval tv;
gettimeofday(&tv, NULL);
g->start = mach_absolute_time();
dprintf(g->logfd,
"=== os_trace log file opened for %s[%u] at %ld.%06u",
getprogname(), getpid(),
tv.tv_sec, tv.tv_usec);
if (g->prepend_timestamp) {
mach_timebase_info_data_t tbi;
if (mach_timebase_info(&tbi) == 0) {
dprintf(g->logfd, " [ns=ticks*%u/%u]",
tbi.numer, tbi.denom);
}
}
dprintf(g->logfd, " ===\n");
}
}
static inline __OS_CONST
struct os_trace_globals_s *
os_trace_globals(void)
{
return (struct os_trace_globals_s *)
os_alloc_once(OS_ALLOC_ONCE_KEY_OS_TRACE,
sizeof(struct os_trace_globals_s),
_os_trace_init);
}
static __attribute__((always_inline))
uint64_t
_os_trace_ticks_since_start(void)
{
return mach_absolute_time() - os_trace_globals()->start;
}
static inline
bool
_os_trace_write_fd(int level __attribute__((__unused__)),
char *str, int fd)
{
size_t len = strlen(str);
str[len++] = '\n';
ssize_t rc, wlen = 0;
do {
rc = write(fd, &str[wlen], len - wlen);
if (os_slowpath(rc == -1)) {
if(errno == EINTR) {
rc = 0;
} else {
return false;
}
}
wlen += rc;
} while (wlen < len);
return true;
}
static __attribute__((__noinline__))
void
_os_trace_write_error(void)
{
char err_str[256];
const char *pfx = "os_trace() :";
size_t pfxlen = strlen(pfx);
strlcpy(err_str, pfx, sizeof(err_str));
strerror_r(errno, err_str+pfxlen, sizeof(err_str)-pfxlen);
_simple_asl_log(LOG_ERR, "com.apple.os_trace", err_str);
}
static inline
void
_os_trace_write(int level, char *str)
{
int fd = os_trace_globals()->logfd;
os_redirect_t rdr = os_trace_globals()->redirect;
if (os_slowpath(rdr) && os_fastpath(rdr(str))) {
return;
}
if (os_slowpath(fd >= 0)) {
if (os_fastpath(_os_trace_write_fd(level, str, fd))) {
return;
} else {
_os_trace_write_error();
os_trace_globals()->logfd = -1;
}
}
_simple_asl_log(level, "com.apple.os_trace", str);
}
static __attribute__((always_inline))
void
_os_tracev(int level, const char *msg, va_list ap)
{
if (os_slowpath(os_trace_globals()->errors_only) && level > LOG_ERR) {
return;
}
char *buf, *freebuf;
size_t len;
len = vasprintf(&buf, msg, ap);
if (!buf) {
return;
}
freebuf = buf;
const size_t pfxlen = strlen(_OS_TRACE_PREFIX);
const size_t timelen = 16;
__OS_COMPILETIME_ASSERT__(pfxlen >= timelen);
if (os_fastpath(len > pfxlen)) {
if (os_slowpath(os_trace_globals()->prepend_timestamp)) {
char tmp = buf[timelen];
snprintf(buf, timelen + 1, "%16llu", _os_trace_ticks_since_start());
buf[timelen] = tmp; } else {
buf += pfxlen;
}
}
_os_trace_write(level, buf);
free(freebuf);
}
void
_os_trace_error_str(char *msg)
{
_os_trace_write(LOG_ERR, msg);
}
__OS_PRINTFLIKE(1, 2)
void
_os_trace(const char *msg, ...)
{
va_list ap;
va_start(ap, msg);
_os_tracev(LOG_DEBUG, msg, ap);
va_end(ap);
}