ACPR/android_system_core
1
0
Fork 0
Code Issues Pull requests Projects Releases Packages Wiki Activity Actions

Merge "Move init's kernel logging into libbase."

Browse source
This commit is contained in:
Treehugger Robot 2016-08-05 00:25:44 +00:00 • committed by Gerrit Code Review
commit bfb89d32f5
7 changed files with 107 additions and 89 deletions
Show stats Download patch file Download diff file Expand all files Collapse all files

19
base/include/android-base/logging.h
View file

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

90
base/logging.cpp
View file

@ -14,12 +14,13 @@
* limitations under the License. * limitations under the License.
*/ */
#ifdef _WIN32 #if defined(_WIN32)
#include <windows.h> #include <windows.h>
#endif #endif
#include "android-base/logging.h" #include "android-base/logging.h"
#include <fcntl.h>
#include <libgen.h> #include <libgen.h>
#include <time.h> #include <time.h>
@ -30,6 +31,10 @@
#include <errno.h> #include <errno.h>
#endif #endif
#if defined(__linux__)
#include <sys/uio.h>
#endif
#include <iostream> #include <iostream>
#include <limits> #include <limits>
#include <sstream> #include <sstream>
@ -172,10 +177,6 @@ static bool gInitialized = false;
static LogSeverity gMinimumLogSeverity = INFO; static LogSeverity gMinimumLogSeverity = INFO;
static auto& gProgramInvocationName = *new std::unique_ptr<std::string>(); static auto& gProgramInvocationName = *new std::unique_ptr<std::string>();
LogSeverity GetMinimumLogSeverity() {
return gMinimumLogSeverity;
}
static const char* ProgramInvocationName() { static const char* ProgramInvocationName() {
if (gProgramInvocationName == nullptr) { if (gProgramInvocationName == nullptr) {
gProgramInvocationName.reset(new std::string(getprogname())); gProgramInvocationName.reset(new std::string(getprogname()));
@ -184,6 +185,42 @@ static const char* ProgramInvocationName() {
return gProgramInvocationName->c_str(); 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, void StderrLogger(LogId, LogSeverity severity, const char*, const char* file,
unsigned int line, const char* message) { unsigned int line, const char* message) {
struct tm now; 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) { 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, void LogdLogger::operator()(LogId id, LogSeverity severity, const char* tag,
const char* file, unsigned int line, const char* file, unsigned int line,
const char* message) { 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]; int priority = kLogSeverityToAndroidLogPriority[severity];
if (id == DEFAULT) { if (id == DEFAULT) {
id = default_log_id_; 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]; log_id lg_id = kLogIdToAndroidLogId[id];
if (priority == ANDROID_LOG_FATAL) { 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); gLogger(id, severity, tag, file, line, message);
} }
ScopedLogSeverity::ScopedLogSeverity(LogSeverity level) { LogSeverity GetMinimumLogSeverity() {
old_ = gMinimumLogSeverity; return gMinimumLogSeverity;
gMinimumLogSeverity = level; }
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() { ScopedLogSeverity::~ScopedLogSeverity() {
gMinimumLogSeverity = old_; SetMinimumLogSeverity(old_);
} }
} // namespace base } // namespace base

3
init/action.cpp
View file

@ -118,7 +118,8 @@ void Action::ExecuteCommand(const Command& command) const {
Timer t; Timer t;
int result = command.InvokeFunc(); 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 trigger_name = BuildTriggersString();
std::string cmd_str = command.BuildCommandString(); std::string cmd_str = command.BuildCommandString();
std::string source = command.BuildSourceString(); std::string source = command.BuildSourceString();

36
init/builtins.cpp
View file

@ -482,11 +482,7 @@ static void import_late(const std::vector<std::string>& args, size_t start_index
* not return. * not return.
*/ */
static int do_mount_all(const std::vector<std::string>& args) { static int do_mount_all(const std::vector<std::string>& args) {
pid_t pid;
int ret = -1; int ret = -1;
int child_ret = -1;
int status;
struct fstab *fstab;
const char* fstabfile = args[1].c_str(); const char* fstabfile = args[1].c_str();
/* /*
@ -495,9 +491,10 @@ static int do_mount_all(const std::vector<std::string>& args) {
* process if anything goes wrong (crash or memory leak), and wait for * process if anything goes wrong (crash or memory leak), and wait for
* the child to finish in the parent. * the child to finish in the parent.
*/ */
pid = fork(); pid_t pid = fork();
if (pid > 0) { if (pid > 0) {
/* Parent. Wait for the child to return */ /* Parent. Wait for the child to return */
int status;
int wp_ret = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0)); int wp_ret = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0));
if (wp_ret == -1) { if (wp_ret == -1) {
// Unexpected error code. We will continue anyway. // Unexpected error code. We will continue anyway.
@ -511,9 +508,13 @@ static int do_mount_all(const std::vector<std::string>& args) {
} }
} else if (pid == 0) { } else if (pid == 0) {
/* child, call fs_mgr_mount_all() */ /* 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); // So we can always see what fs_mgr_mount_all() does.
child_ret = fs_mgr_mount_all(fstab); // 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); fs_mgr_free_fstab(fstab);
if (child_ret == -1) { if (child_ret == -1) {
PLOG(ERROR) << "fs_mgr_mount_all returned an error"; PLOG(ERROR) << "fs_mgr_mount_all returned an error";
@ -866,12 +867,23 @@ static int do_restorecon_recursive(const std::vector<std::string>& args) {
} }
static int do_loglevel(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]); int log_level = std::stoi(args[1]);
if (log_level < KLOG_ERROR_LEVEL || log_level > KLOG_DEBUG_LEVEL) { android::base::LogSeverity severity;
LOG(ERROR) << "loglevel: invalid log level " << log_level; switch (log_level) {
return -EINVAL; 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; return 0;
} }

43
init/log.cpp
View file

@ -17,52 +17,16 @@
#include "log.h" #include "log.h"
#include <fcntl.h> #include <fcntl.h>
#include <stdlib.h>
#include <string.h> #include <string.h>
#include <sys/stat.h>
#include <sys/types.h>
#include <sys/uio.h>
#include <selinux/selinux.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[]) { void InitKernelLogging(char* argv[]) {
// Make stdin/stdout/stderr all point to /dev/null. // Make stdin/stdout/stderr all point to /dev/null.
int fd = open("/sys/fs/selinux/null", O_RDWR); int fd = open("/sys/fs/selinux/null", O_RDWR);
if (fd == -1) { if (fd == -1) {
int saved_errno = errno; int saved_errno = errno;
android::base::InitLogging(argv, &KernelLogger); android::base::InitLogging(argv, &android::base::KernelLogger);
errno = saved_errno; errno = saved_errno;
PLOG(FATAL) << "Couldn't open /sys/fs/selinux/null"; PLOG(FATAL) << "Couldn't open /sys/fs/selinux/null";
} }
@ -71,8 +35,7 @@ void InitKernelLogging(char* argv[]) {
dup2(fd, 2); dup2(fd, 2);
if (fd > 2) close(fd); if (fd > 2) close(fd);
android::base::InitLogging(argv, &KernelLogger); android::base::InitLogging(argv, &android::base::KernelLogger);
klog_set_level(KLOG_INFO_LEVEL);
} }
int selinux_klog_callback(int type, const char *fmt, ...) { 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); va_start(ap, fmt);
vsnprintf(buf, sizeof(buf), fmt, ap); vsnprintf(buf, sizeof(buf), fmt, ap);
va_end(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; return 0;
} }

2
init/log.h
View file

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

3
init/readme.txt
View file

@ -514,6 +514,3 @@ For quicker turnaround when working on init itself, use:
Alternatively, use the emulator: Alternatively, use the emulator:
emulator -partition-size 1024 -verbose -show-kernel -no-window 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).