Move init's kernel logging into libbase.

am: 7bc87a5a78

Change-Id: Ie5e359e8bd7dee4c0549072c7e955eeefe57d785
This commit is contained in:
Elliott Hughes 2016-08-05 00:30:00 +00:00 committed by android-build-merger
commit e2a7eb17b5
7 changed files with 107 additions and 89 deletions

View File

@ -53,8 +53,8 @@ enum LogId {
typedef std::function<void(LogId, LogSeverity, const char*, const char*,
unsigned int, const char*)> LogFunction;
extern void StderrLogger(LogId, LogSeverity, const char*, const char*,
unsigned int, const char*);
void KernelLogger(LogId, LogSeverity, const char*, const char*, unsigned int, const char*);
void StderrLogger(LogId, LogSeverity, const char*, const char*, unsigned int, const char*);
#ifdef __ANDROID__
// We expose this even though it is the default because a user that wants to
@ -79,17 +79,14 @@ class LogdLogger {
// The tag (or '*' for the global level) comes first, followed by a colon and a
// letter indicating the minimum priority level we're expected to log. This can
// be used to reveal or conceal logs with specific tags.
extern void InitLogging(char* argv[], LogFunction&& logger);
void InitLogging(char* argv[], LogFunction&& logger);
// Configures logging using the default logger (logd for the device, stderr for
// the host).
extern void InitLogging(char* argv[]);
void InitLogging(char* argv[]);
// Replace the current logger.
extern void SetLogger(LogFunction&& logger);
// Get the minimum severity level for logging.
extern LogSeverity GetMinimumLogSeverity();
void SetLogger(LogFunction&& logger);
class ErrnoRestorer {
public:
@ -334,6 +331,12 @@ class LogMessage {
DISALLOW_COPY_AND_ASSIGN(LogMessage);
};
// Get the minimum severity level for logging.
LogSeverity GetMinimumLogSeverity();
// Set the minimum severity level for logging, returning the old severity.
LogSeverity SetMinimumLogSeverity(LogSeverity new_severity);
// Allows to temporarily change the minimum severity level for logging.
class ScopedLogSeverity {
public:

View File

@ -14,12 +14,13 @@
* limitations under the License.
*/
#ifdef _WIN32
#if defined(_WIN32)
#include <windows.h>
#endif
#include "android-base/logging.h"
#include <fcntl.h>
#include <libgen.h>
#include <time.h>
@ -30,6 +31,10 @@
#include <errno.h>
#endif
#if defined(__linux__)
#include <sys/uio.h>
#endif
#include <iostream>
#include <limits>
#include <sstream>
@ -172,10 +177,6 @@ static bool gInitialized = false;
static LogSeverity gMinimumLogSeverity = INFO;
static auto& gProgramInvocationName = *new std::unique_ptr<std::string>();
LogSeverity GetMinimumLogSeverity() {
return gMinimumLogSeverity;
}
static const char* ProgramInvocationName() {
if (gProgramInvocationName == nullptr) {
gProgramInvocationName.reset(new std::string(getprogname()));
@ -184,6 +185,42 @@ static const char* ProgramInvocationName() {
return gProgramInvocationName->c_str();
}
#if defined(__linux__)
void KernelLogger(android::base::LogId, android::base::LogSeverity severity,
const char* tag, const char*, unsigned int, const char* msg) {
static constexpr int kLogSeverityToKernelLogLevel[] = {
[android::base::VERBOSE] = 7, // KERN_DEBUG (there is no verbose kernel log level)
[android::base::DEBUG] = 7, // KERN_DEBUG
[android::base::INFO] = 6, // KERN_INFO
[android::base::WARNING] = 4, // KERN_WARNING
[android::base::ERROR] = 3, // KERN_ERROR
[android::base::FATAL] = 2, // KERN_CRIT
};
static_assert(arraysize(kLogSeverityToKernelLogLevel) == android::base::FATAL + 1,
"Mismatch in size of kLogSeverityToKernelLogLevel and values in LogSeverity");
static int klog_fd = TEMP_FAILURE_RETRY(open("/dev/kmsg", O_WRONLY | O_CLOEXEC));
if (klog_fd == -1) return;
int level = kLogSeverityToKernelLogLevel[severity];
// The kernel's printk buffer is only 1024 bytes.
// TODO: should we automatically break up long lines into multiple lines?
// Or we could log but with something like "..." at the end?
char buf[1024];
size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %s\n", level, tag, msg);
if (size > sizeof(buf)) {
size = snprintf(buf, sizeof(buf), "<%d>%s: %zu-byte message too long for printk\n",
level, tag, size);
}
iovec iov[1];
iov[0].iov_base = buf;
iov[0].iov_len = size;
TEMP_FAILURE_RETRY(writev(klog_fd, iov, 1));
}
#endif
void StderrLogger(LogId, LogSeverity severity, const char*, const char* file,
unsigned int line, const char* message) {
struct tm now;
@ -211,28 +248,26 @@ void StderrLogger(LogId, LogSeverity severity, const char*, const char* file,
LogdLogger::LogdLogger(LogId default_log_id) : default_log_id_(default_log_id) {
}
static const android_LogPriority kLogSeverityToAndroidLogPriority[] = {
ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO,
ANDROID_LOG_WARN, ANDROID_LOG_ERROR, ANDROID_LOG_FATAL,
};
static_assert(arraysize(kLogSeverityToAndroidLogPriority) == FATAL + 1,
"Mismatch in size of kLogSeverityToAndroidLogPriority and values "
"in LogSeverity");
static const log_id kLogIdToAndroidLogId[] = {
LOG_ID_MAX, LOG_ID_MAIN, LOG_ID_SYSTEM,
};
static_assert(arraysize(kLogIdToAndroidLogId) == SYSTEM + 1,
"Mismatch in size of kLogIdToAndroidLogId and values in LogId");
void LogdLogger::operator()(LogId id, LogSeverity severity, const char* tag,
const char* file, unsigned int line,
const char* message) {
static constexpr android_LogPriority kLogSeverityToAndroidLogPriority[] = {
ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO,
ANDROID_LOG_WARN, ANDROID_LOG_ERROR, ANDROID_LOG_FATAL,
};
static_assert(arraysize(kLogSeverityToAndroidLogPriority) == FATAL + 1,
"Mismatch in size of kLogSeverityToAndroidLogPriority and values in LogSeverity");
int priority = kLogSeverityToAndroidLogPriority[severity];
if (id == DEFAULT) {
id = default_log_id_;
}
static constexpr log_id kLogIdToAndroidLogId[] = {
LOG_ID_MAX, LOG_ID_MAIN, LOG_ID_SYSTEM,
};
static_assert(arraysize(kLogIdToAndroidLogId) == SYSTEM + 1,
"Mismatch in size of kLogIdToAndroidLogId and values in LogId");
log_id lg_id = kLogIdToAndroidLogId[id];
if (priority == ANDROID_LOG_FATAL) {
@ -427,13 +462,22 @@ void LogMessage::LogLine(const char* file, unsigned int line, LogId id,
gLogger(id, severity, tag, file, line, message);
}
ScopedLogSeverity::ScopedLogSeverity(LogSeverity level) {
old_ = gMinimumLogSeverity;
gMinimumLogSeverity = level;
LogSeverity GetMinimumLogSeverity() {
return gMinimumLogSeverity;
}
LogSeverity SetMinimumLogSeverity(LogSeverity new_severity) {
LogSeverity old_severity = gMinimumLogSeverity;
gMinimumLogSeverity = new_severity;
return old_severity;
}
ScopedLogSeverity::ScopedLogSeverity(LogSeverity new_severity) {
old_ = SetMinimumLogSeverity(new_severity);
}
ScopedLogSeverity::~ScopedLogSeverity() {
gMinimumLogSeverity = old_;
SetMinimumLogSeverity(old_);
}
} // namespace base

View File

@ -118,7 +118,8 @@ void Action::ExecuteCommand(const Command& command) const {
Timer t;
int result = command.InvokeFunc();
if (klog_get_level() >= KLOG_DEBUG_LEVEL) {
// TODO: this should probably be changed to "if (failed || took a long time)"...
if (android::base::GetMinimumLogSeverity() <= android::base::DEBUG) {
std::string trigger_name = BuildTriggersString();
std::string cmd_str = command.BuildCommandString();
std::string source = command.BuildSourceString();

View File

@ -486,11 +486,7 @@ static void import_late(const std::vector<std::string>& args, size_t start_index
* not return.
*/
static int do_mount_all(const std::vector<std::string>& args) {
pid_t pid;
int ret = -1;
int child_ret = -1;
int status;
struct fstab *fstab;
const char* fstabfile = args[1].c_str();
/*
@ -499,9 +495,10 @@ static int do_mount_all(const std::vector<std::string>& args) {
* process if anything goes wrong (crash or memory leak), and wait for
* the child to finish in the parent.
*/
pid = fork();
pid_t pid = fork();
if (pid > 0) {
/* Parent. Wait for the child to return */
int status;
int wp_ret = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0));
if (wp_ret == -1) {
// Unexpected error code. We will continue anyway.
@ -515,9 +512,13 @@ static int do_mount_all(const std::vector<std::string>& args) {
}
} else if (pid == 0) {
/* child, call fs_mgr_mount_all() */
klog_set_level(6); /* So we can see what fs_mgr_mount_all() does */
fstab = fs_mgr_read_fstab(fstabfile);
child_ret = fs_mgr_mount_all(fstab);
// So we can always see what fs_mgr_mount_all() does.
// Only needed if someone explicitly changes the default log level in their init.rc.
android::base::ScopedLogSeverity info(android::base::INFO);
struct fstab* fstab = fs_mgr_read_fstab(fstabfile);
int child_ret = fs_mgr_mount_all(fstab);
fs_mgr_free_fstab(fstab);
if (child_ret == -1) {
PLOG(ERROR) << "fs_mgr_mount_all returned an error";
@ -863,12 +864,23 @@ static int do_restorecon_recursive(const std::vector<std::string>& args) {
}
static int do_loglevel(const std::vector<std::string>& args) {
// TODO: support names instead/as well?
int log_level = std::stoi(args[1]);
if (log_level < KLOG_ERROR_LEVEL || log_level > KLOG_DEBUG_LEVEL) {
LOG(ERROR) << "loglevel: invalid log level " << log_level;
return -EINVAL;
android::base::LogSeverity severity;
switch (log_level) {
case 7: severity = android::base::DEBUG; break;
case 6: severity = android::base::INFO; break;
case 5:
case 4: severity = android::base::WARNING; break;
case 3: severity = android::base::ERROR; break;
case 2:
case 1:
case 0: severity = android::base::FATAL; break;
default:
LOG(ERROR) << "loglevel: invalid log level " << log_level;
return -EINVAL;
}
klog_set_level(log_level);
android::base::SetMinimumLogSeverity(severity);
return 0;
}

View File

@ -17,52 +17,16 @@
#include "log.h"
#include <fcntl.h>
#include <stdlib.h>
#include <string.h>
#include <sys/stat.h>
#include <sys/types.h>
#include <sys/uio.h>
#include <selinux/selinux.h>
static const int kLogSeverityToKLogLevel[] = {
[android::base::VERBOSE] = KLOG_DEBUG_LEVEL,
[android::base::DEBUG] = KLOG_DEBUG_LEVEL,
[android::base::INFO] = KLOG_INFO_LEVEL,
[android::base::WARNING] = KLOG_WARNING_LEVEL,
[android::base::ERROR] = KLOG_ERROR_LEVEL,
[android::base::FATAL] = KLOG_ERROR_LEVEL,
};
static_assert(arraysize(kLogSeverityToKLogLevel) == android::base::FATAL + 1,
"Mismatch in size of kLogSeverityToKLogLevel and values in LogSeverity");
static void KernelLogger(android::base::LogId, android::base::LogSeverity severity,
const char* tag, const char*, unsigned int, const char* msg) {
int level = kLogSeverityToKLogLevel[severity];
if (level > klog_get_level()) return;
// The kernel's printk buffer is only 1024 bytes.
// TODO: should we automatically break up long lines into multiple lines?
// Or we could log but with something like "..." at the end?
char buf[1024];
size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %s\n", level, tag, msg);
if (size > sizeof(buf)) {
size = snprintf(buf, sizeof(buf), "<%d>%s: %zu-byte message too long for printk\n",
level, tag, size);
}
iovec iov[1];
iov[0].iov_base = buf;
iov[0].iov_len = size;
klog_writev(level, iov, 1);
}
void InitKernelLogging(char* argv[]) {
// Make stdin/stdout/stderr all point to /dev/null.
int fd = open("/sys/fs/selinux/null", O_RDWR);
if (fd == -1) {
int saved_errno = errno;
android::base::InitLogging(argv, &KernelLogger);
android::base::InitLogging(argv, &android::base::KernelLogger);
errno = saved_errno;
PLOG(FATAL) << "Couldn't open /sys/fs/selinux/null";
}
@ -71,8 +35,7 @@ void InitKernelLogging(char* argv[]) {
dup2(fd, 2);
if (fd > 2) close(fd);
android::base::InitLogging(argv, &KernelLogger);
klog_set_level(KLOG_INFO_LEVEL);
android::base::InitLogging(argv, &android::base::KernelLogger);
}
int selinux_klog_callback(int type, const char *fmt, ...) {
@ -87,6 +50,6 @@ int selinux_klog_callback(int type, const char *fmt, ...) {
va_start(ap, fmt);
vsnprintf(buf, sizeof(buf), fmt, ap);
va_end(ap);
KernelLogger(android::base::MAIN, severity, "selinux", nullptr, 0, buf);
android::base::KernelLogger(android::base::MAIN, severity, "selinux", nullptr, 0, buf);
return 0;
}

View File

@ -19,8 +19,6 @@
#include <android-base/logging.h>
#include <cutils/klog.h>
void InitKernelLogging(char* argv[]);
int selinux_klog_callback(int level, const char* fmt, ...) __printflike(2, 3);

View File

@ -514,6 +514,3 @@ For quicker turnaround when working on init itself, use:
Alternatively, use the emulator:
emulator -partition-size 1024 -verbose -show-kernel -no-window
You might want to change the klog_set_level call so you see all the kernel
logging in dmesg (or the emulator output).