log: rework logging logic so that we don't keep /dev/console open

This commit is contained in:
Lennart Poettering 2010-05-15 17:25:08 +02:00
parent d9a76d8f86
commit 843d264384
6 changed files with 234 additions and 146 deletions

246
log.c
View File

@ -37,6 +37,7 @@
static LogTarget log_target = LOG_TARGET_CONSOLE;
static int log_max_level = LOG_DEBUG;
static int console_fd = STDERR_FILENO;
static int syslog_fd = -1;
static int kmsg_fd = -1;
@ -44,26 +45,52 @@ static int kmsg_fd = -1;
* use here. */
static char *log_abort_msg = NULL;
void log_close_kmsg(void) {
void log_close_console(void) {
if (kmsg_fd >= 0) {
close_nointr_nofail(kmsg_fd);
kmsg_fd = -1;
if (console_fd < 0)
return;
if (getpid() == 1 || console_fd != STDERR_FILENO) {
close_nointr_nofail(console_fd);
console_fd = -1;
}
}
int log_open_kmsg(void) {
static int log_open_console(void) {
if (log_target != LOG_TARGET_KMSG) {
log_close_kmsg();
if (console_fd >= 0)
return 0;
}
if (getpid() == 1) {
if ((console_fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0) {
log_error("Failed to open /dev/console for logging: %s", strerror(-console_fd));
return console_fd;
}
log_info("Succesfully opened /dev/console for logging.");
} else
console_fd = STDERR_FILENO;
return 0;
}
void log_close_kmsg(void) {
if (kmsg_fd < 0)
return;
close_nointr_nofail(kmsg_fd);
kmsg_fd = -1;
}
static int log_open_kmsg(void) {
if (kmsg_fd >= 0)
return 0;
if ((kmsg_fd = open("/dev/kmsg", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0) {
log_info("Failed to open syslog for logging: %s", strerror(errno));
log_info("Failed to open /dev/kmsg for logging: %s", strerror(errno));
return -errno;
}
@ -74,13 +101,14 @@ int log_open_kmsg(void) {
void log_close_syslog(void) {
if (syslog_fd >= 0) {
close_nointr_nofail(syslog_fd);
syslog_fd = -1;
}
if (syslog_fd < 0)
return;
close_nointr_nofail(syslog_fd);
syslog_fd = -1;
}
int log_open_syslog(void) {
static int log_open_syslog(void) {
union {
struct sockaddr sa;
struct sockaddr_un un;
@ -88,24 +116,20 @@ int log_open_syslog(void) {
struct timeval tv;
int r;
if (log_target != LOG_TARGET_SYSLOG) {
log_close_syslog();
return 0;
}
if (syslog_fd >= 0)
return 0;
if ((syslog_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0)) < 0)
return -errno;
if ((syslog_fd = socket(AF_UNIX, SOCK_DGRAM|SOCK_CLOEXEC, 0)) < 0) {
r = -errno;
goto fail;
}
/* Make sure we don't block for more than 5s when talking to
* syslog */
timeval_store(&tv, SYSLOG_TIMEOUT_USEC);
if (setsockopt(syslog_fd, SOL_SOCKET, SO_SNDTIMEO, &tv, sizeof(tv)) < 0) {
r = -errno;
log_close_syslog();
return r;
goto fail;
}
zero(sa);
@ -114,15 +138,45 @@ int log_open_syslog(void) {
if (connect(syslog_fd, &sa.sa, sizeof(sa)) < 0) {
r = -errno;
log_close_syslog();
log_info("Failed to open syslog for logging: %s", strerror(-r));
return r;
goto fail;
}
log_info("Succesfully opened syslog for logging.");
return 0;
fail:
log_close_syslog();
log_info("Failed to open syslog for logging: %s", strerror(-r));
return r;
}
int log_open(void) {
int r;
/* If we don't use the console we close it here, to not get
* killed by SAK. If we don't use syslog we close it here so
* that we are not confused by somebody deleting the socket in
* the fs. If we don't use /dev/kmsg we still keep it open,
* because there is no reason to close it. */
if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
log_target == LOG_TARGET_SYSLOG)
if ((r = log_open_syslog()) >= 0) {
log_close_console();
return r;
}
if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
log_target == LOG_TARGET_KMSG)
if ((r = log_open_kmsg()) >= 0) {
log_close_syslog();
log_close_console();
return r;
}
log_close_syslog();
return log_open_console();
}
void log_set_target(LogTarget target) {
@ -138,27 +192,39 @@ void log_set_max_level(int level) {
log_max_level = level;
}
static void write_to_console(
static int write_to_console(
int level,
const char*file,
int line,
const char *func,
const char *format,
va_list ap) {
const char *buffer) {
const char *prefix, *suffix;
char location[64];
struct iovec iovec[5];
unsigned n = 0;
bool highlight;
if (LOG_PRI(level) <= LOG_ERR) {
prefix = "\x1B[1;31m";
suffix = "\x1B[0m";
} else {
prefix = "";
suffix = "";
}
if (console_fd < 0)
return 0;
fprintf(stderr, "(%s:%u) %s", file, line, prefix);
vfprintf(stderr, format, ap);
fprintf(stderr, "%s\n", suffix);
snprintf(location, sizeof(location), "(%s:%u) ", file, line);
char_array_0(location);
highlight = LOG_PRI(level) <= LOG_ERR;
zero(iovec);
IOVEC_SET_STRING(iovec[n++], location);
if (highlight)
IOVEC_SET_STRING(iovec[n++], "\x1B[1;31m");
IOVEC_SET_STRING(iovec[n++], buffer);
if (highlight)
IOVEC_SET_STRING(iovec[n++], "\x1B[0m");
IOVEC_SET_STRING(iovec[n++], "\n");
if (writev(console_fd, iovec, n) < 0)
return -errno;
return 1;
}
static int write_to_syslog(
@ -166,18 +232,16 @@ static int write_to_syslog(
const char*file,
int line,
const char *func,
const char *format,
va_list ap) {
const char *buffer) {
char header_priority[16], header_time[64], header_pid[16];
char buffer[LOG_BUFFER_MAX];
struct iovec iovec[5];
struct msghdr msghdr;
time_t t;
struct tm *tm;
if (syslog_fd < 0)
return -EIO;
return 0;
snprintf(header_priority, sizeof(header_priority), "<%i>", LOG_MAKEPRI(LOG_DAEMON, LOG_PRI(level)));
char_array_0(header_priority);
@ -192,9 +256,6 @@ static int write_to_syslog(
snprintf(header_pid, sizeof(header_pid), "[%llu]: ", (unsigned long long) getpid());
char_array_0(header_pid);
vsnprintf(buffer, sizeof(buffer), format, ap);
char_array_0(buffer);
zero(iovec);
IOVEC_SET_STRING(iovec[0], header_priority);
IOVEC_SET_STRING(iovec[1], header_time);
@ -209,7 +270,7 @@ static int write_to_syslog(
if (sendmsg(syslog_fd, &msghdr, 0) < 0)
return -errno;
return 0;
return 1;
}
static int write_to_kmsg(
@ -217,15 +278,13 @@ static int write_to_kmsg(
const char*file,
int line,
const char *func,
const char *format,
va_list ap) {
const char *buffer) {
char header_priority[16], header_pid[16];
char buffer[LOG_BUFFER_MAX];
struct iovec iovec[5];
if (kmsg_fd < 0)
return -EIO;
return 0;
snprintf(header_priority, sizeof(header_priority), "<%i>", LOG_PRI(level));
char_array_0(header_priority);
@ -233,57 +292,77 @@ static int write_to_kmsg(
snprintf(header_pid, sizeof(header_pid), "[%llu]: ", (unsigned long long) getpid());
char_array_0(header_pid);
vsnprintf(buffer, sizeof(buffer), format, ap);
char_array_0(buffer);
zero(iovec);
IOVEC_SET_STRING(iovec[0], header_priority);
IOVEC_SET_STRING(iovec[1], __progname);
IOVEC_SET_STRING(iovec[2], header_pid);
IOVEC_SET_STRING(iovec[3], buffer);
IOVEC_SET_STRING(iovec[4], (char*) "\n");
IOVEC_SET_STRING(iovec[4], "\n");
if (writev(kmsg_fd, iovec, ELEMENTSOF(iovec)) < 0)
return -errno;
return 0;
return 1;
}
#define LOG_DISPATCH(level,file,line,func,format) \
do { \
va_list _ap; \
bool written = false; \
if (log_target == LOG_TARGET_KMSG) { \
va_start(_ap, format); \
written = write_to_kmsg(level, file, line, func, format, _ap) >= 0; \
va_end(_ap); \
} else if (log_target == LOG_TARGET_SYSLOG) { \
va_start(_ap, format); \
written = write_to_syslog(level, file, line, func, format, _ap) >= 0; \
va_end(_ap); \
} \
if (!written) { \
va_start(_ap, format); \
write_to_console(level, file, line, func, format, _ap); \
va_end(_ap); \
} \
} while (false)
static int log_dispatch(
int level,
const char*file,
int line,
const char *func,
const char *buffer) {
void log_meta(
int r;
if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
log_target == LOG_TARGET_SYSLOG) {
if ((r = write_to_syslog(level, file, line, func, buffer)) < 0) {
log_close_syslog();
log_open_kmsg();
} else if (r > 0)
return r;
}
if (log_target == LOG_TARGET_SYSLOG_OR_KMSG ||
log_target == LOG_TARGET_KMSG) {
if ((r = write_to_kmsg(level, file, line, func, buffer)) < 0) {
log_close_kmsg();
log_open_console();
} else if (r > 0)
return r;
}
return write_to_console(level, file, line, func, buffer);
}
int log_meta(
int level,
const char*file,
int line,
const char *func,
const char *format, ...) {
int saved_errno;
char buffer[LOG_BUFFER_MAX];
int saved_errno, r;
va_list ap;
if (_likely(LOG_PRI(level) > log_max_level))
return;
return 0;
saved_errno = errno;
LOG_DISPATCH(level, file, line, func, format);
va_start(ap, format);
vsnprintf(buffer, sizeof(buffer), format, ap);
va_end(ap);
char_array_0(buffer);
r = log_dispatch(level, file, line, func, buffer);
errno = saved_errno;
return r;
}
void log_assert(
@ -293,8 +372,8 @@ void log_assert(
const char *format, ...) {
static char buffer[LOG_BUFFER_MAX];
va_list ap;
int saved_errno = errno;
va_list ap;
va_start(ap, format);
vsnprintf(buffer, sizeof(buffer), format, ap);
@ -303,7 +382,7 @@ void log_assert(
char_array_0(buffer);
log_abort_msg = buffer;
LOG_DISPATCH(LOG_CRIT, file, line, func, format);
log_dispatch(LOG_CRIT, file, line, func, buffer);
abort();
/* If the user chose to ignore this SIGABRT, we are happy to go on, as if nothing happened. */
@ -354,6 +433,7 @@ static const char *const log_target_table[] = {
[LOG_TARGET_CONSOLE] = "console",
[LOG_TARGET_SYSLOG] = "syslog",
[LOG_TARGET_KMSG] = "kmsg",
[LOG_TARGET_SYSLOG_OR_KMSG] = "syslog-or-kmsg",
};
DEFINE_STRING_TABLE_LOOKUP(log_target, LogTarget);

14
log.h
View File

@ -26,10 +26,13 @@
#include "macro.h"
/* If set to SYSLOG and /dev/log can not be opened we fall back to
* KSMG. If KMSG fails, we fall back to CONSOLE */
typedef enum LogTarget{
LOG_TARGET_CONSOLE,
LOG_TARGET_SYSLOG,
LOG_TARGET_KMSG,
LOG_TARGET_SYSLOG,
LOG_TARGET_SYSLOG_OR_KMSG,
_LOG_TARGET_MAX,
_LOG_TARGET_INVALID = -1
} LogTarget;
@ -43,14 +46,15 @@ int log_set_max_level_from_string(const char *e);
LogTarget log_get_target(void);
int log_get_max_level(void);
void log_close_kmsg(void);
int log_open_kmsg(void);
int log_open(void);
void log_close_syslog(void);
int log_open_syslog(void);
void log_close_kmsg(void);
void log_close_console(void);
void log_parse_environment(void);
void log_meta(
int log_meta(
int level,
const char*file,
int line,

98
main.c
View File

@ -136,23 +136,18 @@ _noreturn static void crash(int sig) {
if ((pid = fork()) < 0)
log_error("Failed to fork off crash shell: %s", strerror(errno));
else if (pid == 0) {
int fd;
int fd, r;
if ((fd = acquire_terminal("/dev/console", false, true)) < 0) {
log_error("Failed to acquire terminal: %s", strerror(-fd));
_exit(1);
}
if (dup2(fd, STDIN_FILENO) < 0 ||
dup2(fd, STDOUT_FILENO) < 0 ||
dup2(fd, STDERR_FILENO) < 0) {
log_error("Failed to duplicate terminal fd: %s", strerror(errno));
if ((r = make_stdio(fd)) < 0) {
log_error("Failed to duplicate terminal fd: %s", strerror(-r));
_exit(1);
}
if (fd >= 3)
close_nointr_nofail(fd);
execl("/bin/sh", "/bin/sh", NULL);
log_error("execl() failed: %s", strerror(errno));
@ -182,51 +177,40 @@ static void install_crash_handler(void) {
assert_se(sigaction(SIGABRT, &sa, NULL) == 0);
}
static int console_setup(bool do_reset) {
int tty_fd = -1, null_fd = -1, r = 0;
static int make_null_stdio(void) {
int null_fd, r;
/* If we are init, we connect stdout/stderr to /dev/console
* and stdin to /dev/null and make sure we don't have a
* controlling tty. */
if ((null_fd = open("/dev/null", O_RDWR)) < 0) {
log_error("Failed to open /dev/null: %m");
return -errno;
}
if ((r = make_stdio(null_fd)) < 0)
log_warning("Failed to dup2() device: %s", strerror(-r));
return r;
}
static int console_setup(bool do_reset) {
int tty_fd, r;
/* If we are init, we connect stdin/stdout/stderr to /dev/null
* and make sure we don't have a controlling tty. */
release_terminal();
if ((tty_fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY)) < 0) {
if (!do_reset)
return 0;
if ((tty_fd = open_terminal("/dev/console", O_WRONLY|O_NOCTTY|O_CLOEXEC)) < 0) {
log_error("Failed to open /dev/console: %s", strerror(-tty_fd));
r = -tty_fd;
goto finish;
return -tty_fd;
}
if ((null_fd = open("/dev/null", O_RDONLY)) < 0) {
log_error("Failed to open /dev/null: %m");
r = -errno;
goto finish;
}
assert(tty_fd >= 3);
assert(null_fd >= 3);
if (do_reset)
if (reset_terminal(tty_fd) < 0)
log_error("Failed to reset /dev/console: %m");
if (dup2(tty_fd, STDOUT_FILENO) < 0 ||
dup2(tty_fd, STDERR_FILENO) < 0 ||
dup2(null_fd, STDIN_FILENO) < 0) {
log_error("Failed to dup2() device: %m");
r = -errno;
goto finish;
}
r = 0;
finish:
if (tty_fd >= 0)
close_nointr_nofail(tty_fd);
if (null_fd >= 0)
close_nointr_nofail(null_fd);
if ((r = reset_terminal(tty_fd)) < 0)
log_error("Failed to reset /dev/console: %s", strerror(-r));
close_nointr_nofail(tty_fd);
return r;
}
@ -499,7 +483,7 @@ static int help(void) {
" -h --help Show this help\n"
" --default=UNIT Set default unit\n"
" --log-level=LEVEL Set log level\n"
" --log-target=TARGET Set log target (console, syslog, kmsg)\n"
" --log-target=TARGET Set log target (console, syslog, kmsg, syslog-or-kmsg)\n"
" --running-as=AS Set running as (init, system, session)\n"
" --test Determine startup sequence, dump it and exit\n"
" --dump-configuration-items Dump understood unit configuration items\n"
@ -571,11 +555,10 @@ int main(int argc, char *argv[]) {
FDSet *fds = NULL;
bool reexecute = false;
if (getpid() == 1)
if (getpid() == 1) {
running_as = MANAGER_INIT;
else if (getuid() == 0)
running_as = MANAGER_SYSTEM;
else
log_set_target(LOG_TARGET_SYSLOG_OR_KMSG);
} else
running_as = MANAGER_SESSION;
if (set_default_unit(SPECIAL_DEFAULT_TARGET) < 0)
@ -640,17 +623,18 @@ int main(int argc, char *argv[]) {
umask(0);
}
/* Reset the console, but only if this is really init and we
* are freshly booted */
if (running_as == MANAGER_INIT && action == ACTION_RUN)
console_setup(getpid() == 1 && !serialization);
/* Make sure D-Bus doesn't fiddle with the SIGPIPE handlers */
dbus_connection_set_change_sigpipe(FALSE);
/* Reset the console, but only if this is really init and we
* are freshly booted */
if (running_as != MANAGER_SESSION && action == ACTION_RUN) {
console_setup(getpid() == 1 && !serialization);
make_null_stdio();
}
/* Open the logging devices, if possible and necessary */
log_open_syslog();
log_open_kmsg();
log_open();
/* Make sure we leave a core dump without panicing the
* kernel. */

2
unit.c
View File

@ -1027,7 +1027,7 @@ void unit_notify(Unit *u, UnitActiveState os, UnitActiveState ns) {
/* The syslog daemon just might have become
* available, hence try to connect to it, if
* we aren't yet connected. */
log_open_syslog();
log_open();
if (u->meta.type == UNIT_MOUNT)
/* Another directory became available, let's

18
util.c
View File

@ -1890,6 +1890,24 @@ int parse_usec(const char *t, usec_t *usec) {
return 0;
}
int make_stdio(int fd) {
int r, s, t;
assert(fd >= 0);
r = dup2(fd, STDIN_FILENO);
s = dup2(fd, STDOUT_FILENO);
t = dup2(fd, STDERR_FILENO);
if (fd >= 3)
close_nointr_nofail(fd);
if (r < 0 || s < 0 || t < 0)
return -errno;
return 0;
}
static const char *const ioprio_class_table[] = {
[IOPRIO_CLASS_NONE] = "none",
[IOPRIO_CLASS_RT] = "realtime",

2
util.h
View File

@ -179,6 +179,8 @@ bool chars_intersect(const char *a, const char *b);
char *format_timestamp(char *buf, size_t l, usec_t t);
int make_stdio(int fd);
#define DEFINE_STRING_TABLE_LOOKUP(name,type) \
const char *name##_to_string(type i) { \
if (i < 0 || i >= (type) ELEMENTSOF(name##_table)) \