diff --git a/init/action.cpp b/init/action.cpp index b7e431c34..eeed74415 100644 --- a/init/action.cpp +++ b/init/action.cpp @@ -42,7 +42,7 @@ int Command::InvokeFunc() const { expanded_args[0] = args_[0]; for (std::size_t i = 1; i < args_.size(); ++i) { if (!expand_props(args_[i], &expanded_args[i])) { - ERROR("%s: cannot expand '%s'\n", args_[0].c_str(), args_[i].c_str()); + LOG(ERROR) << args_[0] << ": cannot expand '" << args_[i] << "'"; return -EINVAL; } } @@ -123,9 +123,8 @@ void Action::ExecuteCommand(const Command& command) const { std::string cmd_str = command.BuildCommandString(); std::string source = command.BuildSourceString(); - INFO("Command '%s' action=%s%s returned %d took %.2fs\n", - cmd_str.c_str(), trigger_name.c_str(), source.c_str(), - result, t.duration()); + LOG(INFO) << "Command '" << cmd_str << "' action=" << trigger_name << source + << " returned " << result << " took " << t.duration() << "s"; } } @@ -253,13 +252,12 @@ std::string Action::BuildTriggersString() const { void Action::DumpState() const { std::string trigger_name = BuildTriggersString(); - INFO("on %s\n", trigger_name.c_str()); + LOG(INFO) << "on " << trigger_name; for (const auto& c : commands_) { std::string cmd_str = c.BuildCommandString(); - INFO(" %s\n", cmd_str.c_str()); + LOG(INFO) << " %s" << cmd_str; } - INFO("\n"); } class EventTrigger : public Trigger { @@ -366,7 +364,7 @@ void ActionManager::ExecuteOneCommand() { if (current_command_ == 0) { std::string trigger_name = action->BuildTriggersString(); - INFO("processing action (%s)\n", trigger_name.c_str()); + LOG(INFO) << "processing action (" << trigger_name << ")"; } action->ExecuteOneCommand(current_command_); @@ -395,7 +393,6 @@ void ActionManager::DumpState() const { for (const auto& a : actions_) { a->DumpState(); } - INFO("\n"); } bool ActionParser::ParseSection(const std::vector& args, diff --git a/init/bootchart.cpp b/init/bootchart.cpp index 5704d28fb..467a83801 100644 --- a/init/bootchart.cpp +++ b/init/bootchart.cpp @@ -206,12 +206,12 @@ static int bootchart_init() { int do_bootchart_init(const std::vector& args) { g_remaining_samples = bootchart_init(); if (g_remaining_samples < 0) { - ERROR("Bootcharting init failure: %s\n", strerror(errno)); + PLOG(ERROR) << "Bootcharting initialization failed"; } else if (g_remaining_samples > 0) { - NOTICE("Bootcharting started (will run for %d s).\n", - (g_remaining_samples * BOOTCHART_POLLING_MS) / 1000); + LOG(INFO) << "Bootcharting started (will run for " + << ((g_remaining_samples * BOOTCHART_POLLING_MS) / 1000) << " s)."; } else { - NOTICE("Not bootcharting.\n"); + LOG(VERBOSE) << "Not bootcharting."; } return 0; } diff --git a/init/builtins.cpp b/init/builtins.cpp index c9be50a8d..4ba7f114b 100644 --- a/init/builtins.cpp +++ b/init/builtins.cpp @@ -73,12 +73,12 @@ static const int kTerminateServiceDelayMicroSeconds = 50000; static int insmod(const char *filename, const char *options, int flags) { int fd = open(filename, O_RDONLY | O_NOFOLLOW | O_CLOEXEC); if (fd == -1) { - ERROR("insmod: open(\"%s\") failed: %s", filename, strerror(errno)); + PLOG(ERROR) << "insmod: open(\"" << filename << "\") failed"; return -1; } int rc = syscall(__NR_finit_module, fd, options, flags); if (rc == -1) { - ERROR("finit_module for \"%s\" failed: %s", filename, strerror(errno)); + PLOG(ERROR) << "finit_module for \"" << filename << "\" failed"; } close(fd); return rc; @@ -141,7 +141,7 @@ static int wipe_data_via_recovery(const std::string& reason) { const std::vector options = {"--wipe_data", std::string() + "--reason=" + reason}; std::string err; if (!write_bootloader_message(options, &err)) { - ERROR("failed to set bootloader message: %s", err.c_str()); + LOG(ERROR) << "failed to set bootloader message: " << err; return -1; } android_reboot(ANDROID_RB_RESTART2, 0, "recovery"); @@ -214,13 +214,13 @@ static void unmount_and_fsck(const struct mntent *entry) { const char *f2fs_argv[] = { "/system/bin/fsck.f2fs", "-f", entry->mnt_fsname, }; - android_fork_execvp_ext(ARRAY_SIZE(f2fs_argv), (char **)f2fs_argv, + android_fork_execvp_ext(arraysize(f2fs_argv), (char **)f2fs_argv, &st, true, LOG_KLOG, true, NULL, NULL, 0); } else if (!strcmp(entry->mnt_type, "ext4")) { const char *ext4_argv[] = { "/system/bin/e2fsck", "-f", "-y", entry->mnt_fsname, }; - android_fork_execvp_ext(ARRAY_SIZE(ext4_argv), (char **)ext4_argv, + android_fork_execvp_ext(arraysize(ext4_argv), (char **)ext4_argv, &st, true, LOG_KLOG, true, NULL, NULL, 0); } } @@ -440,7 +440,7 @@ static int do_mount(const std::vector& args) { } close(fd); - ERROR("out of loopback devices"); + LOG(ERROR) << "out of loopback devices"; return -1; } else { if (wait) @@ -503,9 +503,9 @@ static int do_mount_all(const std::vector& args) { if (pid > 0) { /* Parent. Wait for the child to return */ int wp_ret = TEMP_FAILURE_RETRY(waitpid(pid, &status, 0)); - if (wp_ret < 0) { - /* Unexpected error code. We will continue anyway. */ - NOTICE("waitpid failed rc=%d: %s\n", wp_ret, strerror(errno)); + if (wp_ret == -1) { + // Unexpected error code. We will continue anyway. + PLOG(WARNING) << "waitpid failed"; } if (WIFEXITED(status)) { @@ -520,7 +520,7 @@ static int do_mount_all(const std::vector& args) { child_ret = fs_mgr_mount_all(fstab); fs_mgr_free_fstab(fstab); if (child_ret == -1) { - ERROR("fs_mgr_mount_all returned an error\n"); + PLOG(ERROR) << "fs_mgr_mount_all returned an error"; } _exit(child_ret); } else { @@ -545,7 +545,7 @@ static int do_mount_all(const std::vector& args) { ActionManager::GetInstance().QueueEventTrigger("nonencrypted"); } else if (ret == FS_MGR_MNTALL_DEV_NEEDS_RECOVERY) { /* Setup a wipe via recovery, and reboot into recovery */ - ERROR("fs_mgr_mount_all suggested recovery, so wiping data via recovery.\n"); + PLOG(ERROR) << "fs_mgr_mount_all suggested recovery, so wiping data via recovery."; ret = wipe_data_via_recovery("wipe_data_via_recovery"); /* If reboot worked, there is no return. */ } else if (ret == FS_MGR_MNTALL_DEV_FILE_ENCRYPTED) { @@ -559,7 +559,7 @@ static int do_mount_all(const std::vector& args) { // do anything different from the nonencrypted case. ActionManager::GetInstance().QueueEventTrigger("nonencrypted"); } else if (ret > 0) { - ERROR("fs_mgr_mount_all returned unexpected error %d\n", ret); + PLOG(ERROR) << "fs_mgr_mount_all returned unexpected error " << ret; } /* else ... < 0: error */ @@ -596,7 +596,7 @@ static int do_setrlimit(const std::vector& args) { static int do_start(const std::vector& args) { Service* svc = ServiceManager::GetInstance().FindServiceByName(args[1]); if (!svc) { - ERROR("do_start: Service %s not found\n", args[1].c_str()); + LOG(ERROR) << "do_start: Service " << args[1] << " not found"; return -1; } if (!svc->Start()) @@ -607,7 +607,7 @@ static int do_start(const std::vector& args) { static int do_stop(const std::vector& args) { Service* svc = ServiceManager::GetInstance().FindServiceByName(args[1]); if (!svc) { - ERROR("do_stop: Service %s not found\n", args[1].c_str()); + LOG(ERROR) << "do_stop: Service " << args[1] << " not found"; return -1; } svc->Stop(); @@ -617,7 +617,7 @@ static int do_stop(const std::vector& args) { static int do_restart(const std::vector& args) { Service* svc = ServiceManager::GetInstance().FindServiceByName(args[1]); if (!svc) { - ERROR("do_restart: Service %s not found\n", args[1].c_str()); + LOG(ERROR) << "do_restart: Service " << args[1] << " not found"; return -1; } svc->Restart(); @@ -638,7 +638,7 @@ static int do_powerctl(const std::vector& args) { cmd = ANDROID_RB_RESTART2; len = 6; } else { - ERROR("powerctl: unrecognized command '%s'\n", command); + LOG(ERROR) << "powerctl: unrecognized command '" << command << "'"; return -EINVAL; } @@ -652,7 +652,7 @@ static int do_powerctl(const std::vector& args) { reboot_target = &command[len + 1]; } } else if (command[len] != '\0') { - ERROR("powerctl: unrecognized reboot target '%s'\n", &command[len]); + LOG(ERROR) << "powerctl: unrecognized reboot target '" << &command[len] << "'"; return -EINVAL; } @@ -689,7 +689,7 @@ static int do_powerctl(const std::vector& args) { // Wait a bit before recounting the number or running services. usleep(kTerminateServiceDelayMicroSeconds); } - NOTICE("Terminating running services took %.02f seconds", t.duration()); + LOG(VERBOSE) << "Terminating running services took " << t.duration() << " seconds"; } return android_reboot_with_callback(cmd, 0, reboot_target, @@ -865,7 +865,7 @@ static int do_restorecon_recursive(const std::vector& args) { static int do_loglevel(const std::vector& args) { int log_level = std::stoi(args[1]); if (log_level < KLOG_ERROR_LEVEL || log_level > KLOG_DEBUG_LEVEL) { - ERROR("loglevel: invalid log level'%d'\n", log_level); + LOG(ERROR) << "loglevel: invalid log level " << log_level; return -EINVAL; } klog_set_level(log_level); diff --git a/init/devices.cpp b/init/devices.cpp index 32fec52c5..5e12f25d7 100644 --- a/init/devices.cpp +++ b/init/devices.cpp @@ -174,13 +174,14 @@ static void fixup_sys_perms(const char* upath, const char* subsystem) { } std::string attr_file = path + "/" + dp->attr; - INFO("fixup %s %d %d 0%o\n", attr_file.c_str(), dp->uid, dp->gid, dp->perm); + LOG(INFO) << "fixup " << attr_file + << " " << dp->uid << " " << dp->gid << " " << std::oct << dp->perm; chown(attr_file.c_str(), dp->uid, dp->gid); chmod(attr_file.c_str(), dp->perm); } if (access(path.c_str(), F_OK) == 0) { - INFO("restorecon_recursive: %s\n", path.c_str()); + LOG(INFO) << "restorecon_recursive: " << path; restorecon_recursive(path.c_str()); } } @@ -241,8 +242,7 @@ static void make_device(const char *path, mode = get_device_perm(path, links, &uid, &gid) | (block ? S_IFBLK : S_IFCHR); if (selabel_lookup_best_match(sehandle, &secontext, path, links, mode)) { - ERROR("Device '%s' not created; cannot find SELinux label (%s)\n", - path, strerror(errno)); + PLOG(ERROR) << "Device '" << path << "' not created; cannot find SELinux label"; return; } setfscreatecon(secontext); @@ -261,8 +261,7 @@ static void make_device(const char *path, char* fcon = nullptr; int rc = lgetfilecon(path, &fcon); if (rc < 0) { - ERROR("Cannot get SELinux label on '%s' device (%s)\n", - path, strerror(errno)); + PLOG(ERROR) << "Cannot get SELinux label on '" << path << "' device"; goto out; } @@ -270,8 +269,7 @@ static void make_device(const char *path, freecon(fcon); if (different && lsetfilecon(path, secontext)) { - ERROR("Cannot set '%s' SELinux label on '%s' device (%s)\n", - secontext, path, strerror(errno)); + PLOG(ERROR) << "Cannot set '" << secontext << "' SELinux label on '" << path << "' device"; } } @@ -295,7 +293,7 @@ static void add_platform_device(const char *path) name += 9; } - INFO("adding platform device %s (%s)\n", name, path); + LOG(INFO) << "adding platform device " << name << " (" << path << ")"; bus = (platform_node*) calloc(1, sizeof(struct platform_node)); bus->path = strdup(path); @@ -334,7 +332,7 @@ static void remove_platform_device(const char *path) list_for_each_reverse(node, &platform_names) { bus = node_to_item(node, struct platform_node, list); if (!strcmp(path, bus->path)) { - INFO("removing platform device %s\n", bus->name); + LOG(INFO) << "removing platform device " << bus->name; free(bus->path); list_remove(node); free(bus); @@ -423,9 +421,9 @@ static void parse_event(const char *msg, struct uevent *uevent) } if (LOG_UEVENTS) { - INFO("event { '%s', '%s', '%s', '%s', %d, %d }\n", - uevent->action, uevent->path, uevent->subsystem, - uevent->firmware, uevent->major, uevent->minor); + LOG(INFO) << android::base::StringPrintf("event { '%s', '%s', '%s', '%s', %d, %d }", + uevent->action, uevent->path, uevent->subsystem, + uevent->firmware, uevent->major, uevent->minor); } } @@ -509,15 +507,16 @@ static char **get_block_device_symlinks(struct uevent *uevent) return NULL; memset(links, 0, sizeof(char *) * 4); - INFO("found %s device %s\n", type, device); + LOG(INFO) << "found " << type << " device " << device; snprintf(link_path, sizeof(link_path), "/dev/block/%s/%s", type, device); if (uevent->partition_name) { p = strdup(uevent->partition_name); sanitize(p); - if (strcmp(uevent->partition_name, p)) - NOTICE("Linking partition '%s' as '%s'\n", uevent->partition_name, p); + if (strcmp(uevent->partition_name, p)) { + LOG(VERBOSE) << "Linking partition '" << uevent->partition_name << "' as '" << p << "'"; + } if (asprintf(&links[link_num], "%s/by-name/%s", link_path, p) > 0) link_num++; else @@ -595,8 +594,7 @@ static const char *parse_device_name(struct uevent *uevent, unsigned int len) /* too-long names would overrun our buffer */ if(strlen(name) > len) { - ERROR("DEVPATH=%s exceeds %u-character limit on filename; ignoring event\n", - name, len); + LOG(ERROR) << "DEVPATH=" << name << " exceeds " << len << "-character limit on filename; ignoring event"; return NULL; } @@ -631,12 +629,11 @@ static bool assemble_devpath(char *devpath, const char *dirname, { int s = snprintf(devpath, DEVPATH_LEN, "%s/%s", dirname, devname); if (s < 0) { - ERROR("failed to assemble device path (%s); ignoring event\n", - strerror(errno)); + PLOG(ERROR) << "failed to assemble device path; ignoring event"; return false; } else if (s >= DEVPATH_LEN) { - ERROR("%s/%s exceeds %u-character limit on path; ignoring event\n", - dirname, devname, DEVPATH_LEN); + LOG(ERROR) << dirname << "/" << devname + << " exceeds " << DEVPATH_LEN << "-character limit on path; ignoring event"; return false; } return true; @@ -680,8 +677,7 @@ static void handle_generic_device_event(struct uevent *uevent) break; default: - ERROR("%s subsystem's devpath option is not set; ignoring event\n", - uevent->subsystem); + LOG(ERROR) << uevent->subsystem << " subsystem's devpath option is not set; ignoring event"; return; } @@ -737,9 +733,8 @@ static void handle_generic_device_event(struct uevent *uevent) } else if(!strncmp(uevent->subsystem, "sound", 5)) { base = "/dev/snd/"; make_dir(base, 0755); - } else if(!strncmp(uevent->subsystem, "misc", 4) && - !strncmp(name, "log_", 4)) { - INFO("kernel logger is deprecated\n"); + } else if(!strncmp(uevent->subsystem, "misc", 4) && !strncmp(name, "log_", 4)) { + LOG(INFO) << "kernel logger is deprecated"; base = "/dev/log/"; make_dir(base, 0755); name += 4; @@ -818,8 +813,7 @@ static void process_firmware_event(struct uevent *uevent) size_t i; int booting = is_booting(); - INFO("firmware: loading '%s' for '%s'\n", - uevent->firmware, uevent->path); + LOG(INFO) << "firmware: loading '" << uevent->firmware << "' for '" << uevent->path << "'"; l = asprintf(&root, SYSFS_PREFIX"%s/", uevent->path); if (l == -1) @@ -842,7 +836,7 @@ static void process_firmware_event(struct uevent *uevent) goto loading_close_out; try_loading_again: - for (i = 0; i < ARRAY_SIZE(firmware_dirs); i++) { + for (i = 0; i < arraysize(firmware_dirs); i++) { char *file = NULL; l = asprintf(&file, "%s/%s", firmware_dirs[i], uevent->firmware); if (l == -1) @@ -850,10 +844,11 @@ try_loading_again: fw_fd = open(file, O_RDONLY|O_CLOEXEC); free(file); if (fw_fd >= 0) { - if(!load_firmware(fw_fd, loading_fd, data_fd)) - INFO("firmware: copy success { '%s', '%s' }\n", root, uevent->firmware); - else - INFO("firmware: copy failure { '%s', '%s' }\n", root, uevent->firmware); + if (!load_firmware(fw_fd, loading_fd, data_fd)) { + LOG(INFO) << "firmware: copy success { '" << root << "', '" << uevent->firmware << "' }"; + } else { + LOG(ERROR) << "firmware: copy failure { '" << root << "', '" << uevent->firmware << "' }"; + } break; } } @@ -866,7 +861,7 @@ try_loading_again: booting = is_booting(); goto try_loading_again; } - INFO("firmware: could not open '%s': %s\n", uevent->firmware, strerror(errno)); + PLOG(ERROR) << "firmware: could not open '" << uevent->firmware << "'"; write(loading_fd, "-1", 2); goto data_close_out; } @@ -900,7 +895,7 @@ static void handle_firmware_event(struct uevent *uevent) process_firmware_event(uevent); _exit(EXIT_SUCCESS); } else if (pid < 0) { - ERROR("could not fork to process firmware event: %s\n", strerror(errno)); + PLOG(ERROR) << "could not fork to process firmware event"; } } @@ -996,7 +991,7 @@ void device_init() { fcntl(device_fd, F_SETFL, O_NONBLOCK); if (access(COLDBOOT_DONE, F_OK) == 0) { - NOTICE("Skipping coldboot, already done!\n"); + LOG(VERBOSE) << "Skipping coldboot, already done!"; return; } @@ -1005,7 +1000,7 @@ void device_init() { coldboot("/sys/block"); coldboot("/sys/devices"); close(open(COLDBOOT_DONE, O_WRONLY|O_CREAT|O_CLOEXEC, 0000)); - NOTICE("Coldboot took %.2fs.\n", t.duration()); + LOG(INFO) << "Coldboot took " << t.duration() << "s."; } int get_device_fd() diff --git a/init/import_parser.cpp b/init/import_parser.cpp index e2a0f8330..d52247b3e 100644 --- a/init/import_parser.cpp +++ b/init/import_parser.cpp @@ -38,7 +38,7 @@ bool ImportParser::ParseSection(const std::vector& args, return false; } - INFO("Added '%s' to import list\n", conf_file.c_str()); + LOG(INFO) << "Added '" << conf_file << "' to import list"; imports_.emplace_back(std::move(conf_file)); return true; } @@ -48,8 +48,7 @@ void ImportParser::EndFile(const std::string& filename) { imports_.clear(); for (const auto& s : current_imports) { if (!Parser::GetInstance().ParseConfig(s)) { - ERROR("could not import file '%s' from '%s': %s\n", - s.c_str(), filename.c_str(), strerror(errno)); + PLOG(ERROR) << "could not import file '" << s << "' from '" << filename << "'"; } } } diff --git a/init/init.cpp b/init/init.cpp index b2189312d..49e96dee2 100644 --- a/init/init.cpp +++ b/init/init.cpp @@ -87,7 +87,7 @@ void register_epoll_handler(int fd, void (*fn)()) { ev.events = EPOLLIN; ev.data.ptr = reinterpret_cast(fn); if (epoll_ctl(epoll_fd, EPOLL_CTL_ADD, fd, &ev) == -1) { - ERROR("epoll_ctl failed: %s\n", strerror(errno)); + PLOG(ERROR) << "epoll_ctl failed"; } } @@ -98,7 +98,7 @@ int add_environment(const char *key, const char *val) size_t key_len = strlen(key); /* The last environment entry is reserved to terminate the list */ - for (n = 0; n < (ARRAY_SIZE(ENV) - 1); n++) { + for (n = 0; n < (arraysize(ENV) - 1); n++) { /* Delete any existing entry for this key */ if (ENV[n] != NULL) { @@ -118,7 +118,7 @@ int add_environment(const char *key, const char *val) } } - ERROR("No env. room to store: '%s':'%s'\n", key, val); + LOG(ERROR) << "No env. room to store: '" << key << "':'" << val << "'"; return -1; } @@ -141,7 +141,7 @@ static void restart_processes() void handle_control_message(const std::string& msg, const std::string& name) { Service* svc = ServiceManager::GetInstance().FindServiceByName(name); if (svc == nullptr) { - ERROR("no such service '%s'\n", name.c_str()); + LOG(ERROR) << "no such service '" << name << "'"; return; } @@ -152,22 +152,22 @@ void handle_control_message(const std::string& msg, const std::string& name) { } else if (msg == "restart") { svc->Restart(); } else { - ERROR("unknown control msg '%s'\n", msg.c_str()); + LOG(ERROR) << "unknown control msg '" << msg << "'"; } } static int wait_for_coldboot_done_action(const std::vector& args) { Timer t; - NOTICE("Waiting for %s...\n", COLDBOOT_DONE); + LOG(VERBOSE) << "Waiting for " COLDBOOT_DONE "..."; // Any longer than 1s is an unreasonable length of time to delay booting. // If you're hitting this timeout, check that you didn't make your // sepolicy regular expressions too expensive (http://b/19899875). if (wait_for_file(COLDBOOT_DONE, 1)) { - ERROR("Timed out waiting for %s\n", COLDBOOT_DONE); + LOG(ERROR) << "Timed out waiting for " COLDBOOT_DONE; } - NOTICE("Waiting for %s took %.2fs.\n", COLDBOOT_DONE, t.duration()); + LOG(VERBOSE) << "Waiting for " COLDBOOT_DONE " took " << t.duration() << "s."; return 0; } @@ -199,11 +199,11 @@ static int mix_hwrng_into_linux_rng_action(const std::vector& args) open("/dev/hw_random", O_RDONLY | O_NOFOLLOW | O_CLOEXEC)); if (hwrandom_fd == -1) { if (errno == ENOENT) { - ERROR("/dev/hw_random not found\n"); - /* It's not an error to not have a Hardware RNG. */ - result = 0; + LOG(ERROR) << "/dev/hw_random not found"; + // It's not an error to not have a Hardware RNG. + result = 0; } else { - ERROR("Failed to open /dev/hw_random: %s\n", strerror(errno)); + PLOG(ERROR) << "Failed to open /dev/hw_random"; } goto ret; } @@ -211,7 +211,7 @@ static int mix_hwrng_into_linux_rng_action(const std::vector& args) urandom_fd = TEMP_FAILURE_RETRY( open("/dev/urandom", O_WRONLY | O_NOFOLLOW | O_CLOEXEC)); if (urandom_fd == -1) { - ERROR("Failed to open /dev/urandom: %s\n", strerror(errno)); + PLOG(ERROR) << "Failed to open /dev/urandom"; goto ret; } @@ -219,23 +219,22 @@ static int mix_hwrng_into_linux_rng_action(const std::vector& args) chunk_size = TEMP_FAILURE_RETRY( read(hwrandom_fd, buf, sizeof(buf) - total_bytes_written)); if (chunk_size == -1) { - ERROR("Failed to read from /dev/hw_random: %s\n", strerror(errno)); + PLOG(ERROR) << "Failed to read from /dev/hw_random"; goto ret; } else if (chunk_size == 0) { - ERROR("Failed to read from /dev/hw_random: EOF\n"); + LOG(ERROR) << "Failed to read from /dev/hw_random: EOF"; goto ret; } chunk_size = TEMP_FAILURE_RETRY(write(urandom_fd, buf, chunk_size)); if (chunk_size == -1) { - ERROR("Failed to write to /dev/urandom: %s\n", strerror(errno)); + PLOG(ERROR) << "Failed to write to /dev/urandom"; goto ret; } total_bytes_written += chunk_size; } - INFO("Mixed %zu bytes from /dev/hw_random into /dev/urandom", - total_bytes_written); + LOG(INFO) << "Mixed " << total_bytes_written << " bytes from /dev/hw_random into /dev/urandom"; result = 0; ret: @@ -249,7 +248,7 @@ ret: } static void security_failure() { - ERROR("Security failure; rebooting into recovery mode...\n"); + LOG(ERROR) << "Security failure; rebooting into recovery mode..."; android_reboot(ANDROID_RB_RESTART2, 0, "recovery"); while (true) { pause(); } // never reached } @@ -268,7 +267,7 @@ static bool __attribute__((unused)) set_mmap_rnd_bits_min(int start, int min, bo } std::ifstream inf(path, std::fstream::in); if (!inf) { - ERROR("Cannot open for reading: %s!\n", path.c_str()); + LOG(ERROR) << "Cannot open for reading: " << path; return false; } while (start >= min) { @@ -276,7 +275,7 @@ static bool __attribute__((unused)) set_mmap_rnd_bits_min(int start, int min, bo std::string str_val = std::to_string(start); std::ofstream of(path, std::fstream::out); if (!of) { - ERROR("Cannot open for writing: %s!\n", path.c_str()); + LOG(ERROR) << "Cannot open for writing: " << path; return false; } of << str_val << std::endl; @@ -293,8 +292,7 @@ static bool __attribute__((unused)) set_mmap_rnd_bits_min(int start, int min, bo } inf.close(); if (start < min) { - ERROR("Unable to set minimum required entropy %d in %s!\n", - min, path.c_str()); + LOG(ERROR) << "Unable to set minimum required entropy " << min << " in " << path; return false; } return true; @@ -350,7 +348,7 @@ static int set_mmap_rnd_bits_action(const std::vector& args) ret = 0; #endif if (ret == -1) { - ERROR("Unable to set adequate mmap entropy value!\n"); + LOG(ERROR) << "Unable to set adequate mmap entropy value!"; security_failure(); } return ret; @@ -413,7 +411,7 @@ static void export_kernel_boot_props() { { "ro.boot.hardware", "ro.hardware", "unknown", }, { "ro.boot.revision", "ro.revision", "0", }, }; - for (size_t i = 0; i < ARRAY_SIZE(prop_map); i++) { + for (size_t i = 0; i < arraysize(prop_map); i++) { std::string value = property_get(prop_map[i].src_prop); property_set(prop_map[i].dst_prop, (!value.empty()) ? value.c_str() : prop_map[i].default_value); } @@ -427,7 +425,7 @@ static void process_kernel_dt() { std::string dt_file; android::base::ReadFileToString(file_name, &dt_file); if (!dt_file.compare("android,firmware")) { - ERROR("firmware/android is not compatible with 'android,firmware'\n"); + LOG(ERROR) << "firmware/android is not compatible with 'android,firmware'"; return; } @@ -503,7 +501,7 @@ static int audit_callback(void *data, security_class_t /*cls*/, char *buf, size_ property_audit_data *d = reinterpret_cast(data); if (!d || !d->name || !d->cr) { - ERROR("audit_callback invoked with null data arguments!"); + LOG(ERROR) << "audit_callback invoked with null data arguments!"; return 0; } @@ -522,9 +520,9 @@ static void selinux_initialize(bool in_kernel_domain) { selinux_set_callback(SELINUX_CB_AUDIT, cb); if (in_kernel_domain) { - INFO("Loading SELinux policy...\n"); + LOG(INFO) << "Loading SELinux policy..."; if (selinux_android_load_policy() < 0) { - ERROR("failed to load policy: %s\n", strerror(errno)); + PLOG(ERROR) << "failed to load policy"; security_failure(); } @@ -532,8 +530,7 @@ static void selinux_initialize(bool in_kernel_domain) { bool is_enforcing = selinux_is_enforcing(); if (kernel_enforcing != is_enforcing) { if (security_setenforce(is_enforcing)) { - ERROR("security_setenforce(%s) failed: %s\n", - is_enforcing ? "true" : "false", strerror(errno)); + PLOG(ERROR) << "security_setenforce(%s) failed" << (is_enforcing ? "true" : "false"); security_failure(); } } @@ -542,8 +539,8 @@ static void selinux_initialize(bool in_kernel_domain) { security_failure(); } - NOTICE("(Initializing SELinux %s took %.2fs.)\n", - is_enforcing ? "enforcing" : "non-enforcing", t.duration()); + LOG(INFO) << "(Initializing SELinux " << (is_enforcing ? "enforcing" : "non-enforcing") + << " took " << t.duration() << "s.)"; } else { selinux_init_all_handles(); } @@ -583,10 +580,9 @@ int main(int argc, char** argv) { // later on. Now that tmpfs is mounted on /dev, we can actually talk // to the outside world. open_devnull_stdio(); - klog_init(); - klog_set_level(KLOG_NOTICE_LEVEL); + InitKernelLogging(argv); - NOTICE("init %s started!\n", is_first_stage ? "first stage" : "second stage"); + LOG(INFO) << "init " << (is_first_stage ? "first stage" : "second stage") << " started!"; if (!is_first_stage) { // Indicate that booting is in progress to background fw loaders, etc. @@ -611,13 +607,13 @@ int main(int argc, char** argv) { // that the SELinux policy has been loaded. if (is_first_stage) { if (restorecon("/init") == -1) { - ERROR("restorecon failed: %s\n", strerror(errno)); + PLOG(ERROR) << "restorecon failed"; security_failure(); } char* path = argv[0]; char* args[] = { path, const_cast("--second-stage"), nullptr }; if (execv(path, args) == -1) { - ERROR("execv(\"%s\") failed: %s\n", path, strerror(errno)); + PLOG(ERROR) << "execv(\"" << path << "\") failed"; security_failure(); } } @@ -625,7 +621,7 @@ int main(int argc, char** argv) { // These directories were necessarily created before initial policy load // and therefore need their security context restored to the proper value. // This must happen before /dev is populated by ueventd. - NOTICE("Running restorecon...\n"); + LOG(INFO) << "Running restorecon..."; restorecon("/dev"); restorecon("/dev/socket"); restorecon("/dev/__properties__"); @@ -634,7 +630,7 @@ int main(int argc, char** argv) { epoll_fd = epoll_create1(EPOLL_CLOEXEC); if (epoll_fd == -1) { - ERROR("epoll_create1 failed: %s\n", strerror(errno)); + PLOG(ERROR) << "epoll_create1 failed"; exit(1); } @@ -705,7 +701,7 @@ int main(int argc, char** argv) { epoll_event ev; int nr = TEMP_FAILURE_RETRY(epoll_wait(epoll_fd, &ev, 1, timeout)); if (nr == -1) { - ERROR("epoll_wait failed: %s\n", strerror(errno)); + PLOG(ERROR) << "epoll_wait failed"; } else if (nr == 1) { ((void (*)()) ev.data.ptr)(); } diff --git a/init/init_parser.cpp b/init/init_parser.cpp index b44ca59d5..9ec26afb5 100644 --- a/init/init_parser.cpp +++ b/init/init_parser.cpp @@ -93,7 +93,7 @@ void Parser::ParseData(const std::string& filename, const std::string& data) { } bool Parser::ParseConfigFile(const std::string& path) { - INFO("Parsing file %s...\n", path.c_str()); + LOG(INFO) << "Parsing file " << path << "..."; Timer t; std::string data; if (!read_file(path.c_str(), &data)) { @@ -110,15 +110,15 @@ bool Parser::ParseConfigFile(const std::string& path) { // Nexus 9 boot time, so it's disabled by default. if (false) DumpState(); - NOTICE("(Parsing %s took %.2fs.)\n", path.c_str(), t.duration()); + LOG(VERBOSE) << "(Parsing " << path << " took " << t.duration() << "s.)"; return true; } bool Parser::ParseConfigDir(const std::string& path) { - INFO("Parsing directory %s...\n", path.c_str()); + LOG(INFO) << "Parsing directory " << path << "..."; std::unique_ptr config_dir(opendir(path.c_str()), closedir); if (!config_dir) { - ERROR("Could not import directory '%s'\n", path.c_str()); + PLOG(ERROR) << "Could not import directory '" << path << "'"; return false; } dirent* current_file; @@ -128,7 +128,7 @@ bool Parser::ParseConfigDir(const std::string& path) { // Ignore directories and only process regular files. if (current_file->d_type == DT_REG) { if (!ParseConfigFile(current_path)) { - ERROR("could not import file '%s'\n", current_path.c_str()); + LOG(ERROR) << "could not import file '" << current_path << "'"; } } } diff --git a/init/keychords.cpp b/init/keychords.cpp index 7a7838dd3..1cfdd80f5 100644 --- a/init/keychords.cpp +++ b/init/keychords.cpp @@ -43,7 +43,7 @@ void add_service_keycodes(Service* svc) size = sizeof(*keychord) + svc->keycodes().size() * sizeof(keychord->keycodes[0]); keychords = (input_keychord*) realloc(keychords, keychords_length + size); if (!keychords) { - ERROR("could not allocate keychords\n"); + PLOG(ERROR) << "could not allocate keychords"; keychords_length = 0; keychords_count = 0; return; @@ -69,7 +69,7 @@ static void handle_keychord() { ret = read(keychord_fd, &id, sizeof(id)); if (ret != sizeof(id)) { - ERROR("could not read keychord id\n"); + PLOG(ERROR) << "could not read keychord id"; return; } @@ -78,10 +78,10 @@ static void handle_keychord() { if (adb_enabled == "running") { Service* svc = ServiceManager::GetInstance().FindServiceByKeychord(id); if (svc) { - INFO("Starting service %s from keychord\n", svc->name().c_str()); + LOG(INFO) << "Starting service " << svc->name() << " from keychord..."; svc->Start(); } else { - ERROR("service for keychord %d not found\n", id); + LOG(ERROR) << "service for keychord " << id << " not found"; } } } @@ -96,13 +96,13 @@ void keychord_init() { keychord_fd = TEMP_FAILURE_RETRY(open("/dev/keychord", O_RDWR | O_CLOEXEC)); if (keychord_fd == -1) { - ERROR("could not open /dev/keychord: %s\n", strerror(errno)); + PLOG(ERROR) << "could not open /dev/keychord"; return; } int ret = write(keychord_fd, keychords, keychords_length); if (ret != keychords_length) { - ERROR("could not configure /dev/keychord %d: %s\n", ret, strerror(errno)); + PLOG(ERROR) << "could not configure /dev/keychord " << ret; close(keychord_fd); } diff --git a/init/log.cpp b/init/log.cpp index ace9fd710..ee75ffc86 100644 --- a/init/log.cpp +++ b/init/log.cpp @@ -22,48 +22,53 @@ #include -#include - -static void init_klog_vwrite(int level, const char* fmt, va_list ap) { - static const char* tag = basename(getprogname()); +static const int kLogSeverityToKLogLevel[] = { + KLOG_NOTICE_LEVEL, KLOG_DEBUG_LEVEL, KLOG_INFO_LEVEL, + KLOG_WARNING_LEVEL, KLOG_ERROR_LEVEL, 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 prefix_size = snprintf(buf, sizeof(buf), "<%d>%s: ", level, tag); - size_t msg_size = vsnprintf(buf + prefix_size, sizeof(buf) - prefix_size, fmt, ap); - if (msg_size >= sizeof(buf) - prefix_size) { - msg_size = snprintf(buf + prefix_size, sizeof(buf) - prefix_size, - "(%zu-byte message too long for printk)\n", msg_size); + 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 = prefix_size + msg_size; - + iov[0].iov_len = size; klog_writev(level, iov, 1); } -void init_klog_write(int level, const char* fmt, ...) { - va_list ap; - va_start(ap, fmt); - init_klog_vwrite(level, fmt, ap); - va_end(ap); +void InitKernelLogging(char* argv[]) { + android::base::InitLogging(argv, &KernelLogger); + + klog_init(); + klog_set_level(KLOG_NOTICE_LEVEL); } int selinux_klog_callback(int type, const char *fmt, ...) { - int level = KLOG_ERROR_LEVEL; + android::base::LogSeverity severity = android::base::ERROR; if (type == SELINUX_WARNING) { - level = KLOG_WARNING_LEVEL; + severity = android::base::WARNING; } else if (type == SELINUX_INFO) { - level = KLOG_INFO_LEVEL; + severity = android::base::INFO; } + char buf[1024]; va_list ap; va_start(ap, fmt); - init_klog_vwrite(level, fmt, ap); + vsnprintf(buf, sizeof(buf), fmt, ap); va_end(ap); + KernelLogger(android::base::MAIN, severity, "selinux", nullptr, 0, buf); return 0; } diff --git a/init/log.h b/init/log.h index c5c30aff8..cf552a19c 100644 --- a/init/log.h +++ b/init/log.h @@ -17,16 +17,12 @@ #ifndef _INIT_LOG_H_ #define _INIT_LOG_H_ +#include + #include -#define ERROR(x...) init_klog_write(KLOG_ERROR_LEVEL, x) -#define WARNING(x...) init_klog_write(KLOG_WARNING_LEVEL, x) -#define NOTICE(x...) init_klog_write(KLOG_NOTICE_LEVEL, x) -#define INFO(x...) init_klog_write(KLOG_INFO_LEVEL, x) -#define DEBUG(x...) init_klog_write(KLOG_DEBUG_LEVEL, x) -#define VERBOSE(x...) init_klog_write(KLOG_DEBUG_LEVEL, x) +void InitKernelLogging(char* argv[]); -void init_klog_write(int level, const char* fmt, ...) __printflike(2, 3); int selinux_klog_callback(int level, const char* fmt, ...) __printflike(2, 3); #endif diff --git a/init/parser.cpp b/init/parser.cpp index ae103ec82..45862b732 100644 --- a/init/parser.cpp +++ b/init/parser.cpp @@ -20,7 +20,7 @@ void parse_error(struct parse_state *state, const char *fmt, ...) vsnprintf(buf + off, 128 - off, fmt, ap); va_end(ap); buf[127] = 0; - ERROR("%s", buf); + LOG(ERROR) << buf; } int next_token(struct parse_state *state) diff --git a/init/property_service.cpp b/init/property_service.cpp index c617dc667..e2e1b16fc 100644 --- a/init/property_service.cpp +++ b/init/property_service.cpp @@ -64,7 +64,7 @@ static int property_set_fd = -1; void property_init() { if (__system_property_area_init()) { - ERROR("Failed to initialize property area\n"); + LOG(ERROR) << "Failed to initialize property area"; exit(1); } } @@ -127,7 +127,7 @@ static void write_persistent_property(const char *name, const char *value) snprintf(tempPath, sizeof(tempPath), "%s/.temp.XXXXXX", PERSISTENT_PROPERTY_DIR); fd = mkstemp(tempPath); if (fd < 0) { - ERROR("Unable to write persistent property to temp file %s: %s\n", tempPath, strerror(errno)); + PLOG(ERROR) << "Unable to write persistent property to temp file " << tempPath; return; } write(fd, value, strlen(value)); @@ -136,8 +136,8 @@ static void write_persistent_property(const char *name, const char *value) snprintf(path, sizeof(path), "%s/%s", PERSISTENT_PROPERTY_DIR, name); if (rename(tempPath, path)) { + PLOG(ERROR) << "Unable to rename persistent property file " << tempPath << " to " << path; unlink(tempPath); - ERROR("Unable to rename persistent property file %s to %s\n", tempPath, path); } } @@ -176,7 +176,7 @@ static int property_set_impl(const char* name, const char* value) { if (strcmp("selinux.restorecon_recursive", name) == 0 && valuelen > 0) { if (restorecon_recursive(value) != 0) { - ERROR("Failed to restorecon_recursive %s\n", value); + LOG(ERROR) << "Failed to restorecon_recursive " << value; } } @@ -219,7 +219,7 @@ static int property_set_impl(const char* name, const char* value) { int property_set(const char* name, const char* value) { int rc = property_set_impl(name, value); if (rc == -1) { - ERROR("property_set(\"%s\", \"%s\") failed\n", name, value); + LOG(ERROR) << "property_set(\"" << name << "\", \"" << value << "\") failed"; } return rc; } @@ -245,7 +245,7 @@ static void handle_property_set_fd() /* Check socket options here */ if (getsockopt(s, SOL_SOCKET, SO_PEERCRED, &cr, &cr_size) < 0) { close(s); - ERROR("Unable to receive socket options\n"); + PLOG(ERROR) << "Unable to receive socket options"; return; } @@ -254,19 +254,18 @@ static void handle_property_set_fd() ufds[0].revents = 0; nr = TEMP_FAILURE_RETRY(poll(ufds, 1, timeout_ms)); if (nr == 0) { - ERROR("sys_prop: timeout waiting for uid=%d to send property message.\n", cr.uid); + LOG(ERROR) << "sys_prop: timeout waiting for uid " << cr.uid << " to send property message."; close(s); return; } else if (nr < 0) { - ERROR("sys_prop: error waiting for uid=%d to send property message: %s\n", cr.uid, strerror(errno)); + PLOG(ERROR) << "sys_prop: error waiting for uid " << cr.uid << " to send property message"; close(s); return; } r = TEMP_FAILURE_RETRY(recv(s, &msg, sizeof(msg), MSG_DONTWAIT)); if(r != sizeof(prop_msg)) { - ERROR("sys_prop: mis-match msg size received: %d expected: %zu: %s\n", - r, sizeof(prop_msg), strerror(errno)); + PLOG(ERROR) << "sys_prop: mis-match msg size received: " << r << " expected: " << sizeof(prop_msg); close(s); return; } @@ -277,7 +276,7 @@ static void handle_property_set_fd() msg.value[PROP_VALUE_MAX-1] = 0; if (!is_legal_property_name(msg.name, strlen(msg.name))) { - ERROR("sys_prop: illegal property name. Got: \"%s\"\n", msg.name); + LOG(ERROR) << "sys_prop: illegal property name \"" << msg.name << "\""; close(s); return; } @@ -291,15 +290,17 @@ static void handle_property_set_fd() if (check_control_mac_perms(msg.value, source_ctx, &cr)) { handle_control_message((char*) msg.name + 4, (char*) msg.value); } else { - ERROR("sys_prop: Unable to %s service ctl [%s] uid:%d gid:%d pid:%d\n", - msg.name + 4, msg.value, cr.uid, cr.gid, cr.pid); + LOG(ERROR) << "sys_prop: Unable to " << (msg.name + 4) + << " service ctl [" << msg.value << "]" + << " uid:" << cr.uid + << " gid:" << cr.gid + << " pid:" << cr.pid; } } else { if (check_mac_perms(msg.name, source_ctx, &cr)) { property_set((char*) msg.name, (char*) msg.value); } else { - ERROR("sys_prop: permission denied uid:%d name:%s\n", - cr.uid, msg.name); + LOG(ERROR) << "sys_prop: permission denied uid:" << cr.uid << " name:" << msg.name; } // Note: bionic's property client code assumes that the @@ -389,7 +390,7 @@ static void load_properties_from_file(const char* filename, const char* filter) data.push_back('\n'); load_properties(&data[0], filter); } - NOTICE("(Loading properties from %s took %.2fs.)\n", filename, t.duration()); + LOG(VERBOSE) << "(Loading properties from " << filename << " took " << t.duration() << "s.)"; } static void load_persistent_properties() { @@ -397,8 +398,8 @@ static void load_persistent_properties() { std::unique_ptr dir(opendir(PERSISTENT_PROPERTY_DIR), closedir); if (!dir) { - ERROR("Unable to open persistent property directory \"%s\": %s\n", - PERSISTENT_PROPERTY_DIR, strerror(errno)); + PLOG(ERROR) << "Unable to open persistent property directory \"" + << PERSISTENT_PROPERTY_DIR << "\""; return; } @@ -414,25 +415,23 @@ static void load_persistent_properties() { // Open the file and read the property value. int fd = openat(dirfd(dir.get()), entry->d_name, O_RDONLY | O_NOFOLLOW); if (fd == -1) { - ERROR("Unable to open persistent property file \"%s\": %s\n", - entry->d_name, strerror(errno)); + PLOG(ERROR) << "Unable to open persistent property file \"" << entry->d_name << "\""; continue; } struct stat sb; if (fstat(fd, &sb) == -1) { - ERROR("fstat on property file \"%s\" failed: %s\n", entry->d_name, strerror(errno)); + PLOG(ERROR) << "fstat on property file \"" << entry->d_name << "\" failed"; close(fd); continue; } // File must not be accessible to others, be owned by root/root, and // not be a hard link to any other file. - if (((sb.st_mode & (S_IRWXG | S_IRWXO)) != 0) || (sb.st_uid != 0) || (sb.st_gid != 0) || - (sb.st_nlink != 1)) { - ERROR("skipping insecure property file %s (uid=%u gid=%u nlink=%u mode=%o)\n", - entry->d_name, (unsigned int)sb.st_uid, (unsigned int)sb.st_gid, - (unsigned int)sb.st_nlink, sb.st_mode); + if (((sb.st_mode & (S_IRWXG | S_IRWXO)) != 0) || sb.st_uid != 0 || sb.st_gid != 0 || sb.st_nlink != 1) { + PLOG(ERROR) << "skipping insecure property file " << entry->d_name + << " (uid=" << sb.st_uid << " gid=" << sb.st_gid + << " nlink=" << sb.st_nlink << " mode=" << std::oct << sb.st_mode << ")"; close(fd); continue; } @@ -443,8 +442,7 @@ static void load_persistent_properties() { value[length] = 0; property_set(entry->d_name, value); } else { - ERROR("Unable to read persistent property file %s: %s\n", - entry->d_name, strerror(errno)); + PLOG(ERROR) << "Unable to read persistent property file " << entry->d_name; } close(fd); } @@ -477,27 +475,27 @@ void load_persist_props(void) { void load_recovery_id_prop() { std::string ro_hardware = property_get("ro.hardware"); if (ro_hardware.empty()) { - ERROR("ro.hardware not set - unable to load recovery id\n"); + LOG(ERROR) << "ro.hardware not set - unable to load recovery id"; return; } std::string fstab_filename = FSTAB_PREFIX + ro_hardware; std::unique_ptr tab(fs_mgr_read_fstab(fstab_filename.c_str()), - fs_mgr_free_fstab); + fs_mgr_free_fstab); if (!tab) { - ERROR("unable to read fstab %s: %s\n", fstab_filename.c_str(), strerror(errno)); + PLOG(ERROR) << "unable to read fstab " << fstab_filename; return; } fstab_rec* rec = fs_mgr_get_entry_for_mount_point(tab.get(), RECOVERY_MOUNT_POINT); if (rec == NULL) { - ERROR("/recovery not specified in fstab\n"); + LOG(ERROR) << "/recovery not specified in fstab"; return; } int fd = open(rec->blk_device, O_RDONLY); if (fd == -1) { - ERROR("error opening block device %s: %s\n", rec->blk_device, strerror(errno)); + PLOG(ERROR) << "error opening block device " << rec->blk_device; return; } @@ -506,7 +504,7 @@ void load_recovery_id_prop() { std::string hex = bytes_to_hex(reinterpret_cast(hdr.id), sizeof(hdr.id)); property_set("ro.recovery_id", hex.c_str()); } else { - ERROR("error reading /recovery: %s\n", strerror(errno)); + PLOG(ERROR) << "error reading /recovery"; } close(fd); @@ -523,7 +521,7 @@ void start_property_service() { property_set_fd = create_socket(PROP_SERVICE_NAME, SOCK_STREAM | SOCK_CLOEXEC | SOCK_NONBLOCK, 0666, 0, 0, NULL); if (property_set_fd == -1) { - ERROR("start_property_service socket creation failed: %s\n", strerror(errno)); + PLOG(ERROR) << "start_property_service socket creation failed"; exit(1); } diff --git a/init/service.cpp b/init/service.cpp index d917b30e0..d2edddd47 100644 --- a/init/service.cpp +++ b/init/service.cpp @@ -29,6 +29,7 @@ #include #include +#include #include #include #include @@ -91,8 +92,7 @@ void Service::NotifyStateChange(const std::string& new_state) const { std::string prop_name = StringPrintf("init.svc.%s", name_.c_str()); if (prop_name.length() >= PROP_NAME_MAX) { // If the property name would be too long, we can't set it. - ERROR("Property name \"init.svc.%s\" too long; not setting to %s\n", - name_.c_str(), new_state.c_str()); + LOG(ERROR) << "Property name \"init.svc." << name_ << "\" too long; not setting to " << new_state; return; } @@ -100,8 +100,9 @@ void Service::NotifyStateChange(const std::string& new_state) const { } void Service::KillProcessGroup(int signal) { - NOTICE("Sending signal %d to service '%s' (pid %d) process group...\n", - signal, name_.c_str(), pid_); + LOG(VERBOSE) << "Sending signal " << signal + << " to service '" << name_ + << "' (pid " << pid_ << ") process group...\n", kill(pid_, signal); killProcessGroup(uid_, pid_, signal); } @@ -118,7 +119,7 @@ bool Service::Reap() { } if (flags_ & SVC_EXEC) { - INFO("SVC_EXEC pid %d finished...\n", pid_); + LOG(INFO) << "SVC_EXEC pid " << pid_ << " finished..."; return true; } @@ -141,9 +142,10 @@ bool Service::Reap() { if ((flags_ & SVC_CRITICAL) && !(flags_ & SVC_RESTART)) { if (time_crashed_ + CRITICAL_CRASH_WINDOW >= now) { if (++nr_crashed_ > CRITICAL_CRASH_THRESHOLD) { - ERROR("critical process '%s' exited %d times in %d minutes; " - "rebooting into recovery mode\n", name_.c_str(), - CRITICAL_CRASH_THRESHOLD, CRITICAL_CRASH_WINDOW / 60); + LOG(ERROR) << "critical process '" << name_ << "' exited " + << CRITICAL_CRASH_THRESHOLD << " times in " + << (CRITICAL_CRASH_WINDOW / 60) << " minutes; " + << "rebooting into recovery mode"; android_reboot(ANDROID_RB_RESTART2, 0, "recovery"); return false; } @@ -164,15 +166,11 @@ bool Service::Reap() { } void Service::DumpState() const { - INFO("service %s\n", name_.c_str()); - INFO(" class '%s'\n", classname_.c_str()); - INFO(" exec"); - for (const auto& s : args_) { - INFO(" '%s'", s.c_str()); - } - INFO("\n"); + LOG(INFO) << "service " << name_; + LOG(INFO) << " class '" << classname_ << "'"; + LOG(INFO) << " exec "<< android::base::Join(args_, " "); for (const auto& si : sockets_) { - INFO(" socket %s %s 0%o\n", si.name.c_str(), si.type.c_str(), si.perm); + LOG(INFO) << " socket " << si.name << " " << si.type << " " << std::oct << si.perm; } } @@ -362,8 +360,7 @@ bool Service::Start() { bool have_console = (open(console_.c_str(), O_RDWR | O_CLOEXEC) != -1); if (!have_console) { - ERROR("service '%s' couldn't open console '%s': %s\n", - name_.c_str(), console_.c_str(), strerror(errno)); + PLOG(ERROR) << "service '" << name_ << "' couldn't open console '" << console_ << "'"; flags_ |= SVC_DISABLED; return false; } @@ -371,8 +368,7 @@ bool Service::Start() { struct stat sb; if (stat(args_[0].c_str(), &sb) == -1) { - ERROR("cannot find '%s' (%s), disabling '%s'\n", - args_[0].c_str(), strerror(errno), name_.c_str()); + PLOG(ERROR) << "cannot find '" << args_[0] << "', disabling '" << name_ << "'"; flags_ |= SVC_DISABLED; return false; } @@ -384,16 +380,16 @@ bool Service::Start() { char* mycon = nullptr; char* fcon = nullptr; - INFO("computing context for service '%s'\n", args_[0].c_str()); + LOG(INFO) << "computing context for service '" << args_[0] << "'"; int rc = getcon(&mycon); if (rc < 0) { - ERROR("could not get context while starting '%s'\n", name_.c_str()); + LOG(ERROR) << "could not get context while starting '" << name_ << "'"; return false; } rc = getfilecon(args_[0].c_str(), &fcon); if (rc < 0) { - ERROR("could not get context while starting '%s'\n", name_.c_str()); + LOG(ERROR) << "could not get context while starting '" << name_ << "'"; free(mycon); return false; } @@ -406,7 +402,7 @@ bool Service::Start() { free(ret_scon); } if (rc == 0 && scon == mycon) { - ERROR("Service %s does not have a SELinux domain defined.\n", name_.c_str()); + LOG(ERROR) << "Service " << name_ << " does not have a SELinux domain defined."; free(mycon); free(fcon); return false; @@ -414,12 +410,12 @@ bool Service::Start() { free(mycon); free(fcon); if (rc < 0) { - ERROR("could not get context while starting '%s'\n", name_.c_str()); + LOG(ERROR) << "could not get context while starting '" << name_ << "'"; return false; } } - NOTICE("Starting service '%s'...\n", name_.c_str()); + LOG(VERBOSE) << "Starting service '" << name_ << "'..."; pid_t pid = fork(); if (pid == 0) { @@ -446,15 +442,14 @@ bool Service::Start() { std::string pid_str = StringPrintf("%d", getpid()); for (const auto& file : writepid_files_) { if (!WriteStringToFile(pid_str, file)) { - ERROR("couldn't write %s to %s: %s\n", - pid_str.c_str(), file.c_str(), strerror(errno)); + PLOG(ERROR) << "couldn't write " << pid_str << " to " << file; } } if (ioprio_class_ != IoSchedClass_NONE) { if (android_set_ioprio(getpid(), ioprio_class_, ioprio_pri_)) { - ERROR("Failed to set pid %d ioprio = %d,%d: %s\n", - getpid(), ioprio_class_, ioprio_pri_, strerror(errno)); + PLOG(ERROR) << "Failed to set pid " << getpid() + << " ioprio=" << ioprio_class_ << "," << ioprio_pri_; } } @@ -470,32 +465,31 @@ bool Service::Start() { // As requested, set our gid, supplemental gids, and uid. if (gid_) { if (setgid(gid_) != 0) { - ERROR("setgid failed: %s\n", strerror(errno)); + PLOG(ERROR) << "setgid failed"; _exit(127); } } if (!supp_gids_.empty()) { if (setgroups(supp_gids_.size(), &supp_gids_[0]) != 0) { - ERROR("setgroups failed: %s\n", strerror(errno)); + PLOG(ERROR) << "setgroups failed"; _exit(127); } } if (uid_) { if (setuid(uid_) != 0) { - ERROR("setuid failed: %s\n", strerror(errno)); + PLOG(ERROR) << "setuid failed"; _exit(127); } } if (!seclabel_.empty()) { if (setexeccon(seclabel_.c_str()) < 0) { - ERROR("cannot setexeccon('%s'): %s\n", - seclabel_.c_str(), strerror(errno)); + PLOG(ERROR) << "cannot setexeccon('" << seclabel_ << "')"; _exit(127); } } if (priority_ != 0) { if (setpriority(PRIO_PROCESS, 0, priority_) != 0) { - ERROR("setpriority failed: %s\n", strerror(errno)); + PLOG(ERROR) << "setpriority failed"; _exit(127); } } @@ -506,7 +500,7 @@ bool Service::Start() { strs.push_back(const_cast(args_[0].c_str())); for (std::size_t i = 1; i < args_.size(); ++i) { if (!expand_props(args_[i], &expanded_args[i])) { - ERROR("%s: cannot expand '%s'\n", args_[0].c_str(), args_[i].c_str()); + LOG(ERROR) << args_[0] << ": cannot expand '" << args_[i] << "'"; _exit(127); } strs.push_back(const_cast(expanded_args[i].c_str())); @@ -514,14 +508,14 @@ bool Service::Start() { strs.push_back(nullptr); if (execve(strs[0], (char**) &strs[0], (char**) ENV) < 0) { - ERROR("cannot execve('%s'): %s\n", strs[0], strerror(errno)); + PLOG(ERROR) << "cannot execve('" << strs[0] << "')"; } _exit(127); } if (pid < 0) { - ERROR("failed to start '%s'\n", name_.c_str()); + PLOG(ERROR) << "failed to fork for '" << name_ << "'"; pid_ = 0; return false; } @@ -532,14 +526,13 @@ bool Service::Start() { errno = -createProcessGroup(uid_, pid_); if (errno != 0) { - ERROR("createProcessGroup(%d, %d) failed for service '%s': %s\n", - uid_, pid_, name_.c_str(), strerror(errno)); + PLOG(ERROR) << "createProcessGroup(" << uid_ << ", " << pid_ << ") failed for service '" << name_ << "'"; } if ((flags_ & SVC_EXEC) != 0) { - INFO("SVC_EXEC pid %d (uid %d gid %d+%zu context %s) started; waiting...\n", - pid_, uid_, gid_, supp_gids_.size(), - !seclabel_.empty() ? seclabel_.c_str() : "default"); + LOG(INFO) << android::base::StringPrintf("SVC_EXEC pid %d (uid %d gid %d+%zu context %s) started; waiting...", + pid_, uid_, gid_, supp_gids_.size(), + !seclabel_.empty() ? seclabel_.c_str() : "default"); } NotifyStateChange("running"); @@ -672,8 +665,7 @@ ServiceManager& ServiceManager::GetInstance() { void ServiceManager::AddService(std::unique_ptr service) { Service* old_service = FindServiceByName(service->name()); if (old_service) { - ERROR("ignored duplicate definition of service '%s'", - service->name().c_str()); + LOG(ERROR) << "ignored duplicate definition of service '" << service->name() << "'"; return; } services_.emplace_back(std::move(service)); @@ -690,12 +682,12 @@ Service* ServiceManager::MakeExecOneshotService(const std::vector& } } if (command_arg > 4 + NR_SVC_SUPP_GIDS) { - ERROR("exec called with too many supplementary group ids\n"); + LOG(ERROR) << "exec called with too many supplementary group ids"; return nullptr; } if (command_arg >= args.size()) { - ERROR("exec called without command\n"); + LOG(ERROR) << "exec called without command"; return nullptr; } std::vector str_args(args.begin() + command_arg, args.end()); @@ -725,8 +717,7 @@ Service* ServiceManager::MakeExecOneshotService(const std::vector& std::unique_ptr svc_p(new Service(name, "default", flags, uid, gid, supp_gids, seclabel, str_args)); if (!svc_p) { - ERROR("Couldn't allocate service for exec of '%s'", - str_args[0].c_str()); + LOG(ERROR) << "Couldn't allocate service for exec of '" << str_args[0] << "'"; return nullptr; } Service* svc = svc_p.get(); @@ -809,7 +800,6 @@ void ServiceManager::DumpState() const { for (const auto& s : services_) { s->DumpState(); } - INFO("\n"); } bool ServiceManager::ReapOneProcess() { @@ -818,7 +808,7 @@ bool ServiceManager::ReapOneProcess() { if (pid == 0) { return false; } else if (pid == -1) { - ERROR("waitpid failed: %s\n", strerror(errno)); + PLOG(ERROR) << "waitpid failed"; return false; } @@ -833,13 +823,13 @@ bool ServiceManager::ReapOneProcess() { } if (WIFEXITED(status)) { - NOTICE("%s exited with status %d\n", name.c_str(), WEXITSTATUS(status)); + LOG(VERBOSE) << name << " exited with status " << WEXITSTATUS(status); } else if (WIFSIGNALED(status)) { - NOTICE("%s killed by signal %d\n", name.c_str(), WTERMSIG(status)); + LOG(VERBOSE) << name << " killed by signal " << WTERMSIG(status); } else if (WIFSTOPPED(status)) { - NOTICE("%s stopped by signal %d\n", name.c_str(), WSTOPSIG(status)); + LOG(VERBOSE) << name << " stopped by signal " << WSTOPSIG(status); } else { - NOTICE("%s state changed", name.c_str()); + LOG(VERBOSE) << name << " state changed"; } if (!svc) { diff --git a/init/signal_handler.cpp b/init/signal_handler.cpp index ea483d4e2..0dea3e065 100644 --- a/init/signal_handler.cpp +++ b/init/signal_handler.cpp @@ -47,7 +47,7 @@ static void handle_signal() { static void SIGCHLD_handler(int) { if (TEMP_FAILURE_RETRY(write(signal_write_fd, "1", 1)) == -1) { - ERROR("write(signal_write_fd) failed: %s\n", strerror(errno)); + PLOG(ERROR) << "write(signal_write_fd) failed"; } } @@ -55,7 +55,7 @@ void signal_handler_init() { // Create a signalling mechanism for SIGCHLD. int s[2]; if (socketpair(AF_UNIX, SOCK_STREAM | SOCK_NONBLOCK | SOCK_CLOEXEC, 0, s) == -1) { - ERROR("socketpair failed: %s\n", strerror(errno)); + PLOG(ERROR) << "socketpair failed"; exit(1); } diff --git a/init/ueventd.cpp b/init/ueventd.cpp index b63714149..91f8b1ad2 100644 --- a/init/ueventd.cpp +++ b/init/ueventd.cpp @@ -53,10 +53,9 @@ int ueventd_main(int argc, char **argv) signal(SIGCHLD, SIG_IGN); open_devnull_stdio(); - klog_init(); - klog_set_level(KLOG_NOTICE_LEVEL); + InitKernelLogging(argv); - NOTICE("ueventd started!\n"); + LOG(INFO) << "ueventd started!"; selinux_callback cb; cb.func_log = selinux_klog_callback; @@ -108,14 +107,14 @@ void set_device_permission(int nargs, char **args) name = args[0]; if (!strncmp(name,"/sys/", 5) && (nargs == 5)) { - INFO("/sys/ rule %s %s\n",args[0],args[1]); + LOG(INFO) << "/sys/ rule " << args[0] << " " << args[1]; attr = args[1]; args++; nargs--; } if (nargs != 4) { - ERROR("invalid line ueventd.rc line for '%s'\n", args[0]); + LOG(ERROR) << "invalid line ueventd.rc line for '" << args[0] << "'"; return; } @@ -130,14 +129,14 @@ void set_device_permission(int nargs, char **args) perm = strtol(args[1], &endptr, 8); if (!endptr || *endptr != '\0') { - ERROR("invalid mode '%s'\n", args[1]); + LOG(ERROR) << "invalid mode '" << args[1] << "'"; free(tmp); return; } struct passwd* pwd = getpwnam(args[2]); if (!pwd) { - ERROR("invalid uid '%s'\n", args[2]); + LOG(ERROR) << "invalid uid '" << args[2] << "'"; free(tmp); return; } @@ -145,7 +144,7 @@ void set_device_permission(int nargs, char **args) struct group* grp = getgrnam(args[3]); if (!grp) { - ERROR("invalid gid '%s'\n", args[3]); + LOG(ERROR) << "invalid gid '" << args[3] << "'"; free(tmp); return; } diff --git a/init/util.cpp b/init/util.cpp index 368096e15..6315a7acf 100644 --- a/init/util.cpp +++ b/init/util.cpp @@ -34,6 +34,7 @@ #include #include +#include #include /* for ANDROID_SOCKET_* */ @@ -74,7 +75,7 @@ static unsigned int do_decode_uid(const char *s) unsigned int decode_uid(const char *s) { unsigned int v = do_decode_uid(s); if (v == UINT_MAX) { - ERROR("decode_uid: Unable to find UID for '%s'. Returning UINT_MAX\n", s); + LOG(ERROR) << "decode_uid: Unable to find UID for '" << s << "'; returning UINT_MAX"; } return v; } @@ -94,14 +95,14 @@ int create_socket(const char *name, int type, mode_t perm, uid_t uid, if (socketcon) { if (setsockcreatecon(socketcon) == -1) { - ERROR("setsockcreatecon(\"%s\") failed: %s\n", socketcon, strerror(errno)); + PLOG(ERROR) << "setsockcreatecon(\"" << socketcon << "\") failed"; return -1; } } fd = socket(PF_UNIX, type, 0); if (fd < 0) { - ERROR("Failed to open socket '%s': %s\n", name, strerror(errno)); + PLOG(ERROR) << "Failed to open socket '" << name << "'"; return -1; } @@ -115,7 +116,7 @@ int create_socket(const char *name, int type, mode_t perm, uid_t uid, ret = unlink(addr.sun_path); if (ret != 0 && errno != ENOENT) { - ERROR("Failed to unlink old socket '%s': %s\n", name, strerror(errno)); + PLOG(ERROR) << "Failed to unlink old socket '" << name << "'"; goto out_close; } @@ -133,23 +134,26 @@ int create_socket(const char *name, int type, mode_t perm, uid_t uid, freecon(filecon); if (ret) { - ERROR("Failed to bind socket '%s': %s\n", name, strerror(savederrno)); + errno = savederrno; + PLOG(ERROR) << "Failed to bind socket '" << name << "'"; goto out_unlink; } ret = lchown(addr.sun_path, uid, gid); if (ret) { - ERROR("Failed to lchown socket '%s': %s\n", addr.sun_path, strerror(errno)); + PLOG(ERROR) << "Failed to lchown socket '" << addr.sun_path << "'"; goto out_unlink; } ret = fchmodat(AT_FDCWD, addr.sun_path, perm, AT_SYMLINK_NOFOLLOW); if (ret) { - ERROR("Failed to fchmodat socket '%s': %s\n", addr.sun_path, strerror(errno)); + PLOG(ERROR) << "Failed to fchmodat socket '" << addr.sun_path << "'"; goto out_unlink; } - INFO("Created socket '%s' with mode '%o', user '%d', group '%d'\n", - addr.sun_path, perm, uid, gid); + LOG(INFO) << "Created socket '" << addr.sun_path << "'" + << ", mode " << std::oct << perm << std::dec + << ", user " << uid + << ", group " << gid; return fd; @@ -172,11 +176,11 @@ bool read_file(const char* path, std::string* content) { // or group-writable files. struct stat sb; if (fstat(fd, &sb) == -1) { - ERROR("fstat failed for '%s': %s\n", path, strerror(errno)); + PLOG(ERROR) << "fstat failed for '" << path << "'"; return false; } if ((sb.st_mode & (S_IWGRP | S_IWOTH)) != 0) { - ERROR("skipping insecure file '%s'\n", path); + PLOG(ERROR) << "skipping insecure file '" << path << "'"; return false; } @@ -188,12 +192,12 @@ bool read_file(const char* path, std::string* content) { int write_file(const char* path, const char* content) { int fd = TEMP_FAILURE_RETRY(open(path, O_WRONLY|O_CREAT|O_NOFOLLOW|O_CLOEXEC, 0600)); if (fd == -1) { - NOTICE("write_file: Unable to open '%s': %s\n", path, strerror(errno)); + PLOG(ERROR) << "write_file: Unable to open '" << path << "'"; return -1; } int result = android::base::WriteStringToFd(content, fd) ? 0 : -1; if (result == -1) { - NOTICE("write_file: Unable to write to '%s': %s\n", path, strerror(errno)); + PLOG(ERROR) << "write_file: Unable to write to '" << path << "'"; } close(fd); return result; @@ -228,7 +232,7 @@ int mkdir_recursive(const char *pathname, mode_t mode) if (width == 0) continue; if ((unsigned int)width > sizeof(buf) - 1) { - ERROR("path too long for mkdir_recursive\n"); + LOG(ERROR) << "path too long for mkdir_recursive"; return -1; } memcpy(buf, pathname, width); @@ -282,12 +286,10 @@ void make_link_init(const char *oldpath, const char *newpath) memcpy(buf, newpath, width); buf[width] = 0; ret = mkdir_recursive(buf, 0755); - if (ret) - ERROR("Failed to create directory %s: %s (%d)\n", buf, strerror(errno), errno); + if (ret) PLOG(ERROR) << "Failed to create directory " << buf; ret = symlink(oldpath, newpath); - if (ret && errno != EEXIST) - ERROR("Failed to symlink %s to %s: %s (%d)\n", oldpath, newpath, strerror(errno), errno); + if (ret && errno != EEXIST) PLOG(ERROR) << "Failed to symlink " << oldpath << " to " << newpath; } void remove_link(const char *oldpath, const char *newpath) @@ -446,7 +448,7 @@ bool expand_props(const std::string& src, std::string* dst) { const char* end = strchr(c, '}'); if (!end) { // failed to find closing brace, abort. - ERROR("unexpected end of string in '%s', looking for }\n", src.c_str()); + LOG(ERROR) << "unexpected end of string in '" << src << "', looking for }"; return false; } prop_name = std::string(c, end); @@ -458,21 +460,19 @@ bool expand_props(const std::string& src, std::string* dst) { } } else { prop_name = c; - ERROR("using deprecated syntax for specifying property '%s', use ${name} instead\n", - c); + LOG(ERROR) << "using deprecated syntax for specifying property '" << c << "', use ${name} instead"; c += prop_name.size(); } if (prop_name.empty()) { - ERROR("invalid zero-length prop name in '%s'\n", src.c_str()); + LOG(ERROR) << "invalid zero-length property name in '" << src << "'"; return false; } std::string prop_val = property_get(prop_name.c_str()); if (prop_val.empty()) { if (def_val.empty()) { - ERROR("property '%s' doesn't exist while expanding '%s'\n", - prop_name.c_str(), src.c_str()); + LOG(ERROR) << "property '" << prop_name << "' doesn't exist while expanding '" << src << "'"; return false; } prop_val = def_val; diff --git a/init/util.h b/init/util.h index 90fb39af4..45207eb52 100644 --- a/init/util.h +++ b/init/util.h @@ -23,8 +23,6 @@ #include #include -#define ARRAY_SIZE(x) (sizeof(x)/sizeof((x)[0])) - #define COLDBOOT_DONE "/dev/.coldboot_done" int create_socket(const char *name, int type, mode_t perm, diff --git a/init/watchdogd.cpp b/init/watchdogd.cpp index 0d16db907..3a3d81028 100644 --- a/init/watchdogd.cpp +++ b/init/watchdogd.cpp @@ -29,8 +29,7 @@ int watchdogd_main(int argc, char **argv) { open_devnull_stdio(); - klog_init(); - klog_set_level(KLOG_NOTICE_LEVEL); + InitKernelLogging(argv); int interval = 10; if (argc >= 2) interval = atoi(argv[1]); @@ -38,30 +37,31 @@ int watchdogd_main(int argc, char **argv) { int margin = 10; if (argc >= 3) margin = atoi(argv[2]); - NOTICE("started (interval %d, margin %d)!\n", interval, margin); + LOG(INFO) << "watchdogd started (interval " << interval << ", margin " << margin << ")!"; int fd = open(DEV_NAME, O_RDWR|O_CLOEXEC); if (fd == -1) { - ERROR("Failed to open %s: %s\n", DEV_NAME, strerror(errno)); + PLOG(ERROR) << "Failed to open " << DEV_NAME; return 1; } int timeout = interval + margin; int ret = ioctl(fd, WDIOC_SETTIMEOUT, &timeout); if (ret) { - ERROR("Failed to set timeout to %d: %s\n", timeout, strerror(errno)); + PLOG(ERROR) << "Failed to set timeout to " << timeout; ret = ioctl(fd, WDIOC_GETTIMEOUT, &timeout); if (ret) { - ERROR("Failed to get timeout: %s\n", strerror(errno)); + PLOG(ERROR) << "Failed to get timeout"; } else { if (timeout > margin) { interval = timeout - margin; } else { interval = 1; } - WARNING("Adjusted interval to timeout returned by driver:" - " timeout %d, interval %d, margin %d\n", - timeout, interval, margin); + LOG(WARNING) << "Adjusted interval to timeout returned by driver: " + << "timeout " << timeout + << ", interval " << interval + << ", margin " << margin; } }